Page MenuHomePhabricator

Fatal error: request has exceeded memory limit in StripState.php
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error Message

Fatal error: request has exceeded memory limit in /srv/mediawiki/php-1.31.0-wmf.21/includes/parser/StripState.php on line 137

Stack Trace

N/A

Notes

This is occurring with a high frequency in production.

Screenshot from 2018-02-20 16-06-31.png (179×650 px, 13 KB)

Event Timeline

mmodell triaged this task as High priority.Feb 20 2018, 9:50 PM
greg added a subscriber: greg.

parsing team, can you take a look here and give us some guidance on debugging this?

First impression: somebody is adding very large strip markers, which are tripping the memory limits when unstripped to add to the output.

Could be related to 939faea318d9c2107fab3a584bc1c023f3c592e9 which changed the regexp for strip markers. That should have made the match more restrictive, though. But that's precisely the regexp involved in this callback, so it's a pretty strong coincidence.

I think tying this to the initiating web request would be helpful. As it stands, the logs do not tell us what is causing this. Is it possible to find out a more detailed error log that identifies the web request url?

A stack trace would also be helpful. Or at least the value of $type or $text in the unstripType caller.

Also possible that someone is actually trying to do the sort of XSS attack that bawolff was protecting against? Deliberately creating a very long strip marker?

EDIT (from bawolff): ...or a DOS attempt.

Its also possible that the real issue is somewhere else (during parsing), and stripstate handling is the straw that pushes the memory camel over the edge

It's not a DOS, there's not enough requests. It's just a broken bot hitting the same old revision via action=parse again and again. Specifically 256170852, a revision of [[Barack Obama]] from 2008. The solution is to find the person running this bot and to tell them to stop doing it.

It's not a DOS, there's not enough requests. It's just a broken bot hitting the same old revision via action=parse again and again. Specifically 256170852, a revision of [[Barack Obama]] from 2008. The solution is to find the person running this bot and to tell them to stop doing it.

Looking at the diff of that revision, {{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|.}}}}}}}}}}}}}}}}}}}}} is the only thing out of the ordinary, so probably the trigger.

I think tying this to the initiating web request would be helpful. As it stands, the logs do not tell us what is causing this. Is it possible to find out a more detailed error log that identifies the web request url?

Turns out I wasn't look in the right place. fatal.log on mwlog1001 has the traces and Krinkle provided https://logstash.wikimedia.org/goto/9f522ce47239a4373bc059024f286f5e for identifying the request url.

I revision-deleted the revision in question.

greg assigned this task to tstarling.

Thanks, all.

Same issue was filed in T187833. I have a stack trace this time :)

