Page MenuHomePhabricator

DBPerformance: Expectation masterConns <= 0 not met by PermissionManager->isBlockedFrom
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error
message
Expectation ({measure} <= {max}) by {by} not met (actual: {actual}):
Impact

DB stability and load risk due to significant increase in master connections being acquired from GET requests.

Notes

Seen only on 1.34.0-wmf.20, presumed to be regression.

Screenshot 2019-08-30 at 00.11.34.png (548×2 px, 91 KB)

Details

Request ID
XWhZLQpAAC4AAGLnpagAAAAG
Request URL
/w/index.php?title=Main_Page&action=history
Stack Trace
trace
Expectation (masterConns <= 0) by MediaWiki::main not met (actual: 1):
[connect to 10.64.0.205 (testwiki)]
#0 /srv/mediawiki/php-1.34.0-wmf.20/includes/libs/rdbms/TransactionProfiler.php(186): Wikimedia\Rdbms\TransactionProfiler->reportExpectationViolated('masterConns', '[connect to 10....', 1)
#1 /srv/mediawiki/php-1.34.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(937): Wikimedia\Rdbms\TransactionProfiler->recordConnection('10.64.0.205', 'testwiki', true)
#2 /srv/mediawiki/php-1.34.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(893): Wikimedia\Rdbms\LoadBalancer->getServerConnection(0, 'testwiki', 4)
#3 /srv/mediawiki/php-1.34.0-wmf.20/includes/libs/rdbms/loadbalancer/LoadBalancer.php(1038): Wikimedia\Rdbms\LoadBalancer->getConnection(-2, Array, 'testwiki', 4)
#4 /srv/mediawiki/php-1.34.0-wmf.20/includes/GlobalFunctions.php(2570): Wikimedia\Rdbms\LoadBalancer->getMaintenanceConnectionRef(-2, Array, 'testwiki')
#5 /srv/mediawiki/php-1.34.0-wmf.20/includes/block/DatabaseBlock.php(285): wfGetDB(-2)
#6 /srv/mediawiki/php-1.34.0-wmf.20/includes/block/DatabaseBlock.php(1204): MediaWiki\Block\DatabaseBlock::newLoad(Object(User), 1, true, NULL)
#7 /srv/mediawiki/php-1.34.0-wmf.20/includes/block/BlockManager.php(131): MediaWiki\Block\DatabaseBlock::newListFromTarget(Object(User), NULL, true)
#8 /srv/mediawiki/php-1.34.0-wmf.20/includes/user/User.php(1763): MediaWiki\Block\BlockManager->getUserBlock(Object(User), false)
#9 /srv/mediawiki/php-1.34.0-wmf.20/includes/user/User.php(2086): User->getBlockedStatus(false)
#10 /srv/mediawiki/php-1.34.0-wmf.20/includes/Permissions/PermissionManager.php(286): User->getBlock(false)
#11 /srv/mediawiki/php-1.34.0-wmf.20/extensions/Thanks/includes/ThanksHooks.php(85): MediaWiki\Permissions\PermissionManager->isBlockedFrom(Object(User), Object(Title))
#12 /srv/mediawiki/php-1.34.0-wmf.20/extensions/Thanks/includes/ThanksHooks.php(66): ThanksHooks::isUserBlockedFromTitle(Object(User), Object(Title))
#13 /srv/mediawiki/php-1.34.0-wmf.20/includes/Hooks.php(174): ThanksHooks::insertThankLink(Object(Revision), Array, Object(Revision), Object(User))
#14 /srv/mediawiki/php-1.34.0-wmf.20/includes/Hooks.php(202): Hooks::callHook('HistoryRevision...', Array, Array, NULL)
#15 /srv/mediawiki/php-1.34.0-wmf.20/includes/actions/pagers/HistoryPager.php(439): Hooks::run('HistoryRevision...', Array)
#16 /srv/mediawiki/php-1.34.0-wmf.20/includes/actions/pagers/HistoryPager.php(134): HistoryPager->historyLine(Object(stdClass), Object(stdClass), false, false, true)
#17 /srv/mediawiki/php-1.34.0-wmf.20/includes/pager/IndexPager.php(498): HistoryPager->formatRow(Object(stdClass))
#18 /srv/mediawiki/php-1.34.0-wmf.20/includes/actions/HistoryAction.php(308): IndexPager->getBody()
#19 /srv/mediawiki/php-1.34.0-wmf.20/includes/actions/FormlessAction.php(43): HistoryAction->onView()
#20 /srv/mediawiki/php-1.34.0-wmf.20/includes/MediaWiki.php(507): FormlessAction->show()
#21 /srv/mediawiki/php-1.34.0-wmf.20/includes/MediaWiki.php(302): MediaWiki->performAction(Object(Article), Object(Title))
#22 /srv/mediawiki/php-1.34.0-wmf.20/includes/MediaWiki.php(892): MediaWiki->performRequest()
#23 /srv/mediawiki/php-1.34.0-wmf.20/includes/MediaWiki.php(523): MediaWiki->main()
#24 /srv/mediawiki/php-1.34.0-wmf.20/index.php(42): MediaWiki->run()
#25 /srv/mediawiki/w/index.php(3): require('/srv/mediawiki/...')
#26 {main}

Event Timeline

Krinkle triaged this task as Unbreak Now! priority.Aug 29 2019, 11:12 PM

This appears to be caused by T221371, User::isBlocked() uses the replicas by default, where PermissionManager::isBlockedFrom() uses master by default. However, this patch was merged sometime ago, so I'm not sure if that's the root of the problem, but it is a contributing factor.

Change 533365 had a related patch set uploaded (by Dbarratt; owner: Dbarratt):
[mediawiki/extensions/Thanks@master] Read the block status from the replicas

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

Change 533365 merged by jenkins-bot:
[mediawiki/extensions/Thanks@master] Read the block status from the replicas for the 'thank' link

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

Change 533521 had a related patch set uploaded (by Krinkle; owner: Dbarratt):
[mediawiki/extensions/Thanks@wmf/1.34.0-wmf.20] Read the block status from the replicas for the 'thank' link

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

Change 533521 merged by jenkins-bot:
[mediawiki/extensions/Thanks@wmf/1.34.0-wmf.20] Read the block status from the replicas for the 'thank' link

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

Mentioned in SAL (#wikimedia-operations) [2019-08-30T14:17:02Z] <krinkle@deploy1001> Synchronized php-1.34.0-wmf.20/extensions/Thanks/includes/: T231617 - rETHA8a3c458c4d93 (duration: 00m 54s)

Krinkle claimed this task.
Krinkle reassigned this task from Krinkle to dbarratt.
dbarratt added a subscriber: dom_walden.

@dom_walden FYI: @Krinkle and I verified that this is no longer happening in production.