Merge pull request #9984 from pablogsal/master

Improve %timeit magic using average + standard deviation instead of best/worst

IPython/core/magics/execution.py

@@ -15,6 +15,7 b' import os'
 import sys
 import time
 import timeit
+import math
 from pdb import Restart
 
 # cProfile was added in Python2.5
@@ -70,7 +71,6 b' class TimeitResult(object):'
     compile_time: (float) time of statement compilation (s)
 
     """
-
     def __init__(self, loops, repeat, best, worst, all_runs, compile_time, precision):
         self.loops = loops
         self.repeat = repeat
@@ -79,15 +79,27 b' class TimeitResult(object):'
         self.all_runs = all_runs
         self.compile_time = compile_time
         self._precision = precision
+        self.timings = [ dt / self.loops for dt in all_runs]
+
+    @property
+    def average(self):
+        return math.fsum(self.timings) / len(self.timings)
+
+    @property
+    def stdev(self):
+        mean = self.average
+        return (math.fsum([(x - mean) ** 2 for x in self.timings]) / len(self.timings)) ** 0.5
+
+    def __str__(self):
+        return (u"%s loop%s, average of %d: %s +- %s per loop (using standard deviation)"
+                   % (self.loops,"" if self.loops == 1 else "s", self.repeat,
+                      _format_time(self.average, self._precision),
+                      _format_time(self.stdev, self._precision)))
 
     def _repr_pretty_(self, p , cycle):
-         if self.loops == 1:  # No s at "loops" if only one loop
-             unic =  u"%d loop, best of %d: %s per loop" % (self.loops, self.repeat,
-                                            _format_time(self.best, self._precision))
-         else:
-             unic =  u"%d loops, best of %d: %s per loop" % (self.loops, self.repeat,
-                                            _format_time(self.best, self._precision))
-         p.text(u'<TimeitResult : '+unic+u'>')
+       unic = self.__str__()
+       p.text(u'<TimeitResult : '+unic+u'>')
+
 
 
 class TimeitTemplateFiller(ast.NodeTransformer):
@@ -950,20 +962,20 b' python-profiler package from non-free.""")'
         ::
 
           In [1]: %timeit pass
-          10000000 loops, best of 3: 53.3 ns per loop
+          100000000 loops, average of 7: 5.48 ns +- 0.354 ns per loop (using standard deviation)
 
           In [2]: u = None
 
           In [3]: %timeit u is None
-          10000000 loops, best of 3: 184 ns per loop
+          10000000 loops, average of 7: 22.7 ns +- 2.33 ns per loop (using standard deviation)
 
           In [4]: %timeit -r 4 u == None
-          1000000 loops, best of 4: 242 ns per loop
+          10000000 loops, average of 4: 27.5 ns +- 2.91 ns per loop (using standard deviation)
 
           In [5]: import time
 
           In [6]: %timeit -n1 time.sleep(2)
-          1 loop, best of 3: 2 s per loop
+          1 loop, average of 7: 2 s +- 4.71 µs per loop (using standard deviation)
 
 
         The times reported by %timeit will be slightly higher than those
@@ -981,7 +993,8 b' python-profiler package from non-free.""")'
         
         timefunc = timeit.default_timer
         number = int(getattr(opts, "n", 0))
-        repeat = int(getattr(opts, "r", timeit.default_repeat))
+        default_repeat = 7 if timeit.default_repeat < 7 else timeit.default_repeat
+        repeat = int(getattr(opts, "r", default_repeat))
         precision = int(getattr(opts, "p", 3))
         quiet = 'q' in opts
         return_result = 'o' in opts
@@ -1036,22 +1049,18 b' python-profiler package from non-free.""")'
         # This is used to check if there is a huge difference between the
         # best and worst timings.
         # Issue: https://github.com/ipython/ipython/issues/6471
-        worst_tuning = 0
         if number == 0:
             # determine number so that 0.2 <= total time < 2.0
-            number = 1
-            for _ in range(1, 10):
+            for index in range(0, 10):
+                number = 10 ** index
                 time_number = timer.timeit(number)
-                worst_tuning = max(worst_tuning, time_number / number)
                 if time_number >= 0.2:
                     break
-                number *= 10
+
         all_runs = timer.repeat(repeat, number)
         best = min(all_runs) / number
-
         worst = max(all_runs) / number
-        if worst_tuning:
-            worst = max(worst, worst_tuning)
+        timeit_result = TimeitResult(number, repeat, best, worst, all_runs, tc, precision)
 
         if not quiet :
             # Check best timing is greater than zero to avoid a
@@ -1063,16 +1072,13 b' python-profiler package from non-free.""")'
                 print("The slowest run took %0.2f times longer than the "
                       "fastest. This could mean that an intermediate result "
                       "is being cached." % (worst / best))
-            if number == 1:  # No s at "loops" if only one loop
-                print(u"%d loop, best of %d: %s per loop" % (number, repeat,
-                                                              _format_time(best, precision)))
-            else:
-                print(u"%d loops, best of %d: %s per loop" % (number, repeat,
-                                                              _format_time(best, precision)))
+           
+            print( timeit_result )
+
             if tc > tc_min:
                 print("Compiler time: %.2f s" % tc)
         if return_result:
-            return TimeitResult(number, repeat, best, worst, all_runs, tc, precision)
+            return timeit_result
 
     @skip_doctest
     @needs_local_scope
@@ -1326,8 +1332,7 b' def parse_breakpoint(text, current_file):'
     
 def _format_time(timespan, precision=3):
     """Formats the timespan in a human readable form"""
-    import math
-    
+
     if timespan >= 60.0:
         # we have more than a minute, format that in a human readable form
         # Idea from http://snipplr.com/view/5713/

IPython/core/tests/test_interactiveshell.py

@@ -649,12 +649,12 b' class TestAstTransform(unittest.TestCase):'
             called.add(x)
         ip.push({'f':f})
         
-        with tt.AssertPrints("best of "):
+        with tt.AssertPrints("average of "):
             ip.run_line_magic("timeit", "-n1 f(1)")
         self.assertEqual(called, {-1})
         called.clear()
-        
-        with tt.AssertPrints("best of "):
+
+        with tt.AssertPrints("average of "):
             ip.run_cell_magic("timeit", "-n1 f(2)", "f(3)")
         self.assertEqual(called, {-2, -3})
     
@@ -721,13 +721,13 b' class TestAstTransform2(unittest.TestCase):'
         def f(x):
             called.add(x)
         ip.push({'f':f})
-        
-        with tt.AssertPrints("best of "):
+
+        with tt.AssertPrints("average of "):
             ip.run_line_magic("timeit", "-n1 f(1)")
         self.assertEqual(called, {(1,)})
         called.clear()
-        
-        with tt.AssertPrints("best of "):
+
+        with tt.AssertPrints("average of "):
             ip.run_cell_magic("timeit", "-n1 f(2)", "f(3)")
         self.assertEqual(called, {(2,), (3,)})