Page MenuHomePhabricator
Create Task
Maniphest T225103

LBFactory destructor causes unexpected exception at shutdown
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

Error

Request ID: XPfMttBQm20AAFgv6gQAAAAI

message
Wikimedia\Rdbms\DBUnexpectedError: DB connection was already closed.

#0 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/database/Database.php(3940): Wikimedia\Rdbms\Database->assertHasConnectionHandle()
#1 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1434): Wikimedia\Rdbms\Database->commit(string, string)
#2 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1807): Closure$Wikimedia\Rdbms\LoadBalancer::commitMasterChanges(Wikimedia\Rdbms\DatabaseMysqli)
#3 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1440): Wikimedia\Rdbms\LoadBalancer->forEachOpenMasterConnection(Closure$Wikimedia\Rdbms\LoadBalancer::commitMasterChanges;2625)
#4 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(227): Wikimedia\Rdbms\LoadBalancer->commitMasterChanges(string)
#5 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactoryMulti.php(401): Closure$Wikimedia\Rdbms\LBFactory::forEachLBCallMethod(Wikimedia\Rdbms\LoadBalancer, string, array)
#6 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(230): Wikimedia\Rdbms\LBFactoryMulti->forEachLB(Closure$Wikimedia\Rdbms\LBFactory::forEachLBCallMethod;2416, array)
#7 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(282): Wikimedia\Rdbms\LBFactory->forEachLBCallMethod(string, array)
#8 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(187): Wikimedia\Rdbms\LBFactory->commitMasterChanges(string)
#9 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(160): Wikimedia\Rdbms\LBFactory->shutdown(integer)
#10 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(744): Wikimedia\Rdbms\LBFactory->destroy()
#11 [internal function]: Wikimedia\Rdbms\LBFactory->__destruct()

.. and as side-effect:

message
PHP Warning:
Destructor threw an object exception: exception 'Wikimedia\Rdbms\DBTransactionError'

Wikimedia\Rdbms\DBTransactionError:
Wikimedia\Rdbms\LBFactory::shutdown: Commit failed on server(s) 10.64.16.79: DB connection was already closed.

/srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/loadbalancer/LoadBalancer.php:1445
Stack trace:
#0 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(227): Wikimedia\Rdbms\LoadBalancer->commitMasterChanges()
#1 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactoryMulti.php(401): Closure$Wikimedia\Rdbms\LBFactory::forEachLBCallMethod()
#2 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(230): Wikimedia\Rdbms\LBFactoryMulti->forEachLB()
#3 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(282): Wikimedia\Rdbms\LBFactory->forEachLBCallMethod()
#4 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(187): Wikimedia\Rdbms\LBFactory->commitMasterChanges()
#5 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(160): Wikimedia\Rdbms\LBFactory->shutdown()
#6 /srv/mediawiki/php-1.34.0-wmf.8/includes/libs/rdbms/lbfactory/LBFactory.php(744): Wikimedia\Rdbms\LBFactory->destroy()
#7 (): Wikimedia\Rdbms\LBFactory->__destruct()

Impact

No user-visible impact. The issue happens during request shut-down and the error is recoverable. The implicit side-effect
that happens as a result of this error happens to be the correct behaviour. We tried to close a connection that was already closed, and don't mind that it was already closed.

Notes

In production, this has been seen in Logstash for at least 30 days since 1.34-wmf.4:

Screenshot 2019-06-05 at 15.41.28.png (933×1 px, 71 KB)

For labswiki, this used to never happen, but has a very significant spike as of May 25:

Screenshot 2019-06-05 at 15.42.38.png (783×1 px, 69 KB)

Details

SubjectRepoBranchLines +/-
rdbms: make LBFactory close/rollback dangling handles like LoadBalancermediawiki/coremaster+0 -1
Clean up DeferredUpdates transaction handlingmediawiki/corewmf/1.34.0-wmf.14+18 -15
Clean up DeferredUpdates transaction handlingmediawiki/coremaster+18 -15
Customize query in gerrit

Related Objects

Event Timeline

Krinkle created this task.Jun 5 2019, 2:37 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 5 2019, 2:37 PM
Krinkle moved this task from Untriaged to Rdbms library on the MediaWiki-libs-Rdbms board.Jun 5 2019, 2:38 PM
Krinkle updated the task description. (Show Details)Jun 5 2019, 2:43 PM
Krinkle moved this task from Untriaged to Older on the Wikimedia-production-error board.
Krinkle added a comment.Jun 5 2019, 2:48 PM

Might be related to T142079: periodic spike of MW exceptions "DB connection was already closed or the connection dropped.".

aaron claimed this task.Jun 6 2019, 11:40 AM
aaron triaged this task as Medium priority.
aaron moved this task from Inbox, needs triage to To-do: Goals prioritized current Quarter on the Performance-Team board.
Krinkle added a comment.Jun 20 2019, 5:19 PM

