Page MenuHomePhabricator
Create Task
Maniphest T304960

PHP Deprecated: Caller … ignored an error originally raised from IndexPager::buildQueryInfo (LogPager, SpecialLog) or ApiQueryUserContribs::execute
Open, HighPublicPRODUCTION ERROR
Actions

Description

Web

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)

Impact

This is a confusing deprecation warning, and causes log noise. What is happening is that we have code (IndexPager::buildQueryInfo) on Special:Contributions and Special:Log that runs a query. This query can sometimes time out after 30 seconds. Those time outs have their own task and is not this task (linked below).

The code is then mishandling the timeout error, and as a result the next code to run a query encounters the Deprecated: Caller … ignored an error originally raised from warning from Rdbms.

This task is about the mishandling of the timeout error, and the subsequent (confusing) deprecation warning.

See also

Details

Request URL
https://commons.wikimedia.org/wiki/Special:Log/File_Upload_Bot_(Magnus_Manske)
SubjectRepoBranchLines +/-
rdbms: clear any "ignored error" in Database::rollback()mediawiki/coremaster+1 -0
Customize query in gerrit

Related Objects

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
Krinkle triaged this task as High priority.Apr 7 2022, 2:58 PM
Krinkle edited projects, added MediaWiki-libs-Rdbms; removed MediaWiki-User-Interface.
Krinkle added subscribers: aaron, Ladsgroup, Krinkle.

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.
Krinkle renamed this task from 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) (db1149) to Caller ignored an error originally raised from IndexPager::buildQueryInfo or ApiQueryUserContribs::execute.Apr 7 2022, 3:05 PM
Krinkle updated the task description. (Show Details)

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.

Krinkle moved this task from Untriaged to Rdbms library on the MediaWiki-libs-Rdbms board.Apr 7 2022, 3:12 PM
Krinkle removed a project: Wikimedia-Slow-DB-Query.

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
gerritbot added a comment.Apr 11 2022, 11:25 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
gerritbot added a comment.Apr 11 2022, 11:54 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
Umherirrender subscribed.Apr 13 2022, 6:24 PM
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

Krinkle added a comment.Apr 13 2022, 7:42 PM
In T304960#7853240, @Umherirrender wrote:

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

  1. T283282: PHP Deprecated: ignored an error originally raised from WikiPage::insertOn (Lock wait timeout exceeded) and,
  2. 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.
Krinkle reopened this task as Open.Jan 7 2025, 6:49 PM
Krinkle removed aaron as the assignee of this task.

This doens't seemed to have fixed the issue, that is, the timeout from places such as Special:Contributions, IndexPager::buildQueryInfo, and ApiQueryUserContribs::execute still are improperly handled, and still cause whatever the "next" query is to emit PHP Deprecated: Caller … ignored an error originally raised from MediaWiki\Pager\IndexPager::buildQueryInfo

Krinkle renamed this task from Caller ignored an error originally raised from IndexPager::buildQueryInfo or ApiQueryUserContribs::execute to PHP Deprecated: Caller … ignored an error originally raised from IndexPager::buildQueryInfo or ApiQueryUserContribs::execute.Jan 7 2025, 6:50 PM
Krinkle merged a task: T378096: PHP Deprecated: Caller from MediaWiki\User\TalkPageNotificationManager::dbCheckNewUserMessages ignored an error originally raised from MediaWiki\Pager\IndexPager::buildQueryInfo (contributions page filtered for namespace or Rev.
Krinkle merged a task: T356733: SQL query times out when searching Special:Log for a tag.
Krinkle added subscribers: dancy, • Urbanecm_WMF, Michael.
Krinkle added a subscriber: Novem_Linguae.
Krinkle updated the task description. (Show Details)Jan 7 2025, 6:53 PM
Krinkle updated the task description. (Show Details)Jan 7 2025, 6:55 PM
Krinkle edited projects, added Wikimedia-Performance-recommendation, Unstewarded-production-error; removed MW-1.39-notes (1.39.0-wmf.7; 2022-04-11), Performance-Team.
Umherirrender unsubscribed.Feb 14 2025, 10:30 PM
Pppery moved this task from Mar 2022 to Older on the Wikimedia-production-error board.Feb 17 2025, 1:19 AM
daniel updated the task description. (Show Details)Mar 10 2025, 3:23 PM
daniel mentioned this in T387648: PHP Deprecated: Caller from … ignored an error originally raised from SpecialRecentChangesLinked.
Krinkle renamed this task from PHP Deprecated: Caller … ignored an error originally raised from IndexPager::buildQueryInfo or ApiQueryUserContribs::execute to PHP Deprecated: Caller … ignored an error originally raised from SpecialLog or ApiQueryUserContribs::execute.Tue, Apr 1, 2:27 AM
Krinkle removed Phatality ID.
Krinkle mentioned this in T307132: PHP Deprecated: Caller … ignored an error originally raised from ApiQueryRecentChanges.
Krinkle renamed this task from PHP Deprecated: Caller … ignored an error originally raised from SpecialLog or ApiQueryUserContribs::execute to PHP Deprecated: Caller … ignored an error originally raised from IndexPager::buildQueryInfo (LogPager, SpecialLog) or ApiQueryUserContribs::execute.Thu, Apr 3, 9:42 AM
Krinkle merged a task: T390748: PHP Deprecated: Caller from MWExceptionHandler::rollbackPrimaryChanges ignored an error originally raised from MediaWiki\Pager\IndexPager::buildQueryInfo (MediaWiki\Pager\LogPager): [1969] Query execution was interrupted (max_s.
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