Page MenuHomePhabricator
Create Task
Maniphest T207881

excessive "lock wait timeout exceeded " error rate after deploying 1.33.0-wmf.1 to group1
Closed, DuplicatePublicPRODUCTION ERROR
Actions

Assigned To
None
Authored By
• mmodell
Oct 24 2018, 7:26 PM
Tags
Referenced Files
F26808808: Screenshot from 2018-10-25 15-00-48.png
Oct 25 2018, 8:01 PM
F26775508: Screenshot from 2018-10-24 14-36-56.png
Oct 24 2018, 7:37 PM
Subscribers
Addshore
Aklapper
• Banyek
gerritbot
• mmodell
Paladox
Stashbot
TerraCodes

Description

Error

Request ID: AWanh-6v00on8STvSoRR

message
Error: 1205 Lock wait timeout exceeded; try restarting transaction (10.64.48.15)
trace
 	#0 /srv/mediawiki/php-1.33.0-wmf.1/includes/libs/rdbms/database/Database.php(1468): Wikimedia\Rdbms\Database->makeQueryException(string, integer, string, string)
#1 /srv/mediawiki/php-1.33.0-wmf.1/includes/libs/rdbms/database/Database.php(1228): Wikimedia\Rdbms\Database->reportQueryError(string, integer, string, string, boolean)
#2 /srv/mediawiki/php-1.33.0-wmf.1/includes/libs/rdbms/database/Database.php(1695): Wikimedia\Rdbms\Database->query(string, string)
#3 /srv/mediawiki/php-1.33.0-wmf.1/includes/libs/rdbms/database/Database.php(1786): Wikimedia\Rdbms\Database->select(string, string, array, string, array, array)
#4 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/repo/includes/Store/Sql/SqlIdGenerator.php(71): Wikimedia\Rdbms\Database->selectRow(string, string, array, string, array)
#5 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/repo/includes/Store/Sql/SqlIdGenerator.php(46): Wikibase\SqlIdGenerator->generateNewId(Wikimedia\Rdbms\DatabaseMysqli, string)
#6 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/repo/includes/Store/Sql/WikiPageEntityStore.php(120): Wikibase\SqlIdGenerator->getNewId(string)
#7 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/lib/includes/Store/TypeDispatchingEntityStore.php(59): Wikibase\Repo\Store\WikiPageEntityStore->assignFreshId(Wikibase\DataModel\Entity\Item)
#8 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php(269): Wikibase\Lib\Store\TypeDispatchingEntityStore->assignFreshId(Wikibase\DataModel\Entity\Item)
#9 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/repo/includes/Api/EntitySavingHelper.php(197): Wikibase\Repo\Api\EntitySavingHelper->createEntity(string, NULL)
#10 /srv/mediawiki/php-1.33.0-wmf.1/extensions/Wikibase/repo/includes/Api/ModifyEntity.php(277): Wikibase\Repo\Api\EntitySavingHelper->loadEntity()
#11 /srv/mediawiki/php-1.33.0-wmf.1/includes/api/ApiMain.php(1570): Wikibase\Repo\Api\ModifyEntity->execute()
#12 /srv/mediawiki/php-1.33.0-wmf.1/includes/api/ApiMain.php(531): ApiMain->executeAction()
#13 /srv/mediawiki/php-1.33.0-wmf.1/includes/api/ApiMain.php(502): ApiMain->executeActionWithErrorHandling()
#14 /srv/mediawiki/php-1.33.0-wmf.1/api.php(87): ApiMain->execute()
#15 /srv/mediawiki/w/api.php(3): include(string)
#16 {main}

Impact

  • high error rate in logstash.
  • train rolled back to group0

Notes

Details

SubjectRepoBranchLines +/-
Use a pre-commit hook for change_tag_def count updatesmediawiki/coreREL1_32+23 -18
Use a pre-commit hook for change_tag_def count updatesmediawiki/coremaster+23 -18
Use a pre-commit hook for change_tag_def count updatesmediawiki/corewmf/1.33.0-wmf.1+23 -18
Customize query in gerrit

