[horde] need help debuging 100% cpu php processes
Michael Menge
michael.menge at zdv.uni-tuebingen.de
Thu Apr 14 09:49:00 UTC 2016
Hi,
I have a problem with our horde system.
We have the following setup: a ipvs Loadbalancer is distributing the
https requests to 2 webservers.
Connections from the same IP will land on the same webserver if the
next request ocures within 1800 sec.
We use redis as session stroage, and a postgresql 9.3 Database. Redis
and the Database are
on one additional server.
last week I updated Horde 5.2.9 -> 5.2.10 and the other Horde Packages
(e.g. Horde_ActiveSync 2.31.1 -> 2.31.8)
I also updated the other pear/pecl packages and the RHEL 7 system rpms.
Since then I see apache processes piling up taking 100% cpu time and
doing nothing.
As far as i can see, the system is working, our users can read/write
mails, use the
groupware. And even ActiveSync is working as far as I can tell.
But I have to kill the processes to keep the system from slowing down.
I see some errors in the Logs but am not sure if they are related, as
the pids in the logs
do not correspond to the pids of the 100%-cpu processes, and some of
the errors have been
there before the update:
HORDE PHP ERROR: Undefined offset: 2 [pid 23710 on line 983 of
"/usr/share/pear/Horde/Core/ActiveSync/Driver.php"]
HORDE PHP ERROR: Undefined index: lastsynckey [pid 21744 on line 302
of "/usr/share/pear/Horde/ActiveSync/Collections.php"]
HORDE PHP ERROR: Undefined index: truncation [pid 22238 on line 1366
of "/usr/share/pear/Horde/Core/ActiveSync/Driver.php"]
Calling strace on these processes shows nothing (no system call or
signals at all)
Debugging with gdb shows that most, but not all processes are running
function_name = "_endBuffer", filename =
"/usr/share/pear/Horde/Core/ActiveSync/Driver.php",
line_start = 3356, line_end = 3361,
Some are running
function_name = "collectionIsPingable", filename =
"/usr/share/pear/Horde/ActiveSync/SyncCache.php",
line_start = 325, line_end = 329,
First we did suspect that redis could be the problem, as the processes
had connections to redis
hanging in "CLOSE_WAIT". The Reids server did colse the connection
after 300 sec idle time.
Increasing this time out to much larger values, did not lead to less
hanging processes, but
to a lockup as maxclient would be reached and all redis connections
where blocked by the
hanging apache processes.
I am looking for some hints to narrow down this problem.
Thanks for your help in advance
Michael
-- Versions --------------------
php-5.4.16-36.el7_1.x86_64
httpd-2.4.6-40.el7.x86_64
Installed packages, channel pear.horde.org:
===========================================
Package Version State
Horde_ActiveSync 2.31.8 stable
Horde_Alarm 2.2.7 stable
Horde_Argv 2.0.12 stable
Horde_Auth 2.1.12 stable
Horde_Autoloader 2.1.2 stable
Horde_Autoloader_Cache 2.1.2 stable
Horde_Browser 2.0.12 stable
Horde_Cache 2.5.3 stable
Horde_Cli 2.0.6 stable
Horde_Compress 2.1.5 stable
Horde_Compress_Fast 1.1.1 stable
Horde_Constraint 2.0.3 stable
Horde_Controller 2.0.4 stable
Horde_Core 2.23.0 stable
Horde_Crypt 2.7.3 stable
Horde_Crypt_Blowfish 1.1.1 stable
Horde_CssMinify 1.0.2 stable
Horde_Css_Parser 1.0.9 stable
Horde_Data 2.1.4 stable
Horde_Date 2.3.0 stable
Horde_Date_Parser 2.0.5 stable
Horde_Dav 1.1.3 stable
Horde_Db 2.3.1 stable
Horde_Editor 2.0.4 stable
Horde_ElasticSearch 1.0.3 stable
Horde_Exception 2.0.8 stable
Horde_Feed 2.0.4 stable
Horde_Form 2.0.13 stable
Horde_Group 2.1.1 stable
Horde_HashTable 1.2.4 stable
Horde_History 2.3.6 stable
Horde_Http 2.1.6 stable
Horde_Icalendar 2.1.4 stable
Horde_Idna 1.0.4 stable
Horde_Image 2.3.5 stable
Horde_Imap_Client 2.29.6 stable
Horde_Imsp 2.0.9 stable
Horde_Injector 2.0.5 stable
Horde_Itip 2.1.2 stable
Horde_JavascriptMinify 1.1.3 stable
Horde_JavascriptMinify_Jsmin 1.0.2 stable
Horde_Kolab_Format 2.0.8 stable
Horde_Kolab_Server 2.0.5 stable
Horde_Kolab_Session 2.0.3 stable
Horde_Kolab_Storage 2.2.2 stable
Horde_Ldap 2.3.2 stable
Horde_ListHeaders 1.2.4 stable
Horde_Lock 2.1.2 stable
Horde_Log 2.2.0 stable
Horde_LoginTasks 2.0.7 stable
Horde_Mail 2.6.3 stable
Horde_Mail_Autoconfig 1.0.3 stable
Horde_Mapi 1.0.8 stable
Horde_Memcache 2.0.7 stable
Horde_Mime 2.9.4 stable
Horde_Mime_Viewer 2.1.3 stable
Horde_Mongo 1.0.3 stable
Horde_Nls 2.2.0 stable
Horde_Notification 2.0.4 stable
Horde_Oauth 2.0.3 stable
Horde_OpenXchange 1.0.0 stable
Horde_Pack 1.0.6 stable
Horde_Pdf 2.0.7 stable
Horde_Perms 2.1.7 stable
Horde_Prefs 2.7.6 stable
Horde_Queue 1.1.3 stable
Horde_Rdo 2.0.5 stable
Horde_Role 1.0.1 stable
Horde_Routes 2.0.5 stable
Horde_Rpc 2.1.7 stable
Horde_Scribe 2.0.2 stable
Horde_Secret 2.0.6 stable
Horde_Serialize 2.0.5 stable
Horde_Service_Facebook 2.0.9 stable
Horde_Service_Gravatar 1.0.1 stable
Horde_Service_Twitter 2.1.5 stable
Horde_Service_Weather 2.3.3 stable
Horde_SessionHandler 2.2.7 stable
Horde_Share 2.0.10 stable
Horde_Smtp 1.9.3 stable
Horde_Socket_Client 2.1.1 stable
Horde_SpellChecker 2.1.3 stable
Horde_Stream 1.6.3 stable
Horde_Stream_Filter 2.0.4 stable
Horde_Stream_Wrapper 2.1.3 stable
Horde_Support 2.1.5 stable
Horde_SyncMl 2.0.7 stable
Horde_Template 2.0.3 stable
Horde_Test 2.6.0 stable
Horde_Text_Diff 2.1.2 stable
Horde_Text_Filter 2.3.4 stable
Horde_Text_Filter_Jsmin 1.0.2 stable
Horde_Text_Flowed 2.0.3 stable
Horde_Thrift 2.0.2 stable
Horde_Timezone 1.0.11 stable
Horde_Token 2.0.9 stable
Horde_Translation 2.2.1 stable
Horde_Tree 2.0.4 stable
Horde_Url 2.2.5 stable
Horde_Util 2.5.7 stable
Horde_Vfs 2.3.2 stable
Horde_View 2.0.6 stable
Horde_Xml_Element 2.0.4 stable
Horde_Xml_Wbxml 2.0.3 stable
content 2.0.5 stable
horde 5.2.10 stable
horde_lz4 1.0.10 stable
imp 6.2.14 stable
ingo 3.2.10 stable
kronolith 4.2.16 stable
mnemo 4.2.10 stable
nag 4.2.9 stable
timeobjects 2.1.2 stable
turba 4.2.14 stable
Installed packages, channel pear.nrk.io:
========================================
Package Version State
Predis 1.0.3 stable
Installed packages, channel pear.php.net:
=========================================
Package Version State
Archive_Tar 1.4.2 stable
Auth_SASL 1.0.6 stable
Auth_SASL2 0.1.0 beta
Cache 1.5.6 stable
Console_Color2 0.1.2 alpha
Console_Getargs 1.3.5 stable
Console_Getopt 1.4.1 stable
Console_GetoptPlus 1.0.0RC1 beta
Console_Table 1.3.0 stable
DB 1.9.2 stable
Date 1.4.7 stable
Date_Holidays 0.21.8 alpha
Date_Holidays_Germany 0.1.2 alpha
File_Find 1.3.3 stable
File_Fstab 2.0.3 stable
HTTP_Request 1.4.4 stable
HTTP_Request2 2.3.0 stable
Image_Text 0.7.0 beta
MDB2 2.4.1 stable
Mail 1.3.0 stable
Mail_Mime 1.10.0 stable
Math_BigInteger 1.0.2 stable
Net_DIME 1.0.2 stable
Net_DNS2 1.4.1 stable
Net_FTP 1.4.0 stable
Net_IMAP 1.1.3 stable
Net_SMTP 1.7.1 stable
Net_Sieve 1.3.4 stable
Net_Socket 1.0.14 stable
Net_URL 1.0.15 stable
Net_URL2 2.2.0 stable
Numbers_Words 0.18.1 beta
PEAR 1.10.1 stable
SOAP 0.13.0 beta
Services_Weather 1.4.7 stable
Structures_Graph 1.1.1 stable
Text_CAPTCHA 1.0.2 stable
Text_Figlet 1.0.2 stable
Text_LanguageDetect 0.3.0 alpha
Text_Password 1.2.1 stable
XML_Parser 1.3.6 stable
XML_SVG 1.1.0 stable
XML_Serializer 0.20.2 beta
XML_Util 1.3.0 stable
Installed packages, channel pecl.php.net:
=========================================
Package Version State
APC 3.1.13 beta
LZF 1.6.5 stable
geoip 1.0.8 stable
igbinary 1.2.1 stable
imagick 3.1.2 stable
intl 3.0.0 stable
memcache 2.2.7 stable
mongo 1.5.8 stable
msgpack 0.5.7 beta
pam 1.0.3 stable
pecl_http 2.1.4 stable
propro 1.0.0 stable
raphf 1.1.0 stable
xdebug 2.4.0 stable
xdiff 1.4.1 stable
Installed packages, channel phpseclib.sourceforge.net:
======================================================
Package Version State
File_ASN1 1.0.1 stable
---------- gdb bt ------------------
(gdb) bt
#0 0x00007fbf911f4480 in __nanosleep_nocancel () at
../sysdeps/unix/syscall-template.S:81
#1 0x00007fbf911f4334 in __sleep (seconds=0) at
../sysdeps/unix/sysv/linux/sleep.c:137
#2 0x00007fbf83858d7a in zif_sleep (ht=<optimized out>,
return_value=0x7fbf9510c0c8, return_value_ptr=<optimized out>,
this_ptr=<optimized out>, return_value_used=<optimized out>)
at /usr/src/debug/php-5.4.16/ext/standard/basic_functions.c:4395
#3 0x00007fbf839c8f8c in zend_do_fcall_common_helper_SPEC
(execute_data=<optimized out>) at
/usr/src/debug/php-5.4.16/Zend/zend_vm_execute.h:643
#4 0x00007fbf83946077 in execute (op_array=0x7fbf95730f20) at
/usr/src/debug/php-5.4.16/Zend/zend_vm_execute.h:410
#5 0x00007fbf8391eccf in zend_execute_scripts (type=type at entry=8,
retval=retval at entry=0x0, file_count=file_count at entry=3) at
/usr/src/debug/php-5.4.16/Zend/zend.c:1315
#6 0x00007fbf838be6e6 in php_execute_script
(primary_file=primary_file at entry=0x7ffea44a45a0) at
/usr/src/debug/php-5.4.16/main/main.c:2494
#7 0x00007fbf839cac8d in php_handler (r=<optimized out>) at
/usr/src/debug/php-5.4.16/sapi/apache2handler/sapi_apache2.c:667
#8 0x00007fbf92c78240 in ap_run_handler (r=0x7fbf95754470) at config.c:169
#9 0x00007fbf92c78789 in ap_invoke_handler (r=r at entry=0x7fbf95754470)
at config.c:439
#10 0x00007fbf92c8cb0a in ap_process_async_request
(r=r at entry=0x7fbf95754470) at http_request.c:317
#11 0x00007fbf92c8cde4 in ap_process_request
(r=r at entry=0x7fbf95754470) at http_request.c:363
#12 0x00007fbf92c89772 in ap_process_http_sync_connection
(c=0x7fbf94e22fe0) at http_core.c:190
#13 ap_process_http_connection (c=0x7fbf94e22fe0) at http_core.c:231
#14 0x00007fbf92c81810 in ap_run_process_connection (c=0x7fbf94e22fe0)
at connection.c:41
#15 0x00007fbf92c81bf8 in ap_process_connection
(c=c at entry=0x7fbf94e22fe0, csd=<optimized out>) at connection.c:202
#16 0x00007fbf8865380f in child_main
(child_num_arg=child_num_arg at entry=84) at prefork.c:707
#17 0x00007fbf88653a55 in make_child (s=0x7fbf949543c0, slot=84) at
prefork.c:810
#18 0x00007fbf886546ee in perform_idle_server_maintenance
(p=<optimized out>) at prefork.c:912
#19 prefork_run (_pconf=<optimized out>, plog=<optimized out>,
s=<optimized out>) at prefork.c:1100
#20 0x00007fbf92c5e5ae in ap_run_mpm (pconf=0x7fbf94923158,
plog=0x7fbf94950378, s=0x7fbf949543c0) at mpm_common.c:96
#21 0x00007fbf92c57b36 in main (argc=2, argv=0x7ffea44a4cb8) at main.c:777
f 4
#4 0x00007fbf83946077 in execute (op_array=0x7fbf95730f20) at
/usr/src/debug/php-5.4.16/Zend/zend_vm_execute.h:410
410 if ((ret = OPLINE->handler(execute_data TSRMLS_CC)) > 0) {
(gdb) print *op_array
$1 = {type = 2 '\002', function_name = 0x7fbf5c2ee348 "_endBuffer",
scope = 0x7fbf9571ff88, fn_flags = 134283776, prototype = 0x0,
num_args = 0, required_num_args = 0, arg_info = 0x0,
refcount = 0x7fbf95731020, opcodes = 0x7fbf5c2ee4b0, last = 10,
vars = 0x7fbf5c2ee690, last_var = 1, T = 6, brk_cont_array = 0x0,
last_brk_cont = 0, try_catch_array = 0x0,
last_try_catch = 0, static_variables = 0x0, this_var = 4294967295,
filename = 0x7fbf5c2ee358
"/usr/share/pear/Horde/Core/ActiveSync/Driver.php", line_start = 3356,
line_end = 3361,
doc_comment = 0x7fbf5c2ee6a8 "/**\n * End output buffering, log
any unexpected output.\n *\n */", doc_comment_len = 74,
early_binding = 4294967295, literals = 0x7fbf5c2ee398,
last_literal = 7, run_time_cache = 0x7fbf94ebddf8, last_cache_slot
= 5, reserved = {0x1, 0x0, 0x0, 0x0}}
----------------------------------------
--------------------------------------------------------------------------------
M.Menge Tel.: (49) 7071/29-70316
Universität Tübingen Fax.: (49) 7071/29-5912
Zentrum für Datenverarbeitung mail:
michael.menge at zdv.uni-tuebingen.de
Wächterstraße 76
72074 Tübingen
More information about the horde
mailing list