awesomebar results don't show while session is restoring; they pop up only once there are no more pinned tabs to start loading

NEW
Unassigned

Status

()

defect
P3
normal
3 months ago
21 days ago

People

(Reporter: dbaron, Unassigned)

Tracking

(Blocks 1 bug, {perf})

Firefox Tracking Flags

(Not tracked)

Details

I've been seeing this for at least a few months, finally got around to filing a bug on it (although I'm rather surprised I couldn't find one already... maybe I just couldn't find it):

My browser session that I restore on every nightly update has two windows; one of those windows has 24 (currently) pinned tabs and 2981 tabs total. Session restore will restore all the pinned tabs and the active non-pinned tab. (The other window has 3 tabs in it.) Restoring the window clearly loads three tabs at once, so once one completes loading, then the next pinned tab starts loading, from left to right, visibly (based on the progress indicators).

While the pinned tabs are restoring, the awesomebar doesn't work at all. Showing the dropdown appears to be delayed until the moment when there are only 2 pinned tabs currently loading.

So if I try to type, say "query" in the awesomebar to get the Bugzilla search page while the pinned tabs are restoring... nothing happens, and it just sits there for 30+ seconds while all the pinned tabs load, until there are only 2 left to finish loading, and then, almost immediately, the search results pop up.

Are you in the quantumbar study? What's the value of your browser.urlbar.quantumbar pref?

Flags: needinfo?(dbaron)
Priority: -- → P3

browser.urlbar.quantumbar is true

Flags: needinfo?(dbaron)

Thanks, this seems important enough that we should look into it soon.

Priority: P3 → P1

Well, the fact QB is enable doesn't tell us whether this was also a problem with the legacy urlbar. Especially since this happens from "a few months" and we just flipped the pref for everyone a couple days ago. It's still a critical problem to be investigated, but may not be a QB blocker.
It would be interesting to know if disabling quantumbar still shows the same behavior or not, as a first step.

My first suspect is that either I/O is starving and we are waiting for the db handle, or there are so many queries enqueued that the db can't answer promptly, though the address bar has its own separate connection, so the latter is less likely. It may be interesting to measure I/O during those moments, maybe even a snapshot of what is reading what.

Points: --- → 8

David, can you reproduce this with browser.urlbar.quantumbar set to false?

Flags: needinfo?(dbaron)
Blocks: quantumbar
Iteration: --- → 69.1 - May 13 - 26
No longer blocks: quantumbar-release
Assignee: nobody → adw
Status: NEW → ASSIGNED

I have 25 pinned tabs in my main profile and can't seem to reproduce this. There's certainly some jank during startup but I got results before all pinned tabs had started loading, and whether or not the quantumbar is enabled doesn't seem to make a difference.

(In reply to Dão Gottwald [::dao] from comment #5)

David, can you reproduce this with browser.urlbar.quantumbar set to false?

Yes.

Flags: needinfo?(dbaron)

(I recorded a video (with my cellphone) of the bug happening, while I was testing with quantumbar false, though I'm not inclined to upload it to bugzilla given the size -- but let me know if you want it.)

I'm not able to reproduce this either. Like Dao, I see jank, but the popup opens and I'm able to type. And as Marco alludes to, it may be related to the specific Places database.

David, would you be able to capture a profile while this is happening?

Flags: needinfo?(dbaron)

Here's a profile:

https://profiler.firefox.com/public/9f6bd7f25be72fffbb46ecc64beff3cf06828fa3/calltree/?published&v=3

I started typing the URL after starting the profile, and the awesomebar popup showed up shortly before I stopped the profile. (At least I think so... maybe it's only the last 20 seconds of that period, since I thought it would have been a good bit longer...)

Flags: needinfo?(dbaron)

Thanks. Nothing stands out to me immediately except for some activity stream calls related to the new tab page, looks like. Admittedly I don't spend a lot of time looking at profiles though. I'll look at this more tomorrow.

The flame graph shows some noticeable UrlbarProviderOpenTabs and related sqlite activity late in the profile (starting at ~16s), which given the number of open tabs is interesting... Not sure what to make of it yet, how much of it is normal and expected. The promiseDB call subtree in UrlbarProviderOpenTabs is 16% of the JS running time in the whole profile.

(In reply to Drew Willcoxon :adw from comment #12)

The flame graph shows some noticeable UrlbarProviderOpenTabs and related sqlite activity late in the profile (starting at ~16s), which given the number of open tabs is interesting... Not sure what to make of it yet, how much of it is normal and expected. The promiseDB call subtree in UrlbarProviderOpenTabs is 16% of the JS running time in the whole profile.

I see most urlbar handling around 18s (startSearch), and the popup opening (_openPanel) around 18.5, so it doesn't look that bad. Unfortunately I can't find where the focus and input events are handled, to understand if it's the event that is delayed, or its handling is taking too long. It's possible the dom events queue is crowded and we get the input event much later.
There is surely some db traffic here, I see cookies, bookmark keywords, link coloring and the urlbar connection. Though it's not trivial to find some actionable work items from this.

I haven't been able to make progress on this, so unassigning myself.

Assignee: adw → nobody
Status: ASSIGNED → NEW
Iteration: 69.1 - May 13 - 26 → ---
Priority: P1 → P3
You need to log in before you can comment on or make changes to this bug.