Edit report at https://bugs.php.net/bug.php?id=63160&edit=1
ID: 63160
Comment by: r...@php.net
Reported by: r...@php.net
Summary: Lot of fstat call during include
Status: Open
Type: Bug
Package: Performance problem
Operating System: GNU/Linux
PHP Version: 5.4.7
Block user comment: N
Private report: N
New Comment:
Here is the backtrace for each fstat call
Breakpoint 1, do_fstat (d=d@entry=0x7ffff7fcbed0, force=force@entry=0) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:138
138 {
(gdb) bt
#0 do_fstat (d=d@entry=0x7ffff7fcbed0, force=force@entry=0) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:138
#1 0x0000000000581d0b in _php_stream_fopen (filename=<optimized out>,
mode=0x6a3831 "rb", opened_path=0x7fffffffa7d0, options=<optimized out>) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:967
#2 0x000000000057d4f2 in _php_stream_open_wrapper_ex (path=0x7ffff7fcb238
"/home/rcollet/test/test2.php", path@entry=0x7ffff7eba2e0 "test2.php",
mode=mode@entry=0x6a3831 "rb", options=16520,
opened_path=opened_path@entry=0x7fffffffa7d0, context=context@entry=0x0) at
/usr/src/debug/php-5.4.7/main/streams/streams.c:2049
#3 0x0000000000562a21 in php_stream_open_for_zend_ex (filename=0x7ffff7eba2e0
"test2.php", handle=0x7fffffffa7c0, mode=<optimized out>) at
/usr/src/debug/php-5.4.7/main/main.c:1303
#4 0x00000000005d919c in zend_stream_fixup
(file_handle=file_handle@entry=0x7fffffffa7c0, buf=buf@entry=0x7fffffffa500,
len=len@entry=0x7fffffffa508) at /usr/src/debug/php-5.4.7/Zend/zend_stream.c:187
#5 0x000000000058de66 in open_file_for_scanning
(file_handle=file_handle@entry=0x7fffffffa7c0) at
Zend/zend_language_scanner.l:486
#6 0x000000000058e0f2 in compile_file (file_handle=0x7fffffffa7c0, type=2) at
Zend/zend_language_scanner.l:569
#7 0x00007ffff01bbf5a in phar_compile_file (file_handle=0x7fffffffa7c0,
type=2) at /usr/src/debug/php-5.4.7/ext/phar/phar.c:3388
#8 0x000000000058e2e0 in compile_filename (type=type@entry=2,
filename=filename@entry=0x7ffff7fcc960) at Zend/zend_language_scanner.l:625
#9 0x00000000006079fb in ZEND_INCLUDE_OR_EVAL_SPEC_CONST_HANDLER
(execute_data=0x7ffff7f97060) at
/usr/src/debug/php-5.4.7/Zend/zend_vm_execute.h:2592
#10 0x0000000000623c47 in execute (op_array=0x7ffff7fcbaa8) at
/usr/src/debug/php-5.4.7/Zend/zend_vm_execute.h:410
#11 0x00000000005c4a3c in zend_execute_scripts (type=type@entry=8,
retval=retval@entry=0x0, file_count=file_count@entry=3) at
/usr/src/debug/php-5.4.7/Zend/zend.c:1286
#12 0x00000000005645bd in php_execute_script
(primary_file=primary_file@entry=0x7fffffffcd80) at
/usr/src/debug/php-5.4.7/main/main.c:2473
#13 0x000000000066c5c6 in do_cli (argc=2, argv=0x7fffffffe218) at
/usr/src/debug/php-5.4.7/sapi/cli/php_cli.c:988
#14 0x0000000000425aaa in main (argc=2, argv=0x7fffffffe218) at
/usr/src/debug/php-5.4.7/sapi/cli/php_cli.c:1364
(gdb) c
Continuing.
Breakpoint 1, do_fstat (d=d@entry=0x7ffff7fcbed0, force=force@entry=1) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:138
138 {
(gdb) bt
#0 do_fstat (d=d@entry=0x7ffff7fcbed0, force=force@entry=1) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:138
#1 0x00000000005807fa in php_stdiop_stat (stream=<optimized out>,
ssb=0x7fffffffa360) at /usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:546
#2 0x000000000056132f in php_zend_stream_fsizer
(handle=handle@entry=0x7ffff7fcbfa0) at
/usr/src/debug/php-5.4.7/main/main.c:1286
#3 0x0000000000562aaf in php_stream_open_for_zend_ex (filename=0x7ffff7eba2e0
"test2.php", handle=0x7fffffffa7c0, mode=<optimized out>) at
/usr/src/debug/php-5.4.7/main/main.c:1318
#4 0x00000000005d919c in zend_stream_fixup
(file_handle=file_handle@entry=0x7fffffffa7c0, buf=buf@entry=0x7fffffffa500,
len=len@entry=0x7fffffffa508) at /usr/src/debug/php-5.4.7/Zend/zend_stream.c:187
#5 0x000000000058de66 in open_file_for_scanning
(file_handle=file_handle@entry=0x7fffffffa7c0) at
Zend/zend_language_scanner.l:486
#6 0x000000000058e0f2 in compile_file (file_handle=0x7fffffffa7c0, type=2) at
Zend/zend_language_scanner.l:569
#7 0x00007ffff01bbf5a in phar_compile_file (file_handle=0x7fffffffa7c0,
type=2) at /usr/src/debug/php-5.4.7/ext/phar/phar.c:3388
#8 0x000000000058e2e0 in compile_filename (type=type@entry=2,
filename=filename@entry=0x7ffff7fcc960) at Zend/zend_language_scanner.l:625
#9 0x00000000006079fb in ZEND_INCLUDE_OR_EVAL_SPEC_CONST_HANDLER
(execute_data=0x7ffff7f97060) at
/usr/src/debug/php-5.4.7/Zend/zend_vm_execute.h:2592
#10 0x0000000000623c47 in execute (op_array=0x7ffff7fcbaa8) at
/usr/src/debug/php-5.4.7/Zend/zend_vm_execute.h:410
#11 0x00000000005c4a3c in zend_execute_scripts (type=type@entry=8,
retval=retval@entry=0x0, file_count=file_count@entry=3) at
/usr/src/debug/php-5.4.7/Zend/zend.c:1286
#12 0x00000000005645bd in php_execute_script
(primary_file=primary_file@entry=0x7fffffffcd80) at
/usr/src/debug/php-5.4.7/main/main.c:2473
#13 0x000000000066c5c6 in do_cli (argc=2, argv=0x7fffffffe218) at
/usr/src/debug/php-5.4.7/sapi/cli/php_cli.c:988
#14 0x0000000000425aaa in main (argc=2, argv=0x7fffffffe218) at
/usr/src/debug/php-5.4.7/sapi/cli/php_cli.c:1364
(gdb) c
Continuing.
Breakpoint 1, do_fstat (d=d@entry=0x7ffff7fcbed0, force=force@entry=1) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:138
138 {
(gdb) bt
#0 do_fstat (d=d@entry=0x7ffff7fcbed0, force=force@entry=1) at
/usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:138
#1 0x00000000005807fa in php_stdiop_stat (stream=<optimized out>,
ssb=0x7fffffffa3a0) at /usr/src/debug/php-5.4.7/main/streams/plain_wrapper.c:546
#2 0x000000000056132f in php_zend_stream_fsizer (handle=<optimized out>) at
/usr/src/debug/php-5.4.7/main/main.c:1286
#3 0x00000000005d94b7 in zend_stream_fsize (file_handle=<optimized out>) at
/usr/src/debug/php-5.4.7/Zend/zend_stream.c:115
#4 zend_stream_fixup (file_handle=file_handle@entry=0x7fffffffa7c0,
buf=buf@entry=0x7fffffffa500, len=len@entry=0x7fffffffa508) at
/usr/src/debug/php-5.4.7/Zend/zend_stream.c:222
#5 0x000000000058de66 in open_file_for_scanning
(file_handle=file_handle@entry=0x7fffffffa7c0) at
Zend/zend_language_scanner.l:486
#6 0x000000000058e0f2 in compile_file (file_handle=0x7fffffffa7c0, type=2) at
Zend/zend_language_scanner.l:569
#7 0x00007ffff01bbf5a in phar_compile_file (file_handle=0x7fffffffa7c0,
type=2) at /usr/src/debug/php-5.4.7/ext/phar/phar.c:3388
#8 0x000000000058e2e0 in compile_filename (type=type@entry=2,
filename=filename@entry=0x7ffff7fcc960) at Zend/zend_language_scanner.l:625
#9 0x00000000006079fb in ZEND_INCLUDE_OR_EVAL_SPEC_CONST_HANDLER
(execute_data=0x7ffff7f97060) at
/usr/src/debug/php-5.4.7/Zend/zend_vm_execute.h:2592
#10 0x0000000000623c47 in execute (op_array=0x7ffff7fcbaa8) at
/usr/src/debug/php-5.4.7/Zend/zend_vm_execute.h:410
#11 0x00000000005c4a3c in zend_execute_scripts (type=type@entry=8,
retval=retval@entry=0x0, file_count=file_count@entry=3) at
/usr/src/debug/php-5.4.7/Zend/zend.c:1286
#12 0x00000000005645bd in php_execute_script
(primary_file=primary_file@entry=0x7fffffffcd80) at
/usr/src/debug/php-5.4.7/main/main.c:2473
#13 0x000000000066c5c6 in do_cli (argc=2, argv=0x7fffffffe218) at
/usr/src/debug/php-5.4.7/sapi/cli/php_cli.c:988
#14 0x0000000000425aaa in main (argc=2, argv=0x7fffffffe218) at
/usr/src/debug/php-5.4.7/sapi/cli/php_cli.c:1364
Previous Comments:
------------------------------------------------------------------------
[2012-09-25 08:09:07] r...@php.net
Description:
------------
Hi,
Each "include" statement call fstat 3 time, which can be "slow" in some cluster
environment (usgin GFS2 p.e.)
Already open as #49383 (but closed as "not a bug")
The fstat cache is only available inside "plain_wrapper".
A solution could be to expose a stream_cached_stat (in _php_stream_wrapper_ops)
and use it during open process (or a additionnal parameter to stream_stat).
But this will introduce a important bc break.
Test script:
---------------
Trivial test code:
test1.php: <?php include('test2.php'); echo "done\n";
test2.php: irrevelant, can even be empty
$ strace php test1.php
Expected result:
----------------
...
open("xxx/test2.php", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=20, ...}) = 0
mmap(NULL, 20, PROT_READ, MAP_SHARED, 3, 0) = 0x7f0d595da000
munmap(0x7f0d595da000, 20) = 0
close(3)
...
Actual result:
--------------
...
open("xxx/test2.php", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0664, st_size=20, ...}) = 0
fstat(3, {st_mode=S_IFREG|0664, st_size=20, ...}) = 0
fstat(3, {st_mode=S_IFREG|0664, st_size=20, ...}) = 0
mmap(NULL, 20, PROT_READ, MAP_SHARED, 3, 0) = 0x7f0d595da000
munmap(0x7f0d595da000, 20) = 0
close(3)
...
------------------------------------------------------------------------
--
Edit this bug report at https://bugs.php.net/bug.php?id=63160&edit=1
