Closed
Bug 1675274
Opened 4 years ago
Closed 1 year ago
Intermittent Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::Uncached, at /builds/worker/checkouts/gecko/dom/workers/ScriptLoader.cpp:1793
Categories
(Core :: DOM: Workers, defect, P3)
Core
DOM: Workers
Tracking
()
RESOLVED
WORKSFORME
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: assertion, intermittent-failure)
Crash Data
Filed by: smolnar [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=320695304&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Ecq8raeWTrGqkSXnffSfvw/runs/0/artifacts/public/logs/live_backing.log
"INFO - Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::Uncached, at /builds/worker/checkouts/gecko/dom/workers/ScriptLoader.cpp:1793
[task 2020-11-04T10:39:39.469Z] 10:39:39 INFO - #01: soundtouch::SoundTouch::operator=[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x419e8ab]
[task 2020-11-04T10:39:39.469Z] 10:39:39 INFO - #02: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x6337f00]
[task 2020-11-04T10:39:39.469Z] 10:39:39 INFO - #03: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x633766a]
[task 2020-11-04T10:39:39.469Z] 10:39:39 INFO - #04: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x63390dc]
[task 2020-11-04T10:39:39.470Z] 10:39:39 INFO - #05: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x63392f9]
[task 2020-11-04T10:39:39.470Z] 10:39:39 INFO - #06: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x63be30a]
[task 2020-11-04T10:39:39.470Z] 10:39:39 INFO - #07: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x6559e44]
[task 2020-11-04T10:39:39.470Z] 10:39:39 INFO - #08: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x6337f00]
[task 2020-11-04T10:39:39.470Z] 10:39:39 INFO - #09: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x633766a]
[task 2020-11-04T10:39:39.471Z] 10:39:39 INFO - #10: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x63390dc]
[task 2020-11-04T10:39:39.471Z] 10:39:39 INFO - #11: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x63392f9]
[task 2020-11-04T10:39:39.471Z] 10:39:39 INFO - #12: XRE_GetBootstrap[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x68dac68]
[task 2020-11-04T10:39:39.471Z] 10:39:39 INFO - #13: VR_RuntimePath[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x231b061]
[task 2020-11-04T10:39:39.471Z] 10:39:39 INFO - #14: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0xa818e]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #15: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0xa724b]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #16: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x94e06]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #17: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x95850]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #18: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x11ab6ed]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #19: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x1d0cae]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #20: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x1cffe5]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #21: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x3b0f28]
[task 2020-11-04T10:39:39.472Z] 10:39:39 INFO - #22: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x3b3b4f]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #23: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x10a556]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #24: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x11522b]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #25: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x21b25c]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #26: workerlz4_maxCompressedSize[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x61c391a]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #27: Ordinal0[C:\Users\task_1604483748\build\application\firefox\xul.dll +0xaa4be2]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #28: workerlz4_maxCompressedSize[C:\Users\task_1604483748\build\application\firefox\xul.dll +0x61c442a]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #29: Ordinal0[C:\Users\task_1604483748\build\application\firefox\firefox.exe +0x1676]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #30: Ordinal0[C:\Users\task_1604483748\build\application\firefox\firefox.exe +0x120e]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #31: TargetNtUnmapViewOfSection[C:\Users\task_1604483748\build\application\firefox\firefox.exe +0xa3f48]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #32: BaseThreadInitThunk[C:\windows\System32\KERNEL32.DLL +0x13034]
[task 2020-11-04T10:39:39.473Z] 10:39:39 INFO - #33: RtlUserThreadStart[C:\windows\SYSTEM32\ntdll.dll +0x71461]
[task 2020-11-04T10:39:39.498Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/cache/nsApplicationCacheService.cpp:150
[task 2020-11-04T10:39:39.498Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/cache2/AppCacheStorage.cpp:141
[task 2020-11-04T10:39:39.503Z] 10:39:39 INFO - DEBUG: Adding blocker protections.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-04T10:39:39.513Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-04T10:39:39.532Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-04T10:39:39.537Z] 10:39:39 INFO - [2020-11-04T10:39:39Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2020-11-04T10:39:39.537Z] 10:39:39 INFO - [2020-11-04T10:39:39Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2020-11-04T10:39:39.542Z] 10:39:39 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2020-11-04T10:39:39.542Z] 10:39:39 INFO - console.debug: SearchService: "init"
[task 2020-11-04T10:39:39.573Z] 10:39:39 INFO - DEBUG: Adding blocker TrackingDBService: Shutting down the content blocking database. for phase profile-before-change
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: QuotaManager failure: 'OkIf(outputStream)', file ActorsParent.cpp:2587
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: DEBUG: Completed blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdownQ
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - uotaManager failure: 'GetBinaryOutputStream(*file, kUpdateFileFlag)', file ActorsParent.cpp:8413
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:8277
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: 'NS_FAILED(rv)'DEBUG: Finished phase profile-change-teardown
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - , file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:8187
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - [Parent 5560, Unnamed thread 29d34737c00] WARNING: Resource acquired is being released in non-LIFO order; why?
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - : file /builds/worker/checkouts/gecko/xpcom/threads/BlockingResourceBase.cpp:292
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - --- Mutex : dumpSafetyLock (currently acquired)
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - calling context
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - [stack trace unavailable]
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.785Z] 10:39:39 INFO - DEBUG: Starting phase profile-before-change
[task 2020-11-04T10:39:39.804Z] 10:39:39 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:39.804Z] 10:39:39 INFO - DEBUG: Completed blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2020-11-04T10:39:39.804Z] 10:39:39 INFO - DEBUG: Completed blocker Places Expiration: shutdown for phase Places Connection shutdown
[task 2020-11-04T10:39:39.804Z] 10:39:39 INFO - DEBUG: Completed blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2020-11-04T10:39:39.805Z] 10:39:39 INFO - DEBUG: Completed blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2020-11-04T10:39:39.805Z] 10:39:39 INFO - DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2020-11-04T10:39:39.805Z] 10:39:39 INFO - DEBUG: Completed blocker Remote Settings profile-before-change for phase profile-before-change
[task 2020-11-04T10:39:39.805Z] 10:39:39 INFO - DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2020-11-04T10:39:39.806Z] 10:39:39 INFO - DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2020-11-04T10:39:39.806Z] 10:39:39 INFO - DEBUG: Completed blocker DownloadAutoSaveView: writing data for phase profile-before-change
[task 2020-11-04T10:39:39.806Z] 10:39:39 INFO - DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2020-11-04T10:39:39.806Z] 10:39:39 INFO - DEBUG: Completed blocker Search service: shutting down for phase OS.File: Waiting for clients before profileBeforeChange
[task 2020-11-04T10:39:39.806Z] 10:39:39 INFO - DEBUG: Completed blocker DoHController: clear state and remove observers for phase profile-before-change
[task 2020-11-04T10:39:39.806Z] 10:39:39 INFO - DEBUG: Completed blocker places.sqlite#1: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker PlacesUtils wrapped connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker PlacesUtils wrapped connection must be closed before Sqlite.jsm for phase Sqlite.jsm: wait until all clients have completed their task
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker JSON store: writing data for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker PluginProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker AddonManager: shutting down. for phase profile-before-change
[task 2020-11-04T10:39:39.807Z] 10:39:39 INFO - DEBUG: Completed blocker places.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-04T10:39:39.808Z] 10:39:39 INFO - DEBUG: Completed blocker PlacesUtils read-only connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2020-11-04T10:39:39.808Z] 10:39:39 INFO - DEBUG: Completed blocker PlacesUtils read-only connection must be closed before Sqlite.jsm for phase Sqlite.jsm: wait until all clients have completed their task
[task 2020-11-04T10:39:39.808Z] 10:39:39 INFO - DEBUG: Completed blocker CrashMonitor: Writing notifications to file after receiving profile-before-change for phase OS.File: Waiting for clients before profileBeforeChange
[task 2020-11-04T10:39:39.808Z] 10:39:39 INFO - DEBUG: Completed blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-04T10:39:39.810Z] 10:39:39 INFO - DEBUG: Completed blocker Closing ContentPrefService2 connection. for phase Sqlite.jsm: wait until all clients have completed their task
[task 2020-11-04T10:39:39.810Z] 10:39:39 INFO - DEBUG: Completed blocker protections.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-04T10:39:39.810Z] 10:39:39 INFO - DEBUG: Completed blocker TrackingDBService: Shutting down the content blocking database. for phase profile-before-change
[task 2020-11-04T10:39:39.812Z] 10:39:39 INFO - DEBUG: Completed blocker Sqlite.jsm shutdown blocker for phase profile-before-change
[task 2020-11-04T10:39:39.812Z] 10:39:39 INFO - DEBUG: Completed blocker Flush WebExtension StartupCache for phase profile-before-change
[task 2020-11-04T10:39:39.822Z] 10:39:39 INFO - DEBUG: Completed blocker OS.File: flush I/O queued before profileBeforeChange for phase profile-before-change
[task 2020-11-04T10:39:39.822Z] 10:39:39 INFO - DEBUG: Completed blocker JSON store: writing data for phase profile-before-change
[task 2020-11-04T10:39:39.832Z] 10:39:39 INFO - DEBUG: Finished phase profile-before-change
[task 2020-11-04T10:39:39.832Z] 10:39:39 INFO - [Child 3864, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-04T10:39:39.842Z] 10:39:39 INFO - [Child 3864, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-04T10:39:39.852Z] 10:39:39 INFO - DEBUG: Starting phase profile-before-change-telemetry
[task 2020-11-04T10:39:39.852Z] 10:39:39 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:39.942Z] 10:39:39 INFO - DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:39.952Z] 10:39:39 INFO - DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:39.952Z] 10:39:39 INFO - DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:39.971Z] 10:39:39 INFO - DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:39.990Z] 10:39:39 INFO - DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:40.000Z] 10:39:40 INFO - DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:40.000Z] 10:39:40 INFO - DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:40.000Z] 10:39:40 INFO - DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2020-11-04T10:39:40.002Z] 10:39:40 INFO - DEBUG: Completed blocker TelemetryController: shutting down for phase profile-before-change-telemetry
[task 2020-11-04T10:39:40.002Z] 10:39:40 INFO - DEBUG: Finished phase profile-before-change-telemetry
[task 2020-11-04T10:39:40.007Z] 10:39:40 INFO - 1604486380005 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2020-11-04T10:39:40.007Z] 10:39:40 INFO - 1604486380005 Marionette DEBUG Marionette stopped listening
[task 2020-11-04T10:39:40.007Z] 10:39:40 INFO - DEBUG: Starting phase xpcom-will-shutdown
[task 2020-11-04T10:39:40.009Z] 10:39:40 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:40.048Z] 10:39:40 INFO - DEBUG: Completed blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2020-11-04T10:39:40.050Z] 10:39:40 INFO - DEBUG: Finished phase xpcom-will-shutdown
[task 2020-11-04T10:39:40.055Z] 10:39:40 INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2020-11-04T10:39:40.055Z] 10:39:40 INFO - DEBUG: Starting phase web-workers-shutdown
[task 2020-11-04T10:39:40.055Z] 10:39:40 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:40.057Z] 10:39:40 INFO - DEBUG: Finished phase web-workers-shutdown
[task 2020-11-04T10:39:40.067Z] 10:39:40 INFO - [GPU 5528, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-04T10:39:40.688Z] 10:39:40 INFO - [Parent 5560, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-04T10:40:43.328Z] 10:40:43 INFO - Hit MOZ_CRASH(Shutdown too long, probably frozen, causing a crash.) at /builds/worker/checkouts/gecko/toolkit/components/terminator/nsTerminator.cpp:221
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #01: PR_MD_UNLOCK[C:\Users\task_1604483748\build\application\firefox\nss3.dll +0x13ee51]
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #02: o_ceil[C:\windows\System32\ucrtbase.dll +0x1c4be]
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #03: BaseThreadInitThunk[C:\windows\System32\KERNEL32.DLL +0x13034]
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #04: RtlUserThreadStart[C:\windows\SYSTEM32\ntdll.dll +0x71461]
[task 2020-11-04T10:42:49.855Z] 10:42:49 INFO - mozcrash Copy/paste: C:/Users/task_1604483748/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1604483748\appdata\local\temp\tmpb5_xdw.mozrunner\minidumps\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.dmp C:\Users\task_1604483748\build\symbols
[task 2020-11-04T10:42:55.848Z] 10:42:55 INFO - mozcrash Saved minidump as C:\Users\task_1604483748\build\blobber_upload_dir\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.dmp
[task 2020-11-04T10:42:55.848Z] 10:42:55 INFO - mozcrash Saved app info as C:\Users\task_1604483748\build\blobber_upload_dir\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.extra
[task 2020-11-04T10:42:55.849Z] 10:42:55 ERROR - PROCESS-CRASH | toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | application crashed [@ mozilla::`anonymous namespace'::RunWatchdog(void*)]
[task 2020-11-04T10:42:55.850Z] 10:42:55 INFO - Mozilla crash reason: MOZ_CRASH(Shutdown too long, probably frozen, causing a crash.)
[task 2020-11-04T10:42:55.850Z] 10:42:55 INFO - Crash dump filename: c:\users\task_1604483748\appdata\local\temp\tmpb5_xdw.mozrunner\minidumps\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.dmp"```
|
||
Comment 1•4 years ago
|
||
TEST-START | toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data
...
[task 2020-11-04T10:39:39.227Z] 10:39:39 INFO - DEBUG: Adding blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2020-11-04T10:39:39.227Z] 10:39:39 INFO - DEBUG: Starting phase quit-application-granted
[task 2020-11-04T10:39:39.232Z] 10:39:39 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.237Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.239Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.239Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.239Z] 10:39:39 INFO - DEBUG: Adding blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.258Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.258Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.263Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.265Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.267Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.269Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.269Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: '!CanSend() || !mManager || !mManager->CanSend()', file /builds/worker/checkoDEBUG: Completed blocker XPIProvider shutdown for phase quit-application-granted
[task 2020-11-04T10:39:39.269Z] 10:39:39 INFO - uts/gecko/dom/ipc/jsactor/JSWindowActorChild.cpp:41
[task 2020-11-04T10:39:39.290Z] 10:39:39 INFO - DEBUG: Completed blocker SessionStore: flushing all windows for phase quit-application-granted
[task 2020-11-04T10:39:39.290Z] 10:39:39 INFO - DEBUG: Finished phase quit-application-granted
[task 2020-11-04T10:39:39.290Z] 10:39:39 INFO - DEBUG: Adding blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2020-11-04T10:39:39.290Z] 10:39:39 INFO - 1604486379285 Marionette TRACE Received observer notification quit-application
[task 2020-11-04T10:39:39.295Z] 10:39:39 INFO - DEBUG: Adding blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2020-11-04T10:39:39.300Z] 10:39:39 INFO - 1604486379295 Marionette DEBUG 4 <- [1,20,null,{"cause":"restart"}]
[task 2020-11-04T10:39:39.319Z] 10:39:39 INFO - [Child 5456, Main Thread] WARNING: '!window', file /builds/worker/checkouts/gecko/dom/cache/CacheStorage.cpp:579
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.338Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: doh-rollout@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.339Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.339Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.339Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.339Z] 10:39:39 INFO - DEBUG: Completed blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - 1604486379354 Marionette DEBUG Closed connection 4
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - DEBUG: Starting phase profile-change-teardown
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: 'mProgress != Progress::ShutdownCompleted', file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownState.cpp:57
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - [Child 5456, Main Thread] WARNING: '!window', file /builds/worker/checkouts/gecko/dom/cache/CacheStorage.cpp:579
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - [Parent 5560, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/[Childcheckouts/g 5456, DOM Worker] WARNING: '!meWcorkerPrivatko/dom/workee->rAds/remdWoteworkers/RemoteWorkerControllerParent.cpp:123
[task 2020-11-04T10:39:39.364Z] 10:39:39 INFO - [Parent 5560, IPDL Background] WARNING: 'aResulto.rIkseRrReejfec(thtis(,) 'aSta,tu s)f',i flilee /b/ubiludildss//wwoorrkekre/crh/cheecckouts/kgeouts/gecko/dom/workers/remcoteworkers/RemoteWorkerController.cpp:470
[task 2020-11-04T10:39:39.364Z] 10:39:39 INFO - [Parent 5560, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/checkouts/gecko/dom/workers/remoteworkers/RemoteWorkerControllerParent.cpp:123
[task 2020-11-04T10:39:39.364Z] 10:39:39 INFO - ko/dom/workers/WorkerRef.cpp:80
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/cache/nsApplicationCacheService.cpp:161
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - JavaScript error: , line 0: TypeError: ServiceWorker script at http://127.0.0.1:49899/serviceworker/serviceworker.js for scope http://127.0.0.1:49899/serviceworker/ encountered an error during installation.
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::Uncached, at /builds/worker/checkouts/gecko/dom/workers/ScriptLoader.cpp:1793
Severity: normal → --
Component: Data Sanitization → DOM: Workers
Product: Toolkit → Core
Summary: Intermittent toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | application crashed [@ mozilla::`anonymous namespace'::RunWatchdog(void*)] → Intermittent Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::Uncached, at /builds/worker/checkouts/gecko/dom/workers/ScriptLoader.cpp:1793
|
||
Comment 2•4 years ago
|
||
Looking at the log, I see:
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - DEBUG: Starting phase profile-change-teardown
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: 'mProgress != Progress::ShutdownCompleted', file /builds/worker/checkouts/gecko/dom/serviceworkers/ServiceWorkerShutdownState.cpp:57
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - [Child 5456, Main Thread] WARNING: '!window', file /builds/worker/checkouts/gecko/dom/cache/CacheStorage.cpp:579
[task 2020-11-04T10:39:39.359Z] 10:39:39 INFO - [Parent 5560, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/[Childcheckouts/g 5456, DOM Worker] WARNING: '!meWcorkerPrivatko/dom/workee->rAds/remdWoteworkers/RemoteWorkerControllerParent.cpp:123
[task 2020-11-04T10:39:39.364Z] 10:39:39 INFO - [Parent 5560, IPDL Background] WARNING: 'aResulto.rIkseRrReejfec(thtis(,) 'aSta,tu s)f',i flilee /b/ubiludildss//wwoorrkekre/crh/cheecckouts/kgeouts/gecko/dom/workers/remcoteworkers/RemoteWorkerController.cpp:470
[task 2020-11-04T10:39:39.364Z] 10:39:39 INFO - [Parent 5560, IPDL Background] WARNING: 'aResult.IsReject()', file /builds/worker/checkouts/gecko/dom/workers/remoteworkers/RemoteWorkerControllerParent.cpp:123
[task 2020-11-04T10:39:39.364Z] 10:39:39 INFO - ko/dom/workers/WorkerRef.cpp:80
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/cache/nsApplicationCacheService.cpp:161
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - JavaScript error: , line 0: TypeError: ServiceWorker script at http://127.0.0.1:49899/serviceworker/serviceworker.js for scope http://127.0.0.1:49899/serviceworker/ encountered an error during installation.
[task 2020-11-04T10:39:39.383Z] 10:39:39 INFO - Assertion failure: mLoadInfo.mCacheStatus == ScriptLoadInfo::Uncached, at /builds/worker/checkouts/gecko/dom/workers/ScriptLoader.cpp:1793
CONTENT PROCESS CRASHED (by ASSERT)
(...)
[task 2020-11-04T10:39:39.498Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/cache/nsApplicationCacheService.cpp:150
[task 2020-11-04T10:39:39.498Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80040111 (NS_ERROR_NOT_AVAILABLE): file /builds/worker/checkouts/gecko/netwerk/cache2/AppCacheStorage.cpp:141
[task 2020-11-04T10:39:39.503Z] 10:39:39 INFO - DEBUG: Adding blocker protections.sqlite#0: waiting for shutdown for phase Sqlite.jsm: wait until all connections are closed
[task 2020-11-04T10:39:39.513Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-04T10:39:39.532Z] 10:39:39 INFO - [Child 1180, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-04T10:39:39.537Z] 10:39:39 INFO - [2020-11-04T10:39:39Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2020-11-04T10:39:39.537Z] 10:39:39 INFO - [2020-11-04T10:39:39Z WARN xulstore::persist] tried to remove key that isn't in the store
[task 2020-11-04T10:39:39.542Z] 10:39:39 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase profile-before-change
[task 2020-11-04T10:39:39.542Z] 10:39:39 INFO - console.debug: SearchService: "init"
[task 2020-11-04T10:39:39.573Z] 10:39:39 INFO - DEBUG: Adding blocker TrackingDBService: Shutting down the content blocking database. for phase profile-before-change
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: QuotaManager failure: 'OkIf(outputStream)', file ActorsParent.cpp:2587
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: DEBUG: Completed blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdownQ
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - uotaManager failure: 'GetBinaryOutputStream(*file, kUpdateFileFlag)', file ActorsParent.cpp:8413
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: 'NS_FAILED(rv)', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:8277
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - [Parent 5560, QuotaManager IO] WARNING: 'NS_FAILED(rv)'DEBUG: Finished phase profile-change-teardown
[task 2020-11-04T10:39:39.583Z] 10:39:39 INFO - , file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:8187
Nit: I see no single message DEBUG: Finished phase profile-change-teardown, it is mixed with a QM warning?-
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - [Parent 5560, Unnamed thread 29d34737c00] WARNING: Resource acquired is being released in non-LIFO order; why?
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - : file /builds/worker/checkouts/gecko/xpcom/threads/BlockingResourceBase.cpp:292
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - --- Mutex : dumpSafetyLock (currently acquired)
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - calling context
[task 2020-11-04T10:39:39.645Z] 10:39:39 INFO - [stack trace unavailable]
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: IPC message discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:511
[task 2020-11-04T10:39:39.783Z] 10:39:39 INFO - [Parent 5560, Main Thread] WARNING: Error sending reply: file /builds/worker/workspace/obj-build/ipc/ipdl/PContentParent.cpp:12607
Maybe some message to the crashed child process could not be delivered?
[task 2020-11-04T10:39:39.785Z] 10:39:39 INFO - DEBUG: Starting phase profile-before-change
[task 2020-11-04T10:39:39.804Z] 10:39:39 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:39.804Z] 10:39:39 INFO - DEBUG: Completed blocker ...
(... 30 times for different blockers ...)
[task 2020-11-04T10:39:39.832Z] 10:39:39 INFO - DEBUG: Finished phase profile-before-change
[task 2020-11-04T10:39:39.832Z] 10:39:39 INFO - [Child 3864, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
[task 2020-11-04T10:39:39.842Z] 10:39:39 INFO - [Child 3864, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
profile-before-change seemed to work.
[task 2020-11-04T10:39:39.852Z] 10:39:39 INFO - DEBUG: Starting phase profile-before-change-telemetry
(...)
[task 2020-11-04T10:39:40.002Z] 10:39:40 INFO - DEBUG: Finished phase profile-before-change-telemetry
profile-before-change-telemetry seemed to work.
[task 2020-11-04T10:39:40.007Z] 10:39:40 INFO - DEBUG: Starting phase xpcom-will-shutdown
[task 2020-11-04T10:39:40.009Z] 10:39:40 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:40.048Z] 10:39:40 INFO - DEBUG: Completed blocker OS.File: flush pending requests, warn about unclosed files, shut down service. for phase xpcom-will-shutdown
[task 2020-11-04T10:39:40.050Z] 10:39:40 INFO - DEBUG: Finished phase xpcom-will-shutdown
[task 2020-11-04T10:39:40.055Z] 10:39:40 INFO - ###!!! [Child][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
Maybe some message to the crashed child process could not be delivered?
[task 2020-11-04T10:39:40.055Z] 10:39:40 INFO - DEBUG: Starting phase web-workers-shutdown
[task 2020-11-04T10:39:40.055Z] 10:39:40 INFO - DEBUG: Spinning the event loop
[task 2020-11-04T10:39:40.057Z] 10:39:40 INFO - DEBUG: Finished phase web-workers-shutdown
[task 2020-11-04T10:39:40.067Z] 10:39:40 INFO - [GPU 5528, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4287
[task 2020-11-04T10:39:40.688Z] 10:39:40 INFO - [Parent 5560, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3359
!!! 1 MINUTE stall after we finished web-workers-shutdown !!!
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #01: PR_MD_UNLOCK[C:\Users\task_1604483748\build\application\firefox\nss3.dll +0x13ee51]
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #02: o_ceil[C:\windows\System32\ucrtbase.dll +0x1c4be]
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #03: BaseThreadInitThunk[C:\windows\System32\KERNEL32.DLL +0x13034]
[task 2020-11-04T10:40:43.439Z] 10:40:43 INFO - #04: RtlUserThreadStart[C:\windows\SYSTEM32\ntdll.dll +0x71461]
[task 2020-11-04T10:42:49.855Z] 10:42:49 INFO - mozcrash Copy/paste: C:/Users/task_1604483748/fetches\minidump_stackwalk\minidump_stackwalk.exe c:\users\task_1604483748\appdata\local\temp\tmpb5_xdw.mozrunner\minidumps\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.dmp C:\Users\task_1604483748\build\symbols
[task 2020-11-04T10:42:55.848Z] 10:42:55 INFO - mozcrash Saved minidump as C:\Users\task_1604483748\build\blobber_upload_dir\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.dmp
[task 2020-11-04T10:42:55.848Z] 10:42:55 INFO - mozcrash Saved app info as C:\Users\task_1604483748\build\blobber_upload_dir\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.extra
[task 2020-11-04T10:42:55.849Z] 10:42:55 ERROR - PROCESS-CRASH | toolkit/components/cleardata/tests/marionette/test_service_worker_at_shutdown.py ServiceWorkerAtShutdownTestCase.test_unregistering_service_worker_when_clearing_data | application crashed [@ mozilla::`anonymous namespace'::RunWatchdog(void*)]
[task 2020-11-04T10:42:55.850Z] 10:42:55 INFO - Mozilla crash reason: MOZ_CRASH(Shutdown too long, probably frozen, causing a crash.)
[task 2020-11-04T10:42:55.850Z] 10:42:55 INFO - Crash dump filename: c:\users\task_1604483748\appdata\local\temp\tmpb5_xdw.mozrunner\minidumps\c3c6f3b7-6653-4225-ad1a-30d3ad25e5f5.dmp
[task 2020-11-04T10:42:55.850Z] 10:42:55 INFO - Operating system: Windows NT
[task 2020-11-04T10:42:55.850Z] 10:42:55 INFO - 10.0.17134
[task 2020-11-04T10:42:55.851Z] 10:42:55 INFO - CPU: amd64
[task 2020-11-04T10:42:55.851Z] 10:42:55 INFO - family 6 model 94 stepping 3
[task 2020-11-04T10:42:55.851Z] 10:42:55 INFO - 8 CPUs
[task 2020-11-04T10:42:55.851Z] 10:42:55 INFO - GPU: UNKNOWN
[task 2020-11-04T10:42:55.852Z] 10:42:55 INFO - Crash reason: EXCEPTION_BREAKPOINT
[task 2020-11-04T10:42:55.852Z] 10:42:55 INFO - Crash address: 0xda37968e
[task 2020-11-04T10:42:55.852Z] 10:42:55 INFO - Process uptime: 69 seconds
[task 2020-11-04T10:42:55.852Z] 10:42:55 INFO - Thread 18 (crashed)
[task 2020-11-04T10:42:55.853Z] 10:42:55 INFO - 0 xul.dll!mozilla::`anonymous namespace'::RunWatchdog(void*) [nsTerminator.cpp:3f08ccb1f141069bfd90474d6023413303307ec4 : 221 + 0x0]
Shutdown hang crash.
|
|
||
Comment 3•4 years ago
|
||
So my doubt would be: If we shutdown right after a content process crash - what happens? (of course we should also understand, why the content process crashed).
| Comment hidden (Intermittent Failures Robot) |
|
||
Updated•4 years ago
|
Severity: -- → S3
Priority: -- → P3
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Comment 6•3 years ago
|
||
This seems to not happen any more.
Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → WORKSFORME
|
||
Comment 7•2 years ago
|
||
Hi,
This seems to be still happening . Can you take a look?
Thank you!
Recent failure log : https://treeherder.mozilla.org/logviewer?job_id=359209358&repo=autoland&lineNumber=93995
Status: RESOLVED → REOPENED
Flags: needinfo?(jstutte)
Resolution: WORKSFORME → ---
| Comment hidden (Intermittent Failures Robot) |
|
|
||
Updated•2 years ago
|
Flags: needinfo?(jstutte)
|
|
||
Updated•1 year ago
|
Status: REOPENED → RESOLVED
Closed: 3 years ago → 1 year ago
Resolution: --- → WORKSFORME
You need to log in
before you can comment on or make changes to this bug.
Description
•