Closed Bug 1447633 Opened 6 years ago Closed 4 years ago

Intermittent [taskcluster:error] Task timeout after 900 seconds. Force killing container.

Categories

(Testing :: General, defect, P5)

Product:
Testing
Component:
General
Version:
Version 3
Type:
defect

Tracking

(Not tracked)

Status:
RESOLVED INCOMPLETE

People

(Reporter: intermittent-bug-filer, Unassigned)

References

Details

(Keywords: intermittent-failure) 

Filed by: ncsoregi [at] mozilla.com

https://treeherder.mozilla.org/logviewer.html#?job_id=169265427&repo=mozilla-beta

https://queue.taskcluster.net/v1/task/ecGUeNkAR3SBYOIQZ2VvgA/runs/0/artifacts/public/logs/live_backing.log

[task 2018-03-20T18:58:42.140Z] executing ['bash', '-cx', 'cd /builds/worker/checkouts/gecko && ./mach python toolkit/crashreporter/tools/upload_symbols.py https://queue.taskcluster.net/v1/task/${ARTIFACT_TASKID}/artifacts/public/build/target.crashreporter-symbols-full.zip\n']
[task 2018-03-20T18:58:42.142Z] + cd /builds/worker/checkouts/gecko
[task 2018-03-20T18:58:42.142Z] + ./mach python toolkit/crashreporter/tools/upload_symbols.py https://queue.taskcluster.net/v1/task/Vx548tM8Rbe0VelyZVCRmA/artifacts/public/build/target.crashreporter-symbols-full.zip
[task 2018-03-20T18:58:42.663Z] New python executable in /builds/worker/checkouts/gecko/obj-x86_64-pc-linux-gnu/_virtualenv/bin/python2.7
[task 2018-03-20T18:58:42.663Z] Also creating executable in /builds/worker/checkouts/gecko/obj-x86_64-pc-linux-gnu/_virtualenv/bin/python
[task 2018-03-20T18:58:43.767Z] Installing setuptools, pip, wheel...done.
[task 2018-03-20T18:58:44.935Z] running build_ext
[task 2018-03-20T18:58:44.935Z] building 'psutil._psutil_linux' extension
[task 2018-03-20T18:58:44.935Z] creating build
[task 2018-03-20T18:58:44.935Z] creating build/temp.linux-x86_64-2.7
[task 2018-03-20T18:58:44.935Z] creating build/temp.linux-x86_64-2.7/psutil
[task 2018-03-20T18:58:44.935Z] x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fno-strict-aliasing -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -fPIC -DPSUTIL_POSIX=1 -DPSUTIL_VERSION=543 -DPSUTIL_LINUX=1 -I/usr/include/python2.7 -c psutil/_psutil_common.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_common.o
[task 2018-03-20T18:58:44.935Z] x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fno-strict-aliasing -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -fPIC -DPSUTIL_POSIX=1 -DPSUTIL_VERSION=543 -DPSUTIL_LINUX=1 -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o
[task 2018-03-20T18:58:44.935Z] x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fno-strict-aliasing -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -fPIC -DPSUTIL_POSIX=1 -DPSUTIL_VERSION=543 -DPSUTIL_LINUX=1 -I/usr/include/python2.7 -c psutil/_psutil_linux.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o
[task 2018-03-20T18:58:44.935Z] creating build/lib.linux-x86_64-2.7
[task 2018-03-20T18:58:44.935Z] creating build/lib.linux-x86_64-2.7/psutil
[task 2018-03-20T18:58:44.936Z] x86_64-linux-gnu-gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -Wl,-Bsymbolic-functions -Wl,-z,relro -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security build/temp.linux-x86_64-2.7/psutil/_psutil_common.o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o build/temp.linux-x86_64-2.7/psutil/_psutil_linux.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so
[task 2018-03-20T18:58:44.936Z] building 'psutil._psutil_posix' extension
[task 2018-03-20T18:58:44.936Z] x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fno-strict-aliasing -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -fPIC -DPSUTIL_POSIX=1 -DPSUTIL_VERSION=543 -DPSUTIL_LINUX=1 -I/usr/include/python2.7 -c psutil/_psutil_common.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_common.o
[task 2018-03-20T18:58:44.936Z] x86_64-linux-gnu-gcc -pthread -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -fno-strict-aliasing -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -fPIC -DPSUTIL_POSIX=1 -DPSUTIL_VERSION=543 -DPSUTIL_LINUX=1 -I/usr/include/python2.7 -c psutil/_psutil_posix.c -o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o
[task 2018-03-20T18:58:44.936Z] x86_64-linux-gnu-gcc -pthread -shared -Wl,-O1 -Wl,-Bsymbolic-functions -Wl,-Bsymbolic-functions -Wl,-z,relro -fno-strict-aliasing -DNDEBUG -g -fwrapv -O2 -Wall -Wstrict-prototypes -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security -Wl,-Bsymbolic-functions -Wl,-z,relro -Wdate-time -D_FORTIFY_SOURCE=2 -g -fstack-protector-strong -Wformat -Werror=format-security build/temp.linux-x86_64-2.7/psutil/_psutil_common.o build/temp.linux-x86_64-2.7/psutil/_psutil_posix.o -o build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so
[task 2018-03-20T18:58:44.936Z] copying build/lib.linux-x86_64-2.7/psutil/_psutil_linux.so -> psutil
[task 2018-03-20T18:58:44.936Z] copying build/lib.linux-x86_64-2.7/psutil/_psutil_posix.so -> psutil
[task 2018-03-20T18:58:44.936Z] 
[task 2018-03-20T18:58:44.936Z] Error processing command. Ignoring because optional. (optional:packages.txt:comm/build/virtualenv_packages.txt)
[task 2018-03-20T18:58:45.224Z] INFO:upload-symbols:Using symbol upload token from the secrets service: "http://taskcluster/secrets/v1/secret/project/releng/gecko/build/level-3/gecko-symbol-upload"
[task 2018-03-20T18:58:45.725Z] INFO:upload-symbols:Uploading symbol file "https://queue.taskcluster.net/v1/task/Vx548tM8Rbe0VelyZVCRmA/artifacts/public/build/target.crashreporter-symbols-full.zip" to "https://symbols.mozilla.org/upload/"
[task 2018-03-20T18:58:45.725Z] INFO:upload-symbols:Attempt 1 of 5...

