Closed Bug 1608664 Opened 5 years ago Closed 1 years ago

Intermittent [Parent 5200, Gecko_IOThread] ###!!! ABORT: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 85

Tracking

()

Status:

RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Treeherder Bug Filer

Reporter

Description

•

5 years ago

treeherder

Filed by: nerli [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=284547891&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/GNU7h51LQ1KxsxO7N7mfyA/runs/0/artifacts/public/logs/live_backing.log

[task 2020-01-11T19:58:28.957Z] 19:58:28 [task 2020-01-11T19:58:28.958Z] 19:58:28 [task 2020-01-11T19:58:28.958Z] 19:58:28 [task 2020-01-11T19:58:28.958Z] 19:58:28 [task 2020-01-11T19:58:28.958Z] 19:58:28 [task 2020-01-11T19:58:28.959Z] 19:58:28 [task 2020-01-11T19:58:28.959Z] 19:58:28 [task 2020-01-11T19:58:29.194Z] 19:58:29 [task 2020-01-11T19:58:29.197Z] 19:58:29 [task 2020-01-11T19:58:29.197Z] 19:58:29 [task 2020-01-11T19:58:29.197Z] 19:58:29 [task 2020-01-11T19:58:29.197Z] 19:58:29 [task 2020-01-11T19:58:29.198Z] 19:58:29 [task 2020-01-11T19:58:29.213Z] 19:58:29 [task 2020-01-11T19:58:29.213Z] 19:58:29 [task 2020-01-11T19:58:29.213Z] 19:58:29 [task 2020-01-11T19:58:29.312Z] 19:58:29 [task 2020-01-11T19:58:29.312Z] 19:58:29 [task 2020-01-11T19:58:29.313Z] 19:58:29 [task 2020-01-11T19:58:29.313Z] 19:58:29 [task 2020-01-11T19:58:29.313Z] 19:58:29 [task 2020-01-11T19:58:29.314Z] 19:58:29 [task 2020-01-11T19:58:29.314Z] 19:58:29 [task 2020-01-11T19:58:29.314Z] 19:58:29 [task 2020-01-11T19:58:29.329Z] 19:58:29 [task 2020-01-11T19:58:29.348Z] 19:58:29 [task 2020-01-11T19:58:29.348Z] 19:58:29 [task 2020-01-11T19:58:29.348Z] 19:58:29 [task 2020-01-11T19:58:29.348Z] 19:58:29 [task 2020-01-11T19:58:29.349Z] 19:58:29 [task 2020-01-11T19:58:29.349Z] 19:58:29 [task 2020-01-11T19:58:29.349Z] 19:58:29 [task 2020-01-11T19:58:29.349Z] 19:58:29 [task 2020-01-11T19:58:29.368Z] 19:58:29 [task 2020-01-11T19:58:29.368Z] 19:58:29 [task 2020-01-11T19:58:29.489Z] 19:58:29 [task 2020-01-11T19:58:29.489Z] 19:58:29 [task 2020-01-11T19:58:29.489Z] 19:58:29 [task 2020-01-11T19:58:29.489Z] 19:58:29 [task 2020-01-11T19:58:29.489Z] 19:58:29 [task 2020-01-11T19:58:29.510Z] 19:58:29 [task 2020-01-11T19:58:29.532Z] 19:58:29 [task 2020-01-11T19:58:29.532Z] 19:58:29 [task 2020-01-11T19:58:29.535Z] 19:58:29 [task 2020-01-11T19:58:29.550Z] 19:58:29 [task 2020-01-11T19:58:29.565Z] 19:58:29 [task 2020-01-11T19:58:29.565Z] 19:58:29 [task 2020-01-11T19:58:29.594Z] 19:58:29 [task 2020-01-11T19:58:29.594Z] 19:58:29 [task 2020-01-11T19:58:29.595Z] 19:58:29 [task 2020-01-11T19:58:29.595Z] 19:58:29 [task 2020-01-11T19:58:29.595Z] 19:58:29 [task 2020-01-11T19:58:29.595Z] 19:58:29 [task 2020-01-11T19:58:29.595Z] 19:58:29 [task 2020-01-11T19:58:29.596Z] 19:58:29 [task 2020-01-11T19:58:29.596Z] 19:58:29 [task 2020-01-11T19:58:29.596Z] 19:58:29 [task 2020-01-11T19:58:29.596Z] 19:58:29 [task 2020-01-11T19:58:29.596Z] 19:58:29 [task 2020-01-11T19:58:29.596Z] 19:58:29 [task 2020-01-11T19:58:29.597Z] 19:58:29 [task 2020-01-11T19:58:29.597Z] 19:58:29 [task 2020-01-11T19:58:29.597Z] 19:58:29 [task 2020-01-11T19:58:29.612Z] 19:58:29 [task 2020-01-11T19:58:29.612Z] 19:58:29 [task 2020-01-11T19:58:29.612Z] 19:58:29 [task 2020-01-11T19:58:29.612Z] 19:58:29 [task 2020-01-11T19:58:29.613Z] 19:58:29 [task 2020-01-11T19:58:29.613Z] 19:58:29 [task 2020-01-11T19:58:29.613Z] 19:58:29 [task 2020-01-11T19:58:29.613Z] 19:58:29 [task 2020-01-11T19:58:29.628Z] 19:58:29 [task 2020-01-11T19:58:29.628Z] 19:58:29 [task 2020-01-11T19:58:29.628Z] 19:58:29 [task 2020-01-11T19:58:29.628Z] 19:58:29 [task 2020-01-11T19:58:29.629Z] 19:58:29 [task 2020-01-11T19:58:29.629Z] 19:58:29 [task 2020-01-11T19:58:29.629Z] 19:58:29 [task 2020-01-11T19:58:29.629Z] 19:58:29 [task 2020-01-11T19:58:29.630Z] 19:58:29 [task 2020-01-11T19:58:29.645Z] 19:58:29 [task 2020-01-11T19:58:29.645Z] 19:58:29 [task 2020-01-11T19:58:29.645Z] 19:58:29 [task 2020-01-11T19:58:29.645Z] 19:58:29 [task 2020-01-11T19:58:29.645Z] 19:58:29 [task 2020-01-11T19:58:29.646Z] 19:58:29 [task 2020-01-11T19:58:29.646Z] 19:58:29 [task 2020-01-11T19:58:29.646Z] 19:58:29 [task 2020-01-11T19:58:29.673Z] 19:58:29 [task 2020-01-11T19:58:29.673Z] 19:58:29 [task 2020-01-11T19:58:29.673Z] 19:58:29 [task 2020-01-11T19:58:29.673Z] 19:58:29 [task 2020-01-11T19:58:29.674Z] 19:58:29 [task 2020-01-11T19:58:29.674Z] 19:58:29 [task 2020-01-11T19:58:29.674Z] 19:58:29 [task 2020-01-11T19:58:29.674Z] 19:58:29 [task 2020-01-11T19:58:29.681Z] 19:58:29 [task 2020-01-11T19:58:29.681Z] 19:58:29 [task 2020-01-11T19:58:29.682Z] 19:58:29 [task 2020-01-11T19:58:29.682Z] 19:58:29 [task 2020-01-11T19:58:29.682Z] 19:58:29 [task 2020-01-11T19:58:29.683Z] 19:58:29 [task 2020-01-11T19:58:29.683Z] 19:58:29 [task 2020-01-11T19:58:29.683Z] 19:58:29 [task 2020-01-11T19:58:29.878Z] 19:58:29 [task 2020-01-11T19:58:29.878Z] 19:58:29 [task 2020-01-11T19:58:29.878Z] 19:58:29 [task 2020-01-11T19:58:29.879Z] 19:58:29 [task 2020-01-11T19:58:29.879Z] 19:58:29 [task 2020-01-11T19:58:29.879Z] 19:58:29 [task 2020-01-11T19:58:29.880Z] 19:58:29 [task 2020-01-11T19:58:29.880Z] 19:58:29 [task 2020-01-11T19:58:29.880Z] 19:58:29 [task 2020-01-11T19:58:29.880Z] 19:58:29 [task 2020-01-11T19:58:29.881Z] 19:58:29 INFO - TEST-START | Shutdown
INFO - Browser Chrome Test Summary
INFO - Passed: 28
INFO - Failed: 0
INFO - Todo: 1
INFO - Mode: e10s
INFO - *** End BrowserChrome Test Results ***
INFO - GECKO(5656) | [Parent 5200, Main Thread] WARNING: NS_ENSURE_TRUE(GetWrapper()) failed: file z:/build/build/src/dom/ipc/JSWindowActor.cpp, line 61
INFO - GECKO(5656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 070EAC00 == 3 [pid = 152] [id = {361f45c8-0712-4aa8-95af-4ad7939fc32c}] [url = moz-extension://944b71c5-79c1-4052-88f4-00a2f2f4ed60/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 01577400 == 2 [pid = 152] [id = {5e20a674-e75c-4d82-889e-be37851eb8b6}] [url = moz-extension://028f78c0-0328-45b4-bac3-f36fd4157b48/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 070ED000 == 1 [pid = 152] [id = {b1be0698-6af9-4a58-9821-5337a002d66c}] [url = moz-extension://c6dbfaaf-48be-44cb-a533-02b4440bb8fa/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 01570C00 == 0 [pid = 152] [id = {33534c73-a5b4-49c7-ae1a-d034a5517aa2}] [url = moz-extension://e71b56ef-21ba-4f3f-a0de-6e430f028c56/_generated_background_page.html]
INFO - GECKO(5656) | [Parent 5200, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/cache/nsCacheService.cpp, line 855
INFO - GECKO(5656) | [Parent 5200, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/cache/nsCacheService.cpp, line 818
INFO - GECKO(5656) | [Parent 5200, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111: file z:/build/build/src/netwerk/cache/nsApplicationCacheService.cpp, line 158
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 7 (07022280) [pid = 152] [serial = 1] [outer = 00000000] [url = moz-extension://e71b56ef-21ba-4f3f-a0de-6e430f028c56/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 6 (07022700) [pid = 152] [serial = 5] [outer = 00000000] [url = moz-extension://944b71c5-79c1-4052-88f4-00a2f2f4ed60/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 5 (070224C0) [pid = 152] [serial = 3] [outer = 00000000] [url = moz-extension://028f78c0-0328-45b4-bac3-f36fd4157b48/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (07022940) [pid = 152] [serial = 7] [outer = 00000000] [url = moz-extension://c6dbfaaf-48be-44cb-a533-02b4440bb8fa/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0C463800) [pid = 152] [serial = 14] [outer = 00000000] [url = moz-extension://c6dbfaaf-48be-44cb-a533-02b4440bb8fa/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (070F7800) [pid = 152] [serial = 12] [outer = 00000000] [url = moz-extension://028f78c0-0328-45b4-bac3-f36fd4157b48/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (070F8C00) [pid = 152] [serial = 13] [outer = 00000000] [url = moz-extension://944b71c5-79c1-4052-88f4-00a2f2f4ed60/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (070F6400) [pid = 152] [serial = 11] [outer = 00000000] [url = moz-extension://e71b56ef-21ba-4f3f-a0de-6e430f028c56/_generated_background_page.html]
INFO - GECKO(5656) | [Child 152, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file z:/build/build/src/xpcom/base/nsCycleCollector.cpp, line 3362
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 24887
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 24887
INFO - GECKO(5656) | => mShareCount: 20732
INFO - GECKO(5656) | => mAdoptCount: 458
INFO - GECKO(5656) | => mAdoptFreeCount: 494
INFO - GECKO(5656) | => Process ID: 152, Thread ID: 2520
INFO - GECKO(5656) | [2020-01-11T19:58:29Z WARN xulstore::persist] tried to remove key that isn't in the store
INFO - GECKO(5656) | [2020-01-11T19:58:29Z WARN xulstore::persist] tried to remove key that isn't in the store
INFO - GECKO(5656) | [Parent 5200: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 14ECD400 == 4 [pid = 5200] [id = {bfc07a61-1ffb-4fbd-a6f3-c4710d9408ea}] [url = chrome://mochikit/content/browser-harness.xhtml]
INFO - GECKO(5656) | [Parent 5200: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 13B20400 == 3 [pid = 5200] [id = {83eb0fc9-9f75-49bd-97fc-dd9650ab3436}] [url = chrome://browser/content/browser.xhtml]
INFO - GECKO(5656) | [Parent 5200: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 14BF2000 == 2 [pid = 5200] [id = {f781255d-1b4f-4b4b-9b19-e252e0afd8d4}] [url = about:blank]
INFO - GECKO(5656) | [Parent 5200: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 15BED800 == 1 [pid = 5200] [id = {b2552749-5934-464e-9bfc-00758b078ba6}] [url = chrome://extensions/content/dummy.xhtml]
INFO - GECKO(5656) | [Parent 5200: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 17695800 == 0 [pid = 5200] [id = {cc413fe6-7b6b-4c7d-9c64-1f59065c69ce}] [url = resource://gre-resources/hiddenWindow.html]
INFO - GECKO(5656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(5656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(5656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(5656) | [Child 1252: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 01070800 == 0 [pid = 1252] [id = {2d4abfc8-4952-46f0-9b0d-edd6a34f8086}] [url = about:blank]
INFO - GECKO(5656) | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
INFO - GECKO(5656) | [Child 1252: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 1 (01086280) [pid = 1252] [serial = 1] [outer = 00000000] [url = about:blank]
INFO - GECKO(5656) | [Child 1252: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 0 (01076000) [pid = 1252] [serial = 2] [outer = 00000000] [url = about:blank]
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 6595
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 6595
INFO - GECKO(5656) | => mShareCount: 12830
INFO - GECKO(5656) | => mAdoptCount: 386
INFO - GECKO(5656) | => mAdoptFreeCount: 386
INFO - GECKO(5656) | => Process ID: 1252, Thread ID: 4728
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 6646
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 6646
INFO - GECKO(5656) | => mShareCount: 13116
INFO - GECKO(5656) | => mAdoptCount: 301
INFO - GECKO(5656) | => mAdoptFreeCount: 301
INFO - GECKO(5656) | => Process ID: 5236, Thread ID: 5888
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 6808
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 6808
INFO - GECKO(5656) | => mShareCount: 13268
INFO - GECKO(5656) | => mAdoptCount: 301
INFO - GECKO(5656) | => mAdoptFreeCount: 301
INFO - GECKO(5656) | => Process ID: 4844, Thread ID: 3204
INFO - GECKO(5656) | [Parent 5200, Gecko_IOThread] ###!!! ABORT: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 85
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 6851
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 6851
INFO - GECKO(5656) | => mShareCount: 13300
INFO - GECKO(5656) | => mAdoptCount: 301
INFO - GECKO(5656) | => mAdoptFreeCount: 301
INFO - GECKO(5656) | => Process ID: 6000, Thread ID: 5172
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 6621
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 6621
INFO - GECKO(5656) | => mShareCount: 13097
INFO - GECKO(5656) | => mAdoptCount: 301
INFO - GECKO(5656) | => mAdoptFreeCount: 301
INFO - GECKO(5656) | => Process ID: 5676, Thread ID: 848
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 6805
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 6805
INFO - GECKO(5656) | => mShareCount: 14456
INFO - GECKO(5656) | => mAdoptCount: 386
INFO - GECKO(5656) | => mAdoptFreeCount: 386
INFO - GECKO(5656) | => Process ID: 2876, Thread ID: 1392
INFO - GECKO(5656) | nsStringStats
INFO - GECKO(5656) | => mAllocCount: 7480
INFO - GECKO(5656) | => mReallocCount: 0
INFO - GECKO(5656) | => mFreeCount: 7480
INFO - GECKO(5656) | => mShareCount: 14033
INFO - GECKO(5656) | => mAdoptCount: 407
INFO - GECKO(5656) | => mAdoptFreeCount: 407
INFO - GECKO(5656) | => Process ID: 5796, Thread ID: 1584
INFO - TEST-INFO | Main app process: exit 1
INFO - TEST-INFO | Confirming we saw 50 DOCSHELL created and 37 destroyed log strings.
INFO - TEST-INFO | Confirming we saw 156 DOMWINDOW created and 106 destroyed log strings.
INFO - TEST-INFO | browser/base/content/test/tabcrashed/browser_autoSubmitRequest.js | This test created 1 hidden docshell(s)
INFO - TEST-INFO | browser/base/content/test/tabcrashed/browser_clearEmail.js | This test created 1 hidden docshell(s)
INFO - TEST-INFO | browser/base/content/test/tabcrashed/browser_showForm.js | This test created 1 hidden docshell(s)
INFO - TEST-INFO | browser/base/content/test/tabcrashed/browser_shown.js | This test created 1 hidden docshell(s)
INFO - TEST-INFO | browser/base/content/test/tabcrashed/browser_shownRestartRequired.js | This test created 1 hidden docshell(s)
INFO - TEST-INFO | browser/base/content/test/tabcrashed/browser_withoutDump.js | This test created 1 hidden docshell(s)
INFO - Buffered messages finished
ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 1

Comment hidden (Intermittent Failures Robot)

Jed Davis [:jld] ⟨⏰|UTC-7⟩ ⟦he/him⟧

Comment 2

•

5 years ago

This is a debug assertion in base::CloseProcessHandle, checking that the CloseHandle succeeds.

Given the variety of callers for CloseProcessHandle, I suspect that this is a double-close of the process handle itself (maybe a race condition?), but in theory it could also be a side-effect of a double-close somewhere else.

In either case it could be related to bug 1603847.

Priority: P5 → P3

See Also: → https://bugzilla.mozilla.org/show_bug.cgi?id=1603847

Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)

Updated

•

5 years ago

Summary: Intermittent GECKO(5656) | [Parent 5200, Gecko_IOThread] ###!!! ABORT: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 85 → Intermittent [Parent 5200, Gecko_IOThread] ###!!! ABORT: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 85

BMO Automation

Updated

•

2 years ago

Severity: normal → S3

BugBot [:suhaib / :marco/ :calixte]

Comment 3

•

1 years ago

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.

Status: NEW → RESOLVED

Closed: 1 years ago

Resolution: --- → INCOMPLETE

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

Bugzilla

Intermittent [Parent 5200, Gecko_IOThread] ###!!! ABORT: file z:/build/build/src/ipc/chromium/src/base/process_util_win.cc, line 85

Categories

(Core :: IPC, defect, P3)

Tracking

()

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure)

Crash Data

Security

(public)

User Story

Description

Comment 1

Comment 2

Updated

Updated

Comment 3