Page MenuHomePhabricator
Create Task
Maniphest T187942

Replication lag detection broken in wmf.22
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

After rolling out 1.31.0-wmf.22 to group1 wikis I immediately saw ~200 errors per second like the following:

Exception: Database is read-only: The database has been automatically locked while the replica database servers catch up to the master.
File : Line: /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/Database.php:920

Stack:

#0 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/Database.php(1622): Wikimedia\Rdbms\Database->query(string, string)
#1 [internal function]: Wikimedia\Rdbms\Database->insert(string, array, string)
#2 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/DBConnRef.php(49): call_user_func_array(array, array)
#3 /srv/mediawiki/php-1.31.0-wmf.22/includes/libs/rdbms/database/DBConnRef.php(312): Wikimedia\Rdbms\DBConnRef->__call(string, array)
#4 /srv/mediawiki/php-1.31.0-wmf.22/includes/externalstore/ExternalStoreDB.php(97): Wikimedia\Rdbms\DBConnRef->insert(string, array, string)
#5 /srv/mediawiki/php-1.31.0-wmf.22/includes/externalstore/ExternalStore.php(194): ExternalStoreDB->store(string, string)
#6 /srv/mediawiki/php-1.31.0-wmf.22/includes/externalstore/ExternalStore.php(167): ExternalStore::insertWithFallback(array, string, array)
#7 /srv/mediawiki/php-1.31.0-wmf.22/includes/Storage/SqlBlobStore.php(218): ExternalStore::insertToDefault(string)
#8 /srv/mediawiki/php-1.31.0-wmf.22/includes/Storage/RevisionStore.php(361): MediaWiki\Storage\SqlBlobStore->storeBlob(string, array)
#9 /srv/mediawiki/php-1.31.0-wmf.22/includes/Revision.php(1097): MediaWiki\Storage\RevisionStore->insertRevisionOn(MediaWiki\Storage\MutableRevisionRecord, Wikimedia\Rdbms\DatabaseMysqli)
#10 /srv/mediawiki/php-1.31.0-wmf.22/includes/page/WikiPage.php(1918): Revision->insertOn(Wikimedia\Rdbms\DatabaseMysqli)
#11 /srv/mediawiki/php-1.31.0-wmf.22/includes/page/WikiPage.php(1673): WikiPage->doCreate(WikitextContent, integer, User, string, array)
#12 /srv/mediawiki/php-1.31.0-wmf.22/includes/filerepo/file/LocalFile.php(1653): WikiPage->doEditContent(WikitextContent, string, integer, boolean, User)
#13 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/AutoCommitUpdate.php(42): Closure$LocalFile::recordUpload2(Wikimedia\Rdbms\DatabaseMysqli, string)
#14 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/DeferredUpdates.php(259): AutoCommitUpdate->doUpdate()
#15 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/DeferredUpdates.php(210): DeferredUpdates::runUpdate(AutoCommitUpdate, Wikimedia\Rdbms\LBFactoryMulti, string, integer)
#16 /srv/mediawiki/php-1.31.0-wmf.22/includes/deferred/DeferredUpdates.php(127): DeferredUpdates::execute(array, string, integer)
#17 /srv/mediawiki/php-1.31.0-wmf.22/includes/MediaWiki.php(606): DeferredUpdates::doUpdates(string, integer)
#18 /srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php(557): MediaWiki::preOutputCommit(DerivativeContext)
#19 /srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php(513): ApiMain->executeActionWithErrorHandling()
#20 /srv/mediawiki/php-1.31.0-wmf.22/api.php(94): ApiMain->execute()
#21 /srv/mediawiki/w/api.php(3): include(string)
#22 {main}

Oddly, it also seems to have triggered a ton of Notice: Array to string conversion in /srv/mediawiki/php-1.31.0-wmf.21/includes/libs/rdbms/database/position/MySQLMasterPos.php on line 41 but it indicates the old branch, wmf.21 so I'm not sure how these are related.

Rolling back to wmf.21 caused the errors to immediately cease.

Details

