Closed
Bug 1819738
Opened 2 years ago
Closed 2 years ago
Intermittent automation.py | application terminated with exit code -6
Categories
(Release Engineering :: Applications: MozharnessCore, defect, P5)
Release Engineering
Applications: MozharnessCore
Tracking
(Not tracked)
RESOLVED
DUPLICATE
of bug 1770595
People
(Reporter: intermittent-bug-filer, Assigned: gbrown)
Details
(Keywords: intermittent-failure)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=407463681&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/FdkF8i21TAmIEeM7yuYF9w/runs/0/artifacts/public/logs/live_backing.log
[task 2023-03-01T19:49:31.882Z] 19:49:31 INFO - TEST-OK | devtools/client/framework/test/allocations/browser_allocations_reload_no_devtools.js | took 37756ms
[task 2023-03-01T19:49:31.969Z] 19:49:31 INFO - checking window state
[task 2023-03-01T19:49:32.079Z] 19:49:32 INFO - GECKO(1591) | TRACKER NEW GLOBAL: - : about:blank
[task 2023-03-01T19:49:33.772Z] 19:49:33 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1740
[task 2023-03-01T19:49:33.780Z] 19:49:33 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1792
[task 2023-03-01T19:49:33.867Z] 19:49:33 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1714
[task 2023-03-01T19:49:33.913Z] 19:49:33 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1862
[task 2023-03-01T19:49:34.611Z] 19:49:34 INFO - GECKO(1591) | Completed ShutdownLeaks collections in process 1591
[task 2023-03-01T19:49:34.611Z] 19:49:34 INFO - TEST-START | Shutdown
[task 2023-03-01T19:49:34.613Z] 19:49:34 INFO - Browser Chrome Test Summary
[task 2023-03-01T19:49:34.613Z] 19:49:34 INFO - Passed: 2
[task 2023-03-01T19:49:34.614Z] 19:49:34 INFO - Failed: 0
[task 2023-03-01T19:49:34.615Z] 19:49:34 INFO - Todo: 0
[task 2023-03-01T19:49:34.616Z] 19:49:34 INFO - Mode: e10s
[task 2023-03-01T19:49:34.616Z] 19:49:34 INFO - *** End BrowserChrome Test Results ***
[task 2023-03-01T19:49:35.195Z] 19:49:35 INFO - GECKO(1591) | 1677700175194 Marionette TRACE Received observer notification quit-application
[task 2023-03-01T19:49:35.196Z] 19:49:35 INFO - GECKO(1591) | 1677700175195 Marionette INFO Stopped listening on port 2828
[task 2023-03-01T19:49:35.198Z] 19:49:35 INFO - GECKO(1591) | 1677700175197 Marionette DEBUG Marionette stopped listening
[task 2023-03-01T19:49:35.784Z] 19:49:35 INFO - GECKO(1591) | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:49:35.785Z] 19:49:35 INFO - GECKO(1591) | Blocker: Waiting for ping task
[task 2023-03-01T19:49:35.787Z] 19:49:35 INFO - GECKO(1591) | Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:49:35.787Z] 19:49:35 INFO - GECKO(1591) | State: (none)
[task 2023-03-01T19:49:35.791Z] 19:49:35 INFO - GECKO(1591) | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.791Z] 19:49:35 INFO - GECKO(1591) | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:49:35.791Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:49:35.791Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:49:35.791Z] 19:49:35 INFO - GECKO(1591) | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:49:35.792Z] 19:49:35 INFO - GECKO(1591) | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:49:35.793Z] 19:49:35 INFO - GECKO(1591) | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:49:35.808Z] 19:49:35 INFO - GECKO(1591) | console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-01T19:49:35.896Z] 19:49:35 INFO - GECKO(1591) | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:49:35.896Z] 19:49:35 INFO - GECKO(1591) | Blocker: Waiting for ping task
[task 2023-03-01T19:49:35.896Z] 19:49:35 INFO - GECKO(1591) | Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:49:35.897Z] 19:49:35 INFO - GECKO(1591) | State: (none)
[task 2023-03-01T19:49:35.898Z] 19:49:35 INFO - GECKO(1591) | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.899Z] 19:49:35 INFO - GECKO(1591) | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:49:35.902Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:49:35.902Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:49:35.903Z] 19:49:35 INFO - GECKO(1591) | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:49:35.903Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:49:35.904Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:49:35.904Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:49:35.905Z] 19:49:35 INFO - GECKO(1591) | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:49:35.905Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:49:35.906Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:49:35.906Z] 19:49:35 INFO - GECKO(1591) | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:49:35.906Z] 19:49:35 INFO - GECKO(1591) | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:49:35.911Z] 19:49:35 INFO - GECKO(1591) | WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:49:35.912Z] 19:49:35 INFO - GECKO(1591) | Blocker: TelemetryController: shutting down
[task 2023-03-01T19:49:35.912Z] 19:49:35 INFO - GECKO(1591) | Phase: profile-before-change-telemetry
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | State: Error getting state: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange" at addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:49:35.913Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | WARNING: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.914Z] 19:49:35 INFO - GECKO(1591) | WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:49:35.916Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:49:35.916Z] 19:49:35 INFO - GECKO(1591) | addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:49:35.916Z] 19:49:35 INFO - GECKO(1591) | setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:49:35.917Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:49:35.919Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:49:35.919Z] 19:49:35 INFO - GECKO(1591) | @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:49:35.920Z] 19:49:35 INFO - GECKO(1591) | _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:49:35.920Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:49:35.920Z] 19:49:35 INFO - GECKO(1591) | setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:49:35.921Z] 19:49:35 INFO - GECKO(1591) | setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:49:35.921Z] 19:49:35 INFO - GECKO(1591) | observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:49:35.921Z] 19:49:35 INFO - GECKO(1591) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.921Z] 19:49:35 INFO - GECKO(1591) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.922Z] 19:49:35 INFO - GECKO(1591) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.924Z] 19:49:35 INFO - GECKO(1591) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:35.924Z] 19:49:35 INFO - GECKO(1591) | JavaScript error: resource://gre/modules/AsyncShutdown.sys.mjs, line 727: Error: Phase "profile-before-change" is finished, it is too late to register completion condition "OS.File: flush I/O queued before profileBeforeChange"
[task 2023-03-01T19:49:39.747Z] 19:49:39 INFO - TEST-INFO | Main app process: exit 0
[task 2023-03-01T19:49:39.748Z] 19:49:39 INFO - runtests.py | Application ran for: 0:01:05.226487
[task 2023-03-01T19:49:39.749Z] 19:49:39 INFO - zombiecheck | Reading PID log: /tmp/tmprbt94ac_pidlog
[task 2023-03-01T19:49:39.749Z] 19:49:39 INFO - ==> process 1591 launched child process 1609
[task 2023-03-01T19:49:39.749Z] 19:49:39 INFO - ==> process 1591 launched child process 1714
[task 2023-03-01T19:49:39.749Z] 19:49:39 INFO - ==> process 1591 launched child process 1740
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1792
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1818
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1827
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1831
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1862
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1912
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - ==> process 1591 launched child process 1925
[task 2023-03-01T19:49:39.752Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1792
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1827
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1925
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1862
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1831
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1609
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1740
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1714
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1912
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - zombiecheck | Checking for orphan process with PID: 1818
[task 2023-03-01T19:49:39.753Z] 19:49:39 INFO - Stopping web server
[task 2023-03-01T19:49:39.764Z] 19:49:39 INFO - Server shut down.
[task 2023-03-01T19:49:39.788Z] 19:49:39 INFO - Web server killed.
[task 2023-03-01T19:49:39.789Z] 19:49:39 INFO - Stopping web socket server
[task 2023-03-01T19:49:39.808Z] 19:49:39 INFO - Stopping ssltunnel
[task 2023-03-01T19:49:39.829Z] 19:49:39 INFO - Stopping gst for v4l2loopback
[task 2023-03-01T19:49:39.829Z] 19:49:39 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2023-03-01T19:49:39.830Z] 19:49:39 INFO - runtests.py | Running tests: end.
[task 2023-03-01T19:49:39.834Z] 19:49:39 INFO - Failed to unload module: Module b'30\n' not loaded
[task 2023-03-01T19:49:39.839Z] 19:49:39 INFO - Failed to unload module: Module b'31\n' not loaded
[task 2023-03-01T19:49:39.843Z] 19:49:39 INFO - Failed to unload module: Module b'32\n' not loaded
[task 2023-03-01T19:49:39.847Z] 19:49:39 INFO - Failed to unload module: Module b'33\n' not loaded
[task 2023-03-01T19:49:39.848Z] 19:49:39 INFO - Buffered messages finished
[task 2023-03-01T19:49:39.849Z] 19:49:39 INFO - Running manifest: devtools/client/framework/test/metrics/browser_metrics_netmonitor.ini
[task 2023-03-01T19:49:39.867Z] 19:49:39 INFO - Setting pipeline to PAUSED ...
[task 2023-03-01T19:49:39.867Z] 19:49:39 INFO - Pipeline is PREROLLING ...
[task 2023-03-01T19:49:39.869Z] 19:49:39 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:39.869Z] 19:49:39 INFO - Pipeline is PREROLLED ...
[task 2023-03-01T19:49:39.869Z] 19:49:39 INFO - Setting pipeline to PLAYING ...
[task 2023-03-01T19:49:39.869Z] 19:49:39 INFO - New clock: GstSystemClock
[task 2023-03-01T19:49:39.902Z] 19:49:39 INFO - Got EOS from element "pipeline0".
[task 2023-03-01T19:49:39.903Z] 19:49:39 INFO - Execution ended after 0:00:00.033449369
[task 2023-03-01T19:49:39.903Z] 19:49:39 INFO - Setting pipeline to PAUSED ...
[task 2023-03-01T19:49:39.903Z] 19:49:39 INFO - Setting pipeline to READY ...
[task 2023-03-01T19:49:39.903Z] 19:49:39 INFO - (gst-launch-1.0:1977): GStreamer-CRITICAL **: 19:49:39.902: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2023-03-01T19:49:39.903Z] 19:49:39 INFO - Setting pipeline to NULL ...
[task 2023-03-01T19:49:39.903Z] 19:49:39 INFO - Freeing pipeline ...
[task 2023-03-01T19:49:40.230Z] 19:49:40 INFO - PID 1996 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2023-03-01T19:49:40.259Z] 19:49:40 INFO - Increasing default timeout to 120 seconds
[task 2023-03-01T19:49:40.260Z] 19:49:40 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:40.260Z] 19:49:40 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:40.263Z] 19:49:40 INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmpdc_0gj0_.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2023-03-01T19:49:40.264Z] 19:49:40 INFO - runtests.py | Server pid: 1999
[task 2023-03-01T19:49:40.267Z] 19:49:40 INFO - runtests.py | Websocket server pid: 2002
[task 2023-03-01T19:49:40.268Z] 19:49:40 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:40.275Z] 19:49:40 INFO - runtests.py | SSL tunnel pid: 2006
[task 2023-03-01T19:49:40.577Z] 19:49:40 INFO - runtests.py | Running with scheme: http
[task 2023-03-01T19:49:40.577Z] 19:49:40 INFO - runtests.py | Running with e10s: True
[task 2023-03-01T19:49:40.578Z] 19:49:40 INFO - runtests.py | Running with fission: True
[task 2023-03-01T19:49:40.579Z] 19:49:40 INFO - runtests.py | Running with cross-origin iframes: False
[task 2023-03-01T19:49:40.580Z] 19:49:40 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2023-03-01T19:49:40.580Z] 19:49:40 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2023-03-01T19:49:40.580Z] 19:49:40 INFO - runtests.py | Running tests: start.
[task 2023-03-01T19:49:40.581Z] 19:49:40 INFO -
[task 2023-03-01T19:49:40.586Z] 19:49:40 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmpdc_0gj0_.mozrunner
[task 2023-03-01T19:49:40.591Z] 19:49:40 INFO - runtests.py | Application pid: 2027
[task 2023-03-01T19:49:40.591Z] 19:49:40 INFO - TEST-INFO | started process GECKO(2027)
[task 2023-03-01T19:49:43.250Z] 19:49:43 INFO - GECKO(2027) | ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-03-01T19:49:43.283Z] 19:49:43 INFO - GECKO(2027) | ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-03-01T19:49:43.419Z] 19:49:43 INFO - GECKO(2027) | 1677700183417 Marionette INFO Marionette enabled
[task 2023-03-01T19:49:43.428Z] 19:49:43 INFO - GECKO(2027) | 1677700183426 Marionette TRACE Received observer notification final-ui-startup
[task 2023-03-01T19:49:43.437Z] 19:49:43 INFO - GECKO(2027) | 1677700183436 Marionette INFO Listening on port 2828
[task 2023-03-01T19:49:43.438Z] 19:49:43 INFO - GECKO(2027) | 1677700183437 Marionette DEBUG Marionette is listening
[task 2023-03-01T19:49:43.885Z] 19:49:43 INFO - GECKO(2027) | console.error: "Warning: unrecognized command line flag -foreground\n"
[task 2023-03-01T19:49:44.118Z] 19:49:44 INFO - GECKO(2027) | 1677700184117 Marionette DEBUG Accepted connection 0 from 127.0.0.1:58398
[task 2023-03-01T19:49:44.256Z] 19:49:44 INFO - GECKO(2027) | 1677700184255 Marionette DEBUG Closed connection 0
[task 2023-03-01T19:49:44.262Z] 19:49:44 INFO - GECKO(2027) | 1677700184261 Marionette DEBUG Accepted connection 1 from 127.0.0.1:58400
[task 2023-03-01T19:49:44.482Z] 19:49:44 INFO - GECKO(2027) | 1677700184481 Marionette DEBUG Closed connection 1
[task 2023-03-01T19:49:44.485Z] 19:49:44 INFO - GECKO(2027) | 1677700184483 Marionette DEBUG Accepted connection 2 from 127.0.0.1:58402
[task 2023-03-01T19:49:45.762Z] 19:49:45 INFO - GECKO(2027) | 1677700185761 Marionette DEBUG 2 -> [0,1,"WebDriver:NewSession",{"strictFileInteractability":true}]
[task 2023-03-01T19:49:45.789Z] 19:49:45 INFO - GECKO(2027) | 1677700185788 Marionette DEBUG Waiting for initial application window
[task 2023-03-01T19:49:47.617Z] 19:49:47 INFO - GECKO(2027) | console.error: (new Error("Unexpected content-type \"text/plain;charset=US-ASCII\"", "resource://services-settings/Utils.jsm", 407))
[task 2023-03-01T19:49:49.025Z] 19:49:49 INFO - GECKO(2027) | ==2027==ERROR: ThreadSanitizer failed to allocate 0xfe4eeb9c9000 (279614913810432) bytes at address 8c8e4def000 (errno: 12)
[task 2023-03-01T19:49:49.051Z] 19:49:49 INFO - GECKO(2027) | Exiting due to channel error.
[task 2023-03-01T19:49:49.052Z] 19:49:49 INFO - GECKO(2027) | Crash Annotation GraphicsCriticalError: |[C0][GFX1-]: CompositorBridgeChild receives IPC close with reason=AbnormalShutdown (t=2.27891) Exiting due to channel error.
[task 2023-03-01T19:49:49.053Z] 19:49:49 INFO - runtests.py | Waiting for browser...
[task 2023-03-01T19:49:50.077Z] 19:49:50 INFO - TEST-INFO | Main app process: killed by SIGIOT
[task 2023-03-01T19:49:50.078Z] 19:49:50 INFO - Buffered messages finished
[task 2023-03-01T19:49:50.078Z] 19:49:50 ERROR - TEST-UNEXPECTED-FAIL | automation.py | application terminated with exit code -6
[task 2023-03-01T19:49:50.078Z] 19:49:50 INFO - runtests.py | Application ran for: 0:00:09.491570
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - zombiecheck | Reading PID log: /tmp/tmpdo6z7jpvpidlog
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - ==> process 2027 launched child process 2045
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - ==> process 2027 launched child process 2114
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - ==> process 2027 launched child process 2140
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - zombiecheck | Checking for orphan process with PID: 2114
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - zombiecheck | Checking for orphan process with PID: 2140
[task 2023-03-01T19:49:50.080Z] 19:49:50 INFO - zombiecheck | Checking for orphan process with PID: 2045
[task 2023-03-01T19:49:50.081Z] 19:49:50 INFO - Traceback (most recent call last):
[task 2023-03-01T19:49:50.081Z] 19:49:50 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 3589, in doTests
[task 2023-03-01T19:49:50.081Z] 19:49:50 INFO - crashAsPass=options.crashAsPass,
[task 2023-03-01T19:49:50.082Z] 19:49:50 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 2891, in runApp
[task 2023-03-01T19:49:50.082Z] 19:49:50 INFO - six.reraise(exc, value, tb)
[task 2023-03-01T19:49:50.082Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2023-03-01T19:49:50.082Z] 19:49:50 INFO - raise value
[task 2023-03-01T19:49:50.082Z] 19:49:50 INFO - File "/builds/worker/workspace/build/tests/mochitest/runtests.py", line 2751, in runApp
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - self.marionette.start_session()
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - m._handle_socket_failure()
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 707, in _handle_socket_failure
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - reraise(exc_cls, exc, tb)
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2023-03-01T19:49:50.083Z] 19:49:50 INFO - raise value
[task 2023-03-01T19:49:50.084Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-03-01T19:49:50.085Z] 19:49:50 INFO - return func(*args, **kwargs)
[task 2023-03-01T19:49:50.085Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1258, in start_session
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - resp = self._send_message("WebDriver:NewSession", capabilities)
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - m._handle_socket_failure()
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 707, in _handle_socket_failure
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - reraise(exc_cls, exc, tb)
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - raise value
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - return func(*args, **kwargs)
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 656, in _send_message
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - msg = self.client.request(name, params)
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 381, in request
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - return self.receive()
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/transport.py", line 228, in receive
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - raise socket.error("No data received over socket")
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - OSError: No data received over socket
[task 2023-03-01T19:49:50.086Z] 19:49:50 ERROR - Automation Error: Received unexpected exception while running application
[task 2023-03-01T19:49:50.086Z] 19:49:50 ERROR -
[task 2023-03-01T19:49:50.086Z] 19:49:50 INFO - Stopping web server
[task 2023-03-01T19:49:50.128Z] 19:49:50 INFO - Server shut down.
[task 2023-03-01T19:49:50.148Z] 19:49:50 INFO - Web server killed.
[task 2023-03-01T19:49:50.149Z] 19:49:50 INFO - Stopping web socket server
[task 2023-03-01T19:49:50.169Z] 19:49:50 INFO - Stopping ssltunnel
[task 2023-03-01T19:49:50.189Z] 19:49:50 INFO - Stopping gst for v4l2loopback
[task 2023-03-01T19:49:50.190Z] 19:49:50 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2023-03-01T19:49:50.190Z] 19:49:50 INFO - runtests.py | Running tests: end.
[task 2023-03-01T19:49:50.207Z] 19:49:50 INFO - Buffered messages finished
[task 2023-03-01T19:49:50.208Z] 19:49:50 INFO - Running manifest: devtools/client/inspector/computed/test/browser.ini
[task 2023-03-01T19:49:50.226Z] 19:49:50 INFO - Setting pipeline to PAUSED ...
[task 2023-03-01T19:49:50.226Z] 19:49:50 INFO - Pipeline is PREROLLING ...
[task 2023-03-01T19:49:50.228Z] 19:49:50 INFO - Pipeline is PREROLLED ...
[task 2023-03-01T19:49:50.228Z] 19:49:50 INFO - Setting pipeline to PLAYING ...
[task 2023-03-01T19:49:50.228Z] 19:49:50 INFO - New clock: GstSystemClock
[task 2023-03-01T19:49:50.249Z] 19:49:50 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:50.261Z] 19:49:50 INFO - Got EOS from element "pipeline0".
[task 2023-03-01T19:49:50.262Z] 19:49:50 INFO - Execution ended after 0:00:00.033465151
[task 2023-03-01T19:49:50.262Z] 19:49:50 INFO - Setting pipeline to PAUSED ...
[task 2023-03-01T19:49:50.262Z] 19:49:50 INFO - Setting pipeline to READY ...
[task 2023-03-01T19:49:50.262Z] 19:49:50 INFO - (gst-launch-1.0:2170): GStreamer-CRITICAL **: 19:49:50.261: gst_object_unref: assertion '((GObject *) object)->ref_count > 0' failed
[task 2023-03-01T19:49:50.262Z] 19:49:50 INFO - Setting pipeline to NULL ...
[task 2023-03-01T19:49:50.262Z] 19:49:50 INFO - Freeing pipeline ...
[task 2023-03-01T19:49:50.608Z] 19:49:50 INFO - PID 2197 | pk12util: PKCS12 IMPORT SUCCESSFUL
[task 2023-03-01T19:49:50.637Z] 19:49:50 INFO - Increasing default timeout to 120 seconds
[task 2023-03-01T19:49:50.637Z] 19:49:50 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:50.638Z] 19:49:50 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:50.641Z] 19:49:50 INFO - MochitestServer : launching ['/builds/worker/workspace/build/tests/bin/xpcshell', '-g', '/builds/worker/workspace/build/application/firefox', '-f', '/builds/worker/workspace/build/tests/bin/components/httpd.js', '-e', "const _PROFILE_PATH = '/tmp/tmp2u9dx49y.mozrunner'; const _SERVER_PORT = '8888'; const _SERVER_ADDR = '127.0.0.1'; const _TEST_PREFIX = undefined; const _DISPLAY_RESULTS = false;", '-f', '/builds/worker/workspace/build/tests/mochitest/server.js']
[task 2023-03-01T19:49:50.642Z] 19:49:50 INFO - runtests.py | Server pid: 2200
[task 2023-03-01T19:49:50.645Z] 19:49:50 INFO - runtests.py | Websocket server pid: 2203
[task 2023-03-01T19:49:50.646Z] 19:49:50 INFO - INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:49:50.656Z] 19:49:50 INFO - runtests.py | SSL tunnel pid: 2207
[task 2023-03-01T19:49:50.959Z] 19:49:50 INFO - runtests.py | Running with scheme: http
[task 2023-03-01T19:49:50.959Z] 19:49:50 INFO - runtests.py | Running with e10s: True
[task 2023-03-01T19:49:50.959Z] 19:49:50 INFO - runtests.py | Running with fission: True
[task 2023-03-01T19:49:50.960Z] 19:49:50 INFO - runtests.py | Running with cross-origin iframes: False
[task 2023-03-01T19:49:50.961Z] 19:49:50 INFO - runtests.py | Running with serviceworker_e10s: True
[task 2023-03-01T19:49:50.961Z] 19:49:50 INFO - runtests.py | Running with socketprocess_e10s: False
[task 2023-03-01T19:49:50.962Z] 19:49:50 INFO - runtests.py | Running tests: start.
[task 2023-03-01T19:49:50.963Z] 19:49:50 INFO -
[task 2023-03-01T19:49:50.967Z] 19:49:50 INFO - Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -foreground -profile /tmp/tmp2u9dx49y.mozrunner
[task 2023-03-01T19:49:50.971Z] 19:49:50 INFO - runtests.py | Application pid: 2228
|
Assignee | |
Updated•2 years ago
|
Assignee: nobody → gbrown
Status: NEW → RESOLVED
Closed: 2 years ago
Duplicate of bug: 1770595
Resolution: --- → DUPLICATE
You need to log in
before you can comment on or make changes to this bug.
Description
•