Caller ignored an error originally raised from IndexPager::buildQueryInfo or ApiQueryUserContribs::execute
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Assigned To

Authored By

	hashar
	Mar 29 2022, 2:46 PM

Description

Web

mwversion: 1.39.0-wmf.4
reqId: 8d190446-8160-4261-8077-c1ff88b72682
Find reqId in Logstash

normalized_message

[{reqId}] {exception_url}   PHP Deprecated: Caller from LinkBatch::doQuery (for Skin::preloadExistence) ignored an error originally raised from IndexPager::buildQueryInfo (LogPager): [1969] Query execution was interrupted (max_statement_time exceeded) (db

original query trace

#8 /srv/mediawiki/php-1.39.0-wmf.4/includes/pager/IndexPager.php(459): Wikimedia\Rdbms\DBConnRef->select(array, array, array, string, array, array)
#9 /srv/mediawiki/php-1.39.0-wmf.4/includes/pager/IndexPager.php(283): IndexPager->reallyDoQuery(string, integer, boolean)
#10 /srv/mediawiki/php-1.39.0-wmf.4/includes/logging/LogPager.php(490): IndexPager->doQuery()
#11 /srv/mediawiki/php-1.39.0-wmf.4/includes/pager/IndexPager.php(611): LogPager->doQuery()
#12 /srv/mediawiki/php-1.39.0-wmf.4/includes/specials/SpecialLog.php(282): IndexPager->getBody()
#13 /srv/mediawiki/php-1.39.0-wmf.4/includes/specials/SpecialLog.php(163): SpecialLog->show(FormOptions, array)
#14 /srv/mediawiki/php-1.39.0-wmf.4/includes/specialpage/SpecialPage.php(671): SpecialLog->execute(string)

exception trace

#11 /srv/mediawiki/php-1.39.0-wmf.4/includes/cache/LinkBatch.php(238): LinkBatch->doQuery()
#12 /srv/mediawiki/php-1.39.0-wmf.4/includes/cache/LinkBatch.php(212): LinkBatch->executeInto(LinkCache)
#13 /srv/mediawiki/php-1.39.0-wmf.4/includes/skins/Skin.php(457): LinkBatch->execute()
#14 /srv/mediawiki/php-1.39.0-wmf.4/includes/skins/Skin.php(301): Skin->preloadExistence()
#15 /srv/mediawiki/php-1.39.0-wmf.4/includes/skins/SkinTemplate.php(146): Skin->initPage(OutputPage)
#16 /srv/mediawiki/php-1.39.0-wmf.4/includes/OutputPage.php(2808): SkinTemplate->outputPage()
#17 /srv/mediawiki/php-1.39.0-wmf.4/includes/exception/MWExceptionRenderer.php(157): OutputPage->output()
..
#22 /srv/mediawiki/php-1.39.0-wmf.4/index.php(53): MediaWiki->run()

API

original query trace

ApiQueryUserContribs::execute

exception trace,lines=10
#10 /srv/mediawiki/php-1.39.0-wmf.4/includes/block/DatabaseBlock.php(297): Wikimedia\Rdbms\DBConnRef->select(array, array, string, string, array, array)
#11 /srv/mediawiki/php-1.39.0-wmf.4/includes/block/DatabaseBlock.php(892): MediaWiki\Block\DatabaseBlock::newLoad(User, integer, boolean, string)
..
#16 /srv/mediawiki/php-1.39.0-wmf.4/includes/MediaWiki.php(789): MediaWiki\Block\BlockManager->trackBlockWithCookie(User, WebResponse)
#17 /srv/mediawiki/php-1.39.0-wmf.4/includes/api/ApiMain.php(897): MediaWiki::preOutputCommit(DerivativeContext)
#18 /srv/mediawiki/php-1.39.0-wmf.4/includes/api/ApiMain.php(842): ApiMain->executeActionWithErrorHandling()
#19 /srv/mediawiki/php-1.39.0-wmf.4/api.php(90): ApiMain->execute()
#20 /srv/mediawiki/php-1.39.0-wmf.4/api.php(45): wfApiMain()
#21 /srv/mediawiki/w/api.php(3): require(string)

Notes

Two hits, the DB query got killed cause it took longer than 30 seconds.

Details

Request URL: https://commons.wikimedia.org/wiki/Special:Log/File_Upload_Bot_(Magnus_Manske)

	Subject	Repo	Branch	Lines +/-
	rdbms: clear any "ignored error" in Database::rollback()	mediawiki/core	master	+1 -0

Customize query in gerrit

Related Objects

Mentioned Here: T283282: PHP Deprecated: ignored an error originally raised from WikiPage::insertOn (Lock wait timeout exceeded)
T305038: PHP Deprecated: Caller from MediaWiki\Block\DatabaseBlock::newLoad ignored an error originally raised from ApiQueryUserContribs::execute: [1969] Query execution was interrupted (max_statement_time exceeded) (db1179)
T304085: PHP Deprecated: Caller ignored an error raised from SpecialRecentChanges::doMainQuery (max_statement_time exceeded)

Event Timeline

hashar created this task.Mar 29 2022, 2:46 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptMar 29 2022, 2:46 PM

Reedy added a project: Wikimedia-Slow-DB-Query.Mar 29 2022, 3:41 PM

Krinkle moved this task from Untriaged to Mar 2022 on the Wikimedia-production-error board.Apr 7 2022, 2:46 PM

Unlike T304085, this stack (SpecialLog, LogPager, etc.) do not appear to have a "bad" catch clause that fails to handle the error. I'm not sure what's going on in this one?

\cc @aaron @Ladsgroup

Restricted Application added a project: Performance-Team. · View Herald TranscriptApr 7 2022, 2:58 PM

Krinkle merged a task: T305038: PHP Deprecated: Caller from MediaWiki\Block\DatabaseBlock::newLoad ignored an error originally raised from ApiQueryUserContribs::execute: [1969] Query execution was interrupted (max_statement_time exceeded) (db1179).Apr 7 2022, 3:01 PM

Krinkle added a subscriber: Zabe.

I've merged this with the seemingly unrelated API query T305038. The category of issues for which this error message exists would normally mean that these are separate instances of the same mistake.

However, in this rare case it appears we have an issue where code that isn't catching the error (it goes all the way up to the top-level error handler) is still blamed for failing. That is a general infrastructure problem, and a significant regression if my analysis is correct.

Untagging slow-query, this error isn't mainly due to timeout. (For this particular query we don't consider that an infra bug currently). Rather it's an error as result if mishandled timeout.

