749159 - Lots of recent failures with "Modal dialog has been found and processed"

Status: VERIFIED FIXED

(Mozilla QA Graveyard :: Mozmill Tests, defect)

Description

[Maniac Vlad Florin (:vladmaniac)]

Report link: 
http://mozmill-ci.blargon7.com/#/functional/report/2a76d98544f7c11b8b6a1972e9137947
-----------------------------------------------------------------------------------------
Test link: 
http://hg.mozilla.org/qa/mozmill-tests/file/2c6f7194bd93/tests/functional/testPrivateBrowsing/testStartStopPBMode.js
-----------------------------------------------------------------------------------------
Error:
TimeoutError@resource://mozmill/modules/utils.js:429 waitFor@resource://mozmill/modules/utils.js:467 modalDialog_waitForDialog@resource://mozmill/stdlib/securable-module.js -> file:///tmp/tmpcD96o3.mozmill-tests/lib/modal-dialog.js:205 privateBrowsing_start@resource://mozmill/stdlib/securable-module.js -> file:///tmp/tmpcD96o3.mozmill-tests/lib/private-browsing.js:162 testStartStopPrivateBrowsingMode@resource://mozmill/modules/frame.js -> file:///tmp/tmpcD96o3.mozmill-tests/tests/functional/testPrivateBrowsing/testStartStopPBMode.js:55 @resource://mozmill/modules/frame.js:563 @resource://mozmill/modules/frame.js:632 @resource://mozmill/modules/frame.js:675 @resource://mozmill/modules/frame.js:512 @resource://mozmill/modules/frame.js:687 @resource://jsbridge/modules/server.js:184 @resource://jsbridge/modules/server.js:188 @resource://jsbridge/modules/server.js:288 
-----------------------------------------------------------------------------------------
Build from: 
http://hg.mozilla.org/mozilla-central/rev/cc5254f9825f
-----------------------------------------------------------------------------------------
Mozmill Version: 1.5.9 (locally) 
                 1.5.11 (on dashboard CI) 
-----------------------------------------------------------------------------------------
IMPORTANT: Other tests might be affected by the same change/regression in Firefox 15 
Will try a fix on this test and then see if applies to other failing tests with the same error, make some connections. 
-----------------------------------------------------------------------------------------
As talked with Henrik on iRC, we do not include this error as being from the same cause as the addon installation tests fail, intermittent with the same error message. 
This errror is reproducible locally when running a single test from the command line.

Comment 1

[Maniac Vlad Florin (:vladmaniac)]

First I would make the test STR manually see if any UI changes then will follow by investigating Firefox code on hg for changes and mxr

Comment 2

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

We should figure out if this is a Firefox regression or something which has been changed in handling windows. Please check when this regression has been started and which changes have been landed at this time for Firefox.

If a patch is necessary it's definitely in our lib section.

Comment 3

[Maniac Vlad Florin (:vladmaniac)]

