Closed Bug 1351964 Opened 4 years ago Closed 4 years ago

Final tab queue tab is added to the Tabs list out of order

Categories

(Firefox for Android :: General, defect)

53 Branch
defect
Not set
normal

Tracking

()

RESOLVED FIXED
Firefox 55
Tracking Status
firefox52 --- unaffected
firefox-esr52 --- unaffected
firefox53 + verified
firefox54 + verified
firefox55 + verified

People

(Reporter: twointofive, Assigned: jchen)

References

Details

(Keywords: regression)

Attachments

(1 file)

STR:
1) Enable tab queue.
2) Open the tabs tray [the error occurs open or closed, but shows up in different ways].
3) Open another app and add two different links to the tab queue.  After the second one click the notification to "Open now" in firefox.

ER: Two new tabs, in the order opened, with the last one the selected tab.

AR: Two new tabs, in the order opened, with the second to last tab the selected tab.
If you close the tabs tray and then reopen it, now you see the added tabs in the opposite order but still with the first tab you opened the selected tab.

It's timing dependent, but I'm getting AR like 60-70% of the time.  You get a similar error if you add more than two tabs to the queue.

Video here: https://youtu.be/c2mBQ0rFqyY [There are some funky animations going on there because of code from WIP on bug 1350718 (which bug you may notice if you follow the STR with a bunch of tabs already open), but that can be ignored.]
More concrete steps that I've been following: use the Quick Search app as the other app.  Search on "asdf", then click the first two suggested results, "asdf" and "asdfghjkl", to add to the tab queue, then click on "Open now".

I don't think this will actually all be needed, given what I suspect is going on, but for completeness, here's a trace of the timing of the order of add/selected events for the two tabs being added:

