Closed Bug 1787565 Opened 2 years ago Closed 2 years ago

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

Categories

(Firefox :: Firefox View, defect, P1)

defect

Tracking

()

VERIFIED FIXED
106 Branch
Tracking Status
firefox106 --- verified

People

(Reporter: dholbert, Assigned: Gijs)

References

(Blocks 1 open bug)

Details

(Whiteboard: [fidefe-2022-mr1-firefox-view])

Attachments

(5 files)

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

Attached video screencast of bug

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

Flags: needinfo?(sfoster)

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)

Attachment #9291858 - Attachment description: screencast for the "clicked a link from Google search results" STR → screencast for the "clicked a link to Apple.com from Google search results" STR
Blocks: firefox-view
Whiteboard: [fidefe-2022-mr1-firefox-view]
Severity: -- → S2
Priority: -- → P1
Flags: needinfo?(sfoster) → needinfo?(gijskruitbosch+bugs)

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.

Assignee: nobody → gijskruitbosch+bugs
Status: NEW → ASSIGNED
Flags: needinfo?(gijskruitbosch+bugs)

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

Flags: needinfo?(lgreco)

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

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

Flags: needinfo?(lgreco)

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

Pushed by gijskruitbosch@gmail.com:
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

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

See Also: → 1789004
Blocks: 1789004
See Also: 1789004
Blocks: 1789043

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

Flags: needinfo?(gijskruitbosch+bugs)
Pushed by gijskruitbosch@gmail.com:
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

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 - 
Flags: needinfo?(gijskruitbosch+bugs)

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.

Flags: needinfo?(gijskruitbosch+bugs)
See Also: → 1788813
Pushed by gijskruitbosch@gmail.com:
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
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → 106 Branch
See Also: → 1789665
Regressions: 1789652
Flags: qe-verify+

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.

Status: RESOLVED → VERIFIED
Flags: qe-verify+
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Created:
Updated:
Size: