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
View Developer Edit
Welcome! If you don't have a Git account, you can't do anything here.
If you reported this bug, you can edit this bug over here.
(description)
Block user comment
Status: Assign to:
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: Tue Dec 03 17:01:29 2024 UTC