[taskcluster:error] Task timeout after 900 seconds. Force killing container.
[taskcluster 2018-03-20 19:00:01.426Z] === Task Finished ===
[taskcluster 2018-03-20 19:00:01.426Z] Unsuccessful task run with exit code: -1 completed in 1406.337 seconds
[vcs 2018-03-20T18:58:06.259Z] transferred 2.27 GB in 784.3 seconds (2.96 MB/sec)

...doesn't leave much time for anything else!
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: NEW → RESOLVED
Closed: 6 years ago
Resolution: --- → INCOMPLETE
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Resolution: --- → INCOMPLETE
New failure log file: 
https://treeherder.mozilla.org/logviewer.html#?job_id=187806700&repo=mozilla-central&lineNumber=525

Snippet with the failure:
[vcs 2018-07-12T11:30:49.003Z] clone [===================================>       ] 2166408492/2586549887 4m20s
[vcs 2018-07-12T11:30:50.011Z] clone [===================================>       ] 2169161004/2586549887 4m16s
[vcs 2018-07-12T11:30:51.027Z] clone [===================================>       ] 2171913516/2586549887 4m11s

[taskcluster:error] Task timeout after 900 seconds. Force killing container.
[taskcluster 2018-07-12 11:30:57.475Z] === Task Finished ===
[taskcluster 2018-07-12 11:30:57.476Z] Unsuccessful task run with exit code: -1 completed in 1135.151 seconds
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago → 6 years ago
Resolution: --- → INCOMPLETE
This is still happening.

Recent failure: https://treeherder.mozilla.org/logviewer.html#?job_id=212240728&repo=try&lineNumber=930

[vcs 2018-11-16T16:39:30.616Z] clone [=======>                                   ]  549159827/2776892393 1h32m
[vcs 2018-11-16T16:39:31.616Z] clone [=======>                                   ]  549259692/2776892393 1h34m
[vcs 2018-11-16T16:39:32.618Z] clone [=======>                                   ]  549357107/2776892393 1h35m
[vcs 2018-11-16T16:39:33.630Z] clone [=======>                                   ]  549457259/2776892393 1h36m
[vcs 2018-11-16T16:39:34.631Z] clone [=======>                                   ]  549565077/2776892393 1h37m
[vcs 2018-11-16T16:39:35.639Z] clone [=======>                                   ]  550127087/2776892393 1h36m
[vcs 2018-11-16T16:39:36.644Z] clone [=======>                                   ]  550792806/2776892393 1h35m
[vcs 2018-11-16T16:39:37.644Z] clone [=======>                                   ]  551174473/2776892393 1h35m
[vcs 2018-11-16T16:39:38.649Z] clone [=======>                                   ]  551671186/2776892393 1h35m
[vcs 2018-11-16T16:39:39.658Z] clone [=======>                                   ]  551711336/2776892393 1h36m

[taskcluster:error] Task timeout after 900 seconds. Force killing container.
[vcs 2018-11-16T16:39:40.664Z] clone [=======>                                   ]  551749980/2776892393 1h38m
[taskcluster 2018-11-16 16:39:50.373Z] === Task Finished ===
[taskcluster 2018-11-16 16:39:50.388Z] Unsuccessful task run with exit code: -1 completed in 2670.818 seconds
Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
Status: REOPENED → RESOLVED
Closed: 6 years ago → 5 years ago
Resolution: --- → INCOMPLETE

Recent failure log:https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=220739659&repo=mozilla-beta&lineNumber=23

[vcs 2019-01-09T03:05:10.131Z] ensuring https://hg.mozilla.org/releases/mozilla-beta@8d881ce4d5d3f56d85614d7fca672a8f09eb96c1 is available at /builds/worker/checkouts/gecko
[vcs 2019-01-09T03:05:10.964Z] (shared store has an active lock; assuming it is left over from a previous process and that the store is corrupt; deleting store and destination just to be sure)
[vcs 2019-01-09T03:08:13.684Z] (cloning from upstream repo https://hg.mozilla.org/mozilla-unified)
[taskcluster:error] Task timeout after 900 seconds. Force killing container.
[taskcluster 2019-01-09 03:20:06.454Z] === Task Finished ===
[taskcluster 2019-01-09 03:20:06.454Z] Unsuccessful task run with exit code: -1 completed in 922.234 seconds

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup

Status: REOPENED → RESOLVED
Closed: 5 years ago → 5 years ago
Resolution: --- → INCOMPLETE

Recent failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=238034878&repo=mozilla-beta&lineNumber=536

Status: RESOLVED → REOPENED
Resolution: INCOMPLETE → ---
See Also: → 1580066

Recent failures are in upload_symbols tasks which normally complete in less than 5 minutes; in the failure cases, docker setup and/or checkouts are very slow.

https://wiki.mozilla.org/Bug_Triage#Intermittent_Test_Failure_Cleanup
For more information, please visit auto_nag documentation.

Status: REOPENED → RESOLVED
Closed: 5 years ago → 4 years ago
Resolution: --- → INCOMPLETE
You need to log in before you can comment on or make changes to this bug.