Closed
Bug 1819731
Opened 2 years ago
Closed 2 years ago
Intermittent Last test finished | application terminated with exit code 127
Categories
(Core :: Layout: Form Controls, defect, P5)
Core
Layout: Form Controls
Tracking
()
RESOLVED
DUPLICATE
of bug 1819763
People
(Reporter: intermittent-bug-filer, Unassigned)
Details
(Keywords: intermittent-failure)
Filed by: ctuns [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=407460102&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MrrX6kcfSaSPiF8VCt2T8A/runs/0/artifacts/public/logs/live_backing.log
Reftest URL: https://hg.mozilla.org/mozilla-central/raw-file/tip/layout/tools/reftest/reftest-analyzer.xhtml#logurl=https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/MrrX6kcfSaSPiF8VCt2T8A/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1
[task 2023-03-01T19:47:44.785Z] 19:47:44 INFO - REFTEST TEST-PASS | layout/reftests/css-enabled/optgroup/optgroup-fieldset-1.html == layout/reftests/css-enabled/optgroup/optgroup-fieldset-ref.html | image comparison, max difference: 0, number of differing pixels: 0
[task 2023-03-01T19:47:44.789Z] 19:47:44 INFO - REFTEST TEST-END | layout/reftests/css-enabled/optgroup/optgroup-fieldset-1.html == layout/reftests/css-enabled/optgroup/optgroup-fieldset-ref.html
[task 2023-03-01T19:47:44.906Z] 19:47:44 INFO - REFTEST INFO | Slowest test took 706ms (file:///builds/worker/workspace/build/tests/reftest/tests/layout/reftests/css-enabled/optgroup/optgroup-fieldset-1.html)
[task 2023-03-01T19:47:44.908Z] 19:47:44 INFO - REFTEST INFO | Total canvas count = 2
[task 2023-03-01T19:47:45.619Z] 19:47:45 INFO - 1677700065618 Marionette TRACE Received observer notification quit-application
[task 2023-03-01T19:47:45.623Z] 19:47:45 INFO - 1677700065622 Marionette INFO Stopped listening on port 2828
[task 2023-03-01T19:47:45.625Z] 19:47:45 INFO - 1677700065624 Marionette DEBUG Marionette stopped listening
[task 2023-03-01T19:47:47.115Z] 19:47:47 INFO - WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:47:47.117Z] 19:47:47 INFO - Blocker: Waiting for ping task
[task 2023-03-01T19:47:47.118Z] 19:47:47 INFO - Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:47:47.119Z] 19:47:47 INFO - State: (none)
[task 2023-03-01T19:47:47.121Z] 19:47:47 INFO - 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:47:47.123Z] 19:47:47 INFO - WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:47:47.124Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:47:47.127Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:47:47.128Z] 19:47:47 INFO - setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:47:47.128Z] 19:47:47 INFO - @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:47:47.129Z] 19:47:47 INFO - @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:47:47.129Z] 19:47:47 INFO - @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:47:47.130Z] 19:47:47 INFO - _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:47:47.130Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:47:47.132Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:47:47.133Z] 19:47:47 INFO - setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:47:47.133Z] 19:47:47 INFO - observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:47:47.207Z] 19:47:47 INFO - console.error: "TelemetryScheduler.shutdown - Already shut down"
[task 2023-03-01T19:47:47.425Z] 19:47:47 INFO - WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:47:47.426Z] 19:47:47 INFO - Blocker: Waiting for ping task
[task 2023-03-01T19:47:47.427Z] 19:47:47 INFO - Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:47:47.428Z] 19:47:47 INFO - State: (none)
[task 2023-03-01T19:47:47.431Z] 19:47:47 INFO - 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:47:47.436Z] 19:47:47 INFO - WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:47:47.437Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:47:47.438Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:47:47.439Z] 19:47:47 INFO - setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:47:47.440Z] 19:47:47 INFO - @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:47:47.441Z] 19:47:47 INFO - @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:47:47.442Z] 19:47:47 INFO - @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:47:47.445Z] 19:47:47 INFO - _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:47:47.446Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:47:47.447Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:47:47.448Z] 19:47:47 INFO - setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:47:47.448Z] 19:47:47 INFO - observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:47:47.454Z] 19:47:47 INFO - WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:47:47.455Z] 19:47:47 INFO - Blocker: Waiting for ping task
[task 2023-03-01T19:47:47.456Z] 19:47:47 INFO - Phase: TelemetryController: Waiting for pending ping activity
[task 2023-03-01T19:47:47.457Z] 19:47:47 INFO - State: (none)
[task 2023-03-01T19:47:47.459Z] 19:47:47 INFO - 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:47:47.467Z] 19:47:47 INFO - WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:47:47.468Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:47:47.469Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:47:47.470Z] 19:47:47 INFO - setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:47:47.470Z] 19:47:47 INFO - @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:47:47.471Z] 19:47:47 INFO - @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:47:47.472Z] 19:47:47 INFO - @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:47:47.472Z] 19:47:47 INFO - _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:47:47.473Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:47:47.474Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:47:47.474Z] 19:47:47 INFO - setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:47:47.475Z] 19:47:47 INFO - observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:47:47.493Z] 19:47:47 INFO - WARNING: A blocker encountered an error while we were waiting.
[task 2023-03-01T19:47:47.493Z] 19:47:47 INFO - Blocker: TelemetryController: shutting down
[task 2023-03-01T19:47:47.494Z] 19:47:47 INFO - Phase: profile-before-change-telemetry
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - 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:47:47.495Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:47:47.495Z] 19:47:47 INFO - setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:47:47.496Z] 19:47:47 INFO - observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:47:47.498Z] 19:47:47 INFO - 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:47:47.501Z] 19:47:47 INFO - WARNING: addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:727:15
[task 2023-03-01T19:47:47.502Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:523:26
[task 2023-03-01T19:47:47.502Z] 19:47:47 INFO - addBlocker@resource://gre/modules/AsyncShutdown.sys.mjs:458:15
[task 2023-03-01T19:47:47.503Z] 19:47:47 INFO - setupShutdown@resource://gre/modules/osfile/osfile_async_front.jsm:1548:28
[task 2023-03-01T19:47:47.503Z] 19:47:47 INFO - @resource://gre/modules/osfile/osfile_async_front.jsm:1568:16
[task 2023-03-01T19:47:47.504Z] 19:47:47 INFO - @resource://gre/modules/osfile.jsm:12:30
[task 2023-03-01T19:47:47.505Z] 19:47:47 INFO - @resource://gre/modules/TelemetryStorage.sys.mjs:10:28
[task 2023-03-01T19:47:47.505Z] 19:47:47 INFO - _checkPendingPings@resource://gre/modules/TelemetrySend.sys.mjs:863:17
[task 2023-03-01T19:47:47.506Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:803:18
[task 2023-03-01T19:47:47.507Z] 19:47:47 INFO - setup@resource://gre/modules/TelemetrySend.sys.mjs:241:30
[task 2023-03-01T19:47:47.508Z] 19:47:47 INFO - setupTelemetry/this._delayedInitTask<@resource://gre/modules/TelemetryControllerParent.sys.mjs:823:36
[task 2023-03-01T19:47:47.509Z] 19:47:47 INFO - observe@resource://gre/modules/AsyncShutdown.sys.mjs:576:16
[task 2023-03-01T19:47:47.527Z] 19:47:47 INFO - 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:47:47.529Z] 19:47:47 INFO - 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:47:47.531Z] 19:47:47 INFO - 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:47:47.533Z] 19:47:47 INFO - 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:47:47.535Z] 19:47:47 INFO - 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:47:47.536Z] 19:47:47 INFO - 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:47:52.269Z] 19:47:52 INFO - REFTEST INFO | Process mode: e10s
[task 2023-03-01T19:47:52.270Z] 19:47:52 WARNING - leakcheck | refcount logging is off, so leaks can't be detected!
[task 2023-03-01T19:47:52.271Z] 19:47:52 INFO - REFTEST INFO | Running tests in file:///builds/worker/workspace/build/tests/reftest/tests/editor/reftests/xul/reftest.list
[task 2023-03-01T19:47:52.280Z] 19:47:52 INFO - REFTEST INFO | Running with e10s: True
[task 2023-03-01T19:47:52.281Z] 19:47:52 INFO - REFTEST INFO | Running with fission: True
[task 2023-03-01T19:47:52.282Z] 19:47:52 INFO - REFTEST INFO | INFO | runtests.py | TSan using symbolizer at /builds/worker/workspace/build/application/firefox/llvm-symbolizer
[task 2023-03-01T19:47:52.282Z] 19:47:52 INFO - REFTEST INFO | Application command: /builds/worker/workspace/build/application/firefox/firefox -marionette -profile /tmp/tmpgn8rp824.mozrunner
[task 2023-03-01T19:47:55.746Z] 19:47:55 INFO - ATTENTION: default value of option mesa_glthread overridden by environment.
[task 2023-03-01T19:47:55.763Z] 19:47:55 INFO - Inconsistency detected by ld.so: ../elf/dl-tls.c: 481: _dl_allocate_tls_init: Assertion `listp->slotinfo[cnt].gen <= GL(dl_tls_generation)' failed!
[task 2023-03-01T19:50:52.333Z] 19:50:52 ERROR - TEST-UNEXPECTED-FAIL | Last test finished | application terminated with exit code 127
[task 2023-03-01T19:50:52.337Z] 19:50:52 INFO - Traceback (most recent call last):
[task 2023-03-01T19:50:52.338Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 1168, in <module>
[task 2023-03-01T19:50:52.339Z] 19:50:52 INFO - sys.exit(run_test_harness(parser, options))
[task 2023-03-01T19:50:52.339Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 1160, in run_test_harness
[task 2023-03-01T19:50:52.340Z] 19:50:52 INFO - result = reftest.runTests(options.tests, options)
[task 2023-03-01T19:50:52.340Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 710, in runTests
[task 2023-03-01T19:50:52.341Z] 19:50:52 INFO - return self.runSerialTests(manifests, options, cmdargs)
[task 2023-03-01T19:50:52.343Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 1105, in runSerialTests
[task 2023-03-01T19:50:52.343Z] 19:50:52 INFO - status = run(tests=tests)
[task 2023-03-01T19:50:52.344Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 1075, in run
[task 2023-03-01T19:50:52.344Z] 19:50:52 INFO - **kwargs
[task 2023-03-01T19:50:52.345Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 1004, in runApp
[task 2023-03-01T19:50:52.346Z] 19:50:52 INFO - raise reraise(exc, value, tb)
[task 2023-03-01T19:50:52.346Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2023-03-01T19:50:52.346Z] 19:50:52 INFO - raise value
[task 2023-03-01T19:50:52.346Z] 19:50:52 INFO - File "/builds/worker/workspace/build/tests/reftest/runreftest.py", line 961, in runApp
[task 2023-03-01T19:50:52.347Z] 19:50:52 INFO - marionette.start_session()
[task 2023-03-01T19:50:52.347Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 34, in _
[task 2023-03-01T19:50:52.348Z] 19:50:52 INFO - m._handle_socket_failure()
[task 2023-03-01T19:50:52.348Z] 19:50:52 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:50:52.349Z] 19:50:52 INFO - reraise(exc_cls, exc, tb)
[task 2023-03-01T19:50:52.350Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/six.py", line 696, in reraise
[task 2023-03-01T19:50:52.350Z] 19:50:52 INFO - raise value
[task 2023-03-01T19:50:52.351Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/decorators.py", line 24, in _
[task 2023-03-01T19:50:52.351Z] 19:50:52 INFO - return func(*args, **kwargs)
[task 2023-03-01T19:50:52.352Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 1252, in start_session
[task 2023-03-01T19:50:52.352Z] 19:50:52 INFO - self.raise_for_port(timeout=timeout)
[task 2023-03-01T19:50:52.353Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/marionette_driver/marionette.py", line 633, in raise_for_port
[task 2023-03-01T19:50:52.353Z] 19:50:52 INFO - self.host, self.port
[task 2023-03-01T19:50:52.354Z] 19:50:52 INFO - socket.timeout: Timed out waiting for connection on 127.0.0.1:2828!
[task 2023-03-01T19:50:52.366Z] 19:50:52 INFO - Exception ignored in: <bound method BaseProfile.__del__ of <mozprofile.profile.Profile object at 0x7f090e1bc0b8>>
[task 2023-03-01T19:50:52.367Z] 19:50:52 INFO - Traceback (most recent call last):
[task 2023-03-01T19:50:52.367Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozprofile/profile.py", line 84, in __del__
[task 2023-03-01T19:50:52.368Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozprofile/profile.py", line 294, in cleanup
[task 2023-03-01T19:50:52.369Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozprofile/profile.py", line 92, in cleanup
[task 2023-03-01T19:50:52.369Z] 19:50:52 INFO - File "/builds/worker/workspace/build/venv/lib/python3.6/site-packages/mozfile/mozfile.py", line 247, in remove
[task 2023-03-01T19:50:52.370Z] 19:50:52 INFO - ImportError: sys.meta_path is None, Python is likely shutting down
[task 2023-03-01T19:50:52.391Z] 19:50:52 INFO - Return code: 1
[task 2023-03-01T19:50:52.392Z] 19:50:52 ERROR - No suite end message was emitted by this harness.
[task 2023-03-01T19:50:52.393Z] 19:50:52 INFO - TinderboxPrint: reftest-reftest<br/>738/0/7
[task 2023-03-01T19:50:52.393Z] 19:50:52 WARNING - setting return code to 2
[task 2023-03-01T19:50:52.394Z] 19:50:52 INFO - The reftest suite: reftest ran with return status: FAILURE
[task 2023-03-01T19:50:52.395Z] 19:50:52 INFO - Running post-action listener: _package_coverage_data
[task 2023-03-01T19:50:52.395Z] 19:50:52 INFO - Running post-action listener: _resource_record_post_action
[task 2023-03-01T19:50:52.395Z] 19:50:52 INFO - Running post-action listener: process_java_coverage_data
[task 2023-03-01T19:50:52.396Z] 19:50:52 INFO - [mozharness: 2023-03-01 19:50:52.393840Z] Finished run-tests step (success)
[task 2023-03-01T19:50:52.396Z] 19:50:52 INFO - [mozharness: 2023-03-01 19:50:52.393993Z] Running uninstall step.
[task 2023-03-01T19:50:52.397Z] 19:50:52 INFO - Running pre-action listener: _resource_record_pre_action
[task 2023-03-01T19:50:52.397Z] 19:50:52 INFO - Running main action method: uninstall
[task 2023-03-01T19:50:52.398Z] 19:50:52 INFO - Skipping uninstall for non-MSIX test
[task 2023-03-01T19:50:52.398Z] 19:50:52 INFO - Running post-action listener: _resource_record_post_action
[task 2023-03-01T19:50:52.398Z] 19:50:52 INFO - [mozharness: 2023-03-01 19:50:52.394496Z] Finished uninstall step (success)
[task 2023-03-01T19:50:52.399Z] 19:50:52 INFO - Running post-run listener: _resource_record_post_run
[task 2023-03-01T19:50:52.477Z] 19:50:52 INFO - Validating Perfherder data against /builds/worker/workspace/mozharness/external_tools/performance-artifact-schema.json
[task 2023-03-01T19:50:52.481Z] 19:50:52 INFO - PERFHERDER_DATA: {"framework": {"name": "job_resource_usage"}, "suites": [{"name": "reftest.reftest.1.overall", "extraOptions": ["e10s", "taskcluster-projects/887720501152/machineTypes/n2-standard-2"], "subtests": [{"name": "cpu_percent", "value": 61.96936353829559}, {"name": "io_write_bytes", "value": 2929422336}, {"name": "io.read_bytes", "value": 39624704}, {"name": "io_write_time", "value": 1111308}, {"name": "io_read_time", "value": 568}]}, {"name": "reftest.reftest.1.start-pulseaudio", "subtests": [{"name": "time", "value": 0.04024004936218262}, {"name": "cpu_percent", "value": 0}]}, {"name": "reftest.reftest.1.install", "subtests": [{"name": "time", "value": 41.66942477226257}, {"name": "cpu_percent", "value": 50.665}]}, {"name": "reftest.reftest.1.stage-files", "subtests": [{"name": "time", "value": 0.0007646083831787109}, {"name": "cpu_percent", "value": 0}]}, {"name": "reftest.reftest.1.run-tests", "subtests": [{"name": "time", "value": 887.6572947502136}, {"name": "cpu_percent", "value": 62.5036723163842}]}, {"name": "reftest.reftest.1.uninstall", "subtests": [{"name": "time", "value": 0.00026988983154296875}, {"name": "cpu_percent", "value": 0}]}]}
[task 2023-03-01T19:50:52.482Z] 19:50:52 INFO - Total resource usage - Wall time: 928s; CPU: Can't collect data; Read bytes: 39624704; Write bytes: 2929422336; Read time: 568; Write time: 1111308
[task 2023-03-01T19:50:52.483Z] 19:50:52 INFO - TinderboxPrint: I/O read bytes / time<br/>39,624,704 / 568
[task 2023-03-01T19:50:52.483Z] 19:50:52 INFO - TinderboxPrint: I/O write bytes / time<br/>2,929,422,336 / 1,111,308
[task 2023-03-01T19:50:52.484Z] 19:50:52 INFO - TinderboxPrint: CPU idle<br/>702.6 (38.0%)
[task 2023-03-01T19:50:52.484Z] 19:50:52 INFO - TinderboxPrint: CPU system<br/>103.8 (5.6%)
[task 2023-03-01T19:50:52.485Z] 19:50:52 INFO - TinderboxPrint: CPU user<br/>1,039.9 (56.2%)
[task 2023-03-01T19:50:52.485Z] 19:50:52 INFO - TinderboxPrint: Swap in / out<br/>0 / 0
[task 2023-03-01T19:50:52.485Z] 19:50:52 INFO - start-pulseaudio - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-03-01T19:50:52.486Z] 19:50:52 INFO - install - Wall time: 42s; CPU: 51%; Read bytes: 204800; Write bytes: 964886528; Read time: 0; Write time: 194384
[task 2023-03-01T19:50:52.486Z] 19:50:52 INFO - stage-files - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-03-01T19:50:52.489Z] 19:50:52 INFO - run-tests - Wall time: 888s; CPU: 63%; Read bytes: 39043072; Write bytes: 1964343296; Read time: 560; Write time: 916908
[task 2023-03-01T19:50:52.490Z] 19:50:52 INFO - uninstall - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-03-01T19:50:52.590Z] 19:50:52 WARNING - returning nonzero exit status 2
[task 2023-03-01T19:50:52.630Z] cleanup
[task 2023-03-01T19:50:52.630Z] + cleanup
[task 2023-03-01T19:50:52.630Z] + local rv=2
[task 2023-03-01T19:50:52.630Z] + [[ -s /builds/worker/.xsession-errors ]]
[task 2023-03-01T19:50:52.630Z] + cp /builds/worker/.xsession-errors /builds/worker/artifacts/public/xsession-errors.log
[task 2023-03-01T19:50:52.633Z] + '[' ']'
[task 2023-03-01T19:50:52.633Z] + true
[task 2023-03-01T19:50:52.633Z] + cleanup_xvfb
[task 2023-03-01T19:50:52.634Z] ++ pidof Xvfb
[task 2023-03-01T19:50:52.641Z] + local xvfb_pid=49
[task 2023-03-01T19:50:52.641Z] + local vnc=false
[task 2023-03-01T19:50:52.644Z] + local interactive=false
[task 2023-03-01T19:50:52.645Z] + '[' -n 49 ']'
[task 2023-03-01T19:50:52.645Z] + [[ false == false ]]
[task 2023-03-01T19:50:52.645Z] + [[ false == false ]]
[task 2023-03-01T19:50:52.649Z] + kill 49
[task 2023-03-01T19:50:52.649Z] + screen -XS xvfb quit
[task 2023-03-01T19:50:52.694Z] No screen session found.
[task 2023-03-01T19:50:52.695Z] + true
[task 2023-03-01T19:50:52.696Z] + exit 2
[taskcluster 2023-03-01 19:50:53.479Z] === Task Finished ===
[taskcluster 2023-03-01 19:50:56.203Z] Unsuccessful task run with exit code: 2 completed in 1157.507 seconds
|
||
Comment 1•2 years ago
|
||
Looks like the proximal issue (right before ERROR - TEST-UNEXPECTED-FAIL) was:
INFO - Inconsistency detected by ld.so: ../elf/dl-tls.c: 481: _dl_allocate_tls_init: Assertion `listp->slotinfo[cnt].gen <= GL(dl_tls_generation)' failed!
|
|
||
Comment 2•2 years ago
|
||
I found this same error message in a few other bugs' test-failure logs, so I filed bug 1819763 on the general issue and I'll dupe things over there.
You need to log in
before you can comment on or make changes to this bug.
Description
•