Author: Carl Friedrich Bolz <[email protected]>
Branch: py3.5
Changeset: r87747:a4b0016d1aaa
Date: 2016-10-13 11:58 +0200
http://bitbucket.org/pypy/pypy/changeset/a4b0016d1aaa/
Log: port fb6bb835369e to py3.5:
- change timeit to report the average +- standard deviation
- print a warning and point to the perf module.
- increase default number of runs from 3 to 7
reporting the minimum is often quite misleading, see eg
"Statistically Rigorous Java Performance Evaluation" by Georges
et.al. 2007
diff --git a/lib-python/3/test/test_timeit.py b/lib-python/3/test/test_timeit.py
--- a/lib-python/3/test/test_timeit.py
+++ b/lib-python/3/test/test_timeit.py
@@ -12,7 +12,7 @@
DEFAULT_NUMBER = 1000000
# timeit's default number of repetitions.
-DEFAULT_REPEAT = 3
+DEFAULT_REPEAT = timeit.default_repeat
# XXX: some tests are commented out that would improve the coverage but take a
# long time to run because they test the default number of loops, which is
@@ -226,7 +226,7 @@
t.print_exc(s)
self.assert_exc_string(s.getvalue(), 'ZeroDivisionError')
- MAIN_DEFAULT_OUTPUT = "10 loops, best of 3: 1 sec per loop\n"
+ MAIN_DEFAULT_OUTPUT = "1 loops, average of 7: 1 +- 0 sec per loop (using
standard deviation)\n"
def run_main(self, seconds_per_increment=1.0, switches=None, timer=None):
if timer is None:
@@ -252,39 +252,41 @@
def test_main_seconds(self):
s = self.run_main(seconds_per_increment=5.5)
- self.assertEqual(s, "10 loops, best of 3: 5.5 sec per loop\n")
+ self.assertIn("1 loops, average of 7: 5.5 +- 0 sec per loop (using
standard deviation)\n", s)
def test_main_milliseconds(self):
s = self.run_main(seconds_per_increment=0.0055)
- self.assertEqual(s, "100 loops, best of 3: 5.5 msec per loop\n")
+ self.assertIn("100 loops, average of 7: 5.5 +-", s)
+ self.assertIn("msec per loop", s)
def test_main_microseconds(self):
s = self.run_main(seconds_per_increment=0.0000025, switches=['-n100'])
- self.assertEqual(s, "100 loops, best of 3: 2.5 usec per loop\n")
+ self.assertIn("100 loops, average of 7: 2.5", s)
+ self.assertIn("usec per loop", s)
def test_main_fixed_iters(self):
s = self.run_main(seconds_per_increment=2.0, switches=['-n35'])
- self.assertEqual(s, "35 loops, best of 3: 2 sec per loop\n")
+ self.assertIn("35 loops, average of 7: 2 +- 0 sec per loop (using
standard deviation)\n", s)
def test_main_setup(self):
s = self.run_main(seconds_per_increment=2.0,
switches=['-n35', '-s', 'print("CustomSetup")'])
- self.assertEqual(s, "CustomSetup\n" * 3 +
- "35 loops, best of 3: 2 sec per loop\n")
+ self.assertIn("CustomSetup\n" * DEFAULT_REPEAT +
+ "35 loops, average of 7: 2 +- 0 sec per loop (using standard
deviation)\n", s)
def test_main_multiple_setups(self):
s = self.run_main(seconds_per_increment=2.0,
switches=['-n35', '-s', 'a = "CustomSetup"', '-s', 'print(a)'])
- self.assertEqual(s, "CustomSetup\n" * 3 +
- "35 loops, best of 3: 2 sec per loop\n")
+ self.assertIn("CustomSetup\n" * DEFAULT_REPEAT +
+ "35 loops, average of 7: 2 +- 0 sec per loop (using standard
deviation)\n", s)
def test_main_fixed_reps(self):
s = self.run_main(seconds_per_increment=60.0, switches=['-r9'])
- self.assertEqual(s, "10 loops, best of 9: 60 sec per loop\n")
+ self.assertIn("1 loops, average of 9: 60 +- 0 sec per loop (using
standard deviation)\n", s)
def test_main_negative_reps(self):
s = self.run_main(seconds_per_increment=60.0, switches=['-r-5'])
- self.assertEqual(s, "10 loops, best of 1: 60 sec per loop\n")
+ self.assertIn("1 loops, average of 1: 60 +- 0 sec per loop (using
standard deviation)\n", s)
@unittest.skipIf(sys.flags.optimize >= 2, "need __doc__")
def test_main_help(self):
@@ -296,47 +298,54 @@
def test_main_using_time(self):
fake_timer = FakeTimer()
s = self.run_main(switches=['-t'], timer=fake_timer)
- self.assertEqual(s, self.MAIN_DEFAULT_OUTPUT)
+ self.assertIn(self.MAIN_DEFAULT_OUTPUT, s)
self.assertIs(fake_timer.saved_timer, time.time)
def test_main_using_clock(self):
fake_timer = FakeTimer()
s = self.run_main(switches=['-c'], timer=fake_timer)
- self.assertEqual(s, self.MAIN_DEFAULT_OUTPUT)
+ self.assertIn(self.MAIN_DEFAULT_OUTPUT, s)
self.assertIs(fake_timer.saved_timer, time.clock)
def test_main_verbose(self):
s = self.run_main(switches=['-v'])
- self.assertEqual(s, dedent("""\
- 10 loops -> 10 secs
- raw times: 10 10 10
- 10 loops, best of 3: 1 sec per loop
- """))
+ self.assertIn(dedent("""\
+ 1 loops -> 1 secs
+ raw times: 1 1 1 1 1 1 1
+ 1 loops, average of 7: 1 +- 0 sec per loop (using standard
deviation)
+ """), s)
def test_main_very_verbose(self):
s = self.run_main(seconds_per_increment=0.000050, switches=['-vv'])
- self.assertEqual(s, dedent("""\
+ self.assertIn(dedent("""\
+ 1 loops -> 5e-05 secs
10 loops -> 0.0005 secs
100 loops -> 0.005 secs
1000 loops -> 0.05 secs
10000 loops -> 0.5 secs
- raw times: 0.5 0.5 0.5
- 10000 loops, best of 3: 50 usec per loop
- """))
+ raw times: 0.5 0.5 0.5 0.5 0.5 0.5 0.5
+ 10000 loops, average of 7: 50 +- 0 usec per loop (using
standard deviation)
+ """), s)
def test_main_with_time_unit(self):
unit_sec = self.run_main(seconds_per_increment=0.002,
switches=['-u', 'sec'])
- self.assertEqual(unit_sec,
- "1000 loops, best of 3: 0.002 sec per loop\n")
+ self.assertIn("100 loops, average of 7: 0.002",
+ unit_sec)
+ self.assertIn("sec per loop",
+ unit_sec)
unit_msec = self.run_main(seconds_per_increment=0.002,
switches=['-u', 'msec'])
- self.assertEqual(unit_msec,
- "1000 loops, best of 3: 2 msec per loop\n")
+ self.assertIn("100 loops, average of 7: 2",
+ unit_msec)
+ self.assertIn("msec per loop",
+ unit_msec)
unit_usec = self.run_main(seconds_per_increment=0.002,
switches=['-u', 'usec'])
- self.assertEqual(unit_usec,
- "1000 loops, best of 3: 2e+03 usec per loop\n")
+ self.assertIn("100 loops, average of 7: 2e+03",
+ unit_usec)
+ self.assertIn("usec per loop",
+ unit_usec)
# Test invalid unit input
with captured_stderr() as error_stringio:
invalid = self.run_main(seconds_per_increment=0.002,
@@ -354,6 +363,14 @@
s = self.run_main(switches=['-n1', '1/0'])
self.assert_exc_string(error_stringio.getvalue(), 'ZeroDivisionError')
+ def test_main_recommends_perf(self):
+ s = self.run_main(seconds_per_increment=2.0, switches=['-n35', '-s',
'print("CustomSetup")'])
+ self.assertIn(dedent("""\
+ WARNING: timeit is a very unreliable tool. use perf or something
else for real measurements
+ """), s)
+ self.assertIn("-m pip install perf", s)
+
+
if __name__ == '__main__':
unittest.main()
diff --git a/lib-python/3/timeit.py b/lib-python/3/timeit.py
--- a/lib-python/3/timeit.py
+++ b/lib-python/3/timeit.py
@@ -13,7 +13,7 @@
Options:
-n/--number N: how many times to execute 'statement' (default: see below)
- -r/--repeat N: how many times to repeat the timer (default 3)
+ -r/--repeat N: how many times to repeat the timer (default 7)
-s/--setup S: statement to be executed once initially (default 'pass').
Execution time of this setup statement is NOT timed.
-p/--process: use time.process_time() (default is time.perf_counter())
@@ -51,6 +51,8 @@
"""
import gc
+import math
+import os
import sys
import time
import itertools
@@ -59,7 +61,7 @@
dummy_src_name = "<timeit-src>"
default_number = 1000000
-default_repeat = 3
+default_repeat = 7
default_timer = time.perf_counter
_globals = globals
@@ -173,7 +175,8 @@
"""
it = itertools.repeat(None, number)
gcold = gc.isenabled()
- gc.disable()
+ if '__pypy__' not in sys.builtin_module_names:
+ gc.disable() # only do that on CPython
try:
timing = self.inner(it, self.timer)
finally:
@@ -236,6 +239,7 @@
"""
if args is None:
args = sys.argv[1:]
+ origargs = args
import getopt
try:
opts, args = getopt.getopt(args, "n:u:s:r:tcpvh",
@@ -253,7 +257,7 @@
repeat = default_repeat
verbose = 0
time_unit = None
- units = {"usec": 1, "msec": 1e3, "sec": 1e6}
+ units = {'msec': 1000.0, 'usec': 1000000.0, 'sec': 1}
precision = 3
for o, a in opts:
if o in ("-n", "--number"):
@@ -285,17 +289,25 @@
print(__doc__, end=' ')
return 0
setup = "\n".join(setup) or "pass"
+
+ print("WARNING: timeit is a very unreliable tool. use perf or something
else for real measurements")
+ executable = os.path.basename(sys.executable)
+ print("%s -m pip install perf" % executable)
+ print("%s -m perf timeit %s" % (
+ executable,
+ " ".join([(arg if arg.startswith("-") else repr(arg))
+ for arg in origargs]), ))
+ print("-" * 60)
# Include the current directory, so that local imports work (sys.path
# contains the directory of this script, rather than the current
# directory)
- import os
sys.path.insert(0, os.curdir)
if _wrap_timer is not None:
timer = _wrap_timer(timer)
t = Timer(stmt, setup, timer)
if number == 0:
# determine number so that 0.2 <= total time < 2.0
- for i in range(1, 10):
+ for i in range(0, 10):
number = 10**i
try:
x = t.timeit(number)
@@ -307,30 +319,38 @@
if x >= 0.2:
break
try:
- r = t.repeat(repeat, number)
+ timings = t.repeat(repeat, number)
except:
t.print_exc()
return 1
- best = min(r)
if verbose:
- print("raw times:", " ".join(["%.*g" % (precision, x) for x in r]))
- print("%d loops," % number, end=' ')
- usec = best * 1e6 / number
- if time_unit is not None:
- print("best of %d: %.*g %s per loop" % (repeat, precision,
- usec/units[time_unit], time_unit))
+ print("raw times:", " ".join(["%.*g" % (precision, x) for x in
timings]))
+
+ timings = [dt / number for dt in timings]
+
+ def _avg(l):
+ return math.fsum(l) / len(l)
+ def _stdev(l):
+ avg = _avg(l)
+ return (math.fsum([(x - avg) ** 2 for x in l]) / len(l)) ** 0.5
+
+ average = _avg(timings)
+
+ if time_unit is None:
+ scales = [(scale, unit) for unit, scale in units.items()]
+ scales.sort()
+ for scale, time_unit in scales:
+ if average * scale >= 1.0:
+ break
else:
- if usec < 1000:
- print("best of %d: %.*g usec per loop" % (repeat, precision, usec))
- else:
- msec = usec / 1000
- if msec < 1000:
- print("best of %d: %.*g msec per loop" % (repeat,
- precision, msec))
- else:
- sec = msec / 1000
- print("best of %d: %.*g sec per loop" % (repeat,
- precision, sec))
+ print(time_unit)
+ scale = units[time_unit]
+
+ stdev = _stdev(timings)
+ print("%s loops, average of %d: %.*g +- %.*g %s per loop (using standard
deviation)"
+ % (number, repeat,
+ precision, average * scale,
+ precision, stdev * scale, time_unit))
return None
if __name__ == "__main__":
_______________________________________________
pypy-commit mailing list
[email protected]
https://mail.python.org/mailman/listinfo/pypy-commit