1398933 - test-verify sometimes times out

Status: RESOLVED FIXED

(Testing :: General, defect)

Description

[Geoff Brown [:gbrown] (pto Jun 2-Jun 5)]

We expect test-verify to sometimes have more tests to verify than it can verify in a reasonable amount of time. In these cases, test-verify should give up and complete before timing out.

I see some exceptions, where the job runs for too long.

https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=296f26c8422126c7e80812173ebc38e548566234&filter-searchStr=test-verify&filter-tier=1&filter-tier=2&filter-tier=3

This is a merge, so having lots of tests to verify is not unexpected.

https://public-artifacts.taskcluster.net/bkKYRtAIStim-PpcHhxxIg/0/public/logs/live_backing.log

[task 2017-09-09T10:22:55.667898Z] 10:22:55     INFO - Calling ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/mochitest/runtests.py', ... '--verify-max-time=900', '--verify', u'intl/l10n/test/dom/test_domloc_mutations.html'] with output_timeout 1000
...
[task 2017-09-09T11:41:12.971029Z] 11:41:12     INFO - Calling ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py', ... '--verify-max-time=900', '--verify', u'toolkit/components/extensions/test/xpcshell/test_ext_unknown_permissions.js'] with output_timeout 1000
...
[task 2017-09-09T11:46:59.887397Z] 11:46:59     INFO - Calling ['/builds/worker/workspace/build/venv/bin/python', '-u', '/builds/worker/workspace/build/tests/xpcshell/runxpcshelltests.py', ... '--verify-max-time=900', '--verify', u'services/sync/tests/unit/test_syncengine_sync.js'] with output_timeout 1000
...
[task 2017-09-09T11:50:09.064917Z] 11:50:09     INFO -  TEST-START | services/sync/tests/unit/test_syncengine_sync.js

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

Comment 1

[Geoff Brown [:gbrown] (pto Jun 2-Jun 5)]

We triggered "Verification too long", but didn't stop verification:

toolkit/components/extensions/test/mochitest/test_ext_notifications.html
...
[task 2017-09-09T11:28:26.407889Z] 11:28:26     INFO - TinderboxPrint: Verification too long: Not all tests were verified.<br/>
...
intl/l10n/test/test_localization.js

I think it bailed out of one suite (mochitests) but continued with the next suite (xpcshell tests).

Comment 2

[Geoff Brown [:gbrown] (pto Jun 2-Jun 5)]

Attachment: bail out of nested loop when verify max time exceeded

A small fix for a small problem!

Comment 3

[Joel Maher ( :jmaher ) (UTC -8) (PTO'ish until July 5)]

Comment on attachment 8906800 [details] [diff] [review]
bail out of nested loop when verify max time exceeded

Review of attachment 8906800 [details] [diff] [review]:
-----------------------------------------------------------------

oh, this should solve many of the issues.

Comment 4

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/b805cc36637b
Ensure test-verify bails out before timing out; r=jmaher

Comment 5

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/f559248aac81
Follow-up, fix cannot compare timedelta bustage, on a CLOSED TREE

Comment 6

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/b805cc36637b
https://hg.mozilla.org/mozilla-central/rev/f559248aac81