1573633 - Intermittent TEST-UNEXPECTED-TIMEOUT | dom/security/test/csp/test_worker_src.html | application timed out after 370 seconds with no output

Status: RESOLVED DUPLICATE of bug 1576316

(Core :: DOM: Security, defect, P5)

Description

[Treeherder Bug Filer]

Filed by: dvarga [at] mozilla.com
Parsed log: https://treeherder.mozilla.org/logviewer.html#?job_id=261370837&repo=mozilla-central
Full log: https://queue.taskcluster.net/v1/task/FfGI_5F_QKiQjyn9zGPfbw/runs/0/artifacts/public/logs/live_backing.log

---

[task 2019-08-13T17:02:48.150Z] 17:02:48     INFO - TEST-START | dom/security/test/csp/test_worker_src.html
[task 2019-08-13T17:08:59.059Z] 17:08:59     INFO - Buffered messages logged at 17:02:48
[task 2019-08-13T17:08:59.060Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (worker-allowed) 
[task 2019-08-13T17:08:59.060Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (shared-worker-allowed) 
[task 2019-08-13T17:08:59.060Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (service-worker-allowed) 
[task 2019-08-13T17:08:59.061Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (shared-worker-allowed) 
[task 2019-08-13T17:08:59.062Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (worker-allowed) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (service-worker-allowed) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (shared-worker-allowed) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (worker-allowed) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | allowing worker from https://example.com (service-worker-allowed) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (service-worker-blocked) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (worker-blocked) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (shared-worker-blocked) 
[task 2019-08-13T17:08:59.063Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (shared-worker-blocked) 
[task 2019-08-13T17:08:59.064Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (service-worker-blocked) 
[task 2019-08-13T17:08:59.064Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (worker-blocked) 
[task 2019-08-13T17:08:59.065Z] 17:08:59     INFO - Buffered messages logged at 17:02:49
[task 2019-08-13T17:08:59.065Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (service-worker-blocked) 
[task 2019-08-13T17:08:59.065Z] 17:08:59     INFO - TEST-PASS | dom/security/test/csp/test_worker_src.html | blocking worker from https://test1.example.com (worker-blocked) 
[task 2019-08-13T17:08:59.066Z] 17:08:59     INFO - Buffered messages finished
[task 2019-08-13T17:08:59.066Z] 17:08:59    ERROR - TEST-UNEXPECTED-TIMEOUT | dom/security/test/csp/test_worker_src.html | application timed out after 370 seconds with no output
[task 2019-08-13T17:08:59.067Z] 17:08:59    ERROR - Force-terminating active process(es).
[task 2019-08-13T17:08:59.067Z] 17:08:59     INFO - Determining child pids from psutil...
[task 2019-08-13T17:08:59.071Z] 17:08:59     INFO - [1579, 1561, 1455, 2098, 1533, 1419]
[task 2019-08-13T17:08:59.071Z] 17:08:59     INFO - ==> process 1382 launched child process 1403
[task 2019-08-13T17:08:59.072Z] 17:08:59     INFO - ==> process 1382 launched child process 1419
[task 2019-08-13T17:08:59.072Z] 17:08:59     INFO - ==> process 1382 launched child process 1455
[task 2019-08-13T17:08:59.073Z] 17:08:59     INFO - ==> process 1382 launched child process 1474
[task 2019-08-13T17:08:59.073Z] 17:08:59     INFO - ==> process 1382 launched child process 1533
[task 2019-08-13T17:08:59.074Z] 17:08:59     INFO - ==> process 1382 launched child process 1561
[task 2019-08-13T17:08:59.074Z] 17:08:59     INFO - ==> process 1382 launched child process 1579
[task 2019-08-13T17:08:59.074Z] 17:08:59     INFO - ==> process 1382 launched child process 1628
[task 2019-08-13T17:08:59.075Z] 17:08:59     INFO - ==> process 1382 launched child process 1657
[task 2019-08-13T17:08:59.075Z] 17:08:59     INFO - ==> process 1382 launched child process 1687
[task 2019-08-13T17:08:59.075Z] 17:08:59     INFO - ==> process 1382 launched child process 1715
[task 2019-08-13T17:08:59.076Z] 17:08:59     INFO - ==> process 1382 launched child process 1806
[task 2019-08-13T17:08:59.076Z] 17:08:59     INFO - ==> process 1382 launched child process 1836
[task 2019-08-13T17:08:59.077Z] 17:08:59     INFO - ==> process 1382 launched child process 1866
[task 2019-08-13T17:08:59.077Z] 17:08:59     INFO - ==> process 1382 launched child process 1894
[task 2019-08-13T17:08:59.077Z] 17:08:59     INFO - ==> process 1382 launched child process 1922
[task 2019-08-13T17:08:59.078Z] 17:08:59     INFO - ==> process 1382 launched child process 1950
[task 2019-08-13T17:08:59.078Z] 17:08:59     INFO - ==> process 1382 launched child process 1981
[task 2019-08-13T17:08:59.079Z] 17:08:59     INFO - ==> process 1382 launched child process 2009
[task 2019-08-13T17:08:59.079Z] 17:08:59     INFO - ==> process 1382 launched child process 2037
[task 2019-08-13T17:08:59.079Z] 17:08:59     INFO - ==> process 1382 launched child process 2066
[task 2019-08-13T17:08:59.080Z] 17:08:59     INFO - ==> process 1382 launched child process 2098
[task 2019-08-13T17:08:59.080Z] 17:08:59     INFO - Found child pids: set([1922, 1419, 1806, 2066, 1687, 1561, 1950, 1579, 1836, 1455, 2098, 1715, 1981, 1474, 1866, 2009, 1628, 1894, 2037, 1657, 1403, 1533])
[task 2019-08-13T17:08:59.080Z] 17:08:59     INFO - Failed to get child procs
[task 2019-08-13T17:08:59.081Z] 17:08:59     INFO - Killing process: 1922
[task 2019-08-13T17:08:59.081Z] 17:08:59     INFO - TEST-INFO | started process screentopng
[task 2019-08-13T17:08:59.330Z] 17:08:59     INFO - TEST-INFO | screentopng: exit 0
[task 2019-08-13T17:08:59.331Z] 17:08:59     INFO - Can't trigger Breakpad, process no longer exists

Comment 1

[Intermittent Failures Robot]

1 failures in 4839 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573633&startday=2019-08-12&endday=2019-08-18&tree=all

Comment 2

[Natalia Csoregi [:nataliaCs]]

Looks like this started permafailing once Bug 1575609 has landed: https://treeherder.mozilla.org/#/jobs?repo=autoland&searchStr=linux%2Cx64%2Cdebug%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux64%2Fdebug-mochitest-fis-e10s-7%2Cm-fis%287%29&tochange=56e028fe22340309805ffcffd410625e560642c5&fromchange=b0d9e6296249fdfc7ad53fb69078832de77c6c56&selectedJob=263416756

Ehsan, could you please take a look? Thank you.

Comment 3

[Intermittent Failures Robot]

101 failures in 5073 pushes (0.02 failures/push) were associated with this bug in the last 7 days.

This is the #15 most frequent failure this week.

** This failure happened more than 75 times this week! Resolving this bug is a very high priority. **

** Try to resolve this bug as soon as possible. If unresolved for 1 week, the affected test(s) may be disabled. **

Repository breakdown:

• mozilla-central: 29
• autoland: 72

Platform breakdown:

• linux64: 79
• linux64-qr: 13
• windows10-64-qr: 5
• windows10-64: 4

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573633&startday=2019-08-19&endday=2019-08-25&tree=all

Comment 4

[(no longer active)]

My patch in bug 1576316 fixes this.

Comment 5

[Intermittent Failures Robot]

2 failures in 5047 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1
• try: 1

Platform breakdown:

• linux64-qr: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573633&startday=2019-08-26&endday=2019-09-01&tree=all

Comment 6

[Razvan Maries]

New occurrence after fix: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&resultStatus=success%2Cpending%2Crunning%2Ctestfailed%2Cbusted%2Cexception&classifiedState=unclassified&searchStr=linux%2Cx64%2Cquantumrender%2Copt%2Cmochitests%2Cwith%2Cfission%2Cenabled%2Ctest-linux64-qr%2Fopt-mochitest-fis-e10s-3%2Cm-fis%283%29&selectedJob=264675453

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=264675453&repo=mozilla-central&lineNumber=2197

Comment 7

[(no longer active)]

Only one occurrence after that landing, so extremely rare intermittent. Unfortunately don't have time to look into it further at the moment, sorry about that.

Comment 8

[Intermittent Failures Robot]

1 failures in 4408 pushes (0.0 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux64-qr: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1573633&startday=2019-09-02&endday=2019-09-08&tree=all