PHP Warning: Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision: Entity not loaded
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

Error

Request ID: XUH-TQpAAEAAACSEHb0AAACL
Request URL: https://commons.wikimedia.org/wiki/Special:EntityData/M11429447.json?revision=314750378

message

PHP Warning: Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision: Entity not loaded for M11429447 [Called from Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision in /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/Sql/WikiPageEntityRevisionLookup.php at line 148]

trace

#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.34.0-wmf.16/includes/debug/MWDebug.php(309): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.34.0-wmf.16/includes/debug/MWDebug.php(164): MWDebug::sendMessage(string, array, string, integer)
#3 /srv/mediawiki/php-1.34.0-wmf.16/includes/GlobalFunctions.php(1078): MWDebug::warning(string, integer, integer, string)
#4 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/Sql/WikiPageEntityRevisionLookup.php(148): wfLogWarning(string)
#5 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/data-access/src/ByTypeDispatchingEntityRevisionLookup.php(54): Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup->getEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, string)
#6 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/TypeDispatchingEntityRevisionLookup.php(54): Wikibase\DataAccess\ByTypeDispatchingEntityRevisionLookup->getEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, string)
#7 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/CachingEntityRevisionLookup.php(104): Wikibase\Lib\Store\TypeDispatchingEntityRevisionLookup->getEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, string)
#8 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/CachingEntityRevisionLookup.php(87): Wikibase\Lib\Store\CachingEntityRevisionLookup->fetchEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, string)
#9 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/CachingEntityRevisionLookup.php(104): Wikibase\Lib\Store\CachingEntityRevisionLookup->getEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, string)
#10 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/CachingEntityRevisionLookup.php(87): Wikibase\Lib\Store\CachingEntityRevisionLookup->fetchEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, string)
#11 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/repo/includes/LinkedData/EntityDataRequestHandler.php(376): Wikibase\Lib\Store\CachingEntityRevisionLookup->getEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer)
#12 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/repo/includes/LinkedData/EntityDataRequestHandler.php(489): Wikibase\Repo\LinkedData\EntityDataRequestHandler->getEntityRevision(Wikibase\MediaInfo\DataModel\MediaInfoId, integer, boolean)
#13 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/repo/includes/LinkedData/EntityDataRequestHandler.php(263): Wikibase\Repo\LinkedData\EntityDataRequestHandler->showData(WebRequest, OutputPage, string, Wikibase\MediaInfo\DataModel\MediaInfoId, integer)
#14 /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/repo/includes/Specials/SpecialEntityData.php(156): Wikibase\Repo\LinkedData\EntityDataRequestHandler->handleRequest(string, WebRequest, OutputPage)
#15 /srv/mediawiki/php-1.34.0-wmf.16/includes/specialpage/SpecialPage.php(571): Wikibase\Repo\Specials\SpecialEntityData->execute(string)
#16 /srv/mediawiki/php-1.34.0-wmf.16/includes/specialpage/SpecialPageFactory.php(581): SpecialPage->run(string)
#17 /srv/mediawiki/php-1.34.0-wmf.16/includes/MediaWiki.php(296): MediaWiki\Special\SpecialPageFactory->executePath(Title, RequestContext)
#18 /srv/mediawiki/php-1.34.0-wmf.16/includes/MediaWiki.php(892): MediaWiki->performRequest()
#19 /srv/mediawiki/php-1.34.0-wmf.16/includes/MediaWiki.php(523): MediaWiki->main()
#20 /srv/mediawiki/php-1.34.0-wmf.16/index.php(42): MediaWiki->run()
#21 /srv/mediawiki/w/index.php(3): require(string)
#22 {main}

Notes

Blew up after deploy of 1.34.0-wmf.16 to Group1 wikis.

Details

