Take the 2-minute tour ×
Server Fault is a question and answer site for system and network administrators. It's 100% free, no registration required.


I've been experiencing really high CPU on a ruby on rails app (see stack below) and have been trying to diagnose the possible causes to no avail.

Stack:

  • ruby 1.9.3
  • rails 3.2.6
  • Apache/2.2.21 (Debian)
  • Phusion Passenger 3.0.11

Whenever I run strace against the spiking Rack process PID (see Top excerpt below), I am seeing a tonne of stat("/etc/localtime") and clock_gettime(CLOCK_REALTIME) calls and have no idea how to stop these.


Excerpt from Top showin running PID:

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
11674 www-user  20   0  313m 182m 5076 R   99  2.3  63:04.60 Rack: /var/www/my_rails_app/current
11634 www-user  20   0  411m 216m 5144 S   10  2.7 197:55.63 Rack: /var/www/my_rails_app/current


Strace snippet below:

[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 141474018}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 141577456}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 143073982}) = 0
[pid 11674] poll([{fd=15, events=POLLIN|POLLPRI}], 1, 0) = 0 (Timeout)
[pid 11674] write(15, "b\0\0\0\3SELECT `images`.* FROM `ima"..., 102) = 102
[pid 11674] read(15, "\1\0\0\1\0229\0\0\2\3def\23myappy_productio"..., 16384) = 2063
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 144138035}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
...
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] stat("/etc/localtime", {st_mode=S_IFREG|0644, st_size=118, ...}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 154076443}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 154189429}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 157185700}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 157298770}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 165076003}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 165212572}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 167542679}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354058955, 167683436}) = 0
....
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 62052248}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 62182486}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 62919948}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 63057266}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 63751707}) = 0
 [pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 73730686}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 75874687}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 76077133}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 78205019}) = 0
...
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 89370879}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 89583247}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 91637614}) = 0
[pid 11674] clock_gettime(CLOCK_REALTIME, {1354060036, 91782149}) = 0


Have Google'd around and came across a number of suggestions which I've tried with no success.


Things tried so far:

  1. Have tried setting time zone as recommended here
    Made no difference and issue still persists.
    Content of my /etc/localtime:

    TZif2UTCTZif2UTC
    UTC0

  2. Have tried the recommended fix for the leapsecond bug:

    date -s 'date'


No joy so far.


I'm fresh out of ideas so any help/advice on how to diagnose or resolve would be greatly appreciated.


share|improve this question
1  
What application is that PID? –  Shane Madden Nov 28 '12 at 1:30
    
Hi Shane, I've updated the post to include the details of the PID. PLease let me know what you think. –  Yemster Nov 28 '12 at 10:07
    
Looks like it's something running within ruby that's initiating the calls - are you able to do some digging in the code to see if there's anything that could potentially be looping on something that checks the time? –  Shane Madden Nov 29 '12 at 5:33
    
I have seen the same problem in a wordpress site running on CentOS+cPanel+Apache server. I want to know how to fix it too. –  garconcn Dec 31 '12 at 21:41
    
Can you run the strace like this strace -ffttTo /tmp/strace.out -p <pid>. and then pastebin the strace.out file somewhere. –  Soham Chakraborty Dec 18 '13 at 12:07

1 Answer 1

I've found that excessive stats to /etc/localtime are due to missing environment variables.

Try this:

echo $TZ

If it's blank, then set the variable in the correct location (i.e. /home/apache/.bash_profile). You'll need to set it for the user responsible for running your webserver, then reload the daemon (apachectl graceful etc).

TZ='Europe/London'; export TZ

Or whatever the correct timezone is for your region (http://en.wikipedia.org/wiki/List_of_tz_database_time_zones).

share|improve this answer

Your Answer

 
discard

By posting your answer, you agree to the privacy policy and terms of service.

Not the answer you're looking for? Browse other questions tagged or ask your own question.