Last modified: 2011-11-09 10:42:31 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.
Created attachment 8797 [details] strace -tt -ff -F -s1024 on the php-cgi process going crazy
Created attachment 8798 [details] strace -tt -ff -F -s1024 on the php-cgi process going crazy
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.