Subject	Repo	Branch	Lines +/-
Simplify and fix WikiPageEntityMetaDataLookup::selectRevisionInformationById()	mediawiki/extensions/Wikibase	master	+47 -51
Do not warn about entity that was not found in WikiPageEntityRevisionLookup	mediawiki/extensions/Wikibase	wmf/1.34.0-wmf.15	+10 -23
Do not warn about entity that was not found in WikiPageEntityRevisionLookup	mediawiki/extensions/Wikibase	wmf/1.34.0-wmf.16	+10 -23
Do not warn about entity that was not found in WikiPageEntityRevisionLookup	mediawiki/extensions/Wikibase	master	+10 -23

Customize query in gerrit

Related Objects
Search...

		Status	Subtype	Assigned	Task
		Resolved	Release	brennen	T220741 1.34.0-wmf.16 deployment blockers
		Resolved	PRODUCTION ERROR	• Mholloway	T229482 PHP Warning: Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision: Entity not loaded

Event Timeline

brennen created this task.Jul 31 2019, 9:04 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJul 31 2019, 9:04 PM

brennen triaged this task as Unbreak Now! priority.Jul 31 2019, 9:04 PM

Restricted Application added a subscriber: Liuxinyu970226. · View Herald TranscriptJul 31 2019, 9:04 PM

brennen added a parent task: T220741: 1.34.0-wmf.16 deployment blockers.Jul 31 2019, 9:05 PM

• Mholloway added a project: WikibaseMediaInfo.Jul 31 2019, 9:07 PM

greg added a project: Wikidata.Jul 31 2019, 9:07 PM

Ladsgroup added subscribers: • alaa_wmde, Ladsgroup, Lydia_Pintscher.Jul 31 2019, 9:08 PM

A fuller message in case the ErrorException is relevant:

/wiki/Special:EntityData/M37306574.json?revision=356182947   ErrorException from line 309 of /srv/mediawiki/php-1.34.0-wmf.16/includes/debug/MWDebug.php: PHP Warning: Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision: Entity not loaded for M37306574 [Called from Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision in /srv/mediawiki/php-1.34.0-wmf.16/extensions/Wikibase/lib/includes/Store/Sql/WikiPageEntityRevisionLookup.php at line 148]

I believe this warning occurs in a scenario that indicates an error in Wikidata but is expected in WikibaseMediaInfo/Structured Data on Commons, namely that an entity ID exists but there is no Wikibase content blob yet associated with it. So these warnings don't indicate a problem per se. It's just that WikibaseMediaInfo changed how it initializes a UI component in a way that hits this code path. The fix is to find a principled way of determining whether we should care about the absence of a content blob before logging the warning.

I agree with @Mholloway; I think this is a case of diverging assumptions being made by the Wikidata and Mediainfo teams.

The source of the error in question is an AJAX request that is fired in the wikibase.entityPage.entityLoaded hook (defined in Wikibase/repo/resources/wikibase.entityPage.entityLoaded.js).

The AJAX request causes Wikibase\Lib\Store\Sql\WikiPageEntityRevisionLookup::getEntityRevision to be called. That method logs a warning if there is no entityRevision for a given entity ID, i.e. if there is no structured data available for it. It looks like the assumption within Wikibase is: if you have gotten to this point and no relevant data actually exists, something is very wrong.

From the perspective of the MediaInfo extension, all that has happened is that we've checked to see if any structured data already existed for a given file, found none, and went on to set up an empty set of UI elements (caption & statement panels). Every visit to a file page will cause that AJAX request to be launched, whether or not there is any data to retrieve.

I'm not sure if the best solution is to change that AJAX request (or the PHP method it eventually triggers) to treat null results as non-errors, or if some other approach should be used to determine whether or not structured data exists for a given file. It would be good to have a discussion with members of both teams. But in the mean time, I don't think this is a real "error", even though it will clutter the logs until we can come up with a solution.

It's a non-trivial amount of logspam - some ~1000 log messages a minute when deployed to Group1 - and will make diagnosing other issues correspondingly more difficult if rolled out.

Per the logspam section of our docs on holding the train, I'm not especially comfortable creating that situation.

egardner mentioned this in T228693: Properties lacking a label in the user's language have the fallback language name appended to the fallback label.Aug 1 2019, 12:07 AM

