Page MenuHomePhabricator
Create Task
Maniphest T241208

Common (>1000/hour) WMFTimeoutException on zhwiki on api call /w/api.php?format=json&action=query&prop=extlinks%7Ccategories%7Crevisions%7Ciwlinks%7Cimages%7Cimageinfo%7Clinks%7Cextracts%7Cinfo%7Clanglinks
Closed, ResolvedPublic
Actions

Description

The timeout for slow requests seem unusually high for certain api calls on zhwiki:

https://logstash.wikimedia.org/goto/a9d9f1adb46c41635cdbba2bad5ef429

Example trace for:

/w/api.php?format=json&action=query&prop=extlinks%7Ccategories%7Crevisions%7Ciwlinks%7Cimages%7Cimageinfo%7Clinks%7Cextracts%7Cinfo%7Clanglinks&inprop=url&rvprop=content%7Ctimestamp&rvparse&redirects&clshow=!hidden&maxlag=5&cllimit=100&iiprop=mime%7Cdimensions%7Curl%7Cextmetadata%7Ctimestamp&iilimit=500&lllimit=100&llprop=url&uselang=zh-tw&titles=%E7%9A%AE%E5%9F%83%E5%B0%94%E8%8E%B1
#0 /srv/mediawiki/php-1.35.0-wmf.11/extensions/ParserFunctions/includes/ParserFunctions.php(223): {closure}(integer)
#1 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3566): MediaWiki\Extensions\ParserFunctions\ParserFunctions::switch(Parser, PPTemplateFrame_Hash, array)
#2 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3270): Parser->callParserFunction(PPTemplateFrame_Hash, string, array)
#3 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#4 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3448): PPFrame_Hash->expand(PPNode_Hash_Tree)
#5 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPFrame_Hash)
#6 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPTemplateFrame_Hash.php(169): PPFrame_Hash->expand(PPNode_Hash_Tree, integer)
#7 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPTemplateFrame_Hash.php(181): PPTemplateFrame_Hash->getNamedArgument(string)
#8 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3955): PPTemplateFrame_Hash->getArgument(string)
#9 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(270): Parser->argSubstitution(array, PPTemplateFrame_Hash)
#10 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPTemplateFrame_Hash.php(169): PPFrame_Hash->expand(PPNode_Hash_Tree, integer)
#11 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPTemplateFrame_Hash.php(181): PPTemplateFrame_Hash->getNamedArgument(string)
#12 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3955): PPTemplateFrame_Hash->getArgument(string)
#13 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(270): Parser->argSubstitution(array, PPTemplateFrame_Hash)
#14 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3187): PPFrame_Hash->expand(PPNode_Hash_Tree)
#15 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#16 /srv/mediawiki/php-1.35.0-wmf.11/extensions/ParserFunctions/includes/ParserFunctions.php(144): PPFrame_Hash->expand(PPNode_Hash_Tree)
#17 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3566): MediaWiki\Extensions\ParserFunctions\ParserFunctions::ifeq(Parser, PPTemplateFrame_Hash, array)
#18 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3270): Parser->callParserFunction(PPTemplateFrame_Hash, string, array)
#19 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#20 /srv/mediawiki/php-1.35.0-wmf.11/extensions/ParserFunctions/includes/ParserFunctions.php(123): PPFrame_Hash->expand(PPNode_Hash_Tree)
#21 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3566): MediaWiki\Extensions\ParserFunctions\ParserFunctions::if(Parser, PPTemplateFrame_Hash, array)
#22 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3270): Parser->callParserFunction(PPTemplateFrame_Hash, string, array)
#23 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#24 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPTemplateFrame_Hash.php(169): PPFrame_Hash->expand(PPNode_Hash_Tree, integer)
#25 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPTemplateFrame_Hash.php(181): PPTemplateFrame_Hash->getNamedArgument(string)
#26 /srv/mediawiki/php-1.35.0-wmf.11/extensions/Scribunto/includes/engines/LuaCommon/LuaCommon.php(672): PPTemplateFrame_Hash->getArgument(string)
#27 /srv/mediawiki/php-1.35.0-wmf.11/extensions/Scribunto/includes/engines/LuaSandbox/Engine.php(391): Scribunto_LuaEngine->getExpandedArgument(string, string)
#28 [internal function]: Scribunto_LuaSandboxCallback->__call(string, array)
#29 /srv/mediawiki/php-1.35.0-wmf.11/extensions/Scribunto/includes/engines/LuaSandbox/Engine.php(314): LuaSandboxFunction->call(LuaSandboxFunction)
#30 /srv/mediawiki/php-1.35.0-wmf.11/extensions/Scribunto/includes/engines/LuaCommon/LuaCommon.php(292): Scribunto_LuaSandboxInterpreter->callFunction(LuaSandboxFunction, LuaSandboxFunction)
#31 /srv/mediawiki/php-1.35.0-wmf.11/extensions/Scribunto/includes/engines/LuaCommon/LuaCommon.php(979): Scribunto_LuaEngine->executeFunctionChunk(LuaSandboxFunction, PPTemplateFrame_Hash)
#32 /srv/mediawiki/php-1.35.0-wmf.11/extensions/Scribunto/includes/common/Hooks.php(128): Scribunto_LuaModule->invoke(string, PPTemplateFrame_Hash)
#33 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3566): ScribuntoHooks::invokeHook(Parser, PPTemplateFrame_Hash, array)
#34 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3270): Parser->callParserFunction(PPTemplateFrame_Hash, string, array)
#35 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#36 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3448): PPFrame_Hash->expand(PPNode_Hash_Tree)
#37 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#38 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3448): PPFrame_Hash->expand(PPNode_Hash_Tree)
#39 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPTemplateFrame_Hash)
#40 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3448): PPFrame_Hash->expand(PPNode_Hash_Tree)
#41 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/PPFrame_Hash.php(253): Parser->braceSubstitution(array, PPFrame_Hash)
#42 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(3112): PPFrame_Hash->expand(PPNode_Hash_Tree, integer)
#43 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(1477): Parser->replaceVariables(string)
#44 /srv/mediawiki/php-1.35.0-wmf.11/includes/parser/Parser.php(585): Parser->internalParse(string)
#45 /srv/mediawiki/php-1.35.0-wmf.11/includes/content/WikitextContent.php(368): Parser->parse(string, Title, ParserOptions, boolean, boolean, integer)
#46 /srv/mediawiki/php-1.35.0-wmf.11/includes/content/AbstractContent.php(555): WikitextContent->fillParserOutput(Title, integer, ParserOptions, boolean, ParserOutput)
#47 /srv/mediawiki/php-1.35.0-wmf.11/includes/Revision/RenderedRevision.php(267): AbstractContent->getParserOutput(Title, integer, ParserOptions, boolean)
#48 /srv/mediawiki/php-1.35.0-wmf.11/includes/Revision/RenderedRevision.php(236): MediaWiki\Revision\RenderedRevision->getSlotParserOutputUncached(WikitextContent, boolean)
#49 /srv/mediawiki/php-1.35.0-wmf.11/includes/Revision/RevisionRenderer.php(215): MediaWiki\Revision\RenderedRevision->getSlotParserOutput(string)
#50 /srv/mediawiki/php-1.35.0-wmf.11/includes/Revision/RevisionRenderer.php(152): MediaWiki\Revision\RevisionRenderer->combineSlotOutput(MediaWiki\Revision\RenderedRevision, array)
#51 [internal function]: MediaWiki\Revision\RevisionRenderer->MediaWiki\Revision\{closure}(MediaWiki\Revision\RenderedRevision, array)
#52 /srv/mediawiki/php-1.35.0-wmf.11/includes/Revision/RenderedRevision.php(198): call_user_func(Closure, MediaWiki\Revision\RenderedRevision, array)
#53 /srv/mediawiki/php-1.35.0-wmf.11/includes/poolcounter/PoolWorkArticleView.php(196): MediaWiki\Revision\RenderedRevision->getRevisionParserOutput()
#54 /srv/mediawiki/php-1.35.0-wmf.11/includes/poolcounter/PoolCounterWork.php(125): PoolWorkArticleView->doWork()
#55 /srv/mediawiki/php-1.35.0-wmf.11/includes/page/WikiPage.php(1262): PoolCounterWork->execute()
#56 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiParse.php(599): WikiPage->getParserOutput(ParserOptions, integer, boolean)
#57 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiParse.php(164): ApiParse->getParsedContent(WikiPage, ParserOptions, boolean, NULL, NULL, boolean)
#58 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiMain.php(1603): ApiParse->execute()
#59 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiMain.php(508): ApiMain->executeAction()
#60 /srv/mediawiki/php-1.35.0-wmf.11/extensions/TextExtracts/includes/ApiQueryExtracts.php(235): ApiMain->execute()
#61 /srv/mediawiki/php-1.35.0-wmf.11/extensions/TextExtracts/includes/ApiQueryExtracts.php(159): TextExtracts\ApiQueryExtracts->parse(WikiPage)
#62 /srv/mediawiki/php-1.35.0-wmf.11/extensions/TextExtracts/includes/ApiQueryExtracts.php(96): TextExtracts\ApiQueryExtracts->getExtract(Title)
#63 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiQuery.php(255): TextExtracts\ApiQueryExtracts->execute()
#64 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiMain.php(1603): ApiQuery->execute()
#65 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiMain.php(539): ApiMain->executeAction()
#66 /srv/mediawiki/php-1.35.0-wmf.11/includes/api/ApiMain.php(510): ApiMain->executeActionWithErrorHandling()
#67 /srv/mediawiki/php-1.35.0-wmf.11/api.php(78): ApiMain->execute()
#68 /srv/mediawiki/w/api.php(3): require(string)
#69 {main}

While the timeout is doing its job, the frequency in which it happens seems unusually high.

In the past I've seen similar errors due to unoptimized custom user js doing massive requests on every page load, but I don't know if it is the case.

Related Objects

Event Timeline

jcrespo created this task.Dec 20 2019, 7:55 AM
Restricted Application added a project: Platform Engineering. · View Herald TranscriptDec 20 2019, 7:55 AM
Restricted Application added subscribers: Stang, Aklapper. · View Herald Transcript
jcrespo renamed this task from Common (>1000/minute) WMFTimeoutException on zhwiki on api call /w/api.php?format=json&action=query&prop=extlinks%7Ccategories%7Crevisions%7Ciwlinks%7Cimages%7Cimageinfo%7Clinks%7Cextracts%7Cinfo%7Clanglinks to Common (>1000/hour) WMFTimeoutException on zhwiki on api call /w/api.php?format=json&action=query&prop=extlinks%7Ccategories%7Crevisions%7Ciwlinks%7Cimages%7Cimageinfo%7Clinks%7Cextracts%7Cinfo%7Clanglinks.Dec 20 2019, 8:00 AM
Urbanecm subscribed.Dec 20 2019, 2:43 PM

Looked up a random reqid, XfyNLQpAADoAAJ6YlqsAAAAD. It is for /zh-mo/%E5%9F%83%E5%8D%A1%E6%B0%B8%E6%B2%B3%E7%95%94%E5%9C%A3%E9%A9%AC%E4%B8%B9. which took for me to load about 50 seconds.

