From e2d12d2c181f1e1f25609bbdcc8366c211888795 2012-09-27 14:19:29
From: Thomas Kluyver <takowl@gmail.com>
Date: 2012-09-27 14:19:29
Subject: [PATCH] Make %time magic work with AST transformations

---

diff --git a/IPython/core/magics/execution.py b/IPython/core/magics/execution.py
index af73e1a..c8157e6 100644
--- a/IPython/core/magics/execution.py
+++ b/IPython/core/magics/execution.py
@@ -892,20 +892,31 @@ python-profiler package from non-free.""")
         # fail immediately if the given expression can't be compiled
 
         expr = self.shell.prefilter(parameter_s,False)
+        
+        # Minimum time above which parse time will be reported
+        tp_min = 0.1
+        
+        t0 = clock()
+        expr_ast = ast.parse(expr)
+        tp = clock()-t0
+        
+        # Apply AST transformations
+        expr_ast = self.shell.transform_ast(expr_ast)
 
         # Minimum time above which compilation time will be reported
         tc_min = 0.1
 
-        try:
+        if len(expr_ast.body)==1 and isinstance(expr_ast.body[0], ast.Expr):
             mode = 'eval'
-            t0 = clock()
-            code = compile(expr,'<timed eval>',mode)
-            tc = clock()-t0
-        except SyntaxError:
+            source = '<timed eval>'
+            expr_ast = ast.Expression(expr_ast.body[0].value)
+        else:
             mode = 'exec'
-            t0 = clock()
-            code = compile(expr,'<timed exec>',mode)
-            tc = clock()-t0
+            source = '<timed exec>'
+        t0 = clock()
+        code = compile(expr_ast, source, mode)
+        tc = clock()-t0
+        
         # skew measurement as little as possible
         glob = self.shell.user_ns
         wtime = time.time
@@ -931,6 +942,8 @@ python-profiler package from non-free.""")
         print "Wall time: %.2f s" % wall_time
         if tc > tc_min:
             print "Compiler : %.2f s" % tc
+        if tp > tp_min:
+            print "Parser   : %.2f s" % tp
         return out
 
     @skip_doctest
diff --git a/IPython/core/tests/test_interactiveshell.py b/IPython/core/tests/test_interactiveshell.py
index 5fb10f8..652fefc 100644
--- a/IPython/core/tests/test_interactiveshell.py
+++ b/IPython/core/tests/test_interactiveshell.py
@@ -452,6 +452,23 @@ class TestAstTransform(unittest.TestCase):
         with tt.AssertPrints("best of "):
             ip.run_cell_magic("timeit", "-n1 f(2)", "f(3)")
         self.assertEqual(called, set([-2, -3]))
+    
+    def test_time(self):
+        called = []
+        def f(x):
+            called.append(x)
+        ip.push({'f':f})
+        
+        # Test with an expression
+        with tt.AssertPrints("CPU times"):
+            ip.run_line_magic("time", "f(5+9)")
+        self.assertEqual(called, [-14])
+        called[:] = []
+        
+        # Test with a statement (different code path)
+        with tt.AssertPrints("CPU times"):
+            ip.run_line_magic("time", "a = f(-3 + -2)")
+        self.assertEqual(called, [5])
 
 class IntegerWrapper(ast.NodeTransformer):
     """Wraps all integers in a call to Integer()"""