Closed Bug 1753695 Opened 3 years ago Closed 3 years ago

Intermittent SUMMARY: ThreadSanitizer: SEGV /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:1237:7 in mozilla::net::nsSocketTransport::InitiateSocket() | after FATAL ERROR: Non-local network connections are disabled and a connection att

Categories

(Firefox :: New Tab Page, defect, P5)

defect

Tracking

()

RESOLVED DUPLICATE of bug 1714615

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

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


[task 2022-02-04T15:04:25.545Z] 15:04:25     INFO - TEST-START | browser/components/newtab/test/browser/browser_trigger_listeners.js
[task 2022-02-04T15:04:31.227Z] 15:04:31     INFO - GECKO(1969) | FATAL ERROR: Non-local network connections are disabled and a connection attempt to firefox.settings.services.mozilla.com (99.84.191.110) was made.
[task 2022-02-04T15:04:31.228Z] 15:04:31     INFO - GECKO(1969) | 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 2022-02-04T15:04:31.228Z] 15:04:31     INFO - GECKO(1969) | ThreadSanitizer:DEADLYSIGNAL
[task 2022-02-04T15:04:31.228Z] 15:04:31     INFO - GECKO(1969) | ==1969==ERROR: ThreadSanitizer: SEGV on unknown address 0x000000000000 (pc 0x7f68b11fbef4 bp 0x7b4c00002f40 sp 0x7f6826a467c0 T1981)
[task 2022-02-04T15:04:31.228Z] 15:04:31     INFO - GECKO(1969) | ==1969==The signal is caused by a WRITE memory access.
[task 2022-02-04T15:04:31.228Z] 15:04:31     INFO - GECKO(1969) | ==1969==Hint: address points to the zero page.
[task 2022-02-04T15:04:31.298Z] 15:04:31     INFO - GECKO(1969) |     #0 mozilla::net::nsSocketTransport::InitiateSocket() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:1237:7 (libxul.so+0x1199ef4)
[task 2022-02-04T15:04:31.300Z] 15:04:31     INFO - GECKO(1969) |     #1 mozilla::net::nsSocketTransport::OnSocketEvent(unsigned int, nsresult, nsISupports*) /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp (libxul.so+0x119d399)
[task 2022-02-04T15:04:31.301Z] 15:04:31     INFO - GECKO(1969) |     #2 mozilla::net::nsSocketEvent::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:94:17 (libxul.so+0x11c8776)
[task 2022-02-04T15:04:31.302Z] 15:04:31     INFO - GECKO(1969) |     #3 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1189:16 (libxul.so+0xfadb23)
[task 2022-02-04T15:04:31.302Z] 15:04:31     INFO - GECKO(1969) |     #4 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:467:10 (libxul.so+0xfb4542)
[task 2022-02-04T15:04:31.303Z] 15:04:31     INFO - GECKO(1969) |     #5 mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp:1190:11 (libxul.so+0x11a8c87)
[task 2022-02-04T15:04:31.306Z] 15:04:31     INFO - GECKO(1969) |     #6 non-virtual thunk to mozilla::net::nsSocketTransportService::Run() /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransportService2.cpp (libxul.so+0x11aa0e9)
[task 2022-02-04T15:04:31.307Z] 15:04:31     INFO - GECKO(1969) |     #7 nsThread::ProcessNextEvent(bool, bool*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:1189:16 (libxul.so+0xfadb23)
[task 2022-02-04T15:04:31.307Z] 15:04:31     INFO - GECKO(1969) |     #8 NS_ProcessNextEvent(nsIThread*, bool) /builds/worker/checkouts/gecko/xpcom/threads/nsThreadUtils.cpp:467:10 (libxul.so+0xfb4542)
[task 2022-02-04T15:04:31.307Z] 15:04:31     INFO - GECKO(1969) |     #9 mozilla::ipc::MessagePumpForNonMainThreads::Run(base::MessagePump::Delegate*) /builds/worker/checkouts/gecko/ipc/glue/MessagePump.cpp:300:20 (libxul.so+0x1929ece)
[task 2022-02-04T15:04:31.307Z] 15:04:31     INFO - GECKO(1969) |     #10 RunInternal /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:331:10 (libxul.so+0x18a703c)
[task 2022-02-04T15:04:31.307Z] 15:04:31     INFO - GECKO(1969) |     #11 RunHandler /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:324:3 (libxul.so+0x18a703c)
[task 2022-02-04T15:04:31.307Z] 15:04:31     INFO - GECKO(1969) |     #12 MessageLoop::Run() /builds/worker/checkouts/gecko/ipc/chromium/src/base/message_loop.cc:306:3 (libxul.so+0x18a703c)
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) |     #13 nsThread::ThreadFunc(void*) /builds/worker/checkouts/gecko/xpcom/threads/nsThread.cpp:391:10 (libxul.so+0xfa9c03)
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) |     #14 _pt_root /builds/worker/checkouts/gecko/nsprpub/pr/src/pthreads/ptthread.c:201:5 (libnspr4.so+0x44fad)
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) |     #15 __tsan_thread_start_func /builds/worker/fetches/llvm-project/llvm/projects/compiler-rt/lib/tsan/rtl/tsan_interceptors_posix.cpp:967:15 (firefox+0x590cc)
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) |     #16 start_thread /tmp/glibc/nptl/pthread_create.c:463 (libpthread.so.0+0x76da)
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) |     #17 __clone /tmp/glibc/misc/../sysdeps/unix/sysv/linux/x86_64/clone.S:95 (libc.so.6+0x121a3e)
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) | ThreadSanitizer can not provide additional info.
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) | SUMMARY: ThreadSanitizer: SEGV /builds/worker/checkouts/gecko/netwerk/base/nsSocketTransport2.cpp:1237:7 in mozilla::net::nsSocketTransport::InitiateSocket()
[task 2022-02-04T15:04:31.308Z] 15:04:31     INFO - GECKO(1969) | ==1969==ABORTING
[task 2022-02-04T15:04:31.422Z] 15:04:31     INFO - GECKO(1969) | Exiting due to channel error.
[task 2022-02-04T15:04:31.423Z] 15:04:31     INFO - GECKO(1969) | Exiting due to channel error.
[task 2022-02-04T15:04:31.423Z] 15:04:31     INFO - GECKO(1969) | Exiting due to channel error.
[task 2022-02-04T15:04:31.427Z] 15:04:31     INFO - GECKO(1969) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=3.7927) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=1.85288) Exiting due to channel error.
[task 2022-02-04T15:04:31.427Z] 15:04:31     INFO - GECKO(1969) | Exiting due to channel error.
[task 2022-02-04T15:04:31.428Z] 15:04:31     INFO - GECKO(1969) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=254.059) Exiting due to channel error.
[task 2022-02-04T15:04:31.429Z] 15:04:31     INFO - GECKO(1969) | Exiting due to channel error.
[task 2022-02-04T15:04:31.429Z] 15:04:31     INFO - GECKO(1969) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=65.9919) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=265.975) Exiting due to channel error.
[task 2022-02-04T15:04:31.430Z] 15:04:31     INFO - GECKO(1969) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=264.979) Exiting due to channel error.
[task 2022-02-04T15:04:31.431Z] 15:04:31     INFO - GECKO(1969) | Exiting due to channel error.
[task 2022-02-04T15:04:31.431Z] 15:04:31     INFO - GECKO(1969) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=92.6379) Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=260.547) Exiting due to channel error.
[task 2022-02-04T15:04:32.507Z] 15:04:32     INFO - GECKO(1969) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: Receive IPC close with reason=AbnormalShutdown (t=34.3732)
[task 2022-02-04T15:04:32.507Z] 15:04:32     INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2022-02-04T15:04:32.508Z] 15:04:32     INFO - Buffered messages logged at 15:04:25
[task 2022-02-04T15:04:32.508Z] 15:04:32     INFO - Entering test bound setup
[task 2022-02-04T15:04:32.509Z] 15:04:32     INFO - Leaving test bound setup
[task 2022-02-04T15:04:32.509Z] 15:04:32     INFO - Entering test bound test_openURL_visit_counter
[task 2022-02-04T15:04:32.509Z] 15:04:32     INFO - Buffered messages logged at 15:04:27
[task 2022-02-04T15:04:32.510Z] 15:04:32     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "https://example.com/" line: 0}]
[task 2022-02-04T15:04:32.510Z] 15:04:32     INFO - Buffered messages logged at 15:04:29
[task 2022-02-04T15:04:32.511Z] 15:04:32     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "http://example.com/" line: 0}]
[task 2022-02-04T15:04:32.511Z] 15:04:32     INFO - Buffered messages logged at 15:04:30
[task 2022-02-04T15:04:32.511Z] 15:04:32     INFO - Console message: [JavaScript Warning: "This page is in Quirks Mode. Page layout may be impacted. For Standards Mode use “<!DOCTYPE html>”." {file: "http://example.com/" line: 0}]
[task 2022-02-04T15:04:32.512Z] 15:04:32     INFO - Buffered messages logged at 15:04:31
[task 2022-02-04T15:04:32.512Z] 15:04:32     INFO - TEST-PASS | browser/components/newtab/test/browser/browser_trigger_listeners.js | Stub called 3 times for example.com host - 3 == 3 - 
[task 2022-02-04T15:04:32.513Z] 15:04:32     INFO - TEST-PASS | browser/components/newtab/test/browser/browser_trigger_listeners.js | First call should have count 1 - 1 == 1 - 
[task 2022-02-04T15:04:32.513Z] 15:04:32     INFO - TEST-PASS | browser/components/newtab/test/browser/browser_trigger_listeners.js | Third call should have count 2 for http://example.com - 2 == 2 - 
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - Leaving test bound test_openURL_visit_counter
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - Entering test bound test_openURL_visit_counter_withPattern
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - Buffered messages finished
[task 2022-02-04T15:04:32.518Z] 15:04:32    ERROR - TEST-UNEXPECTED-FAIL | browser/components/newtab/test/browser/browser_trigger_listeners.js | application terminated with exit code -6
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - runtests.py | Application ran for: 0:04:35.549307
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - zombiecheck | Reading PID log: /tmp/tmpa83rkds8pidlog
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 1985
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2044
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2063
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2111
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2140
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2153
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2188
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2221
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2279
[task 2022-02-04T15:04:32.518Z] 15:04:32     INFO - ==> process 1969 launched child process 2310
[task 2022-02-04T15:04:32.519Z] 15:04:32     INFO - ==> process 1969 launched child process 2341
[task 2022-02-04T15:04:32.519Z] 15:04:32     INFO - ==> process 1969 launched child process 2369
[task 2022-02-04T15:04:32.519Z] 15:04:32     INFO - ==> process 1969 launched child process 2372
[task 2022-02-04T15:04:32.520Z] 15:04:32     INFO - ==> process 1969 launched child process 2420
[task 2022-02-04T15:04:32.520Z] 15:04:32     INFO - ==> process 1969 launched child process 2448
[task 2022-02-04T15:04:32.521Z] 15:04:32     INFO - ==> process 1969 launched child process 2476
[task 2022-02-04T15:04:32.521Z] 15:04:32     INFO - ==> process 1969 launched child process 2494
[task 2022-02-04T15:04:32.522Z] 15:04:32     INFO - ==> process 1969 launched child process 2518
[task 2022-02-04T15:04:32.522Z] 15:04:32     INFO - ==> process 1969 launched child process 2555
[task 2022-02-04T15:04:32.522Z] 15:04:32     INFO - ==> process 1969 launched child process 2579
[task 2022-02-04T15:04:32.523Z] 15:04:32     INFO - ==> process 1969 launched child process 2625
[task 2022-02-04T15:04:32.523Z] 15:04:32     INFO - ==> process 1969 launched child process 2632
[task 2022-02-04T15:04:32.526Z] 15:04:32     INFO - ==> process 1969 launched child process 2669
[task 2022-02-04T15:04:32.527Z] 15:04:32     INFO - ==> process 1969 launched child process 2673
[task 2022-02-04T15:04:32.527Z] 15:04:32     INFO - ==> process 1969 launched child process 2721
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - ==> process 1969 launched child process 2746
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - ==> process 1969 launched child process 2772
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2310
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2188
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2063
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2448
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2579
[task 2022-02-04T15:04:32.528Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2721
[task 2022-02-04T15:04:32.529Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2341
[task 2022-02-04T15:04:32.529Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2476
[task 2022-02-04T15:04:32.529Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2221
[task 2022-02-04T15:04:32.530Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2746
[task 2022-02-04T15:04:32.530Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2494
[task 2022-02-04T15:04:32.531Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2111
[task 2022-02-04T15:04:32.531Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 1985
[task 2022-02-04T15:04:32.532Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2369
[task 2022-02-04T15:04:32.534Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2625
[task 2022-02-04T15:04:32.535Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2372
[task 2022-02-04T15:04:32.535Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2632
[task 2022-02-04T15:04:32.536Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2772
[task 2022-02-04T15:04:32.536Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2518
[task 2022-02-04T15:04:32.537Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2140
[task 2022-02-04T15:04:32.537Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2279
[task 2022-02-04T15:04:32.538Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2153
[task 2022-02-04T15:04:32.538Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2669
[task 2022-02-04T15:04:32.539Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2673
[task 2022-02-04T15:04:32.539Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2420
[task 2022-02-04T15:04:32.540Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2555
[task 2022-02-04T15:04:32.541Z] 15:04:32     INFO - zombiecheck | Checking for orphan process with PID: 2044
[task 2022-02-04T15:04:32.541Z] 15:04:32     INFO - Stopping web server
[task 2022-02-04T15:04:32.542Z] 15:04:32     INFO - Server shut down.
[task 2022-02-04T15:04:32.551Z] 15:04:32     INFO - Web server killed.
[task 2022-02-04T15:04:32.552Z] 15:04:32     INFO - Stopping web socket server
[task 2022-02-04T15:04:32.572Z] 15:04:32     INFO - Stopping ssltunnel
[task 2022-02-04T15:04:32.592Z] 15:04:32  WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2022-02-04T15:04:32.593Z] 15:04:32     INFO - runtests.py | Running tests: end.
[task 2022-02-04T15:04:32.610Z] 15:04:32     INFO - Buffered messages finished
[task 2022-02-04T15:04:32.610Z] 15:04:32     INFO - Running manifest: browser/components/tests/browser/whats_new_page/browser.ini
[task 2022-02-04T15:04:32.611Z] 15:04:32     INFO - The following extra prefs will be set:
[task 2022-02-04T15:04:32.611Z] 15:04:32     INFO -   app.update.altUpdateDirPath='<test-root>/browser/components/tests/browser/whats_new_page'
[task 2022-02-04T15:04:32.611Z] 15:04:32     INFO -   app.update.disabledForTesting=false
[task 2022-02-04T15:04:32.611Z] 15:04:32     INFO -   browser.aboutwelcome.enabled=false
[task 2022-02-04T15:04:32.611Z] 15:04:32     INFO -   browser.startup.homepage_override.mstone="60.0"
[task 2022-02-04T15:04:32.611Z] 15:04:32     INFO -   browser.startup.upgradeDialog.enabled=false
[task 2022-02-04T15:04:32.629Z] 15:04:32     INFO -  Setting pipeline to PAUSED ...
[task 2022-02-04T15:04:32.629Z] 15:04:32     INFO -  Pipeline is PREROLLING ...
[task 2022-02-04T15:04:32.631Z] 15:04:32     INFO -  Pipeline is PREROLLED ...
[task 2022-02-04T15:04:32.631Z] 15:04:32     INFO -  Setting pipeline to PLAYING ...
[task 2022-02-04T15:04:32.631Z] 15:04:32     INFO -  New clock: GstSystemClock
[task 2022-02-04T15:04:32.665Z] 15:04:32     INFO -  Got EOS from element "pipeline0".
[task 2022-02-04T15:04:32.665Z] 15:04:32     INFO -  Execution ended after 0:00:00.033442328
[task 2022-02-04T15:04:32.665Z] 15:04:32     INFO -  Setting pipeline to PAUSED ...
[task 2022-02-04T15:04:32.666Z] 15:04:32     INFO -  Setting pipeline to READY ...
[task 2022-02-04T15:04:32.666Z] 15:04:32     INFO -  (gst-launch-1.0:2806): GStreamer-CRITICAL **: 15:04:32.664: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2022-02-04T15:04:32.666Z] 15:04:32     INFO -  Setting pipeline to NULL ...
[task 2022-02-04T15:04:32.666Z] 15:04:32     INFO -  Freeing pipeline ...
[task 2022-02-04T15:04:32.686Z] 15:04:32     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-04T15:04:33.055Z] 15:04:33     INFO - PID 2816 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2022-02-04T15:04:33.254Z] 15:04:33     INFO - Increasing default timeout to 120 seconds
[task 2022-02-04T15:04:33.254Z] 15:04:33     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-04T15:04:33.255Z] 15:04:33     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-04T15:04:33.258Z] 15:04:33     INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmp1kydbm3m.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2022-02-04T15:04:33.259Z] 15:04:33     INFO - runtests.py | Server pid: 2825
[task 2022-02-04T15:04:33.263Z] 15:04:33     INFO - runtests.py | Websocket server pid: 2828
[task 2022-02-04T15:04:33.264Z] 15:04:33     INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2022-02-04T15:04:33.279Z] 15:04:33     INFO - runtests.py | SSL tunnel pid: 2832
[task 2022-02-04T15:04:33.831Z] 15:04:33     INFO - runtests.py | Running with scheme: http
[task 2022-02-04T15:04:33.832Z] 15:04:33     INFO - runtests.py | Running with e10s: True
[task 2022-02-04T15:04:33.833Z] 15:04:33     INFO - runtests.py | Running with fission: True
[task 2022-02-04T15:04:33.833Z] 15:04:33     INFO - runtests.py | Running with cross-origin iframes: False
[task 2022-02-04T15:04:33.834Z] 15:04:33     INFO - runtests.py | Running with serviceworker_e10s: True
[task 2022-02-04T15:04:33.834Z] 15:04:33     INFO - runtests.py | Running with socketprocess_e10s: False
[task 2022-02-04T15:04:33.834Z] 15:04:33     INFO - runtests.py | Running tests: start.
[task 2022-02-04T15:04:33.834Z] 15:04:33     INFO - 
[task 2022-02-04T15:04:33.848Z] 15:04:33     INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmp1kydbm3m.mozrunner
[task 2022-02-04T15:04:33.852Z] 15:04:33     INFO - runtests.py | Application pid: 2853
[task 2022-02-04T15:04:33.853Z] 15:04:33     INFO - TEST-INFO | started process GECKO(2853)
[task 2022-02-04T15:04:38.109Z] 15:04:38     INFO - GECKO(2853) | 1643987078108	Marionette	INFO	Marionette enabled
[task 2022-02-04T15:04:39.001Z] 15:04:39     INFO - GECKO(2853) | 1643987079000	Marionette	TRACE	Received observer notification toplevel-window-ready
[task 2022-02-04T15:04:48.274Z] 15:04:48     INFO - GECKO(2853) | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at /tmp/tmp1kydbm3m.mozrunner/search.json.mozlz4", (void 0)))
[task 2022-02-04T15:04:48.797Z] 15:04:48     INFO - GECKO(2853) | JavaScript error: resource://gre/modules/UpdateService.jsm, line 1343: NS_ERROR_FILE_TARGET_DOES_NOT_EXIST: Component returned failure code: 0x80520006 (NS_ERROR_FILE_TARGET_DOES_NOT_EXIST) [nsIFile.directoryEntries]
[task 2022-02-04T15:04:59.430Z] 15:04:59     INFO - GECKO(2853) | 1643987099428	Marionette	TRACE	Received observer notification marionette-startup-requested
[task 2022-02-04T15:04:59.431Z] 15:04:59     INFO - GECKO(2853) | 1643987099430	Marionette	TRACE	Waiting until startup recorder finished recording startup scripts...
[task 2022-02-04T15:04:59.565Z] 15:04:59     INFO - GECKO(2853) | 1643987099564	Marionette	TRACE	All scripts recorded.
[task 2022-02-04T15:04:59.598Z] 15:04:59     INFO - GECKO(2853) | 1643987099597	Marionette	INFO	Listening on port 2828
[task 2022-02-04T15:04:59.601Z] 15:04:59     INFO - GECKO(2853) | 1643987099600	Marionette	DEBUG	Marionette is listening
[task 2022-02-04T15:04:59.803Z] 15:04:59     INFO - GECKO(2853) | 1643987099802	Marionette	DEBUG	Accepted connection 0 from 127.0.0.1:37184
[task 2022-02-04T15:04:59.822Z] 15:04:59     INFO - GECKO(2853) | 1643987099821	Marionette	DEBUG	Closed connection 0
[task 2022-02-04T15:04:59.824Z] 15:04:59     INFO - GECKO(2853) | 1643987099823	Marionette	DEBUG	Accepted connection 1 from 127.0.0.1:37186
[task 2022-02-04T15:04:59.917Z] 15:04:59     INFO - GECKO(2853) | 1643987099916	Marionette	DEBUG	1 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2022-02-04T15:05:00.035Z] 15:05:00     INFO - GECKO(2853) | 1643987100034	RemoteAgent	TRACE	[19] Document already finished loading: https://example.com/
[task 2022-02-04T15:05:00.043Z] 15:05:00     INFO - GECKO(2853) | 1643987100042	Marionette	DEBUG	1 <- [1,1,null,{"sessionId":"66a31de1-8caa-403b-8c96-447eb62d2ca1","capabilities":{"browserName":"firefox","browserVersion":"98.0a ... .mozrunner","moz:shutdownTimeout":360000,"moz:useNonSpecCompliantPointerOrigin":false,"moz:webdriverClick":true,"proxy":{}}}]
[task 2022-02-04T15:05:00.093Z] 15:05:00     INFO - GECKO(2853) | 1643987100092	Marionette	DEBUG	1 -> [0,2,"Addon:Install",{"path":"/tmp/tmpzfpmsrcq.zip","temporary":false}]
[task 2022-02-04T15:05:00.461Z] 15:05:00     INFO - GECKO(2853) | 1643987100460	Marionette	DEBUG	1 <- [1,2,null,{"value":"special-powers@mozilla.org"}]
[task 2022-02-04T15:05:00.499Z] 15:05:00     INFO - GECKO(2853) | 1643987100498	Marionette	DEBUG	1 -> [0,3,"Addon:Install",{"path":"/tmp/tmpmdlw6c_d.zip","temporary":false}]
[task 2022-02-04T15:05:00.704Z] 15:05:00     INFO - GECKO(2853) | 1643987100703	Marionette	DEBUG	1 <- [1,3,null,{"value":"mochikit@mozilla.org"}]
[task 2022-02-04T15:05:00.713Z] 15:05:00     INFO - GECKO(2853) | 1643987100712	Marionette	DEBUG	1 -> [0,4,"Marionette:GetContext",{}]
[task 2022-02-04T15:05:00.715Z] 15:05:00     INFO - GECKO(2853) | 1643987100714	Marionette	DEBUG	1 <- [1,4,null,{"value":"content"}]
[task 2022-02-04T15:05:00.721Z] 15:05:00     INFO - GECKO(2853) | 1643987100720	Marionette	DEBUG	1 -> [0,5,"Marionette:SetContext",{"value":"chrome"}]
[task 2022-02-04T15:05:00.723Z] 15:05:00     INFO - GECKO(2853) | 1643987100722	Marionette	DEBUG	1 <- [1,5,null,{"value":null}]
[task 2022-02-04T15:05:00.753Z] 15:05:00     INFO - GECKO(2853) | 1643987100751	Marionette	DEBUG	1 -> [0,6,"WebDriver:ExecuteScript",{"script":"/* This Source Code Form is subject to the terms of the Mozilla Public\n * License, ... hrome","testUrl":"about:blank"}],"newSandbox":true,"sandbox":"default","line":1945,"filename":"tests/mochitest/runtests.py"}]
[task 2022-02-04T15:05:00.793Z] 15:05:00     INFO - GECKO(2853) | 1643987100792	Marionette	TRACE	[7] MarionetteCommands actor created for window id 2
[task 2022-02-04T15:05:01.006Z] 15:05:01     INFO - GECKO(2853) | 1643987101005	Marionette	TRACE	Received observer notification domwindowopened
[task 2022-02-04T15:05:01.050Z] 15:05:01     INFO - GECKO(2853) | 1643987101048	Marionette	TRACE	Remoteness change detected. Set new top-level browsing context to 51
[task 2022-02-04T15:05:01.098Z] 15:05:01     INFO - GECKO(2853) | 1643987101097	Marionette	DEBUG	1 <- [1,6,null,{"value":null}]
[task 2022-02-04T15:05:01.125Z] 15:05:01     INFO - GECKO(2853) | 1643987101124	Marionette	DEBUG	1 -> [0,7,"Marionette:SetContext",{"value":"content"}]
[task 2022-02-04T15:05:01.127Z] 15:05:01     INFO - GECKO(2853) | 1643987101126	Marionette	DEBUG	1 <- [1,7,null,{"value":null}]
[task 2022-02-04T15:05:01.349Z] 15:05:01     INFO - GECKO(2853) | 1643987101348	Marionette	DEBUG	1 -> [0,8,"WebDriver:DeleteSession",{}]
[task 2022-02-04T15:05:01.365Z] 15:05:01     INFO - GECKO(2853) | 1643987101364	Marionette	DEBUG	1 <- [1,8,null,{"value":null}]
[task 2022-02-04T15:05:01.474Z] 15:05:01     INFO - runtests.py | Waiting for browser...
[task 2022-02-04T15:05:01.553Z] 15:05:01     INFO - GECKO(2853) | 1643987101552	Marionette	DEBUG	Closed connection 1
[task 2022-02-04T15:05:02.761Z] 15:05:02     INFO - TEST-START | browser/components/tests/browser/whats_new_page/browser_whats_new_page.js
[task 2022-02-04T15:05:03.017Z] 15:05:03     INFO - GECKO(2853) | JavaScript error: resource://gre/modules/URLQueryStrippingListService.jsm, line 90: TypeError: can't access property "removeEventListener", Services.cpmm.sharedData is null
[task 2022-02-04T15:05:03.018Z] 15:05:03     INFO - GECKO(2853) | ###!!! [Parent][PBackgroundParent] Error: RunMessage(msgname=PRemoteWorkerService::Msg___delete__) Channel closing: too late to send/recv, messages will be lost
[task 2022-02-04T15:05:03.280Z] 15:05:03     INFO - GECKO(2853) | MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
[task 2022-02-04T15:05:03.290Z] 15:05:03     INFO - GECKO(2853) | MEMORY STAT heapAllocated not supported in this build configuration.
[task 2022-02-04T15:05:04.336Z] 15:05:04     INFO - GECKO(2853) | MEMORY STAT | vsize 130559441MB | residentFast 1468MB
[task 2022-02-04T15:05:04.339Z] 15:05:04     INFO - TEST-OK | browser/components/tests/browser/whats_new_page/browser_whats_new_page.js | took 1578ms

Hi! This is still failing intermittently after the backout of Bug 1272255.

Could you take look?

Flags: needinfo?(jdescottes)

We updated the harness scripts and mach commands for marionette-tests, telemetry-tests-clients and firefox-ui tests. This is a browser mochitest so it sounds unrelated. Investigating but have no clue why this would fail here.

Flags: needinfo?(jdescottes)

Indeed, this looks like Bug 1714615. Closing this bug as a dupe. Thanks

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → DUPLICATE
You need to log in before you can comment on or make changes to this bug.