ID:               49383
 Updated by:       ras...@php.net
 Reported By:      olga at metacafe dot com
 Status:           Analyzed
 Bug Type:         Performance problem
 Operating System: Red Hat 3.4.6-10
 PHP Version:      5.3, 6
 New Comment:

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.



Previous Comments:
------------------------------------------------------------------------

[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 zend_execute_scripts ()
#11 0x0135be38 in php_execute_script ()

#1  0x0137642f in do_fstat ()
#2  0x01377189 in php_stdiop_set_option ()
#3  0x0136fc8e in _php_stream_set_option ()
#4  0x0137dcec in _php_stream_mmap_range ()
#5  0x0135a295 in php_stream_open_for_zend_ex ()
#6  0x0135a2e0 in php_stream_open_for_zend ()
#7  0x013ca05f in zend_stream_fixup ()
#8  0x01383ae7 in open_file_for_scanning ()
#9  0x01383c8d in compile_file ()
#10 0x011eb8f7 in phar_compile_file ()
#11 0x013b4fa7 in zend_execute_scripts ()
#12 0x0135be38 in php_execute_script ()

The do_fstat() function has a cache, but those 3 calls set the 'force'
flag to ignore the cached stat struct.  We need to track down whether it
is possible to not force these.  It seems like it should be possible to
get rid of at least one of those, if not 2.

But again, install an opcode cache, and this stops being a problem.

------------------------------------------------------------------------

[2009-09-03 12:59:44] olga at metacafe dot com

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.

------------------------------------------------------------------------

[2009-09-01 18:27:31] ras...@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?

------------------------------------------------------------------------

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

Reply via email to