Maniphest T31960

Allowed memory size of 134217728 bytes exhausted
Closed, InvalidPublic
Actions

Assigned To

Authored By

	Ckujau
	Jul 19 2011, 5:11 AM

Description

When SimpleSecurity (r92519) is enabled in Mediawiki 1.17, PHP exceeds its memory_limit:

[19-Jul-2011 06:49:46] PHP Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 3276888 bytes) in ../includes/db/Database.php on line 3029

and the webserver (lighttpd/1.4.28, php-cgi/5.3.3-7+squeeze3) delivers an error 500:

GET /mediawiki/load.php?debug=false&lang=en&modules=jquery.checkboxShiftClick%2Cclient%2Ccookie%2Cplaceholder%7Cmediawiki.language%2Cutil%7Cmediawiki.legacy.ajax%2Cajaxwatch%2Cwikibits&skin=vector&version=NaNNaNNaNTNaNNaNNaNZ HTTP/1.1" 500 37 "-" "Mozilla/5.0 (X11; en-US; rv:2.0) Gecko/20100101"

Increasing the memory_limit (tried with 512MB) did not help; php would consume all and then die again.

With firebug (a Firefox addon) installed, I can see 3 GET requests when SimpleSecurity is *disabled*:

/load.php?debug=false&lang=en&modules=startup&only=scripts&skin=vector&* -> 1.5sec with 200 OK

/load.php?debug=false&lang=en&modules=jquery%7Cmediawiki&only=scripts&skin=vector&version=20110622T081140Z -> ~800 msec with 200 OK

/load.php?debug=false&lang=en&modules=jquery.checkboxShiftClick%2Cclient%2Ccookie%2Cplaceholder%7Cmediawiki.language%2Cutil%7Cmediawiki.legacy.ajax%2Cajaxwatch%2Cwikibits&skin=vector&version=20110719T045856Z -> 1sec with 200 OK

When SimpleSecurity is enabled, the 3rd GET requests turns into:

/load.php?debug=false&lang=en&modules=jquery.checkboxShiftClick%2Cclient%2Ccookie%2Cplaceholder%7Cmediawiki.language%2Cutil%7Cmediawiki.legacy.ajax%2Cajaxwatch%2Cwikibits&skin=vector&version=NaNNaNNaNTNaNNaNNaNZ

and returns with "500 Internal Server Error" after around 30sec. In the processlist I can see that one php-cgi is using a lot of CPU time and of course memory, until it hits the memory_limit, then it stops.

My SimpleSecurity config:

$wgSecurityUseDBHook = true;
require_once("$IP/extensions/SimpleSecurity-svn/SimpleSecurity.php");
$wgSecurityRenderInfo = false;
restrictions apply
$wgPageRestrictions['Namespace:Special']['read'] = 'users';
$wgPageRestrictions['Namespace:User']['read'] = 'users';

Two more things here:

The bug is not 100% reproducible: If I disable SimpleSecurity, the bug goes away. Enabling it again (just wgSecurityUseDBHook=true and require_once), the bug may not appear instantly. But as soon as I set wgPageRestrictions again, the bug reappears.

Despite the error 500 for the 3rd GET request, SimpleSecurity still works. The error 500 just show up in the logfile. The article-page is rendered just fine, despite the fact that the 3rd GET request is still in progress.

Version: unspecified
Severity: normal
OS: Linux

Details

Reference: bz29960

Event Timeline

• bzimport raised the priority of this task from to High.Nov 21 2014, 11:34 PM

• bzimport added a project: MediaWiki-extensions-SimpleSecurity.

• bzimport set Reference to bz29960.

Ckujau created this task.Jul 19 2011, 5:11 AM

Created attachment 8797
strace -tt -ff -F -s1024 on the php-cgi process going crazy

Attached:

strace-php-12866.txt224 KBDownload

Created attachment 8798
strace -tt -ff -F -s1024 on the php-cgi process going crazy

Attached:

strace-php-12865.txt44 BDownload

Try disabling $wgSecurityUseDBHook, it often introduces subtle bugs hence it's marked as experimental.

With wgSecurityUseDBHook, the error 500 persists, but PHP does not seem to exceed its memory_limit any more. So the error 500 must be something different.

However, with wgSecurityUseDBHook disabled, wgPageRestrictions won't work any more and all the restricted sites are readable to the world - so that's not a feasible workaround.

I've set this report to "High", as with every request to an article, the memory limit is exhausted. With multiple requests hitting the site, each php-cgi process will grow in size, until each of them exchausts its memory limit. The machine gets loaded pretty fast and becomes unresponsive when php-cgi eats up all available memory. Because of this I have to disable SimpleSecurity for now :(

Can you produce error backtraces by adding the following to LocalSettings.php:

error_reporting( E_ALL | E_STRICT );
ini_set( 'display_errors', 1 );

More details: http://www.mediawiki.org/wiki/Manual:How_to_debug

Could you try my fixes from r92980? It should fix the memory consumption problem.

One wild guess: you don't have the GZIP PHP module?

I've tried to generate a backtrace already, but as soon as I add error_reporting *AND* the ini_set to the beginning of LocalSettings.php, I only get the "Allowed memory size exhausted" message in my php.log, but no Error 500 in my access.log (lighttpd) any more. As soon as I unset ini_set again, the Error 500 reappears (as expected, because of the fatal PHP error):

php.log

PHP Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 9142353 bytes) in /data/Scratch/scm/mediawiki-svn/includes/db/Database.php on line 781

access.log

"GET /mediawiki/load.php?debug=false&lang=en&modules=jquery.checkboxShiftClick%2Cclient%2Ccookie%2Cplaceholder%7Cmediawiki.language%2Cutil%7Cmediawiki.legacy.ajax%2Cwikibits&skin=vector&version=NaNNaNNaNTNaNNaNNaNZ HTTP/1.1" 500 37 "-" "Mozilla/5.0 (X11; en-US; rv:2.0) Gecko/20100101"

I checked out r92980 and at first I thought it was resolved, but after flushing the browser cache, the error reappeared again :(

Regarding the GZIP PHP module: I usually have zlib.output_compression=On, but I've set it to "Off" now, restarted the webserver (and all php-cgi process) and the error persists.

I'm setting this to invalid b/c it does not happen with MW-1.18.0beta1 and SimpleSecurity r102504 (svn) any more. I think I also reproduced it in MW-1.17 w/o any SimpleSecurity extension loaded.

Sorry for the noise,
C.

	F7814: strace-php-12865.txt
	Nov 21 2014, 11:34 PM

	F7813: strace-php-12866.txt
	Nov 21 2014, 11:34 PM

Allowed memory size of 134217728 bytes exhaustedClosed, InvalidPublicActions