test_itimer_virtual (test.test_signal.ItimerTest) ... FAIL

======================================================================
FAIL: test_itimer_prof (test.test_signal.ItimerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/db3l/buildarea/3.x.bolen-tiger/build/Lib/test/test_signal.py", line 391, in test_itimer_prof
    self.fail('timeout waiting for sig_prof signal')
AssertionError: timeout waiting for sig_prof signal

======================================================================
FAIL: test_itimer_virtual (test.test_signal.ItimerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/db3l/buildarea/3.x.bolen-tiger/build/Lib/test/test_signal.py", line 372, in test_itimer_virtual
    (signal.getitimer(self.itimer),))
AssertionError: timeout waiting for sig_vtalrm signal; signal.getitimer(self.itimer) gives: (0.29, 0.2)

----------------------------------------------------------------------
Ran 13 tests in 15.302s

The FreeBSD 7.2 buildbot also shows this failure.  See also issue 3864; although this failure appears to be slightly different, it might be due to a remnant of the same platform bug.  I'm making everyone from that bug nosy on this one.

i486 Ubuntu also showed the test_itimer_virtual failure (but not the other one...FreeBSD didn't show the other one either) here:

http://www.python.org/dev/buildbot/builders/i386 Ubuntu trunk/builds/949/steps/test/logs/stdio

To make the situation worse, this Ubuntu buildbot passed all signal tests on the next run.

test_itimer_virtual assumes that a process must get 0.3s of virtual
time within 5s of real time. This is not true:

I can easily make the test fail even on a fast machine by doing
as root (do it n times for n cores):

nice -n -19 sh -c 'echo "1234^123456789" | bc'


======================================================================
FAIL: test_itimer_prof (__main__.ItimerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "Lib/test/test_signal.py", line 401, in test_itimer_prof
    self.fail('timeout waiting for sig_prof signal')
AssertionError: timeout waiting for sig_prof signal

======================================================================
FAIL: test_itimer_virtual (__main__.ItimerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "Lib/test/test_signal.py", line 379, in test_itimer_virtual
    (signal.getitimer(self.itimer),))
AssertionError: timeout waiting for sig_vtalrm signal; signal.getitimer(self.itimer) gives: (0.200012, 0.200012)

> test_itimer_virtual assumes that a process must get 0.3s of virtual
> time within 5s of real time. This is not true [...]

I agree it's not a good test, especially when run on machines that are heavily loaded, or on an OS running in VM.  I can't really think of *any* way of reliably testing the amount of virtual time that's passed.  Anyone else?

How about removing just the timing part of the itimer_virtual tests? (Leaving the calls in so that the functionality does at least get exercised.)   Or we could leave the timing in so that the test is still useful on an otherwise lightly-loaded machine, but don't count it as a failure if the test times out without getting a signal.

> I can't really think of *any* way of reliably testing the amount of virtual time that's passed.

Can't we try to increase the timeout step by step? Eg. 5 sec => 10 sec, then 15 sec, etc. until the buildbots turn green?

> Can't we try to increase the timeout step by step? Eg. 5 sec => 10 sec, > then 15 sec, etc. until the buildbots turn green?

I think you'd need an increase of an order of magnitude or two (possibly more) in some cases to make this work:  notice that the failure message from the itimer_virtual test gives an indication of how much virtual time *has* actually passed, and in some cases it's none at all (to within the timer resolution).

Also, this doesn't seem like a very future-proof solution.

Reducing the time intervals (0.2, 0.3, ...) probably isn't much of an option either:  I'd expect difficulties with timer resolution.

Mark, I also think there is no reliable witness function that checks
the amount of virtual time used.

I guess it's best to increase the timeout and just print a diagnostic
if the test "fails".

Wasn't the freebsd problem unrelated to this ?

Right, the skip should be left in place.

Just to be clear, the freebsd6 problem was unrelated (presumably).  Freebsd7 seems to be suffering from the issue discussed here.

Committed fix (with the freebsd6 skips intact) in r80238, r80239, r80240
and r80241.



David, is it intentional that py3k doesn't have the freebsd6 fixes?

Stefan, you move too fast!  I was going to review that second patch, honest!

I'm not 100% sure (David can probably confirm), but I think your sys.stdout.write should be a sys.stderr.write.

Mark, sorry, let me know if I should revert anything.

I took the stdout over from some similar print statements that
once were in test_uuid (I agree that stderr would seem more
natural).

[http://svn.python.org/view/python/trunk/Lib/test/test_uuid.py?r1=50896&r2=50949]

The Tiger buildbot triggers the message in build #31:

test_signal
test_itimer_virtual: timeout: likely cause: machine too slow or load too high.


But build #23 is ok.

The only reason the freebsd6 skips aren't in py3k is that I wanted to make sure they worked first, and then I was on vacation and haven't gotten to the merge yet.  If you want to merge your patch before I get to it, feel free to merge mine along with yours.

For 2.6 writing to stderr is indeed better (maybe even requried; I forget if the regrtest stdout check is still in 2.6...I think it probably is).

For 2.7/3.x, I think you should raise a unittest.SkipTest instead, so that it will be counted as a skipped test.

The buildbots are generally happy with the change. However, on OpenBSD
test_itimer_prof fails seemingly unrelated to machine load.

I'm not so familiar with the signal module, but how can the signal
handlers in the tests be guaranteed to work? For example, if you
set a variable inside a signal handler (self.hndl_called=True), it
should be a sig_atomic_t. If you call a function, it should be listed
as signal-safe ( 
http://www.opengroup.org/onlinepubs/009695399/functions/xsh_chap02_04.html ),
but setitimer is not.


I say this because there might be further assumptions in the tests
that could generate hard to track down failures in the future.

Luckily, the OpenBSD failures are caused by issues in libpthread. This
means that some skips could be added (as for FreeBSD), but I'll open
a separate issue for that.


Thanks for the comments on the patch. I add two new patches that
incorporate the stderr/SkipTest suggestions.


Should I apply them and close this issue?

The patches look good, so yes, please apply them.  As for closing the issue...if the failures are no longer happening on the buildbots, then yes :)

I can't find buildbot failures related to this any longer, so I'm closing
this one.