1864922 - Intermittent ::: Test verification FAIL TinderboxPrint: Per-test run of ...\opening-handshake\006.html<br/>: FAILURE

Status: RESOLVED FIXED

(Core :: Networking: WebSockets, defect, P2)

Description

[Treeherder Bug Filer]

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

---

[task 2023-11-15T16:55:24.275Z] 16:55:24     INFO - | `WebSockets: Serialized connection attempts` | PASS    |          |
[task 2023-11-15T16:55:24.276Z] 16:55:24     INFO - 
[task 2023-11-15T16:55:24.276Z] 16:55:24     INFO - ## Slow tests ##
[task 2023-11-15T16:55:24.276Z] 16:55:24     INFO - 
[task 2023-11-15T16:55:24.277Z] 16:55:24     INFO - |                       Test                       | Result | Longest duration (ms) | Timeout (ms) |
[task 2023-11-15T16:55:24.277Z] 16:55:24     INFO - |--------------------------------------------------|--------|-----------------------|--------------|
[task 2023-11-15T16:55:24.278Z] 16:55:24     INFO - | `/websockets/opening-handshake/006.html?wss`     | `OK`   | `9478`                | `10000`      |
[task 2023-11-15T16:55:24.279Z] 16:55:24     INFO - | `/websockets/opening-handshake/006.html?default` | `OK`   | `8410`                | `10000`      |
[task 2023-11-15T16:55:24.279Z] 16:55:24     INFO - 
[task 2023-11-15T16:55:24.279Z] 16:55:24     INFO - ::: Running tests in a loop 10 times : FAIL
[task 2023-11-15T16:55:24.280Z] 16:55:24     INFO - :::
[task 2023-11-15T16:55:24.280Z] 16:55:24    ERROR - ::: Test verification FAIL
[task 2023-11-15T16:55:24.281Z] 16:55:24     INFO - :::
[task 2023-11-15T16:55:24.681Z] 16:55:24     INFO - Return code: 1
[task 2023-11-15T16:55:24.697Z] 16:55:24  WARNING - setting return code to 2
[task 2023-11-15T16:55:24.697Z] 16:55:24    ERROR - TinderboxPrint: Per-test run of ...\opening-handshake\006.html<br/>: FAILURE
[task 2023-11-15T16:55:24.697Z] 16:55:24     INFO - Running post-action listener: _package_coverage_data
[task 2023-11-15T16:55:24.697Z] 16:55:24     INFO - Running post-action listener: _resource_record_post_action
[task 2023-11-15T16:55:24.697Z] 16:55:24     INFO - Running post-action listener: process_java_coverage_data
[task 2023-11-15T16:55:24.697Z] 16:55:24     INFO - Running post-action listener: stop_device
[task 2023-11-15T16:55:24.697Z] 16:55:24     INFO - [mozharness: 2023-11-15 16:55:24.697792Z] Finished run-tests step (success)
[task 2023-11-15T16:55:24.697Z] 16:55:24     INFO - Running post-run listener: _resource_record_post_run
[task 2023-11-15T16:55:24.885Z] 16:55:24     INFO - Total resource usage - Wall time: 105s; CPU: 28%; Read bytes: 485575168; Write bytes: 609276928; Read time: 52; Write time: 51
[task 2023-11-15T16:55:24.885Z] 16:55:24     INFO - TinderboxPrint: CPU usage<br/>28.2%
[task 2023-11-15T16:55:24.885Z] 16:55:24     INFO - TinderboxPrint: I/O read bytes / time<br/>485,575,168 / 52
[task 2023-11-15T16:55:24.885Z] 16:55:24     INFO - TinderboxPrint: I/O write bytes / time<br/>609,276,928 / 51
[task 2023-11-15T16:55:24.895Z] 16:55:24     INFO - TinderboxPrint: CPU idle<br/>599.9 (72.0%)
[task 2023-11-15T16:55:24.895Z] 16:55:24     INFO - TinderboxPrint: CPU system<br/>79.3 (9.5%)
[task 2023-11-15T16:55:24.895Z] 16:55:24     INFO - TinderboxPrint: CPU user<br/>153.6 (18.4%)
[task 2023-11-15T16:55:24.895Z] 16:55:24     INFO - pull - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-11-15T16:55:24.895Z] 16:55:24     INFO - start-emulator - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-11-15T16:55:24.895Z] 16:55:24     INFO - verify-device - Wall time: 0s; CPU: Can't collect data; Read bytes: 0; Write bytes: 0; Read time: 0; Write time: 0
[task 2023-11-15T16:55:24.896Z] 16:55:24     INFO - install - Wall time: 3s; CPU: 40%; Read bytes: 1332224; Write bytes: 21362176; Read time: 0; Write time: 1
[task 2023-11-15T16:55:24.903Z] 16:55:24     INFO - run-tests - Wall time: 102s; CPU: 28%; Read bytes: 484242944; Write bytes: 587790848; Read time: 52; Write time: 50
[task 2023-11-15T16:55:25.213Z] 16:55:25  WARNING - returning nonzero exit status 2
[taskcluster 2023-11-15T16:55:25.682Z]    Exit Code: 2
[taskcluster 2023-11-15T16:55:25.682Z]    User Time: 0s
[taskcluster 2023-11-15T16:55:25.682Z]  Kernel Time: 0s
[taskcluster 2023-11-15T16:55:25.682Z]    Wall Time: 10m6.3738249s
[taskcluster 2023-11-15T16:55:25.682Z]       Result: FAILED
[taskcluster 2023-11-15T16:55:25.682Z] === Task Finished ===
[taskcluster 2023-11-15T16:55:25.682Z] Task Duration: 10m6.375937s
[taskcluster 2023-11-15T16:55:25.910Z] Uploading artifact public/logs/localconfig.json from file Z:\task_170006658020475\logs\localconfig.json with content encoding "gzip", mime type "application/json" and expiry 2024-11-14T15:53:25.018Z
[taskcluster 2023-11-15T16:55:26.189Z] Uploading artifact public/test_info/profile_resource-usage.json from file Z:\task_170006658020475\build\blobber_upload_dir\profile_resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-11-14T15:53:25.018Z
[taskcluster 2023-11-15T16:55:26.434Z] Uploading artifact public/test_info/resource-usage.json from file Z:\task_170006658020475\build\blobber_upload_dir\resource-usage.json with content encoding "gzip", mime type "application/json" and expiry 2024-11-14T15:53:25.018Z
[taskcluster 2023-11-15T16:55:26.710Z] Uploading artifact public/test_info/wpt-test1_errorsummary.log from file Z:\task_170006658020475\build\blobber_upload_dir\wpt-test1_errorsummary.log with content encoding "gzip", mime type "text/plain" and expiry 2024-11-14T15:53:25.018Z
[taskcluster 2023-11-15T16:55:26.934Z] Uploading artifact public/test_info/wpt_instruments.txt from file Z:\task_170006658020475\build\blobber_upload_dir\wpt_instruments.txt with content encoding "gzip", mime type "text/plain; charset=utf-8" and expiry 2024-11-14T15:53:25.018Z
[taskcluster 2023-11-15T16:55:27.159Z] Uploading artifact public/test_info/wptreport.json from file Z:\task_170006658020475\build\blobber_upload_dir\wptreport.json with content encoding "gzip", mime type "application/json" and expiry 2024-11-14T15:53:25.018Z
[taskcluster 2023-11-15T16:55:27.390Z] Uploading link artifact public/logs/live.log to artifact public/logs/live_backing.log with expiry 2024-11-14T15:53:25.018Z
[taskcluster:error] exit status 2

