Closed Bug 906713 Opened 7 years ago Closed 7 years ago

Intermittent browser_thumbnails_background.js | Thumb browser should exist immediately after capture. - Didn't expect undefined, but got it

Categories

(Toolkit :: General, defect)

x86
Linux
defect
Not set

Tracking

()

RESOLVED FIXED
mozilla26
Tracking Status
firefox24 --- fixed
firefox25 --- fixed
firefox26 --- fixed

People

(Reporter: emorley, Assigned: markh)

References

Details

(Keywords: intermittent-failure)

Attachments

(1 file)

Rev3 Fedora 12 mozilla-inbound debug test mochitest-browser-chrome on 2013-08-18 12:19:55 PDT for push 3790c84fc9db

slave: talos-r3-fed-060

https://tbpl.mozilla.org/php/getParsedLog.php?id=26703627&tree=Mozilla-Inbound

{
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mMainThread) failed: file ../../../xpcom/threads/nsThreadManager.cpp, line 251
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0xC1F30001: file nsThreadUtils.cpp, line 161
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(compMgr) failed: file nsComponentManagerUtils.cpp, line 58
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(svc) failed: file ../../../dom/ipc/ContentChild.cpp, line 578
14:02:55     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(compMgr) failed: file nsComponentManagerUtils.cpp, line 58
14:02:55     INFO -  creating 1!
14:02:55     INFO -  [Child 2979] WARNING: nsWindow::GetNativeData not implemented for this type: file ../../../widget/xpwidgets/PuppetWidget.cpp, line 673
14:02:55     INFO -  ++DOCSHELL 0xa417a18 == 1 [id = 1]
14:02:55     INFO -  ++DOMWINDOW == 1 (0xa44bc68) [serial = 1] [outer = (nil)]
14:02:55     INFO -  [TabChild] SHOW (w,h)= (10, 10)
14:02:55     INFO -  loading about:blank, 1
14:02:55     INFO -  ++DOMWINDOW == 2 (0xa4ea190) [serial = 2] [outer = 0xa44bc68]
14:02:55     INFO -  [Parent 2593] WARNING: Could not get disk information from DiskSpaceWatcher: file ../../../../dom/src/storage/DOMStorageIPC.cpp, line 324
14:02:56     INFO -  ++DOMWINDOW == 3 (0xa60bdb0) [serial = 3] [outer = 0xa44bc68]
14:02:56     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(startupCache) failed: file ../../../../content/xbl/src/nsXBLDocumentInfo.cpp, line 502
14:02:56     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(startupCache) failed: file ../../../../content/xbl/src/nsXBLDocumentInfo.cpp, line 572
14:02:56     INFO -  ++DOMWINDOW == 4 (0xa62f3f0) [serial = 4] [outer = 0xa44bc68]
14:02:57     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(mDocShell) failed: file ../../../../embedding/browser/webBrowser/nsWebBrowser.cpp, line 367
14:02:57     INFO -  [Child 2979] WARNING: NS_ENSURE_TRUE(domWindow) failed: file ../../../../embedding/browser/webBrowser/nsDocShellTreeOwner.cpp, line 87
14:02:57     INFO -  TEST-PASS | chrome://mochitests/content/browser/toolkit/components/thumbnails/test/browser_thumbnails_background.js | Second file should exist after capture.
14:02:57  WARNING -  TEST-UNEXPECTED-FAIL | chrome://mochitests/content/browser/toolkit/components/thumbnails/test/browser_thumbnails_background.js | Thumb browser should exist immediately after capture. - Didn't expect undefined, but got it
14:02:57     INFO -  Stack trace:
14:02:57     INFO -      JS frame :: chrome://mochikit/content/browser-test.js :: test_isnot :: line 564
14:02:57     INFO -      JS frame :: chrome://mochitests/content/browser/toolkit/components/thumbnails/test/browser_thumbnails_background.js :: destroyBrowserTimeout :: line 150
14:02:57     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 198
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 122
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 47
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 189
14:02:57     INFO -      JS frame :: chrome://mochitests/content/browser/toolkit/components/thumbnails/test/browser_thumbnails_background.js :: onDone :: line 309
14:02:57     INFO -      JS frame :: resource://gre/modules/BackgroundPageThumbs.jsm :: callOnDonesFn :: line 343
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 122
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 47
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 189
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 122
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: then :: line 47
14:02:57     INFO -      JS frame :: resource://gre/modules/commonjs/sdk/core/promise.js :: resolve :: line 189
14:02:57     INFO -      JS frame :: resource://gre/modules/Task.jsm :: TaskImpl_run :: line 226
14:02:57     INFO -      JS frame :: resource://gre/modules/Promise.jsm :: <TOP_LEVEL> :: line 554
14:02:57     INFO -      JS frame :: resource://gre/modules/Promise.jsm :: <TOP_LEVEL> :: line 336
14:02:57     INFO -      native frame :: <unknown filename> :: <TOP_LEVEL> :: line 0
}
The problem here is that we are simply hitting the timeout again - the second capture may take longer than 1 second to complete.

The fix is to reset the default timeout after we wait for the timeout, so the second capture uses the default timeout, meaning the browser will still exist after it completes.
Assignee: nobody → mhammond
Attachment #800602 - Flags: review?(adw)
Comment on attachment 800602 [details] [diff] [review]
0001-Bug-906713-reset-default-capture-timeout-earlier-to-.patch

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

Nice catch, thanks.  The precise problem seems to be that _store finishes after the destroy-browser timer fires, so I wonder if Capture._done should call captureCallback along with the doneCallbacks when PageThumbs._store() completes.  Your patch is still susceptible to failure when _store takes longer than _destroyBrowserTimeout.  Not likely, so r+, but maybe it becomes more likely if a bunch of _stores are queued up?
Attachment #800602 - Flags: review?(adw) → review+
(In reply to Drew Willcoxon :adw from comment #9)
> Comment on attachment 800602 [details] [diff] [review]
> 0001-Bug-906713-reset-default-capture-timeout-earlier-to-.patch
> 
> Review of attachment 800602 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> Nice catch, thanks.  The precise problem seems to be that _store finishes
> after the destroy-browser timer fires, so I wonder if Capture._done should
> call captureCallback along with the doneCallbacks when PageThumbs._store()
> completes.

Maybe - but I don't think the current behaviour is actually a problem - if this happens "for real", then we are just going to recreate the browser element and things should work fine.  Seeing we are just fixing this orange, I think we can defer this until there is evidence of an actual problem.

> Your patch is still susceptible to failure when _store takes
> longer than _destroyBrowserTimeout.  Not likely, so r+, but maybe it becomes
> more likely if a bunch of _stores are queued up?

This would imply something very bad is happening with the tests - and the mochi framework is going to time us out anyway.  So I think this too is fine for the sake of this orange.

https://hg.mozilla.org/integration/fx-team/rev/e89edb607559
Status: NEW → ASSIGNED
https://hg.mozilla.org/mozilla-central/rev/e89edb607559
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → mozilla26
Blocks: 931889
You need to log in before you can comment on or make changes to this bug.