bpo-35513, unittest: TextTestRunner uses time.perf_counter() (GH-11180)

TextTestRunner of unittest.runner now uses time.perf_counter() rather
than time.time() to measure the execution time of a test: time.time()
can go backwards, whereas time.perf_counter() is monotonic.

Similar change made in libregrtest, pprint and random.
This commit is contained in:
Victor Stinner 2018-12-17 11:30:34 +01:00 committed by GitHub
parent 2cf4c202ff
commit 8db5b54463
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 19 additions and 15 deletions

View File

@ -568,11 +568,11 @@ def _perfcheck(object=None):
if object is None: if object is None:
object = [("string", (1, 2), [3, 4], {5: 6, 7: 8})] * 100000 object = [("string", (1, 2), [3, 4], {5: 6, 7: 8})] * 100000
p = PrettyPrinter() p = PrettyPrinter()
t1 = time.time() t1 = time.perf_counter()
_safe_repr(object, {}, None, 0) _safe_repr(object, {}, None, 0)
t2 = time.time() t2 = time.perf_counter()
p.pformat(object) p.pformat(object)
t3 = time.time() t3 = time.perf_counter()
print("_safe_repr:", t2 - t1) print("_safe_repr:", t2 - t1)
print("pformat:", t3 - t2) print("pformat:", t3 - t2)

View File

@ -740,14 +740,14 @@ def _test_generator(n, func, args):
sqsum = 0.0 sqsum = 0.0
smallest = 1e10 smallest = 1e10
largest = -1e10 largest = -1e10
t0 = time.time() t0 = time.perf_counter()
for i in range(n): for i in range(n):
x = func(*args) x = func(*args)
total += x total += x
sqsum = sqsum + x*x sqsum = sqsum + x*x
smallest = min(x, smallest) smallest = min(x, smallest)
largest = max(x, largest) largest = max(x, largest)
t1 = time.time() t1 = time.perf_counter()
print(round(t1-t0, 3), 'sec,', end=' ') print(round(t1-t0, 3), 'sec,', end=' ')
avg = total/n avg = total/n
stddev = _sqrt(sqsum/n - avg*avg) stddev = _sqrt(sqsum/n - avg*avg)

View File

@ -162,7 +162,7 @@ def runtest_inner(ns, test, display_failure=True):
abstest = get_abs_module(ns, test) abstest = get_abs_module(ns, test)
clear_caches() clear_caches()
with saved_test_environment(test, ns.verbose, ns.quiet, pgo=ns.pgo) as environment: with saved_test_environment(test, ns.verbose, ns.quiet, pgo=ns.pgo) as environment:
start_time = time.time() start_time = time.perf_counter()
the_module = importlib.import_module(abstest) the_module = importlib.import_module(abstest)
# If the test has a test_main, that will run the appropriate # If the test has a test_main, that will run the appropriate
# tests. If not, use normal unittest test loading. # tests. If not, use normal unittest test loading.
@ -180,7 +180,7 @@ def runtest_inner(ns, test, display_failure=True):
refleak = dash_R(the_module, test, test_runner, ns.huntrleaks) refleak = dash_R(the_module, test, test_runner, ns.huntrleaks)
else: else:
test_runner() test_runner()
test_time = time.time() - start_time test_time = time.perf_counter() - start_time
post_test_cleanup() post_test_cleanup()
except support.ResourceDenied as msg: except support.ResourceDenied as msg:
if not ns.quiet and not ns.pgo: if not ns.quiet and not ns.pgo:

View File

@ -14,26 +14,26 @@ def test_scaled_msg(scale, name):
longStr = b'Z'*scale longStr = b'Z'*scale
localCF = creatorFunc localCF = creatorFunc
start = time.time() start = time.perf_counter()
for f in range(iterations): for f in range(iterations):
x = localCF(longStr).digest() x = localCF(longStr).digest()
end = time.time() end = time.perf_counter()
print(('%2.2f' % (end-start)), "seconds", iterations, "x", len(longStr), "bytes", name) print(('%2.2f' % (end-start)), "seconds", iterations, "x", len(longStr), "bytes", name)
def test_create(): def test_create():
start = time.time() start = time.perf_counter()
for f in range(20000): for f in range(20000):
d = creatorFunc() d = creatorFunc()
end = time.time() end = time.perf_counter()
print(('%2.2f' % (end-start)), "seconds", '[20000 creations]') print(('%2.2f' % (end-start)), "seconds", '[20000 creations]')
def test_zero(): def test_zero():
start = time.time() start = time.perf_counter()
for f in range(20000): for f in range(20000):
x = creatorFunc().digest() x = creatorFunc().digest()
end = time.time() end = time.perf_counter()
print(('%2.2f' % (end-start)), "seconds", '[20000 "" digests]') print(('%2.2f' % (end-start)), "seconds", '[20000 "" digests]')

View File

@ -168,7 +168,7 @@ class TextTestRunner(object):
warnings.filterwarnings('module', warnings.filterwarnings('module',
category=DeprecationWarning, category=DeprecationWarning,
message=r'Please use assert\w+ instead.') message=r'Please use assert\w+ instead.')
startTime = time.time() startTime = time.perf_counter()
startTestRun = getattr(result, 'startTestRun', None) startTestRun = getattr(result, 'startTestRun', None)
if startTestRun is not None: if startTestRun is not None:
startTestRun() startTestRun()
@ -178,7 +178,7 @@ class TextTestRunner(object):
stopTestRun = getattr(result, 'stopTestRun', None) stopTestRun = getattr(result, 'stopTestRun', None)
if stopTestRun is not None: if stopTestRun is not None:
stopTestRun() stopTestRun()
stopTime = time.time() stopTime = time.perf_counter()
timeTaken = stopTime - startTime timeTaken = stopTime - startTime
result.printErrors() result.printErrors()
if hasattr(result, 'separator2'): if hasattr(result, 'separator2'):

View File

@ -0,0 +1,4 @@
:class:`~unittest.runner.TextTestRunner` of :mod:`unittest.runner` now uses
:func:`time.perf_counter` rather than :func:`time.time` to measure the
execution time of a test: :func:`time.time` can go backwards, whereas
:func:`time.perf_counter` is monotonic.