Last modified: 2011-11-09 10:42:31 UTC

Wikimedia Bugzilla is closed!

Wikimedia migrated from Bugzilla to Phabricator. Bug reports are handled in Wikimedia Phabricator.
This static website is read-only and for historical purposes. It is not possible to log in and except for displaying bug reports and their history, links might be broken. See T31960, the corresponding Phabricator task for complete and up-to-date bug report information.
Bug 29960 - Allowed memory size of 134217728 bytes exhausted
Allowed memory size of 134217728 bytes exhausted
Status: RESOLVED INVALID
Product: MediaWiki extensions
Classification: Unclassified
SimpleSecurity (Other open bugs)
unspecified
All Linux
: High normal (vote)
: ---
Assigned To: Aran
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2011-07-19 05:11 UTC by Christian Kujau
Modified: 2011-11-09 10:42 UTC (History)
1 user (show)

See Also:
Web browser: ---
Mobile Platform: ---
Assignee Huggle Beta Tester: ---


Attachments
strace -tt -ff -F -s1024 on the php-cgi process going crazy (224.04 KB, text/plain)
2011-07-19 05:21 UTC, Christian Kujau
Details
strace -tt -ff -F -s1024 on the php-cgi process going crazy (44 bytes, text/plain)
2011-07-19 05:22 UTC, Christian Kujau
Details

Description Christian Kujau 2011-07-19 05:11:17 UTC
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*:

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

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

3) /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:

1) 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.

2) 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.
Comment 1 Christian Kujau 2011-07-19 05:21:52 UTC
Created attachment 8797 [details]
strace -tt -ff -F -s1024  on the php-cgi process going crazy
Comment 2 Christian Kujau 2011-07-19 05:22:37 UTC
Created attachment 8798 [details]
strace -tt -ff -F -s1024  on the php-cgi process going crazy
Comment 3 Max Semenik 2011-07-19 06:09:16 UTC
Try disabling $wgSecurityUseDBHook, it often introduces subtle bugs hence it's marked as experimental.
Comment 4 Christian Kujau 2011-07-19 17:23:25 UTC
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.
Comment 5 Christian Kujau 2011-07-24 07:46:35 UTC
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 :(
Comment 6 Max Semenik 2011-07-24 08:01:58 UTC
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
Comment 7 Max Semenik 2011-07-24 10:50:11 UTC
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?
Comment 8 Christian Kujau 2011-07-25 04:10:29 UTC
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.
Comment 9 Christian Kujau 2011-11-09 10:42:31 UTC
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.

Note You need to log in before you can comment on or make changes to this bug.


Navigation
Links