Author: Carl Friedrich Bolz <cfb...@gmx.de>
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
pypy-commit@python.org
https://mail.python.org/mailman/listinfo/pypy-commit

Reply via email to