Page MenuHomePhabricator

enabling wgDebugFunctionEntry triggers infinite loop
Closed, ResolvedPublic

Description

stack trace produced by the bug

When enabling profiling by providing a StartProfiler.php script along with setting

$wgDebugFunctionEntry = true;

php hits its maximum nesting level. The error stacktrace is attached.

In short, wfProfileIn calls wfDebug. wfDebug calls wfRunHooks which(the impl not the hooks) goes back to calling wfProfileIn by the 16th stack frame.

The bug can be reproduced for bisecting by creating StartProfiler.php and executing

$ echo "\$wgDebugFunctionEntry = true;wfProfileIn('test');" | php maintenance/eval.php

This finds af125df5199b5c232bf335d735cecc6d8f8e9784 as the change which caused this bug. Tested on a new mediawiki/vagrant instance with no additional extensions enabled.


Version: 1.22.0
Severity: normal

Attached:

Details

Reference
bz55818

Event Timeline

bzimport raised the priority of this task from to Medium.Nov 22 2014, 2:11 AM
bzimport set Reference to bz55818.
bzimport added a subscriber: Unknown Object (MLST).

(In reply to comment #0)

This finds af125df5199b5c232bf335d735cecc6d8f8e9784 as the change which
caused this bug.

CC'ing author and reviewer.

For the record, here is the traceback:

0. wfRunHooks at GlobalFunctions.php:3885

  1. Hooks::run at Hooks.php:136
  2. wfProfileIn at Profiler.php:38
  3. Profiler::profileIn at Profiler.php:207
  4. Profiler::debug at Profiler.php:719
  5. wfDebug at GlobalFunctions.php:934
  6. wfRunHooks at GlobalFunctions.php:3885

This is all because of the undocumented Debug hook in wfDebug. The Debug hook is used if an extension wants to stop a debug message from being sent out (it cannot change the message because it's not sent by reference).

I really don't see the point of this hook, and ideally the wfDebug and related functions should be as low-level and avoid calling other code as much as possible to avoid situations like this. So I suggest just removing that hook, which would solve this loop.

Change 90453 had a related patch set uploaded by EBernhardson:
Remove 'Debug' hook from wfDebug and wfDebugLog

https://gerrit.wikimedia.org/r/90453

Change 90453 merged by jenkins-bot:
Remove 'Debug' hook from wfDebug and wfDebugLog

https://gerrit.wikimedia.org/r/90453

(In reply to comment #2)

This is all because of the undocumented Debug hook in wfDebug. The Debug hook
is used if an extension wants to stop a debug message from being sent out (it
cannot change the message because it's not sent by reference).

I really don't see the point of this hook, ...

It was added in r88843 (bug 29140) and in fact documented.

bug 29140 does seem like a reasonable use case, but i wonder if it could be implemented such that it doesn't hook into each call to wfDebug. I havn't fully investigated whats happening here in mw, but in libraries like Monolog they have the ability to build a list of messages and cache them in-process, to be flushed to an external source(like firebug) with a single call at the end of the request rather than every ->log() call. I wonder if something similar could be appropriate for re-enabling firebug.