Closed Bug 1397557 Opened 7 years ago Closed 5 years ago

Intermittent browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | leaked 2 window(s) until shutdown [url = http://example.com/browser/browser/extensions/pdfjs/test/file_pdfjs_test.pdf#zoom=100]

Categories

(Firefox :: PDF Viewer, defect, P5)

defect

Tracking

()

RESOLVED INCOMPLETE
Tracking Status
firefox57 --- disabled

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure, Whiteboard: [stockwell disabled])

This is showing up really frequently in my 57-as-Beta Try simulations (link below to the patch that can be used to replicate the config). Any ideas what might be going on, Yury?

https://hg.mozilla.org/try/rev/4dd50f5e4457ac281429a36983b0efbfb38a47dd
Flags: needinfo?(ydelendik)
This is going to be an extremely frequent Windows intermittent on Beta. Can you help, bdahl?
Flags: needinfo?(bdahl)
Flags: needinfo?(ydelendik)
:ryanvm, unless you have other information, we should disable this test on mozilla-beta:
diff --git a/browser/extensions/pdfjs/test/browser.ini b/browser/extensions/pdfjs/test/browser.ini
--- a/browser/extensions/pdfjs/test/browser.ini
+++ b/browser/extensions/pdfjs/test/browser.ini
@@ -3,8 +3,9 @@ support-files =
   file_pdfjs_test.pdf
   head.js

 [browser_pdfjs_main.js]
 [browser_pdfjs_navigation.js]
 [browser_pdfjs_savedialog.js]
 [browser_pdfjs_views.js]
 [browser_pdfjs_zoom.js]
+skip-if = debug && os != "linux" # Bug 1397557


I am confused why this isn't failing on trunk- this smells like a configuration issue, but this has been reported 2 weeks ago with no action.
Yury, do you think you'll have cycles to work on #8925 any time soon or should we just skip the test on debug builds on Beta (all platforms) for now?
Flags: needinfo?(ydelendik)
I just merged Yury's changes. Want to give it try Ryan?
Flags: needinfo?(ydelendik)
Flags: needinfo?(ryanvm)
Flags: needinfo?(bdahl)
Doesn't appear to help :(

This is what I pushed to Try:
https://hg.mozilla.org/try/rev/aa43758e213aa203b0d82c117a901374f97ebdf4

And the failures still hit:
https://treeherder.mozilla.org/logviewer.html#?job_id=134416943&repo=try

Guess I'll just disable the test for now. I haven't run any 58-as-Beta Try simulations yet, but I'm worried this will persist there once I do :(
Flags: needinfo?(ryanvm)
And actually, there's a new Win7 debug failure too:
https://treeherder.mozilla.org/logviewer.html#?job_id=134418083&repo=try

That's the only platform we still run non-e10s tests on, so it could be a general issue with that configuration too.
Test disabled on debug builds. Hopefully it doesn't just move the failures to the new last test in the directory :\.
https://hg.mozilla.org/releases/mozilla-beta/rev/c8b1590db564
I was looking at some more logs of good and bad osx runs. On a bad run I'll see (stripped down logs):

>> INFO --DOMWINDOW file_pdfjs_test.pdf#zoom=100`
>> TEST-START | Shutdown
>> ...
>> INFO --DOMWINDOW file_pdfjs_test.pdf#zoom=100`

vs a good run

>> INFO --DOMWINDOW file_pdfjs_test.pdf#zoom=100`
>> INFO --DOMWINDOW file_pdfjs_test.pdf#zoom=100`
>> TEST-START | Shutdown
>> ...

