Closed Bug 1509250 Opened 6 years ago Closed 4 years ago

Session tab replaced with about:newtab if session manually restored too early after startup

Categories

(Firefox :: Session Restore, defect, P2)

Product:
Firefox
Component:
Session Restore
Version:
65 Branch
Platform:
x86_64
All
Type:
defect

Tracking

()

Status:
RESOLVED WORKSFORME
Project Flags:
Fission Milestone M5
Tracking Flags:
Tracking Status
firefox-esr60 --- unaffected

People

(Reporter: alice0775, Assigned: mconley)

References

Details

(Keywords: regression)

Attachments

(1 file)

results of SessionStore.getCurrentState();
78.92 KB, text/plain
Details 
I can reproduce 100% with the following STR.
And I found regression window with the following STR.

Steps to reproduce:
1. Open http://ftp.mozilla.org/pub/firefox/nightly/ in tab 1
2. Open new tab in tab 2
3. Load http://ftp.mozilla.org/pub/firefox/nightly/ in the tab 2
4. Wait for page loading and then wait another 15 seconds
5. Quit browser
6. Restart browser and Restore Previous Session

Regression window:

https://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=5c3e0fc819ba0da8cdcd85eb16cedcb9d2c8f81e&tochange=d835874be99afb421be275d5ed04b1a050458977

Regressed by: Bug 1472212
Blocks: 1472212
@:imjching,

