910523 - "Restore Previous Session" button in about:home is missing sometimes when restart browser though "Restore Previous Session" is available in History menu

Status: RESOLVED FIXED

(Firefox :: General, defect)

Description

[Alice0775 White]

Build Identifier:
http://hg.mozilla.org/mozilla-central/rev/416075f77249
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:26.0) Gecko/20100101 Firefox/26.0 ID:20130828030202

Reproducible: often

Steps To Reproduce:
1. Open https://paperc.com/store/overview and wait to complete loading the page
2. Exit Browser
3. Restart Browser
   --- observe "Restore Previous Session" button
4. Click "Restore Previous Session" button
5. Repeat from Step2, (It may be necessary to repeat the considerable number of times)

Actual Results:
"Restore Previous Session" button in about:home is missing.
Curiously, "Restore Previous Session" is available in History menu and in another opened about:home.

Comment 1

[Alice0775 White]

Regression window(m-c)
Good:
http://hg.mozilla.org/mozilla-central/rev/b3ff36cb6a1a
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:25.0) Gecko/20130710 Firefox/25.0 ID:20130710064457
Bad:
http://hg.mozilla.org/mozilla-central/rev/dde4dcd6fa46
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:25.0) Gecko/20130710 Firefox/25.0 ID:20130710105040
Pushlog:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=b3ff36cb6a1a&tochange=dde4dcd6fa46


Regression window(m-i)
Good:
http://hg.mozilla.org/integration/mozilla-inbound/rev/6fe449ecd692
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:25.0) Gecko/20130709 Firefox/25.0 ID:20130709060259
Bad:
http://hg.mozilla.org/integration/mozilla-inbound/rev/65d8c8919823
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:25.0) Gecko/20130709 Firefox/25.0 ID:20130709062357
Pushlog:
http://hg.mozilla.org/integration/mozilla-inbound/pushloghtml?fromchange=6fe449ecd692&tochange=65d8c8919823

Comment 2

[Alice0775 White]

In local build
Last Good: ccc02d2288d5
First Bad: 552aab6137ef

Regressed by:
552aab6137ef	David Rajchenbach-Teller — Bug 888479 - Port osfile_shared_allthreads.jsm and dependents to worker module loader. r=froydnj

Comment 3

[David Teller [:Yoric] - still alive but not very active]

Do we have any kind of log?

Comment 4

[Alice0775 White]

