[horde] PHP7 : Memory eater bug? -> infinite recursion, getting closer :)
Torben Dannhauer
torben at dannhauer.info
Fri Feb 17 12:40:35 UTC 2017
Zitat von Michael J Rubinsky <mrubinsk at horde.org>:
> Quoting Torben Dannhauer <torben at dannhauer.info>:
>
>> Zitat von Torben Dannhauer <torben at dannhauer.info>:
>>
>>> Hi,
>>>
>>>
>>>
>>> Yesterday I discovered a lot of errors thrown by PHP7 due to my memory
>>> limit.
>>>
>>>
>>>
>>> I get lots of errors like this:
>>>
>>> <snip>
>>>
>>> [13-Feb-2017 09:57:35 Europe/Berlin] PHP Fatal error: Allowed memory size
>>> of 1073741824 bytes exhausted (tried to allocate 20480 bytes) in
>>> /var/www/torben/web/ssl-dannhauer.de/horde/mnemo/lib/Mnemo.php on line 537
>>>
>>> [13-Feb-2017 09:57:35 Europe/Berlin] PHP Fatal error: Allowed memory size
>>> of 1073741824 bytes exhausted (tried to allocate 20480 bytes) in
>>> /usr/share/php/Horde/ErrorHandler.php on line 193
>>>
>>> [13-Feb-2017 09:58:08 Europe/Berlin] PHP Fatal error: Allowed memory size
>>> of 1073741824 bytes exhausted (tried to allocate 20480 bytes) in
>>> /var/www/torben/web/ssl-dannhauer.de/horde/mnemo/lib/Mnemo.php on line 537
>>>
>>> [13-Feb-2017 09:58:08 Europe/Berlin] PHP Fatal error: Allowed memory size
>>> of 1073741824 bytes exhausted (tried to allocate 20480 bytes) in
>>> /usr/share/php/Horde/ErrorHandler.php on line 193
>>>
>>> <snap>
>>>
>>>
>>>
>>> It doesn't matter whether my limit is configured as 512M, 2G or 3G. Anyway,
>>> a limit exceed in that order of memory is very likely to be a bug.
>>>
>>> Unfortunatly I do not have a clue how to start debugging here. The System
>>> itself shows of course only the processes, not the memory consumption of
>>> every running script.
>>>
>>>
>>>
>>> Any hints whjere to start?
>>>
>>>
>>>
>>> Many thanks,
>>>
>>> Torben
>>>
>>
>>
>>
>> I'm getting closer to the problem.
>>
>> I installed xdebug to dive deeper into the issue and discovered
>> that the error does not longer occur as long als xdebug is loaded
>> into PHP.
>> Screening the tons of logs produced by xdebug, I sawthat xedebug
>> cancels the execution due to the max_nesting level. So the error
>> still DOES occur, but is catched by xdebug and announced in the
>> loggs with different message.
>> Here is the full log, it indicates an endless recursion in mnemo -
>> whit fits perfect to the picture of this issue:
>>
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP Fatal error: Maximum
>> function nesting level of '256' reached, aborting! in
>> /usr/share/php/Horde/ErrorHandler.php on line 193
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP Stack trace:
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 1. {main}()
>> <webroot>/horde/rpc.php:0
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 2.
>> Horde_Rpc_ActiveSync->getResponse() <webroot>/horde/rpc.php:160
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 3.
>> Horde_ActiveSync->handleRequest()
>> /usr/share/php/Horde/Rpc/ActiveSync.php:143
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 4.
>> Horde_ActiveSync_Request_Base->handle()
>> /usr/share/php/Horde/ActiveSync.php:834
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 5.
>> Horde_ActiveSync_Request_Ping->_handle()
>> /usr/share/php/Horde/ActiveSync/Request/Base.php:253
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 6.
>> Horde_ActiveSync_Collections->pollForChanges()
>> /usr/share/php/Horde/ActiveSync/Request/Ping.php:222
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 7.
>> Horde_ActiveSync_Collections->getCollectionChangeCount()
>> /usr/share/php/Horde/ActiveSync/Collections.php:1222
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 8.
>> Horde_ActiveSync_Collections->getCollectionChanges()
>> /usr/share/php/Horde/ActiveSync/Collections.php:1417
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 9.
>> Horde_ActiveSync_State_Base->getChanges()
>> /usr/share/php/Horde/ActiveSync/Collections.php:1401
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 10.
>> Horde_Core_ActiveSync_Driver->getServerChanges()
>> /usr/share/php/Horde/ActiveSync/State/Base.php:437
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 11.
>> Horde_Core_ActiveSync_Connector->getChanges()
>> /usr/share/php/Horde/Core/ActiveSync/Driver.php:1112
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 12.
>> Horde_Registry_Caller->getChangesByModSeq()
>> /usr/share/php/Horde/Core/ActiveSync/Connector.php:1098
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 13.
>> Horde_Registry_Caller->__call()
>> /usr/share/php/Horde/Core/ActiveSync/Connector.php:1098
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 14.
>> Horde_Registry->call() /usr/share/php/Horde/Registry/Caller.php:41
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 15.
>> Horde_Registry->callByPackage()
>> /usr/share/php/Horde/Registry.php:1088
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 16.
>> Mnemo_Api->getChangesByModSeq()
>> /usr/share/php/Horde/Registry.php:1131
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 17.
>> Mnemo_Api->getChanges() <webroot>/horde/mnemo/lib/Api.php:135
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 18. Mnemo_Api->listBy()
>> <webroot>/horde/mnemo/lib/Api.php:117
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 19. Mnemo_Api->listBy()
>> <webroot>/horde/mnemo/lib/Api.php:158
>> [.... and so on...]
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 252. Mnemo_Api->listBy()
>> <webroot>/horde/mnemo/lib/Api.php:158
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 253. Mnemo_Api->listBy()
>> <webroot>/horde/mnemo/lib/Api.php:158
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 254.
>> Mnemo::getSyncNotepads() <webroot>/horde/mnemo/lib/Api.php:155
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 255.
>> Horde_Prefs->getValue() <webroot>/horde/mnemo/lib/Mnemo.php:538
>> [16-Feb-2017 13:20:50 Europe/Berlin] PHP 256.
>> Horde_Prefs->_getScope() /usr/share/php/Horde/Prefs.php:289
>>
>> I'm happy to get any hint what might be the reason. I assume
>> something to do with PHP7 ;)
>
> Can you see what Mnemo::getSyncNotepads(); returns? Easiest way
> would be to use admin->phpshell from within horde, be sure to choose
> the Mnemo scope from the drop down menu.
>
Oh, have never thought to use the Horde build in shell to debug :)
Anyway, I enhanced the loggin in the file since not every
access/client triogfgers the issue, it happens only occassionally.
The function listBy($action, $timestamp, $notepad = null, $end =
null, $isModSeq = false)
if called with the parameters action:add timestamp:50855 notepad:
end:51055 isModSeq:1
in the recursive loop. The queried array is then.
Array
(
[0] =>
)
What is the intented logic if an empty array is returned?
Thanks,
Torben
>
>> Thanks,
>> Torben
>>
>>
>>
>>
>>
>>
>>
>> --
>> Horde mailing list
>> Frequently Asked Questions: http://horde.org/faq/
>> To unsubscribe, mail: horde-unsubscribe at lists.horde.org
>
>
>
> --
> mike
> The Horde Project
> http://www.horde.org
> https://www.facebook.com/hordeproject
> https://www.twitter.com/hordeproject
More information about the horde
mailing list