1676088 - AsyncShutdownTimeout in AboutHomeStartupCache Getting cache streams

Status: RESOLVED DUPLICATE of bug 1673716

(Firefox :: New Tab Page, defect)

Description

[Treeherder Bug Filer]

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

---

[task 2020-11-09T04:47:04.442Z] 04:47:04     INFO -  raptor-perftest Info: starting test: raptor-tp6-ebay-firefox-cold
[task 2020-11-09T04:47:04.442Z] 04:47:04     INFO -  raptor-webext Info: starting web extension test: raptor-tp6-ebay-firefox-cold
[task 2020-11-09T04:47:04.442Z] 04:47:04     INFO -  raptor-webext Info: test settings: {'expected_browser_cycles': 25, u'alert_threshold': u'2.0', u'playback_pageset_manifest': u'mitm5-linux-firefox-ebay.manifest', u'browser_cycles': u'25', 'here': u'C:\\Users\\task_1604895292\\build\\tests\\raptor\\raptor\\tests\\tp6\\desktop', u'measure': [u'fnbpaint', u'fcp', u'dcf', u'loadtime'], 'path': u'C:\\Users\\task_1604895292\\build\\tests\\raptor\\raptor\\tests\\tp6\\desktop\\raptor-tp6-ebay-firefox', 'manifest_relpath': u'tests\\tp6\\desktop\\ebay.ini', 'cold': True, u'unit': u'ms', u'alert_on': [u'fcp', u'loadtime'], u'type': u'pageload', 'name': u'raptor-tp6-ebay-firefox-cold', u'playback_recordings': u'mitm5-linux-firefox-ebay.mp', u'page_cycles': 1, u'apps': u'firefox', u'test_url': u'https://www.ebay.com/', 'manifest': u'C:\\Users\\task_1604895292\\build\\tests\\raptor\\raptor\\tests\\tp6\\desktop\\ebay.ini', 'ancestor_manifest': u'tests\\tp6\\desktop-tests.ini', u'page_timeout': u'60000', u'playback_version': u'5.1.1', u'playback': u'mitmproxy', 'browser_cycle': 2, 'expected': 'pass', u'lower_is_better': True, 'relpath': u'tests\\tp6\\desktop\\raptor-tp6-ebay-firefox'}
[task 2020-11-09T04:47:04.443Z] 04:47:04     INFO -  raptor-webext Info: web extension config: {'subtest_alert_on': [u'fcp', u'loadtime'], 'verbose': False, 'e10s': True, 'app': 'firefox', 'symbols_path': 'https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/dHt-tLHcQyuByoZcZW37tQ/artifacts/public/build/target.crashreporter-symbols.zip', 'power_test': False, 'run_local': False, 'playback_files': [u'C:\\Users\\task_1604895292\\build\\tests\\raptor\\raptor\\tooltool-manifests\\playback\\mitm5-linux-firefox-ebay.manifest'], 'chimera': False, 'cold': True, 'gecko_profile_interval': None, 'binary': 'C:\\Users\\task_1604895292\\build\\application\\firefox\\firefox.exe', 'local_profile_dir': 'c:\\users\\task_1604895292\\appdata\\local\\temp\\tmpdpj4px\\profile', 'enable_control_server_wait': False, 'no_conditioned_profile': False, 'environment': {}, 'platform': 'win', 'playback_version': u'5.1.1', 'conditioned_profile_scenario': 'settled', 'extra_prefs': {'extensions.logging.enabled': True}, 'gecko_profile': False, 'gecko_profile_entries': None, 'disable_perf_tuning': False, 'playback_tool': u'mitmproxy', 'host': '127.0.0.1', 'enable_fission': False, 'memory_test': False, 'enable_webrender': False, 'obj_path': None, 'live_sites': False, 'device_name': None, 'project': 'mozilla-central', 'cpu_test': False, 'is_release_build': False, 'using_condprof': True, 'processor': 'x86_64'}
[task 2020-11-09T04:47:04.443Z] 04:47:04     INFO -  raptor-gen-test-config Info: writing test settings into background js, so webext can get it
[task 2020-11-09T04:47:04.443Z] 04:47:04     INFO -  raptor-gen-test-config Info: finished writing test config to C:\Users\task_1604895292\build\tests\raptor\webext\raptor\auto_gen_test_config.js
[task 2020-11-09T04:47:04.443Z] 04:47:04     INFO -  raptor-webext Info: installing webext C:\Users\task_1604895292\build\tests\raptor\raptor\webextension\..\..\webext\raptor
[task 2020-11-09T04:47:04.453Z] 04:47:04     INFO -  raptor-webext-desktop Info: starting firefox
[task 2020-11-09T04:47:04.453Z] 04:47:04     INFO -  Application command: C:\Users\task_1604895292\build\application\firefox\firefox.exe --allow-downgrade --wait-for-browser -profile c:\users\task_1604895292\appdata\local\temp\tmpdpj4px\profile
[task 2020-11-09T04:47:10.792Z] 04:47:10     INFO -  raptor-control-server Info: received webext_loaded: raptor runner.js is loaded!
[task 2020-11-09T04:47:10.850Z] 04:47:10     INFO -  raptor-control-server Info: received webext_status: testing on Firefox 84.0a1 20201108212832
[task 2020-11-09T04:47:10.889Z] 04:47:10     INFO -  raptor-control-server Info: received webext_status: test name is: raptor-tp6-ebay-firefox-cold
[task 2020-11-09T04:47:10.908Z] 04:47:10     INFO -  raptor-control-server Info: received webext_status: test settings url is: http://127.0.0.1:49826/json/raptor-tp6-ebay-firefox-cold.json
[task 2020-11-09T04:47:10.918Z] 04:47:10     INFO -  raptor-control-server Info: received webext_status: starting raptorRunner
[task 2020-11-09T04:47:10.918Z] 04:47:10     INFO -  PID 7820 | console.info: "[raptor-runnerjs] getting test settings from control server"
[task 2020-11-09T04:47:10.968Z] 04:47:10     INFO -  raptor-control-server Info: reading test settings from json/raptor-tp6-ebay-firefox-cold.json
[task 2020-11-09T04:47:10.968Z] 04:47:10     INFO -  raptor-control-server Info: sent test settings to webext runner
[task 2020-11-09T04:47:10.970Z] 04:47:10     INFO -  PID 7820 | console.info: "[raptor-runnerjs] test settings received: {\"raptor-options\": {\"expected_browser_cycles\": 25, \"subtest_unit\": \"ms\", \"alert_threshold\": 2.0, \"type\": \"pageload\", \"page_cycles\": 1, \"subtest_lower_is_better\": true, \"alert_on\": [\"fcp\", \"loadtime\"], \"test_url\": \"https://www.ebay.com/\", \"page_timeout\": 60000, \"host\": \"127.0.0.1\", \"measure\": {\"fcp\": true, \"dcf\": true, \"fnbpaint\": true, \"loadtime\": true}, \"cold\": true, \"lower_is_better\": true, \"unit\": \"ms\"}}"
[task 2020-11-09T04:47:10.970Z] 04:47:10     INFO -  PID 7820 | console.info: "[raptor-runnerjs] test URL: https://www.ebay.com/"
[task 2020-11-09T04:47:10.970Z] 04:47:10     INFO -  PID 7820 | console.info: "[raptor-runnerjs] using page timeout: 60000ms"
[task 2020-11-09T04:47:15.729Z] 04:47:15     INFO -  raptor-control-server Info: received webext_status: * pausing 1 seconds to let browser settle... *
[task 2020-11-09T04:47:15.729Z] 04:47:15     INFO -  PID 7820 | console.info: "[raptor-runnerjs] wrote settings to ext local storage"
[task 2020-11-09T04:47:15.730Z] 04:47:15     INFO -  PID 7820 | console.info: "[raptor-runnerjs] pageload test start"
[task 2020-11-09T04:47:16.738Z] 04:47:16     INFO -  raptor-control-server Info: received webext_status: opening new tab
[task 2020-11-09T04:47:16.797Z] 04:47:16     INFO -  raptor-control-server Info: received webext_status: opened new empty tab: 2
[task 2020-11-09T04:47:16.822Z] 04:47:16     INFO -  raptor-control-server Info: received webext_status: found active tab with id 2
[task 2020-11-09T04:47:16.827Z] 04:47:16     INFO -  raptor-control-server Info: received webext_status: running 1 pagecycles of https://www.ebay.com/
[task 2020-11-09T04:47:17.833Z] 04:47:17     INFO -  raptor-control-server Info: received webext_status: begin page cycle 1
[task 2020-11-09T04:47:17.838Z] 04:47:17     INFO -  raptor-control-server Info: received webext_status: update tab 2 for https://www.ebay.com/
[task 2020-11-09T04:47:17.865Z] 04:47:17     INFO -  raptor-control-server Info: received webext_status: tab 2 updated
[task 2020-11-09T04:47:17.884Z] 04:47:17     INFO -  raptor-control-server Info: received webext_status: ended page cycle 1
[task 2020-11-09T04:49:21.041Z] 04:49:21     INFO -  mozcrash Downloading symbols from: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/dHt-tLHcQyuByoZcZW37tQ/artifacts/public/build/target.crashreporter-symbols.zip
[task 2020-11-09T04:49:24.081Z] 04:49:24     INFO -  mozcrash Copy/paste: C:/Users/task_1604895292/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1604895292\appdata\local\temp\tmpdpj4px\profile\minidumps\50f244ad-cefc-4759-bceb-0ce3e9804dff.dmp c:\users\task_1604895292\appdata\local\temp\tmp4dqbzi
[task 2020-11-09T04:49:33.474Z] 04:49:33     INFO -  mozcrash Saved minidump as C:\Users\task_1604895292\build\blobber_upload_dir\50f244ad-cefc-4759-bceb-0ce3e9804dff.dmp
[task 2020-11-09T04:49:33.475Z] 04:49:33     INFO -  mozcrash Saved app info as C:\Users\task_1604895292\build\blobber_upload_dir\50f244ad-cefc-4759-bceb-0ce3e9804dff.extra
[task 2020-11-09T04:49:33.475Z] 04:49:33    ERROR -  PROCESS-CRASH | runner.py | application crashed [@ NS_DebugBreak(unsigned int, char const*, char const*, char const*, int)]
[task 2020-11-09T04:49:33.476Z] 04:49:33     INFO -  Mozilla crash reason: MOZ_CRASH()
[task 2020-11-09T04:49:33.476Z] 04:49:33     INFO -  Crash dump filename: c:\users\task_1604895292\appdata\local\temp\tmpdpj4px\profile\minidumps\50f244ad-cefc-4759-bceb-0ce3e9804dff.dmp
[task 2020-11-09T04:49:33.477Z] 04:49:33     INFO -  Operating system: Windows NT
[task 2020-11-09T04:49:33.477Z] 04:49:33     INFO -                    10.0.17134
[task 2020-11-09T04:49:33.478Z] 04:49:33     INFO -  CPU: amd64
[task 2020-11-09T04:49:33.478Z] 04:49:33     INFO -       family 6 model 142 stepping 9
[task 2020-11-09T04:49:33.478Z] 04:49:33     INFO -       4 CPUs
[task 2020-11-09T04:49:33.479Z] 04:49:33     INFO -  GPU: UNKNOWN
[task 2020-11-09T04:49:33.479Z] 04:49:33     INFO -  Crash reason:  EXCEPTION_BREAKPOINT
[task 2020-11-09T04:49:33.480Z] 04:49:33     INFO -  Crash address: 0x3c30c5f5
[task 2020-11-09T04:49:33.480Z] 04:49:33     INFO -  Process uptime: 85 seconds
[task 2020-11-09T04:49:33.481Z] 04:49:33     INFO -  Thread 0 (crashed)
[task 2020-11-09T04:49:33.481Z] 04:49:33     INFO -   0  mozglue.dll!mozalloc_abort(char const* const) [mozalloc_abort.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 33 + 0x0]
[task 2020-11-09T04:49:33.482Z] 04:49:33     INFO -      rax = 0x00007ffd3c37a97a   rdx = 0x00007ffd5f879650
[task 2020-11-09T04:49:33.483Z] 04:49:33     INFO -      rcx = 0x00000000ffffffff   rbx = 0x0000000000000003
[task 2020-11-09T04:49:33.483Z] 04:49:33     INFO -      rsi = 0x000000fe2aff9ca0   rdi = 0x00007ffd5f7a9860
[task 2020-11-09T04:49:33.483Z] 04:49:33     INFO -      rbp = 0x0000000000000003   rsp = 0x000000fe2aff9c00
[task 2020-11-09T04:49:33.484Z] 04:49:33     INFO -       r8 = 0x000000fe2aff8468    r9 = 0x00007ffd2b6b0de0
[task 2020-11-09T04:49:33.484Z] 04:49:33     INFO -      r10 = 0x0000000000000000   r11 = 0x000000fe2aff9ae0
[task 2020-11-09T04:49:33.484Z] 04:49:33     INFO -      r12 = 0x0000000000000000   r13 = 0x0000000000000000
[task 2020-11-09T04:49:33.485Z] 04:49:33     INFO -      r14 = 0x0000000000000000   r15 = 0x000000fe2aff9fb0
[task 2020-11-09T04:49:33.485Z] 04:49:33     INFO -      rip = 0x00007ffd3c30c5f5
[task 2020-11-09T04:49:33.485Z] 04:49:33     INFO -      Found by: given as instruction pointer in context
[task 2020-11-09T04:49:33.485Z] 04:49:33     INFO -   1  xul.dll!NS_DebugBreak(unsigned int, char const*, char const*, char const*, int) [nsDebugImpl.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 435 + 0x31]
[task 2020-11-09T04:49:33.486Z] 04:49:33     INFO -      rbx = 0x0000000000000003   rbp = 0x0000000000000003
[task 2020-11-09T04:49:33.486Z] 04:49:33     INFO -      rsp = 0x000000fe2aff9c40   r12 = 0x0000000000000000
[task 2020-11-09T04:49:33.486Z] 04:49:33     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000000
[task 2020-11-09T04:49:33.486Z] 04:49:33     INFO -      r15 = 0x000000fe2aff9fb0   rip = 0x00007ffd26af0589
[task 2020-11-09T04:49:33.487Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.487Z] 04:49:33     INFO -   2  xul.dll!nsDebugImpl::Abort(char const*, int) [nsDebugImpl.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 134 + 0x14]
[task 2020-11-09T04:49:33.487Z] 04:49:33     INFO -      rbx = 0x0000000000000003   rbp = 0x0000000000000003
[task 2020-11-09T04:49:33.488Z] 04:49:33     INFO -      rsp = 0x000000fe2affa300   r12 = 0x0000000000000000
[task 2020-11-09T04:49:33.488Z] 04:49:33     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000000
[task 2020-11-09T04:49:33.488Z] 04:49:33     INFO -      r15 = 0x000000fe2aff9fb0   rip = 0x00007ffd26af061b
[task 2020-11-09T04:49:33.489Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.489Z] 04:49:33     INFO -   3  xul.dll!XPTC__InvokebyIndex + 0x72
[task 2020-11-09T04:49:33.489Z] 04:49:33     INFO -      rbx = 0x0000000000000003   rbp = 0x0000000000000003
[task 2020-11-09T04:49:33.489Z] 04:49:33     INFO -      rsp = 0x000000fe2affa330   r12 = 0x0000000000000000
[task 2020-11-09T04:49:33.490Z] 04:49:33     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000000
[task 2020-11-09T04:49:33.490Z] 04:49:33     INFO -      r15 = 0x000000fe2aff9fb0   rip = 0x00007ffd2b60cf02
[task 2020-11-09T04:49:33.490Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.491Z] 04:49:33     INFO -   4  0x247611adbe0
[task 2020-11-09T04:49:33.491Z] 04:49:33     INFO -      rbx = 0x0000000000000003   rbp = 0x0000000000000003
[task 2020-11-09T04:49:33.491Z] 04:49:33     INFO -      rsp = 0x000000fe2affa340   r12 = 0x0000000000000000
[task 2020-11-09T04:49:33.492Z] 04:49:33     INFO -      r13 = 0x0000000000000000   r14 = 0x0000000000000000
[task 2020-11-09T04:49:33.492Z] 04:49:33     INFO -      r15 = 0x000000fe2aff9fb0   rip = 0x00000247611adbe0
[task 2020-11-09T04:49:33.492Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.493Z] 04:49:33     INFO -   5  xul.dll!trunc + 0x5b258
[task 2020-11-09T04:49:33.493Z] 04:49:33     INFO -      rsp = 0x000000fe2affa350   rip = 0x00007ffd2b66e0c8
[task 2020-11-09T04:49:33.493Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.493Z] 04:49:33     INFO -   6  xul.dll!trunc + 0x54aa0
[task 2020-11-09T04:49:33.494Z] 04:49:33     INFO -      rsp = 0x000000fe2affa360   rip = 0x00007ffd2b667910
[task 2020-11-09T04:49:33.494Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.494Z] 04:49:33     INFO -   7  xul.dll!static XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [XPCWrappedNative.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 1142 + 0x4b3]
[task 2020-11-09T04:49:33.495Z] 04:49:33     INFO -      rsp = 0x000000fe2affa380   rip = 0x00007ffd273d0cf6
[task 2020-11-09T04:49:33.495Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.495Z] 04:49:33     INFO -   8  xul.dll!XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [XPCWrappedNativeJSOps.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 925 + 0xa]
[task 2020-11-09T04:49:33.495Z] 04:49:33     INFO -      rsp = 0x000000fe2affa5c0   rip = 0x00007ffd273d2934
[task 2020-11-09T04:49:33.496Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.496Z] 04:49:33     INFO -   9  xul.dll!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 599 + 0x1b8]
[task 2020-11-09T04:49:33.496Z] 04:49:33     INFO -      rsp = 0x000000fe2affa720   rip = 0x00007ffd261ddf68
[task 2020-11-09T04:49:33.497Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.497Z] 04:49:33     INFO -  10  xul.dll!Interpret(JSContext*, js::RunState&) [Interpreter.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 3337 + 0xba]
[task 2020-11-09T04:49:33.497Z] 04:49:33     INFO -      rsp = 0x000000fe2affa840   rip = 0x00007ffd2a0fd056
[task 2020-11-09T04:49:33.498Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.498Z] 04:49:33     INFO -  11  xul.dll!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 636 + 0x5f]
[task 2020-11-09T04:49:33.498Z] 04:49:33     INFO -      rsp = 0x000000fe2affae00   rip = 0x00007ffd261de5e8
[task 2020-11-09T04:49:33.499Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.499Z] 04:49:33     INFO -  12  xul.dll!js::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, js::AnyInvokeArgs const&, JS::MutableHandle<JS::Value>, js::CallReason) [Interpreter.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 681 + 0x86]
[task 2020-11-09T04:49:33.499Z] 04:49:33     INFO -      rsp = 0x000000fe2affaf20   rip = 0x00007ffd2632ff06
[task 2020-11-09T04:49:33.499Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.500Z] 04:49:33     INFO -  13  xul.dll!PromiseReactionJob(JSContext*, unsigned int, JS::Value*) [Promise.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 1904 + 0x7f]
[task 2020-11-09T04:49:33.500Z] 04:49:33     INFO -      rsp = 0x000000fe2affaf70   rip = 0x00007ffd2a1e6858
[task 2020-11-09T04:49:33.500Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.501Z] 04:49:33     INFO -  14  xul.dll!js::InternalCallOrConstruct(JSContext*, JS::CallArgs const&, js::MaybeConstruct, js::CallReason) [Interpreter.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 599 + 0x1b8]
[task 2020-11-09T04:49:33.501Z] 04:49:33     INFO -      rsp = 0x000000fe2affb0f0   rip = 0x00007ffd261ddf68
[task 2020-11-09T04:49:33.501Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.502Z] 04:49:33     INFO -  15  xul.dll!JS::Call(JSContext*, JS::Handle<JS::Value>, JS::Handle<JS::Value>, JS::HandleValueArray const&, JS::MutableHandle<JS::Value>) [jsapi.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 2830 + 0xab]
[task 2020-11-09T04:49:33.502Z] 04:49:33     INFO -      rsp = 0x000000fe2affb210   rip = 0x00007ffd263a7bf1
[task 2020-11-09T04:49:33.502Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.502Z] 04:49:33     INFO -  16  xul.dll!mozilla::dom::LifecycleConnectedCallback::Call(mozilla::dom::BindingCallContext&, JS::Handle<JS::Value>, mozilla::ErrorResult&) [WebComponentsBinding.cpp: : 251 + 0xd]
[task 2020-11-09T04:49:33.503Z] 04:49:33     INFO -      rsp = 0x000000fe2affb320   rip = 0x00007ffd27c64e9e
[task 2020-11-09T04:49:33.503Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.503Z] 04:49:33     INFO -  17  xul.dll!mozilla::PromiseJobRunnable::Run(mozilla::AutoSlowOperation&) [CycleCollectedJSContext.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 211 + 0x6d]
[task 2020-11-09T04:49:33.504Z] 04:49:33     INFO -      rsp = 0x000000fe2affb3d0   rip = 0x00007ffd26afbb39
[task 2020-11-09T04:49:33.504Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.504Z] 04:49:33     INFO -  18  xul.dll!mozilla::CycleCollectedJSContext::AfterProcessTask(unsigned int) [CycleCollectedJSContext.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 469 + 0x1f2]
[task 2020-11-09T04:49:33.504Z] 04:49:33     INFO -      rsp = 0x000000fe2affb650   rip = 0x00007ffd262b6256
[task 2020-11-09T04:49:33.505Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.505Z] 04:49:33     INFO -  19  xul.dll!XPCJSContext::AfterProcessTask(unsigned int) [XPCJSContext.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 1467 + 0xa]
[task 2020-11-09T04:49:33.505Z] 04:49:33     INFO -      rsp = 0x000000fe2affb710   rip = 0x00007ffd273ae62f
[task 2020-11-09T04:49:33.506Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.506Z] 04:49:33     INFO -  20  xul.dll!nsThread::ProcessNextEvent(bool, bool*) [nsThread.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 1233 + 0x12]
[task 2020-11-09T04:49:33.506Z] 04:49:33     INFO -      rsp = 0x000000fe2affb850   rip = 0x00007ffd2610bad6
[task 2020-11-09T04:49:33.507Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.507Z] 04:49:33     INFO -  21  xul.dll!XPTC__InvokebyIndex + 0x72
[task 2020-11-09T04:49:33.507Z] 04:49:33     INFO -      rsp = 0x000000fe2affba30   rip = 0x00007ffd2b60cf02
[task 2020-11-09T04:49:33.508Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.508Z] 04:49:33     INFO -  22  xul.dll!trunc + 0x55991
[task 2020-11-09T04:49:33.508Z] 04:49:33     INFO -      rsp = 0x000000fe2affba40   rip = 0x00007ffd2b668801
[task 2020-11-09T04:49:33.509Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.509Z] 04:49:33     INFO -  23  xul.dll!trunc + 0x5cb00
[task 2020-11-09T04:49:33.509Z] 04:49:33     INFO -      rsp = 0x000000fe2affba50   rip = 0x00007ffd2b66f970
[task 2020-11-09T04:49:33.509Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.510Z] 04:49:33     INFO -  24  xul.dll!trunc + 0x54aa0
[task 2020-11-09T04:49:33.510Z] 04:49:33     INFO -      rsp = 0x000000fe2affba60   rip = 0x00007ffd2b667910
[task 2020-11-09T04:49:33.510Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.511Z] 04:49:33     INFO -  25  xul.dll!static XPCWrappedNative::CallMethod(XPCCallContext&, XPCWrappedNative::CallMode) [XPCWrappedNative.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 1142 + 0x4b3]
[task 2020-11-09T04:49:33.511Z] 04:49:33     INFO -      rsp = 0x000000fe2affba80   rip = 0x00007ffd273d0cf6
[task 2020-11-09T04:49:33.511Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.512Z] 04:49:33     INFO -  26  xul.dll!XPC_WN_CallMethod(JSContext*, unsigned int, JS::Value*) [XPCWrappedNativeJSOps.cpp:0db6e7f710012caf761b337d61fdd4cb29cfb8e4 : 925 + 0xa]
[task 2020-11-09T04:49:33.512Z] 04:49:33     INFO -      rsp = 0x000000fe2affbcc0   rip = 0x00007ffd273d2934
[task 2020-11-09T04:49:33.512Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.512Z] 04:49:33     INFO -  27  0x149ebdea7da
[task 2020-11-09T04:49:33.513Z] 04:49:33     INFO -      rsp = 0x000000fe2affbe20   rip = 0x00000149ebdea7da
[task 2020-11-09T04:49:33.513Z] 04:49:33     INFO -      Found by: call frame info
[task 2020-11-09T04:49:33.513Z] 04:49:33     INFO -  28  xul.dll!trunc + 0x82fb50
[task 2020-11-09T04:49:33.514Z] 04:49:33     INFO -      rsp = 0x000000fe2affbe48   rip = 0x00007ffd2be429c0
[task 2020-11-09T04:49:33.514Z] 04:49:33     INFO -      Found by: stack scanning
[task 2020-11-09T04:49:33.514Z] 04:49:33     INFO -  Thread 1
[task 2020-11-09T04:49:33.514Z] 04:49:33     INFO -   0  ntdll.dll!NtRemoveIoCompletion + 0x14```

Comment 1

[Intermittent Failures Robot]

3 failures in 4040 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 3

Platform breakdown:

• windows10-64-ref-hw-2017: 3

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1676088&startday=2020-11-09&endday=2020-11-15&tree=all

Comment 2

[Intermittent Failures Robot]

8 failures in 4810 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 8

Platform breakdown:

• windows10-64-ref-hw-2017: 8

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1676088&startday=2020-11-16&endday=2020-11-22&tree=all

Comment 3

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 5

Platform breakdown:

• windows10-64-ref-hw-2017: 5

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1676088&startday=2020-11-23&endday=2020-11-29&tree=all

Comment 4

[Intermittent Failures Robot]

4 failures in 3712 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 4

Platform breakdown:

• windows10-64-ref-hw-2017: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1676088&startday=2020-11-30&endday=2020-12-06&tree=all

Comment 5

[Chris Peterson [:cpeterson]]

This is not an XPConnect bug. Moving to New Tab component because this is an AsyncShutdown hang in about:home:

"AsyncShutdownTimeout": "{"phase":"quit-application-granted","conditions":[{"name":"AboutHomeStartupCache: Writing cache","state":"Getting cache streams","filename":"resource:///modules/BrowserGlue.jsm","lineNumber":5213,"stack":["resource:///modules/BrowserGlue.jsm:init:5213","resource:///modules/BrowserGlue.jsm:BG__beforeUIStartup:1419","resource:///modules/BrowserGlue.jsm:BG_observe:1042"]}]}",

The pref to enable verbose loging is toolkit.asyncshutdown.log.

AsyncShutdown is calling gDebug.abort():

https://searchfox.org/mozilla-central/rev/23c25cd32a1e87095301273937b4ee162f41e860/toolkit/components/asyncshutdown/AsyncShutdown.jsm#1016-1027

Comment 6

[Gavin Suntop [:gvn] (they/them)]

Mike, is this something you are familiar with?

Comment 7

[Mike Conley (:mconley) (:⚙️)]

I am, yes. I expect this went away with bug 1673716.