SubjectRepoBranchLines +/-
rdbms: make DBMasterPos implement Serializablemediawiki/coremaster+42 -3
rdbms: make DBMasterPos implement Serializablemediawiki/corewmf/1.31.0-wmf.22+42 -3
Make LocalFile check early if the revision store is availablemediawiki/coremaster+52 -3
Make LocalFile check early if the revision store is availablemediawiki/corewmf/1.31.0-wmf.22+52 -3
Add ExternalStoreMedium::isReadOnly() methodmediawiki/coremaster+43 -31
Add ExternalStoreMedium::isReadOnly() methodmediawiki/corewmf/1.31.0-wmf.22+43 -31
Check read-only mode in ApiContentTranslationSavemediawiki/extensions/ContentTranslationmaster+5 -0
Add various read-only mode checksmediawiki/extensions/Echomaster+15 -2
Customize query in gerrit

Revisions and Commits

rMW MediaWiki
Concern RaisedrMWa114bd9f4d9d rdbms: avoid "SHOW MASTER/SLAVE STATUS" queries in the GTID case

Related Objects
Search...

StatusSubtypeAssignedTask
 ResolvedRelease• mmodellT183961 1.31.0-wmf.22 deployment blockers
 ResolvedPRODUCTION ERRORaaronT187942 Replication lag detection broken in wmf.22

Event Timeline

• mmodell created this task.Feb 21 2018, 8:51 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptFeb 21 2018, 8:51 PM
• mmodell triaged this task as High priority.Feb 21 2018, 8:51 PM
• mmodell added a parent task: T183961: 1.31.0-wmf.22 deployment blockers.

Assigned to @aaron because he's the only author to touch the code in question.

Stashbot subscribed.Feb 21 2018, 8:53 PM

Mentioned in SAL (#wikimedia-operations) [2018-02-21T20:53:42Z] <twentyafterfour> MediaWiki Train for 1.31.0-wmf.22 is blocked by T187942

• demon subscribed.Feb 21 2018, 8:56 PM

The array-to-string conversion bug was already in the old branch---it got triggered likely because of the underlying lag as an unrelated symptom.

• mmodell mentioned this in T183961: 1.31.0-wmf.22 deployment blockers.Feb 21 2018, 9:00 PM
Krinkle added a project: Performance-Team.Feb 21 2018, 10:41 PM
• Seton subscribed.Feb 21 2018, 10:43 PM
• mmodell added a commit: rMWa114bd9f4d9d: rdbms: avoid "SHOW MASTER/SLAVE STATUS" queries in the GTID case.Feb 21 2018, 10:43 PM
aaron added a comment.Feb 22 2018, 2:32 AM

I've looking at the 21->22 logs, changes, and trying things on mw.org. I don't see a read-only problem there and https://www.mediawiki.org/w/api.php?action=query&meta=siteinfo&siprop=dbrepllag&sishowalldb= looks fine. I don't see any lag in the DBs or seen by MW in that time (LoadBalancer graph at Grafana, those the resolution is low).

'+channel:DBReplication +"read-only"' is mostly empty. The bump in "Server {host} is not replicating?" was for one server and ended before the wmf22 deploy.

aaron added a comment.Feb 22 2018, 2:37 AM

$dbr->getLag() and $lb->getLagTimes() works fine in eval.php on wmf22 wikis as well.

• mmodell added a comment.Feb 22 2018, 2:56 AM

So the log message is probably a false alarm, but why? I'm also digging through the changes trying to see what might be the cause...

gerritbot subscribed.Feb 22 2018, 3:16 AM

Change 413292 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/extensions/Echo@master] Add various read-only mode checks

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

gerritbot added a project: Patch-For-Review.Feb 22 2018, 3:16 AM
gerritbot added a comment.Feb 22 2018, 3:18 AM

Change 413293 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/extensions/ContentTranslation@master] Check read-only mode in ApiContentTranslationSave

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

aaron added a comment.Feb 22 2018, 3:18 AM

The php warning is noise. The "Database is read-only" flood is an actual bug...no idea why that happened.

gerritbot added a comment.Feb 22 2018, 9:07 AM

Change 413318 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] Add ExternalStoreMedium::isReadOnly() method

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

gerritbot added a comment.Feb 22 2018, 9:07 AM

Change 413319 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] Make LocalFile check early if the revision store is available

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

gerritbot added a comment.Feb 22 2018, 9:30 AM

Change 413293 abandoned by Aaron Schulz:
Check read-only mode in ApiContentTranslationSave

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

Nikerabbit subscribed.Feb 22 2018, 11:05 AM
EBernhardson subscribed.Feb 22 2018, 3:09 PM
Johan added a project: User-notice.Feb 22 2018, 3:39 PM
gerritbot added a comment.Feb 22 2018, 4:09 PM

Change 413293 restored by Aaron Schulz:
Check read-only mode in ApiContentTranslationSave

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

gerritbot added a comment.Feb 22 2018, 8:33 PM

Change 413292 merged by jenkins-bot:
[mediawiki/extensions/Echo@master] Add various read-only mode checks

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

gerritbot added a comment.Feb 22 2018, 8:34 PM

Change 413293 merged by jenkins-bot:
[mediawiki/extensions/ContentTranslation@master] Check read-only mode in ApiContentTranslationSave

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

ReleaseTaggerBot added a project: MW-1.31-release-notes (WMF-deploy-2018-02-27 (1.31.0-wmf.23)).Feb 22 2018, 9:01 PM
gerritbot added a comment.Feb 22 2018, 9:31 PM

Change 413474 had a related patch set uploaded (by Chad; owner: Aaron Schulz):
[mediawiki/core@wmf/1.31.0-wmf.22] Add ExternalStoreMedium::isReadOnly() method

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

gerritbot added a comment.Feb 22 2018, 9:41 PM

Change 413318 merged by jenkins-bot:
[mediawiki/core@master] Add ExternalStoreMedium::isReadOnly() method

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

gerritbot added a comment.Feb 22 2018, 9:43 PM

Change 413474 merged by jenkins-bot:
[mediawiki/core@wmf/1.31.0-wmf.22] Add ExternalStoreMedium::isReadOnly() method

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

gerritbot added a comment.Feb 22 2018, 9:51 PM

Change 413484 had a related patch set uploaded (by Chad; owner: Aaron Schulz):
[mediawiki/core@wmf/1.31.0-wmf.22] Make LocalFile check early if the revision store is available

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

gerritbot added a comment.Feb 22 2018, 10:00 PM

Change 413484 merged by jenkins-bot:
[mediawiki/core@wmf/1.31.0-wmf.22] Make LocalFile check early if the revision store is available

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

ReleaseTaggerBot edited projects, added MW-1.31-release-notes (WMF-deploy-2018-02-20 (1.31.0-wmf.22)); removed MW-1.31-release-notes (WMF-deploy-2018-02-27 (1.31.0-wmf.23)).Feb 22 2018, 10:00 PM
gerritbot added a comment.Feb 22 2018, 10:25 PM

Change 413319 merged by jenkins-bot:
[mediawiki/core@master] Make LocalFile check early if the revision store is available

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

ReleaseTaggerBot edited projects, added MW-1.31-release-notes (WMF-deploy-2018-02-27 (1.31.0-wmf.23)); removed MW-1.31-release-notes (WMF-deploy-2018-02-20 (1.31.0-wmf.22)).Feb 22 2018, 11:00 PM
gerritbot added a comment.Feb 23 2018, 3:40 AM

Change 413665 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] rdbms: make DBMasterPos implement Serializable

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

Johan moved this task from To Triage to Announce in next Tech/News on the User-notice board.Feb 23 2018, 1:51 PM
Johan moved this task from Announce in next Tech/News to In current Tech/News draft on the User-notice board.Feb 23 2018, 3:01 PM
• mmodell added a comment.Feb 23 2018, 5:25 PM

Is this safe to deploy now?

jcrespo subscribed.Feb 23 2018, 5:26 PM

Let me know if we can do something on infrastructure as a followup to avoid or detect this in the future- like better beta dbs, with GTID, or simulating lag there.

• demon added a comment.Feb 23 2018, 8:42 PM

Mostly better! Still got a spike of the following, all with wikidatawiki:

