1406213 - test-verify sometimes times out, still

Status: RESOLVED FIXED

(Testing :: General, defect)

Description

[Geoff Brown [:gbrown] (pto Apr 11-18)]

As in bug 1398933, but now very rare.

https://treeherder.mozilla.org/#/jobs?repo=mozilla-inbound&revision=b25870b6590be5e881987ec7092be735e668ee80&filter-searchStr=test-verify

https://public-artifacts.taskcluster.net/PaDjHz2-TRyOcTdXQvuKbA/0/public/logs/live_backing.log

[task 2017-10-05T11:19:55.848Z] 11:19:55     INFO - Running post-action listener: find_tests_for_verification
...
[task 2017-10-05T12:48:27.679Z] 12:48:27     INFO -  :::
[task 2017-10-05T12:48:27.680Z] 12:48:27     INFO -  ::: Test verification summary for: /builds/worker/workspace/build/tests/xpcshell/tests/toolkit/mozapps/extensions/test/xpcshell/test_system_update_newset.js
[task 2017-10-05T12:48:27.681Z] 12:48:27     INFO -  :::
[task 2017-10-05T12:48:27.683Z] 12:48:27     INFO -  ::: 1. Run each test 10 times, sequentially. : Pass
[task 2017-10-05T12:48:27.684Z] 12:48:27     INFO -  ::: 2. Run each test 10 times, sequentially, in chaos mode. : Pass
[task 2017-10-05T12:48:27.685Z] 12:48:27     INFO -  :::
[task 2017-10-05T12:48:27.686Z] 12:48:27     INFO -  ::: Test verification PASSED
[task 2017-10-05T12:48:27.687Z] 12:48:27     INFO -  :::

...

[task 2017-10-05T12:48:42.165Z] 12:48:42     INFO -  TEST-PASS | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_system_repository.js | took 1494ms
[task 2017-10-05T12:48:42.186Z] 12:48:42     INFO -  TEST-START | xpcshell.ini:toolkit/mozapps/extensions/test/xpcshell/test_system_repository.js

[taskcluster:error] Task timeout after 5400 seconds. Force killing container.
[taskcluster 2017-10-05 12:48:42.603Z] === Task Finished ===
[taskcluster 2017-10-05 12:48:42.604Z] Unsuccessful task run with exit code: -1 completed in 5401.75 seconds

Comment 1

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Attachment: break out of all loops when verification time exceeded

I think the existing strategy is sound, as is the implementation for detecting when the max verification time is exceeded.

The trouble is that there are *3* loops to break out of when that max time is exceeded:

for suite_category ...:
    for suite in category ...:
        for file-to-be-verified ...:

This should break out of all of them.

https://treeherder.mozilla.org/#/jobs?repo=try&revision=7f9f38687f6c1f84cd47332350448429f8526ed1

Comment 2

[Geoff Brown [:gbrown] (pto Apr 11-18)]

Attachment: break out of all loops when verification time exceeded + do not reset start_time

Found and fixed another small problem. Now it's perfect!

Comment 3

[Geoff Brown [:gbrown] (pto Apr 11-18)]

https://treeherder.mozilla.org/#/jobs?repo=try&revision=6d1b305ea3f6ac5b58ae342c2337cc22ad96e3df

Comment 4

[Joel Maher ( :jmaher ) (UTC -8)]

Comment on attachment 8916202 [details] [diff] [review]
break out of all loops when verification time exceeded + do not reset start_time

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

::: testing/mozharness/scripts/desktop_unittest.py
@@ +763,4 @@
>                          # Verification has run out of time. That is okay! Stop running
>                          # tests so that a task timeout is not triggered, and so that
>                          # (partial) results are made available in a timely manner.
>                          self.info("TinderboxPrint: Verification too long: Not all tests were verified.<br/>")

shouldn't this be an error vs an info, we probably will never see this message.

Comment 5

[Geoff Brown [:gbrown] (pto Apr 11-18)]

An error will turn the job orange. TV normally runs out of time on a merge, or other change that affects lots of files -- not conditions that we want to cause bug filing, etc. I want the job to be green, and I don't mind if we are sometimes unaware that verification was not complete.

Comment 6

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/mozilla-inbound/rev/7fd42c49a756
Ensure test verification gives up after max time exceeded; r=jmaher

Comment 7

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

https://hg.mozilla.org/mozilla-central/rev/7fd42c49a756