1561474 - Intermittent bgo/run [taskcluster:error] Aborting task...

Status: RESOLVED FIXED

(Firefox Build System :: General, defect)

Description

[Treeherder Bug Filer]

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

---

[vcs 2019-06-26T00:16:06.941Z] updating [==============================================> ] 271200/279523 49s
[vcs 2019-06-26T00:16:09.324Z] updating [==============================================> ] 271500/279523 47s
[vcs 2019-06-26T00:16:13.330Z] updating [==============================================> ] 271800/279523 46s
[vcs 2019-06-26T00:16:15.466Z] updating [==============================================> ] 271900/279523 48s
[vcs 2019-06-26T00:16:16.525Z] updating [==============================================> ] 272200/279523 46s
[taskcluster:error] Aborting task...
[taskcluster 2019-06-26T00:16:17.503Z] SUCCESS: The process with PID 4076 (child process of PID 1252) has been terminated.
[taskcluster 2019-06-26T00:16:17.503Z] SUCCESS: The process with PID 3896 (child process of PID 912) has been terminated.
[taskcluster 2019-06-26T00:16:17.503Z] SUCCESS: The process with PID 1252 (child process of PID 912) has been terminated.
[taskcluster 2019-06-26T00:16:17.503Z] SUCCESS: The process with PID 912 (child process of PID 2604) has been terminated.
[taskcluster 2019-06-26T00:16:17.503Z]
[taskcluster 2019-06-26T00:16:17.503Z] === Task Finished ===
[taskcluster 2019-06-26T00:16:17.503Z] Task Duration: 20m0.0650428s
[taskcluster:error] Uploading error artifact public/build/profdata.tar.xz from file build/src/artifacts/profdata.tar.xz with message "Could not read file 'Z:\task_1561498049\build\src\artifacts\profdata.tar.xz'", reason "file-missing-on-worker" and expiry 2020-06-24T23:03:07.896Z
[taskcluster:error] TASK FAILURE during artifact upload: file-missing-on-worker: Could not read file 'Z:\task_1561498049\build\src\artifacts\profdata.tar.xz'
[taskcluster:error] Uploading error artifact public/build/profile-run-1.log from file build/src/artifacts/profile-run-1.log with message "Could not read file 'Z:\task_1561498049\build\src\artifacts\profile-run-1.log'", reason "file-missing-on-worker" and expiry 2020-06-24T23:03:07.896Z
[taskcluster:error] TASK FAILURE during artifact upload: file-missing-on-worker: Could not read file 'Z:\task_1561498049\build\src\artifacts\profile-run-1.log'
[taskcluster:error] Uploading error artifact public/build/profile-run-2.log from file build/src/artifacts/profile-run-2.log with message "Could not read file 'Z:\task_1561498049\build\src\artifacts\profile-run-2.log'", reason "file-missing-on-worker" and expiry 2020-06-24T23:03:07.896Z
[taskcluster:error] TASK FAILURE during artifact upload: file-missing-on-worker: Could not read file 'Z:\task_1561498049\build\src\artifacts\profile-run-2.log'
[taskcluster 2019-06-26T00:16:19.011Z] [mounts] Preserving cache: Moving "Z:\task_1561498049\build" to "Z:\caches\ER9TlNX1T1GKloovEhAybQ"
[taskcluster 2019-06-26T00:16:19.622Z] [mounts] Denying task_1561498049 access to 'Z:\caches\ER9TlNX1T1GKloovEhAybQ'
[taskcluster 2019-06-26T00:17:00.481Z] Uploading redirect artifact public/logs/live.log to URL https://queue.taskcluster.net/v1/task/GJNVH_zbSCqZBoEzixtKUw/runs/0/artifacts/public/logs/live_backing.log with mime type "text/plain; charset=utf-8" and expiry 2020-06-24T23:03:07.896Z
[taskcluster:error] Task aborted - max run time exceeded
[taskcluster:error] file-missing-on-worker: Could not read file 'Z:\task_1561498049\build\src\artifacts\profdata.tar.xz'
[taskcluster:error] file-missing-on-worker: Could not read file 'Z:\task_1561498049\build\src\artifacts\profile-run-1.log'
[taskcluster:error] file-missing-on-worker: Could not read file 'Z:\task_1561498049\build\src\artifacts\profile-run-2.log'

Comment 1

[Michael Shal [:mshal]]

Looks like it took the whole task runtime just trying to clone the tree. If this happens more frequently, we can try just bumping the timeout to ignore the issue, or look into why cloning is slow. :sheehan, any ideas what might've happened here?

Comment 2

[Connor Sheehan [:sheehan]]

