Bug #74709 [NEW]: PHP-FPM process eating 100% CPU attempting to use kill_all_lockers

From: Date: Thu, 08 Jun 2017 08:33:33 +0000
Subject: Bug #74709 [NEW]: PHP-FPM process eating 100% CPU attempting to use kill_all_lockers
Groups: php.bugs 
Request: Send a blank email to php-bugs+get-209415@lists.php.net to get a copy of this message
From:             devel at jasonwoods dot me dot uk
Operating system: CentOS 6
PHP version:      5.6.30
Package:          FPM related
Bug Type:         Bug
Bug description:PHP-FPM process eating 100% CPU attempting to use kill_all_lockers

Description:
------------
I had a spinning process eating 100% CPU on a server this morning.
Attaching strace it was stuck in an infinite loop with the following:

kill(2260, SIGKILL)                     = -1 EPERM (Operation not
permitted)
fcntl(3, F_GETLK, {type=F_RDLCK, whence=SEEK_SET, start=1, len=1,
pid=2260}) = 0

The process it was attempting to kill was a member of a different FPM
pool, and was running under a different user, thus the EPERM.

Stack trace of the spinning process when attaching gdb was:

#0  0x00007f33ebaf9777 in kill () from /lib64/libc.so.6
#1  0x00007f33e4b9f4a2 in kill_all_lockers () at
/usr/src/debug/php-5.6.30/ext/opcache/ZendAccelerator.c:606
#2  accel_is_inactive () at
/usr/src/debug/php-5.6.30/ext/opcache/ZendAccelerator.c:661
#3  accel_activate () at
/usr/src/debug/php-5.6.30/ext/opcache/ZendAccelerator.c:2192
#4  0x00000000005d80ee in zend_llist_apply (l=<value optimized out>,
func=0x5d4290 <zend_extension_activator>) at
/usr/src/debug/php-5.6.30/Zend/zend_llist.c:191
#5  0x00000000005d5eba in init_executor () at
/usr/src/debug/php-5.6.30/Zend/zend_execute_API.c:161
#6  0x00000000005e4ae3 in zend_activate () at
/usr/src/debug/php-5.6.30/Zend/zend.c:936
#7  0x0000000000582652 in php_request_startup () at
/usr/src/debug/php-5.6.30/main/main.c:1647
#8  0x0000000000693f2d in main (argc=<value optimized out>, argv=<value
optimized out>) at
/usr/src/debug/php-5.6.30/sapi/fpm/fpm/fpm_main.c:1927

My hypothesis based on limited reading of how this works is that it
seems that a process in some pool held an opcache lock for too long and
then another process in another pool attempted to perform an "opcache
restart" of sorts, but was unable to complete it as it kept failing to
kill a process in another pool for which it has no access. There is no
backoff and no "failure" case and so it starts spinning.

Meanwhile, while this was happening, no processes in the same pool as
the hung process were responding to requests. The other pools were
responding successfully. Restarting the php-fpm completely recovered the
environment.

Expected result:
----------------
No spinning process.

Should the php-fpm coordinator/parent process not handling the opcache
restart? Or maybe each pool should be using a different opcache lock so
they never conflict?

Actual result:
--------------
Spinning process eating 100% CPU.

-- 
Edit bug report at https://bugs.php.net/bug.php?id=74709&edit=1
-- 
Try a snapshot (PHP 5.4):   https://bugs.php.net/fix.php?id=74709&r=trysnapshot54
Try a snapshot (PHP 5.5):   https://bugs.php.net/fix.php?id=74709&r=trysnapshot55
Try a snapshot (trunk):     https://bugs.php.net/fix.php?id=74709&r=trysnapshottrunk
Fixed in SVN:               https://bugs.php.net/fix.php?id=74709&r=fixed
Fixed in release:           https://bugs.php.net/fix.php?id=74709&r=alreadyfixed
Need backtrace:             https://bugs.php.net/fix.php?id=74709&r=needtrace
Need Reproduce Script:      https://bugs.php.net/fix.php?id=74709&r=needscript
Try newer version:          https://bugs.php.net/fix.php?id=74709&r=oldversion
Not developer issue:        https://bugs.php.net/fix.php?id=74709&r=support
Expected behavior:          https://bugs.php.net/fix.php?id=74709&r=notwrong
Not enough info:            https://bugs.php.net/fix.php?id=74709&r=notenoughinfo
Submitted twice:            https://bugs.php.net/fix.php?id=74709&r=submittedtwice
register_globals:           https://bugs.php.net/fix.php?id=74709&r=globals
PHP 4 support discontinued: https://bugs.php.net/fix.php?id=74709&r=php4
Daylight Savings:           https://bugs.php.net/fix.php?id=74709&r=dst
IIS Stability:              https://bugs.php.net/fix.php?id=74709&r=isapi
Install GNU Sed:            https://bugs.php.net/fix.php?id=74709&r=gnused
Floating point limitations: https://bugs.php.net/fix.php?id=74709&r=float
No Zend Extensions:         https://bugs.php.net/fix.php?id=74709&r=nozend
MySQL Configuration Error:  https://bugs.php.net/fix.php?id=74709&r=mysqlcfg



Thread (10 messages)

« previous php.bugs (#209415) next »