Page MenuHomePhabricator

MessageBlobStore::clear queries take 40+ seconds
Closed, ResolvedPublic

Description

I was testing a patch on my development wiki (copy of twn wiki) and pages were timing out so I i fired up mytop. I saw multiple queries from MessageBlobStore::clear (one for each time I reloaded the page). Observering the list, they took ~50 seconds each to complete. It looks like it has only been fixed for WMF in T29320, not properly in core.

Event Timeline

Nikerabbit raised the priority of this task from to Needs Triage.
Nikerabbit updated the task description. (Show Details)
Nikerabbit added a subscriber: Nikerabbit.

Where do these calls primarily come from?

Do they occur while browsing the wiki? On write actions via index.php? In api.php? In load.php? In jobqueue jobs?

Unfortunately I don't remember details anymore and I can't think of why the queries would suddenly take so long.

Aklapper changed the task status from Open to Stalled.Apr 15 2015, 4:27 PM
Aklapper lowered the priority of this task from Medium to Lowest.
Aklapper set Security to None.

Just saw this again:

*** 13:12:27: Rebuilding caches ***
[Sat Sep  5 13:13:32 2015] [hphp] [8306:7f734a212a00:0:000001] [] SlowTimer [50823ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:13:32 2015] [hphp] [8309:7f734a212a00:0:000001] [] SlowTimer [50720ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:13:32 2015] [hphp] [8308:7f734a212a00:0:000001] [] SlowTimer [50962ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:13:32 2015] [hphp] [8307:7f734a212a00:0:000001] [] SlowTimer [50906ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:14:24 2015] [hphp] [8308:7f734a212a00:0:000002] [] SlowTimer [51451ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:14:24 2015] [hphp] [8306:7f734a212a00:0:000002] [] SlowTimer [51434ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:14:24 2015] [hphp] [8309:7f734a212a00:0:000002] [] SlowTimer [51403ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
[Sat Sep  5 13:14:24 2015] [hphp] [8307:7f734a212a00:0:000002] [] SlowTimer [51491ms] at runtime/ext_mysql: slow query: DELETE /* MessageBlobStore::clear  */ FROM `bw_msg_resource`
*** 13:15:10: All done ***

It was running php maintenance/rebuildLocalisationCache.php --threads=4

Aklapper changed the task status from Stalled to Open.Sep 15 2015, 10:02 AM
Aklapper raised the priority of this task from Lowest to Low.