800800 - Ensure we always wait for removeAllHistory() in places.js to stop the failure 'Browsing History has been cleared'

Status: RESOLVED FIXED

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

Description

[Andreea Matei [:AndreeaMatei]]

It's already happening for the second time, on Windows XP with ESR 10.0.8 and now 10.0.9.

Details:
TimeoutError("Browsing History has been cleared")@resource://mozmill/modules/utils.js:449 waitFor([object Proxy],"Browsing History has been cleared")@resource://mozmill/modules/utils.js:487 

This is related to places.js module.

Comment 1

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

We are making use of the places method not only in that test, right? So I wonder why it works in other tests.

Comment 2

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

Looks like this only happens for release builds on esr10. Please ensure to use those builds and no nightly ones. I will put this in for next week.

Comment 3

[Andreea Matei [:AndreeaMatei]]

Has happened with testCheckItemHighlight.js also:

* http://mozmill-ci.blargon7.com/#/functional/failure?branch=All&platform=All&from=2012-10-12&to=&test=%2FtestAwesomeBar%2FtestCheckItemHighlight.js&func=testCheckItemHighlight.js%3A%3AsetupModule

Comment 4

[Alex Lakatos[:AlexLakatos]]

(In reply to Andreea Matei [:AndreeaMatei] from comment #3)
> Has happened with testCheckItemHighlight.js also:
> 
> *
> http://mozmill-ci.blargon7.com/#/functional/
> failure?branch=All&platform=All&from=2012-10-
> 12&to=&test=%2FtestAwesomeBar%2FtestCheckItemHighlight.
> js&func=testCheckItemHighlight.js%3A%3AsetupModule
Given this, I think we should change the summary to reflect what we need to accomplish here: Ensure we always wait for removeAllHistory() in places.js

Comment 5

[Alex Lakatos[:AlexLakatos]]

Attachment: skipPatch v1.0 [esr10]

I can not reproduce the issue with ESR 10.0.9 nor 10.0.10(candidate build1). The fail frequency was low, and in case you want to skip the failing tests, here is a skip patch. But I would advise against it, seeing as how nothing failed in the last 12 days.
I would propose closing this as WORKSFORME, and reopening if it fails again.

Comment 6

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

Comment on attachment 675094 [details] [diff] [review]
skipPatch v1.0 [esr10]

I do not think we want to skip it. If possible it should be investigated on the machine the failure happened. Also I would like to keep it open for now.

Comment 7

[Dave Hunt [:davehunt] [he/him] ⌚BST]

As Henrik suggests in comment 6, please try to replicate on the machine the failure is occurring on.

Comment 8

[Alex Lakatos[:AlexLakatos]]

(In reply to Dave Hunt (:davehunt) from comment #7)
> As Henrik suggests in comment 6, please try to replicate on the machine the
> failure is occurring on.
It's happening on different machines and on different branches as well. The initial failure happens on mm-win-xp-3 and the recent failure happens on mm-win-xp-1
Other tests have started failing, but not frequently
http://mozmill-ci.blargon7.com/#/functional/failure?branch=All&platform=All&from=2012-10-30&to=&test=%2FtestAwesomeBar%2FtestSuggestHistory.js&func=testSuggestHistory.js%3A%3AsetupModule

Comment 9

[Andreea Matei [:AndreeaMatei]]

I believe what happens here is that over a functional testrun, not all the tests clear history in tearDown. Actually only those in awesomeBar do. 
I've noticed that the tests are not run alphabetically, in fact awesomeBar tests are somewhere at the end on the testrun. So they will have to remove all the history added until then.

We have several options: to increase the waitFor timeout, to clear history after each test or to see if we can redesign the method.

Comment 10

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Andreea: It's true that there's no guarantee to the order the tests are run unless you use a manifest file, but as far as I can tell the awesomebar tests are being run early on the suite.

Could you try to replicate the issue using the manifest files and forcing the relevant tests to run last?

Comment 11

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

(In reply to Andreea Matei [:AndreeaMatei] from comment #9)
> I believe what happens here is that over a functional testrun, not all the
> tests clear history in tearDown. Actually only those in awesomeBar do. 
> I've noticed that the tests are not run alphabetically, in fact awesomeBar
> tests are somewhere at the end on the testrun. So they will have to remove
> all the history added until then.

That's only true for Linux but not for Windows and OS X. So on which platforms are we facing this bug?

Comment 12

[Andreea Matei [:AndreeaMatei]]

On Windows XP is happening. I will look then to see how we can remove history otherwise or if we can wait for another event also.

Comment 13

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

Then your above idea is not the cause. On Windows the awesomebar tests are getting executed first. How much time do they take means which timeout do we need? Are you testing on a fully utilized machine?

Comment 14

[Andreea Matei [:AndreeaMatei]]

I've managed to reproduce it constantly (at least once in 20 runs) with the builds from the mozmill-ci dashboard (ESR10 and default, not beta), on fully loaded XP vm.
The timeout needed not to fail in these conditions is 8000.

Comment 15

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

Does it happen when you run this test on its own too?

Comment 16

[Andreea Matei [:AndreeaMatei]]

Nope, on single runs of different awesomebar tests it's not failing.

Comment 17

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

What's the minimum set of tests then? We really don't add that much to the history, so it's suspicious. What would you check next?

Comment 18

[Alex Lakatos[:AlexLakatos]]

Failed in /testAwesomeBar/testVisibleItemsMax.js
http://mozmill-ci.blargon7.com/#/functional/failure?branch=All&platform=All&from=2012-12-04&to=&test=%2FtestAwesomeBar%2FtestVisibleItemsMax.js&func=testVisibleItemsMax.js%3A%3AsetupModule

Comment 19

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

Can we please get this fixed soon? While Andreea is away someone else from the SV team should take care of it. This is a P1 failure. Thanks.

Comment 20

[Alex Lakatos[:AlexLakatos]]

Failed on 17esr today on Windows XP, on two tests in the same run
http://mozmill-ci.blargon7.com/#/functional/report/352218d7e3125c857fc1d371679d9997

Comment 21

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

This is our other P1 issue for this week. So please put focus on it so we can fix it. Seems like with the patch on bug 815605 it's failing constantly now.

Comment 22

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

Andreea, as given this should be fixed. I have landed the fix on bug 815605 on all other branches. So if nothing fails today please mark this bug as fixed.

Comment 23

[Andreea Matei [:AndreeaMatei]]

No more failures. Will reopen if the case, hopefully not.

Comment 24

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

Doesn't look that it is fixed for esr10, esr17, and most likely 17.0 release:

http://mozmill-ci.blargon7.com/#/functional/report/a11aa7b15f4e571fd6fe21a2db2c61cc

http://mozmill-ci.blargon7.com/#/functional/report/a11aa7b15f4e571fd6fe21a2db2b9200

Comment 25

[Andreea Matei [:AndreeaMatei]]

The ESR10 link report has no failure now, just on the restart addons.

I checked the files from the report and it appears on esr17 the patch wasn't applied at the moment of the run:
http://hg.mozilla.org/qa/mozmill-tests/file/f25449c1ea43/lib/places.js

Comment 26

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

(In reply to Andreea Matei [:AndreeaMatei] from comment #25)
> I checked the files from the report and it appears on esr17 the patch wasn't
> applied at the moment of the run:
> http://hg.mozilla.org/qa/mozmill-tests/file/f25449c1ea43/lib/places.js

As far as I can see it has: http://hg.mozilla.org/qa/mozmill-tests/file/f25449c1ea43/lib/places.js#l104

Comment 27

[Andreea Matei [:AndreeaMatei]]

The patch wasn't applied there, no failures today on ESR17, so marking as closed for now.

Comment 28

[Daniela Petrovici]

Reproducible on Nightly builds on XP SP3 - it happened in 12/21 in the test /testAwesomeBar/testAccessLocationBar.js
http://mozmill-ci.blargon7.com/#/functional/report/a11aa7b15f4e571fd6fe21a2dbbd2f40

Comment 29

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

Has it been ever failed again since Dec 21st? If not please close this bug. It might be it was a fallout from the pb mode changes.

Comment 30

[Andrei Eftimie]

(In reply to Henrik Skupin (:whimboo) from comment #29)
> Has it been ever failed again since Dec 21st? If not please close this bug.
> It might be it was a fallout from the pb mode changes.

Happened again on 2012-12-30 on Win XP on Aurora (fr)
http://mozmill-ci.blargon7.com/#/functional/report/23d8fbdd0190d4b0496d6b129f0bd5b4

Comment 31

[Andrei Eftimie]

Again on Nightly Win XP in the test:
/testAwesomeBar/testVisibleItemsMax.js
http://mozmill-ci.blargon7.com/#/functional/report/23d8fbdd0190d4b0496d6b129f5f03c1

Comment 32

[Andrei Eftimie]

Also on the 18.0 branch:
http://mozmill-ci.blargon7.com/#/functional/report/23d8fbdd0190d4b0496d6b129f69b694

Comment 33

[mario garbi]

Happened again on Firefox 19.0 (19.0, en-US, 20130109111322): 
http://mozmill-ci.blargon7.com/#/functional/report/23d8fbdd0190d4b0496d6b129fe8a608

Comment 34

[Andreea Matei [:AndreeaMatei]]

I'm curious to see if this will fail again on the new system, since it's now happening only on Windows.
Until now, I can fix it only by increasing the timeout for the waitFor, so it could be a issue of slow machines.

Comment 35

[Andreea Matei [:AndreeaMatei]]

Looks like with the new machines this is not failing, for 3 weeks now, yey :)

Comment 36

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

So it's a sign for slowish operating machines then. We have a timeout of 5s right now, that's correct? We should probably increase that to 10s. What do you think?

Comment 37

[Andreea Matei [:AndreeaMatei]]

When I was testing with increased timeout, 8-9 seconds did the trick. So yes, 10s should be safe enough. I will retest it and provide a patch.

Comment 38

[Andreea Matei [:AndreeaMatei]]

Attachment: increase timeout

Increasing timeout.
Applies to default, aurora and beta. Used to occur on esr10 as well but we're not working on that anymore.

Comment 39

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

Comment on attachment 709047 [details] [diff] [review]
increase timeout

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

::: lib/places.js
@@ +134,4 @@
>      browserHistory.removeAllPages();
>      assert.waitFor(function () {
>        return finishedStateFlag;
> +    }, "Browsing History has been cleared", 10000, 100);

I would make this a global constant instead. Most likely we should also apply this to the other method which relies on the observer.

Comment 40

[Andreea Matei [:AndreeaMatei]]

Attachment: increase timeout

As talked on IRC, added another timeout for clearing history.

Comment 41

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

Comment on attachment 710572 [details] [diff] [review]
increase timeout

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

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

Comment 42

[Andreea Matei [:AndreeaMatei]]

Applies cleanly to all other branches.
Fingers crossed to never see the error again.

Comment 43

[Dave Hunt [:davehunt] [he/him] ⌚BST]

Transplanted as:
http://hg.mozilla.org/qa/mozmill-tests/rev/213e20e8ba92 (mozilla-aurora)
http://hg.mozilla.org/qa/mozmill-tests/rev/6692f287b545 (mozilla-beta)
http://hg.mozilla.org/qa/mozmill-tests/rev/6c0b67d188e9 (mozilla-release)
http://hg.mozilla.org/qa/mozmill-tests/rev/b70b3bb0996c (mozilla-esr17)