[php-maint] Bug#618462: php5: Large quantities of timezone file stat() calls causing possible regression
Erik Jacobson
azhrarn at underhanded.org
Mon Mar 5 20:08:34 UTC 2012
Package: php5
Version: 5.3.10-1
Severity: normal
Hi, while trying to narrow down possible causes of Apache child wait
states, I came across this possible issue with PHP apparently calling
stat() against the system timezone files repeatedly. This bug seems to
be primarily with tz init/searching looking at *all* the timezone files
with a question as to if it's a performance impact.
My issue is related but slightly different.
On a loaded server with ~150 php page requests a second, I was showing
an unusual amount of stat() calls in a child strace like so:
www-data 27168 0.7 0.1 321968 21780 ? SN 13:04 0:02 \_ /usr/sbin/apache2 -k start
# strace -p 27168 -f -c
Process 27168 attached - interrupt to quit
^CProcess 27168 detached
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
33.95 0.042694 3 12898 375 stat
25.95 0.032636 1 42586 select
6.68 0.008394 3 2893 munmap
5.15 0.006479 0 21928 sendto
Doing an strace dump and analyzing the stat calls pointed some at htaccess and include path
searches, but the vast majority were calls like so:
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
stat("/usr/share/zoneinfo/America/New_York", {st_mode=S_IFREG|0644, st_size=3519, ...}) = 0
The above block of calls were contiguous, all in less then a second.
Blocks like the above seem to roll through more then once a minute, and
individual stat() calls to the same file seem to appear once every 10-20
syscalls. The above identical lookup is the vast majority of the listed
stat calls in strace.
This is in a SINGLE child thread, out of *hundreds* of active threads.
The end result is thousands of stat calls a second.. To the same file.
Which never changes. And is never cached in APC. I haven't been able
to test the above load with switching to UTC and hoping it doesn't
try to lookup the file, as our current setup relies on local time for
certain operations (ugh).
I'm currently recompiling PHP to take advantage of their timezonedb lib,
and hoping it keeps everything in ram. Either that or I put the
timezone directory in a ramdisk and hoping for the best.
-- System Information:
Debian Release: 6.0
APT prefers unstable
APT policy: (500, 'unstable')
Architecture: amd64 (x86_64)
Kernel: Linux 2.6.32-5-amd64 (SMP w/4 CPU cores)
Versions of packages php5 depends on:
ii libapache2-mod-php5 5.3.10-1 server-side, HTML-embedded scripti
ii php5-common 5.3.10-1 Common files for packages built fr
php5 recommends no packages.
php5 suggests no packages.
-- no debconf information
More information about the pkg-php-maint
mailing list