Comment 1

[BugBot [:suhaib / :marco/ :calixte]]

:acreskey, since you are the author of the regressor, bug 1816258, could you take a look?

For more information, please visit BugBot documentation.

Comment 2

[Intermittent Failures Robot]

4 failures in 3495 pushes (0.001 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 4

Platform and build breakdown:

• windows11-32-2009-qr: 1
  • opt: 1
• windows11-64-2009-qr: 1
  • opt: 1
• macosx1015-64-qr: 1
  • opt: 1
• linux1804-64-qr: 1
  • opt: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?bug=1864922&startday=2023-11-13&endday=2023-11-19&tree=all

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

Set release status flags based on info from the regressing bug 1816258

Comment 4

[Andrew Creskey [:acreskey]]

This is a longer-running test because it tests three failures in a row, so I've re-landed it with the wpt flag for longer tests
<meta name="timeout" content="long">

Comment 5

[Andrew Creskey [:acreskey]]

This looks to be fixed with my last patch here as I no longer see any failures:
https://treeherder.mozilla.org/intermittent-failures/bugdetails?startday=2023-10-28&endday=2023-11-27&tree=all&failurehash=all&bug=1864922

But I'll give it a few more days.

Comment 6

[Andrew Creskey [:acreskey]]

I haven't seen a single failure since the fix so I am closing.