{
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/parser/StripState.php",
  "line": 137
},
{
  "args": [
    "array"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/parser/StripState.php",
  "line": 127,
  "function": "unstripCallback",
  "type": "->",
  "class": "StripState",
  "object": "[object] (StripState: {})"
},
{
  "args": [
    "string",
    "string"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/parser/StripState.php",
  "line": 101,
  "function": "unstripType",
  "type": "->",
  "class": "StripState",
  "object": "[object] (StripState: {})"
},
{
  "args": [
    "string"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/parser/Parser.php",
  "line": 1373,
  "function": "unstripNoWiki",
  "type": "->",
  "class": "StripState",
  "object": "[object] (StripState: {})"
},
{
  "args": [
    "string",
    "boolean",
    "boolean"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/parser/Parser.php",
  "line": 446,
  "function": "internalParseHalfParsed",
  "type": "->",
  "class": "Parser",
  "object": "[object] (Parser: )"
},
{
  "args": [
    "string",
    "Title",
    "ParserOptions",
    "boolean",
    "boolean",
    "integer"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/StubObject.php",
  "line": 112,
  "function": "parse",
  "type": "->",
  "class": "Parser",
  "object": "[object] (Parser: )"
},
{
  "args": [
    "string",
    "array"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/StubObject.php",
  "line": 138,
  "function": "_call",
  "type": "->",
  "class": "StubObject",
  "object": "[object] (StubObject: {})"
},
{
  "args": [
    "string",
    "array"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/content/WikitextContent.php",
  "line": 329,
  "function": "__call",
  "type": "->",
  "class": "StubObject",
  "object": "[object] (StubObject: {})"
},
{
  "args": [
    "Title",
    "integer",
    "ParserOptions",
    "boolean",
    "ParserOutput"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/content/AbstractContent.php",
  "line": 516,
  "function": "fillParserOutput",
  "type": "->",
  "class": "WikitextContent",
  "object": "[object] (WikitextContent: {})"
},
{
  "args": [
    "Title",
    "integer",
    "ParserOptions"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/poolcounter/PoolWorkArticleView.php",
  "line": 145,
  "function": "getParserOutput",
  "type": "->",
  "class": "AbstractContent",
  "object": "[object] (WikitextContent: {})"
},
{
  "args": [],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/poolcounter/PoolCounterWork.php",
  "line": 123,
  "function": "doWork",
  "type": "->",
  "class": "PoolWorkArticleView",
  "object": "[object] (PoolWorkArticleView: {\"poolCounter\":{}})"
},
{
  "args": [],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/page/WikiPage.php",
  "line": 1133,
  "function": "execute",
  "type": "->",
  "class": "PoolCounterWork",
  "object": "[object] (PoolWorkArticleView: {\"poolCounter\":{}})"
},
{
  "args": [
    "ParserOptions",
    "integer",
    "boolean"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiParse.php",
  "line": 602,
  "function": "getParserOutput",
  "type": "->",
  "class": "WikiPage",
  "object": "[object] (WikiPage: {\"mTitle\":{\"mTextform\":\"Rosetta@home\",\"mUrlform\":\"Rosetta@home\",\"mDbkeyform\":\"Rosetta@home\",\"mNamespace\":0,\"mInterwiki\":\"\",\"mFragment\":\"\",\"mArticleID\":3255539,\"mRestrictions\":{\"edit\":[],\"move\":[]},\"mCascadeRestriction\":false,\"mCascadingRestrictions\":null,\"mCascadeSources\":null,\"mRestrictionsLoaded\":true,\"mTitleProtection\":null,\"mDefaultNamespace\":0,\"mRedirect\":false},\"mDataLoaded\":true,\"mIsRedirect\":0,\"mLatest\":821745844,\"mPreparedEdit\":false})"
},
{
  "args": [
    "WikiPage",
    "ParserOptions",
    "boolean",
    "NULL",
    "Revision",
    "boolean"
  ],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiParse.php",
  "line": 120,
  "function": "getParsedContent",
  "type": "->",
  "class": "ApiParse",
  "object": "[object] (ApiParse: {})"
},
{
  "args": [],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php",
  "line": 1580,
  "function": "execute",
  "type": "->",
  "class": "ApiParse",
  "object": "[object] (ApiParse: {})"
},
{
  "args": [],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php",
  "line": 542,
  "function": "executeAction",
  "type": "->",
  "class": "ApiMain",
  "object": "[object] (ApiMain: {\"mCommit\":false})"
},
{
  "args": [],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php",
  "line": 513,
  "function": "executeActionWithErrorHandling",
  "type": "->",
  "class": "ApiMain",
  "object": "[object] (ApiMain: {\"mCommit\":false})"
},
{
  "args": [],
  "file": "/srv/mediawiki/php-1.31.0-wmf.22/api.php",
  "line": 94,
  "function": "execute",
  "type": "->",
  "class": "ApiMain",
  "object": "[object] (ApiMain: {\"mCommit\":false})"
},
{
  "args": [
    "string"
  ],
  "file": "/srv/mediawiki/w/api.php",
  "line": 3,
  "function": "include"
}

If it is a bot that is requesting external links on a page, could that be a bot that updates links on a page to IA links for dead links? While there is probably an issue here in the parser (to be determined), the bot seems to be repeatedly retrying the same failing request.

This comment was removed by ssastry.

Looks like that is a very similar revision to the one that started this (which Tim had rev-del'ed).

Diff: https://en.wikipedia.org/?diff=255139603&diffonly=1

Revision 255139603 (1 December 2008)
   Quick guide to Rosetta and its graphics

-  
+ {{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|{{unblock|.}}}}}}}}}}}}}}}}}}}}}
  
  Like all BOINC projects, Rosetta@home runs in the background of the user's computer using idle computer power,

