classification
Title: test_signal fails on os x 10.6
Type: Stage:
Components: Library (Lib), Tests Versions: Python 3.1, Python 3.2, Python 2.7, Python 2.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: mark.dickinson Nosy List: chuck, mark.dickinson, ned.deily, ronaldoussoren
Priority: normal Keywords: patch

Created on 2009-10-02 21:18 by chuck, last changed 2009-10-31 10:42 by mark.dickinson. This issue is now closed.

Files
File name Uploaded Description Edit
test_signal.fail chuck, 2009-10-02 21:18
issue7042.patch mark.dickinson, 2009-10-04 13:23
Messages (15)
msg93457 - (view) Author: Jan (chuck) * Date: 2009-10-02 21:18
======================================================================
FAIL: test_itimer_virtual (test.test_signal.ItimerTest)
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/Users/jan/src/python26/Lib/test/test_signal.py", line 368, in 
test_itimer_virtual
    self.assertEquals(signal.getitimer(self.itimer), (0.0, 0.0))
AssertionError: (0.17993600000000001, 0.20000000000000001) != (0.0, 0.0)

----------------------------------------------------------------------

Complete output attached.
msg93470 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2009-10-03 01:49
test_signal does not fail for me on 10.6 using the python.org 2.6.3 
installer (which is 32-bit).  The test hangs (presumably in the wait 
loop) with a 10.6 64-bit build of Python 2.6.3rc1.  FWIW, the 2.6.3 
test_signal seems to run OK with Apple's 64-bit python2.6.2 in 10.6. 
What kind of build and on what kind of machine were you running this?

There are other issues open that report similar problems running 
test_signal on other OS's: http://bugs.python.org/issue5972, which was 
reported against Red Hat Linux 4.1.2, and possibly 
http://bugs.python.org/issue3864 on FreeBSD.  Perhaps there's a common 
thread here.
msg93480 - (view) Author: Jan (chuck) * Date: 2009-10-03 06:27
This is a 64 bit machine and the test failed for the checkout of the 
python26-maint branch. I just configured and made it without any flags. 
(Does that produce a 64 bit build?)
msg93483 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2009-10-03 09:20
By default, 10.6 prefers to run 64-bit architectures when available.  You 
can easily tell whether a python 2.x is running as 32-bit or 64-bit by 
checking sys.maxint:

$ /usr/local/bin/python2.6 -c 'import sys; print sys.maxint'
2147483647
$ /usr/bin/python2.6 -c 'import sys; print sys.maxint'
9223372036854775807
msg93485 - (view) Author: Jan (chuck) * Date: 2009-10-03 09:40
$ ./python.exe -c 'import sys; print sys.maxint'
9223372036854775807
msg93538 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-04 12:43
I'm seeing this failure too, on a 64-bit build of the trunk on OS X 
10.6.1.

If I understand the test, it's setting up a timer that's supposed to run 
for 0.3 seconds of 'virtual time', signal, and then signal every 0.2 
seconds of virtual time thereafter.  The test passes after 4 (or is it 3?) 
signals have been handled, for a total of 0.9 seconds of virtual time.

The problem appears to be that the 'for i in xrange(100000000): ...' loop 
simply isn't long enough for 0.9 seconds of virtual time to even elapse:  
on my machine, around 0.06 seconds of virtual time appear to have elapsed 
by the time the loop is finished.

When I increase the loop to 'for i in xrange(10**10): ...', the test 
*eventually* passes.  Those 0.9 seconds of virtual time took over 29 
minutes of real time, on an otherwise mostly-idle machine.  (2.53GHz Core 
2 Duo.)

When I add some actual work into the xrange loop (computing pow(12345, 
67890, 10000001) and throwing away the result) then test_itimer_virtual 
passes, in a reasonably short amount of time (a second or so).

I don't know what the precise definition of virtual time is, or whether 
there's a defect in the way that Snow Leopard is measuring it.  At any 
rate, I don't think the reported behaviour is a bug in the signal module:  
the test should be fixed somehow, though (perhaps by adding that pow() 
call).
msg93539 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-04 13:01
Issue #5972 looks like the same problem.
msg93542 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-04 13:08
This may also explain why the x86 FreeBSD trunk buildbot is currently 
hanging on test_signal.

(And I see Ned already mentioned issue 5972 above.  Sorry for the noise.)
msg93543 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-04 13:23
chuck: does the attached patch fix the problem for you?
msg93553 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-04 18:49
I've applied the above patch in r75236 (trunk), r75237 (release26-maint),
r75238 (py3k) and r75239 (release31-maint).  With any luck this should fix 
the issue.  Jan Hosang, can you confirm that this is fixed?
msg93579 - (view) Author: Jan (chuck) * Date: 2009-10-05 07:23
I updated the checkout of the 26 branch, and the test runs fine now.

I have no clue about virtual time as well. If this is about passing time, 
there should be better ways (than those which break if your computer gets 
faster).
msg93582 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-05 08:36
> If this is about passing time, there should be better ways (than
> those which break if your computer gets faster).

Agreed.  The challenge is to find ways that don't add too much in the
way of extra complexity, fragility, or dependencies to the unit test.

How about replacing the xrange(100000000) loop with something like this,
which allows 30 seconds of real time and then fails with a timeout 
message:

start_time = time.time()
while time.time() - start_time < 5.0:
    <use some process time here>
    if signal.getitimer(self.itimer) == (0.0, 0.0):
        break
else:
    self.fail('timeout waiting for virtual timer signal')
msg93583 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-05 08:37
Oops.  That 5.0 should have been 30.0, of course.
msg93592 - (view) Author: Jan (chuck) * Date: 2009-10-05 11:33
I think a timing out while loop explains much better what is happening. I 
mean we are trying to keep the cpu busy for 0.9 seconds (if I understand 
the definition of virtual time correctly) and not do 100000000 increments 
(which might be done faster than 0.9 seconds).
msg94752 - (view) Author: Mark Dickinson (mark.dickinson) * (Python committer) Date: 2009-10-31 10:42
I've fixed test_itimer_virtual and test_itimer_prof to use a timeout 
instead of an xrange/range(100000000) loop, in r75986 through r75989.
History
Date User Action Args
2009-10-31 10:42:17mark.dickinsonsetstatus: open -> closed

messages: + msg94752
2009-10-05 11:33:49chucksetmessages: + msg93592
2009-10-05 08:37:12mark.dickinsonsetmessages: + msg93583
2009-10-05 08:36:12mark.dickinsonsetassignee: mark.dickinson
messages: + msg93582
2009-10-05 07:23:50chucksetstatus: pending -> open

messages: + msg93579
2009-10-04 18:49:14mark.dickinsonsetstatus: open -> pending
resolution: fixed
messages: + msg93553

versions: + Python 3.1, Python 3.2
2009-10-04 13:23:02mark.dickinsonsetfiles: + issue7042.patch
keywords: + patch
messages: + msg93543
2009-10-04 13:08:50mark.dickinsonsetmessages: + msg93542
2009-10-04 13:01:19mark.dickinsonsetmessages: + msg93539
2009-10-04 12:43:30mark.dickinsonsetnosy: + mark.dickinson

messages: + msg93538
versions: + Python 2.7
2009-10-03 09:40:41chucksetmessages: + msg93485
2009-10-03 09:20:19ned.deilysetmessages: + msg93483
2009-10-03 06:27:24chucksetmessages: + msg93480
2009-10-03 01:49:44ned.deilysetnosy: + ronaldoussoren, ned.deily
messages: + msg93470
2009-10-02 21:18:29chuckcreate