[Tickets #11041] PHP process hangs drawing 100% CPU until killed

Wed Feb 29 10:38:19 UTC 2012

DO NOT REPLY TO THIS MESSAGE. THIS EMAIL ADDRESS IS NOT MONITORED.

Ticket URL: http://bugs.horde.org/ticket/11041
------------------------------------------------------------------------------
  Ticket             | 11041
  Created By         | pop3 at flachtaucher.de
  Summary            | PHP process hangs drawing 100% CPU until killed
  Queue              | IMP
  Version            | 5.0.18
  Type               | Bug
  State              | Unconfirmed
  Priority           | 2. Medium
  Milestone          |
  Patch              |
  Owners             |
------------------------------------------------------------------------------

pop3 at flachtaucher.de (2012-02-29 10:38) wrote:

Helo,

since upgrading to IMP 5.X we experience the following issue:

Sporadically one PHP process draws 100% CPU until it reaches  
max_execution_time. This happens > 10 times per day on a busy System  
serving >100k e-mail-accounts. php errorlog shows that the script  
reaches max_execution time while it is in different parts of  
imp/lib/Imap/Tree.php like this:

[27-Feb-2012 10:59:07] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1709

You can find more lines from the errorlog below.

strace on the process that draws 100% CPU does not show anything so  
not syscalls are executed.

Environment: PHP5.3.10, APC. (We got the same behaviour with 5.2.X and  
eaccelerator)

To further diagnose this issue we ran the attached patch  
("diagnose_patch.diff")

This will alert us if a certain loop in Tree.php gets executed 1.000  
times and save print_r of debug_backtrace to a file. We have verified  
at least one instance where this code gets triggered for a process  
that suffers from the 100% CPU problem and gets killed after reaching  
max_execution_time. You can find the output for this process in  
"daignose_output.txt".

As far as we can tell there seems to be loop in the code of Tree.php,  
specifically in getPollList: The foreach does not ever seem to exit in  
our case.

Unfortunately we do not know how to continue in solving this problem.  
Can you please point us into the right direction? We are willing to  
run more diagnostic code to further narrow down the root cause of this  
elusive problem.

Some output from php errorlog:

[27-Feb-2012 10:42:04] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 829
[27-Feb-2012 10:43:13] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1708
[27-Feb-2012 10:44:19] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/framework/Prefs/lib/Horde/Prefs.php on  
line 317
[27-Feb-2012 10:44:41] PHP Fatal error:  Call to a member function  
getName() on a non-object in horde-git/imp/lib/Ajax/Application.php on  
line 1349
[27-Feb-2012 10:44:52] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1827
[27-Feb-2012 10:45:11] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1827
[27-Feb-2012 10:45:52] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1676
[27-Feb-2012 10:45:54] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1827
[27-Feb-2012 10:45:59] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1279
[27-Feb-2012 10:46:00] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1709
[27-Feb-2012 10:46:04] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1277
[27-Feb-2012 10:46:07] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1709
[27-Feb-2012 10:46:07] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1709
[27-Feb-2012 10:46:15] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in  
horde-git/framework/Prefs/lib/Horde/Prefs/Scope.php on line 138
[27-Feb-2012 10:46:16] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1277
[27-Feb-2012 10:51:09] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1277
[27-Feb-2012 10:51:11] PHP Fatal error:  Call to a member function  
getName() on a non-object in horde-git/imp/lib/Ajax/Application.php on  
line 1349
[27-Feb-2012 10:54:41] PHP Fatal error:  Call to a member function  
getName() on a non-object in horde-git/imp/lib/Ajax/Application.php on  
line 1349
[27-Feb-2012 10:57:34] PHP Fatal error:  Call to a member function  
getName() on a non-object in horde-git/imp/lib/Ajax/Application.php on  
line 1349
[27-Feb-2012 10:58:45] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1827
[27-Feb-2012 10:58:50] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1826
[27-Feb-2012 10:59:07] PHP Fatal error:  Maximum execution time of 300  
seconds exceeded in horde-git/imp/lib/Imap/Tree.php on line 1709

pop3 at flachtaucher.de (2012-02-29 10:38) uploaded: diagnose_patch.diff

http://bugs.horde.org/h/services/download/?module=whups&actionID=download_file&file=diagnose_patch.diff&ticket=11041&fn=%2Fdiagnose_patch.diff