The same vandal made a few more similar edits in 2008, per https://en.wikipedia.org/wiki/Special:Contributions/Endingkey.

Yeah, deleting the revision obviously isn't the ultimate solution to this issue ;)

Krinkle set Security to Software security bug.Feb 26 2018, 11:15 PM
Krinkle added a project: acl*security.
Krinkle changed the visibility from "Public (No Login Required)" to "Custom Policy".

Replying to some IRC discussion

<subbu> TimStarling, doing it once, twice, thrice .. and looking at the expandtemplates output shows that the size of the output starts blowing up rapidly.
<subbu> roughly 4^(nesting level-1) * 4k

I see that in my own testing, but the StripState size (var_dumped) isn't increasing quite as fast.

<TimStarling> the post-expand include size is meant to limit massive preprocessor expansions, but I guess strip marker expansion is not included

Yeah, it seems to be counting the length of the strip marker rather than the length of the text inside the marker.

<Krinkle> TimStarling: Hm.. do we use strip markers for template parameters like {{{1}}} etc.? I thought maybe the expansion is big because of the recursion there.
<Krinkle> BUt afaik we don't use stripmarkers for those

We don't. But this template does {{#tag:nowiki|{{{1}}}}} three times, and each one of those creates a strip marker. What it probably really wants is a way to get the unparsed wikitext of {{{1}}} to pass to #tag:nowiki, but that's not available so it does the next best thing (and which will generally work for normal uses of the template).

  • {{unblock|.}} produces something like 3707 bytes of text. This includes three strip markers hiding 1 byte each (and two more for 29 bytes).
  • {{unblock|{{unblock|.}}}}, produces something like 7412 bytes of text, which looks like wrapping the output of the template around itself once. But it also includes three strip markers hiding 3707 bytes each that show up when thing get unstripped.
  • {{unblock|{{unblock|{{unblock|.}}}}}}, produces something like 11117 bytes of text. Again, it looks like it adds one more level of wrapping. But it also includes three strip markers hiding 3707 bytes each and three more hiding 7412 bytes each, and each of those 7412-byte markers has another copy of the three 3707-byte markers for a total of 66720 extra bytes that show up when thing get unstripped.
  • {{unblock|{{unblock|{{unblock|{{unblock|.}}}}}}}} continues the trend. It produces only 14822 bytes of text directly, but it has all the strip markers from the previous version plus three strip markers hiding 11117 bytes each that each have a copy of the three 3707-byte markers and the three 7412-byte markers (that each in turn have the three 3707-byte markers), for a total of 300231 extra bytes that show up when thing get unstripped.

In each case it's only the directly produced bytes that get counted against the post-expand and argument size limits, while the real size explosion is in the three strip markers that each have three strip markers inside, recursively.

Fix uploaded at https://gerrit.wikimedia.org/r/#/c/415207/ . Any objections to removing the policy? This is not a DOS attack. It's apparently not even a DOS attack vector, since the memory limit is doing its job, and the CPU time is short.

Krinkle changed the visibility from "Custom Policy" to "Public (No Login Required)".

Any objections to removing the policy?

Done.

Change 415207 merged by jenkins-bot:
[mediawiki/core@master] Limit total expansion size in StripState and improve limit handling

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

mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:09 PM