1100953 - Test failure "Tab with URL 'http://localhost:43336/layout/mozilla.html' has been opened" in testRestorePreviousSession/test2.js

Status: RESOLVED FIXED

(Mozilla QA Graveyard :: Mozmill Tests, defect, P3)

Description

[Andreea Matei [:AndreeaMatei]]

Started to fail today on Windows XP, Vista, several locales, with beta.

Affected line:
http://hg.mozilla.org/qa/mozmill-tests/file/mozilla-beta/firefox/tests/functional/testSessionStore/testRestorePreviousSession/test2.js#l42

Comment 1

[Andrei Eftimie]

There's one (only one) report on 35 as well; Windows, en-US:
http://mozmill-daily.blargon7.com/#/functional/report/635fcffb06b246be47416301bd344646

Only on XP and Win7, multiple locales, different machines.

Comment 2

[Cosmin Malutan, [:cosmin-malutan]]

To clarify I'll explain the test, the failure and the fix.
The tests:
Test 1:
1 Adds a HTTP resource on collector, this takes port 43336 by default, if it's take it will increment and try the higher one:
 > https://github.com/mozilla/mozmill/blob/hotfix-2.0/mozmill/mozmill/extension/resource/modules/frame.js#L663
 >https://github.com/mozilla/mozmill/blob/hotfix-2.0/mozmill/mozmill/extension/resource/modules/frame.js#L613 
2 Opens 3 links from the resource added and checks they opened

Test 2:
1 Adds a HTTP resource again.
2 Hits historyRestoreLastSession
3 Waits for 3 new tabs to open
 > This passed, so the session is restored, no doubts
4 Checks that the opened tabs are the one from TEST_DATA
 > Here it fails even if the first assertion passed.
 > Reason: We have different addresses in TEST_DATA from what we actually have on opened tabs

This happens when the port 43336 is token or doesn't get released between test1 and test2, and the collector tries different port numbers, this makes the TEST_DATA different

What needs to be done here is to add the TEST_DATA from test1 on persisted object and use it in test2 to check that the correct tabs have been restored.

Comment 3

[Andreea Matei [:AndreeaMatei]]

The persisted object use seems to be what we need indeed. Please create a fix patch. This test is pretty new and the failure intermittent.

Comment 4

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Well, even if we use the persisted object the ports would be different, and a comparison should fail, right? I wonder WHY the port is not released. Maybe that is caused by the not perfect restart handling of Firefox. Cosmin, can you reproduce this locally? If yes, could you please try with a Mozmill 2.1 build with better restart logic?

Comment 5

[Cosmin Malutan, [:cosmin-malutan]]

(In reply to Henrik Skupin (:whimboo) from comment #4)
> Well, even if we use the persisted object the ports would be different, and
> a comparison should fail, right? I wonder WHY the port is not released.
We don't care about the server/port in the second test, the page restored are cached not loaded, we shouldn't use the server at all in the second test, I've tested this!

> Maybe that is caused by the not perfect restart handling of Firefox. Cosmin,
> can you reproduce this locally? If yes, could you please try with a Mozmill
> 2.1 build with better restart logic?
This fails very rarely, I've seen it once or twice locally. And could be dozens of things that causes this behavior, maybe the port it's not available in first test and we use the next one, and in the second test it is available and we use that one, it will still be different from test1. But as I said we don't care about the server in the second test and we shouldn't sync the ports between the two testes just to have the same "constant" TEST_DATA(right now is not constant at all :))
Now even if it wouldn't fail with 2.1 anymore, the correct approach here it will be to don't add  new file server in test2 but to check that the tabs opened in test1 are restored, this shouldn't depend at all on ports?

Comment 6

[Henrik Skupin [:whimboo][⌚️UTC+2]]

If pages are loaded from the cache it should be fine. But if not keep in mind that you will get a 404 if httpd.js has not been setup correctly. So your proposal can cause a regression.

Comment 7

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: patch v1.0

