MediaWiki version: 1.35.0-wmf.32
Method OOUI\Element::__toString() must not throw an exception, caught WMFTimeoutException: the execution time limit of 60 seconds was exceeded
Why is this triggering OOUI rendering at all in the api query
#0 /srv/mediawiki/php-1.35.0-wmf.32/vendor/oojs/oojs-ui/php/Tag.php(468): unknown()
#1 /srv/mediawiki/php-1.35.0-wmf.32/vendor/oojs/oojs-ui/php/Element.php(264): OOUI\Tag->toString()
#2 /srv/mediawiki/php-1.35.0-wmf.32/vendor/oojs/oojs-ui/php/Tag.php(494): OOUI\Element->toString()
#3 /srv/mediawiki/php-1.35.0-wmf.32/vendor/oojs/oojs-ui/php/Tag.php(468): OOUI\Tag->__toString()
#4 /srv/mediawiki/php-1.35.0-wmf.32/vendor/oojs/oojs-ui/php/Element.php(264): OOUI\Tag->toString()
#5 /srv/mediawiki/php-1.35.0-wmf.32/extensions/WikibaseMediaInfo/src/View/MediaInfoEntityTermsView.php(94): OOUI\Element->toString()
#6 /srv/mediawiki/php-1.35.0-wmf.32/extensions/WikibaseMediaInfo/src/View/MediaInfoView.php(86): Wikibase\MediaInfo\View\MediaInfoEntityTermsView->getHtml()
#7 /srv/mediawiki/php-1.35.0-wmf.32/extensions/WikibaseMediaInfo/src/View/MediaInfoView.php(79): Wikibase\MediaInfo\View\MediaInfoView->getCaptionsHtml()
#8 /srv/mediawiki/php-1.35.0-wmf.32/extensions/Wikibase/repo/includes/ParserOutput/FullEntityParserOutputGenerator.php(233): Wikibase\MediaInfo\View\MediaInfoView->getContent()
#9 /srv/mediawiki/php-1.35.0-wmf.32/extensions/Wikibase/repo/includes/ParserOutput/FullEntityParserOutputGenerator.php(161): Wikibase\Repo\ParserOutput\FullEntityParserOutputGenerator->addHtmlToParserOutput()
#10 /srv/mediawiki/php-1.35.0-wmf.32/extensions/Wikibase/repo/includes/ParserOutput/StatsdTimeRecordingEntityParserOutputGenerator.php(48): Wikibase\Repo\ParserOutput\FullEntityParserOutputGenerator->getParserOutput()
#11 /srv/mediawiki/php-1.35.0-wmf.32/extensions/Wikibase/repo/includes/Content/EntityContent.php(242): Wikibase\Repo\ParserOutput\StatsdTimeRecordingEntityParserOutputGenerator->getParserOutput()
#12 /srv/mediawiki/php-1.35.0-wmf.32/extensions/Wikibase/repo/includes/Content/EntityContent.php(181): Wikibase\EntityContent->getParserOutputFromEntityView()
#13 /srv/mediawiki/php-1.35.0-wmf.32/includes/Revision/RenderedRevision.php(267): Wikibase\EntityContent->getParserOutput()
#14 /srv/mediawiki/php-1.35.0-wmf.32/includes/Revision/RenderedRevision.php(236): MediaWiki\Revision\RenderedRevision->getSlotParserOutputUncached()
#15 /srv/mediawiki/php-1.35.0-wmf.32/includes/Revision/RevisionRenderer.php(230): MediaWiki\Revision\RenderedRevision->getSlotParserOutput()
#16 /srv/mediawiki/php-1.35.0-wmf.32/includes/Revision/RevisionRenderer.php(152): MediaWiki\Revision\RevisionRenderer->combineSlotOutput()
#17 [internal function]: MediaWiki\Revision\RevisionRenderer->MediaWiki\Revision\{closure}()
#18 /srv/mediawiki/php-1.35.0-wmf.32/includes/Revision/RenderedRevision.php(198): call_user_func()
#19 /srv/mediawiki/php-1.35.0-wmf.32/includes/filerepo/file/LocalFile.php(2185): MediaWiki\Revision\RenderedRevision->getRevisionParserOutput()
#20 /srv/mediawiki/php-1.35.0-wmf.32/extensions/CommonsMetadata/src/DataCollector.php(290): LocalFile->getDescriptionText()
#21 /srv/mediawiki/php-1.35.0-wmf.32/extensions/CommonsMetadata/src/DataCollector.php(98): CommonsMetadata\DataCollector->getDescriptionText()
#22 /srv/mediawiki/php-1.35.0-wmf.32/extensions/CommonsMetadata/src/HookHandler.php(70): CommonsMetadata\DataCollector->collect()
#23 /srv/mediawiki/php-1.35.0-wmf.32/includes/HookContainer/HookContainer.php(320): CommonsMetadata\HookHandler::onGetExtendedMetadata()
#24 /srv/mediawiki/php-1.35.0-wmf.32/includes/HookContainer/HookContainer.php(132): MediaWiki\HookContainer\HookContainer->callLegacyHook()
#25 /srv/mediawiki/php-1.35.0-wmf.32/includes/Hooks.php(136): MediaWiki\HookContainer\HookContainer->run()
#26 /srv/mediawiki/php-1.35.0-wmf.32/includes/media/FormatMetadata.php(1710): Hooks::run()
#27 /srv/mediawiki/php-1.35.0-wmf.32/includes/media/FormatMetadata.php(1627): FormatMetadata->getExtendedMetadataFromHook()
#28 /srv/mediawiki/php-1.35.0-wmf.32/includes/api/ApiQueryImageInfo.php(576): FormatMetadata->fetchExtendedMetadata()
#29 /srv/mediawiki/php-1.35.0-wmf.32/includes/api/ApiQueryImageInfo.php(184): ApiQueryImageInfo::getInfo()
#30 /srv/mediawiki/php-1.35.0-wmf.32/includes/api/ApiQuery.php(263): ApiQueryImageInfo->execute()
#31 /srv/mediawiki/php-1.35.0-wmf.32/includes/api/ApiMain.php(1580): ApiQuery->execute()
#32 /srv/mediawiki/php-1.35.0-wmf.32/includes/api/ApiMain.php(523): ApiMain->executeAction()
#33 /srv/mediawiki/php-1.35.0-wmf.32/includes/api/ApiMain.php(494): ApiMain->executeActionWithErrorHandling()
#34 /srv/mediawiki/php-1.35.0-wmf.32/api.php(84): ApiMain->execute()
#35 /srv/mediawiki/w/api.php(3): require()Looks like the API response is generating HTML for things like descriptions, and some of these chunks of HTML contain markup related to Wikibase (for example, this wikidata-aware table is included as a string of HTML in the response above). Could it be that the metadata template (or some custom template) on one of the file pages in these results is attempting to pull in data from MediaInfo and breaking?
@egardner From what I can see, what happens is this API request is asking for structured data and other metadata relating to media files on Commons. As part of serving that request, the MW core call to FormatMetadata->fetchExtendedMetadata is hooked into by the CommonsMetadata extension.
The CommonsMetadata extension gets most of its data not from data in a JSON slot (like Wikibase), but instead by parsing the file page wikitext and and then querying the resulting DOM of the parser output HTML for elements like <span class="licensetpl_short" style="display:none;">CC BY-SA 3.0</span>. This is how it knows the license of the file, and among other consumers, this is shown in the Mediaviewer lightboxes, on web and in apps. It is generally not expected for a web request to parse multiple wiki pages (given the size and complexity of wikitext, this is generally something we dedicate a single request for, be it a save edit, or a cache-missed page view). But when an API internally relies on ParserOutput, this means it can end up having to parse many (possibly unpopular) files and thus basically consistently unavailable to apps and API consumers if it has to parse in order to get it.
That by itself is a significant problem and should be causing a number of timeouts in production reguarly. But, the trace we see in this task shows something else, which is that this on-demand parse from CommonsMetadata for the file description page is also causing WikibaseMediaInfo to try to render its JSON slot into a UI and calling into relatively slow OOUI server-rendering code (esp when an item has many translations or despictions). That probably doesn't/shouldn't need to happen when parsing wikitext for the purpose of saving edits on Commons, or extracting metadata, and instead only happen lazily on the other end when viewing an article similar to the Skin. On the other hand, given its slowness it does benefit from caching in the ParserCache, which is what happens today. So maybe that's the better compromise as-is, and maybe we just need to prioritise phasing out the way CommonsMetadata works today in favour of storing this consistenly in secondary tables and/or different slots so that it is always available for all files instead of only cached.
Is this error still happening? I'm still learning my way around Logstash but I was only able to find two occurrences in the last year or so. I was able to successfully run the original API query listed above just now – the first run took a while, but no errors.
@egardner You might have to adjust the Logstash query to allow for a little more varation. It's not always exactly Element::__toString() on the top of the call stack when the timeout is reached. It might also be in a different part of OOUI, such as Tag->appendContent() or HorizontalLayout->toString(), etc.
I did a search for exception.trace:"MediaInfoView.php" on the mediawiki-errors dashboard and found 125 timeouts in the last month. Note that the retention period for our Logstash is 3 months, so queries further back naturally yield no results.