Closed
Bug 1927306
Opened 1 year ago
Closed 1 year ago
AsyncShutdown timeout in quit-application-granted Conditions: [{"name":"XPIProvider shutdown","state":"(none)","filename":"resource://gre/modules/addons/XPIProvider.sys.mjs"
Categories
(Toolkit :: Add-ons Manager, defect, P5)
Toolkit
Add-ons Manager
Tracking
()
RESOLVED
INCOMPLETE
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure, intermittent-testcase)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=479932862&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/H187aXRUQlKidNy7PSS4QA/runs/0/artifacts/public/logs/live_backing.log
[task 2024-10-26T22:30:43.697Z] 22:30:43 INFO - TEST-START | remote/shared/listeners/test/browser/browser_BrowsingContextListener.js
[task 2024-10-26T22:31:28.707Z] 22:31:28 INFO - TEST-INFO | started process screentopng
[task 2024-10-26T22:31:28.847Z] 22:31:28 INFO - TEST-INFO | screentopng: exit 0
[task 2024-10-26T22:31:28.847Z] 22:31:28 INFO - Buffered messages logged at 22:30:43
[task 2024-10-26T22:31:28.848Z] 22:31:28 INFO - Entering test bound test_attachedOnNewTab
[task 2024-10-26T22:31:28.850Z] 22:31:28 INFO - Buffered messages finished
[task 2024-10-26T22:31:28.850Z] 22:31:28 INFO - TEST-UNEXPECTED-FAIL | remote/shared/listeners/test/browser/browser_BrowsingContextListener.js | Test timed out -
[task 2024-10-26T22:31:28.850Z] 22:31:28 INFO - GECKO(8108) | Completed ShutdownLeaks collections in process 8108
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - TEST-START | Shutdown
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - Browser Chrome Test Summary
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - Passed: 0
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - Failed: 1
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - Todo: 0
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - Mode: e10s
[task 2024-10-26T22:31:28.851Z] 22:31:28 INFO - *** End BrowserChrome Test Results ***
[task 2024-10-26T22:31:28.852Z] 22:31:28 INFO - GECKO(8108) | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2024-10-26T22:31:38.722Z] 22:31:38 INFO - GECKO(8108) | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"XPIProvider shutdown","state":"(none)","filename":"resource://gre/modules/addons/XPIProvider.sys.mjs","lineNumber":2610,"stack":["resource://gre/modules/addons/XPIProvider.sys.mjs:startup:2610","resource://gre/modules/AddonManager.sys.mjs:callProvider:226","resource://gre/modules/AddonManager.sys.mjs:_startProvider:535","resource://gre/modules/AddonManager.sys.mjs:startup:745","resource://gre/modules/AddonManager.sys.mjs:startup:3650","resource://gre/modules/amManager.sys.mjs:observe:73"]}] Barrier: quit-application-granted
[task 2024-10-26T22:34:29.723Z] 22:34:29 INFO - GECKO(8108) | FATAL ERROR: AsyncShutdown timeout in quit-application-granted Conditions: [{"name":"XPIProvider shutdown","state":"(none)","filename":"resource://gre/modules/addons/XPIProvider.sys.mjs","lineNumber":2610,"stack":["resource://gre/modules/addons/XPIProvider.sys.mjs:startup:2610","resource://gre/modules/AddonManager.sys.mjs:callProvider:226","resource://gre/modules/AddonManager.sys.mjs:_startProvider:535","resource://gre/modules/AddonManager.sys.mjs:startup:745","resource://gre/modules/AddonManager.sys.mjs:startup:3650","resource://gre/modules/amManager.sys.mjs:observe:73"]}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
[task 2024-10-26T22:34:29.723Z] 22:34:29 INFO - GECKO(8108) | [Parent 8108, Main Thread] ###!!! ABORT: file resource://gre/modules/addons/XPIProvider.sys.mjs:2610
[task 2024-10-26T22:34:29.724Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::GenerateDump attempting to generate:</tmp/tmpr9ugnmus.mozrunner/minidumps/061eb445-5f87-6d04-b075-2540b2e7353a.dmp
[task 2024-10-26T22:34:29.727Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2024-10-26T22:34:29.727Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::GenerateDump cloned child 8266
[task 2024-10-26T22:34:29.728Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2024-10-26T22:34:29.822Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::GenerateDump minidump generation <succeeded
[task 2024-10-26T22:40:39.819Z] 22:40:39 INFO - TEST-UNEXPECTED-TIMEOUT | remote/shared/listeners/test/browser/browser_BrowsingContextListener.js | application timed out after 370 seconds with no output
[task 2024-10-26T22:40:39.819Z] 22:40:39 INFO - TEST-INFO took 595304ms
[task 2024-10-26T22:40:39.819Z] 22:40:39 INFO - Buffered messages finished
[task 2024-10-26T22:40:39.822Z] 22:40:39 WARNING - Force-terminating active process(es).
[task 2024-10-26T22:40:39.822Z] 22:40:39 WARNING - profiler Attempting to start the profiler to help with diagnosing the hang.
[task 2024-10-26T22:40:39.822Z] 22:40:39 INFO - profiler Sending SIGUSR1 to pid 8108 start the profiler.
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - Traceback (most recent call last):
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/mozprocess/processhandler.py", line 1151, in _read
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - for line, callback in iter(get_line, (b"", None)):
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/mozprocess/processhandler.py", line 1145, in get_line
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - return queue.get(timeout=queue_timeout)
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/usr/lib/python3.8/queue.py", line 178, in get
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - raise Empty
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - _queue.Empty
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - During handling of the above exception, another exception occurred:
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - Traceback (most recent call last):
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/mozprocess/processhandler.py", line 1165, in _read
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - self.timeout_callback()
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/builds/worker/workspace/build/venv/lib/python3.8/site-packages/mozprocess/processhandler.py", line 1060, in __call__
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - e(*args, **kwargs)
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 2846, in timeoutHandler
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - self.handleTimeout(
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 3907, in handleTimeout
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - os.kill(browser_pid, signal.SIGUSR1)
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - ProcessLookupError: [Errno 3] No such process
[task 2024-10-26T22:40:39.823Z] 22:40:39 INFO - TEST-INFO | Main app process: exit 11
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - Buffered messages finished
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - runtests.py | Application ran for: 0:11:25.527720
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Reading PID log: /tmp/tmpaxn84swopidlog
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - ==> process 8108 launched child process 8161
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - ==> process 8108 launched child process 8185
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - ==> process 8108 launched child process 8202
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - ==> process 8108 launched child process 8222
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - ==> process 8108 launched child process 8224
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - ==> process 8108 launched child process 8261
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Checking for orphan process with PID: 8224
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Checking for orphan process with PID: 8161
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Checking for orphan process with PID: 8261
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Checking for orphan process with PID: 8202
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Checking for orphan process with PID: 8185
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - zombiecheck | Checking for orphan process with PID: 8222
[task 2024-10-26T22:40:39.824Z] 22:40:39 INFO - mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MzxUxdU4QnqAOlUNjBlQ2Q/artifacts/public/build/target.crashreporter-symbols.zip
[task 2024-10-26T22:40:49.825Z] 22:40:49 INFO - mozcrash Copy/paste: /builds/worker/fetches/minidump-stackwalk/minidump-stackwalk --symbols-url=https://symbols.mozilla.org/ --cyborg=/tmp/tmpwh4vuytc/061eb445-5f87-6d04-b075-2540b2e7353a.trace /tmp/tmpr9ugnmus.mozrunner/minidumps/061eb445-5f87-6d04-b075-2540b2e7353a.dmp /tmp/tmp81u5ipzn
[task 2024-10-26T22:40:53.951Z] 22:40:53 INFO - mozcrash Saved minidump as /builds/worker/workspace/build/blobber_upload_dir/061eb445-5f87-6d04-b075-2540b2e7353a.dmp
[task 2024-10-26T22:40:53.952Z] 22:40:53 INFO - mozcrash Saved app info as /builds/worker/workspace/build/blobber_upload_dir/061eb445-5f87-6d04-b075-2540b2e7353a.extra
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - PROCESS-CRASH | [Parent 8108, Main Thread] ###!!! ABORT: file resource://gre/modules/addons/XPIProvider.sys.mjs:2610 [@ MOZ_Crash] | remote/shared/listeners/test/browser/browser_BrowsingContextListener.js
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Process type: main
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Process pid: 8108
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Mozilla crash reason: [Parent 8108, Main Thread] ###!!! ABORT: file resource://gre/modules/addons/XPIProvider.sys.mjs:2610
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Crash dump filename: /tmp/tmpr9ugnmus.mozrunner/minidumps/061eb445-5f87-6d04-b075-2540b2e7353a.dmp
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Operating system: Linux
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - 4.4.0-1014-aws #14taskcluster1-Ubuntu SMP Tue Apr 3 10:27:00 UTC 2018
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - CPU: amd64
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - family 6 model 85 stepping 7
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - 4 CPUs
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Linux Ubuntu 18.04 - bionic (Ubuntu 18.04.6 LTS)
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO -
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Crash reason: SIGSEGV / SEGV_MAPERR
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Crash address: 0x0000000000000000
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Crashing instruction: `mov dword [0x0], 0x202`
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Memory accessed by instruction:
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - 0. Address: 0x0000000000000000
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Size: 4
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Process uptime: not available
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO -
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Thread 0 firefox-bin (crashed)
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - 0 libxul.so!MOZ_Crash [Assertions.h:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 317]
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.172Z] 22:40:54 INFO - 1 libxul.so!Abort [nsDebugImpl.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 514]
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - 2 libxul.so!NS_DebugBreak [nsDebugImpl.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 471 + 0x24]
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rax = 0x0000562236435220 rdx = 0x00007f8251fc9180
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rcx = 0x00007f82659199a0 rbx = 0x00007ffdf5965830
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000000
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rbp = 0x00007f824f4037f6 rsp = 0x00007ffdf5965430
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r8 = 0x0000000000000000 r9 = 0x00000000029dc749
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r10 = 0xa5577c147704832d r11 = 0x00000000001b5859
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r12 = 0x0000000000000000 r13 = 0x00007f826122cb68
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r14 = 0x00007ffdf59654b8 r15 = 0x00007ffdf5965520
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rip = 0x00007f825456f52f
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - Found by: given as instruction pointer in context
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - 3 libxul.so!nsDebugImpl::Abort(char const*, int) + 0x1b
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rbx = 0x00007f824f7b3d10 rbp = 0x00007ffdf5965ba0
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rsp = 0x00007ffdf5965b70 r12 = 0x00007f8246a2c3c0
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r13 = 0x0000000000000009 r14 = 0x0000000000000002
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r15 = 0x0000000000000000 rip = 0x00007f825456f61c
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - 4 libxul.so!NS_InvokeByIndex + 0x8d
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rbx = 0x00007f824f7b3d10 rbp = 0x00007ffdf5965ba0
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - rsp = 0x00007ffdf5965b80 r12 = 0x00007f8246a2c3c0
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r13 = 0x0000000000000009 r14 = 0x0000000000000002
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - r15 = 0x0000000000000000 rip = 0x00007f8254773a92
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - 5 libxul.so!Invoke [XPCWrappedNative.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 1620]
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - 6 libxul.so!Call [XPCWrappedNative.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 1174]
[task 2024-10-26T22:40:54.173Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 7 libxul.so!XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [XPCWrappedNative.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 1120 + 0x1e93]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rbx = 0x00007f824f7b3d10 rbp = 0x00007f826432b0e0
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rsp = 0x00007ffdf5965bb0 r12 = 0x0000000000000002
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r13 = 0x00007f824f7b3c20 r14 = 0x0000000000000002
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r15 = 0x0000000000000000 rip = 0x00007f8255779cef
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 8 libxul.so!XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [XPCWrappedNativeJSOps.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 966 + 0x7]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rbx = 0x00007f8221abad18 rbp = 0x0000378ddab9ff10
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rsp = 0x00007ffdf5965de0 r12 = 0x00007f82616325f0
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r13 = 0x0000378ddab9ff10 r14 = 0x00007ffdf5965e18
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r15 = 0x00007ffdf5965df8 rip = 0x00007f825577ccdb
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 9 libxul.so!CallJSNative [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 528]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 10 libxul.so!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 624 + 0x18c]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffdf5965fc0
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rsp = 0x00007ffdf5965f00 r12 = 0x0000007e64030150
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r13 = 0x00007f8246f13400 r14 = 0x00007ffdf59662f0
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r15 = 0x00007f8246f35100 rip = 0x00007f825cfa7817
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 11 libxul.so!InternalCall [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 691]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 12 libxul.so!CallFromStack [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 696]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - 13 libxul.so!js::Interpret(JSContext*, js::RunState&) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 3326 + 0x6]
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rbx = 0x000000000009ad52 rbp = 0x00007f822174d378
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - rsp = 0x00007ffdf5965fd0 r12 = 0x0000000000000077
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r13 = 0x00007f826338d3a0 r14 = 0x0000000000000001
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - r15 = 0xfff9800000000000 rip = 0x00007f825cfc203d
[task 2024-10-26T22:40:54.174Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 14 libxul.so!MaybeEnterInterpreterTrampoline [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 433]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 15 libxul.so!js::RunScript(JSContext*, js::RunState&) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 498 + 0x261]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007f8246f35100 rbp = 0x00007ffdf5966420
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966370 r12 = 0x0000000000000001
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00007ffdf59664a8 r14 = 0x00007ffdf5966490
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x0000000000000000 rip = 0x00007f825cfa680f
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 16 libxul.so!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 656 + 0xc]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffdf59664f0
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966430 r12 = 0x00007f8246f13400
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00000000000aac0f r14 = 0x00007ffdf5966690
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007f8246f35100 rip = 0x00007f825cfa7bca
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 17 libxul.so!InternalCall [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 691]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 18 libxul.so!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 723 + 0xb]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007ffdf5966640 rbp = 0x0000000000000000
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966500 r12 = 0x00007f82520f38e0
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00007f8246f35100 r14 = 0x00007ffdf5966690
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007ffdf5966640 rip = 0x00007f825cfa9049
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 19 libxul.so!Call [Interpreter.h:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 120]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 20 libxul.so!PromiseReactionJob(JSContext*, unsigned int, JS::Value*) [Promise.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 2256 + 0xc4]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007ffdf5966640 rbp = 0x00007ffdf5966690
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966580 r12 = 0x00007f82520f38e0
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00007f8246f35100 r14 = 0x00007ffdf5966628
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007ffdf5966670 rip = 0x00007f825d33f40e
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 21 libxul.so!CallJSNative [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 528]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 22 libxul.so!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 624 + 0x18c]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x0000000000000000 rbp = 0x00007ffdf59667d0
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966710 r12 = 0x00003df0c8101ea0
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00007f8246f13400 r14 = 0x00007ffdf5966870
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007f8246f35100 rip = 0x00007f825cfa7817
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 23 libxul.so!InternalCall [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 691]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 24 libxul.so!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 723 + 0xb]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007ffdf5966970 rbp = 0x0000000000000000
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf59667e0 r12 = 0x00007ffdf5966880
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x0000000000000000 r14 = 0x00007ffdf5966870
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007ffdf5966970 rip = 0x00007f825cfa9049
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 25 libxul.so!JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [CallAndConstruct.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 119 + 0x22]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007ffdf5966970 rbp = 0x00007ffdf5966b90
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966860 r12 = 0x00007ffdf5966880
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x0000000000000000 r14 = 0x00007f8246f35100
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007ffdf5966930 rip = 0x00007f825d0e781b
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 26 libxul.so!mozilla::dom::PromiseJobCallback::Call(mozilla::dom::BindingCallContext&, JS::Handle<JS::Value>, mozilla::ErrorResult&) [PromiseBinding.cpp: : 83 + 0xa]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007ffdf5966b38 rbp = 0x00007ffdf5966b90
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf5966930 r12 = 0x00007ffdf5966970
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00007f8221898600 r14 = 0x00007ffdf5966b90
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x00007f82520f38e0 rip = 0x00007f825761de23
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 27 libxul.so!mozilla::dom::PromiseJobCallback::Call(mozilla::ErrorResult&, char const*, mozilla::dom::CallbackObject::ExceptionHandling, JS::Realm*) [PromiseBinding.h: : 198 + 0x11]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007ffdf5966b90 rbp = 0x00007ffdf5966b90
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rsp = 0x00007ffdf59669b0 r12 = 0x0000000000000000
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r13 = 0x00007ffdf5966b88 r14 = 0x00007f8221898600
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - r15 = 0x0000000000000000 rip = 0x00007f82545a838d
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 28 libxul.so!Call [PromiseBinding.h: : 211]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - 29 libxul.so!mozilla::PromiseJobRunnable::Run(mozilla::AutoSlowOperation&) [CycleCollectedJSContext.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 209 + 0x2e]
[task 2024-10-26T22:40:54.175Z] 22:40:54 INFO - rbx = 0x00007f822192b340 rbp = 0x00007ffdf5966b90
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rsp = 0x00007ffdf5966b80 r12 = 0x0000000000000000
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r13 = 0x00007ffdf5966b88 r14 = 0x00007ffdf5966c0c
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r15 = 0x0000000000000000 rip = 0x00007f82545a7dba
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - 30 libxul.so!mozilla::CycleCollectedJSContext::PerformMicroTaskCheckPoint(bool) [CycleCollectedJSContext.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 714 + 0x7]
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rbx = 0x00007f8246a2e000 rbp = 0x00007ffdf5966c0c
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rsp = 0x00007ffdf5966be0 r12 = 0x00007ffdf5966c10
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r13 = 0x00007f822253e610 r14 = 0x00007ffdf5966c0b
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r15 = 0x0000000000000001 rip = 0x00007f8254592091
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - 31 libxul.so!mozilla::CycleCollectedJSContext::AfterProcessTask(unsigned int) + 0x11
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rbx = 0x00007f8246a2e000 rbp = 0x0000000000000002
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rsp = 0x00007ffdf5966c90 r12 = 0x00007f824ebd13a0
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r13 = 0x00007f824d66f108 r14 = 0x00007ffdf5966e80
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r15 = 0x00007f8246a2e000 rip = 0x00007f8254592ea2
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - 32 libxul.so!XPCJSContext::AfterProcessTask(unsigned int) [XPCJSContext.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 1466 + 0x9]
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rbx = 0x00007f8246a2e000 rbp = 0x0000000000000002
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rsp = 0x00007ffdf5966ca0 r12 = 0x00007f824ebd13a0
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r13 = 0x00007f824d66f108 r14 = 0x00007ffdf5966e80
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r15 = 0x00007f8246a2e000 rip = 0x00007f825571665e
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - 33 libxul.so!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 1193 + 0x12]
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rbx = 0x00007f8272d70980 rbp = 0x0000000000000000
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - rsp = 0x00007ffdf5966d60 r12 = 0x00007f824ebd13a0
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r13 = 0x00007f824d66f108 r14 = 0x00007ffdf5966e80
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - r15 = 0x00007f8246a2e000 rip = 0x00007f82547351c5
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: call frame info
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - 34 libxul.so!NS_ProcessNextEvent [nsThreadUtils.cpp:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 480]
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: inlining
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - 35 libxul.so!SpinEventLoopUntil<(mozilla::ProcessFailureBehavior)1, (lambda at /builds/worker/checkouts/gecko/xpcom/threads/nsThreadManager.cpp:699:61)> [SpinEventLoopUntil.h:64b8710ad5862d5b9830283b09fc8eb0d0ced10c : 176]
[task 2024-10-26T22:40:54.176Z] 22:40:54 INFO - Found by: inlining
<...>
[task 2024-10-26T22:40:54.185Z] 22:40:54 INFO - 116 firefox-bin!_start + 0x28
[task 2024-10-26T22:40:54.185Z] 22:40:54 INFO - rsp = 0x00007ffdf596b390 rip = 0x00005622363279d9
[task 2024-10-26T22:40:54.185Z] 22:40:54 INFO - Found by: stack scanning
[task 2024-10-26T22:40:54.185Z] 22:40:54 INFO -
[task 2024-10-26T22:40:54.185Z] 22:40:54 INFO - Thread 1 gmain
| Comment hidden (Intermittent Failures Robot) |
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 3•1 year ago
|
||
This timeout is caused by a shutdown hang:
https://treeherder.mozilla.org/logviewer?job_id=479932862&repo=mozilla-central&lineNumber=50444
[task 2024-10-26T22:31:28.852Z] 22:31:28 INFO - GECKO(8108) | [GFX1-]: RenderCompositorSWGL failed mapping default framebuffer, no dt
[task 2024-10-26T22:31:38.722Z] 22:31:38 INFO - GECKO(8108) | WARNING: At least one completion condition is taking too long to complete. Conditions: [{"name":"XPIProvider shutdown","state":"(none)","filename":"resource://gre/modules/addons/XPIProvider.sys.mjs","lineNumber":2610,"stack":["resource://gre/modules/addons/XPIProvider.sys.mjs:startup:2610","resource://gre/modules/AddonManager.sys.mjs:callProvider:226","resource://gre/modules/AddonManager.sys.mjs:_startProvider:535","resource://gre/modules/AddonManager.sys.mjs:startup:745","resource://gre/modules/AddonManager.sys.mjs:startup:3650","resource://gre/modules/amManager.sys.mjs:observe:73"]}] Barrier: quit-application-granted
[task 2024-10-26T22:34:29.723Z] 22:34:29 INFO - GECKO(8108) | FATAL ERROR: AsyncShutdown timeout in quit-application-granted Conditions: [{"name":"XPIProvider shutdown","state":"(none)","filename":"resource://gre/modules/addons/XPIProvider.sys.mjs","lineNumber":2610,"stack":["resource://gre/modules/addons/XPIProvider.sys.mjs:startup:2610","resource://gre/modules/AddonManager.sys.mjs:callProvider:226","resource://gre/modules/AddonManager.sys.mjs:_startProvider:535","resource://gre/modules/AddonManager.sys.mjs:startup:745","resource://gre/modules/AddonManager.sys.mjs:startup:3650","resource://gre/modules/amManager.sys.mjs:observe:73"]}] At least one completion condition failed to complete within a reasonable amount of time. Causing a crash to ensure that we do not leave the user with an unresponsive process draining resources.
[task 2024-10-26T22:34:29.723Z] 22:34:29 INFO - GECKO(8108) | [Parent 8108, Main Thread] ###!!! ABORT: file resource://gre/modules/addons/XPIProvider.sys.mjs:2610
[task 2024-10-26T22:34:29.724Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::GenerateDump attempting to generate:</tmp/tmpr9ugnmus.mozrunner/minidumps/061eb445-5f87-6d04-b075-2540b2e7353a.dmp
[task 2024-10-26T22:34:29.727Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::WaitForContinueSignal waiting for continue signal...
[task 2024-10-26T22:34:29.727Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::GenerateDump cloned child 8266
[task 2024-10-26T22:34:29.728Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::SendContinueSignalToChild sent continue signal to child
[task 2024-10-26T22:34:29.822Z] 22:34:29 INFO - GECKO(8108) | ExceptionHandler::GenerateDump minidump generation <succeeded
[task 2024-10-26T22:40:39.819Z] 22:40:39 INFO - TEST-UNEXPECTED-TIMEOUT | remote/shared/listeners/test/browser/browser_BrowsingContextListener.js | application timed out after 370 seconds with no output
Component: Agent → Add-ons Manager
Product: Remote Protocol → Toolkit
Summary: Intermittent remote/shared/listeners/test/browser/browser_BrowsingContextListener.js | single tracking bug → AsyncShutdown timeout in quit-application-granted Conditions: [{"name":"XPIProvider shutdown","state":"(none)","filename":"resource://gre/modules/addons/XPIProvider.sys.mjs"
|
|
||
Updated•1 year ago
|
Severity: S4 → --
Priority: P5 → --
|
||
Comment 4•1 year ago
|
||
Setting to p5/s4 as this is a code coverage build, which can be slow to get through async blockers before the timeout. If it shows up in another kind of build, we'll bump it up.
Severity: -- → S4
Priority: -- → P5
| Comment hidden (Intermittent Failures Robot) |
|
||
Comment 6•1 year ago
|
||
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit BugBot documentation.
Status: NEW → RESOLVED
Closed: 1 year ago
Resolution: --- → INCOMPLETE
| Comment hidden (Intermittent Failures Robot) |
You need to log in
before you can comment on or make changes to this bug.
Description
•