1787565 - Firefox View sometimes shows the wrong (previous) domain name in Recently Closed Tabs, for pages that completed navigation in the background

Status: VERIFIED FIXED

(Firefox :: Firefox View, defect, P1)

Description

[Daniel Holbert [:dholbert]]

STR:

1. Have a window with at least 2 tabs open (so you can close one without losing the window)
2. In one of your tabs (or in a new tab), paste https://www.example.org/ into your URL bar and hit enter.
3. In that same tab, paste https://www.mozilla.org/ into the URL bar and hit enter.
4. Click the Firefox View icon at the left end of your tab-strip.
5. Click the "x" button on the (now-backgrounded) tab that you were navigating in the earlier steps.
6. Look to see what appears in the "Recently Closed" section in Firefox View.

ACTUAL RESULTS:
An entry appears with the correct title taken from mozilla.org, but showing the domain as being example.org . We're showing an old/stale domain that the closed tab was not actually visiting at the time that it was closed.

EXPECTED RESULTS:
The domain should show mozilla.org, not example.org

Comment 1

[Daniel Holbert [:dholbert]]

Attachment: screencast of bug

Comment 2

[Daniel Holbert [:dholbert]]

Attachment: screenshot from the end of the screencast, with arrows to highlight the issue

Comment 3

[Daniel Holbert [:dholbert]]

