1582970 - Perma linux64 CCov browser-chrome [taskcluster:error] Task timeout after 7200 seconds. Force killing container.

Status: RESOLVED FIXED

(Testing :: Code Coverage, defect, P5)

Description

[Treeherder Bug Filer]

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

---

[task 2019-09-21T15:38:54.380Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for mozstd-trackwhite-digest256
[task 2019-09-21T15:38:54.380Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for base-cryptomining-track-digest256
[task 2019-09-21T15:38:54.382Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for mozstd-trackwhite-digest256
[task 2019-09-21T15:38:54.382Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for base-cryptomining-track-digest256
[task 2019-09-21T15:38:54.382Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for mozstd-trackwhite-digest256
[task 2019-09-21T15:38:54.383Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for social-tracking-protection-digest256
[task 2019-09-21T15:38:54.383Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for social-tracking-protection-facebook-digest256
[task 2019-09-21T15:38:54.383Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for social-tracking-protection-linkedin-digest256
[task 2019-09-21T15:38:54.386Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for social-tracking-protection-twitter-digest256
[task 2019-09-21T15:38:54.386Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Enabling table updates for mozstd-trackwhite-digest256
[task 2019-09-21T15:38:54.387Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Starting managing lists
[task 2019-09-21T15:38:54.388Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): needsUpdate: {
[task 2019-09-21T15:38:54.388Z] 15:38:54 INFO - GECKO(7204) | "http://127.0.0.1:8888/safebrowsing4-dummy/update": {
[task 2019-09-21T15:38:54.388Z] 15:38:54 INFO - GECKO(7204) | "goog-phish-proto": true,
[task 2019-09-21T15:38:54.388Z] 15:38:54 INFO - GECKO(7204) | "goog-malware-proto": true,
[task 2019-09-21T15:38:54.389Z] 15:38:54 INFO - GECKO(7204) | "goog-unwanted-proto": true,
[task 2019-09-21T15:38:54.389Z] 15:38:54 INFO - GECKO(7204) | "goog-passwordwhite-proto": false,
[task 2019-09-21T15:38:54.389Z] 15:38:54 INFO - GECKO(7204) | "goog-badbinurl-proto": true,
[task 2019-09-21T15:38:54.390Z] 15:38:54 INFO - GECKO(7204) | "goog-downloadwhite-proto": true
[task 2019-09-21T15:38:54.390Z] 15:38:54 INFO - GECKO(7204) | },
[task 2019-09-21T15:38:54.390Z] 15:38:54 INFO - GECKO(7204) | "http://127.0.0.1:8888/safebrowsing-dummy/update": {
[task 2019-09-21T15:38:54.390Z] 15:38:54 INFO - GECKO(7204) | "mozplugin-block-digest256": true,
[task 2019-09-21T15:38:54.391Z] 15:38:54 INFO - GECKO(7204) | "allow-flashallow-digest256": true,
[task 2019-09-21T15:38:54.391Z] 15:38:54 INFO - GECKO(7204) | "except-flashallow-digest256": true,
[task 2019-09-21T15:38:54.391Z] 15:38:54 INFO - GECKO(7204) | "block-flash-digest256": true,
[task 2019-09-21T15:38:54.393Z] 15:38:54 INFO - GECKO(7204) | "except-flash-digest256": true,
[task 2019-09-21T15:38:54.394Z] 15:38:54 INFO - GECKO(7204) | "block-flashsubdoc-digest256": true,
[task 2019-09-21T15:38:54.394Z] 15:38:54 INFO - GECKO(7204) | "except-flashsubdoc-digest256": true,
[task 2019-09-21T15:38:54.394Z] 15:38:54 INFO - GECKO(7204) | "base-fingerprinting-track-digest256": true,
[task 2019-09-21T15:38:54.394Z] 15:38:54 INFO - GECKO(7204) | "base-cryptomining-track-digest256": true,
[task 2019-09-21T15:38:54.394Z] 15:38:54 INFO - GECKO(7204) | "social-tracking-protection-digest256": true,
[task 2019-09-21T15:38:54.397Z] 15:38:54 INFO - GECKO(7204) | "social-tracking-protection-facebook-digest256": true,
[task 2019-09-21T15:38:54.397Z] 15:38:54 INFO - GECKO(7204) | "social-tracking-protection-linkedin-digest256": true,
[task 2019-09-21T15:38:54.397Z] 15:38:54 INFO - GECKO(7204) | "social-tracking-protection-twitter-digest256": true,
[task 2019-09-21T15:38:54.398Z] 15:38:54 INFO - GECKO(7204) | "mozstd-trackwhite-digest256": true
[task 2019-09-21T15:38:54.399Z] 15:38:54 INFO - GECKO(7204) | }
[task 2019-09-21T15:38:54.399Z] 15:38:54 INFO - GECKO(7204) | }
[task 2019-09-21T15:38:54.400Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Initializing update checker for http://127.0.0.1:8888/safebrowsing4-dummy/update provided by google4
[task 2019-09-21T15:38:54.400Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Next update 0min from now
[task 2019-09-21T15:38:54.401Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Initializing update checker for http://127.0.0.1:8888/safebrowsing-dummy/update provided by mozilla
[task 2019-09-21T15:38:54.401Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Next update at 1
[task 2019-09-21T15:38:54.401Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Next update 0min from now
[task 2019-09-21T15:38:54.437Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): checkForUpdates with http://127.0.0.1:8888/safebrowsing-dummy/update
[task 2019-09-21T15:38:54.438Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): Can't make update request
[task 2019-09-21T15:38:54.438Z] 15:38:54 INFO - GECKO(7204) | listmanager: 15:38:54 GMT+0000 (Coordinated Universal Time): download error for mozplugin-block-digest256,allow-flashallow-digest256,except-flashallow-digest256,block-flash-digest256,except-flash-digest256,block-flashsubdoc-digest256,except-flashsubdoc-digest256,base-fingerprinting-track-digest256,base-cryptomining-track-digest256,social-tracking-protection-digest256,social-tracking-protection-facebook-digest256,social-tracking-protection-linkedin-digest256,social-tracking-protection-twitter-digest256,mozstd-trackwhite-digest256: 404
[task 2019-09-21T15:38:54.567Z] 15:38:54 INFO - GECKO(7204) | --DOMWINDOW == 3 (0x7fa8b4b0f000) [pid = 7368] [serial = 1592] [outer = (nil)] [url = about:blank]
[task 2019-09-21T15:38:54.567Z] 15:38:54 INFO - GECKO(7204) | --DOMWINDOW == 2 (0x7fa8b4b0f400) [pid = 7368] [serial = 1593] [outer = (nil)] [url = https://tracking.example.org/browser/toolkit/components/antitracking/test/browser/3rdParty.html]
[task 2019-09-21T15:38:54.630Z] 15:38:54 INFO - GECKO(7204) | ++DOCSHELL 0x7fa8b570a800 == 1 [pid = 7368] [id = {4cdf4780-0217-478e-910d-5f107ba0103a}]
[task 2019-09-21T15:38:54.630Z] 15:38:54 INFO - GECKO(7204) | ++DOMWINDOW == 3 (0x7fa8b53403e0) [pid = 7368] [serial = 1594] [outer = (nil)]
[task 2019-09-21T15:38:54.631Z] 15:38:54 INFO - GECKO(7204) | ++DOMWINDOW == 4 (0x7fa8b4b03c00) [pid = 7368] [serial = 1595] [outer = 0x7fa8b53403e0]
[task 2019-09-21T15:38:54.753Z] 15:38:54 INFO - GECKO(7204) | --DOMWINDOW == 3 (0x7fa8b5340200) [pid = 7368] [serial = 1588] [outer = (nil)] [url = http://example.net/browser/toolkit/components/antitracking/test/browser/page.html]
[task 2019-09-21T15:38:54.983Z] 15:38:54 INFO - GECKO(7204) | ++DOMWINDOW == 4 (0x7fa8b4b0cc00) [pid = 7368] [serial = 1596] [outer = 0x7fa8b53403e0]
[task 2019-09-21T15:38:55.383Z] 15:38:55 INFO - GECKO(7204) | ++DOMWINDOW == 5 (0x7fa8b4b11c00) [pid = 7368] [serial = 1597] [outer = 0x7fa8b53403e0]
[task 2019-09-21T15:38:55.501Z] 15:38:55 INFO - GECKO(7204) | ++DOCSHELL 0x7fa8b5734000 == 2 [pid = 7368] [id = {40b39b98-0216-4ea5-8c8b-2abe14e7d623}]
[task 2019-09-21T15:38:55.501Z] 15:38:55 INFO - GECKO(7204) | ++DOMWINDOW == 6 (0x7fa8b5340020) [pid = 7368] [serial = 1598] [outer = (nil)]
[task 2019-09-21T15:38:55.503Z] 15:38:55 INFO - GECKO(7204) | [Child 7368, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T15:38:55.503Z] 15:38:55 INFO - GECKO(7204) | [Child 7368, Main Thread] WARNING: '!mWindow->GetCurrentInnerWindow()', file /builds/worker/workspace/build/src/dom/ipc/nsQueryActor.h, line 20
[task 2019-09-21T15:38:55.504Z] 15:38:55 INFO - GECKO(7204) | ++DOMWINDOW == 7 (0x7fa8b531a000) [pid = 7368] [serial = 1599] [outer = 0x7fa8b5340020]
[task 2019-09-21T15:38:55.765Z] 15:38:55 INFO - GECKO(7204) | ++DOMWINDOW == 8 (0x7fa8b4b11400) [pid = 7368] [serial = 1600] [outer = 0x7fa8b5340020]
[task 2019-09-21T15:38:55.908Z] 15:38:55 INFO - GECKO(7204) | --DOMWINDOW == 7 (0x7fa8b4b0a400) [pid = 7368] [serial = 1590] [outer = (nil)] [url = http://example.net/browser/toolkit/components/antitracking/test/browser/page.html]
[task 2019-09-21T15:38:56.179Z] 15:38:56 INFO - GECKO(7204) | ++DOMWINDOW == 8 (0x7fa8b531a800) [pid = 7368] [serial = 1601] [outer = 0x7fa8b53403e0]

[taskcluster:error] Task timeout after 7200 seconds. Force killing container.
[taskcluster 2019-09-21 15:38:56.884Z] === Task Finished ===
[taskcluster 2019-09-21 15:38:56.884Z] Unsuccessful task run with exit code: -1 completed in 7201.844 seconds

Comment 1

[Cosmin Sabou [:CosminS]]

Started with this merge here: https://treeherder.mozilla.org/#/jobs?repo=mozilla-central&group_state=expanded&searchStr=linux%2Cx64%2Cccov%2Cdebug%2Cmochitests%2Ctest-linux64-ccov%2Fdebug-mochitest-browser-chrome-e10s-11%2Cm%28bc11%29&tochange=de5a09d263ff557012c5872a9edfb276ca1e353f&fromchange=c221a75fbf2957b6254fedb96436b5efbf0fd147&selectedJob=267810137
Geoff, can you please take a look over what's going on here? Thank you

Added jobs here: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&fromchange=d5760163d949c957f5155984e3718aa59701d075&tochange=69aa8e7e33d5d417e4d40f83accd36a275fccd08&searchStr=linux%2Cx64%2Cccov%2Cdebug%2Cmochitests%2Ctest-linux64-ccov%2Fdebug-mochitest-browser-chrome-e10s

Comment 2

[Intermittent Failures Robot]

7 failures in 4350 pushes (0.002 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• mozilla-central: 7

Platform breakdown:

• linux64-ccov: 7

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

Comment 3

[Geoff Brown [:gbrown]]

I just increased the max-run-time for these tasks in bug 1582241.

Comment 4

[Geoff Brown [:gbrown]]

...and that was primarily to allow for the extra time required for antitracking tests, fixed in bug 1580606.

These timeouts are again in the chunk containing antitracking tests.

Failures appear perma on some builds, but come and go across builds, with successful runs completing in the 110 - 120 minute range.

Since most linux64 ccov browser-chrome chunks complete in about 30 minutes, I think we can only increase max-run-time further, unless we want to skip the antitracking tests on ccov.

Comment 5

[Geoff Brown [:gbrown]]

Attachment: Bug 1582970 - Increase max-run-time for linux64 ccov browser-chrome; r=marco

The recent increase was not quite enough: Allow another 30 minutes for linux64
ccov browser-chrome.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/9c77e87effb3
Increase max-run-time for linux64 ccov browser-chrome; r=marco

Comment 7

[Cosmin Sabou [:CosminS]]

https://hg.mozilla.org/mozilla-central/rev/9c77e87effb3

Comment 8

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• linux64-ccov: 1

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