(In reply to Henrik Skupin (:whimboo) from comment #6)
> If pages are loaded from the cache it should be fine. But if not keep in
> mind that you will get a 404 if httpd.js has not been setup correctly. So
> your proposal can cause a regression.
I was aware of that, I tested this manually too, that's how I known the page is cached.

http://mozmill-crowd.blargon7.com/#/functional/report/635fcffb06b246be47416301bd624c13

Comment 8

[Andrei Eftimie]

Comment on attachment 8525926 [details] [diff] [review]
patch v1.0

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

Looks like a good fix.
https://hg.mozilla.org/qa/mozmill-tests/rev/fe06a666471f (default)

Comment 9

[Andrei Eftimie]

And lets get this in Aurora.
https://hg.mozilla.org/qa/mozmill-tests/rev/bdc88078c8a4 (mozilla-aurora)

Comment 10

[Andrei Eftimie]

ALl green on beta:
https://hg.mozilla.org/qa/mozmill-tests/rev/0d763ff26b27 (mozilla-beta)

Thanks Cosmin for the fix.

Comment 11

[Cosmin Malutan, [:cosmin-malutan]]

Thanks for review!

Comment 12

[Andreea Matei [:AndreeaMatei]]

This failed today with beta 7 times with windows machines. So lesser than before, but something is still missing here for windows at least. Let's investigate on Monday.

http://mozmill-release.blargon7.com/#/functional/failure?app=Firefox&branch=All&platform=All&from=2014-11-21&to=2014-11-21&test=%2FtestSessionStore%2FtestRestorePreviousSession%2Ftest2.js&func=testRestorePreviousSession

Comment 13

[Cosmin Malutan, [:cosmin-malutan]]

I can't reproduce this issue, thought I can see some wrong things in the test.
1 waitForPageLoad waits for load event, but it doesn't assure that the correct page has been loaded in test1, a "Server not found" page also makes the waitForPageLoad pass. 
2 For the firs tab we use the controller and for the second and third we use tabBrowser.controller, this shouldn't affect the test but it's inconsistent. I won't bring a new patch until I can reproduce this but I would like the two things changed too.

Comment 14

[Cosmin Malutan, [:cosmin-malutan]]

This failed once in the Fridays Beta, and once in last Tuesday. I couldn't reproduced it when I ran the test for 200 times.

Comment 15

[Henrik Skupin [:whimboo][⌚️UTC+2]]

This could actually be a fallout from bug 1112601.

Comment 16

[Cosmin Malutan, [:cosmin-malutan]]

Might be, as I already said we don't check in the first test if the expected pages are open, so we might fail in opening the tabs in test1 and not in restoring them in second test.
Also I would add an hellper method in utils, waitForSessionWrite(aCallback) which will add an observer on topic "sessionstore-state-write" execute the callback and wait for observer to be notified. This will let us know if we have the tabs saved in session so we will know if we failed to open the tabs in the first place or we failed to restore them in second test.
Henrik what do you think, should I do this enhancement?

Comment 17

[Henrik Skupin [:whimboo][⌚️UTC+2]]

For such a specific test it might be helpful to have, but please not in utils. We might need a module more sessionstore specific.

Comment 18

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: follow-up patch

I added a method to wait for session data to be written to the disk. 
I added a check in the first tests that we open the desired tabs.


http://mozmill-crowd.blargon7.com/#/functional/report/946d3cd70aaf19c33a8878f8c4d772dc

Comment 19

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8538426 [details] [diff] [review]
follow-up patch

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

::: firefox/lib/sessionstore.js
@@ +22,5 @@
>                            .getService(Ci.nsISessionStore);
>  
>  // Preference for indicating the amount of restorable tabs
>  const SESSIONSTORE_MAXTABS_PREF = 'browser.sessionstore.max_tabs_undo';
> +const TIMEOUT_SESSION_SAVE = 60000;

Both are different blocks. Also do we really need 60s? This sounds massive!

@@ +279,5 @@
> + *        Function that will dirty the session
> + * @param {number} [aTimeout=60000]
> + *        Timeout the session data to be saved on disk
> + */
> +function waitForSessionSave(aCallback, aTimeout) {

default to 60s here directly.

@@ +300,5 @@
>  exports.getClosedTabCount = getClosedTabCount;
>  exports.resetRecentlyClosedTabs = resetRecentlyClosedTabs;
>  exports.undoClosedTab = undoClosedTab;
>  exports.undoClosedWindow = undoClosedWindow;
> +exports.waitForSessionSave = waitForSessionSave;

waitForSessionSaved please

::: firefox/tests/functional/testSessionStore/testRestorePreviousSession/test1.js
@@ +57,5 @@
> +  TEST_DATA.forEach((aURL, aIndex) => {
> +    // Wait for the expected tab to load
> +    var tab;
> +    assert.waitFor(() => !!(tab = tabs.getTabsWithURL(aURL)[0]),
> +                   "Tab with URL '" + aURL + "' has been opened");

I don't see why you need the tab variable here.

Comment 20

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: follow-up patch v2.0

(In reply to Henrik Skupin (:whimboo) from comment #19)
> >  // Preference for indicating the amount of restorable tabs
> >  const SESSIONSTORE_MAXTABS_PREF = 'browser.sessionstore.max_tabs_undo';
> > +const TIMEOUT_SESSION_SAVE = 60000;
> 
> Both are different blocks. Also do we really need 60s? This sounds massive!
I removed the const and default directly in function arguments list as suggested. It needs somewhere between 5-10 seconds, but from experience when we will ran 200 jobs it might fail with timeout so for safety I left it 1m.

Comment 21

[Andreea Matei [:AndreeaMatei]]

Comment on attachment 8538556 [details] [diff] [review]
follow-up patch v2.0

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

Tests well, has all requested changes.

Comment 22

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8538556 [details] [diff] [review]
follow-up patch v2.0

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

::: firefox/lib/sessionstore.js
@@ +274,5 @@
> +/**
> + * Executes a function and waits for session to be saved on disk
> + *
> + * @param {function} aCallback
> + *        Function that will dirty the session

In all other cases we use "callback". I would propose we do the same here and in the method description.

Also i would rephrase the text to something like: "that will cause the session to be written to disk".

@@ +278,5 @@
> + *        Function that will dirty the session
> + * @param {number} [aTimeout=60000]
> + *        Timeout the session data to be saved on disk
> + */
> +function waitForSessionSaved(aCallback, aTimeout = 60000) {

As the coding styles say no blanks before or after a '=' in the parameter list.

@@ +284,5 @@
> +  var observer = { observe: function () { updated = true } };
> +
> +  Services.obs.addObserver(observer, TOPIC_SESSIONSTORE_STATE_CHANGED, false);
> +  try {
> +    aCallback();

I do not see we have an assert to check if that is really a function.

@@ +286,5 @@
> +  Services.obs.addObserver(observer, TOPIC_SESSIONSTORE_STATE_CHANGED, false);
> +  try {
> +    aCallback();
> +
> +    assert.waitFor(() =>  updated,

nit: extra blank.

::: firefox/tests/functional/testSessionStore/testRestorePreviousSession/test1.js
@@ +56,5 @@
> +  // Check if correct tabs have been opened
> +  TEST_DATA.forEach((aURL, aIndex) => {
> +    // Wait for the expected tab to load
> +    assert.waitFor(() => !!tabs.getTabsWithURL(aURL)[0],
> +                   "Tab with URL '" + aURL + "' has been opened");

I don't see why we have to use tabs.getTabsWithURL(). It should be clear which tab has which page loaded, so you can compare with the index. Here we do not check the ordering.

Comment 23

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: follow-up patch v2.1

I fixed those nits, here is a complete testrun:
http://mozmill-crowd.blargon7.com/#/functional/report/f4189e259b668417231c4d9ed055e247

Comment 24

[Andreea Matei [:AndreeaMatei]]

Comment on attachment 8540177 [details] [diff] [review]
follow-up patch v2.1

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

I don't see any changes in this patch, forgot to qrefresh maybe?

Comment 25

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: follow-up patch v2.1

Yes, sorry for that.

Comment 26

[Andreea Matei [:AndreeaMatei]]

Comment on attachment 8541191 [details] [diff] [review]
follow-up patch v2.1

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

You can add review for Henrik next time.

::: firefox/lib/sessionstore.js
@@ +275,5 @@
> + * Executes a function and waits for session to be saved on disk
> + *
> + * @param {function} aCallback
> + *        Callback that will cause the session to be written to disk
> + * @param {number} [aTimeout=60000]

Please have the types start with uppercase.

@@ +282,5 @@
> +function waitForSessionSaved(aCallback, aTimeout=60000) {
> +  var updated = false;
> +  var observer = { observe: function () { updated = true } };
> +
> +  assert.equal(typeof aCallback, "function", "Callback function is defined");

We usually have added this check at the very beginning.

@@ +290,5 @@
> +    aCallback();
> +
> +    assert.waitFor(() => updated, "Session has been saved to disk", aTimeout);
> +  }
> +  finally {hg

Please remove hg.

Comment 27

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: follow-up patch v3.0

(In reply to Andreea Matei [:AndreeaMatei] from comment #26)
> @@ +275,5 @@
> > + * Executes a function and waits for session to be saved on disk
> > + *
> > + * @param {function} aCallback
> > + *        Callback that will cause the session to be written to disk
> > + * @param {number} [aTimeout=60000]
> 
> Please have the types start with uppercase.
I never knew we changed this, from what I know we use lowercase for types since the beginning. If that changed we should wait for a re-factoring bug to change the other cases in the same file, otherwise it will be really ugly to have mixed-style in the same file.
bug 671705 comment 9
bug 671705 comment 24
bug 799149 comment 51
bug 1025849 comment 12
bug 882137 comment 5
bug 1005811 comment 36

I made the other two changes. Thanks! :) 

Report:
http://mozmill-crowd.blargon7.com/#/functional/report/52eab30bb033ac30e956a49469a152cb

Comment 28

[Andreea Matei [:AndreeaMatei]]

We have bug 882137 for jsdoc updates, but yes, I was under the impression it had to be with uppercase, bug 882137 comment 5 clarifies that it's lowercase so we're fine.

Comment 29

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8542918 [details] [diff] [review]
follow-up patch v3.0

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

::: firefox/lib/sessionstore.js
@@ +279,5 @@
> + * @param {number} [aTimeout=60000]
> + *        Timeout the session data to be saved on disk
> + */
> +function waitForSessionSaved(aCallback, aTimeout=60000) {
> +  assert.equal(typeof aCallback, "function", "Callback function is defined");

And once more again... Callback implies that it is a function.

::: firefox/tests/functional/testSessionStore/testRestorePreviousSession/test1.js
@@ +46,5 @@
> +
> +    // Open 2 new tabs
> +    openTabWithUrl(TEST_DATA[1]);
> +    openTabWithUrl(TEST_DATA[2]);
> +  });

So I think we can hit a race condition here. If the session is saved after loading the first page, the other two will not be included. I think the waitForSessionSaved() call should only be around the last page load.

Comment 30

[Cosmin Malutan, [:cosmin-malutan]]

Attachment: follow-up patch v3.1

(In reply to Henrik Skupin (:whimboo) from comment #29)
> > +    // Open 2 new tabs
> > +    openTabWithUrl(TEST_DATA[1]);
> > +    openTabWithUrl(TEST_DATA[2]);
> > +  });
> 
> So I think we can hit a race condition here. If the session is saved after
> loading the first page, the other two will not be included. I think the
> waitForSessionSaved() call should only be around the last page load.
Makes sense, I call waitForSessionSaved only when opening the last tab.
 
http://mozmill-crowd.blargon7.com/#/functional/report/5c7e7a22f9984b46554bc3b9fc590735

Comment 31

[Mihaela Velimiroviciu (:mihaelav)]

Comment on attachment 8543863 [details] [diff] [review]
follow-up patch v3.1

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

Looks good to me.

Comment 32

[Henrik Skupin [:whimboo][⌚️UTC+2]]

Comment on attachment 8543863 [details] [diff] [review]
follow-up patch v3.1

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

Looks fine to me now. Thanks!

Comment 33

[Andreea Matei [:AndreeaMatei]]

Comment on attachment 8543863 [details] [diff] [review]
follow-up patch v3.1

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

http://hg.mozilla.org/qa/mozmill-tests/rev/dc011ae4ed03 (default)

Lets see how it behaves and check backporting then.

Comment 34

[Cosmin Malutan, [:cosmin-malutan]]

Didn't failed anymore on nightly since we landed this patch, the patch applies cleanly on Aurora and Beta, let's back-port it. 
http://mozmill-daily.blargon7.com/#/functional/failure?app=Firefox&branch=All&platform=All&from=2015-01-05&to=2015-01-12&test=%2FtestSessionStore%2FtestRestorePreviousSession%2Ftest2.js&func=testRestorePreviousSession

Comment 35

[Henrik Skupin [:whimboo][⌚️UTC+2]]

The backport to aurora should be done by todays merge, and beta can get it the next days.

Comment 36

[Andreea Matei [:AndreeaMatei]]

I already done this before seeing the comment. Was thinking it would cause less conflicts in the merge, but the other bugs that can also be backported I'll leave for the merge then.
http://hg.mozilla.org/qa/mozmill-tests/rev/eef67639dcb6 (aurora)
http://hg.mozilla.org/qa/mozmill-tests/rev/d349fcd32030 (beta)