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

Status: NEW

(Firefox :: Address Bar, defect, P3)

Description

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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.

Comment 1

[Drew Willcoxon :adw]

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

Comment 2

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

browser.urlbar.quantumbar is true

Comment 3

[Drew Willcoxon :adw]

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

Comment 4

[Marco Bonardo [:mak]]

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.

Comment 5

[Dão Gottwald [:dao]]

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

Comment 6

[Dão Gottwald [:dao]]

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.

Comment 7

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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

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

Yes.

Comment 8

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

(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.)

Comment 9

[Drew Willcoxon :adw]

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?

Comment 10

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

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...)

Comment 11

[Drew Willcoxon :adw]

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.

Comment 12

[Drew Willcoxon :adw]

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.

Comment 13

[Marco Bonardo [:mak]]

(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.

Comment 14

[Drew Willcoxon :adw]

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

Comment 15

[David Baron :dbaron: (⌚️UTC-4, no longer working on Mozilla)]

Just noting that I still see this in nightly (both yesterday's and today's).

Comment 16

[Mandy Cheang [:mcheang][she/her]]

To move forward with this bug we can take more recent profile with the 25 pinned tabs and 3000 open tabs. Then investigate the 18s delay with a member of the performance team, if the 18s delay is still happening. Presuming it's still happening after we take the profile. It will be worth taking a look at the profile with a performance team member because there's many events happening before the address bar code kicks in.