Bug #79412 [Ver->Csd]: Opcache chokes and uses 100% CPU on specific script
Edit report at https://bugs.php.net/bug.php?id=79412&edit=1
ID: 79412
Updated by: dmitry@php.net
Reported by: bugs at rudeirer dot wtf
Summary: Opcache chokes and uses 100% CPU on specific script
-Status: Verified
+Status: Closed
Type: Bug
Package: opcache
Operating System: Debian 10 (amd64)
PHP Version: 7.4.4
Assigned To: dmitry
Block user comment: N
Private report: N
New Comment:
Automatic comment on behalf of dmitry@zend.com
Revision: http://git.php.net/?p=php-src.git;a=commit;h=65120cfc0969fe9ebd3d4d659b610a54a35ae026
Log: Fixed bug #79412 (Opcache chokes and uses 100% CPU on specific script).
Previous Comments:
------------------------------------------------------------------------
[2020-03-25 11:30:33] nikic@php.net
@dmitry: You might want to take a look at this, I don't understand the details of the range
inference algorithm well.
I think the basic issues is that
#15.CV3($count) = Pi<BB4>(#21.CV3($count) & RANGE[-- .. #17.CV0($limitPerRun) -
1])
narrows the range when $limitPerRun is 10, but later gets expanded to the full range, at which point
we're doing to start incrementing the range one by one (because we're using a narrowing
meet at this point).
But I can't really tell what the root problem here is.
------------------------------------------------------------------------
[2020-03-25 11:07:51] nikic@php.net
Debug log:
change range (init SCC 0) 5 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 1) 4 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 2) 14 [-- -9223372036854775808..9223372036854775807 ++]
change range (warmup 0 SCC 3) 11 [-- -9223372036854775808..9223372036854775807 ++]
change range (warmup 0 SCC 3) 19 [-- -9223372036854775808..9223372036854775807 ++]
change range (warmup 0 SCC 3) 25 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 3) 20 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 4) 3 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 5) 2 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 6) 1 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 7) 7 [-- -9223372036854775808..9223372036854775807 ++]
change range (warmup 0 SCC 8) 9 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 8) 12 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 9) 0 [-- -9223372036854775808..9223372036854775807 ++]
change range (init SCC 10) 6 [10..10]
change range (warmup 0 SCC 11) 8 [10..10]
change range (warmup 0 SCC 11) 10 [-- -9223372036854775808..9223372036854775807 ++]
change range (warmup 0 SCC 11) 13 [0..0]
change range (warmup 0 SCC 11) 17 [10..10]
change range (warmup 0 SCC 11) 23 [10..10]
change range (warmup 0 SCC 11) 16 [10..10]
change range (warmup 0 SCC 11) 18 [0..0]
change range (warmup 0 SCC 11) 24 [0..0]
change range (warmup 0 SCC 11) 21 [1..1]
change range (warmup 0 SCC 11) 15 [1..1]
change range (widening SCC 11) 18 [0..9223372036854775807 ++]
change range (widening SCC 11) 21 [1..9223372036854775807 ++]
change range (widening SCC 11) 24 [0..9223372036854775807 ++]
change range (widening SCC 11) 15 [1..9223372036854775807 ++]
change range (init SCC 11) 26 [-- -9223372036854775808..9223372036854775807 ++]
change range (narrowing SCC 11) 8 [-- -9223372036854775808..9223372036854775807 ++]
change range (narrowing SCC 11) 15 [1..9]
change range (narrowing SCC 11) 17 [-- -9223372036854775808..9223372036854775807 ++]
change range (narrowing SCC 11) 18 [0..9]
change range (narrowing SCC 11) 21 [1..10]
change range (narrowing SCC 11) 23 [-- -9223372036854775808..9223372036854775807 ++]
change range (narrowing SCC 11) 24 [0..10]
change range (narrowing SCC 11) 15 [1..10]
change range (narrowing SCC 11) 16 [2..9223372036854775807 ++]
change range (narrowing SCC 11) 18 [0..10]
change range (narrowing SCC 11) 21 [1..11]
change range (narrowing SCC 11) 24 [0..11]
change range (narrowing SCC 11) 15 [1..11]
change range (narrowing SCC 11) 18 [0..11]
change range (narrowing SCC 11) 21 [1..12]
change range (narrowing SCC 11) 24 [0..12]
change range (narrowing SCC 11) 15 [1..12]
change range (narrowing SCC 11) 18 [0..12]
change range (narrowing SCC 11) 21 [1..13]
change range (narrowing SCC 11) 24 [0..13]
change range (narrowing SCC 11) 15 [1..13]
change range (narrowing SCC 11) 18 [0..13]
change range (narrowing SCC 11) 21 [1..14]
change range (narrowing SCC 11) 24 [0..14]
change range (narrowing SCC 11) 15 [1..14]
change range (narrowing SCC 11) 18 [0..14]
...
------------------------------------------------------------------------
[2020-03-25 05:51:13] bugs at rudeirer dot wtf
Description:
------------
I observed several non-responding FPM worker processes using 100% CPU. Attaching gdb and printing a
stack trace indicated that the issue might be with opcache. In /proc/PID/fd, it could be seen that
all affected processes had opened a specific file. Disabling opcache or blacklisting the file worked
around the problem.
By trial and error, I removed lines from the problematic file in order to produce a short test
script. The code is not runnable any more, but it's small and still causes the problem. (In the
original code, all referenced variables were properly defined.)
I originally encountered this problem while using PHP 7.3.14 as supplied by Debian, so I believe 7.3
is also affected. For testing, I downloaded and compiled PHP 7.4.4 in a clean Debian 10 chroot. The
configure line was "./configure --enable-debug --prefix=/opt/php/7.4.4". No changes were
made to php.ini or any other file. Saving the test script as "bug.php" and running it with
"php -d zend_extension=opcache.so -d opcache.enable_cli=1 bug.php" exhibits the
problematic behavior.
This is a stack trace obtained after letting php run the test script for a few seconds:
#0 0x00007f3c0717639b in zend_infer_ranges (op_array=0x7f3c07277008, ssa=0x7f3c07286028) at
/home/build/php-7.4.4/ext/opcache/Optimizer/zend_inference.c:1815
#1 0x00007f3c0719268d in zend_ssa_inference (arena=0x7ffc6c37df10, op_array=0x7f3c07277008,
script=0x7f3c07277000, ssa=0x7f3c07286028, optimization_level=2147401727) at
/home/build/php-7.4.4/ext/opcache/Optimizer/zend_inference.c:4330
#2 0x00007f3c0715ee7a in zend_dfa_analyze_op_array (op_array=0x7f3c07277008, ctx=0x7ffc6c37df10,
ssa=0x7f3c07286028) at /home/build/php-7.4.4/ext/opcache/Optimizer/dfa_pass.c:113
#3 0x00007f3c07142fdb in zend_optimize_script (script=0x7f3c07277000,
optimization_level=2147401727, debug_level=0) at
/home/build/php-7.4.4/ext/opcache/Optimizer/zend_optimizer.c:1382
#4 0x00007f3c071113f8 in cache_script_in_shared_memory (new_persistent_script=0x7f3c07277000,
key=0x7f3c071d6da4 <accel_globals+484> "bug.php:2274224:2220784", key_length=23,
from_shared_memory=0x7ffc6c37e220) at /home/build/php-7.4.4/ext/opcache/ZendAccelerator.c:1451
#5 0x00007f3c071132da in persistent_compile_file (file_handle=0x7ffc6c381810, type=8) at
/home/build/php-7.4.4/ext/opcache/ZendAccelerator.c:2136
#6 0x0000563a74674bf5 in zend_execute_scripts (type=8, retval=0x0, file_count=3) at
/home/build/php-7.4.4/Zend/zend.c:1659
#7 0x0000563a745dd9dd in php_execute_script (primary_file=0x7ffc6c381810) at
/home/build/php-7.4.4/main/main.c:2617
#8 0x0000563a7474a481 in do_cli (argc=6, argv=0x563a767e78c0) at
/home/build/php-7.4.4/sapi/cli/php_cli.c:961
#9 0x0000563a7474b451 in main (argc=6, argv=0x563a767e78c0) at
/home/build/php-7.4.4/sapi/cli/php_cli.c:1356
Test script:
---------------
<?php
$limitPerRun = 10;
foreach ($foo as $bar)
{
$count = 0;
foreach ($runs as $run)
{
++$count;
if ($count >= $limitPerRun)
{
break;
}
}
foo($limitPerRun);
}
------------------------------------------------------------------------
--
Edit this bug report at https://bugs.php.net/bug.php?id=79412&edit=1
Thread (5 messages)