1577598 - Intermittent [taskcluster:error] Task timeout after 1800 seconds. Force killing container. After warning: sparse profile 'build/sparse-profiles/webrender' not found in rev 000000000000 - ignoring it

Status: RESOLVED DUPLICATE of bug 1589796

(Taskcluster :: General, defect, P5)

Description

[Treeherder Bug Filer]

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

---

vcs 2019-08-29T15:53:50.446Z] new changesets b52fcec46987
[vcs 2019-08-29T15:53:52.818Z] (setting sparse config to profile build/sparse-profiles/webrender)
[vcs 2019-08-29T15:53:52.821Z] 0 files added, 0 files dropped, 0 files conflicting
[vcs 2019-08-29T15:53:52.821Z] (sparse refresh complete)
[vcs 2019-08-29T15:53:54.336Z] warning: sparse profile 'build/sparse-profiles/webrender' not found in rev 000000000000 - ignoring it
[vcs 2019-08-29T15:53:58.252Z]
[vcs 2019-08-29T15:53:59.266Z] updating [ ] 100/12952
[vcs 2019-08-29T15:54:00.345Z] updating [=========> ] 2710/12952 04s
[vcs 2019-08-29T15:54:01.346Z] updating [=================> ] 4710/12952 04s
[vcs 2019-08-29T15:54:02.184Z] updating [==================================> ] 8730/12952 02s
[vcs 2019-08-29T15:54:02.419Z]
[vcs 2019-08-29T15:54:02.419Z] 12952 files updated, 0 files merged, 0 files removed, 0 files unresolved
[vcs 2019-08-29T15:54:02.460Z] updated to e9268d2f323358d07eaf690515108508d6d7588e
[vcs 2019-08-29T15:54:02.463Z] PERFHERDER_DATA: {"framework": {"name": "vcs"}, "suites": [{"extraOptions": ["c5.4xlarge"], "lowerIsBetter": true, "name": "clone", "serverUrl": "us-west-2.hgmointernal.net", "shouldAlert": false, "subtests": [], "value": 1061.3723449707031}, {"extraOptions": ["c5.4xlarge"], "lowerIsBetter": true, "name": "sparse_update_config", "serverUrl": "us-west-2.hgmointernal.net", "shouldAlert": false, "subtests": [], "value": 0.0028960704803466797}, {"extraOptions": ["c5.4xlarge"], "lowerIsBetter": true, "name": "update_sparse", "serverUrl": "us-west-2.hgmointernal.net", "shouldAlert": false, "subtests": [], "value": 9.638661861419678}, {"extraOptions": ["c5.4xlarge"], "lowerIsBetter": true, "name": "overall", "serverUrl": "us-west-2.hgmointernal.net", "shouldAlert": false, "subtests": [], "value": 1073.8918249607086}, {"extraOptions": ["c5.4xlarge"], "lowerIsBetter": true, "name": "overall_clone", "serverUrl": "us-west-2.hgmointernal.net", "shouldAlert": false, "subtests": [], "value": 1073.8918249607086}, {"extraOptions": ["c5.4xlarge"], "lowerIsBetter": true, "name": "overall_clone_fullcheckout", "serverUrl": "us-west-2.hgmointernal.net", "shouldAlert": false, "subtests": [], "value": 1073.8918249607086}]}
[vcs 2019-08-29T15:54:02.743Z] TinderboxPrint:<a href=https://us-west-2.hgmointernal.net/releases/mozilla-beta/rev/e9268d2f323358d07eaf690515108508d6d7588e title='Built from mozilla-beta revision e9268d2f323358d07eaf690515108508d6d7588e'>e9268d2f323358d07eaf690515108508d6d7588e</a>
[setup 2019-08-29T15:54:02.743Z] GECKO_PATH is /builds/worker/checkouts/gecko
[setup 2019-08-29T15:54:02.743Z] MOZ_FETCHES_DIR is /builds/worker/fetches
[fetches 2019-08-29T15:54:02.743Z] fetching artifacts
[fetches 2019-08-29T15:54:02.743Z] executing ['/usr/bin/python3', '-u', '/builds/worker/checkouts/gecko/taskcluster/scripts/misc/fetch-content', 'task-artifacts']
[fetches 2019-08-29T15:54:02.813Z] attempt 1/5
[fetches 2019-08-29T15:54:02.813Z] attempt 1/5
[fetches 2019-08-29T15:54:02.813Z] Downloading https://queue.taskcluster.net/v1/task/QGh5kyQPS3OXPX0NGW8vFg/artifacts/public/build/rustc.tar.xz to /builds/worker/fetches/rustc.tar.xz
[fetches 2019-08-29T15:54:02.813Z] Downloading https://queue.taskcluster.net/v1/task/Hc-JG4f0T-2T2eeMkyU8mg/artifacts/public/build/cctools.tar.xz to /builds/worker/fetches/cctools.tar.xz
[fetches 2019-08-29T15:54:02.813Z] Downloading https://queue.taskcluster.net/v1/task/QGh5kyQPS3OXPX0NGW8vFg/artifacts/public/build/rustc.tar.xz
[fetches 2019-08-29T15:54:02.813Z] Downloading https://queue.taskcluster.net/v1/task/Hc-JG4f0T-2T2eeMkyU8mg/artifacts/public/build/cctools.tar.xz
[fetches 2019-08-29T15:54:02.815Z] attempt 1/5
[fetches 2019-08-29T15:54:02.815Z] attempt 1/5
[fetches 2019-08-29T15:54:02.815Z] attempt 1/5
[fetches 2019-08-29T15:54:02.815Z] Downloading https://queue.taskcluster.net/v1/task/KKzWMWv0RoigH6SXSz2k1w/artifacts/public/build/clang.tar.xz to /builds/worker/fetches/clang.tar.xz
[fetches 2019-08-29T15:54:02.815Z] Downloading https://queue.taskcluster.net/v1/task/TnUClsLNQcaaaNQV_jU8PQ/artifacts/public/build/wrench-deps.tar.bz2 to /builds/worker/fetches/wrench-deps.tar.bz2
[fetches 2019-08-29T15:54:02.816Z] Downloading https://queue.taskcluster.net/v1/task/DVjFdpqPSQ-jNWxbnnFFzw/artifacts/public/build/llvm-dsymutil.tar.xz to /builds/worker/fetches/llvm-dsymutil.tar.xz
[fetches 2019-08-29T15:54:02.816Z] Downloading https://queue.taskcluster.net/v1/task/KKzWMWv0RoigH6SXSz2k1w/artifacts/public/build/clang.tar.xz
[fetches 2019-08-29T15:54:02.816Z] Downloading https://queue.taskcluster.net/v1/task/TnUClsLNQcaaaNQV_jU8PQ/artifacts/public/build/wrench-deps.tar.bz2
[fetches 2019-08-29T15:54:02.816Z] Downloading https://queue.taskcluster.net/v1/task/DVjFdpqPSQ-jNWxbnnFFzw/artifacts/public/build/llvm-dsymutil.tar.xz
[fetches 2019-08-29T15:54:03.445Z] https://queue.taskcluster.net/v1/task/Hc-JG4f0T-2T2eeMkyU8mg/artifacts/public/build/cctools.tar.xz resolved to 2480200 bytes with sha256 bd816d30a7c916fb86f1b3373ef13ddcad70578482cebca4878208f2ee520f5d in 0.631s
[fetches 2019-08-29T15:54:03.445Z] Extracting /builds/worker/fetches/cctools.tar.xz to /builds/worker/fetches
[fetches 2019-08-29T15:54:03.706Z] https://queue.taskcluster.net/v1/task/DVjFdpqPSQ-jNWxbnnFFzw/artifacts/public/build/llvm-dsymutil.tar.xz resolved to 6896964 bytes with sha256 62405ade2f7a4d19f52a5856f533680dd900a2a4b3902858139670154b621ab3 in 0.890s
[fetches 2019-08-29T15:54:03.706Z] Extracting /builds/worker/fetches/llvm-dsymutil.tar.xz to /builds/worker/fetches
[fetches 2019-08-29T15:54:04.334Z] /builds/worker/fetches/cctools.tar.xz extracted in 0.889s
[fetches 2019-08-29T15:54:04.334Z] Removing /builds/worker/fetches/cctools.tar.xz
[fetches 2019-08-29T15:54:06.694Z] /builds/worker/fetches/llvm-dsymutil.tar.xz extracted in 2.988s
[fetches 2019-08-29T15:54:06.694Z] Removing /builds/worker/fetches/llvm-dsymutil.tar.xz
[fetches 2019-08-29T15:54:08.574Z] https://queue.taskcluster.net/v1/task/TnUClsLNQcaaaNQV_jU8PQ/artifacts/public/build/wrench-deps.tar.bz2 resolved to 36315999 bytes with sha256 c9720b3108b12af6a32e04d4943449f2d79397adc52dd9fc93157a5ac826b6af in 5.758s
[fetches 2019-08-29T15:54:08.574Z] Extracting /builds/worker/fetches/wrench-deps.tar.bz2 to /builds/worker/fetches
[fetches 2019-08-29T15:59:36.806Z] https://queue.taskcluster.net/v1/task/KKzWMWv0RoigH6SXSz2k1w/artifacts/public/build/clang.tar.xz resolved to 190531864 bytes with sha256 76f0e0891070202744b608090d44d0b982634fc93b3c206c169334b9a79efb68 in 333.990s
[fetches 2019-08-29T15:59:36.807Z] Extracting /builds/worker/fetches/clang.tar.xz to /builds/worker/fetches
[fetches 2019-08-29T16:00:29.810Z] https://queue.taskcluster.net/v1/task/QGh5kyQPS3OXPX0NGW8vFg/artifacts/public/build/rustc.tar.xz resolved to 228143336 bytes with sha256 83f444046007d0278774aae606d2c8fa4a054770f23ab882b418a198af49b623 in 386.996s
[fetches 2019-08-29T16:00:29.810Z] Extracting /builds/worker/fetches/rustc.tar.xz to /builds/worker/fetches
[fetches 2019-08-29T16:03:48.602Z] /builds/worker/fetches/wrench-deps.tar.bz2 extracted in 580.028s
[fetches 2019-08-29T16:03:48.602Z] Removing /builds/worker/fetches/wrench-deps.tar.bz2
[taskcluster:error] Task timeout after 1800 seconds. Force killing container.
[taskcluster 2019-08-29 16:06:10.848Z] === Task Finished ===
[taskcluster 2019-08-29 16:06:10.850Z] Unsuccessful task run with exit code: -1 completed in 1954.907 seconds