03-30 01:06:22.421 31591-11137D/***TabQueueHelper open multiple tabs [1]
03-30 01:06:22.801 31591-31623D/***receive TabsOpened in GeckoApp from SessionStore.jsm [2]
03-30 01:06:22.801 31591-31623D/***calling loadUrlWithIntentExtras to load asdfghjkl [3]
03-30 01:06:22.801 31591-31623D/***add the asdfghjkl tab to Tabs.mOrder [4]
03-30 01:06:22.801 31591-31623D/***notifyListeners for asdfghjkl ADDED event is NOT on the UI thread [5]
03-30 01:06:22.801 31591-31623D/***set asdfghjkl as the new Tabs.mSelectedTab [6]
03-30 01:06:22.991 31591-31591D/***Tab:Added event received in Tabs for asdf [7]
03-30 01:06:22.991 31591-31591D/***add the asdf tab to Tabs.mOrder [4]
03-30 01:06:22.991 31591-31591D/***notifyListeners for asdfghjkl ADDED event IS on the UI thread [8]
03-30 01:06:22.991 31591-31591D/***TabsLayout gets ADDED notification for asdf [9]
03-30 01:06:22.991 31591-31591D/***set asdf as the new Tabs.mSelectedTab [6]
03-30 01:06:23.011 31591-31591D/***TabsLayout gets SELECTED notification for asdf [9]
03-30 01:06:23.151 31591-31591D/***TabsLayout gets ADDED notification for asdfghjkl [9]
03-30 01:06:23.161 31591-31591D/***TabsLayout gets SELECTED notification for asdfghjkl [9]

[1] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/tabqueue/TabQueueHelper.java#296
[2] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/GeckoApp.java#1784
[3] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/GeckoApp.java#2172
[4] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/Tabs.java#249
[5] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/Tabs.java#768
[6] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/Tabs.java#298
[7] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/Tabs.java#559
[8] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/Tabs.java#766
[9] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/tabs/TabsLayout.java#106

So it looks to me like when we send off the queued tabs to be loaded in browser.js [10], the TabsOpened event (sent from js at [11]), signaling that the first tab has been opened, is returning before the Tab:Added event (sent from js at [12]), which is what triggers the first tab actually being added to Tabs.mOrder, so the two tabs are added to Tabs.mOrder in the wrong order.  After that, the Tab:Added event from Tabs for the asdfghjkl tab, which it actually processes first because of the first error, actually takes longer to arrive at TabsLayout than the asdf tab because the notifyListeners for the asdfghjkl tab is called NOT on the UI thread while the asdf tab is called ON the UI thread.

[10] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/GeckoApp.java#1790
[11] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/components/SessionStore.js#225
[12] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/chrome/content/browser.js#3589

Jim, does that sound plausible to you, and might it be a result of recent event dispatcher changes?
Flags: needinfo?(nchen)
I should mention that the way choosing the selected tab in the tabs tray works is that TabsLayout receives SELECTED/UNSELECTED events, then notifies the adapter that the target tab of those events has changed, and then RecyclerView rebinds that tab, and in the rebind we set the selection state of the tab by comparing it with Tabs.mSelectedTab.  So even though the SELECTED events arrive in the right order at TabsLayout, we still get the selection wrong because selection was set in the wrong order on Tabs.mSelectedTab.
(In reply to Tom Klein from comment #1)
> the TabsOpened event (sent from js at [11]), signaling that
> the first tab has been opened)

Not the first tab, but all tabs - "Tabs:TabsOpened" is sent only after _openTabs() has opened *all* tabs contained in data on the Gecko side.
(In reply to Jan Henning [:JanH] from comment #3)
> (In reply to Tom Klein from comment #1)
> > the TabsOpened event (sent from js at [11]), signaling that
> > the first tab has been opened)
> 
> Not the first tab, but all tabs - "Tabs:TabsOpened" is sent only after
> _openTabs() has opened *all* tabs contained in data on the Gecko side.

Right, that's worth emphasizing.  We don't actually add a tab to the queue file until the "Tab saved in Firefox | Open now" overlay for that tab goes away (either by timing out or by opening another link).  So in the STR and comment 1, it's important that for the second link you press "Open now" before the overlay goes away on its own.  This bug doesn't reproduce without that step (we take a different path if you tab a bunch of queues, all overlays are gone, and then you manually switch back to fennec).  The issue is the case where you've added one (or more) tabs to the tab queue file, and then for the last tab you open from another app you click "Open now" on the overlay - in that case we open all the _previous_ tabs (which is just one tab in the STR) from browser.js, but that last tab gets created in java first, and its the race between those two creations that's the issue here.
We open all the already queued tabs at [1], and then once we receive the "Tabs:TabsOpened" from js that all of those queued tabs have been opened, we open the final tab that came in with the last intent we receive when we click on "Open now" [2].

[1] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/GeckoApp.java#1790
[2] https://dxr.mozilla.org/mozilla-central/rev/272ce6c2572164f5f6a9fba2a980ba9ccf50770c/mobile/android/base/java/org/mozilla/gecko/GeckoApp.java#2172
Thanks for tracking it down! Sounds like the "Tabs:TabsOpened" listener should be a UI thread listener like the other tab listeners, so we don't end up processing it before the other tab listeners.
Flags: needinfo?(nchen)
[Tracking Requested - why for this release]: regression
Tracking 53/54/55+. :jchen are you going to own fixing this bug?  Thanks.
Assignee: nobody → nchen
Status: NEW → ASSIGNED
Use the UI thread for handling "Tabs:TabsOpened", so we don't race with
other tab events that are already handled on the UI thread.
Attachment #8854675 - Flags: review?(s.kaspari)
Attachment #8854675 - Flags: review?(s.kaspari) → review+
Want to uplift this to 53, if you can land this on m-c quickly? It could still make the beta 10 build tomorrow.
Flags: needinfo?(nchen)
Pushed by nchen@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/3a75f63f3801
Use UI thread for "Tabs:TabsOpened" event; r=sebastian
Comment on attachment 8854675 [details] [diff] [review]
Use UI thread for "Tabs:TabsOpened" event (v1)

Approval Request Comment
[Feature/Bug causing the regression]: Bug 1321418
[User impact if declined]: Wrong tab queue behavior when queuing multiple tabs
[Is this code covered by automated tests?]: No
[Has the fix been verified in Nightly?]: Yes
[Needs manual test from QE? If yes, steps to reproduce]: No
[List of other uplifts needed for the feature/fix]: None
[Is the change risky?]: No
[Why is the change risky/not risky?]: Small patch that addresses this particular bug but doesn't introduce new behavior.
[String changes made/needed]: None
Flags: needinfo?(nchen)
Attachment #8854675 - Flags: approval-mozilla-beta?
Attachment #8854675 - Flags: approval-mozilla-aurora?
The patch works for me too.  Thanks Jim.
Comment on attachment 8854675 [details] [diff] [review]
Use UI thread for "Tabs:TabsOpened" event (v1)

Prevent race condition that messes up tab order on FxA, seems worth the last minute uplift risk to beta 53 so that we never ship with this regression.
Attachment #8854675 - Flags: approval-mozilla-beta?
Attachment #8854675 - Flags: approval-mozilla-beta+
Attachment #8854675 - Flags: approval-mozilla-aurora?
Attachment #8854675 - Flags: approval-mozilla-aurora+
Bug 1349612 is another regression from the same bug, and should be uplifted as well IMO.
Flags: needinfo?(lhenry)
https://hg.mozilla.org/mozilla-central/rev/3a75f63f3801
Status: ASSIGNED → RESOLVED
Closed: 4 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 55
Verified as fixed on all branches, Nightly 55.0a1 (2017-04-10), Aurora 54.0a2 (2017-04-10) and Beta 53.0b11, this issue was verified on a Samsung Galaxy S6 Edge (Android 6.0.1)
You need to log in before you can comment on or make changes to this bug.