Anomie moved this task from Inbox to Triage Meeting Inbox on the Platform Engineering board.Dec 20 2019, 3:00 PM
Anomie subscribed.

My vague impression from the logstash logs is that it's probably something trying to scrape the site. Unfortunately the logs at that link seem to have neither a useful IP nor a user agent so I can't really support that guess.

The particular trace here is timing out in a page parse via TextExtracts. I note the request is also using rvprop=content&rvparse, which also parses the page, and some of the similar URLs in logstash are timing out in that instead. Possibly the double-parsing is enough to exceed the time limit.

Note rvparse was deprecated in MW 1.30 (f389d14b). Still, though, in the past week it has been used millions of times by IPs and about 14000 times by logged-in users, all of the latter apparently via Huggle. If Huggle is updated to stop using rvparse, I could see proceeding to remove it completely.

As for TextExtracts, it has an official maintainer (Reading Web) but they seem to have effectively abandoned it (T240691#5751885).

Anomie moved this task from Unsorted to Needs details or plan on the MediaWiki-Action-API board.Dec 20 2019, 3:00 PM
jcrespo added a comment.Dec 20 2019, 3:07 PM

I feel that I need to justify myself a bit, because I open many tickets that end up on CPT board (not intentional). Just to be clear, I open them to track them and people are aware of issues generating errors (they are generating alerts on the monitoring system) with the expectation of being triaged and understood, but not all necessarily acted on- if I were you I would only work on those with top priority. If they end up disappearing, ticket could be resolved.

Jdforrester-WMF subscribed.Dec 20 2019, 3:29 PM

If we drop rvparse in production now, Huggle will be briefly broken and fixed in a few days' time, I imagine.

Would that be better than risking stability over the holiday break?

Anomie mentioned this in T241250: Huggle uses deprecated `rvparse`.Dec 20 2019, 4:21 PM

I filed T241250: Huggle uses deprecated `rvparse` to give Huggle developers a heads-up. Ideally they'd make the fix preemptively in a timely manner to free us to drop rvparse without having to temporarily break a popular tool.

Marostegui subscribed.Dec 21 2019, 3:18 PM
Krinkle moved this task from Untriaged to Dec2019/1.35.wmf.10+ on the Wikimedia-production-error board.Jan 8 2020, 6:00 PM
• WDoranWMF closed this task as Resolved.Feb 25 2020, 5:45 PM
• WDoranWMF claimed this task.
• WDoranWMF subscribed.

It looks like the timeouts dropped off after around Feb 9th, closing for now, please re-open if problem is persisting or re-emerging.

Shizhao moved this task from Backlog to Closed on the Chinese-Sites board.Feb 26 2020, 11:37 AM
Aklapper removed a subscriber: Anomie.Oct 16 2020, 5:38 PM
Stang unsubscribed.Nov 14 2021, 12:10 AM
Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL · Credits