(In reply to David Rajchenbach Teller [:Yoric] from comment #3)
> Do we have any kind of log?

No, no error in error console.
But, if it was occurred, snippets is also missing.


I think this is rare case. So, I withdraw tracking request until I find another web sites.

Comment 5

[Alice0775 White]

This http://html5demos.com/offlineapp page also affected:

Reproducible: often

Steps To Reproduce:
1. Open http://html5demos.com/offlineapp
(2. Click "Allow" button if door hanger was popped up for Aurora25.0a2 and earlier)

3. Exit Browser From Menu Alt > F > X or Alt+F4
4. Restart Browser
   --- observe "Restore Previous Session" button

5. Click "Restore Previous Session" button if the button was available
6. Repeat from step3

Actual Results:
"Restore Previous Session" button in about:home is missing at step4 sometimes.
Curiously, "Restore Previous Session" is available in History menu and in another opened about:home.

These affected web site use offline storage. 
So, something of offline storage-related seems to be broken.

Comment 6

[David Teller [:Yoric] - still alive but not very active]

I can reproduce that bug on MacOS X. Doesn't seem to be specific to the web site, though: I have the same behavior with http://example.net .

Comment 7

[David Teller [:Yoric] - still alive but not very active]

From what I understand, this means that something has sent message "browser:purge-session-history". Investigating further.

Comment 8

[David Teller [:Yoric] - still alive but not very active]

Investigating further, this seems to indicate that Sanitizer.history.clear has been called.

Comment 9

[David Teller [:Yoric] - still alive but not very active]

OS.File logging indicates that the session restore file has been loaded properly.

Comment 10

[Alice0775 White]

(In reply to David Rajchenbach Teller [:Yoric] from comment #6)
> I can reproduce that bug on MacOS X. Doesn't seem to be specific to the web
> site, though: I have the same behavior with http://example.net .

Confirmed.
And I got same regression range of comment#1 and  comment#2.

STR:
1. Open http://example.net and wait to complete loading the page
2. Exit Browser
3. Restart Browser
   --- observe "Restore Previous Session" button
4. Click "Restore Previous Session" button
5. Repeat from Step2, (It may be necessary to repeat the considerable number of times)

Actual Results:
"Restore Previous Session" button in about:home is missing.

Comment 11

[David Teller [:Yoric] - still alive but not very active]

I've spent a few hours attempting to find out what's going on.
So far, my best guess is that, for some reason, AboutHome.jsm is not loaded/initialized. I have no idea why, though.

Comment 12

[David Teller [:Yoric] - still alive but not very active]

Got it. I believe that the issue is actually totally unrelated to OS.File, but has been attributed to the OS.File refactoring because it is non-deterministic.

In AboutHome.jsm, |AboutHome.receiveMessage| accesses |SessionStore.canRestoreLastSession| without waiting for Session Restore to be initialized. This causes a race condition between Session Restore initialization and about:home initialization.

Comment 13

[David Teller [:Yoric] - still alive but not very active]

Attachment: about:home now waits until SessionRestore is initialized properly before using its data

Comment 14

[:Gavin Sharp [email: [e-mail]]]

Comment on attachment 799395 [details] [diff] [review]
about:home now waits until SessionRestore is initialized properly before using its data

>diff --git a/browser/modules/AboutHome.jsm b/browser/modules/AboutHome.jsm

>+      Cu.reportError("Error in AboutHome.sendAboutHomeData " + x);

ubernit: can you add a colon? helps distinguish the log message from the exception text.

Comment 15

[:Felipe Gomes (needinfo for replies!)]

Attachment: Test fix?

David, I could not locally reproduce the test failure that was happening on that try push. Maybe it's because I'm testing with a debug build, and the debug spew slow it enough to always have the about:home page updated before the test checks run.
In any case, I wrote a function that should wait on the proper conditions before starting the test. Can you check if it fixes the prob for you? If it doesn't hopefully it's not too far and it's a good hint on how it can be fixed.

(The function always enter in the "already updated" branch for me)

Comment 16

[David Teller [:Yoric] - still alive but not very active]

Try: https://tbpl.mozilla.org/?tree=Try&rev=1f8ff3f35f24

Comment 17

[:Felipe Gomes (needinfo for replies!)]

new try: https://tbpl.mozilla.org/?tree=Try&rev=089d5b13f878
(loadFrameScript didn't like the \n in the data url)

Comment 18

[:Felipe Gomes (needinfo for replies!)]

From that try run, the testcase where the code was added worked properly now, but a later testcase is seem failing now, so it probably needs the same fix.

It's strange because the main function guiding the testcases already has a mutation observer that waits for the proper properties to be set. I don't know why that wait is not enough.

Comment 19

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

I looked into the test failure since I'm able to reproduce it with pretty high probability.

The basic problem is as follows. The test wants us to load the snippets using the URL "nonexistent://test", which is supposed to cause the XHR to fail so that we load default snippets instead. However, the code that sets the snippets URL to "nonexistent://test" happens well after we would initiate the XHR in loadSnippets. Most of the time this seems to work because some other code sets the snippets-last-update value to the current time. However, there are cases where that code also runs too late.

I think this may have always been possible, it was just unlikely. I'll post a patch tomorrow. I'll try to reduce the crazy number of ordering dependencies as well.

Comment 20

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 802027 [details] [diff] [review]
Test fix?

Review of attachment 802027 [details] [diff] [review]:
-----------------------------------------------------------------

Canceling f? while waiting for billm's patch.

Comment 21

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Attachment: abouthome-test.fix

This patch changes how the tests are run for about:home. A major problem with the current code is that it tries to hook into about:home in a way that just doesn't seem valid to me. If it wants to run some code before a function F in aboutHome.js runs, and it knows that F is triggered by an event E, then it registers its own event handler for E and runs the code then. However, there's no guarantee that its code will run before F--it might run after.

I've tried to solve this problem by introducing some custom events that aboutHome.js triggers. These events allow the about:home tests to hook in at exactly the right time. There's one event that triggers after the snippets map has been loaded from disk but before it's used to actually display the snippets. There's another event that runs after about:home is finished loading.

Comment 22

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Comment on attachment 803408 [details] [diff] [review]
abouthome-test.fix

Flagging felipe too.

Comment 23

[:Felipe Gomes (needinfo for replies!)]

Comment on attachment 803408 [details] [diff] [review]
abouthome-test.fix

Review of attachment 803408 [details] [diff] [review]:
-----------------------------------------------------------------

::: browser/base/content/test/browser_aboutHome.js
@@ +430,5 @@
> + * @param aTab
> + *        The tab containing about:home.
> + * @return {Promise} resolved when the page is loaded and ready.
> + */
> +function promiseLoadSucceeded(aTab)

The "Load" name alone implies too much to me that it's just the page loading, rather than it waiting to do something. I suggest we change the function to "promiseLoadSnippetsSucceeded" and the event name to "AboutHomeLoadSnippetsSucceeded"

@@ +435,5 @@
> +{
> +  let deferred = Promise.defer();
> +
> +  aTab.linkedBrowser.addEventListener("AboutHomeLoadSucceeded", function load(event) {
> +    aTab.linkedBrowser.removeEventListener("AboutHomeLoadSnippets", load, true);

note: wrong event name being removed

Comment 24

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Attachment: abouthome-test.fix v2

I fixed those problems and did some further work to ensure that event handlers are always installed before the event could possibly happen.

Comment 25

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

I did a try run here, but it probably makes sense for David to land these patches. I think we're ready to go.
https://tbpl.mozilla.org/?tree=Try&rev=99400c22c96b

Comment 26

[David Teller [:Yoric] - still alive but not very active]

https://hg.mozilla.org/integration/mozilla-inbound/rev/699072fa930d
https://hg.mozilla.org/integration/mozilla-inbound/rev/ff9eb2690763

Comment 27

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/699072fa930d
https://hg.mozilla.org/mozilla-central/rev/ff9eb2690763

Comment 28

[Lukas Blakk [:lsblakk] use ?needinfo]

This needs to uplift to Beta if low risk - please provide a nomination with risk evaluation.

Comment 29

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 799395 [details] [diff] [review]
about:home now waits until SessionRestore is initialized properly before using its data

[Approval Request Comment]
Bug caused by (feature/regressing bug #): Bug 899222, I believe.
User impact if declined: Non-deterministically, users will not be able to call Session Restore from about:home.
Testing completed (on m-c, etc.): The patch has been on m-c for 1 week.
Risk to taking this patch (and alternatives if risky): Low.
String or IDL/UUID changes made by this patch: None.

Comment 30

[David Teller [:Yoric] - still alive but not very active]

Comment on attachment 803852 [details] [diff] [review]
abouthome-test.fix v2

[Approval Request Comment]
Bug caused by (feature/regressing bug #): Bug 899222, I believe.
User impact if declined: Non-deterministically, users will not be able to call Session Restore from about:home.
Testing completed (on m-c, etc.): The patch has been on m-c for 1 week.
Risk to taking this patch (and alternatives if risky): Low.
String or IDL/UUID changes made by this patch: None.

Comment 31

[Ryan VanderMeulen [:RyanVM]]

Has conflicts in browser_aboutHome.js. Please post a branch-specific patch for uplift.

Comment 32

[David Teller [:Yoric] - still alive but not very active]

Bill, you wrote that part of the patch. Can you handle this?

Comment 33

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Attachment: patch for beta

I backported David's fix to beta. Getting Felipe's review since we're now waiting in a different part of the code (since the about:home refactoring hadn't landed on beta).

I'm not seeing the test failures on beta that we saw on trunk, at least not locally. Assuming that the tests pass on try, there's no need to backport the test changes. Here's the try push:
https://tbpl.mozilla.org/?tree=Try&rev=98c2c38deffd

Comment 34

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-beta/rev/e67ff293405d

Comment 35

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Could someone who can reproduce Alice's original STR check to see if it's fixed on beta now?

Comment 36

[Ioana (away)]

I couldn't reproduce the issue on Firefox 25 buggy builds on Ubuntu 13.04 32bit and Mac OS X 10.7.5 64bit even after restarting Firefox the 20-something-th time.

It did reproduce quite easily on Windows 7 64bit though, so I verified it there on:
Mozilla/5.0 (Windows NT 6.1; WOW64; rv:25.0) Gecko/20100101 Firefox/25.0 (20131001024718)

Comment 37

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

RyanVM checked this into aurora a while ago, I think. Here are the commits.

http://hg.mozilla.org/releases/mozilla-aurora/rev/ff9eb2690763
http://hg.mozilla.org/releases/mozilla-aurora/rev/699072fa930d

Comment 38

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/c15febfd8b29

Comment 39

[[github robot]]

Commit pushed to master at https://github.com/mozilla/addon-sdk

https://github.com/mozilla/addon-sdk/commit/9316838b204337a35d5dc60867e6d50163eee289
Tweak some comments per bug 910523 and bug 910517.

Taken from https://hg.mozilla.org/integration/fx-team/rev/c15febfd8b29