Related Objects

Event Timeline

• mmodell created this task.Oct 24 2018, 7:26 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptOct 24 2018, 7:26 PM
• mmodell triaged this task as Unbreak Now! priority.Oct 24 2018, 7:27 PM
• mmodell updated the task description. (Show Details)
Restricted Application added subscribers: Liuxinyu970226, TerraCodes. · View Herald TranscriptOct 24 2018, 7:27 PM
Stashbot subscribed.Oct 24 2018, 7:31 PM

Mentioned in SAL (#wikimedia-operations) [2018-10-24T19:31:50Z] <twentyafterfour> the errors were all coming from wmf.26 but the error rate skyrocketed after deploying 1.33.0-wmf.1 to group1 so there is some query in the new branch which is holding a lock. T207881

• mmodell added projects: DBA, MediaWiki-libs-Rdbms.Oct 24 2018, 7:33 PM
• mmodell added a comment.Oct 24 2018, 7:37 PM

Screenshot from 2018-10-24 14-36-56.png (406×603 px, 15 KB)

• Banyek subscribed.Oct 24 2018, 9:10 PM

Those are the exceptions in the given time range: https://logstash.wikimedia.org/app/kibana#/dashboard/default?_g=(refreshInterval%3A(display%3AOff%2Cpause%3A!f%2Cvalue%3A0)%2Ctime%3A(from%3A'2018-10-24T19%3A22%3A00.000Z'%2Cmode%3Aabsolute%2Cto%3A'2018-10-24T19%3A24%3A00.000Z'))

gerritbot subscribed.Oct 24 2018, 9:11 PM

Change 469518 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@master] Use a pre-commit hook for change_tag_def count updates

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

gerritbot added a project: Patch-For-Review.Oct 24 2018, 9:11 PM
Paladox subscribed.Oct 24 2018, 9:16 PM
gerritbot added a comment.Oct 24 2018, 10:14 PM

Change 469518 merged by jenkins-bot:
[mediawiki/core@master] Use a pre-commit hook for change_tag_def count updates

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

ReleaseTaggerBot added a project: MW-1.33-notes (1.33.0-wmf.2; 2018-10-30).Oct 24 2018, 11:01 PM
• Banyek mentioned this in T207901: dbproxy1005 reports database failover.Oct 25 2018, 7:59 AM
• Banyek lowered the priority of this task from Unbreak Now! to Medium.Oct 25 2018, 8:30 AM
jcrespo raised the priority of this task from Medium to Unbreak Now!.Oct 25 2018, 8:32 AM
gerritbot added a comment.Oct 25 2018, 5:11 PM

Change 469653 had a related patch set uploaded (by Aaron Schulz; owner: Aaron Schulz):
[mediawiki/core@wmf/1.33.0-wmf.1] Use a pre-commit hook for change_tag_def count updates

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

gerritbot added a comment.Oct 25 2018, 5:34 PM

Change 469653 merged by jenkins-bot:
[mediawiki/core@wmf/1.33.0-wmf.1] Use a pre-commit hook for change_tag_def count updates

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

ReleaseTaggerBot edited projects, added MW-1.33-notes (1.33.0-wmf.1; 2018-10-23); removed MW-1.33-notes (1.33.0-wmf.2; 2018-10-30).Oct 25 2018, 6:01 PM
• mmodell added a comment.EditedOct 25 2018, 7:53 PM

I'm seeing a lot of occurrences of this with Function: Wikibase\SqlIdGenerator::generateNewId

and also a lot with

Function: User::loadFromDatabase

• mmodell added a comment.Oct 25 2018, 8:00 PM

This is happening even more now that I did a full scap with wmf.1 still on group0 only.

• mmodell added a comment.Oct 25 2018, 8:01 PM

This is for the past 1 hour, during which time I ran a full scap sync:

Screenshot from 2018-10-25 15-00-48.png (595×1 px, 21 KB)

• mmodell added a comment.Oct 25 2018, 8:03 PM

I've also seen periodic alerts for apache and hhvm:

PROBLEM - Apache HTTP on mw1270 is CRITICAL: HTTP CRITICAL: HTTP/1.1 503 Service Unavailable - 1308 bytes in 0.001 second response time
14:55:29	<+icinga-wm>	PROBLEM - HHVM rendering on mw1270 is CRITICAL: HTTP CRITICAL: HTTP/1.1 503 Service Unavailable - 1308 bytes in 0.001 second response time
14:56:29	<+icinga-wm>	RECOVERY - Apache HTTP on mw1270 is OK: HTTP OK: HTTP/1.1 301 Moved Permanently - 616 bytes in 0.038 second response time
14:56:30	<+icinga-wm>	RECOVERY - HHVM rendering on mw1270 is OK: HTTP OK: HTTP/1.1 200 OK - 74206 bytes in 0.103 second response time

and just now:

+icinga-wm>	PROBLEM - MediaWiki exceptions and fatals per minute on graphite1001 is CRITICAL: CRITICAL: 80.00% of data above the critical threshold [50.0] https://grafana.wikimedia.org/dashboard/db/mediawiki-graphite-alerts?orgId=1&panelId=2&fullscreen
• mmodell added a comment.Oct 25 2018, 8:34 PM

Promoted group1 to wmf.1 again and now even more lock wait timeouts for Function: Wikibase\SqlIdGenerator::generateNewId

• mmodell updated the task description. (Show Details)Oct 25 2018, 8:39 PM
• mmodell added a project: MediaWiki-extensions-WikibaseRepository.Oct 25 2018, 8:46 PM
Restricted Application added a project: Wikidata. · View Herald TranscriptOct 25 2018, 8:46 PM
Addshore subscribed.Oct 25 2018, 11:43 PM
• mmodell lowered the priority of this task from Unbreak Now! to High.Oct 26 2018, 12:53 AM
Addshore added a comment.Oct 26 2018, 1:00 AM

This shouldn't be a blocker for the train, we gets spikes of these sometimes when people try to create too many entities in quick succession.
At some point in the future we will have to look at solving this

• mmodell removed a parent task: T206655: 1.33.0-wmf.1 deployment blockers.Oct 26 2018, 1:04 AM
Addshore added a comment.Oct 26 2018, 5:06 PM

It does look like this is occurring more recently.
https://logstash.wikimedia.org/goto/109c48d009146d7e2ca4f30a312e98fe

Addshore added a project: [DEPRECATED] wdwb-tech.Oct 26 2018, 5:11 PM
Krinkle moved this task from Untriaged to Older on the Wikimedia-production-error board.Oct 26 2018, 10:27 PM
gerritbot added a comment.Oct 28 2018, 11:33 PM

Change 470300 had a related patch set uploaded (by Paladox; owner: Aaron Schulz):
[mediawiki/core@REL1_32] Use a pre-commit hook for change_tag_def count updates

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

jcrespo moved this task from Triage to Blocked external/Not db team on the DBA board.Oct 29 2018, 8:06 AM
gerritbot added a comment.Oct 29 2018, 9:52 PM

Change 470300 abandoned by Krinkle:
Use a pre-commit hook for change_tag_def count updates

Reason:
Unexplained backport proposal.

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

Addshore moved this task from incoming to needs discussion or investigation on the Wikidata board.Oct 31 2018, 5:08 PM
Addshore mentioned this in T194299: Lock wait timeout exceeded in SqlIdGenerator::generateNewId.Nov 1 2018, 2:51 PM
Addshore closed this task as a duplicate of T194299: Lock wait timeout exceeded in SqlIdGenerator::generateNewId.Nov 1 2018, 3:04 PM
Restricted Application removed a subscriber: Liuxinyu970226. · View Herald TranscriptNov 1 2018, 3:04 PM
• mmodell changed the subtype of this task from "Task" to "Production Error".Aug 28 2019, 11:08 PM
Maintenance_bot removed a project: Patch-For-Review.Aug 28 2019, 11:30 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