[php-maint] Bug#618462: Bug#618462: php5: Large quantities of timezone file stat() calls causing possible regression

Erik Jacobson azhrarn at underhanded.org
Tue Mar 6 18:07:31 UTC 2012


I wish it were easy as removing a function call, but as far as I can
tell, the only place we even use a function with "timezone" in it is in
one specific page that's rarely used.  We do use time() in many places,
but nothing else that I can find. :/

I did recompile php from upstream, and all the stat() issues went away.
The biggest syscall culprit now would be poll(), but there's not a whole
lot I can do about that.

On Mon, Mar 05, 2012 at 11:41:42PM +0100, Ondřej Surý wrote:
> Erik,
> 
> I have checked some of my all records and is there a chance that you
> call timelib_timezone_id_is_valid() ?
> 
> I found this in my old records:
> 
> 1. Added overhead when timezone is not set -> I don't think we should
> really do anything in here. It's a simple matter of adding
> date_default_timezone_set("xxx/yyy") to your application. After adding
> this call PHP will use that value as first in guess_timezone().
> However we could put something about it to README.Debian.
> 
> 2. We call stat() everytime timelib_timezone_id_is_valid() is called.
> That is adds some slowdown, but I don't really see a way how to fix
> that unless you readahead all timezones, which will make PHP even more
> slower (mainly at startup, but that happens basically every time with
> non-threaded model).
> 
> O.
> 
> On Mon, Mar 5, 2012 at 21:08, Erik Jacobson <azhrarn at underhanded.org> wrote:
> > 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
> >
> >
> >
> > _______________________________________________
> > pkg-php-maint mailing list
> > pkg-php-maint at lists.alioth.debian.org
> > http://lists.alioth.debian.org/cgi-bin/mailman/listinfo/pkg-php-maint
> 
> 
> 
> -- 
> Ondřej Surý <ondrej at sury.org>
> 

-- 
ICQ: 116080581 | Jabber: azhrarn at underhanded.org
AIM/Y!: AzhrarnLOD | IRC: Kross @ irc.escapistmagazine.com
( Vim, Tabs, BSD Braces, Debian, and Perl )
-------------- next part --------------
A non-text attachment was scrubbed...
Name: signature.asc
Type: application/pgp-signature
Size: 198 bytes
Desc: Digital signature
URL: <http://lists.alioth.debian.org/pipermail/pkg-php-maint/attachments/20120306/5f5354a2/attachment.pgp>


More information about the pkg-php-maint mailing list