Comment 1

[Bogdan Tara[:bogdan_tara | bogdant]]

Glandium, is this your domain? Could you, please, take a look?

Comment 2

[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-beta: 1
• mozilla-central: 1

Platform breakdown:

• macosx64-qr: 1
• linux64-qr: 1

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

Comment 3

[Mike Hommey [:glandium]]

Things like this happen sometimes:
[vcs 2019-08-29T15:52:52.467Z] transferred 3.02 GB in 1003.2 seconds (3.08 MB/sec)

And that's a us-west-2 ec2 instance downloading from us-west-2 S3. I don't know what we can do about that, apart from avoiding the transfer in the first place, but maybe there's something that's simply wrong in our configuration or something that'd be worth looking at. Tentatively redirecting to Dustin.

Comment 4

[Dustin J. Mitchell [:dustin] (he/him)]

We see stuff like this occasionally. Since it's so rare, there's no way to investigate further, but my hunch has always been some hiccup in the AWS networks -- maybe something that trips up PMTU discovery or shrinks the TCP window size. It could also be a failover in S3, where some frontend layer took a while to detect a failure in one backend component. Anyway, all conjecture -- bottom line is, S3's good most of the time, but has a nonzero probability of slow transfers (and a nonzero probability of random 5xx's).

Comment 5

[Intermittent Failures Robot]

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

Repository breakdown:

• mozilla-central: 1

Platform breakdown:

• osx-cross: 1

For more details, see:
https://treeherder.mozilla.org/intermittent-failures.html#/bugdetails?bug=1577598&startday=2020-02-10&endday=2020-02-16&tree=all