Closed Bug 1135866 Opened 9 years ago Closed 8 years ago

Intermittent browser_bug562890.js,browser_openDialog.js | Test timed out | Found a tab after previous test timed out: about:addons - | Found unexpected Addons:Manager window still open

Categories

(Toolkit :: Add-ons Manager, defect)

x86
Windows 7
defect
Not set
normal

Tracking

()

RESOLVED FIXED
mozilla47
Tracking Status
firefox44 --- wontfix
firefox45 --- fixed
firefox46 --- fixed
firefox47 --- fixed

People

(Reporter: RyanVM, Assigned: Unfocused)

Details

(Keywords: intermittent-failure)

Attachments

(2 files, 1 obsolete file)

Attached image test screenshot
21:14:01 INFO - 692 INFO TEST-START | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js
21:14:01 INFO - 1424668441978 addons.manager DEBUG Starting provider: <unnamed-provider>
21:14:01 INFO - 1424668441978 addons.manager DEBUG Registering shutdown blocker for <unnamed-provider>
21:14:01 INFO - 1424668441978 addons.manager DEBUG Provider finished startup: <unnamed-provider>
21:15:32 INFO - TEST-INFO | screenshot: exit status 0
21:15:32 INFO - 693 INFO checking window state
21:15:32 INFO - 694 INFO Registering custom chrome-like protocol.
21:15:32 INFO - 695 INFO Registering mock add-on provider
21:15:32 INFO - 696 INFO Loading manager window in dialog
21:15:32 INFO - 697 INFO Console message: 1424668441978 addons.manager DEBUG Starting provider: <unnamed-provider>
21:15:32 INFO - 698 INFO Console message: 1424668441978 addons.manager DEBUG Registering shutdown blocker for <unnamed-provider>
21:15:32 INFO - 699 INFO Console message: 1424668441978 addons.manager DEBUG Provider finished startup: <unnamed-provider>
21:15:32 INFO - 700 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Should have an add-ons manager window
21:15:32 INFO - 701 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Should be displaying the correct UI
21:15:32 INFO - 702 INFO must wait for load
21:15:32 INFO - 703 INFO must wait for focus
21:15:32 INFO - 704 INFO window has focus, waiting for manager load
21:15:32 INFO - 705 INFO Manager waiting for view load
21:15:32 INFO - 706 INFO Testing Test add-on 1
21:15:32 INFO - 707 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Prefs button should be visible.
21:15:32 INFO - 708 INFO must wait for load
21:15:32 INFO - 709 INFO must wait for focus
21:15:32 INFO - 710 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | The correct addon pref window should have opened
21:15:32 INFO - 711 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Window was open as a chrome dialog.
21:15:32 INFO - 712 INFO must wait for focus
21:15:32 INFO - 713 INFO Testing Test add-on 2
21:15:32 INFO - 714 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Prefs button should be visible.
21:15:32 INFO - 715 INFO must wait for load
21:15:32 INFO - 716 INFO must wait for focus
21:15:32 INFO - 717 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | The correct addon pref window should have opened
21:15:32 INFO - 718 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Window was open as a chrome dialog.
21:15:32 INFO - 719 INFO must wait for focus
21:15:32 INFO - 720 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Should have an add-ons manager window to close
21:15:32 INFO - 721 INFO TEST-PASS | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Should be closing window with correct URI
21:15:32 INFO - 722 INFO Telling manager window to close
21:15:32 INFO - 723 INFO Manager window close() call returned
21:15:32 INFO - 724 INFO Console message: 1424668456296 Toolkit.GMP WARN GMPInstallManager.parseResponseXML got node name: html, expected: updates
21:15:32 INFO - 725 INFO Console message: [JavaScript Error: "1424668456296 Toolkit.GMP ERROR GMPInstallManager.simpleCheckAndInstall Could not check for addons: {"target":{},"message":"got node name: html, expected: updates"}" {file: "resource://gre/modules/Log.jsm" line: 749}]
21:15:32 INFO - 726 INFO Console message: 1424668456344 Services.HealthReport.HealthReporter WARN Saved state file does not exist.
21:15:32 INFO - 727 INFO Longer timeout required, waiting longer... Remaining timeouts: 1
21:15:32 INFO - 728 INFO TEST-UNEXPECTED-FAIL | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Test timed out - expected PASS
21:15:32 INFO - 729 INFO TEST-UNEXPECTED-FAIL | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | Found unexpected Addons:Manager window still open -
21:15:32 INFO - Stack trace:
21:15:32 INFO - chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/test-window/head.js:checkOpenWindows:110
21:15:32 INFO - chrome://mochitests/content/browser/toolkit/mozapps/extensions/test/browser/test-window/head.js:null:162
21:15:32 INFO - chrome://mochikit/content/browser-test.js:Tester.prototype.nextTest<:367
21:15:32 INFO - self-hosted:next:620
21:15:32 INFO - timeoutFn@chrome://mochikit/content/browser-test.js:764:9
21:15:32 INFO - Manager window unload handler
21:15:32 INFO - 730 INFO Unregistering mock add-on provider
21:15:32 INFO - 731 INFO MEMORY STAT vsize after test: 781983744
21:15:32 INFO - 732 INFO MEMORY STAT vsizeMaxContiguous after test: 578682880
21:15:32 INFO - 733 INFO MEMORY STAT residentFast after test: 222478336
21:15:32 INFO - 734 INFO MEMORY STAT heapAllocated after test: 47315686
21:15:32 INFO - 735 INFO TEST-OK | toolkit/mozapps/extensions/test/browser/test-window/browser_openDialog.js | took 90067ms
Summary: Intermittent browser_openDialog.js | Test timed out | Found unexpected Addons:Manager window still open → Intermittent browser_bug562890.js,browser_openDialog.js | Test timed out | Found unexpected Addons:Manager window still open
Summary: Intermittent browser_bug562890.js,browser_openDialog.js | Test timed out | Found unexpected Addons:Manager window still open → Intermittent browser_bug562890.js,browser_openDialog.js | Test timed out | Found a tab after previous test timed out: about:addons - | Found unexpected Addons:Manager window still open
This is the #3 intermittent orange over the past 3 days.  It would be helpful to get this assigned.
Flags: needinfo?(dolske)
I looked at this a little over the break.  It appears to getting stuck on waiting for focus.
Blair - all yours!
Assignee: nobody → bmcbride
Flags: needinfo?(dolske)
Status: NEW → ASSIGNED
So, I think this *might* work. But as I can't reliabily reproduce the failure, I also can't really know for sure this fixes things :\ So I'm thinking: land this, and see if it makes a difference ¯\_(ツ)_/¯
(In reply to Blair McBride [:Unfocused] (unavailable) from comment #561)
> So, I think this *might* work. But as I can't reliabily reproduce the
> failure, I also can't really know for sure this fixes things :\ So I'm
> thinking: land this, and see if it makes a difference ¯\_(ツ)_/¯

You can do a try push with a bunch of retriggers, no?
Comment on attachment 8705604 [details]
MozReview Request: Bug 1135866 - Wait for focus in browser_bug562890.js & browser_openDialog.js r?mossop

https://reviewboard.mozilla.org/r/30087/#review26851

These are pretty straightforward fixes that shouldn't cause any harm and if they fix it then we win!
Attachment #8705604 - Flags: review?(dtownsend) → review+
(In reply to Ben Kelly [:bkelly] from comment #562)
> (In reply to Blair McBride [:Unfocused] (unavailable) from comment #561)
> > So, I think this *might* work. But as I can't reliabily reproduce the
> > failure, I also can't really know for sure this fixes things :\ So I'm
> > thinking: land this, and see if it makes a difference ¯\_(ツ)_/¯
> 
> You can do a try push with a bunch of retriggers, no?

Who needs a bunch? It only took me one run with this patch in https://treeherder.mozilla.org/#/jobs?repo=try&revision=d3ce035ea709&selectedJob=15251543 to get a timeout in both tests, with a screenshot showing the browser window hiding back behind the "Browser chrome tests" window, waiting for focus that isn't going to happen.
*sigh* Ok, looking into it more...

Frustratingly, my own try push today hasn't shown it yet: https://treeherder.mozilla.org/#/jobs?repo=try&revision=1aeebd3818c9&selectedJob=15277492
Well, I don't know what's up with this... I mean, it ended up kinda looked like a window manager bug, where a window *should* be getting focused after another one closes, but just doesn't. So I thought in theory that introducing a wait between the window closing and trying to force focus the other window would help. But in addition to probably being unreliable, I haven't been able to test it because....

The frequency of the failure happening have suddenly drastically dropped. See the difference between comment 567 (157 failures) and comment 21 (21 failures). And I don't have anything to account for that (don't see anything obvious land around the time of the drop, but could have easily missed it).

So given all that, my thought is to just disable these tests on Windows opt/PGO builds. The failure has only happened once on a Windows debug build since the start of December, and once on a non-Windows build (Linux asan) in the same timeframe. 64bit is by far the most common, but 32bit failures have happened 5 times in the time period. IMO, we still get adequate test coverage this way - and I don't think it's a problem with the test or the code it tests (I think any fix there would be a workaround).
Attachment #8705604 - Attachment is obsolete: true
Attachment #8708989 - Flags: review?(dtownsend)
Attachment #8708989 - Flags: review?(dtownsend) → review+
(In reply to Blair McBride [:Unfocused] (mostly unavailable) from comment #573)
> https://hg.mozilla.org/integration/fx-team/rev/6a1ce080d938

Note that this went red on the push after because of the "&& &&" in the condition. I pushed a fix:

remote:   https://hg.mozilla.org/integration/fx-team/rev/b81f61d88a91
https://hg.mozilla.org/mozilla-central/rev/6a1ce080d938
https://hg.mozilla.org/mozilla-central/rev/b81f61d88a91
Status: ASSIGNED → RESOLVED
Closed: 8 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla47
Whiteboard: [checkin-needed-aurora][checkin-needed-beta]
https://hg.mozilla.org/releases/mozilla-aurora/rev/1dc751d3ef23
https://hg.mozilla.org/releases/mozilla-aurora/rev/5f35f66873ad
Whiteboard: [checkin-needed-aurora][checkin-needed-beta] → [checkin-needed-beta]
Whiteboard: [checkin-needed-beta]
You need to log in before you can comment on or make changes to this bug.