Seems related: rMW143333b172cd: rdbms: do not close the connection in LoadBalancerSingle::__destruct / https://gerrit.wikimedia.org/r/517350.

Not exactly the same though (commit is LoadBalancer, this bug is LBFactory), but might need a similar change?

aaron added a comment.Jun 22 2019, 5:56 PM
In T225103#5271836, @Krinkle wrote:

Seems related: rMW143333b172cd: rdbms: do not close the connection in LoadBalancerSingle::__destruct / https://gerrit.wikimedia.org/r/517350.

Not exactly the same though (commit is LoadBalancer, this bug is LBFactory), but might need a similar change?

That was an exceptional case of the connection being injected. Regular LBs should still close up on destruction.

aaron merged a task: T228436: web request timeout after 200 seconds due to Wikimedia\Rdbms\LBFactory->__destruct() > Wikimedia\Rdbms\LBFactory->commitMasterChanges().Jul 18 2019, 8:15 PM
aaron added subscribers: hashar, aaron, Agusbou2015 and 3 others.
gerritbot added a comment.Jul 18 2019, 8:16 PM

Change 524320 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] Clean up DeferredUpdates transaction handling

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

gerritbot added a project: Patch-For-Review.Jul 18 2019, 8:16 PM
aaron added a parent task: T220739: 1.34.0-wmf.14 deployment blockers.Jul 18 2019, 8:36 PM
gerritbot added a comment.Jul 18 2019, 10:07 PM

Change 524364 had a related patch set uploaded (by Krinkle; owner: Aaron Schulz):
[mediawiki/core@wmf/1.34.0-wmf.14] Clean up DeferredUpdates transaction handling

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

gerritbot added a comment.Jul 18 2019, 10:19 PM

Change 524320 merged by jenkins-bot:
[mediawiki/core@master] Clean up DeferredUpdates transaction handling

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

ReleaseTaggerBot added a project: MW-1.34-notes (1.34.0-wmf.15; 2019-07-23).Jul 18 2019, 11:00 PM
Jdforrester-WMF subscribed.Jul 18 2019, 11:17 PM

Is this still a train blocker?

aaron added a comment.Jul 19 2019, 6:11 AM
In T225103#5348415, @Jdforrester-WMF wrote:

Is this still a train blocker?

I assume not, unless some further problems emerge.

zeljkofilipin subscribed.Jul 19 2019, 8:27 AM

If this is not a train blocker, please remove T220739 from parent tasks. If it is a blocker, priority should be set to UBN.

hashar mentioned this in T228436: web request timeout after 200 seconds due to Wikimedia\Rdbms\LBFactory->__destruct() > Wikimedia\Rdbms\LBFactory->commitMasterChanges().Jul 19 2019, 8:48 AM
Jdforrester-WMF removed a parent task: T220739: 1.34.0-wmf.14 deployment blockers.Jul 19 2019, 4:08 PM
gerritbot added a comment.Jul 22 2019, 3:47 PM

Change 524364 abandoned by Krinkle:
Clean up DeferredUpdates transaction handling

Reason:
Will go out in the wmf.15 train

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

Maintenance_bot removed a project: Patch-For-Review.Jul 22 2019, 4:11 PM
Krinkle merged a task: T203700: Fix "Transaction round stage must be 'cursory' (not 'within-rollback')" from LBFactory/DeferredUpdates.Jul 23 2019, 5:45 PM
Restricted Application added a project: Platform Engineering. · View Herald TranscriptJul 23 2019, 5:45 PM
Krinkle removed a project: Platform Engineering.Jul 23 2019, 5:45 PM
gerritbot added a comment.Aug 9 2019, 5:17 AM

Change 529199 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] rdbms: make LBFactory close/rollback dangling handles like LoadBalancer

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

gerritbot added a project: Patch-For-Review.Aug 9 2019, 5:17 AM
Krinkle moved this task from To-do: Goals prioritized current Quarter to Doing (old) on the Performance-Team board.Aug 24 2019, 10:44 PM
gerritbot added a comment.Aug 24 2019, 11:15 PM

Change 529199 merged by jenkins-bot:
[mediawiki/core@master] rdbms: make LBFactory close/rollback dangling handles like LoadBalancer

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

Maintenance_bot removed a project: Patch-For-Review.Aug 25 2019, 12:10 AM
aaron closed this task as Resolved.Aug 25 2019, 1:18 AM
• LarsWirzenius unsubscribed.Aug 28 2019, 10:17 AM
Krinkle mentioned this in T231443: Uncaught Wikimedia\Rdbms\DBUnexpectedError: Wikimedia\Rdbms\Database::close: mass commit/rollback of peer transaction required (DBO_TRX set).Aug 28 2019, 10:12 PM
• mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:06 PM
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