I'm not sure if the best solution is to change that AJAX request (or the PHP method it eventually triggers) to treat null results as non-errors, or if some other approach should be used to determine whether or not structured data exists for a given file.

IIRC it is a normal situation for a file on commons to have MediaInfo ID, but not to have any actual data. So I think Wikidata should be not issuing warnings in this case. If it's important to issue such warnings for Wikidata, config switch may be added whether to warn on missing data or not - for Wikidata it is highly abnormal, but for Commons it is routine.

WMDE-leszek subscribed.Aug 1 2019, 7:46 AM

In T229482#5383431, @Smalyshev wrote:

I'm not sure if the best solution is to change that AJAX request (or the PHP method it eventually triggers) to treat null results as non-errors, or if some other approach should be used to determine whether or not structured data exists for a given file.

IIRC it is a normal situation for a file on commons to have MediaInfo ID, but not to have any actual data. So I think Wikidata should be not issuing warnings in this case. If it's important to issue such warnings for Wikidata, config switch may be added whether to warn on missing data or not - for Wikidata it is highly abnormal, but for Commons it is routine.

Sounds reasonable. I'm looking for the history/reasons of introducing that warning to see if it is really needed. Will keep you posted

Change 527015 had a related patch set uploaded (by Alaa Sarhan; owner: Alaa Sarhan):
[mediawiki/extensions/Wikibase@master] Do not warn about entity that was not found in WikiPageEntityRevisionLookup

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

gerritbot added a project: Patch-For-Review.Aug 1 2019, 9:25 AM

So from the change that introduced the warning (changing it from a debug message) https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Wikibase/+/134379, there's no sign nor discussion on the patch regarding the reasoning behind it. It could be that introducing redirects in EntityContent was expected to allow more of these cases and it was desirable to see them in our logs. @daniel I don't expect you to really remember now why that was needed back then, but just in case any memories come to mind on the change to this line https://gerrit.wikimedia.org/r/c/mediawiki/extensions/Wikibase/+/134379/48/lib/includes/store/sql/WikiPageEntityLookup.php#104 that'd be helpful.

Meanwhile I'm submitting a patch changing that warning into debug log to get feedback from Wikidata team.

• alaa_wmde added a project: Wikidata-Campsite (Wikidata-Campsite-Iteration-∞ (On Hold)).Aug 1 2019, 9:25 AM

• alaa_wmde moved this task from To Do (prioritised from top to bottom) to Peer Review on the Wikidata-Campsite (Wikidata-Campsite-Iteration-∞ (On Hold)) board.

In a more general note to multimedia team is that this hook is pretty expensive and have some plans to reduce using that in Wikidata (T229221: Reduce usages of wikibase.entityPage.entityLoaded hook in frontend code) for example limiting it to only when someone wants to edit (lazyloading) and I recommend either doing that or using something that's not super expensive.

Looking at the code in the patch, it seems like the error is triggered when a) an ID is known and b) the revision is found but c) no entity could be loaded. Back then, this would have indicated a serious problem, like corrupt serialization or some such.

With MediaInfo, this can now happen legitimately, with no corruption: a) the MediaInfoId is derived from the internal page ID, so it may be known to the system even if no MediaInfo exists on the page. And b) the revision row can be loaded, even if there is no MediaInfo slot on the page. So as far as I can see, failing to load an entity for a known EntityId that refers to an existing page is no longer an exceptional condition worth logging.

My understanding however is incomplete. E.g. if loadRevisionRow joins against the slots table, the above is untrue, because a page with no MediaInfo slot would then return null from that method, and the warning would only be triggered when there slot is indeed there but the entity couldn't be loaded for some reason. That would probably still be logged. Please double-check.

• alaa_wmde mentioned this in T229574: Make logging warning or info of not finding entity for revision configurable .Aug 1 2019, 12:17 PM

Thanks @daniel for the details

My understanding however is incomplete. E.g. if loadRevisionRow joins against the slots table, the above is untrue, because a page with no MediaInfo slot would then return null from that method, and the warning would only be triggered when there slot is indeed there but the entity couldn't be loaded for some reason. That would probably still be logged. Please double-check.