(ni=sfoster to be sure this is on someone's radar, since it seems fairly-broken. I filed a few different Firefox View bugs in rapid succession, and IMO this is the most-concerning/broken-feeling of the ones that I filed.)

Comment 4

[Daniel Holbert [:dholbert]]

This happens for navigation as well, not just e.g. copypasting.

Here are some "link-to-twitter" STR:

1. Visit https://www.mozilla.org/
2. Scroll to the bottom, to find our link to Twitter ("Follow @Mozilla"), and click the twitter icon.
3. Click the Firefox View button on your tab-strip.
4. Click the "x" on the tab that you were navigating, to close it.
5. Look for the entry for that closed tab in your "Recently Closed" section.

ACTUAL RESULTS:
You get a "Recently closed" entry that says "Mozilla @mozilla / Twitter" but shows the pre-navigation domain name "mozilla.org"

And here's a "link from Google search results" set of STR:

1. Type "Apple" into your url bar and hit enter to kick off a google search (assuming you have Google as your search provider; probably same outcome regardless of who you've got)
2. Click a link in the google search results to "https://www.apple.com"
3. Click the Firefox View button on your tab-strip.
4. Click the "x" on the tab that you were navigating, to close it.
5. Look for the entry for that closed tab in your "Recently Closed" section.

ACTUAL RESULTS:
You get a "Recently closed" entry that says

[apple logo] Apple                google.com

(which is in fact an entry for https://apple.com)

Comment 5

[Daniel Holbert [:dholbert]]

Attachment: screencast for the "clicked a link to Apple.com from Google search results" STR

Comment 6

[:Gijs (he/him)]

So this is Very Annoying.

What happens is session store notifies us when a tab is closed. But at that point, when we ask for closed tab information from session restore, it gives us the (at that point) incomplete information it has, not the last thing that loaded in the tab. There is no evidence in that data that the tab has navigated, so we have no idea. The tab is also gone, so we can't just call TabState.flush() and pass it a browser for which we want to know about up-to-date tab state.

A few ms later, this stack:

copyFromCache resource:///modules/sessionstore/TabState.jsm:194
    copyFromCache resource:///modules/sessionstore/TabState.jsm:44
    onTabStateUpdate resource:///modules/sessionstore/SessionStore.jsm:1306
    updateSessionStoreFromTablistener resource:///modules/sessionstore/SessionStore.jsm:1396
    updateSessionStoreFromTablistener resource:///modules/sessionstore/SessionStore.jsm:475
    SSF_updateSessionStoreForWindow resource://gre/modules/SessionStoreFunctions.jsm:83
    UpdateSessionStoreForStorage resource://gre/modules/SessionStoreFunctions.jsm:34

invoked from C++ code updates the data for the closed tab. This was great for the extant consumers of this data in the browser itself because they ask for this data "just in time" (ie when the user opens a menu), which is hardly likely to coincide with the few ms between closing the tab and this last update coming in (async).

Firefox View obtains the data continuously in response to observer notifications / events. Unfortunately, I don't see anywhere in this stack that sends any kind of event or observer notification. So this update happening is completely opaque to anything outside session restore. This seems to be new since SHIP, and it wouldn't surprise me if this also meant add-ons and other consumers got outdated info - though I'm not sure what APIs are exposed to add-ons wrt this stuff (:rpl, can you help?).

Even invoking notifyOfClosedObjectsChanged isn't enough by itself because nothing in this code sets the flag that the data has updated.

Will keep digging a bit but it's getting pretty late.

Comment 7

[:Gijs (he/him)]

(In reply to :Gijs (he/him) from comment #6)

Firefox View obtains the data continuously in response to observer notifications / events. Unfortunately, I don't see anywhere in this stack that sends any kind of event or observer notification. So this update happening is completely opaque to anything outside session restore. This seems to be new since SHIP, and it wouldn't surprise me if this also meant add-ons and other consumers got outdated info - though I'm not sure what APIs are exposed to add-ons wrt this stuff (:rpl, can you help?).

Let's actually needinfo folks...

(I'd ping Nika but she's out and this needs sorting sooner rather than later)

Comment 8

[:Gijs (he/him)]

Attachment: Bug 1787565 - update recently closed tab entries in Firefox View based on delayed tab navigation information from session history, r?sclements

I don't love this solution but it appears to work and I can't think of anything better.

Comment 9

[Luca Greco [:rpl] [:luca] [:lgreco]]

(In reply to :Gijs (he/him) from comment #7)

(In reply to :Gijs (he/him) from comment #6)

Firefox View obtains the data continuously in response to observer notifications / events. Unfortunately, I don't see anywhere in this stack that sends any kind of event or observer notification. So this update happening is completely opaque to anything outside session restore. This seems to be new since SHIP, and it wouldn't surprise me if this also meant add-ons and other consumers got outdated info - though I'm not sure what APIs are exposed to add-ons wrt this stuff (:rpl, can you help?).

Let's actually needinfo folks...

(I'd ping Nika but she's out and this needs sorting sooner rather than later)

Hi Gijs,
Thanks for pinging up about this.

I'm going to give this a try locally to confirm it, but based on a quick look on searchfox I think it is reasonable to assume that the add-ons may also be technically getting the same kind of outdated details about the recently closed tabs.

The WebExtensions API that expose these kind of details about recently closed tabs and windows is the sessions API, in particular:

• sessions.getRecentlyClosed (link to the API method implementation) is the API method that an extension would be calling to get the details about the closed tabs and windows, internally it is using SessionStore.getClosedWindowData and SessionStore.getClosedTabData.

• sessions.onChanged (link to the API event implementation) is an API event that an extension would be register a listener to be notified to changes to the list of recently closed tabs and windows (the event doesn't send any details when it is fired, the extension would still be calling sessions.getRecentlyClosed to gather those), internally the API event is observing "sessionstore-closed-objects-changed" observer notification topic, which seems to be the same that FirefoxView is also observing.

Comment 10

[Luca Greco [:rpl] [:luca] [:lgreco]]

Attachment: extension_test_to_try_trigger_getRecentlyClosed_issue_using_sessions_webextensions_api.patch

Hi Gijs,
my apologies, it took me a bit more time than I wanted to get back to try to trigger the same kind of issue from an extension through the sessions API.

The patch that I'm attaching include a test case with a test extension and it tries to recreate the issue as described in comment 0 STR (the about:firefoxview page is loaded in the first tab, but I mainly did that to be able to compare what I was getting from the API with that FirefoxView was rendering to confirm that the STR should have be triggering the issue as expected from that perspective).

The test case is trying to call browser.sessions.getRecentlyClosed after we switched tab and closed the background one, but also from inside the following WebExtensions API events.

• a sessions.onChanged listener
• a tabs.onRemoved listener
• a tabs.onUpdated listener

Initially I was trying only with sessions.onChanged, but the call to getRecentlyClosed called from that listener didn't seem to be able to ever trigger the issue, even with --verify it didn't trigger any failure for me locally (on Linux Desktop build).

I guessed that may have been "pure timing luck" though, the latency introduced by emitting the event in the child extension process and then handle the call to browser.sessions.getRecentlyClosed on the parent process to be the actual reason why that call was always getting the last navigated url for the closed tab.

At that point I also tried with tabs.onRemoved and that didn't fail with --verify neither.

As a last attempt, I tried also with tabs.onUpdated (I used the tabs API but it could have been a setInterval callback as well, my idea for this last attempt was really more of a "what if browser.sessions.getRecentlyClosed would be called at a more random time while the tabs are being updated as part of closing the background tabkind of test, and so thetabs.onUpdated` listener isn't filtered to target the specific tab the test is going to close).

This last attempt from tabs.onUpdated was intermittently able to trigger it with --verify (sometimes on the first set of runs, most often while running in a chaosmode set of runs).

And so, the fact that the extension can trigger it intermittently seems to confirm that theoretically it can be triggered using the extension API, but it may or may not be triggered based on timing of when the browser.sessions.getRecentlyClosed API call gets handled on the parent process side.

The additional latency introduced by the parent process emitting browser.sessions.onChanged (or browser.tabs.onRemoved and the extension listener handling that event (and then call browser.sessions.getRecentlyClosed API in response of that) may not be making the extensions able to trigger the issue as often as the FirefoxView tab (which would be calling SessionStore.getClosedTabData kind of synchronously when its observer gets notified for "sessionstore-closed-objects-changed").

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/df6d4e6e452c
update recently closed tab entries in Firefox View based on delayed tab navigation information from session history, r=sclements

Comment 12

[Atila Butkovits]

Backed out for causing failures at browser_ext_brbrowser_recently_closed_tabs.js

Backout link: https://hg.mozilla.org/integration/autoland/rev/1e3a0ec39e0366f4570536edd7e000b953c5cfb7

Push with failures: https://treeherder.mozilla.org/jobs?repo=autoland&selectedTaskRun=LuEZW-ZVRliF7ZdKdcYTdQ.0&resultStatus=testfailed%2Cbusted%2Cexception%2Cretry%2Cusercancel&revision=df6d4e6e452c2276de1ec52dbc63c72404e5f5b6

Failure log: https://treeherder.mozilla.org/logviewer?job_id=389293305&repo=autoland&lineNumber=4343

Comment 13

[Luca Greco [:rpl] [:luca] [:lgreco]]

Hi Gijs,
I think that the browser_ext_brbrowser_recently_closed_tabs.js from comment 12 is meant to be browser_recently_closed_tabs.js (which is the test tweaked in the patch attached to this issue).

I see in the "push with failures" link that there was also a failure triggered from browser_ext_browserAction_popup_resize_bottom.js but I'm not sure that may have been really triggered by the patch attached to this issue.

On the contrary the following other failures may be related:

• browser_ext_sessions_restore.js (the failure message queue is empty - Got "[\"notificationCount\",\"notificationCount\",\"notificationCount\",\"notificationCount\"]", expected "[]" is not unlikely to be a side-effect of the change to SessionStore.jsm), failure logs

• browser_closed_objects_changed_notifications_tabs.js (The expected number of notifications was received. - Got 3, expected 1 seems like it may be related and also be related to the failure triggered from browser_ext_sessions_restore.js), failure logs

Comment 14

[:Gijs (he/him)]

Thanks Luca! I talked to Shane as well. I listed some findings in bug 1789043. To avoid messing with add-ons or the session store tests but fix the issue in fxview, for now I updated the patch to use a slightly different observer topic (thanks Shane for the suggestion).

I've pushed to try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=c7f4ea289ec5c4643e7910e791896418cfb08b30

Assuming that works I'll reland with that change. I see a slight flicker in the URL field when following the steps in comment #0 / comment #4 - but AFAICT this will only be visible when closing tabs while on Firefox View, and so I think that for now this is acceptable. I don't think we have time to pursue the fuller "refactor a bunch of session restore to be more robust" fix in the timeline we have for Firefox View at this point...

Comment 15

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/b63ab5a39b53
update recently closed tab entries in Firefox View based on delayed tab navigation information from session history, r=sclements

Comment 16

[Iulian Moraru]

Backed out for causing bc failures on browser_recently_closed_tabs.js.

Push with failures

Failure log

Backout link

[task 2022-09-03T10:38:58.187Z] 10:38:58     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | parent must be in snapshot. Has [parent]. - true == true - 
[task 2022-09-03T10:38:58.189Z] 10:38:58     INFO - Buffered messages finished
[task 2022-09-03T10:38:58.192Z] 10:38:58     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | After filtering we must have the expected number of events. - 3 == 2 - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertEvents :: line 181
[task 2022-09-03T10:38:58.192Z] 10:38:58     INFO - Stack trace:
[task 2022-09-03T10:38:58.192Z] 10:38:58     INFO - resource://testing-common/TelemetryTestUtils.jsm:assertEvents:181
[task 2022-09-03T10:38:58.193Z] 10:38:58     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js:test_list_ordering/<:191
[task 2022-09-03T10:38:58.194Z] 10:38:58     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | category in event firefoxview#tab_pickup_open#tabs must match. - "firefoxview" matches "firefoxview" - 
[task 2022-09-03T10:38:58.195Z] 10:38:58     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-09-03T10:38:58.200Z] 10:38:58     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | method in event firefoxview#tab_pickup_open#tabs must match. - "tab_pickup_open" matches "entered" - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertEvents :: line 216
[task 2022-09-03T10:38:58.200Z] 10:38:58     INFO - Stack trace:
[task 2022-09-03T10:38:58.201Z] 10:38:58     INFO - resource://testing-common/TelemetryTestUtils.jsm:assertEvents:216
[task 2022-09-03T10:38:58.201Z] 10:38:58     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js:test_list_ordering/<:191
[task 2022-09-03T10:38:58.201Z] 10:38:58     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-09-03T10:38:58.204Z] 10:38:58     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | object in event firefoxview#tab_pickup_open#tabs must match. - "tabs" matches "firefoxview" - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertEvents :: line 216
[task 2022-09-03T10:38:58.204Z] 10:38:58     INFO - Stack trace:
[task 2022-09-03T10:38:58.204Z] 10:38:58     INFO - resource://testing-common/TelemetryTestUtils.jsm:assertEvents:216
[task 2022-09-03T10:38:58.204Z] 10:38:58     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js:test_list_ordering/<:191
[task 2022-09-03T10:38:58.207Z] 10:38:58     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | category in event firefoxview#entered#firefoxview must match. - "firefoxview" matches "firefoxview" - 
[task 2022-09-03T10:38:58.207Z] 10:38:58     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-09-03T10:38:58.211Z] 10:38:58     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | method in event firefoxview#entered#firefoxview must match. - "entered" matches "recently_closed" - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertEvents :: line 216
[task 2022-09-03T10:38:58.211Z] 10:38:58     INFO - Stack trace:
[task 2022-09-03T10:38:58.211Z] 10:38:58     INFO - resource://testing-common/TelemetryTestUtils.jsm:assertEvents:216
[task 2022-09-03T10:38:58.211Z] 10:38:58     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js:test_list_ordering/<:191
[task 2022-09-03T10:38:58.212Z] 10:38:58     INFO - Not taking screenshot here: see the one that was previously logged
[task 2022-09-03T10:38:58.218Z] 10:38:58     INFO - TEST-UNEXPECTED-FAIL | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | object in event firefoxview#entered#firefoxview must match. - "firefoxview" matches "tabs" - JS frame :: resource://testing-common/TelemetryTestUtils.jsm :: assertEvents :: line 216
[task 2022-09-03T10:38:58.218Z] 10:38:58     INFO - Stack trace:
[task 2022-09-03T10:38:58.218Z] 10:38:58     INFO - resource://testing-common/TelemetryTestUtils.jsm:assertEvents:216
[task 2022-09-03T10:38:58.218Z] 10:38:58     INFO - chrome://mochitests/content/browser/browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js:test_list_ordering/<:191
[task 2022-09-03T10:38:58.219Z] 10:38:58     INFO - GECKO(1632) | -----------------------------------------------------
[task 2022-09-03T10:38:58.223Z] 10:38:58     INFO - GECKO(1632) | Suppressions used:
[task 2022-09-03T10:38:58.223Z] 10:38:58     INFO - GECKO(1632) |   count      bytes template
[task 2022-09-03T10:38:58.224Z] 10:38:58     INFO - GECKO(1632) |       2        288 libfontconfig.so
[task 2022-09-03T10:38:58.225Z] 10:38:58     INFO - GECKO(1632) | -----------------------------------------------------
[task 2022-09-03T10:38:58.226Z] 10:38:58     INFO - TEST-PASS | browser/components/firefoxview/tests/browser/browser_recently_closed_tabs.js | Got element with selector: #recently-closed-tabs-container > summary - 

Comment 17

[:Gijs (he/him)]

I don't think that failure is strictly caused by this patch. I can also reproduce it on current central without this patch in TV mode.

I posted a lengthy explanation in bug 1788813. But I can address this here so the patch can land and then I or someone else can work on a proper fix in bug 1788813.

Comment 18

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/2b31d0ddd068
update recently closed tab entries in Firefox View based on delayed tab navigation information from session history, r=sclements

Comment 19

[Atila Butkovits]

https://hg.mozilla.org/mozilla-central/rev/2b31d0ddd068

Comment 20

[Bogdan Maris, Desktop Test Engineering]

Reproduced the initial issue described in comment 0 using old Nightly form 2022-08-27, verified that the domain matches the title of the closed tab on Firefox 106.0b2 across platforms (MacOS 11, Windows 10 and Ubuntu 21.10), although there is still the slight issue from comment 14 but based on that comment it is acceptable at this stage.