So it seems the window is getting collected, just not during the requested shutdown.
(In reply to Ryan VanderMeulen [:RyanVM] from comment #19)
> Hopefully it doesn't just move the failures to the new last test in the directory :\.

And that's exactly what happened.
https://treeherder.mozilla.org/logviewer.html#?job_id=134439809&repo=mozilla-beta

Skipped the entire directory on debug builds until we can get to the bottom of this :(
https://hg.mozilla.org/releases/mozilla-beta/rev/3b5a6259ec27
Whiteboard: [stockwell disable-recommended] → [stockwell disabled]
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
https://treeherder.mozilla.org/logviewer.html#?job_id=190704228&repo=autoland&lineNumber=35510

13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 2832, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 904
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 904
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 1076, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | --DOMWINDOW == 3 (00000209B177A400) [pid = 8000] [serial = 14] [outer = 0000000000000000] [url = http://example.com/browser/browser/extensions/pdfjs/test/file_pdfjs_test.pdf]
13:32:56     INFO -  GECKO(7656) | --DOMWINDOW == 2 (00000209B2262C00) [pid = 8000] [serial = 18] [outer = 0000000000000000] [url = http://example.com/browser/browser/extensions/pdfjs/test/file_pdfjs_test.pdf#zoom=100]
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 1076, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 904
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 2580, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 2580, Chrome_ChildThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | [Child 2580, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 904
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Gecko_IOThread] WARNING: pipe error: 109: file z:/build/build/src/ipc/chromium/src/chrome/common/ipc_channel_win.cc, line 346
13:32:56     INFO -  GECKO(7656) | nsStringStats
13:32:56     INFO -  GECKO(7656) |  => mAllocCount:           7668
13:32:56     INFO -  GECKO(7656) |  => mReallocCount:          233
13:32:56     INFO -  GECKO(7656) |  => mFreeCount:            7668
13:32:56     INFO -  GECKO(7656) |  => mShareCount:           4890
13:32:56     INFO -  GECKO(7656) |  => mAdoptCount:            903
13:32:56     INFO -  GECKO(7656) |  => mAdoptFreeCount:        903
13:32:56     INFO -  GECKO(7656) |  => Process ID: 2832, Thread ID: 2504
13:32:56     INFO -  GECKO(7656) | nsStringStats
13:32:56     INFO -  GECKO(7656) |  => mAllocCount:           9267
13:32:56     INFO -  GECKO(7656) |  => mReallocCount:          292
13:32:56     INFO -  GECKO(7656) |  => mFreeCount:            9267
13:32:56     INFO -  GECKO(7656) |  => mShareCount:           5812
13:32:56     INFO -  GECKO(7656) |  => mAdoptCount:           1379
13:32:56     INFO -  GECKO(7656) |  => mAdoptFreeCount:       1379
13:32:56     INFO -  GECKO(7656) |  => Process ID: 2580, Thread ID: 6896
13:32:56     INFO -  GECKO(7656) | --DOCSHELL 00000209B2112800 == 2 [pid = 8000] [id = {b21bbf03-d61d-4be3-b2c4-b7c8296cc490}]
13:32:56     INFO -  GECKO(7656) | --DOCSHELL 00000209A964F000 == 1 [pid = 8000] [id = {a23682c0-fe83-4546-9a73-9a7d2a3c2e1f}]
13:32:56     INFO -  GECKO(7656) | --DOMWINDOW == 1 (00000209A961A600) [pid = 8000] [serial = 19] [outer = 0000000000000000] [url = about:blank]
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | [Child 8000, Main Thread] WARNING: '!mMainThread', file z:/build/build/src/xpcom/threads/nsThreadManager.cpp, line 516
13:32:56     INFO -  GECKO(7656) | --DOCSHELL 00000209B2109000 == 0 [pid = 8000] [id = {9c1d75fb-a214-4d99-ba21-60ea06e89a94}]
13:32:56     INFO -  GECKO(7656) | --DOMWINDOW == 0 (00000209B2261800) [pid = 8000] [serial = 20] [outer = 0000000000000000] [url = about:blank]
13:32:56     INFO -  GECKO(7656) | nsStringStats
13:32:56     INFO -  GECKO(7656) |  => mAllocCount:          25569
13:32:56     INFO -  GECKO(7656) |  => mReallocCount:         1671
13:32:56     INFO -  GECKO(7656) |  => mFreeCount:           25569
13:32:56     INFO -  GECKO(7656) |  => mShareCount:          35991
13:32:56     INFO -  GECKO(7656) |  => mAdoptCount:           2407
13:32:56     INFO -  GECKO(7656) |  => mAdoptFreeCount:       2449
13:32:56     INFO -  GECKO(7656) |  => Process ID: 8000, Thread ID: 5984
13:32:56     INFO -  GECKO(7656) | nsStringStats
13:32:56     INFO -  GECKO(7656) |  => mAllocCount:          11369
13:32:56     INFO -  GECKO(7656) |  => mReallocCount:          341
13:32:56     INFO -  GECKO(7656) |  => mFreeCount:           11369
13:32:56     INFO -  GECKO(7656) |  => mShareCount:          11230
13:32:56     INFO -  GECKO(7656) |  => mAdoptCount:           1227
13:32:56     INFO -  GECKO(7656) |  => mAdoptFreeCount:       1231
13:32:56     INFO -  GECKO(7656) |  => Process ID: 1076, Thread ID: 6960
13:32:56     INFO -  GECKO(7656) | 1532784776754	Marionette	DEBUG	Received observer notification xpcom-will-shutdown
13:32:56     INFO -  GECKO(7656) | 1532784776754	Marionette	INFO	Stopped listening on port 2828
13:32:56     INFO -  GECKO(7656) | 1532784776755	Marionette	DEBUG	Remote service is inactive
13:32:56     INFO -  GECKO(7656) | [Parent 7656, Main Thread] WARNING: NS_ENSURE_TRUE(mDB) failed: file z:/build/build/src/netwerk/cache/nsDiskCacheDeviceSQL.cpp, line 1422
13:32:57     INFO -  GECKO(7656) | [Parent 7656, Main Thread] WARNING: NS_ENSURE_TRUE(maybeContext) failed: file z:/build/build/src/xpcom/threads/nsThread.cpp, line 904
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 11 (000002A95AA1D600) [pid = 7656] [serial = 1] [outer = 0000000000000000] [url = chrome://gfxsanity/content/sanityparent.html]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 10 (000002A95908BC00) [pid = 7656] [serial = 6] [outer = 0000000000000000] [url = about:blank]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 9 (000002A94DB26400) [pid = 7656] [serial = 2] [outer = 0000000000000000] [url = about:blank]
13:32:57     INFO -  GECKO(7656) | --DOCSHELL 000002A95E92C800 == 4 [pid = 7656] [id = {fceebb98-9f32-4d27-a534-59651cb2c4f4}]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 8 (000002A95DFB5000) [pid = 7656] [serial = 8] [outer = 0000000000000000] [url = about:blank]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 7 (000002A95AA23C00) [pid = 7656] [serial = 5] [outer = 0000000000000000] [url = chrome://browser/content/browser.xul]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 6 (000002A95EF3DE00) [pid = 7656] [serial = 16] [outer = 0000000000000000] [url = chrome://mochikit/content/browser-harness.xul]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 5 (000002A9580A2000) [pid = 7656] [serial = 21] [outer = 0000000000000000] [url = about:blank]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 4 (000002A95E8CF800) [pid = 7656] [serial = 17] [outer = 0000000000000000] [url = about:blank]
13:32:57     INFO -  GECKO(7656) | --DOCSHELL 000002A95AACA800 == 3 [pid = 7656] [id = {181398ec-eec5-4f7c-b6ea-97b4f7b2f22f}]
13:32:57     INFO -  GECKO(7656) | --DOCSHELL 000002A95E7A1000 == 2 [pid = 7656] [id = {0edda94e-d87a-490c-bfa5-64621b421386}]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 3 (000002A96297F200) [pid = 7656] [serial = 12] [outer = 0000000000000000] [url = chrome://extensions/content/dummy.xul]
13:32:57     INFO -  GECKO(7656) | --DOCSHELL 000002A960338800 == 1 [pid = 7656] [id = {6196119a-fe2a-407b-a13a-ef629884a247}]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 2 (000002A95908E400) [pid = 7656] [serial = 15] [outer = 0000000000000000] [url = chrome://extensions/content/dummy.xul]
13:32:57     INFO -  GECKO(7656) | --DOCSHELL 000002A95AACC000 == 0 [pid = 7656] [id = {32f6d90d-83ac-4378-a978-926fec6c44cd}]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 1 (000002A95AA22A00) [pid = 7656] [serial = 3] [outer = 0000000000000000] [url = resource://gre-resources/hiddenWindow.html]
13:32:57     INFO -  GECKO(7656) | --DOMWINDOW == 0 (000002A959093800) [pid = 7656] [serial = 7] [outer = 0000000000000000] [url = resource://gre-resources/hiddenWindow.html]
13:32:57     INFO -  GECKO(7656) | nsStringStats
13:32:57     INFO -  GECKO(7656) |  => mAllocCount:          87703
13:32:57     INFO -  GECKO(7656) |  => mReallocCount:         6575
13:32:57     INFO -  GECKO(7656) |  => mFreeCount:           87703
13:32:57     INFO -  GECKO(7656) |  => mShareCount:          95244
13:32:57     INFO -  GECKO(7656) |  => mAdoptCount:           3672
13:32:57     INFO -  GECKO(7656) |  => mAdoptFreeCount:       3736
13:32:57     INFO -  GECKO(7656) |  => Process ID: 7656, Thread ID: 8156
13:32:57     INFO -  TEST-INFO | Main app process: exit 0
13:32:57    ERROR -  910 ERROR TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_views.js | leaked 2 window(s) until shutdown [url = http://example.com/browser/browser/extensions/pdfjs/test/file_pdfjs_test.pdf]
13:32:57     INFO -  TEST-INFO | browser/extensions/pdfjs/test/browser_pdfjs_views.js | windows(s) leaked: [pid = 8000] [serial = 14], [pid = 8000] [serial = 11]
13:32:57    ERROR -  911 ERROR TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_views.js | leaked 1 docShell(s) until shutdown
13:32:57     INFO -  TEST-INFO | browser/extensions/pdfjs/test/browser_pdfjs_views.js | docShell(s) leaked: [pid = 8000] [id = {a23682c0-fe83-4546-9a73-9a7d2a3c2e1f}]
13:32:57    ERROR -  912 ERROR TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | leaked 2 window(s) until shutdown [url = http://example.com/browser/browser/extensions/pdfjs/test/file_pdfjs_test.pdf#zoom=100]
13:32:57     INFO -  TEST-INFO | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | windows(s) leaked: [pid = 8000] [serial = 15], [pid = 8000] [serial = 18]
13:32:57    ERROR -  913 ERROR TEST-UNEXPECTED-FAIL | browser/extensions/pdfjs/test/browser_pdfjs_zoom.js | leaked 1 docShell(s) until shutdown
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago6 years ago
Resolution: --- → INCOMPLETE
Recent failure log: https://treeherder.mozilla.org/logviewer.html#?job_id=204476971&repo=autoland&lineNumber=20583
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 6 years ago5 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
Status: REOPENED → RESOLVED
Closed: 5 years ago5 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.