Interesting.. I'll double check what is going on in there (have no clue yet tbh)

Change 527015 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Do not warn about entity that was not found in WikiPageEntityRevisionLookup

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

The patch just merged drops the log level for this to debug, and I see that this follow-up (https://gerrit.wikimedia.org/r/#/c/mediawiki/extensions/Wikibase/+/527090/) changes it again to info. Does dropping the log level below warning suffice to unblock the train?

In T229482#5384191, @Mholloway wrote:

The patch just merged drops the log level for this to debug, and I see that this follow-up (https://gerrit.wikimedia.org/r/#/c/mediawiki/extensions/Wikibase/+/527090/) changes it again to info. Does dropping the log level below warning suffice to unblock the train?

As far as the error reported here is concerned, it should suffice to unbloack the train.

Maintenance_bot removed a project: Patch-For-Review.Aug 1 2019, 1:10 PM

Change 527098 had a related patch set uploaded (by Mholloway; owner: Alaa Sarhan):
[mediawiki/extensions/Wikibase@wmf/1.34.0-wmf.16] Do not warn about entity that was not found in WikiPageEntityRevisionLookup

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

gerritbot added a project: Patch-For-Review.Aug 1 2019, 1:18 PM

Change 527099 had a related patch set uploaded (by Mholloway; owner: Alaa Sarhan):
[mediawiki/extensions/Wikibase@wmf/1.34.0-wmf.15] Do not warn about entity that was not found in WikiPageEntityRevisionLookup

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

Confirmed on the Beta Cluster that this is working as intended.

ReleaseTaggerBot added a project: MW-1.34-notes (1.34.0-wmf.17; 2019-08-06).Aug 1 2019, 2:01 PM

Thanks all. I'll roll this forward shortly.

Change 527098 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@wmf/1.34.0-wmf.16] Do not warn about entity that was not found in WikiPageEntityRevisionLookup

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

Change 527099 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@wmf/1.34.0-wmf.15] Do not warn about entity that was not found in WikiPageEntityRevisionLookup

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

ReleaseTaggerBot edited projects, added MW-1.34-notes (1.34.0-wmf.16; 2019-07-30); removed MW-1.34-notes (1.34.0-wmf.17; 2019-08-06).Aug 1 2019, 3:00 PM

Maintenance_bot removed a project: Patch-For-Review.Aug 1 2019, 3:10 PM

Mentioned in SAL (#wikimedia-operations) [2019-08-01T15:13:04Z] <mholloway-shell@deploy1001> Synchronized php-1.34.0-wmf.16/extensions/Wikibase: Do not warn about entity that was not found in WikiPageEntityRevisionLookup (T229482) (duration: 01m 20s)

Mentioned in SAL (#wikimedia-operations) [2019-08-01T15:16:26Z] <mholloway-shell@deploy1001> Synchronized php-1.34.0-wmf.15/extensions/Wikibase: Do not warn about entity that was not found in WikiPageEntityRevisionLookup (T229482) (duration: 01m 14s)

• Mholloway closed this task as Resolved.Aug 1 2019, 3:31 PM

• Mholloway claimed this task.

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

• alaa_wmde moved this task from Peer Review to Done on the Wikidata-Campsite (Wikidata-Campsite-Iteration-∞ (On Hold)) board.Aug 30 2019, 2:40 PM

• alaa_wmde mentioned this in T234336: Set error report for missing entity in main slot to warning.Oct 1 2019, 3:08 PM

Maintenance_bot moved this task from incoming to in progress on the Wikidata board.Oct 25 2019, 4:13 AM

Change 661956 had a related patch set uploaded (by Lucas Werkmeister (WMDE); owner: Lucas Werkmeister (WMDE)):
[mediawiki/extensions/Wikibase@master] Simplify and fix WikiPageEntityMetaDataLookup::selectRevisionInformationById()

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

gerritbot added a project: Patch-For-Review.Feb 5 2021, 4:07 PM

Change 661956 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Simplify and fix WikiPageEntityMetaDataLookup::selectRevisionInformationById()