4


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.


Community
  • 1
Yemster
  • 41
  • 1
  • 3
  • 1
    What application is that PID? – Shane Madden Nov 28 '12 at 01: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 05: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 . and then pastebin the strace.out file somewhere. – Soham Chakraborty Dec 18 '13 at 12:07

2 Answers2

2

export TZ=:/etc/localtime also works - it will read the file on start-up and never again - this means daemon processes would need to be re-started, if you ever change the contents of this file.

However, like you, we also run UTC on all our servers, so it never changes.

Can't help you on the "clock_gettime" - however, I would say on VMs we found time() to be quite expensive, so we have a daemon process that allocates some shared memory and puts the time in there, then all processes that want to know the time attach to & read the shared memory instead of using the time() fn.

James Stevens
  • 131
  • 4
  • 1
    Here is a good explanation about `export TZ=:/etc/localtime`: https://packagecloud.io/blog/set-environment-variable-save-thousands-of-system-calls/ – famzah Oct 13 '21 at 20:16
  • As this is a `glibc` issue, it's possible you won't see it on Alpine, which uses `musl-libc` – James Stevens Oct 15 '21 at 07:52
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).

baronleaky
  • 11
  • 1