Filed by: malexandru [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=336102805&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/Sxo9RoWkR8aybDvVg_QsMQ/runs/0/artifacts/public/logs/live_backing.log
[task 2021-04-11T03:47:08.275Z] 03:47:08 INFO - 1618112828261 Toolkit.Telemetry TRACE TelemetrySend::_doPing - server: http://localhost:8000/pings, persisted: false, id: af636890-af7e-d34a-bd1d-24203c2e0787
[task 2021-04-11T03:47:08.276Z] 03:47:08 INFO - pingserver pings_handler received 'main' ping with reason 'environment-change'
[task 2021-04-11T03:47:08.277Z] 03:47:08 INFO - wait_for_pings running action 'restart_browser'.
[task 2021-04-11T03:47:08.277Z] 03:47:08 INFO - 1618112828266 Toolkit.Telemetry INFO TelemetrySend::_doPing - successfully loaded, status: 200
[task 2021-04-11T03:47:08.277Z] 03:47:08 INFO - 1618112828267 Toolkit.Telemetry TRACE TelemetrySend::_onPingRequestFinished - success: true, persisted: false
[task 2021-04-11T03:47:08.278Z] 03:47:08 INFO - 1618112828267 Toolkit.Telemetry TRACE TelemetrySend::Scheduler::_doSendTask - bailing out after sending, shutdown: false, pendingPingCount: 0
[task 2021-04-11T03:47:08.278Z] 03:47:08 INFO - 1618112828268 Toolkit.Telemetry TRACE TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-04-11T03:47:08.278Z] 03:47:08 INFO - 1618112828268 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/datareporting/aborted-session-ping
[task 2021-04-11T03:47:08.278Z] 03:47:08 INFO - 1618112828268 Marionette DEBUG 1 -> [0,8,"Marionette:GetContext",{}]
[task 2021-04-11T03:47:08.278Z] 03:47:08 INFO - 1618112828268 Marionette DEBUG 1 <- [1,8,null,{"value":"content"}]
[task 2021-04-11T03:47:08.279Z] 03:47:08 INFO - 1618112828269 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/datareporting/archived/2021-04/1618112828260.af636890-af7e-d34a-bd1d-24203c2e0787.main.jsonlz4
[task 2021-04-11T03:47:08.279Z] 03:47:08 INFO - 1618112828271 Marionette DEBUG 1 -> [0,9,"Marionette:AcceptConnections",{"value":false}]
[task 2021-04-11T03:47:08.279Z] 03:47:08 INFO - 1618112828271 Marionette INFO Stopped listening on port 2828
[task 2021-04-11T03:47:08.280Z] 03:47:08 INFO - 1618112828271 Marionette DEBUG 1 <- [1,9,null,{"value":null}]
[task 2021-04-11T03:47:08.280Z] 03:47:08 INFO - 1618112828272 Marionette DEBUG 1 -> [0,10,"Marionette:Quit",{"flags":["eRestart","eForceQuit"]}]
[task 2021-04-11T03:47:08.292Z] 03:47:08 INFO - 1618112828292 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: toolkit.startup.last_success
[task 2021-04-11T03:47:08.294Z] 03:47:08 INFO - 1618112828294 Marionette TRACE Received observer notification quit-application
[task 2021-04-11T03:47:08.295Z] 03:47:08 INFO - 1618112828294 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.sessionstore.resume_session_once
[task 2021-04-11T03:47:08.297Z] 03:47:08 INFO - 1618112828297 Marionette DEBUG 1 <- [1,10,null,{"cause":"restart","forced":false}]
[task 2021-04-11T03:47:08.317Z] 03:47:08 INFO - 1618112828317 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: browser.sessionstore.upgradeBackup.latestBuildID
[task 2021-04-11T03:47:08.325Z] 03:47:08 INFO - 1618112828325 Marionette DEBUG Closed connection 1
[task 2021-04-11T03:47:08.329Z] 03:47:08 INFO - 1618112828329 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: nsPref:changed, aData: privacy.sanitize.pending
[task 2021-04-11T03:47:08.336Z] 03:47:08 INFO - WARNING: A blocker encountered an error while we were waiting.
[task 2021-04-11T03:47:08.337Z] 03:47:08 INFO - Blocker: Flush WebExtension StartupCache
[task 2021-04-11T03:47:08.337Z] 03:47:08 INFO - Phase: IOUtils: waiting for profileBeforeChange IO to complete
[task 2021-04-11T03:47:08.337Z] 03:47:08 INFO - State: (none)
[task 2021-04-11T03:47:08.337Z] 03:47:08 INFO - WARNING: Error: The object has been already finalized.
[task 2021-04-11T03:47:08.337Z] 03:47:08 INFO - WARNING: finalize@resource://gre/modules/DeferredTask.jsm:267:13
[task 2021-04-11T03:47:08.338Z] 03:47:08 INFO - save/<@resource://gre/modules/ExtensionParent.jsm:1725:32
[task 2021-04-11T03:47:08.338Z] 03:47:08 INFO - trigger@resource://gre/modules/AsyncShutdown.jsm:747:23
[task 2021-04-11T03:47:08.338Z] 03:47:08 INFO - _wait@resource://gre/modules/AsyncShutdown.jsm:899:15
[task 2021-04-11T03:47:08.338Z] 03:47:08 INFO - wait@resource://gre/modules/AsyncShutdown.jsm:880:34
[task 2021-04-11T03:47:08.339Z] 03:47:08 INFO - wait@resource://gre/modules/nsAsyncShutdown.jsm:209:25
[task 2021-04-11T03:47:08.339Z] 03:47:08 INFO - addBlocker/moduleBlocker/<@resource://gre/modules/nsAsyncShutdown.jsm:156:30
[task 2021-04-11T03:47:08.339Z] 03:47:08 INFO - moduleBlocker@resource://gre/modules/nsAsyncShutdown.jsm:152:9
[task 2021-04-11T03:47:08.340Z] 03:47:08 INFO - trigger@resource://gre/modules/AsyncShutdown.jsm:747:23
[task 2021-04-11T03:47:08.340Z] 03:47:08 INFO - _wait@resource://gre/modules/AsyncShutdown.jsm:899:15
[task 2021-04-11T03:47:08.340Z] 03:47:08 INFO - wait@resource://gre/modules/AsyncShutdown.jsm:880:34
[task 2021-04-11T03:47:08.340Z] 03:47:08 INFO - observe@resource://gre/modules/AsyncShutdown.jsm:557:10
[task 2021-04-11T03:47:08.341Z] 03:47:08 INFO - 1618112828339 Toolkit.Telemetry TRACE TelemetryEnvironment::observe - aTopic: browser-search-service, aData: write-settings-to-disk-complete
[task 2021-04-11T03:47:08.341Z] 03:47:08 INFO - JavaScript error: resource://gre/modules/DeferredTask.jsm, line 267: Error: The object has been already finalized.
[task 2021-04-11T03:47:08.345Z] 03:47:08 INFO - 1618112828344 Toolkit.Telemetry TRACE TelemetryController::shutdown
[task 2021-04-11T03:47:08.345Z] 03:47:08 INFO - 1618112828344 Toolkit.Telemetry TRACE TelemetryEventPing::::Shutting down.
[task 2021-04-11T03:47:08.345Z] 03:47:08 INFO - 1618112828344 Toolkit.Telemetry TRACE TelemetryEventPing::::_submitPing
[task 2021-04-11T03:47:08.345Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry TRACE TelemetryController::submitExternalPing - type: event, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-04-11T03:47:08.346Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry TRACE TelemetryController::assemblePing - Type event, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-04-11T03:47:08.346Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry TRACE TelemetryController::submitExternalPing - ping assembled, id: e4511c8f-bce2-194d-8140-351a9315a5de
[task 2021-04-11T03:47:08.346Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry TRACE TelemetrySend::submitPing - ping id: e4511c8f-bce2-194d-8140-351a9315a5de, options: {"usePingSender":true}
[task 2021-04-11T03:47:08.347Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry INFO TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-04-11T03:47:08.347Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry TRACE TelemetryPrioPing::Shutting down.
[task 2021-04-11T03:47:08.347Z] 03:47:08 INFO - 1618112828345 Toolkit.Telemetry TRACE TelemetryPrioPing::_submitPing
[task 2021-04-11T03:47:08.347Z] 03:47:08 INFO - 1618112828346 Toolkit.Telemetry TRACE TelemetryPrioPing::nothing to send
[task 2021-04-11T03:47:08.348Z] 03:47:08 INFO - 1618112828346 Toolkit.Telemetry TRACE TelemetryReportingPolicy::shutdown
[task 2021-04-11T03:47:08.348Z] 03:47:08 INFO - 1618112828346 Toolkit.Telemetry TRACE TelemetryEnvironment::shutdown
[task 2021-04-11T03:47:08.348Z] 03:47:08 INFO - 1618112828346 Toolkit.Telemetry TRACE TelemetrySend::Scheduler::shutdown
[task 2021-04-11T03:47:08.349Z] 03:47:08 INFO - 1618112828346 Toolkit.Telemetry TRACE TelemetrySend::promisePendingPingActivity - Waiting for ping task
[task 2021-04-11T03:47:08.349Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetryHealthPing::::shutdown()
[task 2021-04-11T03:47:08.349Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetrySession::shutdownChromeProcess
[task 2021-04-11T03:47:08.349Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetryEnvironment::unregisterChangeListener for TelemetrySession::onEnvironmentChange
[task 2021-04-11T03:47:08.350Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry WARN TelemetryEnvironment::registerChangeListener - already shutdown
[task 2021-04-11T03:47:08.350Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetryScheduler::shutdown
[task 2021-04-11T03:47:08.350Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetrySession::saveShutdownPings
[task 2021-04-11T03:47:08.350Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetrySession::getSessionPayload - reason: shutdown, clearSubsession: false
[task 2021-04-11T03:47:08.351Z] 03:47:08 INFO - 1618112828347 Toolkit.Telemetry TRACE TelemetrySession::assemblePayloadWithMeasurements - reason: shutdown, submitting subsession data: true
[task 2021-04-11T03:47:08.351Z] 03:47:08 INFO - 1618112828349 Toolkit.Telemetry TRACE TelemetryController::submitExternalPing - type: main, aOptions: {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-04-11T03:47:08.352Z] 03:47:08 INFO - 1618112828349 Toolkit.Telemetry TRACE TelemetryController::assemblePing - Type main, aOptions {"addClientId":true,"addEnvironment":true,"usePingSender":true}
[task 2021-04-11T03:47:08.352Z] 03:47:08 INFO - 1618112828351 Toolkit.Telemetry TRACE TelemetryController::submitExternalPing - ping assembled, id: 90074bad-7d1d-724e-b729-2348fc488b14
[task 2021-04-11T03:47:08.352Z] 03:47:08 INFO - 1618112828351 Toolkit.Telemetry TRACE TelemetrySend::submitPing - ping id: 90074bad-7d1d-724e-b729-2348fc488b14, options: {"usePingSender":true}
[task 2021-04-11T03:47:08.352Z] 03:47:08 INFO - 1618112828351 Toolkit.Telemetry INFO TelemetryReportingPolicy::get dataSubmissionPolicyNotifiedDate - No date stored yet.
[task 2021-04-11T03:47:08.353Z] 03:47:08 INFO - 1618112828351 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/datareporting/archived/2021-04/1618112828345.e4511c8f-bce2-194d-8140-351a9315a5de.event.jsonlz4
[task 2021-04-11T03:47:08.353Z] 03:47:08 INFO - 1618112828352 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/saved-telemetry-pings/e4511c8f-bce2-194d-8140-351a9315a5de
[task 2021-04-11T03:47:08.354Z] 03:47:08 INFO - 1618112828352 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/datareporting/archived/2021-04/1618112828350.90074bad-7d1d-724e-b729-2348fc488b14.main.jsonlz4
[task 2021-04-11T03:47:08.354Z] 03:47:08 INFO - 1618112828353 Toolkit.Telemetry TRACE TelemetryStorage::savePingToFile - path: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/saved-telemetry-pings/90074bad-7d1d-724e-b729-2348fc488b14
[task 2021-04-11T03:47:08.356Z] 03:47:08 INFO - 1618112828355 Toolkit.Telemetry TRACE TelemetryStorage::savePendingPing - saved ping with id e4511c8f-bce2-194d-8140-351a9315a5de
[task 2021-04-11T03:47:08.356Z] 03:47:08 INFO - 1618112828356 Toolkit.Telemetry TRACE TelemetrySend::_sendWithPingSender - sending e4511c8f-bce2-194d-8140-351a9315a5de to http://localhost:8000/pings/submit/telemetry/e4511c8f-bce2-194d-8140-351a9315a5de/event/Firefox/89.0a1/default/20210411031624?v=4
[task 2021-04-11T03:47:08.357Z] 03:47:08 INFO - 1618112828356 Toolkit.Telemetry TRACE TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-04-11T03:47:08.357Z] 03:47:08 INFO - 1618112828357 Toolkit.Telemetry TRACE TelemetryStorage::savePendingPing - saved ping with id 90074bad-7d1d-724e-b729-2348fc488b14
[task 2021-04-11T03:47:08.358Z] 03:47:08 INFO - 1618112828357 Toolkit.Telemetry TRACE TelemetrySend::_sendWithPingSender - sending 90074bad-7d1d-724e-b729-2348fc488b14 to http://localhost:8000/pings/submit/telemetry/90074bad-7d1d-724e-b729-2348fc488b14/main/Firefox/89.0a1/default/20210411031624?v=4
[task 2021-04-11T03:47:08.358Z] 03:47:08 INFO - 1618112828357 Toolkit.Telemetry TRACE TelemetrySend::_sendWithPingSender - too late to send. Batching.
[task 2021-04-11T03:47:08.358Z] 03:47:08 INFO - 1618112828357 Toolkit.Telemetry TRACE TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-04-11T03:47:08.359Z] 03:47:08 INFO - 1618112828357 Toolkit.Telemetry TRACE TelemetryStorage::removeAbortedSessionPing - success
[task 2021-04-11T03:47:08.359Z] 03:47:08 INFO - 1618112828358 Toolkit.Telemetry TRACE TelemetrySend::flushPingSenderBatch - Sending 2 pings.
[task 2021-04-11T03:47:08.359Z] 03:47:08 INFO - 1618112828359 Toolkit.Telemetry TRACE TelemetryStorage::_popAndPerformQueuedOperation - Performing queued operation.
[task 2021-04-11T03:47:08.360Z] 03:47:08 INFO - 1618112828359 Marionette TRACE Received observer notification xpcom-will-shutdown
[task 2021-04-11T03:47:08.360Z] 03:47:08 INFO - 1618112828360 Marionette DEBUG Marionette stopped listening
[task 2021-04-11T03:47:08.374Z] 03:47:08 INFO - pingserver pings_handler received 'event' ping
[task 2021-04-11T03:47:08.377Z] 03:47:08 INFO - pingserver pings_handler received 'main' ping with reason 'shutdown'
[task 2021-04-11T03:47:08.392Z] 03:47:08 INFO - ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-04-11T03:47:08.425Z] 03:47:08 INFO - 1618112828424 Toolkit.Telemetry TRACE TelemetryController::observe - app-startup notified.
[task 2021-04-11T03:47:08.425Z] 03:47:08 INFO - 1618112828425 Toolkit.Telemetry CONFIG TelemetryController::enableTelemetryRecording - canRecordBase:true, canRecordExtended: false
[task 2021-04-11T03:50:18.370Z] 03:50:18 INFO - mozcrash Copy/paste: /opt/worker/tasks/task_161810240929161/fetches/minidump_stackwalk/minidump_stackwalk /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/minidumps/58F6555C-2C5C-4FFB-802D-B13DAC9789F9.dmp /var/folders/ds/9_p3r7s95p7_1rx9lt0_5wg0000014/T/tmpa1grnij4
[task 2021-04-11T03:50:20.483Z] 03:50:20 INFO - mozcrash Saved minidump as /opt/worker/tasks/task_161810240929161/build/blobber_upload_dir/58F6555C-2C5C-4FFB-802D-B13DAC9789F9.dmp
[task 2021-04-11T03:50:20.483Z] 03:50:20 INFO - mozcrash Saved app info as /opt/worker/tasks/task_161810240929161/build/blobber_upload_dir/58F6555C-2C5C-4FFB-802D-B13DAC9789F9.extra
[task 2021-04-11T03:50:20.632Z] 03:50:20 INFO - PROCESS-CRASH | telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management | application crashed [@ XUL + 0x2887d43]
[task 2021-04-11T03:50:20.632Z] 03:50:20 INFO - Crash dump filename: /opt/worker/tasks/task_161810240929161/build/tmp9mbadst3.mozrunner/minidumps/58F6555C-2C5C-4FFB-802D-B13DAC9789F9.dmp
[task 2021-04-11T03:50:20.632Z] 03:50:20 INFO - Operating system: Mac OS X
[task 2021-04-11T03:50:20.632Z] 03:50:20 INFO - 10.15.7 19H524
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - CPU: amd64
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - family 6 model 158 stepping 10
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - 12 CPUs
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - GPU: UNKNOWN
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - Crash reason: EXC_BAD_ACCESS / KERN_INVALID_ADDRESS
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - Crash address: 0x0
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - Process uptime: 2 seconds
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - Thread 0 (crashed)
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - 0 XUL + 0x2887d43
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - rax = 0x0000000000000001 rdx = 0x0000000008220045
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - rcx = 0x0000000000000008 rbx = 0x000000010a0ac5d8
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - rsi = 0x0000000000020000 rdi = 0x0000000000000000
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - rbp = 0x00007ffee5dd8360 rsp = 0x00007ffee5dd8220
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - r8 = 0x00000000000185b9 r9 = 0xffffffff00000000
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - r10 = 0x000000011d3da600 r11 = 0x000000000000001d
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - r12 = 0x0000000000000003 r13 = 0x0000000000000003
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - r14 = 0x0000000000000003 r15 = 0x000000010a0ac000
[task 2021-04-11T03:50:20.633Z] 03:50:20 INFO - rip = 0x000000010cc36d43
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - 1 XUL + 0x7405ad
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - rbp = 0x00007ffee5dd83b0 rsp = 0x00007ffee5dd8370
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - rip = 0x000000010aaef5ad
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - 2 XUL + 0x8332b3
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - rbp = 0x00007ffee5dd83d0 rsp = 0x00007ffee5dd83c0
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - rip = 0x000000010abe22b3
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - 3 XUL + 0x73c559
[task 2021-04-11T03:50:20.634Z] 03:50:20 INFO - rbp = 0x00007ffee5dd8410 rsp = 0x00007ffee5dd83e0
<...>
[task 2021-04-11T03:50:20.638Z] 03:50:20 INFO - Thread 1
[task 2021-04-11T03:50:20.638Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__workq_kernreturn + 0xa
[task 2021-04-11T03:50:20.638Z] 03:50:20 INFO - rax = 0x0000000002000170 rdx = 0x0000000000000000
[task 2021-04-11T03:50:20.638Z] 03:50:20 INFO - rcx = 0x000070000b4fbfa8 rbx = 0x0000000000064003
[task 2021-04-11T03:50:20.638Z] 03:50:20 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000004
[task 2021-04-11T03:50:20.638Z] 03:50:20 INFO - rbp = 0x000070000b4fbfd0 rsp = 0x000070000b4fbfa8
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r8 = 0x0000000000064003 r9 = 0x0000000000000000
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000246
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r12 = 0x000070000b4fc000 r13 = 0x0000000000000000
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r14 = 0x0000000000000000 r15 = 0x0000000000000000
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rip = 0x00007fff6f72f4ce
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - 1 libsystem_pthread.dylib!start_wqthread + 0xf
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rbp = 0x000070000b4fbff0 rsp = 0x000070000b4fbfe0
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rip = 0x00007fff6f7ecb77
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - 2 libdispatch.dylib!_dispatch_root_queues_init_once + 0xd8
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rsp = 0x000070000b4fc098 rip = 0x00007fff6f5a203b
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Found by: stack scanning
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Thread 2
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__workq_kernreturn + 0xa
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rax = 0x0000000002000170 rdx = 0x0000000000000000
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rcx = 0x000070000b57efa8 rbx = 0x0000000000064003
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000004
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rbp = 0x000070000b57efd0 rsp = 0x000070000b57efa8
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r8 = 0x0000000000000001 r9 = 0x000000012bbb0a00
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000246
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r12 = 0x000070000b57f000 r13 = 0x0000000000000000
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - r14 = 0x0000000000000000 r15 = 0x0000000000000000
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rip = 0x00007fff6f72f4ce
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - 1 libsystem_pthread.dylib!start_wqthread + 0xf
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rbp = 0x000070000b57eff0 rsp = 0x000070000b57efe0
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rip = 0x00007fff6f7ecb77
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - 2 libdispatch.dylib!_dispatch_root_queues_init_once + 0xd8
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - rsp = 0x000070000b57f098 rip = 0x00007fff6f5a203b
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Found by: stack scanning
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - Thread 3
[task 2021-04-11T03:50:20.639Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__workq_kernreturn + 0xa
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rax = 0x0000000002000170 rdx = 0x0000000000000000
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rcx = 0x000070000b684fa8 rbx = 0x0000000000064005
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000004
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rbp = 0x000070000b684fd0 rsp = 0x000070000b684fa8
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r8 = 0x0000000120b012a8 r9 = 0x0000000000000001
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000246
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r12 = 0x000070000b685000 r13 = 0x0000000000000000
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r14 = 0x0000000000000000 r15 = 0x0000000000000000
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rip = 0x00007fff6f72f4ce
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - 1 libsystem_pthread.dylib!start_wqthread + 0xf
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rbp = 0x000070000b684ff0 rsp = 0x000070000b684fe0
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rip = 0x00007fff6f7ecb77
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - 2 libdispatch.dylib!_dispatch_root_queues_init_once + 0xd8
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rsp = 0x000070000b685098 rip = 0x00007fff6f5a203b
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - Found by: stack scanning
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - Thread 4
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__workq_kernreturn + 0xa
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rax = 0x0000000002000170 rdx = 0x0000000000000000
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rcx = 0x000070000b707fa8 rbx = 0x0000000000064003
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rsi = 0x0000000000000000 rdi = 0x0000000000000004
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rbp = 0x000070000b707fd0 rsp = 0x000070000b707fa8
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r8 = 0x000000012b800180 r9 = 0x000000012bb01001
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000246
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r12 = 0x000070000b708000 r13 = 0x0000000000000000
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - r14 = 0x0000000000000000 r15 = 0x0000000000000000
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rip = 0x00007fff6f72f4ce
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - 1 libsystem_pthread.dylib!start_wqthread + 0xf
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rbp = 0x000070000b707ff0 rsp = 0x000070000b707fe0
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - rip = 0x00007fff6f7ecb77
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.640Z] 03:50:20 INFO - 2 libdispatch.dylib!_dispatch_root_queues_init_once + 0xd8
[task 2021-04-11T03:50:20.641Z] 03:50:20 INFO - rsp = 0x000070000b708098 rip = 0x00007fff6f5a203b
[task 2021-04-11T03:50:20.641Z] 03:50:20 INFO - Found by: stack scanning
[task 2021-04-11T03:50:20.641Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.641Z] 03:50:20 INFO - Thread 5
[task 2021-04-11T03:50:20.641Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!kevent + 0xa
<...>
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - Thread 6
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__psynch_cvwait + 0xa
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rax = 0x0000000002000131 rdx = 0x0000000000000200
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rcx = 0x000070000b91ca98 rbx = 0x0000000000000002
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rsi = 0x0000020100000300 rdi = 0x000000011cc29b38
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rbp = 0x000070000b91cb30 rsp = 0x000070000b91ca98
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - r8 = 0x0000000000000000 r9 = 0x00000000000000a0
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000202
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - r12 = 0x000000011cc29b38 r13 = 0x0000000000000016
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - r14 = 0x0000020100000300 r15 = 0x000070000b91d000
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rip = 0x00007fff6f730882
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - 1 libmozglue.dylib!mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl&) [ConditionVariable_posix.cpp:0ea49daf534fcd9a49708717b3864a4ebc73c20d : 108 + 0xb]
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rbp = 0x000070000b91cb50 rsp = 0x000070000b91cb40
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rip = 0x0000000109e7486c
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - 2 XUL + 0x11c3c9
[task 2021-04-11T03:50:20.642Z] 03:50:20 INFO - rbp = 0x000070000b91cbb0 rsp = 0x000070000b91cb60
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010a4cb3c9
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 3 XUL + 0x124d40
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91ccf0 rsp = 0x000070000b91cbc0
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010a4d3d40
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 4 XUL + 0x129ac9
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91cd20 rsp = 0x000070000b91cd00
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010a4d8ac9
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 5 XUL + 0x73e064
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91cd70 rsp = 0x000070000b91cd30
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010aaed064
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 6 XUL + 0x6f4b66
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91cda0 rsp = 0x000070000b91cd80
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010aaa3b66
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 7 XUL + 0x122ca9
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91cf60 rsp = 0x000070000b91cdb0
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010a4d1ca9
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 8 libnss3.dylib!_pt_root [ptthread.c:0ea49daf534fcd9a49708717b3864a4ebc73c20d : 201 + 0x8]
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91cfb0 rsp = 0x000070000b91cf70
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x000000010a258125
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 9 libsystem_pthread.dylib!_pthread_start + 0x94
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rbp = 0x000070000b91cfd0 rsp = 0x000070000b91cfc0
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - rip = 0x00007fff6f7f1109
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.643Z] 03:50:20 INFO - 10 libsystem_pthread.dylib!thread_start + 0xf
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b91cff0 rsp = 0x000070000b91cfe0
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x00007fff6f7ecb8b
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 11 libnss3.dylib + 0x157fc0
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rsp = 0x000070000b91d098 rip = 0x000000010a257fc0
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: stack scanning
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Thread 7
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__psynch_cvwait + 0xa
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rax = 0x0000000002000131 rdx = 0x0000000000000500
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rcx = 0x000070000b9a29a8 rbx = 0x0000000000000002
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rsi = 0x0000050100000600 rdi = 0x000000011745db18
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b9a2a40 rsp = 0x000070000b9a29a8
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - r8 = 0x0000000000000000 r9 = 0x00000000000000a0
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000202
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - r12 = 0x000000011745db18 r13 = 0x0000000000000016
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - r14 = 0x0000050100000600 r15 = 0x000070000b9a3000
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x00007fff6f730882
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 1 libmozglue.dylib!mozilla::detail::ConditionVariableImpl::wait_for(mozilla::detail::MutexImpl&, mozilla::BaseTimeDuration<mozilla::TimeDurationValueCalculator> const&) [ConditionVariable_posix.cpp:0ea49daf534fcd9a49708717b3864a4ebc73c20d : 115 + 0xb]
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b9a2a90 rsp = 0x000070000b9a2a50
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x0000000109e748ed
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 2 XUL + 0x3e517c7
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b9a2f30 rsp = 0x000070000b9a2aa0
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x000000010e2007c7
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 3 XUL + 0x3e5156e
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b9a2f60 rsp = 0x000070000b9a2f40
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x000000010e20056e
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 4 libnss3.dylib!_pt_root [ptthread.c:0ea49daf534fcd9a49708717b3864a4ebc73c20d : 201 + 0x8]
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b9a2fb0 rsp = 0x000070000b9a2f70
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x000000010a258125
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - 5 libsystem_pthread.dylib!_pthread_start + 0x94
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rbp = 0x000070000b9a2fd0 rsp = 0x000070000b9a2fc0
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - rip = 0x00007fff6f7f1109
[task 2021-04-11T03:50:20.644Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - 6 libsystem_pthread.dylib!thread_start + 0xf
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rbp = 0x000070000b9a2ff0 rsp = 0x000070000b9a2fe0
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rip = 0x00007fff6f7ecb8b
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - Found by: previous frame's frame pointer
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - 7 libnss3.dylib + 0x157fc0
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rsp = 0x000070000b9a3098 rip = 0x000000010a257fc0
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - Found by: stack scanning
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO -
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - Thread 8
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - 0 libsystem_kernel.dylib!__psynch_cvwait + 0xa
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rax = 0x0000000002000131 rdx = 0x0000000000000100
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rcx = 0x000070000b9e5a98 rbx = 0x0000000000000002
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rsi = 0x0000010100000200 rdi = 0x000000011cc290b8
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rbp = 0x000070000b9e5b30 rsp = 0x000070000b9e5a98
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - r8 = 0x0000000000000000 r9 = 0x00000000000000a0
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - r10 = 0x0000000000000000 r11 = 0x0000000000000202
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - r12 = 0x000000011cc290b8 r13 = 0x0000000000000016
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - r14 = 0x0000010100000200 r15 = 0x000070000b9e6000
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - rip = 0x00007fff6f730882
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - Found by: given as instruction pointer in context
[task 2021-04-11T03:50:20.645Z] 03:50:20 INFO - 1 libmozglue.dylib!mozilla::detail::ConditionVariableImpl::wait(mozilla::detail::MutexImpl&) [ConditionVariable_posix.cpp:0ea49daf534fcd9a49708717b3864a4ebc73c20d : 108 + 0xb]
<...>
[task 2021-04-11T03:50:20.780Z] 03:50:20 INFO - 0x7fff6f824000 - 0x7fff6f859fff libxpc.dylib ???
[task 2021-04-11T03:50:20.782Z] 03:50:20 INFO - TEST-UNEXPECTED-ERROR | telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management | OSError: Process has been unexpectedly closed (Exit code: 0) (Reason: Process crashed (Exit code: 0))
[task 2021-04-11T03:50:20.782Z] 03:50:20 INFO - Traceback (most recent call last):
[task 2021-04-11T03:50:20.782Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 214, in run
[task 2021-04-11T03:50:20.782Z] 03:50:20 INFO - testMethod()
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/tests/telemetry/marionette/tests/client/test_subsession_management.py", line 110, in test_subsession_management
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - ping3 = self.wait_for_ping(self.restart_browser, MAIN_SHUTDOWN_PING)
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 170, in wait_for_ping
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - action_func, ping_filter, 1, ping_server=ping_server
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 156, in wait_for_pings
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - action_func()
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 176, in restart_browser
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - return self.marionette.restart(clean=False, in_app=True)
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 37, in _
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - m._handle_socket_failure()
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 716, in _handle_socket_failure
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - IOError, IOError(message.format(returncode=returncode, reason=exc)), tb
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/six.py", line 702, in reraise
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - raise value.with_traceback(tb)
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py", line 27, in _
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - return func(*args, **kwargs)
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 1087, in restart
[task 2021-04-11T03:50:20.783Z] 03:50:20 INFO - self.raise_for_port(timeout=timeout_restart, check_process_status=False)
[task 2021-04-11T03:50:20.784Z] 03:50:20 INFO - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py", line 594, in raise_for_port
[task 2021-04-11T03:50:20.784Z] 03:50:20 INFO - raise IOError("Process crashed (Exit code: {})".format(runner.wait(0)))
[task 2021-04-11T03:50:20.784Z] 03:50:20 INFO - TEST-INFO took 196509ms
[task 2021-04-11T03:50:20.786Z] 03:50:20 ERROR - test_end for telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management 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 \"/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py\", line 247, in run\n self.tearDown()\n File \"/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py\", line 240, in tearDown\n super(TelemetryTestCase, self).tearDown()\n File \"/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runner/mixins/window_manager.py\", line 24, in tearDown\n if len(self.marionette.chrome_window_handles) > len(self.start_windows):\n File \"/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py\", line 1338, in chrome_window_handles\n return self._send_message(\"WebDriver:GetChromeWindowHandles\")\n File \"/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/decorators.py\", line 27, in _\n return func(*args, **kwargs)\n File \"/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_driver/marionette.py\", line 618, in _send_message\n raise errors.InvalidSessionIdException(\"Please start a session\")\n", "extra": {"class_name": "test_subsession_management.TestSubsessionManagement", "method_name": "test_subsession_management"}, "test": "telemetry/marionette/tests/client/test_subsession_management.py TestSubsessionManagement.test_subsession_management", "status": "ERROR"}
[task 2021-04-11T03:50:20.788Z] 03:50:20 CRITICAL - pingserver Failed to start HTTP server on port 8000; is something already using that port?
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - [Errno 48] Address already in use
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - Traceback (most recent call last):
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runtests.py", line 108, in cli
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - failed = harness_instance.run()
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runtests.py", line 82, in run
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - runner.run_tests(tests)
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1042, in run_tests
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - self.run_test_sets()
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1269, in run_test_sets
[task 2021-04-11T03:50:20.791Z] 03:50:20 ERROR - self.run_test_set(self.tests)
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1239, in run_test_set
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - self.run_test(test["filepath"], test["expected"])
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runner/base.py", line 1191, in run_test
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - **self.test_kwargs
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/marionette_test/testcases.py", line 412, in add_tests_to_suite
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - **kwargs
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/fog_testcase.py", line 15, in __init__
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - super(FOGTestCase, self).__init__(*args, **kwargs)
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/testcase.py", line 32, in __init__
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - self.testvars["server_root"], self.testvars["server_url"]
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/telemetry_harness/ping_server.py", line 60, in __init__
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - self._httpd = httpd.FixtureServer(server_root, url=url)
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/marionette_harness/runner/httpd.py", line 123, in __init__
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR - key_file=ssl_key,
[task 2021-04-11T03:50:20.792Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/wptserve/server.py", line 820, in __init__
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - http2=http2)
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - File "/opt/worker/tasks/task_161810240929161/build/venv/lib/python3.7/site-packages/wptserve/server.py", line 190, in __init__
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - http.server.HTTPServer.__init__(self, hostname_port, request_handler_cls, **kwargs)
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/socketserver.py", line 452, in __init__
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - self.server_bind()
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/http/server.py", line 137, in server_bind
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - socketserver.TCPServer.server_bind(self)
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/socketserver.py", line 466, in server_bind
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - self.socket.bind(self.server_address)
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - OSError: [Errno 48] Address already in use
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR -
[task 2021-04-11T03:50:20.793Z] 03:50:20 ERROR - Return code: 1
[task 2021-04-11T03:50:20.794Z] 03:50:20 ERROR - Got 1 unexpected statuses
[task 2021-04-11T03:50:20.794Z] 03:50:20 ERROR - Got 1 unexpected crashes
[task 2021-04-11T03:50:20.794Z] 03:50:20 ERROR - No suite end message was emitted by this harness.
[task 2021-04-11T03:50:20.794Z] 03:50:20 CRITICAL - # TBPL FAILURE #
[task 2021-04-11T03:50:20.794Z] 03:50:20 WARNING - setting return code to 2
[task 2021-04-11T03:50:20.794Z] 03:50:20 INFO - Running post-action listener: _package_coverage_data
[task 2021-04-11T03:50:20.794Z] 03:50:20 INFO - Running post-action listener: _resource_record_post_action
[task 2021-04-11T03:50:20.794Z] 03:50:20 INFO - Running post-action listener: process_java_coverage_data
[task 2021-04-11T03:50:20.794Z] 03:50:20 INFO - [mozharness: 2021-04-11 03:50:20.794866Z] Finished run-tests step (success)
[task 2021-04-11T03:50:20.794Z] 03:50:20 INFO - [mozharness: 2021-04-11 03:50:20.794919Z] Running uninstall step.
[task 2021-04-11T03:50:20.795Z] 03:50:20 INFO - Running pre-action listener: _resource_record_pre_action
[task 2021-04-11T03:50:20.795Z] 03:50:20 INFO - Running main action method: uninstall
[task 2021-04-11T03:50:20.795Z] 03:50:20 INFO - Getting output from command: ['/opt/worker/tasks/task_161810240929161/build/venv/bin/mozuninstall', '/opt/worker/tasks/task_161810240929161/build/application']
[task 2021-04-11T03:50:20.795Z] 03:50:20 INFO - Copy/paste: /opt/worker/tasks/task_161810240929161/build/venv/bin/mozuninstall /opt/worker/tasks/task_161810240929161/build/application
[task 2021-04-11T03:50:21.077Z] 03:50:21 INFO - Running post-action listener: _resource_record_post_action
[task 2021-04-11T03:50:21.077Z] 03:50:21 INFO - [mozharness: 2021-04-11 03:50:21.077429Z] Finished uninstall step (success)
[task 2021-04-11T03:50:21.077Z] 03:50:21 INFO - Running post-run listener: _resource_record_post_run
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - Total resource usage - Wall time: 241s; CPU: 5%; Read bytes: 43995136; Write bytes: 792170496; Read time: 690; Write time: 1492
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: CPU usage<br/>5.3%
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: I/O read bytes / time<br/>43,995,136 / 690
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: I/O write bytes / time<br/>792,170,496 / 1,492
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: CPU idle<br/>2,727.2 (94.4%)
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: CPU system<br/>43.6 (1.5%)
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: CPU user<br/>118.5 (4.1%)
[task 2021-04-11T03:50:21.146Z] 03:50:21 INFO - TinderboxPrint: Swap in / out<br/>277,446,656 / 0
[task 2021-04-11T03:50:21.147Z] 03:50:21 INFO - install - Wall time: 19s; CPU: 14%; Read bytes: 253019648; Write bytes: 273154048; Read time: 16456; Write time: 422
[task 2021-04-11T03:50:21.150Z] 03:50:21 INFO - run-tests - Wall time: 223s; CPU: 4%; Read bytes: 38580224; Write bytes: 514179072; Read time: 557; Write time: 1065
[task 2021-04-11T03:50:21.150Z] 03:50:21 INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-04-11T03:50:21.206Z] 03:50:21 WARNING - returning nonzero exit status 2
[taskcluster 2021-04-11T03:50:21.234Z] Exit Code: 2
[taskcluster 2021-04-11T03:50:21.234Z] User Time: 1m8.620725s
[taskcluster 2021-04-11T03:50:21.234Z] Kernel Time: 14.115368s
[taskcluster 2021-04-11T03:50:21.234Z] Wall Time: 4m50.855934s
[taskcluster 2021-04-11T03:50:21.234Z] Result: FAILED```
Description
•