testament: timeout doesn't work: it waits for process to complete

[timotheecour]

Example

discard """
  timeout: 0.1
"""

from std/os import sleep

while true:
  sleep(100)

Current Output

doesn't terminate

Expected Output

fail with reTimeout after specified timeout (0.1 seconds)

Possible Solution

the current implementation is naive: it calls execCmdEx2 and waits for process to complete (and only then compares test duration to timeout), but instead should use a timeout and abort process when timeout expires. Side note: epochTime is used, but this is incorrect, see #17405.

This could explains why CI sometimes times out after 90 minutes due.

/Users/timothee/git_clone/nim/Nim_prs/testament/testament.nim(825) testament
/Users/timothee/git_clone/nim/Nim_prs/testament/testament.nim(804) main
/Users/timothee/git_clone/nim/Nim_prs/testament/categories.nim(540) processSingleTest
/Users/timothee/git_clone/nim/Nim_prs/testament/testament.nim(574) testSpec
/Users/timothee/git_clone/nim/Nim_prs/testament/testament.nim(555) targetHelper
/Users/timothee/git_clone/nim/Nim_prs/testament/testament.nim(515) testSpecHelper
/Users/timothee/git_clone/nim/Nim_prs/testament/testament.nim(135) execCmdEx2
/Users/timothee/git_clone/nim/Nim_prs/lib/pure/streams.nim(1002) readLine
/Users/timothee/git_clone/nim/Nim_prs/lib/pure/streams.nim(1323) fsReadLine
/Users/timothee/git_clone/nim/Nim_prs/lib/system/io.nim(453) readLine
SIGINT: Interrupted by Ctrl-C.

Additional Information

1.5.1 b8b67ad

EDIT: added medium priority; this bug potentially explains cryptic errors of the form:

##[error]The operation was canceled.

in CI eg https://dev.azure.com/nim-lang/Nim/_build/results?buildId=14599&view=logs&jobId=a0440cd6-2060-5545-8b53-639e777de0c6&j=a0440cd6-2060-5545-8b53-639e777de0c6&t=e8126762-32e4-52a6-97de-95cf0bedbe3d

TODO

• investigate fix #17812(repr fails to compile with ARC/ORC) #17816 (comment)

[timotheecour]

this is not just about testament: timeout:

here's another example:

2021-03-25T19:29:09.7770712Z �[32mPASS: �[36mlib/packages/docutils/rstgen.nim c                          �[34m ( 1.32 sec)�[0m
2021-03-25T19:29:09.7771156Z progress[all]: 125/127 starting: cat: ic
2021-03-25T19:29:09.7772995Z /home/vsts/work/1/s/testament/testament --nim:/home/vsts/work/1/s/bin/nim --batch:_ pcat ic 
2021-03-25T19:29:13.2272809Z �[2m�[33mSKIP: �[1m�[36mtests/ic/tgenerics_temp.nim c  --incremental:on �[0m
2021-03-25T19:29:13.2283508Z �[32mPASS: �[36mtests/ic/thallo_temp.nim c  --incremental:on                �[34m ( 1.72 sec)�[0m
2021-03-25T19:29:13.2284712Z �[32mPASS: �[36mtests/ic/thallo_temp.nim c  --incremental:on                �[34m ( 1.50 sec)�[0m
2021-03-25T19:29:13.2285818Z �[32mPASS: �[36mtests/ic/thallo_temp.nim c  --incremental:on                �[34m ( 0.21 sec)�[0m
2021-03-25T19:29:13.2286561Z progress[all]: 126/127 starting: cat: megatest
2021-03-25T19:29:13.2288194Z /home/vsts/work/1/s/testament/testament --nim:/home/vsts/work/1/s/bin/nim --batch:_ pcat megatest 
2021-03-25T19:29:13.5603781Z joinable specs: 616
2021-03-25T19:30:12.7653315Z megatest output OK
2021-03-25T20:38:17.0944376Z ##[error]The operation was canceled.
2021-03-25T20:38:17.0949347Z ##[section]Finishing: Run CI

https://dev.azure.com/nim-lang/255dfe86-e590-40bb-a8a2-3c0295ebdeb1/_apis/build/builds/14752/logs/114

if a test is buggy and never returns, testament will just wait for it until CI times out.

the fix is to cap each test with a (customizable) timeout