1651899 - Intermittent ShutdownLeaks | process() called before end of test suite | After FATAL ERROR: Non-local network connections are disabled and a connection attempt to www.google.com (172.217.164.164) was made during browser_ext_omnibox.js

Status: RESOLVED FIXED

(WebExtensions :: Untriaged, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2020-07-10T04:08:05.983Z] 04:08:05 INFO - TEST-START | browser/components/extensions/test/browser/browser_ext_omnibox.js
[task 2020-07-10T04:08:06.080Z] 04:08:06 INFO - GECKO(1261) | [Parent 1261, Main Thread] WARNING: Need BrowserChild to get the nativeWindow from!: file /builds/worker/checkouts/gecko/widget/PuppetWidget.cpp, line 1086
[task 2020-07-10T04:08:06.081Z] 04:08:06 INFO - GECKO(1261) | [Child 1433: Main Thread]: I/DocShellAndDOMWindowLeak ++DOCSHELL 0x7f2bc8117400 == 7 [pid = 1433] [id = {a750c9b4-be01-4473-bd81-4e8b5a8d6435}]
[task 2020-07-10T04:08:06.081Z] 04:08:06 INFO - GECKO(1261) | [Child 1433: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 41 (0x7f2bc9b6f430) [pid = 1433] [serial = 1186] [outer = (nil)]
[task 2020-07-10T04:08:06.082Z] 04:08:06 INFO - GECKO(1261) | [Child 1433: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 42 (0x7f2bcadbbc00) [pid = 1433] [serial = 1187] [outer = 0x7f2bc9b6f430]
[task 2020-07-10T04:08:06.097Z] 04:08:06 INFO - GECKO(1261) | [Child 1433, Main Thread] WARNING: Fallback to BasicLayerManager: file /builds/worker/checkouts/gecko/dom/ipc/BrowserChild.cpp, line 2633
[task 2020-07-10T04:08:06.132Z] 04:08:06 INFO - GECKO(1261) | [Child 1433: Main Thread]: I/DocShellAndDOMWindowLeak ++DOMWINDOW == 43 (0x7f2bcba4d000) [pid = 1433] [serial = 1188] [outer = 0x7f2bc9b6f430]
[task 2020-07-10T04:08:06.747Z] 04:08:06 INFO - GECKO(1261) | [Child 1529: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 4 (0x7f4a18d05400) [pid = 1529] [serial = 310] [outer = (nil)] [url = about:blank]
[task 2020-07-10T04:08:06.748Z] 04:08:06 INFO - GECKO(1261) | [Child 1529: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 3 (0x7f4a18d0d800) [pid = 1529] [serial = 314] [outer = (nil)] [url = about:blank]
[task 2020-07-10T04:08:06.748Z] 04:08:06 INFO - GECKO(1261) | [Child 1529: Main Thread]: I/DocShellAndDOMWindowLeak --DOMWINDOW == 2 (0x7f4a18d0c400) [pid = 1529] [serial = 312] [outer = (nil)] [url = about:blank]
[task 2020-07-10T04:08:06.748Z] 04:08:06 INFO - GECKO(1261) | [Child 1529: Main Thread]: I/DocShellAndDOMWindowLeak --DOCSHELL 0x7f4a18d04400 == 0 [pid = 1529] [id = {33c486d8-49d0-4fcf-88e9-4a954300af37}] [url = about:blank]
[task 2020-07-10T04:08:07.212Z] 04:08:07 INFO - GECKO(1261) | FATAL ERROR: Non-local network connections are disabled and a connection attempt to www.google.com (172.217.164.164) was made.
[task 2020-07-10T04:08:07.214Z] 04:08:07 INFO - GECKO(1261) | You should only access hostnames available via the test networking proxy (if running mochitests) or from a test-specific httpd.js server (if running xpcshell tests). Browser services should be disabled or redirected to a local server.
[task 2020-07-10T04:08:07.218Z] 04:08:07 INFO - GECKO(1261) | Hit MOZ_CRASH(Attempting to connect to non-local address!) at /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:1318
[task 2020-07-10T04:08:07.219Z] 04:08:07 INFO - GECKO(1261) | #01: mozilla::net::nsSocketTransport::OnSocketEvent(unsigned int, nsresult, nsISupports*) [netwerk/base/nsSocketTransport2.cpp:0]
[task 2020-07-10T04:08:07.221Z] 04:08:07 INFO - GECKO(1261) | #02: mozilla::net::nsSocketEvent::Run() [netwerk/base/nsSocketTransport2.cpp:94]
[task 2020-07-10T04:08:07.222Z] 04:08:07 INFO - GECKO(1261) | #03: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1236]
[task 2020-07-10T04:08:07.223Z] 04:08:07 INFO - GECKO(1261) | #04: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:513]
[task 2020-07-10T04:08:07.224Z] 04:08:07 INFO - GECKO(1261) | #05: mozilla::net::nsSocketTransportService::Run() [netwerk/base/nsSocketTransportService2.cpp:1196]
[task 2020-07-10T04:08:07.226Z] 04:08:07 INFO - GECKO(1261) | #06: non-virtual thunk to mozilla::net::nsSocketTransportService::Run() [netwerk/base/nsSocketTransportService2.cpp:0]
[task 2020-07-10T04:08:07.227Z] 04:08:07 INFO - GECKO(1261) | #07: nsThread::ProcessNextEvent(bool, bool*) [xpcom/threads/nsThread.cpp:1236]
[task 2020-07-10T04:08:07.228Z] 04:08:07 INFO - GECKO(1261) | #08: NS_ProcessNextEvent(nsIThread*, bool) [xpcom/threads/nsThreadUtils.cpp:513]
[task 2020-07-10T04:08:07.239Z] 04:08:07 INFO - GECKO(1261) | #09: mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) [ipc/glue/MessagePump.cpp:303]
[task 2020-07-10T04:08:07.239Z] 04:08:07 INFO - GECKO(1261) | #10: MessageLoop::RunInternal() [ipc/chromium/src/base/message_loop.cc:334]
[task 2020-07-10T04:08:07.239Z] 04:08:07 INFO - GECKO(1261) | #11: MessageLoop::Run() [ipc/chromium/src/base/message_loop.cc:310]
[task 2020-07-10T04:08:07.239Z] 04:08:07 INFO - GECKO(1261) | #12: nsThread::ThreadFunc(void*) [xpcom/threads/nsThread.cpp:449]
[task 2020-07-10T04:08:07.260Z] 04:08:07 INFO - GECKO(1261) | #13: _pt_root [nsprpub/pr/src/pthreads/ptthread.c:204]
[task 2020-07-10T04:08:07.261Z] 04:08:07 INFO - fix-stacks error: failed to read breakpad symbols dir /builds/worker/workspace/build/symbols/libpthread.so.0 for /lib/x86_64-linux-gnu/libpthread.so.0
[task 2020-07-10T04:08:07.261Z] 04:08:07 INFO - fix-stacks note: this is expected and harmless for system libraries on debug automation runs
[task 2020-07-10T04:08:07.262Z] 04:08:07 INFO - GECKO(1261) | #14: ??? [/lib/x86_64-linux-gnu/libpthread.so.0 + 0x76db]
[task 2020-07-10T04:08:07.263Z] 04:08:07 INFO - GECKO(1261) | #15: clone [/lib/x86_64-linux-gnu/libc.so.6 + 0x121a3f]
[task 2020-07-10T04:08:07.263Z] 04:08:07 INFO - GECKO(1261) | #16: ??? (???:???)
[task 2020-07-10T04:08:07.264Z] 04:08:07 INFO - GECKO(1261) | ExceptionHandler::GenerateDump cloned child 2199
[task 2020-07-10T04:08:07.264Z] 04:08:07 INFO - GECKO(1261) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2020-07-10T04:08:07.265Z] 04:08:07 INFO - GECKO(1261) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2020-07-10T04:08:07.452Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.454Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.454Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.455Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.456Z] 04:08:07 INFO - GECKO(1261) | [GFX1-]: Receive IPC close with reason=AbnormalShutdown
[task 2020-07-10T04:08:07.459Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.459Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.473Z] 04:08:07 INFO - GECKO(1261) | Exiting due to channel error.
[task 2020-07-10T04:08:07.529Z] 04:08:07 INFO - TEST-INFO | Main app process: exit 11
[task 2020-07-10T04:08:07.531Z] 04:08:07 ERROR - TEST-UNEXPECTED-FAIL | ShutdownLeaks | process() called before end of test suite
[task 2020-07-10T04:08:07.532Z] 04:08:07 INFO - TEST-INFO | Confirming we saw 962 DOCSHELL created and 939 destroyed log strings.
[task 2020-07-10T04:08:07.532Z] 04:08:07 INFO - TEST-INFO | Confirming we saw 2557 DOMWINDOW created and 2463 destroyed log strings.
[task 2020-07-10T04:08:07.533Z] 04:08:07 INFO - Buffered messages logged at 04:08:05
[task 2020-07-10T04:08:07.533Z] 04:08:07 INFO - Entering test bound
[task 2020-07-10T04:08:07.534Z] 04:08:07 INFO - Extension loaded
[task 2020-07-10T04:08:07.534Z] 04:08:07 INFO - Buffered messages logged at 04:08:06
[task 2020-07-10T04:08:07.535Z] 04:08:07 INFO - Console message: Warning: attempting to write 19427 bytes to preference extensions.webextensions.uuids. This is bad for general performance and memory usage. Such an amount of data should rather be written to an external file. This preference will not be sent to any content processes.
[task 2020-07-10T04:08:07.535Z] 04:08:07 INFO - Buffered messages finished
[task 2020-07-10T04:08:07.535Z] 04:08:07 ERROR - TEST-UNEXPECTED-FAIL | browser/components/extensions/test/browser/browser_ext_omnibox.js | application terminated with exit code 11

Comment 1

[Andreea Pavel [:apavel]]

Retriggers: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2C18.04%2Cx64%2Cdebug%2Cmochitests%2Ctest-linux1804-64&tochange=9d8aeedf6049e20e365483a8a79fee2cf0d17e14&test_paths=browser%2Fcomponents%2Fextensions%2Ftest%2Fbrowser&group_state=expanded&fromchange=6318d54b706818d5768c890f5dd584c6d60fbeff&selectedTaskRun=HsZ7QNK_ScaUAGQ4f8-5mA.0

Comment 2

[Intermittent Failures Robot]

16 failures in 5265 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 14
• mozilla-central: 2

Platform breakdown:

• linux1804-64: 4
• windows10-64: 6
• windows7-32-shippable: 1
• windows10-64-qr: 3
• windows7-32: 1
• macosx1014-64: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1651899&startday=2020-07-06&endday=2020-07-12&tree=all

Comment 3

[Harry Twyford]

I strongly suspect this was caused by the issue pointed out in bug 1645324 comment 21. With that issue now fixed, I'm going to close this bug. Please reopen if this intermittent reoccurs!