[horde] Maximum execution time of 29 seconds exceeded

Michael J Rubinsky mrubinsk at horde.org
Thu Aug 13 14:28:05 UTC 2015


Quoting Gian Franco Bagdadi Barcellini <gian at unicamp.br>:

> Hi,
>
> I am having problems with timeout execution of apache/PHP process  
> and cpu load rises high values (loop?)
> Process HTTP do not timeout, only php ($conf['max_exec_time'] = 29;);


This is too low for ActiveSync use. You need it to be AT LEAST as long  
as the maximum heartbeat interval any of your clients might use. The  
maximum for ActiveSync is something like 59 minutes. Though this is a  
separate issue to the high CPU load.



> Currently we have a base with approximately of 100 users activesync
>
> My versions and softwares are:
>
>   Horde Groupware 5.2.10
>   Horde_ActiveSync 2.28.6
>
>   Apache 2.2.29 with mod_php
>   PHP-5.6.10
>   MySQL 5.6.20
>
> We have proxies with this configuration:
>
> # conexoes Mobile ActiveSync Microsoft
> ProxyPass         /Microsoft-Server-ActiveSync  
> https://xxxx.yyyy.br/Microsoft-Server-ActiveSync  
> connectiontimeout=600 timeout=4000
> ProxyPassReverse  /Microsoft-Server-ActiveSync  
> https://xxxx.yyyy.br/Microsoft-Server-ActiveSync
>
> and ActiveSYnc:
>
> $conf['activesync']['params']['driverconfig'] = 'horde';
> $conf['activesync']['storage'] = 'Sql';
> $conf['activesync']['emailsync'] = true;
> $conf['activesync']['version'] = '14.1';
> $conf['activesync']['auth']['type'] = 'basic';
> $conf['activesync']['autodiscovery'] = 'user';
> $conf['activesync']['outlookdiscovery'] = false;
> $conf['activesync']['logging']['type'] = false;
> $conf['activesync']['ping']['heartbeatmin'] = 60;
> $conf['activesync']['ping']['heartbeatmax'] = 2700;

This line is setting the maximum heartbeat to 2700 seconds == 45  
minutes. You should have your max_execution be AT LEAST this long,  
preferably a bit longer since it's possible for the actual connection  
to need longer if changes are found at the very end of the heartbeat.

> $conf['activesync']['ping']['heartbeatdefault'] = 480;
> $conf['activesync']['ping']['deviceping'] = true;
> $conf['activesync']['ping']['waitinterval'] = 15;
> $conf['activesync']['enabled'] = true;
>
>
> I'm getting this errors quite often from log horde, in debug mode:
>
> ...
>
> 2015-08-11T16:39:45-03:00 NOTICE: HORDE PHP ERROR: Only variable  
> references should be returned by reference [pid 26763 on line 111 of  
> "/usr/local/lib/php/Horde/ActiveSy        nc/Imap/Message.php"]
>   26725 2015-08-11T16:39:45-03:00 DEBUG: HORDE  1.  
> Horde_Rpc_ActiveSync->getResponse()  
> /www/httpd-2.2.29/htdocs/horde-5.2.10/rpc.php:160
>   26726  2. Horde_ActiveSync->handleRequest()  
> /usr/local/lib/php/Horde/Rpc/ActiveSync.php:143
>   26727  3. Horde_ActiveSync_Request_Base->handle()  
> /usr/local/lib/php/Horde/ActiveSync.php:803
>   26728  4. Horde_ActiveSync_Request_Sync->_handle()  
> /usr/local/lib/php/Horde/ActiveSync/Request/Base.php:253
>   26729  5. Horde_ActiveSync_Connector_Exporter->sendNextChange()  
> /usr/local/lib/php/Horde/ActiveSync/Request/Sync.php:508
>   26730  6. Horde_ActiveSync_Connector_Exporter->_sendNextChange()  
> /usr/local/lib/php/Horde/ActiveSync/Connector/Exporter.php:156
>   26731  7. Horde_Core_ActiveSync_Driver->getMessage()  
> /usr/local/lib/php/Horde/ActiveSync/Connector/Exporter.php:205
>   26732  8. Horde_ActiveSync_Imap_Adapter->getMessages()  
> /usr/local/lib/php/Horde/Core/ActiveSync/Driver.php:1352
>   26733  9. Horde_ActiveSync_Imap_Adapter->_buildMailMessage()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Adapter.php:653
>   26734 10. Horde_ActiveSync_Imap_Message->getAttachmentsMimeParts()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Adapter.php:1153
>   26735 11. Horde_ActiveSync_Imap_Message->getMimePart()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Message.php:398
>   26736 12. Horde_ActiveSync_Imap_Message->getBodyPart()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Message.php:457
>   26737 13. Horde_ActiveSync_Imap_Message->__get()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Message.php:583
>   26738 14. Horde_ErrorHandler::errorHandler()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Message.php:111