Your bunch of patch seems to cause the regression.
See, STR and regression window in Comment#3.
Can you please look into this?
Flags: needinfo?(jay)
I tried this a few times on Linux (which has this pref enabled) and could not reproduce it.
(In reply to Kestrel from comment #5)
> I tried this a few times on Linux (which has this pref enabled) and could
> not reproduce it.


if you do not reproduce, repeat the following steps 4-5 times

5. Quit browser
6. Restart browser and Restore Previous Session
(In reply to Alice0775 White from comment #6)
> (In reply to Kestrel from comment #5)
> > I tried this a few times on Linux (which has this pref enabled) and could
> > not reproduce it.
> 
> 
> if you do not reproduce, repeat the following steps 4-5 times
> 
> 5. Quit browser
> 6. Restart browser and Restore Previous Session


if you do not reproduce, you should do "Restore Previous Session" before Firefox Home(Default) contents is displayed in tab 1.

i.e,
5. Quit browser
6. Restart browser and perform "Restore Previous Session" from menu as soon as possible
about:newtab loads too quickly for me in a clean profile so I turned on all rows, highlights, pocket recommendations etc to slow it down and I was able to reproduce it a few times with some very fast clicking.

Easier to reproduce with keyboard cheatcode: Alt+S ↓ ↓ Enter
When the problem occurs, the following error is shown in the Browser Console:

Must reset tab before calling restoreTab. SessionStore.jsm:3821
  restoreTab resource:///modules/sessionstore/SessionStore.jsm:3821
  restoreTabs resource:///modules/sessionstore/SessionStore.jsm:3805
  ssi_restoreWindow resource:///modules/sessionstore/SessionStore.jsm:3599
  _restoreWindowsFeaturesAndTabs resource:///modules/sessionstore/SessionStore.jsm:3679
  _restoreWindowsInReversedZOrder resource:///modules/sessionstore/SessionStore.jsm:3696
  ssi_restoreLastSession resource:///modules/sessionstore/SessionStore.jsm:2918
OS: Windows 10 → All
Summary: Session restore fails. Current tab will be newtab. → Session tab replaced with about:newtab if session manually restored too early after startup
Jay Lim is gone.
ni? to :mconley
Flags: needinfo?(jay) → needinfo?(mconley)
Assignee: nobody → mconley
Blocks: 1508577
No longer blocks: 1472212
Flags: needinfo?(mconley)
Blocks: 1513045
No longer blocks: 1508577
Flags: needinfo?(mconley)
I can still reproduce this on Nightly66.0a1(20181217000148). It is annoying.
status-firefox66: --- → affected

I'm having quite a bit of difficulty reproducing this, even on my slower Windows machine.

Alice, if you have a second, can you show me a screen capture of you hitting the bug?

Flags: needinfo?(mconley) → needinfo?(alice0775)

(In reply to Mike Conley (:mconley) (:⚙️) from comment #12)

I'm having quite a bit of difficulty reproducing this, even on my slower
Windows machine.

Alice, if you have a second, can you show me a screen capture of you hitting
the bug?

I can still reproduce the issue easily on Nightl66.0a1.
However, It is not reproduce when screen capture software is running. So, I cannot attach screen cast.

Flags: needinfo?(alice0775)

okay, I got screen capture, but it is low quality.

Screencast: https://youtu.be/FYdmMFyi4e4

(In reply to Alice0775 White from comment #14)

okay, I got screen capture, but it is low quality.

Screencast: https://youtu.be/FYdmMFyi4e4

Thanks! I'll start working on this tomorrow.

See Also: → 1518863

The problem seems to be no longer reproducible in normal use.
It just happens if Nightly updated when browser startup. Because, in that case, it takes longer time to display the default Home Tab.

P1 since assigned, cheers

Priority: -- → P1

I'm having no luck reproducing this still.

Alice, if you're able to reproduce this semi-reliably, the next time this happens, can you please open the Browser Console, and copy the output message from this command:

SessionStore.getWindowState(window);

and then paste it here in a new comment?

Flags: needinfo?(alice0775)

The following error is shown in Browser console Before execution the |SessionStore.getWindowState(window);| :

Must reset tab before calling restoreTab. SessionStore.jsm:3821

restoreTab resource:///modules/sessionstore/SessionStore.jsm:3821
restoreTabs resource:///modules/sessionstore/SessionStore.jsm:3805
ssi_restoreWindow resource:///modules/sessionstore/SessionStore.jsm:3599
_restoreWindowsFeaturesAndTabs resource:///modules/sessionstore/SessionStore.jsm:3679
_restoreWindowsInReversedZOrder resource:///modules/sessionstore/SessionStore.jsm:3696
ssi_restoreLastSession resource:///modules/sessionstore/SessionStore.jsm:2918

And result of |SessionStore.getWindowState(window);|:

SessionStore.getWindowState(window);
"{"windows":[{"tabs":[{"entries":[{"url":"http://archive.mozilla.org/pub/firefox/candidates/","title":"Directory Listing: /pub/firefox/candidates/","cacheKey":0,"ID":0,"docshellUUID":"{9ea5a670-9513-4083-93a7-26221a46db7b}","originalURI":"http://archive.mozilla.org/pub/firefox/candidates/","resultPrincipalURI":null,"principalToInherit_base64":"vQZuXxRvRHKDMXv9BbHtkAAAAAAAAAAAwAAAAAAAAEYAAAA4bW96LW51bGxwcmluY2lwYWw6e2ExMzE5Y2Y5LTgzNTUtNGMwNy04ZDA4LTFkYTEyMzZlYjJkN30AAAAA","triggeringPrincipal_base64":"SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=","docIdentifier":0,"persist":true}],"lastAccessed":1548114080213,"hidden":false,"attributes":{},"index":1,"userContextId":0,"userTypedValue":"","userTypedClear":0,"image":"data:image/png;base64,iVBORw0KGgoAAAANSUhEUgAAABAAAAAQCAMAAAAoLQ9TAAAAVFBMVEUAAAAEBAQzAAAMDAxmAAAWFhaAAACZAAAiIiKZADMAMwDMAADMADMzMwAzMzP/AABmMzOZMwDMMwBVVVX/MwBmZmZ3d3eGhoagoKTAwMDx8fH///++0uXOAAAAAXRSTlMAQObYZgAAAIpJREFUGBl1wdESATEMBdCbNJIS9rJLq/b//5Mxs8YD5+CnXnXqA5vHpBlpqgNvd7Ewv7rVgjcRY87hx6UGXqRLkG5zkGkDWIvODJIeSUaF9CCdpJaFzDPWqkF10lXbOQwyijPpznRrhxtWKUEyd7q0/ekOSB/qZGrDpinpl4qPMQVTF3wZ7uWGP57dswcg5Jr0LgAAAABJRU5ErkJggg=="},{"entries":[{"url":"about:home","title":"New Tab","cacheKey":0,"ID":0,"docshellUUID":"{fda9c30e-4b7c-47ab-9311-70e70ea4d85c}","resultPrincipalURI":null,"principalToInherit_base64":"vQZuXxRvRHKDMXv9BbHtkAAAAAAAAAAAwAAAAAAAAEYAAAA4bW96LW51bGxwcmluY2lwYWw6ezY4ZDNkYjVlLWUxMGYtNGMzZC04Yzc5LWFjZTE3MWQzYjhmZn0AAAAA","triggeringPrincipal_base64":"SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=","docIdentifier":0,"persist":true}],"lastAccessed":1548114143243,"hidden":false,"attributes":{},"userContextId":0,"index":1,"userTypedValue":"","userTypedClear":0,"image":"chrome://branding/content/icon32.png"}],"selected":2,"_closedTabs":[{"state":{"entries":[{"url":"about:home","title":"New Tab","cacheKey":0,"ID":0,"docshellUUID":"{5597a6e4-2470-4707-8c72-ea026be28c4c}","resultPrincipalURI":null,"principalToInherit_base64":"vQZuXxRvRHKDMXv9BbHtkAAAAAAAAAAAwAAAAAAAAEYAAAA4bW96LW51bGxwcmluY2lwYWw6ezBlNmFmNGM5LWYwZDEtNGJhMy1hMmY4LWM1MWQ3MTg2YzllYX0AAAAA","triggeringPrincipal_base64":"SmIS26zLEdO3ZQBgsLbOywAAAAAAAAAAwAAAAAAAAEY=","docIdentifier":0,"persist":true}],"lastAccessed":1548114076836,"hidden":false,"attributes":{},"userContextId":0,"index":1,"userTypedValue":"","userTypedClear":0,"image":"chrome://branding/content/icon32.png"},"title":"New Tab","image":"chrome://branding/content/icon32.png","pos":0,"closedAt":1548114078832,"closedId":0}],"busy":false,"width":1526,"height":955,"screenX":246,"screenY":64,"sizemode":"maximized","zIndex":1}]}"

Flags: needinfo?(alice0775)

Hm, that's interesting... okay, thanks Alice, I have one more diagnostic thing for you to try.

After you restart the browser, but before you restore the session, can you run:

SessionStore.getCurrentState();

Right-click on the result, choose "Copy Object", and paste it in a comment here?

Flags: needinfo?(alice0775)
Flags: needinfo?(alice0775)
Flags: needinfo?(mconley)

Okay, after a bit of study and experimentation, I think I've been able to induce the symptoms of this bug out on my development machine.

Here's what I think is going on:

We have some code who’s job it is to figure out what the homepage should be. That’s _handleURIToLoad in _delayedStartup. It passes a function to _callWithURIToLoad that either calls that function immediately, or (in the bad case), waits for the gBrowserInit.uriToLoadPromise to resolve.

uriToLoadPromise waits for SessionStartup.willOverrideHomepage to resolve, and that only resolves once we both have a session, and have ensured that the CrashMonitor.previousCheckpoints Promise has resolved.

If, in SessionStartup.jsm, this._initialState is set in willOverrideHomepage, that function will return a Promise that only resolves once uriToLoadPromise resolves.

That leaves a window of time where the user can restore the session, but uriToLoadPromise hasn't yet fired. If the user restores the session in that window of time, it gets overwritten by the homepage stuff once uriToLoadPromise resolves.

I have a trypush up with a workaround for Alice to try, just to see if I'm on the right track here. I'll message with build links once I have them.

Hi Alice, I know you said you were having more difficulty reproducing this lately, so I'm not sure if this experiment will work, but is there any chance you could try reproducing the bug with these two builds? I have a fix in there that I think addresses it.

32-bit: https://queue.taskcluster.net/v1/task/ac-bqEVrS9a5LLjRqFd4CA/runs/0/artifacts/public/build/target.zip

64-bit: https://queue.taskcluster.net/v1/task/FH495LUdT-WcwOA-3YgSNw/runs/0/artifacts/public/build/target.zip

Flags: needinfo?(mconley) → needinfo?(alice0775)

I can syill reproduce. And an error in Browser console.

Must reset tab before calling restoreTab. SessionStore.jsm:3821

restoreTab resource:///modules/sessionstore/SessionStore.jsm:3821
restoreTabs resource:///modules/sessionstore/SessionStore.jsm:3805
ssi_restoreWindow resource:///modules/sessionstore/SessionStore.jsm:3599
_restoreWindowsFeaturesAndTabs resource:///modules/sessionstore/SessionStore.jsm:3679
_restoreWindowsInReversedZOrder resource:///modules/sessionstore/SessionStore.jsm:3696
ssi_restoreLastSession resource:///modules/sessionstore/SessionStore.jsm:2918

And I found a reliable STR.

  1. Start the previous m-i build with new profile

  2. Enable Menubar

  3. Restart the browser.

  4. If default browser dialog pops up, disable it.

  5. Open http://ftp.mozilla.org/pub/firefox/nightly/ in tab 1

  6. Load http://ftp.mozilla.org/pub/firefox/nightly/ in the tab 2

  7. Wait for page loading and then wait another 15 seconds

  8. Quit the browser

  9. Start a new m-i build

  10. When Menubar is ready, Click History –> Restore Previous Session

Flags: needinfo?(alice0775)

s/syill/still/

Flags: needinfo?(mconley)

Fwiw, I do think this error message is the key to the mystery:

restoreTab resource:///modules/sessionstore/SessionStore.jsm:3821
restoreTabs resource:///modules/sessionstore/SessionStore.jsm:3805
ssi_restoreWindow resource:///modules/sessionstore/SessionStore.jsm:3599
_restoreWindowsFeaturesAndTabs resource:///modules/sessionstore/SessionStore.jsm:3679
_restoreWindowsInReversedZOrder resource:///modules/sessionstore/SessionStore.jsm:3696
ssi_restoreLastSession resource:///modules/sessionstore/SessionStore.jsm:2918

We're failing to restore the second tab because it's in a weird state. I'm still trying to figure out how else it can get into that state. :/

(In reply to Mike Conley (:mconley) (:⚙️) from comment #27)

We're failing to restore the second tab because it's in a weird state. I'm still trying to figure out how else it can get into that state. :/

Okay, I think I see it.

That error message happens because of this:

    if (TAB_STATE_FOR_BROWSER.has(browser)) {
      Cu.reportError("Must reset tab before calling restoreTab.");
      return;
    }

So in what cases can TAB_STATE_FOR_BROWSER have that initial browser in there during start-up?

  1. We’re already restoring that tab via restoreTab
  2. We’re in the midst of restoring that tab via a navigateAndRestore
  3. We’ve marked that tab via markTabAsRestoring, so we’re restoring that tab...

So, I have a new theory:

  1. onLoad for the initial window fires, and it goes into _setupInitialBrowserAndTab.
  2. We get the gBrowserInit.uriToLoadPromise, and if it’s actually a Promise, because SessionStore is still getting its act together, we make the initial tab the default remoteness type.
  3. So we’ve got an initial tab with a default web content process. Then, SessionStore start-up finishes, and _callWithURIToLoad decides to load “about:home”, which causes a navigateAndRestore.
  4. That navigateAndRestore sets TAB_STATE_FOR_BROWSER for the browser. While we’re waiting for the navigateAndRestore to complete is when attempting to restore the last session will fail, because that tab is still in the process of navigating and restoring. That means that the about:home load will continue.
  5. So, ultimately, there’s a slow navigateAndRestore going on, and then if a restore last session occurs during that window, it’ll get ignored for the tabs still navigateAndRestore-ing.

Fixes:

  1. Short-term fix is to make the initial tab start with the remoteness of about:home if uriToLoadPromise is in fact a Promise.
  2. Longer-term fix is to make session restoration blow away state such that any navigateAndRestore’s are cancelled.

I'll put together a try-build for (1), and if that works, try to get that landed, and then file a follow-up for (2).

Hi Alice, I have a new build for you to try:

64-bit: https://queue.taskcluster.net/v1/task/Cv7zuiGnRC-RR5e_Mpn8sw/runs/0/artifacts/public/build/target.zip

32-bit: https://queue.taskcluster.net/v1/task/PzsSRy_jTM-EpyKoCVodKg/runs/0/artifacts/public/build/target.zip

Are you able to reproduce the issue with this one?

Flags: needinfo?(mconley) → needinfo?(alice0775)

The try build works as expected with STR comment#25.
I can no longer reproduce the issue :)
https://hg.mozilla.org/try/rev/62dad6ffcb269f90e615ce75ce533409601b2e59

Flags: needinfo?(alice0775) → needinfo?(mconley)

This bug relies on the privileged content process, which is held to Nightly right now. Dropping the 66 tracking flag.

status-firefox66: affected → disabled
tracking-firefox66: + → ---
status-firefox67: --- → affected
Flags: needinfo?(mconley)
Priority: P1 → P2
Fission Milestone: --- → M2
Fission Milestone: M2 → M3
Fission Milestone: M3 → M4

Mike, can you confirm that this is disabled in 68 and still a nightly-only bug? Thanks

Flags: needinfo?(mconley)

This is still held to Nightly-only, and is still a Nightly-only bug.

status-firefox68: affected → disabled
Flags: needinfo?(mconley)

Roll some unfixed bugs from Fission Milestone M4 to M5

0ee3c76a-bc79-4eb2-8d12-05dc0b68e732

Fission Milestone: M4 → M5

Hi Alice0775 White,

I'm hoping to try turning on browser.tabs.remote.separatePrivilegedContentProcess again soon. If you flip that preference in Nightly and restart the browser, are you still able to reproduce this bug?

Flags: needinfo?(alice0775)

(In reply to Mike Conley (:mconley) (:⚙️) from comment #36)

Hi Alice0775 White,

I'm hoping to try turning on browser.tabs.remote.separatePrivilegedContentProcess again soon. If you flip that preference in Nightly and restart the browser, are you still able to reproduce this bug?

@Mike,
Sorry, I forgot to pay attention to this bug.

In recent builds, there is a delay (1-2 seconds) for the menu"Restore Previous Session" to be enabled from disable state.
So, this bug can no longer be reproduced with default settings...

I should change bug status to WORKSFORME.

Status: NEW → RESOLVED
Closed: 4 years ago
status-firefox63: unaffected → ---
status-firefox64: unaffected → ---
status-firefox65: disabled → ---
status-firefox66: disabled → ---
status-firefox67: disabled → ---
status-firefox68: disabled → ---
Flags: needinfo?(alice0775)
Resolution: --- → WORKSFORME

Hi Alice0775 White,

Thank you. We've recently re-enabled the separate privileged about content process in Nightly. If you end up seeing this bug again now that it's enabled, please re-open.

Thank you!

You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: