glenfant/stopit

Inconsistent failing on testing on Python 2

Closed this issue · 6 comments

livibetter commented

I don't know how stopit does behind the scene, but just want to give some feedback.

The following command doesn't give same test results every time I ran it:

$ python2 setup.py test
[snip]
Doctest: README.rst ... FAIL
======================================================================
FAIL: /home/livibetter/p/stopit/README.rst
Doctest: README.rst
----------------------------------------------------------------------
Traceback (most recent call last):
  File "/usr/lib64/python2.7/doctest.py", line 2201, in runTest
    raise self.failureException(self.format_failure(new.getvalue()))
AssertionError: Failed doctest test for README.rst
  File "/home/livibetter/p/stopit/README.rst", line 0

----------------------------------------------------------------------
File "/home/livibetter/p/stopit/README.rst", line 174, in README.rst
Failed example:
    time.time() - start_time < 2.1
Expected:
    True
Got:
    False
----------------------------------------------------------------------
File "/home/livibetter/p/stopit/README.rst", line 204, in README.rst
Failed example:
    time.time() - start_time < 2.1
Expected:
    True
Got:
    False


----------------------------------------------------------------------
Ran 1 test in 8.948s

FAILED (failures=1)

The result above has two failures, but sometimes both pass, sometimes only one of them fails. The testing should be have same results every time, maybe there is something with Python 2?

I tried with Python 3 a few times, it seems all passed, which is consistent.

 ~/p/stopit [git:master] $ python2 --version
Python 2.7.5
 ~/p/stopit [git:master] $ python3 --version
Python 3.3.3
 ~/p/stopit [git:master] $ uname -a
Linux dfed 3.10.25-gentoo-1 #1 SMP PREEMPT Tue Jan 21 03:19:58 CST 2014 x86_64 Intel(R) Core(TM)2 CPU T5600 @ 1.83GHz GenuineIntel GNU/Linux

As I said in beginning, I don't know anything about stopit, but I can help with information from my system if that helps.

teolisitza commented

+1. Python 2.7.5 on Debian Linux (wheezy) has the same issue. Sometimes it times out properly, sometimes it does not. It's a huge bummer too, because the promise of a cross-platform thread safe timeout mechanism is very exciting.

glenfant commented

That's strange. Tests keep smiling for me on Python 2.6, 2.7 and 3.3 on OSX ! I'm preparing a new release including a signal based timeout, and I'll check this on an Ubuntu box at office.

@teolisitza : can you inspect / log the value of your_context_manager.status after the block is left when you notice it does not work as expected ? What do you meant exactly by "it does not timeout properly" (help me to find out what) ?

glenfant commented

BTW, sorry to reply so late. It seems that I do not receive mail notifications when a new issue is filed here 👎

teolisitza commented

Hey no problem sir. I'm on vacation right now but will find the example
that was not working for me and give you more details on Monday. Thanks for
the cool package,

teo

On Thu, May 1, 2014 at 4:22 PM, Gilles Lenfant notifications@github.comwrote:

BTW, sorry to reply so late. It seems that I do not receive mail
notifications when a new issue is filed here [image: 👎]

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/2#issuecomment-41968203
.

glenfant commented

Okay, I can reproduce the issue mentioned by @livibetter : a random failure on the test (now in line 442 of git master's README.rst).
Re-reading the doc about threading and signal, there is no garantee that a Timer thread will start exactly at the specified time. Such GIL related issues may add delay to propagate the asynchronous exception.

glenfant commented

Oh, I can understand what's going on.

Due to the nature of the interpreted languages, and the specific Pyton threading and context switching features (GIL, ...) there is no way to guarantee that the interruption of the code block under timeout control will occur precisely at the moment specified by the programmer. In fact, it may be reported by "some" fractions of seconds depending on the atomic Python instructions being actually executed before the next context switching. Hmmm complicated to explain precisely.

You may play with the Python check interval to have a more precise timeout control (means less delay between the specified timeout and the effective timeout). See the Python docs about sys.setcheckinterval(...) and sys.getcheckinterval().

With the default check interval (100), I can randomly notice - like you - that the effective timeout exceeds sometimes by 0.1 second or more the assigned timeout.
Reducing it in the tests.py this check interval decreases the tests failures rate. And finally, with sys.setcheckinterval(20) the failure we noticed disappears completely.

But reducing too much this check interval may have has side effects. Read this:

In the first time (for the upcoming 1.1.0 release):

  • I'll change the tests such they are less strict in timeout accuracy
  • I'll write a warning about this in the README.md

I'll consider adding a check_interval parameter to the context managers and decorators provided by stopit in a future release to let the developers choose wether or not to change temporarily this check interval, if they want to privilege timeout accuracy over global performances.

I'll close this ticket and open another one for above mentioned feature.