php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #63160 Lot of fstat call during include
Submitted: 2012-09-25 08:09 UTC Modified: 2019-07-17 12:58 UTC
Votes:1
Avg. Score:4.0 ± 0.0
Reproduced:1 of 1 (100.0%)
Same Version:0 (0.0%)
Same OS:0 (0.0%)
From: remi@php.net Assigned: nikic (profile)
Status: Closed Package: Performance problem
PHP Version: 5.4.7 OS: GNU/Linux
Private report: No CVE-ID: None
Welcome back! If you're the original bug submitter, here's where you can edit the bug or add additional notes.
If you forgot your password, you can retrieve your password here.
Password:
Status:
Package:
Bug Type:
Summary:
From: remi@php.net
New email:
PHP Version: OS:

 

 [2012-09-25 08:09 UTC] remi@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)    
...



Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2012-09-25 08:10 UTC] remi@php.net
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
 [2012-09-25 09:27 UTC] laruence@php.net
the simple way is make the plain stream stat not force, like:
diff --git a/main/streams/plain_wrapper.c b/main/streams/plain_wrapper.c
index 80c22ce..2bc81a5 100644
--- a/main/streams/plain_wrapper.c
+++ b/main/streams/plain_wrapper.c
@@ -543,7 +543,7 @@ static int php_stdiop_stat(php_stream *stream, 
php_stream_statbuf *ssb TSRMLS_DC
 
 	assert(data != NULL);
 
-	ret = do_fstat(data, 1);
+	ret = do_fstat(data, 0);
 	memcpy(&ssb->sb, &data->sb, sizeof(ssb->sb));
 	return ret;
 }


but, this might introduce some unexpected issues. so, run with apc :)
 [2012-09-25 11:59 UTC] remi@php.net
I agree, APC is interesting (for lot of other reasons) and it reduces the 3 "fstat" calls to 2 "stat" calls.

Droping the "force" option doesn't seems acceptable ;)
 [2019-07-17 12:58 UTC] nikic@php.net
-Status: Open +Status: Closed -Assigned To: +Assigned To: nikic
 [2019-07-17 12:58 UTC] nikic@php.net
This is fixed in PHP 7.4. One goes away because we no longer use mmap and the other is removed in https://github.com/php/php-src/commit/07a4d134abd07690f9921eb0d0c7eeb671b0b875 by avoiding the "force" just for includes, where we don't need it.
 
PHP Copyright © 2001-2025 The PHP Group
All rights reserved.
Last updated: Fri May 02 10:01:28 2025 UTC