(In reply to Henrik Skupin (:whimboo) from comment #2)
> We should figure out if this is a Firefox regression or something which has
> been changed in handling windows. Please check when this regression has been
> started and which changes have been landed at this time for Firefox.
> 
> If a patch is necessary it's definitely in our lib section.

I'll have to check manually and test Nightly builds locally because the Mozmill dashboard is a bit un-synced with the Firefox 15 release (a build or two behind). I suspect this started from day 1 of Firefox 15. 

Furthermore, i suspect a change has been made in handling windows because manually the test works with the given STR, but the mozmill test simply does not open the pb modal dialog anymore - this is visible when running the test locally from the command line. 

Lets figure out what the problem is...

Comment 4

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

This bug is critical to our test execution. So please make sure to spend all available resources on it so we can get it fixed ASAP.

Comment 5

[Maniac Vlad Florin (:vladmaniac)]

Build works: http://hg.mozilla.org/mozilla-central/rev/75c7378c87b6

Build broken: http://hg.mozilla.org/mozilla-central/rev/cc5254f9825f

Comment 6

[Remus Pop (:RemusPop)]

Attachment: Patch v1

The regression window found by Vlad gives a lot of bugs. My belief is that bug 640904 might be the one to cause us the trouble. Please look at the patch name and not the bug name.

I'm not 100% sure what the problem is but I suspect that the observer created with timer within the modal dialog gets destroyed when closing the window, because the code after this bit:
if (window) {
  window.close();
}
never gets executed. As I understand, this.finished should act like a synchronisation mechanism, but we never reach that piece of code.

So, long story short, I've moved this.finished = true before we close the window.
Here are the results for the some testruns on Mac and Linux:
http://mozmill-crowd.blargon7.com/#/functional/reports?branch=All&platform=All&from=2012-04-30&to=2012-04-30
Neither have errors on modal-dialog, so if I've somehow mistaken, the patch will work in the short-run for sure.

Comment 7

[u279076]

Comment on attachment 619552 [details] [diff] [review]
Patch v1

I'd like to hear from Henrik before I give feedback on this change. I appreciate the reasoning behind this change but I'd like to be sure about what this is doing before I commit to it. I'd rather have a fix than a band-aid that breaks some weeks down the road.

Comment 8

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

I absolutely want to see the real regression bug. Vlad, why you weren't able to track this down? I thought that you have a development machine setup to build Firefox on your own on Mac at least? Given that no-one else did that yet, I will have to dive into now.

Comment 9

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

(In reply to Maniac Vlad Florin (:vladmaniac) from comment #5)
> Build works: http://hg.mozilla.org/mozilla-central/rev/75c7378c87b6
> Build broken: http://hg.mozilla.org/mozilla-central/rev/cc5254f9825f

Whenever you have found the regression range please make sure to always add the following information: buildids, changesets, pushlog link. Seeing the changesets only isn't a big help when you want to re-check those builds. Thanks.

Comment 10

[Maniac Vlad Florin (:vladmaniac)]

(In reply to Henrik Skupin (:whimboo) from comment #9)
> (In reply to Maniac Vlad Florin (:vladmaniac) from comment #5)
> > Build works: http://hg.mozilla.org/mozilla-central/rev/75c7378c87b6
> > Build broken: http://hg.mozilla.org/mozilla-central/rev/cc5254f9825f
> 
> Whenever you have found the regression range please make sure to always add
> the following information: buildids, changesets, pushlog link. Seeing the
> changesets only isn't a big help when you want to re-check those builds.
> Thanks.

Right

Comment 11

[Maniac Vlad Florin (:vladmaniac)]

(In reply to Henrik Skupin (:whimboo) from comment #8)
> I absolutely want to see the real regression bug. Vlad, why you weren't able
> to track this down? I thought that you have a development machine setup to
> build Firefox on your own on Mac at least? Given that no-one else did that
> yet, I will have to dive into now.

I've just downloaded builds from and found the regression range. 
Its difficult to find the real bug with this method. I did not build Firefox locally unfortunately. 

I don't know the options to build Firefox from a date, only using latest-mozilla-central

Comment 12

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

Attachment: minimized testcase

Minimized testcase to reproduce the new failure. Just place the modal-dialog.js file into the same folder to run it.

Comment 13

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

Something I can see in a debug build is:

[Exception... "'[JavaScript Error: "can't access dead object" {file: "resource://mozmill/stdlib/securable-module.js -> file:///Volumes/data/code/firefox/modal-dialog.js" line: 116}]' when calling method: [nsIObserver::observe]"  nsresult: "0x80570021 (NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS)"  location: "native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0"  data: yes]

It confirms that we are operating on an already freed object. Will dig into further.

Comment 14

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

Actual pushlog of mozilla-central is:
http://hg.mozilla.org/mozilla-central/pushloghtml?fromchange=75c7378c87b6&tochange=cc5254f9825f

Comment 15

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

This regression has been caused by bug 695480. So any compartment in content our chrome code refers to gets destroyed automatically. That means we are working on a dead object as the above comment already states.

That means we have to make sure to mark the handling of the modal dialog as finished *before* the references to compartments are getting deleted.

Comment 16

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

Comment on attachment 619552 [details] [diff] [review]
Patch v1

First, thanks Remus for jumping on it and trying to fix it. Looks like your approach was correct but not complete. See below. Also please don't name patches as 'quickfix'. This implies bad code to me. We always want to check-in patches which really fix issues.

>+      this.finished = true;
>+
>       if (window) {
>         window.close();
>       }
> 
>-      this.finished = true;
>       this.stop();

This will leave a running instance of the timer around. Both lines have to be moved up so they are getting called before the window gets destroyed.

Comment 17

[Remus Pop (:RemusPop)]

Attachment: Patch v2 (default)

Moved the this.stop so it will always execute before closing the window.

Comment 18

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

Comment on attachment 620315 [details] [diff] [review]
Patch v2 (default)

Looks good to me. Some other failures should probably pop-up with this fix landed.

Comment 19

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

Landed on default as:
http://hg.mozilla.org/qa/mozmill-tests/rev/4d11b76a73ae

If it's fixed with the next test-run we should also land this on all the other branches.

Remus, would you mind testing it across all branches?

Comment 20

[Maniac Vlad Florin (:vladmaniac)]

I will step in and test this across branches

Comment 21

[Maniac Vlad Florin (:vladmaniac)]

Henrik, this patch is intended only for the default branch. We can wait for tomorrow's results in the dashboard and verify this

Comment 22

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

(In reply to Maniac Vlad Florin (:vladmaniac) from comment #21)
> Henrik, this patch is intended only for the default branch. We can wait for
> tomorrow's results in the dashboard and verify this

Not sure about all those assumptions, Vlad. I'm the owner of this module and I know when a patch will apply cleanly to other branches. And this is the case here. There was no change to this module in a couple of months.

So given that todays testruns are fine and the failure is gone, I will check Aurora and land the patch across branches once it is green.

Comment 23

[Maniac Vlad Florin (:vladmaniac)]

Patch introduces new failures in mozilla-aurora branch

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

Comment 24

[Maniac Vlad Florin (:vladmaniac)]

(In reply to Maniac Vlad Florin (:vladmaniac) from comment #23)
> Patch introduces new failures in mozilla-aurora branch
> 
> http://mozmill-crowd.blargon7.com/#/functional/report/
> c2b72632f20450b6d99d14c709454a0d

Please ignore this result 
This was due to a system failure on my machine, which happened locally. 

The good results of the patch testing are here, as can Henrik confirm 
http://mozmill-crowd.blargon7.com/#/functional/report/c2b72632f20450b6d99d14c7094951dd 

All is good for mozilla-aurora

Comment 25

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

Landed on other branches:
http://hg.mozilla.org/qa/mozmill-tests/rev/7033afbd4715 (aurora)
http://hg.mozilla.org/qa/mozmill-tests/rev/1600c0e9ba5c (beta)
http://hg.mozilla.org/qa/mozmill-tests/rev/ae7b2258712b (release)
http://hg.mozilla.org/qa/mozmill-tests/rev/4ddc75ca184c (esr10)

Comment 26

[u279076]

Haven't seen these failures in a while. Marking verified.