(In reply to Michael Shal [:mshal] from comment #1)

Looks like it took the whole task runtime just trying to clone the tree. If this happens more frequently, we can try just bumping the timeout to ignore the issue, or look into why cloning is slow. :sheehan, any ideas what might've happened here?

On a first glace there are a few things I notice that seem wrong here:

• The vcs checkout directory and the cache don't seem to be mounted to the local filesystem (or at least I think that is what that message means?).
• The vcs step that is taking so long here is actually the "update", aka creating the working directory of the files, not cloning the repo.
• The task was unable to fetch the hgmointernal secret (this is probably unrelated to the bug, but out of place nonetheless).

Given the second point, I think this is an issue with filesystem performance. I believe EC2 has these kinds of issues when a new instance is bootstrapped from an AMI (the first read/write is extremely slow IIRC). The first point in the above list may be contributing as well.

Comment 3

[Intermittent Failures Robot]

14 failures in 4409 pushes (0.003 failures/push) were associated with this bug in the last 7 days.

Repository breakdown:

• autoland: 13
• mozilla-central: 1

Platform breakdown:

• windows2012-64-shippable: 13
• windows2012-32-shippable: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1561474&startday=2019-06-24&endday=2019-06-30&tree=all

Comment 4

[Intermittent Failures Robot]

19 failures in 848 pushes (0.022 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 17
• mozilla-central: 2

Platform breakdown:

• windows2012-64-shippable: 11
• windows10-64-ccov: 1
• windows2012-32-shippable: 7

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1561474&startday=2019-07-03&endday=2019-07-03&tree=all

Comment 5

[Dorel Luca [:dluca]]

This bug failed 46 times in the last 7 days. On windows2012-64-shippable and windows2012-32-shippable on opt build types.

Recent log:
https://treeherder.mozilla.org/logviewer.html#?job_id=255041763&repo=autoland

Comment 6

[Intermittent Failures Robot]

47 failures in 3501 pushes (0.013 failures/push) were associated with this bug in the last 7 days.

This is the #37 most frequent failure this week.

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

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

Repository breakdown:

• autoland: 41
• mozilla-central: 5
• oak: 1

Platform breakdown:

• windows2012-32-shippable: 23
• windows2012-64-shippable: 23
• windows10-64-ccov: 1

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

Comment 7

[Intermittent Failures Robot]

19 failures in 1090 pushes (0.017 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 17
• mozilla-inbound: 2

Platform breakdown:

• windows2012-32-shippable: 10
• windows2012-64-shippable: 9

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

Comment 8

[Intermittent Failures Robot]

30 failures in 1024 pushes (0.029 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 23
• mozilla-beta: 1
• mozilla-central: 4
• mozilla-inbound: 2

Platform breakdown:

• windows2012-64-shippable: 12
• windows2012-32-shippable: 18

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1561474&startday=2019-07-10&endday=2019-07-10&tree=all

Comment 9

[Michael Shal [:mshal]]

Attachment: Bug 1561474 - Define and use a sparse profile for the profile-run task; r?sheehan

This was originally from bug 1528374 for Mac PGO, but that isn't able to
land yet and it should help Windows PGO runs in the meantime.

Comment 10

[Michael Shal [:mshal]]

Attachment: Bug 1561474 - Use sparse-profile on Windows generate tasks; r?#firefox-build-system-reviewers

Depends on D37807

Comment 11

[Intermittent Failures Robot]

18 failures in 893 pushes (0.02 failures/push) were associated with this bug yesterday.

Repository breakdown:

• autoland: 12
• mozilla-central: 3
• mozilla-inbound: 1
• mozilla-beta: 2

Platform breakdown:

• windows2012-64-shippable: 4
• windows2012-32-shippable: 13
• windows10-64-ccov: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1561474&startday=2019-07-11&endday=2019-07-11&tree=all

Comment 12

[Intermittent Failures Robot]

16 failures in 837 pushes (0.019 failures/push) were associated with this bug yesterday.

** This test has failed more than 150 times in the last 21 days. It should be disabled until it can be fixed. **

Repository breakdown:

• mozilla-inbound: 2
• autoland: 14

Platform breakdown:

• windows2012-64-shippable: 8
• windows2012-32-shippable: 8

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

Comment 13

[Intermittent Failures Robot]

93 failures in 4710 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-inbound: 9
• autoland: 74
• mozilla-beta: 3
• mozilla-central: 7

Platform breakdown:

• windows2012-32-shippable: 54
• windows2012-64-shippable: 38
• windows10-64-ccov: 1

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

Comment 14

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/d501a16ad338
Define and use a sparse profile for the profile-run task; r=sheehan
https://hg.mozilla.org/integration/autoland/rev/155d964c8be4
Use sparse-profile on Windows generate tasks; r=firefox-build-system-reviewers,chmanchester

Comment 15

[Alexandru Michis [:malexandru]]

https://hg.mozilla.org/mozilla-central/rev/d501a16ad338
https://hg.mozilla.org/mozilla-central/rev/155d964c8be4

Comment 16

[Ryan VanderMeulen [:RyanVM]]

Looks like this is hitting Beta also. Please request approval if you're comfortable doing so.

Comment 17

[Michael Shal [:mshal]]

Comment on attachment 9077560 [details]
Bug 1561474 - Use sparse-profile on Windows generate tasks; r?#firefox-build-system-reviewers

Beta/Release Uplift Approval Request

• User impact if declined: Impacts sheriffing the beta tree, since Windows 'run' tasks will intermittently fail without these patches. Does not impact the final shipped product.
• Is this code covered by automated tests?: No
• Has the fix been verified in Nightly?: Yes
• Needs manual test from QE?: No
• If yes, steps to reproduce:
• List of other uplifts needed: None
• Risk to taking this patch: Low
• Why is the change risky/not risky? (and alternatives if risky): This change modifies how many files are checked out by hg before the profile generation step runs. If there are any issues importing the patch, it should be an obvious failure when the 'run' tasks is scheduled.
• String changes made/needed: none

Comment 18

[Ryan VanderMeulen [:RyanVM]]

Comment on attachment 9077559 [details]
Bug 1561474 - Define and use a sparse profile for the profile-run task; r?sheehan

Fixes some intermittent build failures on Windows. Doesn't affect the resulting builds, just how much we checkout at the start of the build. Approved for 69.0b6.

Comment 19

[Andreea Pavel [:apavel]]

https://hg.mozilla.org/releases/mozilla-beta/rev/4335c2b0fb72
https://hg.mozilla.org/releases/mozilla-beta/rev/128eaae4deb4

Comment 20

[Intermittent Failures Robot]

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

Repository breakdown:

• autoland: 2
• mozilla-inbound: 1

Platform breakdown:

• windows2012-64-shippable: 1
• windows2012-32-shippable: 2

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1561474&startday=2019-07-15&endday=2019-07-21&tree=all