[horde] PHP7 : Memory eater bug? -> infinite recursion, getting closer :)

Thu Feb 16 12:49:10 UTC 2017

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 ;)

Thanks,
Torben