classification
Title: Lib/test/lock_tests.py should not use time.time(), but time.monotonic()
Type: Stage: resolved
Components: Tests Versions: Python 3.8
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: miss-islington, pablogsal, vstinner
Priority: normal Keywords: patch

Created on 2018-12-16 22:05 by vstinner, last changed 2018-12-17 10:54 by vstinner. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 11180 merged vstinner, 2018-12-16 22:38
PR 11182 merged vstinner, 2018-12-16 22:42
PR 11185 merged miss-islington, 2018-12-17 08:37
PR 11188 merged miss-islington, 2018-12-17 10:30
Messages (6)
msg331939 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-16 22:05
https://buildbot.python.org/all/#/builders/145/builds/956

Unhandled exception in thread started by <function Bunch.__init__.<locals>.task at 0x111775cb0>
Traceback (most recent call last):
  File "/Users/buildbot/buildarea/3.x.billenstein-sierra/build/Lib/test/lock_tests.py", line 41, in task
    f()
  File "/Users/buildbot/buildarea/3.x.billenstein-sierra/build/Lib/test/lock_tests.py", line 591, in f
    self.assertTimeout(dt, 0.1)
  File "/Users/buildbot/buildarea/3.x.billenstein-sierra/build/Lib/test/lock_tests.py", line 80, in assertTimeout
    self.assertGreaterEqual(actual, expected * 0.6)
  File "/Users/buildbot/buildarea/3.x.billenstein-sierra/build/Lib/unittest/case.py", line 1283, in assertGreaterEqual
    self.fail(self._formatMessage(msg, standardMsg))
  File "/Users/buildbot/buildarea/3.x.billenstein-sierra/build/Lib/unittest/case.py", line 719, in fail
    raise self.failureException(msg)
AssertionError: -0.24049997329711914 not greater than or equal to 0.06
test_waitfor_timeout (test.test_threading.ConditionTests) ... FAIL

test_waitfor_timeout():

                ...
                dt = time.time()
                result = cond.wait_for(lambda : state==4, timeout=0.1)
                dt = time.time() - dt
                self.assertFalse(result)
                self.assertTimeout(dt, 0.1)
                ...

with:

    def assertTimeout(self, actual, expected):
        ...
        self.assertGreaterEqual(actual, expected * 0.6)
        ...

It seems like time.time() gone backward on the buildbot. The test must use time.monotonic() to measure time difference.

Attached PR fix the issue.
msg331951 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-17 08:36
New changeset 2cf4c202ffeb30787c944365ba54013688b854c2 by Victor Stinner in branch 'master':
bpo-35513: Replace time.time() with time.monotonic() in tests (GH-11182)
https://github.com/python/cpython/commit/2cf4c202ffeb30787c944365ba54013688b854c2
msg331954 - (view) Author: miss-islington (miss-islington) Date: 2018-12-17 09:03
New changeset be69ff232df23b6ee165d7c34df5435d497cb79b by Miss Islington (bot) in branch '3.7':
bpo-35513: Replace time.time() with time.monotonic() in tests (GH-11182)
https://github.com/python/cpython/commit/be69ff232df23b6ee165d7c34df5435d497cb79b
msg331968 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-17 10:30
New changeset 8db5b54463118e5eb60cb3582e3108623f01f5df by Victor Stinner in branch 'master':
bpo-35513, unittest: TextTestRunner uses time.perf_counter() (GH-11180)
https://github.com/python/cpython/commit/8db5b54463118e5eb60cb3582e3108623f01f5df
msg331975 - (view) Author: miss-islington (miss-islington) Date: 2018-12-17 10:49
New changeset 9ade4cbc0f54fc0e2970e4e202f09ab83f5e3b77 by Miss Islington (bot) in branch '3.7':
bpo-35513, unittest: TextTestRunner uses time.perf_counter() (GH-11180)
https://github.com/python/cpython/commit/9ade4cbc0f54fc0e2970e4e202f09ab83f5e3b77
msg331976 - (view) Author: STINNER Victor (vstinner) * (Python committer) Date: 2018-12-17 10:54
I searched from "time.time" and "from time import(...)time" in the Python standard library (in the master branch) and it seems like all usage of time.time() are now appropriate. I close the issue.

Sometimes, I'm not sure that if time.monotonic() or time.perf_counter() should be used, but at least both functions are monotonic and so are not affected by this issue (clock going backwards).
History
Date User Action Args
2018-12-17 10:54:06vstinnersetstatus: open -> closed
resolution: fixed
messages: + msg331976

stage: patch review -> resolved
2018-12-17 10:49:24miss-islingtonsetmessages: + msg331975
2018-12-17 10:30:56miss-islingtonsetpull_requests: + pull_request10426
2018-12-17 10:30:43vstinnersetmessages: + msg331968
2018-12-17 09:03:08miss-islingtonsetnosy: + miss-islington
messages: + msg331954
2018-12-17 08:37:03miss-islingtonsetpull_requests: + pull_request10423
2018-12-17 08:36:42vstinnersetmessages: + msg331951
2018-12-16 22:42:45vstinnersetpull_requests: + pull_request10421
2018-12-16 22:38:25vstinnersetkeywords: + patch
stage: patch review
pull_requests: + pull_request10420
2018-12-16 22:05:49vstinnercreate