#49383 [Bgs]: Lots of empty fstat() calls slow performance

ID: 49383 User updated by: olga at metacafe dot com Reported By: olga at metacafe dot com Status: Bogus Bug Type: Performance problem Operating System: Red Hat 3.4.6-10 PHP Version: 5.3, 6 New Comment: Turning all messages on/off didn't change the behavior. We tend eliminate the notices on the development stage. Can you please look at the system calls summary below? fstat() takes 25% of the total time. This doesn't happen in PHP 5.2.9. % time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 24.85 33.820248 256 131908 fstat 13.54 18.431644 263 70002 66 lstat 9.81 13.346466 259 51520 mmap 9.72 13.223388 258 51175 munmap 9.39 12.775102 264 48450 192 stat 8.83 12.014341 265 45383 10 open 8.72 11.866944 257 46154 close 3.47 4.724639 255 18530 396 read 3.26 4.430927 256 17297 lseek 1.88 2.557480 244 10477 poll 1.59 2.170520 261 8326 recvfrom 1.52 2.073135 259 7994 sendto ... ------ ----------- ----------- --------- --------- ---------------- 100.00 136.108580 526555 1324 total In 5.2.9 fstat() takes about 8% of total time. Previous Comments: ------------------------------------------------------------------------ [2009-09-01 18:27:31] rasmus@php.net You need to do proper profiling to determine that. Start by turning on all warning messages. If you are throwing warnings or notices, even if you are not displaying or logging them anywhere, it is going to slow you down and there are a bunch of new ones in 5.3. Set your error reporting to something like 16777215 (0xffffff) which will catch all current and future error levels and fix anything you see. Then check your performance again. ------------------------------------------------------------------------ [2009-09-01 18:13:05] olga at metacafe dot com When I compare 5.2.9 with 5.3, I see that (a) 5.3 is slower. According to release notes, I was expecting performance improvement, or at least the same performance as in previous version. (b) top 5 system calls in 5.3 take more time that in 5.2.9 lstat() calls are reduced, but fstat(), mmap() and munmap() are used much more than before. Maybe I'm wrong about fstat(), but that's the only difference I found so far. What else could have caused this performance problem? ------------------------------------------------------------------------ [2009-09-01 15:01:17] rasmus@php.net You suppose it is because of fstat? I seriously doubt that. fstat is really fast because it doesn't need to touch the disk at all. It simply grabs the stat struct from an already open file descriptor. If you can show me some profiling numbers where fstat is anywhere on the radar, I'll take a look, but I am highly suspicious that fstat would have anything to do with any performance issues. Disk-touching stats like lstat are the ones you need to worry about. ------------------------------------------------------------------------ [2009-09-01 14:48:03] olga at metacafe dot com Any PHP code does it. The code: <?php echo "Hello!"; ?> The strace: open("[path]/test.php", O_RDONLY) = 16 fstat(16, {st_mode=S_IFREG|0644, st_size=82, ...}) = 0 fstat(16, {st_mode=S_IFREG|0644, st_size=82, ...}) = 0 fstat(16, {st_mode=S_IFREG|0644, st_size=82, ...}) = 0 mmap(NULL, 82, PROT_READ, MAP_SHARED, 16, 0) = 0x2a9a8b4000 munmap(0x2a9a8b4000, 82) = 0 close(16) = 0 ------------------------------------------------------------------------ [2009-08-31 11:48:20] jani@php.net Thank you for this bug report. To properly diagnose the problem, we need a short but complete example script to be able to reproduce this bug ourselves. A proper reproducing script starts with <?php and ends with ?>, is max. 10-20 lines long and does not require any external resources such as databases, etc. If the script requires a database to demonstrate the issue, please make sure it creates all necessary tables, stored procedures etc. Please avoid embedding huge scripts into the report. ------------------------------------------------------------------------ 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/49383 -- Edit this bug report at http://bugs.php.net/?id=49383&edit=1