[horde] need help debuging 100% cpu php processes
Andy Dorman
adorman at ironicdesign.com
Thu Apr 14 13:03:16 UTC 2016
On 04/14/2016 04:49 AM, Michael Menge wrote:
> 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
>
Probably a silly question...but do you restart your PHP processes when
you restart apache?
We had a similar issue a couple of weeks ago and it took me an hour to
realize apache and php-fpm were having a very odd problem communicating
with each other (usually apache presents a very obvious error when it
can't communicate with php). I restarted both php and apache and things
went back to normal.
--
Andy Dorman
More information about the horde
mailing list