aaron moved this task from Inbox, needs triage to Doing: Prio Interrupt on the Performance-Team board.Apr 11 2022, 6:58 PM

Change 779140 had a related patch set uploaded (by Aaron Schulz; author: Aaron Schulz):

[mediawiki/core@master] rdbms: clear any "ignored error" in Database::rollback()

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

gerritbot added a project: Patch-For-Review.Apr 11 2022, 11:25 PM

Change 779140 merged by jenkins-bot:

[mediawiki/core@master] rdbms: clear any "ignored error" in Database::rollback()

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

ReleaseTaggerBot added a project: MW-1.39-notes (1.39.0-wmf.7; 2022-04-11).Apr 12 2022, 12:00 AM

Maintenance_bot removed a project: Patch-For-Review.Apr 12 2022, 12:30 AM

hashar unsubscribed.Apr 12 2022, 8:42 AM

In T304960#7846913, @gerritbot wrote:

Change 779140 merged by jenkins-bot:

[mediawiki/core@master] rdbms: clear any "ignored error" in Database::rollback()

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

Does this fix also fix tasks with the same error message "ignored an error originally raised from"?
That are T283282 and T304085

In T304960#7853240, @Umherirrender wrote:

Does this fix also fix tasks with the same error message "ignored an error originally raised from"?
That are

T283282: PHP Deprecated: ignored an error originally raised from WikiPage::insertOn (Lock wait timeout exceeded) and,

T304085: PHP Deprecated: Caller ignored an error raised from SpecialRecentChanges::doMainQuery (max_statement_time exceeded)

Not exactly.

In T304960#7838495, @Krinkle wrote:

The category of issues for which this error message exists would normally mean that these are separate instances of the same mistake.

T304085 is due to a mistake specific to RecentChanges where the issue is exaclty as the warning says: That specific method is ignoring the error and not handling it correctly.

However T283282 looks like it might indeed be another victim of the same false positive that caused this warning to appear when the code in question didn't do anything wrong. We'll have to see whether that changes anything next week.

aaron closed this task as Resolved.Apr 19 2022, 5:20 PM

aaron claimed this task.

Caller ignored an error originally raised from IndexPager::buildQueryInfo or ApiQueryUserContribs::executeClosed, ResolvedPublicPRODUCTION ERRORActions