This is harmless and has already been fixed in Git.


> ...
>
> 2015-08-11T16:40:25-03:00 NOTICE: HORDE PHP ERROR: Undefined offset:  
> 124981 [pid 26763 on line 1078 of  
> "/usr/local/lib/php/Math/BigInteger.php"]
> 2592237 2015-08-11T16:40:25-03:00 DEBUG: HORDE  1.  
> Horde_Rpc_ActiveSync->getResponse()  
> /www/httpd-2.2.29/htdocs/horde-5.2.10/rpc.php:160
> 2592238  2. Horde_ActiveSync->handleRequest()  
> /usr/local/lib/php/Horde/Rpc/ActiveSync.php:143
> 2592239  3. Horde_ActiveSync_Request_Base->handle()  
> /usr/local/lib/php/Horde/ActiveSync.php:803
> 2592240  4. Horde_ActiveSync_Request_Sync->_handle()  
> /usr/local/lib/php/Horde/ActiveSync/Request/Base.php:253
> 2592241  5. Horde_ActiveSync_Connector_Exporter->sendNextChange()  
> /usr/local/lib/php/Horde/ActiveSync/Request/Sync.php:508
> 2592242  6. Horde_ActiveSync_Connector_Exporter->_sendNextChange()  
> /usr/local/lib/php/Horde/ActiveSync/Connector/Exporter.php:156
> 2592243  7. Horde_Core_ActiveSync_Driver->getMessage()  
> /usr/local/lib/php/Horde/ActiveSync/Connector/Exporter.php:205
> 2592244  8. Horde_ActiveSync_Imap_Adapter->getMessages()  
> /usr/local/lib/php/Horde/Core/ActiveSync/Driver.php:1352
> 2592245  9. Horde_ActiveSync_Imap_Adapter->_buildMailMessage()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Adapter.php:653
> 2592246 10. Horde_ActiveSync_Imap_Message->getAttachmentsMimeParts()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Adapter.php:1153
> 2592247 11. Horde_ActiveSync_Imap_Message->_decodeTnefData()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Message.php:412
> 2592248 12. Horde_Compress_Tnef->decompress()  
> /usr/local/lib/php/Horde/ActiveSync/Imap/Message.php:361
> 2592249 13. Horde_Compress_Tnef->_decodeMessageProperty()  
> /usr/local/lib/php/Horde/Compress/Tnef.php:285
> 2592250 14. Horde_Mapi::filetimeToUnixtime()  
> /usr/local/lib/php/Horde/Compress/Tnef.php:663
> 2592251 15. Horde_Mapi::_win64ToUnix() /usr/local/lib/php/Horde/Mapi.php:145
> 2592252 16. Math_BigInteger->subtract() /usr/local/lib/php/Horde/Mapi.php:193
> 2592253 17. Math_BigInteger->_subtract()  
> /usr/local/lib/php/Math/BigInteger.php:991
> 2592254 18. Horde_ErrorHandler::errorHandler()  
> /usr/local/lib/php/Math/BigInteger.php:1078
> 2592255
> 2592256 2015-08-11T16:40:25-03:00 NOTICE: HORDE PHP ERROR: Undefined  
> offset: 124982 [pid 26763 on line 1078 of  
> "/usr/local/lib/php/Math/BigInteger.php"]
> 2592257 2015-08-11T16:40:25-03:00 EMERG: HORDE Maximum execution  
> time of 29 seconds exceeded [pid 26763 on line 140 of  
> "/usr/local/lib/php/Horde/Support/Backtrace.php"]
> 2592258 2015-08-11T16:40:25-03:00 DEBUG: HORDE 1.  
> Horde_ErrorHandler::catchFatalError()
> ...
>
> where the value ranges 1 to 124981(?)
>
> Any help about this? necessary more information?
>
> Thanks in advance
> Gian


This is related to a date field in some Microsoft TNEF attachment in  
one of the emails being synchronized. Impossible to say what the  
actual issue is without access to the attachment causing the error.

-- 
mike
The Horde Project
http://www.horde.org
https://www.facebook.com/hordeproject
https://www.twitter.com/hordeproject
-------------- next part --------------
A non-text attachment was scrubbed...
Name: smime.p7s
Type: application/pkcs7-signature
Size: 5751 bytes
Desc: S/MIME Signature
URL: <http://lists.horde.org/archives/horde/attachments/20150813/d82f430a/attachment.bin>


More information about the horde mailing list