Bug #49383 [Com]: Lots of empty fstat() calls slow performance
Edit report at http://bugs.php.net/bug.php?id=49383edit=1 ID: 49383 Comment by: a dot rogge at solvention dot de Reported by:olga at metacafe dot com Summary:Lots of empty fstat() calls slow performance Status: Bogus Type: Bug Package:Performance problem Operating System: Red Hat 3.4.6-10 PHP Version:5.3, 6 Block user comment: N New Comment: First of all: No, we don't use open_basedir or safe_mode or stuff like that. But I still do not understand what this has to do with the issue. The redundant fstat() calls are obviously *not* from open_basedir, because the fstat() calls are done after the file was opened. I run 5.1.6, 5.2.14 and 5.3.2 with the same configuration. For 5.1.6 and 5.2.14 everything looks normally, in 5.3.2 there are suddenly three instead of one fstat() call after opening the file. The calls are identical and adjacent with no other syscalls in between. The two successive calls do not provide any more information than the first one and thus are redundant and useless. This is obviously a performance regression. Do you want to tell me that this is a new feature? Previous Comments: [2010-08-12 01:24:32] ras...@php.net Do you have openbase_dir enabled? If so, for security reasons we can't use the stat cache which is going to cause a lot of stats. For a setup with slow stats, I suggest chroot/jail or something along those lines rather than open_basedir to keep users separated. [2010-08-11 20:10:56] a dot rogge at solvention dot de Nobody cares wether or not APC works around the problem. There is obviously a regression from 5.2 to 5.3. Somebody maanged to triple the number of fstat() calls that are done for an include(). Yesterday I reproduced the issue on our webcluster. Running the Red Hat provided PHP 5.1.6 (from RHEL 5.5) the loadavg was around 8 for all boxes. Upgrading to PHP 5.3.2 made the loadavg raised to values of 30 or higher. Page load time went from 1 second to around 30 seconds. The best part is: we did install and configure apc for 5.3.2, but not for 5.1.6 So eventually 5.3.2 *with* APC produces 3 times more load and needs 30 times longer than our ancient 5.1.6 *without* APC. However, I must admit that we have our PHP-files on GFS2 where stat() is traditionally a bit slow. [2010-01-21 23:16:42] ras...@php.net Unable to reproduce under apc. [2009-10-14 11:28:06] olga at metacafe dot com The problem persists. We upgraded APC to the latest version (3.1.3p1). Cache full count is 0, hit ratio is 99.9%. I understand that this shouldn't happen, but there are still 3 fstat() calls per file opened. Here's our APC configuration - maybe you can see if anything is wrong with it? Do you have other versions? apc.cache_by_default1 apc.canonicalize1 apc.coredump_unmap 0 apc.enable_cli 1 apc.enabled 1 apc.file_md50 apc.file_update_protection 2 apc.filters apc.gc_ttl 3600 apc.include_once_override 1 apc.lazy_classes0 apc.lazy_functions 0 apc.max_file_size 1M apc.mmap_file_mask /tmp/apc.IR76ZW apc.num_files_hint 1024 apc.preload_path apc.report_autofilter 0 apc.rfc1867 0 apc.rfc1867_freq0 apc.rfc1867_nameAPC_UPLOAD_PROGRESS apc.rfc1867_prefix upload_ apc.rfc1867_ttl 3600 apc.shm_segments1 apc.shm_size128 apc.stat0 apc.stat_ctime 0 apc.ttl 7200 apc.use_request_time1 apc.user_entries_hint 4096 apc.user_ttl7200 apc.write_lock 1 [2009-09-03 16:49:18] ras...@php.net The only time this code is executed if you are running APC is if the script is not cached. So, either your APC setup is not working, you are constantly trashing your cache (check apc.php and look at the cache-full counter), or something else weird is going on. These fstats are coming from compiler which reads the script from disk and compiles it down to opcodes. It is impossible for this code to execute on an APC-cached script because we point the executor directly at the already compiled opcodes in shared memory. The remainder of the comments for this report are too long. To view the rest of the comments, please view the bug report online at http://bugs.php.net/bug.php?id=49383 -- Edit this bug report at http://bugs.php.net/bug.php?id=49383edit=1
Bug #49383 [Com]: Lots of empty fstat() calls slow performance
Edit report at http://bugs.php.net/bug.php?id=49383edit=1 ID: 49383 Comment by: a dot rogge at solvention dot de Reported by:olga at metacafe dot com Summary:Lots of empty fstat() calls slow performance Status: Bogus Type: Bug Package:Performance problem Operating System: Red Hat 3.4.6-10 PHP Version:5.3, 6 Block user comment: N New Comment: Nobody cares wether or not APC works around the problem. There is obviously a regression from 5.2 to 5.3. Somebody maanged to triple the number of fstat() calls that are done for an include(). Yesterday I reproduced the issue on our webcluster. Running the Red Hat provided PHP 5.1.6 (from RHEL 5.5) the loadavg was around 8 for all boxes. Upgrading to PHP 5.3.2 made the loadavg raised to values of 30 or higher. Page load time went from 1 second to around 30 seconds. The best part is: we did install and configure apc for 5.3.2, but not for 5.1.6 So eventually 5.3.2 *with* APC produces 3 times more load and needs 30 times longer than our ancient 5.1.6 *without* APC. However, I must admit that we have our PHP-files on GFS2 where stat() is traditionally a bit slow. Previous Comments: [2010-01-21 23:16:42] ras...@php.net Unable to reproduce under apc. [2009-10-14 11:28:06] olga at metacafe dot com The problem persists. We upgraded APC to the latest version (3.1.3p1). Cache full count is 0, hit ratio is 99.9%. I understand that this shouldn't happen, but there are still 3 fstat() calls per file opened. Here's our APC configuration - maybe you can see if anything is wrong with it? Do you have other versions? apc.cache_by_default1 apc.canonicalize1 apc.coredump_unmap 0 apc.enable_cli 1 apc.enabled 1 apc.file_md50 apc.file_update_protection 2 apc.filters apc.gc_ttl 3600 apc.include_once_override 1 apc.lazy_classes0 apc.lazy_functions 0 apc.max_file_size 1M apc.mmap_file_mask /tmp/apc.IR76ZW apc.num_files_hint 1024 apc.preload_path apc.report_autofilter 0 apc.rfc1867 0 apc.rfc1867_freq0 apc.rfc1867_nameAPC_UPLOAD_PROGRESS apc.rfc1867_prefix upload_ apc.rfc1867_ttl 3600 apc.shm_segments1 apc.shm_size128 apc.stat0 apc.stat_ctime 0 apc.ttl 7200 apc.use_request_time1 apc.user_entries_hint 4096 apc.user_ttl7200 apc.write_lock 1 [2009-09-03 16:49:18] ras...@php.net The only time this code is executed if you are running APC is if the script is not cached. So, either your APC setup is not working, you are constantly trashing your cache (check apc.php and look at the cache-full counter), or something else weird is going on. These fstats are coming from compiler which reads the script from disk and compiles it down to opcodes. It is impossible for this code to execute on an APC-cached script because we point the executor directly at the already compiled opcodes in shared memory. [2009-09-03 15:06:28] olga at metacafe dot com Thanks for the quick response. We do work with APC. I tested the new PHP without APC also, to make sure the fstat() calls aren't caused by it. But the statistics I sent to you are from web server that works with APC. You can also see from my first submission that in 5.2.9 fstat() doesn't take much time. [2009-09-03 14:24:14] ras...@php.net Still surprised these fstats take that long on your system. Note also that if you install APC, they completely go away. If you are down to caring about performance at the syscall level like that and you are not running a decent opcode cache, you are kind of confused. Here is a backtrace of those 3 fstats: #1 0x0137642f in do_fstat () #2 0x0137768f in _php_stream_fopen () #3 0x013719ba in _php_stream_open_wrapper_ex () #4 0x0135a1a3 in php_stream_open_for_zend_ex () #5 0x0135a2e0 in php_stream_open_for_zend () #6 0x013ca05f in zend_stream_fixup () #7 0x01383ae7 in open_file_for_scanning () #8 0x01383c8d in compile_file () #9 0x011eb8f7 in phar_compile_file () #10 0x013b4fa7 in zend_execute_scripts () #11 0x0135be38 in php_execute_script () #1 0x0137642f in do_fstat () #2 0x01376ee1 in php_stdiop_stat () #3 0x0135a148 in php_zend_stream_fsizer () #4 0x0135a206 in php_stream_open_for_zend_ex () #5 0x0135a2e0 in php_stream_open_for_zend () #6 0x013ca05f in zend_stream_fixup () #7 0x01383ae7 in open_file_for_scanning () #8 0x01383c8d in compile_file () #9 0x011eb8f7 in phar_compile_file () #10 0x013b4fa7 in
