Closed
Bug 1838943
Opened 1 year ago
Closed 1 year ago
Intermittent testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_remoteness_change | marionette_driver.errors.NoSuchWindowException: Browsing context has been discarded
Categories
(Testing :: Marionette Client and Harness, defect, P5)
Testing
Marionette Client and Harness
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1838331
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=419648152&repo=mozilla-beta
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/KaQGunBoT_OglKJNZ2x1mw/runs/0/artifacts/public/logs/live_backing.log
[task 2023-06-16T18:53:05.023Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: content process pid = 4144 crashed without leaving a minidump behind: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:4486
[task 2023-06-16T18:53:05.026Z] 18:53:05 ERROR - A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2023-06-16T18:53:05.055Z] 18:53:05 INFO - [Child 3132, Main Thread] WARNING: DispatchEvent called on non-current inner window, dropping. Please check the window in the caller instead.: file /builds/worker/checkouts/gecko/dom/base/nsGlobalWindowInner.cpp:4344
[task 2023-06-16T18:53:05.071Z] 18:53:05 INFO - 1686941585070 Marionette TRACE Canceled page load listener because the top-browsing context has been closed
[task 2023-06-16T18:53:05.071Z] 18:53:05 INFO - 1686941585071 Marionette DEBUG 45 <- [1,72,null,{"value":null}]
[task 2023-06-16T18:53:05.074Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: '!mCancelable', file /builds/worker/checkouts/gecko/image/imgRequestProxy.cpp:476
[task 2023-06-16T18:53:05.082Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2023-06-16T18:53:05.082Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: '!inner', file /builds/worker/checkouts/gecko/dom/ipc/jsactor/JSWindowActorProtocol.cpp:163
[task 2023-06-16T18:53:05.087Z] 18:53:05 INFO - [GPU 1948, Compositor] WARNING: Possibly dropping task posted to updater thread: file /builds/worker/checkouts/gecko/gfx/layers/apz/src/APZUpdater.cpp:371
[task 2023-06-16T18:53:05.092Z] 18:53:05 INFO - DEBUG: Completed blocker ShieldRecipeClient: Cleaning up for phase profile-before-change
[task 2023-06-16T18:53:05.117Z] 18:53:05 INFO - 1686941585117 Marionette TRACE [1] MarionetteCommands actor destroyed for window id 2
[task 2023-06-16T18:53:05.120Z] 18:53:05 INFO - 1686941585119 Marionette DEBUG 45 -> [0,73,"WebDriver:GetCurrentURL",{}]
[task 2023-06-16T18:53:05.122Z] 18:53:05 INFO - 1686941585121 Marionette DEBUG 45 <- [1,73,{"error":"no such window","message":"Browsing context has been discarded","stacktrace":"RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8\nWebDriverError@chrome://remote/content/shared/webdriver/Er ... ote/content/marionette/server.sys.mjs:265:9\n_onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20\n"},null]
[task 2023-06-16T18:53:05.123Z] 18:53:05 INFO - DEBUG: Completed blocker SessionFile: Finish writing Session Restore data for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.124Z] 18:53:05 INFO - DEBUG: Starting phase xpcom-will-shutdown
[task 2023-06-16T18:53:05.125Z] 18:53:05 INFO - [Child 3132, Main Thread] WARNING: IPC message 'PContent::Msg_StoreUserInteractionAsPermission' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:507
[task 2023-06-16T18:53:05.127Z] 18:53:05 INFO - [Child 3132, Main Thread] WARNING: IPC message 'PContent::Msg_StoreUserInteractionAsPermission' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:507
[task 2023-06-16T18:53:05.128Z] 18:53:05 INFO - DEBUG: Spinning the event loop
[task 2023-06-16T18:53:05.128Z] 18:53:05 INFO - DEBUG: Finished phase xpcom-will-shutdown
[task 2023-06-16T18:53:05.132Z] 18:53:05 INFO - [Parent 2456, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:232
[task 2023-06-16T18:53:05.133Z] 18:53:05 INFO - [Parent 2456, Socket Thread] WARNING: cannot post event if not initialized: file /builds/worker/checkouts/gecko/netwerk/protocol/http/nsHttpConnectionMgr.cpp:232
[task 2023-06-16T18:53:05.133Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: unable to post continuation event: file /builds/worker/checkouts/gecko/xpcom/io/nsStreamUtils.cpp:467
[task 2023-06-16T18:53:05.136Z] 18:53:05 INFO - JavaScript error: chrome://remote/content/marionette/cert.sys.mjs, line 51: NS_ERROR_NOT_AVAILABLE: Component returned failure code: 0x80040111 (NS_ERROR_NOT_AVAILABLE) [nsICertOverrideService.setDisableAllSecurityChecksAndLetAttackersInterceptMyData]
[task 2023-06-16T18:53:05.138Z] 18:53:05 INFO - DEBUG: Starting phase profile-change-teardown
[task 2023-06-16T18:53:05.150Z] 18:53:05 INFO - DEBUG: Spinning the event loop
[task 2023-06-16T18:53:05.161Z] 18:53:05 INFO - DEBUG: Completed blocker PlacesFrecencyRecalculator: shutdown for phase profile-change-teardown
[task 2023-06-16T18:53:05.161Z] 18:53:05 INFO - DEBUG: Completed blocker sanitize.js: Sanitize on shutdown for phase Places Clients shutdown
[task 2023-06-16T18:53:05.162Z] 18:53:05 INFO - DEBUG: Completed blocker StorageSyncService: shutdown for phase profile-change-teardown
[task 2023-06-16T18:53:05.210Z] 18:53:05 INFO - [Child 3132, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3426
[task 2023-06-16T18:53:05.224Z] 18:53:05 INFO - [Child 3132, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2023-06-16T18:53:05.236Z] 18:53:05 INFO - [Child 3132, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4687
[task 2023-06-16T18:53:05.247Z] 18:53:05 INFO - [Child 7248, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3426
[task 2023-06-16T18:53:05.250Z] 18:53:05 INFO - [Child 7248, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2023-06-16T18:53:05.258Z] 18:53:05 INFO - [Child 7248, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4687
[task 2023-06-16T18:53:05.602Z] 18:53:05 INFO - [Parent 2456, IPC I/O Parent] WARNING: ConnectNamedPipe timed out!: file /builds/worker/checkouts/gecko/ipc/chromium/src/chrome/common/ipc_channel_win.cc:327
[task 2023-06-16T18:53:05.604Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: content process pid = 8852 crashed without leaving a minidump behind: file /builds/worker/checkouts/gecko/dom/ipc/ContentParent.cpp:4486
[task 2023-06-16T18:53:05.605Z] 18:53:05 ERROR - A content process crashed and MOZ_CRASHREPORTER_SHUTDOWN is set, shutting down
[task 2023-06-16T18:53:05.607Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: addons-search-detection@mozilla.com for phase profile-change-teardown
[task 2023-06-16T18:53:05.608Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: amazondotcom@search.mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.608Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: bing@search.mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.608Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: ddg@search.mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.609Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: default-theme@mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.609Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: formautofill@mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.609Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: google@search.mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.610Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: pictureinpicture@mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.610Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: screenshots@mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.611Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: webcompat-reporter@mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.611Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: webcompat@mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.611Z] 18:53:05 INFO - DEBUG: Completed blocker Extension shutdown: wikipedia@search.mozilla.org for phase profile-change-teardown
[task 2023-06-16T18:53:05.612Z] 18:53:05 INFO - DEBUG: Finished phase profile-change-teardown
[task 2023-06-16T18:53:05.759Z] 18:53:05 INFO - DEBUG: Starting phase profile-before-change
[task 2023-06-16T18:53:05.769Z] 18:53:05 INFO - DEBUG: Spinning the event loop
[task 2023-06-16T18:53:05.773Z] 18:53:05 INFO - DEBUG: Completed blocker EnvironmentAddonBuilder for phase AddonManager: Waiting to start provider shutdown.
[task 2023-06-16T18:53:05.774Z] 18:53:05 INFO - DEBUG: Completed blocker PageActions: purging unregistered actions from cache for phase profile-before-change
[task 2023-06-16T18:53:05.774Z] 18:53:05 INFO - DEBUG: Completed blocker Places Expiration: shutdown for phase Places Connection shutdown
[task 2023-06-16T18:53:05.776Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'handlers' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.776Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'shieldpreferenceexperiments' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.777Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'ExperimentStoreData' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.777Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'logins' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.778Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'broadcastlisteners' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.778Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'extensionsettings' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.778Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'clients' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.779Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'clients' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.779Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'clients' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.779Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'addons' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.780Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'addons' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.780Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'addons' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.780Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'passwords' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.781Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'passwords' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.781Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'passwords' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.781Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'prefs' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.782Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'prefs' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.782Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'bookmarks' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.782Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'bookmarks' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.783Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'forms' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.783Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'forms' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.784Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'forms' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.784Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'history' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.784Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'history' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.785Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'history' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.785Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'tabs' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.785Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'tabs' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.786Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'addresses' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.786Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'addresses' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.786Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'creditcards' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.787Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'creditcards' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.787Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'extensionstorage' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.787Z] 18:53:05 INFO - DEBUG: Completed blocker JSON store: writing data for 'extensionstorage' for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.788Z] 18:53:05 INFO - DEBUG: Completed blocker RemoteSettingsClient - finish IDB access. for phase profile-before-change
[task 2023-06-16T18:53:05.788Z] 18:53:05 INFO - DEBUG: Completed blocker Remote Settings profile-before-change for phase profile-before-change
[task 2023-06-16T18:53:05.788Z] 18:53:05 INFO - DEBUG: Completed blocker DownloadAutoSaveView: writing data for phase profile-before-change
[task 2023-06-16T18:53:05.788Z] 18:53:05 INFO - DEBUG: Completed blocker Search service: shutting down for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.789Z] 18:53:05 INFO - DEBUG: Completed blocker places.sqlite#1: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-06-16T18:53:05.805Z] 18:53:05 INFO - DEBUG: Completed blocker PlacesUtils wrapped connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2023-06-16T18:53:05.820Z] 18:53:05 INFO - DEBUG: Completed blocker PlacesUtils wrapped connection must be closed before Sqlite.sys.mjs for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2023-06-16T18:53:05.820Z] 18:53:05 INFO - DEBUG: Completed blocker SitePermsAddonProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-06-16T18:53:05.821Z] 18:53:05 INFO - DEBUG: Completed blocker GMPProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-06-16T18:53:05.821Z] 18:53:05 INFO - DEBUG: Completed blocker XPIProvider for phase AddonManager: Waiting for providers to shut down.
[task 2023-06-16T18:53:05.821Z] 18:53:05 INFO - DEBUG: Completed blocker AddonManager: shutting down. for phase profile-before-change
[task 2023-06-16T18:53:05.822Z] 18:53:05 INFO - DEBUG: Completed blocker CrashMonitor: Writing notifications to file after receiving profile-before-change and awaiting all checkpoints written for phase IOUtils: waiting for profileBeforeChange IO to complete
[task 2023-06-16T18:53:05.823Z] 18:53:05 INFO - DEBUG: Completed blocker places.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-06-16T18:53:05.824Z] 18:53:05 INFO - DEBUG: Completed blocker PlacesUtils read-only connection closing as part of Places shutdown for phase Places Connection shutdown
[task 2023-06-16T18:53:05.824Z] 18:53:05 INFO - DEBUG: Completed blocker PlacesUtils read-only connection must be closed before Sqlite.sys.mjs for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2023-06-16T18:53:05.826Z] 18:53:05 INFO - DEBUG: Completed blocker content-prefs.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-06-16T18:53:05.826Z] 18:53:05 INFO - DEBUG: Completed blocker Closing ContentPrefService2 connection. for phase Sqlite.sys.mjs: wait until all clients have completed their task
[task 2023-06-16T18:53:05.827Z] 18:53:05 INFO - DEBUG: Completed blocker protections.sqlite#0: waiting for shutdown for phase Sqlite.sys.mjs: wait until all connections are closed
[task 2023-06-16T18:53:05.828Z] 18:53:05 INFO - DEBUG: Completed blocker TrackingDBService: Shutting down the content blocking database. for phase profile-before-change
[task 2023-06-16T18:53:05.828Z] 18:53:05 INFO - DEBUG: Completed blocker Sqlite.sys.mjs shutdown blocker for phase profile-before-change
[task 2023-06-16T18:53:05.838Z] 18:53:05 INFO - [Child 8328, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3426
[task 2023-06-16T18:53:05.839Z] 18:53:05 INFO - [Child 8328, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2023-06-16T18:53:05.845Z] 18:53:05 INFO - [Child 8328, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4687
[task 2023-06-16T18:53:05.847Z] 18:53:05 INFO - DEBUG: Finished phase profile-before-change
[task 2023-06-16T18:53:05.852Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.852Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: initiateShutdownWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.853Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.853Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: cache: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.854Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: sdb: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.854Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: fs: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.854Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: ls: '0.000000s: starting', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.855Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.000000s: startKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.855Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.000000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.856Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.000000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.862Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.016000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.864Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.016000s: Live database entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.864Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.016000s: gLiveDatabaseHashtable entry removed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.872Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.032000s: stopKillActorsTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.880Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.032000s: shutdownAndJoinWorkThreads', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.880Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: idb: '0.032000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.880Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: cache: '0.032000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.880Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: sdb: '0.032000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.881Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: fs: '0.032000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.881Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: ls: '0.032000s: completed', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.882Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.032000s: shutdownAndJoinIOThread', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.882Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.032000s: invalidatePendingDirectoryLocks', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.882Z] 18:53:05 INFO - [Parent 2456, IPDL Background] WARNING: quota manager shutdown step: '0.032000s: stopCrashBrowserTimer', file /builds/worker/checkouts/gecko/dom/quota/ActorsParent.cpp:3383
[task 2023-06-16T18:53:05.883Z] 18:53:05 INFO - DEBUG: Starting phase profile-before-change-telemetry
[task 2023-06-16T18:53:05.883Z] 18:53:05 INFO - DEBUG: Spinning the event loop
[task 2023-06-16T18:53:05.884Z] 18:53:05 INFO - [Parent 2456, Main Thread] WARNING: NS_ENSURE_SUCCESS(rv, rv) failed with result 0x80004005 (NS_ERROR_FAILURE): file /builds/worker/checkouts/gecko/toolkit/xre/nsXREDirProvider.cpp:475
[task 2023-06-16T18:53:05.993Z] 18:53:05 INFO - DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2023-06-16T18:53:06.041Z] 18:53:06 INFO - DEBUG: Adding blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2023-06-16T18:53:06.060Z] 18:53:06 INFO - DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2023-06-16T18:53:06.061Z] 18:53:06 INFO - DEBUG: Completed blocker Waiting for ping task for phase TelemetryController: Waiting for pending ping activity
[task 2023-06-16T18:53:06.073Z] 18:53:06 INFO - DEBUG: Completed blocker TelemetryController: shutting down for phase IOUtils: waiting for sendTelemetry IO to complete
[task 2023-06-16T18:53:06.075Z] 18:53:06 INFO - DEBUG: Finished phase profile-before-change-telemetry
[task 2023-06-16T18:53:06.076Z] 18:53:06 INFO - DEBUG: Starting phase xpcom-will-shutdown
[task 2023-06-16T18:53:06.077Z] 18:53:06 INFO - DEBUG: Spinning the event loop
[task 2023-06-16T18:53:06.078Z] 18:53:06 INFO - DEBUG: Finished phase xpcom-will-shutdown
[task 2023-06-16T18:53:06.085Z] 18:53:06 INFO - DEBUG: Starting phase web-workers-shutdown
[task 2023-06-16T18:53:06.085Z] 18:53:06 INFO - DEBUG: Spinning the event loop
[task 2023-06-16T18:53:06.086Z] 18:53:06 INFO - DEBUG: Finished phase web-workers-shutdown
[task 2023-06-16T18:53:06.092Z] 18:53:06 INFO - [GPU 1948, Main Thread] WARNING: IPC message 'PGPU::Msg_FOGData' discarded: actor cannot send: file /builds/worker/checkouts/gecko/ipc/glue/ProtocolUtils.cpp:507
[task 2023-06-16T18:53:06.103Z] 18:53:06 INFO - Destroying context 00000128A25BF000 surface 00000128A253CE40 on display 00000128A258B400
[task 2023-06-16T18:53:06.133Z] 18:53:06 INFO - [GPU 1948, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4687
[task 2023-06-16T18:53:06.744Z] 18:53:06 INFO - [Parent 2456, Main Thread] WARNING: '!top', file /builds/worker/checkouts/gecko/dom/xul/MenuBarListener.cpp:99
[task 2023-06-16T18:53:06.905Z] 18:53:06 INFO - [Parent 2456, Main Thread] WARNING: Extra shutdown CC: 'i < NORMAL_SHUTDOWN_COLLECTIONS', file /builds/worker/checkouts/gecko/xpcom/base/nsCycleCollector.cpp:3426
[task 2023-06-16T18:53:06.919Z] 18:53:06 INFO - [Parent 2456, Main Thread] WARNING: NS_ENSURE_TRUE(InitStaticMembers()) failed: file /builds/worker/workspace/obj-build/dist/include/mozilla/Preferences.h:129
[task 2023-06-16T18:53:06.963Z] 18:53:06 INFO - [Parent 2456, Main Thread] WARNING: NS_ENSURE_TRUE(Preferences::InitStaticMembers()) failed: file /builds/worker/checkouts/gecko/modules/libpref/Preferences.cpp:4687
[task 2023-06-16T18:53:06.971Z] 18:53:06 INFO - nsStringStats
[task 2023-06-16T18:53:06.971Z] 18:53:06 INFO - => mAllocCount: 378645
[task 2023-06-16T18:53:06.971Z] 18:53:06 INFO - => mReallocCount: 0
[task 2023-06-16T18:53:06.972Z] 18:53:06 INFO - => mFreeCount: 378644 -- LEAKED 1 !!!
[task 2023-06-16T18:53:06.972Z] 18:53:06 INFO - => mShareCount: 427072
[task 2023-06-16T18:53:06.972Z] 18:53:06 INFO - => mAdoptCount: 4820
[task 2023-06-16T18:53:06.972Z] 18:53:06 INFO - => mAdoptFreeCount: 6421
[task 2023-06-16T18:53:06.973Z] 18:53:06 INFO - => Process ID: 2456, Thread ID: 1820
[task 2023-06-16T18:59:05.148Z] 18:59:05 INFO - Failed to gather test failure debug: Process has been unexpectedly closed (Exit code: 245) (Reason: Connection timed out after 360.0s)
[task 2023-06-16T18:59:05.154Z] 18:59:05 ERROR - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_remoteness_change | marionette_driver.errors.NoSuchWindowException: Browsing context has been discarded
[task 2023-06-16T18:59:05.154Z] 18:59:05 INFO - stacktrace:
[task 2023-06-16T18:59:05.155Z] 18:59:05 INFO - RemoteError@chrome://remote/content/shared/RemoteError.sys.mjs:8:8
[task 2023-06-16T18:59:05.155Z] 18:59:05 INFO - WebDriverError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:187:5
[task 2023-06-16T18:59:05.155Z] 18:59:05 INFO - NoSuchWindowError@chrome://remote/content/shared/webdriver/Errors.sys.mjs:613:5
[task 2023-06-16T18:59:05.155Z] 18:59:05 INFO - assert.that/<@chrome://remote/content/shared/webdriver/Assert.sys.mjs:485:13
[task 2023-06-16T18:59:05.156Z] 18:59:05 INFO - assert.open@chrome://remote/content/shared/webdriver/Assert.sys.mjs:147:4
[task 2023-06-16T18:59:05.156Z] 18:59:05 INFO - GeckoDriver.prototype.getCurrentUrl@chrome://remote/content/marionette/driver.sys.mjs:870:15
[task 2023-06-16T18:59:05.156Z] 18:59:05 INFO - despatch@chrome://remote/content/marionette/server.sys.mjs:320:40
[task 2023-06-16T18:59:05.156Z] 18:59:05 INFO - execute@chrome://remote/content/marionette/server.sys.mjs:291:16
[task 2023-06-16T18:59:05.157Z] 18:59:05 INFO - onPacket/<@chrome://remote/content/marionette/server.sys.mjs:264:20
[task 2023-06-16T18:59:05.157Z] 18:59:05 INFO - onPacket@chrome://remote/content/marionette/server.sys.mjs:265:9
[task 2023-06-16T18:59:05.157Z] 18:59:05 INFO - _onJSONObjectReady/<@chrome://remote/content/marionette/transport.sys.mjs:496:20
[task 2023-06-16T18:59:05.157Z] 18:59:05 INFO - Traceback (most recent call last):
[task 2023-06-16T18:59:05.158Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 198, in run
[task 2023-06-16T18:59:05.158Z] 18:59:05 INFO - testMethod()
[task 2023-06-16T18:59:05.158Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 571, in test_remoteness_change
[task 2023-06-16T18:59:05.158Z] 18:59:05 INFO - self.run_bfcache_test(test_pages)
[task 2023-06-16T18:59:05.159Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 438, in run_bfcache_test
[task 2023-06-16T18:59:05.159Z] 18:59:05 INFO - check_page_status(page, len(test_pages))
[task 2023-06-16T18:59:05.159Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 395, in check_page_status
[task 2023-06-16T18:59:05.159Z] 18:59:05 INFO - self.assertEqual(self.marionette.get_url(), page["url"])
[task 2023-06-16T18:59:05.160Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1595, in get_url
[task 2023-06-16T18:59:05.160Z] 18:59:05 INFO - return self._send_message("WebDriver:GetCurrentURL", key="value")
[task 2023-06-16T18:59:05.160Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\decorators.py", line 24, in _
[task 2023-06-16T18:59:05.160Z] 18:59:05 INFO - return func(*args, **kwargs)
[task 2023-06-16T18:59:05.161Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 703, in _send_message
[task 2023-06-16T18:59:05.161Z] 18:59:05 INFO - self._handle_error(err)
[task 2023-06-16T18:59:05.162Z] 18:59:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 715, in _handle_error
[task 2023-06-16T18:59:05.162Z] 18:59:05 INFO - raise errors.lookup(error)(message, stacktrace=stacktrace)
[task 2023-06-16T18:59:05.162Z] 18:59:05 INFO - TEST-INFO took 371408ms
[task 2023-06-16T18:59:05.174Z] 18:59:05 INFO - test_end for testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_remoteness_change logged while not in progress. Logged with data: {"message": "marionette_driver.errors.InvalidSessionIdException: Please start a session", "expected": "PASS", "stack": "Traceback (most recent call last):\n File \"Z:\\task_168693924335962\\build\\venv\\lib\\site-packages\\marionette_harness\\marionette_test\\testcases.py\", line 231, in run\n self.tearDown()\n File \"Z:\\task_168693924335962\\build\\tests\\marionette\\tests\\testing\\marionette\\harness\\marionette_harness\\tests\\unit\\test_navigation.py\", line 63, in tearDown\n self.marionette.timeout.reset()\n File \"Z:\\task_168693924335962\\build\\venv\\lib\\site-packages\\marionette_driver\\timeout.py\", line 101, in reset\n self.script = DEFAULT_SCRIPT_TIMEOUT\n File \"Z:\\task_168693924335962\\build\\venv\\lib\\site-packages\\marionette_driver\\timeout.py\", line 54, in script\n self._set(\"script\", sec)\n File \"Z:\\task_168693924335962\\build\\venv\\lib\\site-packages\\marionette_driver\\timeout.py\", line 30, in _set\n self._marionette._send_message(\"WebDriver:SetTimeouts\", {name: ms})\n File \"Z:\\task_168693924335962\\build\\venv\\lib\\site-packages\\marionette_driver\\decorators.py\", line 24, in _\n return func(*args, **kwargs)\n File \"Z:\\task_168693924335962\\build\\venv\\lib\\site-packages\\marionette_driver\\marionette.py\", line 693, in _send_message\n raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_navigation.TestBackForwardNavigation", "method_name": "test_remoteness_change"}, "test": "testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_remoteness_change", "status": "ERROR"}
[task 2023-06-16T18:59:05.176Z] 18:59:05 INFO - TEST-START | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_same_document_hash_change
[task 2023-06-16T18:59:05.176Z] 18:59:05 INFO - Application command: Z:\task_168693924335962\build\application\firefox\firefox.exe -no-remote -marionette --wait-for-browser -profile C:\Users\task_168693924335962\AppData\Local\Temp\tmp094cyt3l.mozrunner
[task 2023-06-16T19:01:05.612Z] 19:01:05 ERROR - TEST-UNEXPECTED-ERROR | testing/marionette/harness/marionette_harness/tests/unit/test_navigation.py TestBackForwardNavigation.test_same_document_hash_change | OSError: Process has been unexpectedly closed (Exit code: 3221227782) (Reason: Process killed after 120s because no connection to Marionette server could be established. Check gecko.log for errors)
[task 2023-06-16T19:01:05.613Z] 19:01:05 INFO - Traceback (most recent call last):
[task 2023-06-16T19:01:05.614Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 179, in run
[task 2023-06-16T19:01:05.614Z] 19:01:05 INFO - self.setUp()
[task 2023-06-16T19:01:05.614Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\tests\marionette\tests\testing\marionette\harness\marionette_harness\tests\unit\test_navigation.py", line 36, in setUp
[task 2023-06-16T19:01:05.614Z] 19:01:05 INFO - super(BaseNavigationTestCase, self).setUp()
[task 2023-06-16T19:01:05.615Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_harness\runner\mixins\window_manager.py", line 13, in setUp
[task 2023-06-16T19:01:05.615Z] 19:01:05 INFO - super(WindowManagerMixin, self).setUp()
[task 2023-06-16T19:01:05.615Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 401, in setUp
[task 2023-06-16T19:01:05.616Z] 19:01:05 INFO - super(MarionetteTestCase, self).setUp()
[task 2023-06-16T19:01:05.616Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_harness\marionette_test\testcases.py", line 304, in setUp
[task 2023-06-16T19:01:05.617Z] 19:01:05 INFO - self.marionette.start_session()
[task 2023-06-16T19:01:05.617Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\decorators.py", line 34, in _
[task 2023-06-16T19:01:05.617Z] 19:01:05 INFO - m._handle_socket_failure()
[task 2023-06-16T19:01:05.617Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 780, in _handle_socket_failure
[task 2023-06-16T19:01:05.618Z] 19:01:05 INFO - reraise(
[task 2023-06-16T19:01:05.618Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\six.py", line 702, in reraise
[task 2023-06-16T19:01:05.618Z] 19:01:05 INFO - raise value.with_traceback(tb)
[task 2023-06-16T19:01:05.618Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\decorators.py", line 24, in _
[task 2023-06-16T19:01:05.618Z] 19:01:05 INFO - return func(*args, **kwargs)
[task 2023-06-16T19:01:05.619Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 1287, in start_session
[task 2023-06-16T19:01:05.619Z] 19:01:05 INFO - self.start_binary(timeout)
[task 2023-06-16T19:01:05.619Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 587, in start_binary
[task 2023-06-16T19:01:05.619Z] 19:01:05 INFO - reraise(IOError, IOError(msg.format(timeout)), sys.exc_info()[2])
[task 2023-06-16T19:01:05.620Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\six.py", line 702, in reraise
[task 2023-06-16T19:01:05.620Z] 19:01:05 INFO - raise value.with_traceback(tb)
[task 2023-06-16T19:01:05.620Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 577, in start_binary
[task 2023-06-16T19:01:05.621Z] 19:01:05 INFO - self.raise_for_port(timeout=timeout)
[task 2023-06-16T19:01:05.621Z] 19:01:05 INFO - File "Z:\task_168693924335962\build\venv\lib\site-packages\marionette_driver\marionette.py", line 671, in raise_for_port
[task 2023-06-16T19:01:05.621Z] 19:01:05 INFO - raise socket.timeout(
[task 2023-06-16T19:01:05.621Z] 19:01:05 INFO - TEST-INFO took 120439ms
|
||
Updated•1 year ago
|
You need to log in
before you can comment on or make changes to this bug.
Description
•