Closed Bug 1747047 Opened 4 years ago Closed 3 years ago

Intermittent [tier2] TVw TinderboxPrint: Per-test run of .../secure-context.https.html<br/>: FAILURE

Categories

(Core :: DOM: Service Workers, defect, P5)

Product:
Core
Component:
DOM: Service Workers
Type:
defect

Tracking

()

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

Details

(Keywords: intermittent-failure)

Filed by: abutkovits [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=361981983&repo=autoland
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/fvpWEXKUT3-YCaOV1XBF4Q/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/fvpWEXKUT3-YCaOV1XBF4Q/runs/0/artifacts/public/logs/live_backing.log&only_show_unexpected=1

[task 2021-12-21T10:07:13.366Z] 10:07:13     INFO - TEST-OK | /service-workers/service-worker/secure-context.https.html | took 8542ms
[task 2021-12-21T10:07:13.367Z] 10:07:13     INFO - No more tests
[task 2021-12-21T10:07:13.382Z] 10:07:13     INFO - PID 1701 | 1640081233381	Marionette	INFO	Stopped listening on port 49554
[task 2021-12-21T10:07:19.033Z] 10:07:19     INFO - PID 1701 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-12-21T10:07:19.671Z] 10:07:19     INFO - Browser exited with return code 0
[task 2021-12-21T10:07:19.675Z] 10:07:19     INFO - Closing logging queue
[task 2021-12-21T10:07:19.675Z] 10:07:19     INFO - queue closed
[task 2021-12-21T10:07:19.697Z] 10:07:19     INFO - Got 0 unexpected results, with 0 unexpected passes
[task 2021-12-21T10:07:19.697Z] 10:07:19     INFO - SUITE-END | took 127s
[task 2021-12-21T10:07:19.698Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:9000
[task 2021-12-21T10:07:19.764Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:8446
[task 2021-12-21T10:07:19.809Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:8445
[task 2021-12-21T10:07:19.848Z] 10:07:19     INFO - wptserve Close on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8888))
[task 2021-12-21T10:07:19.848Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:8000
[task 2021-12-21T10:07:19.851Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:8443
[task 2021-12-21T10:07:19.852Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:8444
[task 2021-12-21T10:07:19.884Z] 10:07:19     INFO - wptserve Stopped http server on 127.0.0.1:8003
[task 2021-12-21T10:07:20.082Z] 10:07:20     INFO - wptserve Close on: (<AddressFamily.AF_INET: 2>, <SocketKind.SOCK_STREAM: 1>, 6, '', ('127.0.0.1', 8889))
[task 2021-12-21T10:07:20.106Z] 10:07:20     INFO - wptserve Stopped http server on 127.0.0.1:8002
[task 2021-12-21T10:07:20.178Z] 10:07:20     INFO - wptserve Stopped http server on 127.0.0.1:8001
[task 2021-12-21T10:07:20.253Z] 10:07:20     INFO - Closing logging queue
[task 2021-12-21T10:07:20.253Z] 10:07:20     INFO - queue closed
[task 2021-12-21T10:07:20.257Z] 10:07:20     INFO - ## All results ##
[task 2021-12-21T10:07:20.257Z] 10:07:20     INFO - 
[task 2021-12-21T10:07:20.258Z] 10:07:20     INFO - ### /service-workers/service-worker/secure-context.https.html ###
[task 2021-12-21T10:07:20.258Z] 10:07:20     INFO - |                         Subtest                          | Results | Messages |
[task 2021-12-21T10:07:20.258Z] 10:07:20     INFO - |----------------------------------------------------------|---------|----------|
[task 2021-12-21T10:07:20.259Z] 10:07:20     INFO - |                                                          | OK      |          |
[task 2021-12-21T10:07:20.259Z] 10:07:20     INFO - | `Ensure service worker is bypassed in insecure contexts` | PASS    |          |
[task 2021-12-21T10:07:20.259Z] 10:07:20     INFO - 
[task 2021-12-21T10:07:20.260Z] 10:07:20     INFO - ## Slow tests ##
[task 2021-12-21T10:07:20.260Z] 10:07:20     INFO - 
[task 2021-12-21T10:07:20.260Z] 10:07:20     INFO - |                             Test                            | Result | Longest duration (ms) | Timeout (ms) |
[task 2021-12-21T10:07:20.261Z] 10:07:20     INFO - |-------------------------------------------------------------|--------|-----------------------|--------------|
[task 2021-12-21T10:07:20.261Z] 10:07:20     INFO - | `/service-workers/service-worker/secure-context.https.html` | `OK`   | `12786`               | `10000`      |
[task 2021-12-21T10:07:20.261Z] 10:07:20     INFO - 
[task 2021-12-21T10:07:20.262Z] 10:07:20     INFO - ::: Running tests in a loop 10 times : PASS
[task 2021-12-21T10:07:20.262Z] 10:07:20     INFO - ::: Running tests in a loop with restarts 5 times : PASS
[task 2021-12-21T10:07:20.262Z] 10:07:20     INFO - ::: Running tests in a loop 10 times with flags chaos_mode_flags=0xfb : FAIL
[task 2021-12-21T10:07:20.263Z] 10:07:20     INFO - :::
[task 2021-12-21T10:07:20.263Z] 10:07:20    ERROR - ::: Test verification FAIL
[task 2021-12-21T10:07:20.263Z] 10:07:20     INFO - :::
[task 2021-12-21T10:07:20.607Z] 10:07:20    ERROR - Return code: 1
[task 2021-12-21T10:07:20.607Z] 10:07:20    ERROR - # TBPL FAILURE #
[task 2021-12-21T10:07:20.607Z] 10:07:20  WARNING - setting return code to 2
[task 2021-12-21T10:07:20.608Z] 10:07:20    ERROR - TinderboxPrint: Per-test run of .../secure-context.https.html<br/>: FAILURE
[task 2021-12-21T10:07:20.608Z] 10:07:20     INFO - Running post-action listener: _package_coverage_data
[task 2021-12-21T10:07:20.608Z] 10:07:20     INFO - Running post-action listener: _resource_record_post_action
[task 2021-12-21T10:07:20.608Z] 10:07:20     INFO - Running post-action listener: process_java_coverage_data
[task 2021-12-21T10:07:20.608Z] 10:07:20     INFO - Running post-action listener: stop_device
[task 2021-12-21T10:07:20.608Z] 10:07:20     INFO - [mozharness: 2021-12-21 10:07:20.608551Z] Finished run-tests step (success)
[task 2021-12-21T10:07:20.608Z] 10:07:20     INFO - Running post-run listener: _resource_record_post_run
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - Total resource usage - Wall time: 212s; CPU: 7%; Read bytes: 88219648; Write bytes: 639983616; Read time: 1304; Write time: 1890
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: CPU usage<br/>7.4%
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: I/O read bytes / time<br/>88,219,648 / 1,304
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: I/O write bytes / time<br/>639,983,616 / 1,890
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: CPU idle<br/>2,349.4 (92.2%)
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: CPU system<br/>55.6 (2.2%)
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: CPU user<br/>142.9 (5.6%)
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - TinderboxPrint: Swap in / out<br/>323,141,632 / 0
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-12-21T10:07:20.688Z] 10:07:20     INFO - start-emulator - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-12-21T10:07:20.689Z] 10:07:20     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2021-12-21T10:07:20.689Z] 10:07:20     INFO - install - Wall time: 19s; CPU: 14%; Read bytes: 255047168; Write bytes: 254541824; Read time: 16896; Write time: 381
[task 2021-12-21T10:07:20.691Z] 10:07:20     INFO - run-tests - Wall time: 195s; CPU: 7%; Read bytes: 80932864; Write bytes: 384561152; Read time: 990; Write time: 1497
[task 2021-12-21T10:07:20.827Z] 10:07:20  WARNING - returning nonzero exit status 2
[taskcluster 2021-12-21T10:07:21.069Z]    Exit Code: 2
[taskcluster 2021-12-21T10:07:21.069Z]    User Time: 2m34.240845s
[taskcluster 2021-12-21T10:07:21.069Z]  Kernel Time: 41.520909s
[taskcluster 2021-12-21T10:07:21.069Z]    Wall Time: 4m45.285012s
[taskcluster 2021-12-21T10:07:21.069Z]       Result: FAILED

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: NEW → RESOLVED
Closed: 3 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.