Closed Bug 1467537 Opened Last year Closed Last year

Long beach ball hang when opening History menu caused by slow SQL: DELETE FROM moz_updateoriginsinsert_temp

Categories

(Toolkit :: Places, defect, P1, major)

Unspecified
macOS
defect

Tracking

()

RESOLVED FIXED
mozilla62
Tracking Status
firefox-esr52 --- unaffected
firefox-esr60 --- unaffected
firefox60 --- unaffected
firefox61 --- unaffected
firefox62 --- fixed

People

(Reporter: cpeterson, Assigned: mak)

References

Details

(Keywords: regression, Whiteboard: [fxsearch])

Attachments

(1 file)

Firefox Nightly on macOS has been frequently hanging for me since mid-May, particularly when my MacBook Pro wakes from hibernation. With today's Nightly build (2018-06-05), however, the hangs are much worse.

STR seems to be to enable one or more extensions and then open Firefox's History menu. I tried bisecting the hangs with mozregression, which pointed to autofill bug 1239708.

Here are some slow SQL queries logged after I reproduced the (~70 second) beach ball hang.

Slow SQL Statements on Main Thread Hits 	Avg. Time (ms) 	Statement

1 	75231 	SELECT h.id, h.url, h.title AS page_title, h.rev_host, h.visit_count, h.last_visit_date, null, null, null, null, null, null AS tags , h.frecency, h.hidden, h.guid, null, null, null FROM moz_places h WHERE h.hidden = 0 AND EXISTS (SELECT id FROM moz_historyvisits WHERE place_id = h.id AND visit_type NOT IN (0,4,8) LIMIT 1) ORDER BY last_visit_date DESC LIMIT 15 /* places.sqlite */

Slow SQL Statements on Helper Threads Hits 	Avg. Time (ms) 	Statement

2 	39383 	DELETE FROM moz_updateoriginsinsert_temp /* places.sqlite */ 

I can usually reproduce the hang after enabling one or both of the following simple extensions (and the opening the History menu). Enabling almost any extension will do, but these are two trivial extensions that consistently reproduced the problem for me.

https://addons.mozilla.org/en-US/firefox/addon/always-right/
https://addons.mozilla.org/en-US/firefox/addon/in-page-pop-up-reporter/


In bug 1462046 comment 26, Marco asks:

(In reply to Marco Bonardo [::mak] from comment #26)
> the second statement took an unexpected long time to
> run (40s) and due to legacy architectural problem we didn't solve yet (UI
> queries are on the main-thread yet), the main-thread tries to run a query in
> the meanwhile, and locks on the connection mutex.

> Honestly I don't think the add-ons have any relation with this, or at least
> I can't see one.

I agree that the particular add-ons don't seem related, but but the hangs really do seem to happen only when add-ons are enabled. Perhaps it is just coincidental timing or maybe enabling an add-on causes some Sync activity the contends with populating the History menu?

I can only repro this hang on my MacBook Pro. My Windows 10 laptop syncs with the same Firefox account, but doesn't hang.

> Is the disk particularly busy and loud (if mechanical) before these lock-ups
> happen?

N/A because I have a MacBook Pro with an SSD.

> Did you enable the new Sync mirroring?

I have Sync enabled, but I haven't flipped any experimental Sync prefs.
See Also: → 1462046
I'll do some investigation and see if we have options to debug/reduce this one.
We surely can't completely resolve it unless we rearchitecture all the views.
Assignee: nobody → mak77
Status: NEW → ASSIGNED
Priority: -- → P2
Whiteboard: [fxsearch]
I think I may have found a big inefficiency.
Flags: needinfo?(cpeterson)
Severity: normal → major
Priority: P2 → P1
Thanks Chris, I can't express how important is this fix.
Blocks: 1239708
Blocks: 1463017
This is not easily testable by QE, thus minusing. Hopefully Chris will be able to check the improvement here.
Flags: qe-verify-
The test failure is trivially due to the fact we were not calculating things quickly enough before, the test doesn't expect autofill to happen, but it happens with the patch.
This actually exposed a possible bug in the autocomplete controller I'm looking into.
Comment on attachment 8984385 [details]
Bug 1467537 - The delete trigger on moz_updateoriginsinsert_temp is recalculating the whole table every time.

https://reviewboard.mozilla.org/r/250206/#review256742

Thanks Marco, really good catch.
Attachment #8984385 - Flags: review?(adw) → review+
Could you please also describe the controller fix, here and/or in the commit message, mostly for posterity?
Pushed by mak77@bonardo.net:
https://hg.mozilla.org/integration/autoland/rev/d30ccb8af2fe
The delete trigger on moz_updateoriginsinsert_temp is recalculating the whole table every time. r=adw
https://hg.mozilla.org/mozilla-central/rev/d30ccb8af2fe
Status: ASSIGNED → RESOLVED
Closed: Last year
Resolution: --- → FIXED
Target Milestone: --- → mozilla62
Blocks: 1463512
Depends on: 1506461
You need to log in before you can comment on or make changes to this bug.