classification
Title: regrtest --timeout: apply the timeout on a function, not on the whole file
Type: Stage:
Components: Tests Versions: Python 3.3
process
Status: closed Resolution: wont fix
Dependencies: Superseder:
Assigned To: Nosy List: michael.foord, pitrou, rhettinger, vstinner
Priority: normal Keywords: patch

Created on 2011-04-07 21:54 by vstinner, last changed 2011-04-18 21:49 by vstinner. This issue is now closed.

Files
File name Uploaded Description Edit
regrtest_timeout-3.patch vstinner, 2011-04-08 11:49 review
Messages (15)
msg133262 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-07 21:54
I added recently a --timeout option to regrtest.py: dump the traceback of all threads and exit if a test takes more than TIMEOUT seconds (issue #11727). But my implementation was not correct: the timeout is applied on the whole file, not on a single function. Attached patch fixes this issue.
msg133265 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-07 22:01
I forgot to patch some calls to runtest(): new patch.
msg133269 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-04-07 22:22
The question is: what's the point? Having an individual test timeout is not more "correct" than having a timeout for a test file. Both are arbitrary. Therefore, I'd prefer we choose the simplest solution and this patch brings complication. I'm -0.5 on it.
msg133271 - (view) Author: Raymond Hettinger (rhettinger) * (Python committer) Date: 2011-04-07 22:37
FWIW, I prefer the whole file approach.
msg133272 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-07 22:49
I would like a timeout per function call because some files contain many slow tests: the duration of a file depends on the number of tests. Imagine that all functions takes 1 second: a file with 200 functions takes 200 seconds, whereas a file with 1 test takes just 1 second.

The problem is some files having a lot of slow tests like test_io, test_largefile or test_subprocess (especially test_io).

Buildbots use currently a global timeout of 1 hour. I tried timeouts of 5, 15 and 30 minutes for a file, and I always got false positive. Using a timeout of 15 minutes per function, I don't expect any false positive anymore.
msg133273 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-04-07 22:51
> Buildbots use currently a global timeout of 1 hour. I tried timeouts
> of 5, 15 and 30 minutes for a file, and I always got false positive.
> Using a timeout of 15 minutes per function, I don't expect any false
> positive anymore.

Still I don't see the point. Is a 60 minutes timeout too long?
msg133275 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-07 23:08
> Still I don't see the point. Is a 60 minutes timeout too long?

If regrtest timeout is too close to the buildbot timeout, we may not get the traceback if the blocking test is the last test.

I don't know yet if we will get false positive with a timeout of 60 minutes.

Another *minor* advantage of a smaller regrtest timeout is to "protect" the buildbot: catching faster a hang avoids to wait one hour to start a new build. Most hangs are sporadic or introduced by recent commits.
msg133276 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-04-07 23:10
Le jeudi 07 avril 2011 à 23:08 +0000, STINNER Victor a écrit :
> STINNER Victor <victor.stinner@haypocalc.com> added the comment:
> 
> > Still I don't see the point. Is a 60 minutes timeout too long?
> 
> If regrtest timeout is too close to the buildbot timeout, we may not
> get the traceback if the blocking test is the last test.

The buildbot timeout is 65 minutes right now. I don't think (I hope)
this is too close.

> I don't know yet if we will get false positive with a timeout of 60 minutes.

Ok, let's see.
msg133305 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-08 11:49
Simplify the test and set the default timeout to 15 min.
msg133306 - (view) Author: Michael Foord (michael.foord) * (Python committer) Date: 2011-04-08 11:51
Victor's reasons for wanting per-test timeout rather than per-file seem sound. Need to review the patch to see how much extra complexity it actually introduces (although on a casual reading the new custom result object it introduces is trivially simple, so not a maintenance burden).
msg133310 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-08 12:32
With the current implementation of faulthandler.dump_tracebacks_later(), use a timeout per function means create a new thread for each function (the thread is interrupted and exits when the test is done).

Quick benchmark with test_io on Linux (lowest "real time" of 3 runs):

- time ./python Lib/test/regrtest.py -v (with timeout): 1 min 3 sec
- time ./python Lib/test/regrtest.py -v, without timeout: 1 min 3 sec
- time ./python Lib/test/test_io.py (without timeout): 1 min 3 sec

test_io have 403 tests and 8 are skipped, so it looks like the creation of ~400 threads is really fast on Linux! test_io is one of the biggest test suite I think.
msg133312 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-08 14:42
I did a similar test on Windows: test_io takes ~19.1 sec with and without timeout. If I look closer, the timeout overhead (call a thread per function call) is 112 µs per function call. The average duration of a test is 48 ms (47,750 µs), so the overhead is 0,2%. I am not sure of these numbers (it is difficult to get reliable numbers, especially in a VM), but I'm sure that the overflow is very low.
msg133331 - (view) Author: Antoine Pitrou (pitrou) * (Python committer) Date: 2011-04-08 17:31
> I did a similar test on Windows: test_io takes ~19.1 sec with and
> without timeout.

You may want to test with test_argparse.
msg133344 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-08 21:17
Le vendredi 08 avril 2011 à 17:31 +0000, Antoine Pitrou a écrit :
> Antoine Pitrou <pitrou@free.fr> added the comment:
> 
> > I did a similar test on Windows: test_io takes ~19.1 sec with and
> > without timeout.
> 
> You may want to test with test_argparse.

Oh... test_argparse has 1608 test! Benchmark on Linux:
- without timeout: 18.931 sec
- with timeout/function call: 19.436 sec

So on this test suite, the overhead is 2.7%. The current timeout
implementation has an overhead near 0% on the same test suite (I tried
to compute the overhead, but I found -0.2% which looks wrong :-)).

I'm too lazy to start Windows for another benchmark tonight.
msg133994 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2011-04-18 21:49
A timeout of 60 minutes looks to be fine. Today I debuged a thread+signal issue which gave me an headache, so I prefer to close this issue: only add create thread per file, and not a thread per function.
History
Date User Action Args
2011-04-18 21:49:31vstinnersetstatus: open -> closed
resolution: wont fix
messages: + msg133994
2011-04-08 21:17:30vstinnersetmessages: + msg133344
2011-04-08 17:31:46pitrousetmessages: + msg133331
2011-04-08 14:42:19vstinnersetmessages: + msg133312
2011-04-08 12:32:45vstinnersetmessages: + msg133310
2011-04-08 11:51:28michael.foordsetmessages: + msg133306
2011-04-08 11:49:16vstinnersetfiles: - regrtest_timeout-2.patch
2011-04-08 11:49:11vstinnersetfiles: + regrtest_timeout-3.patch

messages: + msg133305
2011-04-07 23:10:20pitrousetmessages: + msg133276
2011-04-07 23:08:31vstinnersetmessages: + msg133275
2011-04-07 22:51:19pitrousetmessages: + msg133273
2011-04-07 22:49:54vstinnersetmessages: + msg133272
2011-04-07 22:37:02rhettingersetnosy: + rhettinger
messages: + msg133271
2011-04-07 22:22:36pitrousetnosy: + pitrou
messages: + msg133269
2011-04-07 22:01:39vstinnersetfiles: - regrtest_timeout.patch
2011-04-07 22:01:22vstinnersetfiles: + regrtest_timeout-2.patch

messages: + msg133265
2011-04-07 21:55:38pitrousetnosy: + michael.foord
2011-04-07 21:54:53vstinnercreate