Last Comment Bug 704140 - Failure in /testToolbar/testBackForwardButtons.js | Timeout waiting for element with id mission_statement
: Failure in /testToolbar/testBackForwardButtons.js | Timeout waiting for eleme...
Status: VERIFIED FIXED
[mozmill-test-failure]
:
Product: Mozilla QA
Classification: Other
Component: Mozmill Tests (show other bugs)
: unspecified
: All All
: -- normal (vote)
: ---
Assigned To: Remus Pop (:RemusPop)
:
Mentors:
https://bugzilla.mozilla.org/buglist....
Depends on: 892415
Blocks:
  Show dependency treegraph
 
Reported: 2011-11-21 07:34 PST by Remus Pop (:RemusPop)
Modified: 2013-07-11 03:13 PDT (History)
5 users (show)
remus.pop: in‑litmus+
See Also:
QA Whiteboard:
Iteration: ---
Points: ---
fixed
fixed
fixed
fixed
fixed


Attachments
proposed fix v1 (all branches) (1.71 KB, patch)
2011-11-22 06:21 PST, Remus Pop (:RemusPop)
vlad.mozbugs: review+
Details | Diff | Review
screenshot of fail (133.15 KB, image/png)
2011-12-08 00:34 PST, Remus Pop (:RemusPop)
no flags Details
skip patch v1 [checked-in: default, aurora, beta] (2.17 KB, patch)
2012-01-05 07:58 PST, Remus Pop (:RemusPop)
vlad.mozbugs: review+
hskupin: review+
Details | Diff | Review
patch v1 (all branches) (2.03 KB, patch)
2012-06-08 05:26 PDT, Remus Pop (:RemusPop)
hskupin: review-
Details | Diff | Review
patch v2 (all branches) (2.07 KB, patch)
2012-06-08 07:11 PDT, Remus Pop (:RemusPop)
hskupin: review-
Details | Diff | Review
patch v3 (all branches) (2.02 KB, patch)
2012-06-11 00:00 PDT, Remus Pop (:RemusPop)
hskupin: review-
Details | Diff | Review
patch v4 (all branches) (2.62 KB, patch)
2012-06-14 05:23 PDT, Remus Pop (:RemusPop)
hskupin: review+
Details | Diff | Review
patch v5 (all branches) (2.62 KB, patch)
2012-06-15 02:52 PDT, Remus Pop (:RemusPop)
hskupin: review+
Details | Diff | Review

Description Remus Pop (:RemusPop) 2011-11-21 07:34:15 PST
TEST: /testToolbar/testBackForwardButtons.js
ERROR: Timeout exceeded for waitForElement ID: mission_statement
WHEN: 2011-11-21
FIRST: 2011-10-11
BRANCHES: default, aurora

This occurs on all OS's.

