Closed Bug 1719799 Opened 5 years ago Closed 5 years ago

Intermittent [TCw] TEST-UNEXPECTED-TIMEOUT | /WebCryptoAPI/getRandomValues-bigint.tentative.any.worker.html | TestRunner hit external timeout (this may indicate a hang)

Categories

(Core :: DOM: Web Crypto, defect, P5)

Product:
Core
Component:
DOM: Web Crypto
Type:
defect

Tracking

()

Status:
RESOLVED INVALID

People

(Reporter: intermittent-bug-filer, Unassigned)

References

(Regression)

Details

(Keywords: intermittent-failure, regression)

Filed by: apavel [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer?job_id=344762735&repo=mozilla-central
Full log: https://firefox-ci-tc.services.mozilla.com/api/queue/v1/task/QuSmastBRMqsg39iPgdDOA/runs/0/artifacts/public/logs/live_backing.log

[task 2021-07-09T06:22:26.185Z] 06:22:26     INFO - TEST-START | /WebCryptoAPI/getRandomValues-bigint.tentative.any.worker.html
[task 2021-07-09T06:22:26.274Z] 06:22:26     INFO - PID 7424 | [CodeCoverage] Requested flush for 1684.
[task 2021-07-09T06:22:31.944Z] 06:22:31     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:32.131Z] 06:22:32     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:22:32.132Z] 06:22:32     INFO - PID 7424 | [CodeCoverage] Requested flush for 5344.
[task 2021-07-09T06:22:32.133Z] 06:22:32     INFO - PID 7424 | [CodeCoverage] Requested flush for 6044.
[task 2021-07-09T06:22:32.133Z] 06:22:32     INFO - PID 7424 | [CodeCoverage] Requested flush for 7296.
[task 2021-07-09T06:22:32.133Z] 06:22:32     INFO - PID 7424 | [CodeCoverage] Requested flush for 6496.
[task 2021-07-09T06:22:35.975Z] 06:22:35     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:35.983Z] 06:22:35     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:22:39.672Z] 06:22:39     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:39.679Z] 06:22:39     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:22:43.431Z] 06:22:43     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:43.445Z] 06:22:43     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:22:47.471Z] 06:22:47     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:47.476Z] 06:22:47     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:22:48.238Z] 06:22:48     INFO - PID 7424 | [CodeCoverage] Requested flush for 1684.
[task 2021-07-09T06:22:49.976Z] 06:22:49     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:50.127Z] 06:22:50     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:22:50.128Z] 06:22:50     INFO - PID 7424 | [CodeCoverage] Requested flush for 5344.
[task 2021-07-09T06:22:50.129Z] 06:22:50     INFO - PID 7424 | [CodeCoverage] Requested flush for 6044.
[task 2021-07-09T06:22:50.129Z] 06:22:50     INFO - PID 7424 | [CodeCoverage] Requested flush for 7296.
[task 2021-07-09T06:22:50.129Z] 06:22:50     INFO - PID 7424 | [CodeCoverage] Requested flush for 6496.
[task 2021-07-09T06:22:57.104Z] 06:22:57     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:22:57.118Z] 06:22:57     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:23:01.030Z] 06:23:01     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:23:01.038Z] 06:23:01     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:23:01.191Z] 06:23:01     INFO - Got timeout in harness
[task 2021-07-09T06:23:01.193Z] 06:23:01     INFO - TEST-UNEXPECTED-TIMEOUT | /WebCryptoAPI/getRandomValues-bigint.tentative.any.worker.html | TestRunner hit external timeout (this may indicate a hang)
[task 2021-07-09T06:23:01.193Z] 06:23:01     INFO - TEST-INFO took 35008ms
[task 2021-07-09T06:23:04.821Z] 06:23:04     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:23:04.834Z] 06:23:04     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:23:08.580Z] 06:23:08     INFO - PID 7424 | [CodeCoverage] flush completed.
[task 2021-07-09T06:23:08.584Z] 06:23:08     INFO - PID 7424 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:12.307Z] 06:24:12     INFO - Browser exited with return code 572
[task 2021-07-09T06:24:22.309Z] 06:24:22  WARNING - Forcibly terminating runner process
[task 2021-07-09T06:24:22.355Z] 06:24:22     INFO - Application command: Z:\task_1625811428\build\application\firefox\firefox.exe -marionette about:blank --wait-for-browser -profile C:\Users\task_1625811428\AppData\Local\Temp\tmpzd7shkos
[task 2021-07-09T06:24:22.358Z] 06:24:22     INFO - Starting runner
[task 2021-07-09T06:24:23.109Z] 06:24:23     INFO - PID 6712 | 1625811863109	Marionette	INFO	Marionette enabled
[task 2021-07-09T06:24:24.892Z] 06:24:24     INFO - PID 6712 | console.warn: SearchSettings: "get: No settings file exists, new profile?" (new NotFoundError("Could not open the file at C:\\Users\\task_1625811428\\AppData\\Local\\Temp\\tmpzd7shkos\\search.json.mozlz4", (void 0)))
[task 2021-07-09T06:24:26.204Z] 06:24:26     INFO - PID 6712 | 1625811866204	Marionette	INFO	Listening on port 50131
[task 2021-07-09T06:24:26.282Z] 06:24:26     INFO - PID 6712 | ###!!! [Parent][RunMessage] Error: Channel closing: too late to send/recv, messages will be lost
[task 2021-07-09T06:24:26.889Z] 06:24:26     INFO - TEST-START | /WebCryptoAPI/getRandomValues-bigint.tentative.any.html
task 2021-07-09T06:24:26.912Z] 06:24:26     INFO - PID 6712 | [CodeCoverage] Requested flush for 7848.
[task 2021-07-09T06:24:32.881Z] 06:24:32     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:33.106Z] 06:24:33     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:33.107Z] 06:24:33     INFO - PID 6712 | [CodeCoverage] Requested flush for 8832.
[task 2021-07-09T06:24:33.108Z] 06:24:33     INFO - PID 6712 | [CodeCoverage] Requested flush for 11180.
[task 2021-07-09T06:24:33.108Z] 06:24:33     INFO - PID 6712 | [CodeCoverage] Requested flush for 7052.
[task 2021-07-09T06:24:33.109Z] 06:24:33     INFO - PID 6712 | [CodeCoverage] Requested flush for 2368.
[task 2021-07-09T06:24:36.903Z] 06:24:36     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:36.911Z] 06:24:36     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:40.593Z] 06:24:40     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:40.601Z] 06:24:40     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:44.292Z] 06:24:44     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:44.306Z] 06:24:44     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:48.109Z] 06:24:48     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:48.114Z] 06:24:48     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:49.088Z] 06:24:49     INFO - PID 6712 | [CodeCoverage] Requested flush for 7848.
[task 2021-07-09T06:24:52.919Z] 06:24:52     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:53.069Z] 06:24:53     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:24:53.071Z] 06:24:53     INFO - PID 6712 | [CodeCoverage] Requested flush for 8832.
[task 2021-07-09T06:24:53.071Z] 06:24:53     INFO - PID 6712 | [CodeCoverage] Requested flush for 11180.
[task 2021-07-09T06:24:53.072Z] 06:24:53     INFO - PID 6712 | [CodeCoverage] Requested flush for 7052.
[task 2021-07-09T06:24:53.072Z] 06:24:53     INFO - PID 6712 | [CodeCoverage] Requested flush for 2368.
[task 2021-07-09T06:24:56.812Z] 06:24:56     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:24:56.825Z] 06:24:56     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:25:00.520Z] 06:25:00     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:25:00.527Z] 06:25:00     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:25:01.895Z] 06:25:01     INFO - Got timeout in harness
[task 2021-07-09T06:25:01.897Z] 06:25:01     INFO - TEST-UNEXPECTED-TIMEOUT | /WebCryptoAPI/getRandomValues-bigint.tentative.any.html | TestRunner hit external timeout (this may indicate a hang)
[task 2021-07-09T06:25:01.897Z] 06:25:01     INFO - TEST-INFO took 35008ms
[task 2021-07-09T06:25:01.897Z] 06:25:01     INFO - No more tests
[task 2021-07-09T06:25:04.497Z] 06:25:04     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:25:04.510Z] 06:25:04     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:25:08.290Z] 06:25:08     INFO - PID 6712 | [CodeCoverage] flush completed.
[task 2021-07-09T06:25:08.294Z] 06:25:08     INFO - PID 6712 | [CodeCoverage] JS flush completed.
[task 2021-07-09T06:26:13.006Z] 06:26:13     INFO - Browser exited with return code 572

This test was added in bug 1718932. Timothy - if this becomes an issue, can you have a look?

Flags: needinfo?(timothygu99)
Regressed by: 1718932
Has Regression Range: --- → yes
Keywords: regression

Seems pretty similar to bug 1262688, bug 1328789, bug 1329585, and bug 1495700. It seems to be occurring fairly infrequently, so I'll just close it.

Status: NEW → RESOLVED
Closed: 5 years ago
Flags: needinfo?(timothygu99)
Resolution: --- → INVALID
You need to log in before you can comment on or make changes to this bug.