#0 /srv/mediawiki/php-1.31.0-wmf.22/includes/externalstore/ExternalStore.php(168): ExternalStore::insertWithFallback(array, string, array)
#1 /srv/mediawiki/php-1.31.0-wmf.22/includes/Storage/SqlBlobStore.php(218): ExternalStore::insertToDefault(string)
#2 /srv/mediawiki/php-1.31.0-wmf.22/includes/Storage/RevisionStore.php(368): MediaWiki\Storage\SqlBlobStore->storeBlob(string, array)
#3 /srv/mediawiki/php-1.31.0-wmf.22/includes/Revision.php(1097): MediaWiki\Storage\RevisionStore->insertRevisionOn(MediaWiki\Storage\MutableRevisionRecord, Wikimedia\Rdbms\DatabaseMysqli)
#4 /srv/mediawiki/php-1.31.0-wmf.22/includes/page/WikiPage.php(1918): Revision->insertOn(Wikimedia\Rdbms\DatabaseMysqli)
#5 /srv/mediawiki/php-1.31.0-wmf.22/includes/page/WikiPage.php(1673): WikiPage->doCreate(Wikibase\ItemContent, integer, User, string, array)
#6 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Wikibase/repo/includes/Store/Sql/WikiPageEntityStore.php(293): WikiPage->doEditContent(Wikibase\ItemContent, string, integer, boolean, User)
#7 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Wikibase/repo/includes/Store/Sql/WikiPageEntityStore.php(190): Wikibase\Repo\Store\WikiPageEntityStore->saveEntityContent(Wikibase\ItemContent, string, User, integer, boolean)
#8 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Wikibase/lib/includes/Store/TypeDispatchingEntityStore.php(88): Wikibase\Repo\Store\WikiPageEntityStore->saveEntity(Wikibase\DataModel\Entity\Item, string, User, integer, boolean)
#9 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Wikibase/repo/includes/EditEntity.php(713): Wikibase\Lib\Store\TypeDispatchingEntityStore->saveEntity(Wikibase\DataModel\Entity\Item, string, User, integer, boolean)
#10 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php(351): Wikibase\EditEntity->attemptSave(Wikibase\DataModel\Entity\Item, string, integer, string)
#11 /srv/mediawiki/php-1.31.0-wmf.22/extensions/Wikibase/repo/includes/Api/ModifyEntity.php(286): Wikibase\Repo\Api\EntitySavingHelper->attemptSaveEntity(Wikibase\DataModel\Entity\Item, string)
#12 /srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php(1580): Wikibase\Repo\Api\ModifyEntity->execute()
#13 /srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php(542): ApiMain->executeAction()
#14 /srv/mediawiki/php-1.31.0-wmf.22/includes/api/ApiMain.php(513): ApiMain->executeActionWithErrorHandling()
#15 /srv/mediawiki/php-1.31.0-wmf.22/api.php(94): ApiMain->execute()
#16 /srv/mediawiki/w/api.php(3): include(string)
#17 {main}

So rolled wikidatawiki back to wmf.21, but other wikis moved forward ok :)

gerritbot added a comment.Feb 23 2018, 8:50 PM

Change 413799 had a related patch set uploaded (by Chad; owner: Aaron Schulz):
[mediawiki/core@wmf/1.31.0-wmf.22] rdbms: make DBMasterPos implement Serializable

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

gerritbot added a comment.Feb 23 2018, 8:57 PM

Change 413665 merged by jenkins-bot:
[mediawiki/core@master] rdbms: make DBMasterPos implement Serializable

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

gerritbot added a comment.Feb 23 2018, 9:02 PM

Change 413799 merged by jenkins-bot:
[mediawiki/core@wmf/1.31.0-wmf.22] rdbms: make DBMasterPos implement Serializable

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

ReleaseTaggerBot edited projects, added MW-1.31-release-notes (WMF-deploy-2018-02-20 (1.31.0-wmf.22)); removed MW-1.31-release-notes (WMF-deploy-2018-02-27 (1.31.0-wmf.23)).Feb 23 2018, 10:00 PM
aaron closed this task as Resolved.Feb 25 2018, 2:38 PM
RandomDSdevel awarded a token.Feb 27 2018, 9:52 PM
Johan moved this task from In current Tech/News draft to Already announced/Archive on the User-notice board.Mar 1 2018, 10:09 AM
matmarex mentioned this in T179884: Files occasionally getting uploaded to Commons without file pages..Mar 5 2018, 8:05 PM
• mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:09 PM
Ladsgroup edited projects, added User-notice-archive; removed User-notice.Aug 13 2022, 1:53 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