My main concern is that this code from the test:
> // Click on the Back button for the number of local pages visited
>   for (var i = LOCAL_TEST_PAGES.length - 2; i >= 0; i--) {
>     controller.click(backButton);

>     var element = new elementslib.ID(controller.tabs.activeTab, LOCAL_TEST_PAGES[i].id);
>     controller.waitForElement(element, TIMEOUT);

fails at getting the variable 'element' because if the page is not displayed yet, elementslib.ID cannot get the element with that ID. 
I cannot reproduce this locally, but it's an assumption. 

If this sounds sane to you I could come up with a patch.
If I am correct, could waitForPageLoad() work or should we take another approach?
Comment 1 Henrik Skupin (:whimboo) 2011-11-21 07:37:59 PST
Is this a regression on default and aurora only?
Comment 2 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2011-11-21 18:50:15 PST
Remus, assuming clicking the back button fires a pageLoad event, your solution should suffice. But please investigate if this is a Firefox regression first.

Thanks
Comment 3 Remus Pop (:RemusPop) 2011-11-21 23:02:46 PST
I cannot reproduce it locally so I assume it's not a regression. A patch will be available soon.
Comment 4 Remus Pop (:RemusPop) 2011-11-22 06:21:28 PST
Created attachment 576137 [details] [diff] [review]
proposed fix v1 (all branches)

I "concatenated" the defining of element variable with the use of waitForElement, so we wait for the element to be present.
Comment 5 Maniac Vlad Florin (:vladmaniac) 2011-11-22 07:55:18 PST
Comment on attachment 576137 [details] [diff] [review]
proposed fix v1 (all branches)

Looks good, works good
Comment 6 Henrik Skupin (:whimboo) 2011-11-22 08:57:36 PST
This change is a no-op. Nothing is different for the waitForElement method because in both situations an instance of Element will be passed in. Given that the element is a wrapper it holds the specific values to retrieve the real node based on the specified type.

I don't see why this change should fix it, Vlad.
Comment 7 Remus Pop (:RemusPop) 2011-11-22 22:53:52 PST
My bad then, sorry. I assumed that waitForElement will wait for the element to appear on the page and in the original representation the real nodes you are talking about do not get loaded so "element" variable does not get loaded with the real element.

If this is the case, we would have to find something else to wait for until our page loads. Any suggestion is welcomed. waitForPageLoad does not work here.
Comment 8 Henrik Skupin (:whimboo) 2011-11-23 01:30:35 PST
(In reply to Remus Pop (:RemusPop) from comment #7)
> My bad then, sorry. I assumed that waitForElement will wait for the element
> to appear on the page and in the original representation the real nodes you
> are talking about do not get loaded so "element" variable does not get
> loaded with the real element.

waitForElement waits until the wanted node is part of the DOM and can be found via the given method, e.g. getElementById for elementslib.id(). All that logic is hidden in Element.

I would suggest you add some debugging code locally to check when the node appears. Given that we load the page correctly it has to be present in the DOM.

> If this is the case, we would have to find something else to wait for until
> our page loads. Any suggestion is welcomed. waitForPageLoad does not work
> here.

No, we still have to use waitForElement because waitForPageLoad doesn't work here. The content is delivered from the bfcache and waitForPageLoad doesn't handle it correctly in Mozmill 1.5.x.
Comment 9 Remus Pop (:RemusPop) 2011-12-07 06:01:18 PST
Found the problem. 
This fail appears when the window somehow loses focus, no matter what approach I use in waiting for the element. It seems that it always fails when navigating forward.

What do you suggest to overcome this issue?
Comment 10 Remus Pop (:RemusPop) 2011-12-07 06:29:48 PST
Sometimes I see the forward button as if the mouse cursor was over it.
Comment 11 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2011-12-07 08:55:08 PST
You should investigate why this test loses focus; most likely a test executing before it is not giving focus back to the main browser window properly.

In the meantime, this test should be disabled.
Comment 12 Henrik Skupin (:whimboo) 2011-12-07 13:39:18 PST
What do you mean with loosing focus when clicking on the forward button? The window should never loose focus. Can you create a screencast which visualizes it?
Comment 13 Remus Pop (:RemusPop) 2011-12-08 00:34:14 PST
Created attachment 579982 [details]
screenshot of fail

Please see the forward button. After this the fail will occur.
If the test would not fail we should have seen mozilla_mission.html in the location bar, but the forward button did not get clicked.
Comment 14 Henrik Skupin (:whimboo) 2011-12-08 00:35:58 PST
As mentioned please submit a screencast. Also slow-down the script execution by inserting sleep calls.
Comment 15 Remus Pop (:RemusPop) 2011-12-08 02:00:28 PST
I added some sleep() calls before clicking on the forward button and after clicking it.
I cannot reproduce this fail anymore. Might have something to do with the button not being clickable at some moment, but it's strange that it only occurs on the same page and only for forward.
Comment 16 Henrik Skupin (:whimboo) 2011-12-08 02:20:52 PST
In which step of the test we fail exactly?
Comment 17 Remus Pop (:RemusPop) 2011-12-08 02:24:34 PST
> controller.click(forwardButton);
this isn't executed...

> controller.waitForElement(element, TIMEOUT);
...so this fails
Comment 18 Henrik Skupin (:whimboo) 2011-12-08 02:31:50 PST
This information is not helpful because this call is inside a loop. Please be really specific with the step. As best describe in pseudo-code if possible.
Comment 19 Remus Pop (:RemusPop) 2011-12-08 02:45:17 PST
This occurs when j=1, so it's the first iteration for the forward actions.
Comment 20 Remus Pop (:RemusPop) 2011-12-08 05:15:36 PST
The test fails on aurora and nightly. Aurora and nightly both hide the forward button if there is no page to forward to. So changes are high that the button is clicked faster than it appears.
Comment 21 Remus Pop (:RemusPop) 2011-12-08 07:23:29 PST
There is a dom attribute that is involved, "disabled", but that does not tell us when the button appears. The dom attribute does not exist if forward button is visible and has a value of false if it's visible.

There is an animation and we need to wait for it to finish.
Comment 22 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2011-12-08 09:39:55 PST
Remus, does adding a waitFor(!disabled) fix this?
Comment 23 Henrik Skupin (:whimboo) 2011-12-08 12:36:32 PST
I'm not sure what you mean that both Nightly and Aurora are hiding the button?! The button is always visible and only gets disabled. Also what do you mean with animation? There is none, it directly switches from disabled to enabled.
Comment 24 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2011-12-08 12:55:11 PST
(In reply to Henrik Skupin (:whimboo) from comment #23)
> I'm not sure what you mean that both Nightly and Aurora are hiding the
> button?! The button is always visible and only gets disabled. Also what do
> you mean with animation? There is none, it directly switches from disabled
> to enabled.

On my Mac Nightly, the FORWARD button is visibly hidden until you go BACK a page at which point it animates to appear. When you go all the way forward again, the button disappears. The FOWARD button does not just get greyed out.
Comment 25 Henrik Skupin (:whimboo) 2011-12-08 13:21:59 PST
Oh. This only happens for fresh profiles but not for existing ones. That why I haven't seen it yet. So yeah, that makes a difference. I would suggest to ask the developer who has implemented that new feature, or check MXR which event we have to wait for.
Comment 26 Remus Pop (:RemusPop) 2011-12-08 22:52:04 PST
(In reply to Anthony Hughes, Mozilla QA (irc: ashughes) from comment #22)
> Remus, does adding a waitFor(!disabled) fix this?

Unfortunately not, Anthony. We specifically have to wait for the animation to complete.
Comment 27 Remus Pop (:RemusPop) 2011-12-09 04:39:16 PST
https://bugzilla.mozilla.org/show_bug.cgi?id=674744 
https://bugzilla.mozilla.org/show_bug.cgi?id=677027
are responsible for this animation. For what I've seen, on linux there is a 400ms animation time. First thing that comes to my mind is just use a sleep(500) unless we find something reliable.
Comment 28 Henrik Skupin (:whimboo) 2011-12-09 05:01:44 PST
I would assume that there is an event which gets fired for the element when the transition has been finished.
Comment 29 Remus Pop (:RemusPop) 2011-12-09 05:11:15 PST
Found something else instead. Element with id "urlbar" changes margin-left from 4px to -32px. So we would have to wait for margin-left to be exactly 4px in our case (forward is visible).
Comment 30 Henrik Skupin (:whimboo) 2011-12-09 05:43:02 PST
Please avoid conditional positions or margins. As requested find an event if possible.
Comment 31 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2011-12-09 06:26:15 PST
I seem to remember a similar problem where we had to add a special waitFor for notification bars. Perhaps we could reuse some of that code?
Comment 32 Remus Pop (:RemusPop) 2011-12-09 06:31:52 PST
Found the event.
https://developer.mozilla.org/en/CSS/CSS_transitions#Detecting_the_completion_of_a_transition

So we should use an event listener.
Comment 33 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2011-12-09 06:38:34 PST
Thanks for finding that Remus. Henrik, could we add a generic listener for this to the API which we can create wrappers for cases we need to use it?
Comment 34 Henrik Skupin (:whimboo) 2011-12-09 07:21:51 PST
Lets come up with a code example first. I would like to see it before we should make a decision.
Comment 35 Henrik Skupin (:whimboo) 2012-01-03 13:51:38 PST
Remus, can you please come up with an update to this bug? It fails nearly constantly at least on OS X 10.7. We have to fix or skip it.
Comment 36 Anthony Hughes (:ashughes) [GFX][QA][Mentor] 2012-01-04 19:11:04 PST
This is now one of our top failures.

Remus, if you can't fix it by tomorrow, disable it. I don't want to see this failure in our reports tomorrow.
Comment 37 Remus Pop (:RemusPop) 2012-01-05 07:58:56 PST
Created attachment 586084 [details] [diff] [review]
skip patch v1 [checked-in: default, aurora, beta]

This skips the test. A fix will be available soon.
Comment 38 Maniac Vlad Florin (:vladmaniac) 2012-01-05 08:10:55 PST
Comment on attachment 586084 [details] [diff] [review]
skip patch v1 [checked-in: default, aurora, beta]

+ 

over to Anthony for final rev and check in
Comment 39 Henrik Skupin (:whimboo) 2012-01-05 23:47:24 PST
Comment on attachment 586084 [details] [diff] [review]
skip patch v1 [checked-in: default, aurora, beta]

I want to see this checked-in for our todays daily builds. So taking the review request. I will land it across branches and will not skip release as the description assumes.
Comment 40 Henrik Skupin (:whimboo) 2012-01-05 23:56:50 PST
Comment on attachment 586084 [details] [diff] [review]
skip patch v1 [checked-in: default, aurora, beta]

Landed as:
http://hg.mozilla.org/qa/mozmill-tests/rev/55d7034f5c1f (default)
http://hg.mozilla.org/qa/mozmill-tests/rev/e5255c7f3ff6 (aurora)
http://hg.mozilla.org/qa/mozmill-tests/rev/8f6f795737d2 (beta)
Comment 41 Remus Pop (:RemusPop) 2012-01-06 07:13:22 PST
Removed Mozmill testgroup for the testcases with ID:
15498, 40596
Comment 42 Henrik Skupin (:whimboo) 2012-06-05 04:10:05 PDT
What's the status of this bug?
Comment 43 Remus Pop (:RemusPop) 2012-06-05 04:24:45 PDT
There's a need to find a method to calculate (get) the initial length of the location bar. The resizing is always the same size.
Comment 44 Henrik Skupin (:whimboo) 2012-06-05 04:34:22 PDT
Why do we have to do that? I don't see a reason why we have to start calculating any widget sizes.
Comment 45 Remus Pop (:RemusPop) 2012-06-05 04:37:00 PDT
That was the initial thought on how to check when the forward button is completely visible. It was something like the location bar is now 200px, and then we should waitfor location bar being 180px long.
I don't know if there is some event happening.
Comment 46 Henrik Skupin (:whimboo) 2012-06-05 04:39:42 PDT
Why would you do that? You can wait until the forward button has been made visible via the appropriate JS property.
Comment 47 Remus Pop (:RemusPop) 2012-06-05 04:45:08 PDT
As far as I remember that did not work, but it's worth to look again.
Comment 48 Remus Pop (:RemusPop) 2012-06-07 04:46:11 PDT
No property is of good use here. Properties change before the transition ends.
I will try to listen to 'transitionend' to see if it fires when the transition is complete, but I think the next method would be easier.
Other than that we have getElementStyle in the utils lib which works fine for what we want.
We just have to check margin-left of urlbar, not container
Comment 49 Henrik Skupin (:whimboo) 2012-06-07 06:36:06 PDT
So I would propose we check how Mochitests are doing that. I believe that there should be at least a single test around.
Comment 50 Remus Pop (:RemusPop) 2012-06-08 00:34:24 PDT
Searched MXR but I couldn't find any test related to the forward button.
Comment 51 Henrik Skupin (:whimboo) 2012-06-08 00:41:34 PDT
(In reply to Remus Pop (:RemusPop) from comment #50)
> Searched MXR but I couldn't find any test related to the forward button.

Ok, so afair Jared was working on the conditional forward button. Lets ask him what would be the best way to test if it has become visible.
Comment 52 Jared Wein [:jaws] (please needinfo? me) 2012-06-08 04:31:21 PDT
The best way to check this would be to add an event listener for "transitionend" and then in that event listener check if the forward button has the "disabled" property to know if it will accept clicks.
Comment 53 Remus Pop (:RemusPop) 2012-06-08 05:26:35 PDT
Created attachment 631356 [details] [diff] [review]
patch v1 (all branches)

I've attached an event listener to the forward button. When the event fires, onTransitionEnd will set transitionEnd to true so out waitFor will continue. Also we are waiting for the disabled property to be set to false.
Comment 54 Henrik Skupin (:whimboo) 2012-06-08 05:45:15 PDT
Comment on attachment 631356 [details] [diff] [review]
patch v1 (all branches)

>+  transitionFinished = false;

You missed a var.

>+  forwardButton.getNode().addEventListener("transitionend", onTransitionEnd, false);

Please declare the function right above in the test method.

>+     return transitionFinished && !forwardButton.disabled;

How can this work? forwardButton is an Element and not a node so it will not have a disabled property. Also you should use hasAttribte('disabled') here.

>+   }, "Transition has been finished");

This has to be more descriptive so people can understand what we are waiting for: 'forward button has been made visible'

>+  forwardButton.getNode().removeEventListener("transitionend", onTransitionEnd, false);

That's the wrong location to remove the listener. Do it right in the callback. Otherwise we will leak this listener when a test above fails.
Comment 55 Remus Pop (:RemusPop) 2012-06-08 05:51:25 PDT
(In reply to Henrik Skupin (:whimboo) from comment #54)
> Comment on attachment 631356 [details] [diff] [review]
> patch v1 (all branches)
 
> >+     return transitionFinished && !forwardButton.disabled;
> 
> How can this work? forwardButton is an Element and not a node so it will not
> have a disabled property. Also you should use hasAttribte('disabled') here.

The javascript object has that property, which has the same value as the DOM attribute.
Comment 56 Henrik Skupin (:whimboo) 2012-06-08 06:12:02 PDT
But it will raise a strict warning if .disabled doesn't exist. So you would have to use 'disabled' in object. hasAttribute hides that nicely.
Comment 57 Remus Pop (:RemusPop) 2012-06-08 06:45:00 PDT
.disabled always exists in the js object. It is either set to true or false.

But I will use hasAttribute if you think that will work for sure.
Comment 58 Remus Pop (:RemusPop) 2012-06-08 07:11:25 PDT
Created attachment 631382 [details] [diff] [review]
patch v2 (all branches)

Addressed all requests.
Comment 59 Henrik Skupin (:whimboo) 2012-06-08 07:14:43 PDT
If we have DOM attributes we should prefer those instead of using JS properties.
Comment 60 Henrik Skupin (:whimboo) 2012-06-08 08:12:45 PDT
Comment on attachment 631382 [details] [diff] [review]
patch v2 (all branches)

>+  var transitionFinished = false;
>+
>+  function onTransitionEnd() {
>+    transitionFinished = true;
>+    forwardButton.removeEventListener("transitionend", onTransitionEnd, false);
>+  }
>+
>+  forwardButton.getNode().addEventListener("transitionend", onTransitionEnd, false);

I hate that we can't make use of the waitForEvent() method in Mozmill's controller (see bug 762925). So that's fine here.

>+   // Wait for forward button to be visible
>+   controller.waitFor(function() {
>+     return transitionFinished && !forwardButton.getNode().hasAttribute('disabled');
>+   }, "The forward button has been made visible");

There is really no need for the comment. All we have to know is in the waitFor message.

Keep in mind that I haven't tested the code yet. If you can come up with a quick update I can test over the weekend.
Comment 61 Remus Pop (:RemusPop) 2012-06-11 00:00:59 PDT
Created attachment 631813 [details] [diff] [review]
patch v3 (all branches)

Removed the comment.
Comment 62 Henrik Skupin (:whimboo) 2012-06-11 09:25:26 PDT
Comment on attachment 631813 [details] [diff] [review]
patch v3 (all branches)

>   // Click on the Forward button for the number of websites visited
>   for (var j = 1; j < LOCAL_TEST_PAGES.length; j++) {
>+   controller.waitFor(function() {
>+     return transitionFinished && !forwardButton.getNode().hasAttribute('disabled');
>+   }, "The forward button has been made visible");
>+
>     controller.click(forwardButton);

Looks good, but something we definitely need here is a more descriptive message. Given that this code runs in a loop we should say: 'made visible for %URI%' or at least 'made visible for the %j% page'?

Also i'm sure that the original test also checked that the forward button is disabled if the latest page in this tab is open. Same would apply to the backward button. We really should add that.
Comment 63 Remus Pop (:RemusPop) 2012-06-14 05:23:34 PDT
Created attachment 633106 [details] [diff] [review]
patch v4 (all branches)

the message is now updated. This patch applies on all branches, including esr10.
Comment 64 Henrik Skupin (:whimboo) 2012-06-14 05:33:51 PDT
Pushed to default:
http://hg.mozilla.org/qa/mozmill-tests/rev/144f26ede858

Please check the next results. If all are passing we can transplant this patch.
Comment 65 Henrik Skupin (:whimboo) 2012-06-14 11:20:04 PDT
This has been failed on OS X 10.7 today:
http://mozmill-ci.blargon7.com/#/functional/report/e67171ea696231bb192f56561516ff6b

Backed out:
http://hg.mozilla.org/qa/mozmill-tests/rev/4b19f597d523
Comment 66 Remus Pop (:RemusPop) 2012-06-15 02:25:34 PDT
I can't get it to fail and it doesn't make any sense. Here is the report on the same platform:
http://mozmill-crowd.blargon7.com/#/functional/report/e67171ea696231bb192f56561522d2e4
Comment 67 Henrik Skupin (:whimboo) 2012-06-15 02:35:34 PDT
Well, right now it's hard to say why because we check for the transitioned event and the disabled state. But what I think it's a race condition. You will have to insert the transitioned event listener already before you actually use the back button. Otherwise we can miss it and that's probably what happened here.
Comment 68 Remus Pop (:RemusPop) 2012-06-15 02:52:31 PDT
Created attachment 633449 [details] [diff] [review]
patch v5 (all branches)

As suggested, I've moved the lines in which we add the event listener. Would be nice if we could have the testrun results today.
Comment 69 Henrik Skupin (:whimboo) 2012-06-15 03:07:13 PDT
Pushed:
http://hg.mozilla.org/qa/mozmill-tests/rev/3123f0da26f5

Lets hope that it will stick today. Lets watch the results over the weekend.
Comment 70 Remus Pop (:RemusPop) 2012-06-18 01:36:28 PDT
We can safely push this patch to the other patches as it hasn't failed on default.
Comment 72 Remus Pop (:RemusPop) 2012-06-19 02:52:28 PDT
Added to the Mozmill Tests group:
55491, 15498, 40596, 63845
Comment 73 Henrik Skupin (:whimboo) 2012-06-19 03:17:34 PDT
The litmus tests are referencing 'testGeneral/testBackForwardButtons.js' which also has to be updated.
Comment 74 Remus Pop (:RemusPop) 2012-06-19 06:34:50 PDT
The above testcases have been updated.

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