php.net |  support |  documentation |  report a bug |  advanced search |  search howto |  statistics |  random bug |  login
Bug #79412 Opcache chokes and uses 100% CPU on specific script
Submitted: 2020-03-25 05:51 UTC Modified: 2020-03-25 11:30 UTC
From: bugs at rudeirer dot wtf Assigned: dmitry (profile)
Status: Closed Package: opcache
PHP Version: 7.4.4 OS: Debian 10 (amd64)
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: bugs at rudeirer dot wtf
New email:
PHP Version: OS:

 

 [2020-03-25 05:51 UTC] 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);
}


Patches

Pull Requests

History

AllCommentsChangesGit/SVN commitsRelated reports
 [2020-03-25 08:08 UTC] sjon@php.net
-Status: Open +Status: Verified
 [2020-03-25 11:07 UTC] 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 11:30 UTC] nikic@php.net
-Assigned To: +Assigned To: dmitry
 [2020-03-25 11:30 UTC] 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 14:38 UTC] dmitry@php.net
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).
 [2020-03-25 14:38 UTC] dmitry@php.net
-Status: Verified +Status: Closed
 
PHP Copyright © 2001-2024 The PHP Group
All rights reserved.
Last updated: Thu Nov 21 12:01:29 2024 UTC