Bug #75488 [Opn]: Under heavy load PHP misses Opcache hits with no errors

Edit report at https://bugs.php.net/bug.php?id=75488&edit=1 ID: 75488 User updated by: david at davidfavor dot com Reported by: david at davidfavor dot com Summary: Under heavy load PHP misses Opcache hits with no errors Status: Open Type: Bug Package: opcache Operating System: Ubuntu Zesty PHP Version: 7.2.1 Block user comment: N Private report: N New Comment: This is a huge problem for high traffic sites using PHP for dynamic content generation. Be great if someone knowledgable about Opcache could take a look at this + determine a fix or work around. Thanks. Previous Comments: ------------------------------------------------------------------------ [2018-01-15 16:05:12] david at davidfavor dot com Bumping version to 7.2.1 as problem still exits. ------------------------------------------------------------------------ [2017-12-06 18:18:05] david at davidfavor dot com IP has changed to 144.217.34.13 for PHP-7.2 container. ------------------------------------------------------------------------ [2017-12-06 18:14:25] david at davidfavor dot com Bumping version from 7.1.12 to 7.2.0 as problem persists. lxd: net11-ubuntu-zesty-php72 # php --version PHP 7.2.0-1+ubuntu17.04.1+deb.sury.org+1 (cli) (built: Nov 30 2017 13:59:08) ( NTS ) Copyright (c) 1997-2017 The PHP Group Zend Engine v3.2.0, Copyright (c) 1998-2017 Zend Technologies with Zend OPcache v7.2.0-1+ubuntu17.04.1+deb.sury.org+1, Copyright (c) 1999-2017, by Zend Technologies ------------------------------------------------------------------------ [2017-11-29 15:34:49] david at davidfavor dot com I've bumped version from 7.11 to 7.12, as problem persists. lxd: net11-david-favor # php --version PHP 7.1.12-1+ubuntu17.04.1+deb.sury.org+1 (cli) (built: Nov 29 2017 10:04:01) ( NTS ) Copyright (c) 1997-2017 The PHP Group Zend Engine v3.1.0, Copyright (c) 1998-2017 Zend Technologies with Zend OPcache v7.1.12-1+ubuntu17.04.1+deb.sury.org+1, Copyright (c) 1999-2017, by Zend Technologies with Xdebug v2.5.5, Copyright (c) 2002-2017, by Derick Rethans ------------------------------------------------------------------------ [2017-11-11 16:39:00] david at davidfavor dot com Steps to reproduce. Config settings + opcache data links... http://144.217.34.1/wptools/phpinfo.php http://144.217.34.1/wptools/ocp-0.2.0.php 1) set opcache.ini values to never revalidate #opcache.revalidate_freq=0 #opcache.validate_timestamps=0 #opcache.enable_file_override=0 lxd: net11-david-favor # service php7.1-fpm restart lxd: net11-david-favor # truncate -s 0 /var/log/php7.1-fpm/access.log 2) Initiate a simple load test... lxd: net11-david-favor # h2load -ph2c -t16 -c16 -m16 -n200000 https://net11.heartbeat.davidfavor.com/hello.php ... ... ... finished in 11.29s, 17719.92 req/s, 2.06MB/s requests: 200000 total, 200000 started, 200000 done, 200000 succeeded, 0 failed, 0 errored, 0 timeout status codes: 200000 2xx, 0 3xx, 0 4xx, 0 5xx This works as expected. 200000 started. 200000 successes. 0 failures. 3) Count log entries... lxd: net11-david-favor # egrep -e hello.php /var/log/php7.1-fpm/access.log | wc -l 200000 4) Count log entries != 0.00%, so this could shows non-cached PHP executions. This count should be 1, as the .php file should run once + then be cached + come out of cache forever, since revalidate is off. lxd: net11-david-favor # egrep -e hello.php /var/log/php7.1-fpm/access.log | egrep -v -e " 0.00%" | wc -l 5098 5) Now check opcache data... Opcache shows 2 misses + 195K hits, which is wrong. Should be 5098 misses + 194K hits. This problem is reproducible 100% of the time. 6) After thought. Now 3% breakage on 200K requests might seem inconsequential. The problem occurs on high traffic sites, so say 100+ WordPress post slugs with sustained traffic of 50K-100K/second visits. These are the numbers on the client site I host which surfaced the problem. When this breakage begins on various page requests, which involve man .php files, the entire site begins to circle the drain quickly. Here's an example of why. Consider these crazy numbers from a random snippet of FPM log entries. 1) hello.php 5.863 2048 170.56% 2) hello.php 1.468 2048 681.20% 3) hello.php 1.695 2048 589.97% 4) hello.php 0.217 2048 4608.29% 5) hello.php 0.228 2048 4385.96% 6) hello.php 0.148 2048 0.00% These entries show milliseconds to execute + memory usage + CPU usage. Item #1 - Seriously bad 5.8 seconds to finish, with low CPU usage. This means an FPM thread is tied up for 5.8 seconds, so site death will surely occur, with high traffic. Item #4 + #5 - FPM threads finish quickly + they hammer the CPU. Item #6 - What should occur with every request. Fast execution time + 0.00% CPU usage, as the only operation should be an opcache lookup + data return. 7) WordPress workaround. In WordPress the work around is to use a caching plugin which utilizes mod_rewrite correctly. Currently WP Super Cache is broken, so files are returned by Apache from file cache, then the original request leaks through to PHP, so site dies because of this bug. WP Fastest Cache does fix this problem, because files are returned by Apache from file cache + them short circuited/stopped, so request terminates without hitting PHP. High traffic PHP sites must work around this bug to survive right now, which requires a good bit of expertise to resolve for non-WordPress sites, which have no simple mod_rewrite caching options. I'm happy to provide any developer with root ssh access to the LXD container where this bug can be worked + fixed. ------------------------------------------------------------------------ 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 https://bugs.php.net/bug.php?id=75488 -- Edit this bug report at https://bugs.php.net/bug.php?id=75488&edit=1