From 50cb32f820303725c016f57b7dec581635180e53 2013-02-05 15:34:30 From: Thomas Kluyver Date: 2013-02-05 15:34:30 Subject: [PATCH] Merge pull request #2855 from JanSchulz/2751_timit time(it) magic: Implement minutes/hour formatting and "%%time" cell magic --- diff --git a/IPython/core/magics/execution.py b/IPython/core/magics/execution.py index dc6d8cc..76bea6c 100644 --- a/IPython/core/magics/execution.py +++ b/IPython/core/magics/execution.py @@ -1,3 +1,4 @@ +# -*- coding: utf-8 -*- """Implementation of execution-related magic functions. """ #----------------------------------------------------------------------------- @@ -675,7 +676,7 @@ python-profiler package from non-free.""") del sys.modules[main_mod_name] return stats - + @skip_doctest @line_cell_magic def timeit(self, line='', cell=None): @@ -746,31 +747,6 @@ python-profiler package from non-free.""") those from %timeit.""" import timeit - import math - - # XXX: Unfortunately the unicode 'micro' symbol can cause problems in - # certain terminals. Until we figure out a robust way of - # auto-detecting if the terminal can deal with it, use plain 'us' for - # microseconds. I am really NOT happy about disabling the proper - # 'micro' prefix, but crashing is worse... If anyone knows what the - # right solution for this is, I'm all ears... - # - # Note: using - # - # s = u'\xb5' - # s.encode(sys.getdefaultencoding()) - # - # is not sufficient, as I've seen terminals where that fails but - # print s - # - # succeeds - # - # See bug: https://bugs.launchpad.net/ipython/+bug/348466 - - #units = [u"s", u"ms",u'\xb5',"ns"] - units = [u"s", u"ms",u'us',"ns"] - - scaling = [1, 1e3, 1e6, 1e9] opts, stmt = self.parse_options(line,'n:r:tcp:', posix=False, strict=False) @@ -855,50 +831,49 @@ python-profiler package from non-free.""") best = min(timer.repeat(repeat, number)) / number - if best > 0.0 and best < 1000.0: - order = min(-int(math.floor(math.log10(best)) // 3), 3) - elif best >= 1000.0: - order = 0 - else: - order = 3 - print u"%d loops, best of %d: %.*g %s per loop" % (number, repeat, - precision, - best * scaling[order], - units[order]) + print u"%d loops, best of %d: %s per loop" % (number, repeat, + _format_time(best, precision)) if tc > tc_min: print "Compiler time: %.2f s" % tc @skip_doctest @needs_local_scope - @line_magic - def time(self,parameter_s, local_ns=None): + @line_cell_magic + def time(self,line='', cell=None, local_ns=None): """Time execution of a Python statement or expression. The CPU and wall clock times are printed, and the value of the expression (if any) is returned. Note that under Win32, system time is always reported as 0, since it can not be measured. + + This function can be used both as a line and cell magic: + + - In line mode you can time a single-line statement (though multiple + ones can be chained with using semicolons). - This function provides very basic timing functionality. In Python - 2.3, the timeit module offers more control and sophistication, so this - could be rewritten to use it (patches welcome). + - In cell mode, you can time the cell body (a directly + following statement raises an error). + + This function provides very basic timing functionality. Use the timeit + magic for more controll over the measurement. Examples -------- :: - In [1]: time 2**128 + In [1]: %time 2**128 CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s Wall time: 0.00 Out[1]: 340282366920938463463374607431768211456L In [2]: n = 1000000 - In [3]: time sum(range(n)) + In [3]: %time sum(range(n)) CPU times: user 1.20 s, sys: 0.05 s, total: 1.25 s Wall time: 1.37 Out[3]: 499999500000L - In [4]: time print 'hello world' + In [4]: %time print 'hello world' hello world CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s Wall time: 0.00 @@ -909,19 +884,25 @@ python-profiler package from non-free.""") the expression can take a noticeable amount of time to compute, that time is purely due to the compilation: - In [5]: time 3**9999; + In [5]: %time 3**9999; CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s Wall time: 0.00 s - In [6]: time 3**999999; + In [6]: %time 3**999999; CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s Wall time: 0.00 s Compiler : 0.78 s """ # fail immediately if the given expression can't be compiled - - expr = self.shell.prefilter(parameter_s,False) + + if line and cell: + raise UsageError("Can't use statement directly after '%%time'!") + + if cell: + expr = self.shell.prefilter(cell,False) + else: + expr = self.shell.prefilter(line,False) # Minimum time above which parse time will be reported tp_min = 0.1 @@ -967,13 +948,13 @@ python-profiler package from non-free.""") cpu_user = end[0]-st[0] cpu_sys = end[1]-st[1] cpu_tot = cpu_user+cpu_sys - print "CPU times: user %.2f s, sys: %.2f s, total: %.2f s" % \ - (cpu_user,cpu_sys,cpu_tot) - print "Wall time: %.2f s" % wall_time + print "CPU times: user %s, sys: %s, total: %s" % \ + (_format_time(cpu_user),_format_time(cpu_sys),_format_time(cpu_tot)) + print "Wall time: %s" % _format_time(wall_time) if tc > tc_min: - print "Compiler : %.2f s" % tc + print "Compiler : %s" % _format_time(tc) if tp > tp_min: - print "Parser : %.2f s" % tp + print "Parser : %s" % _format_time(tp) return out @skip_doctest @@ -1092,3 +1073,44 @@ def parse_breakpoint(text, current_file): return current_file, int(text) else: return text[:colon], int(text[colon+1:]) + +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/ + parts = [("d", 60*60*24),("h", 60*60),("min", 60), ("s", 1)] + time = [] + leftover = timespan + for suffix, length in parts: + value = int(leftover / length) + if value > 0: + leftover = leftover % length + time.append(u'%s%s' % (str(value), suffix)) + if leftover < 1: + break + return " ".join(time) + + + # Unfortunately the unicode 'micro' symbol can cause problems in + # certain terminals. + # See bug: https://bugs.launchpad.net/ipython/+bug/348466 + # Try to prevent crashes by being more secure than it needs to + # E.g. eclipse is able to print a ยต, but has no sys.stdout.encoding set. + units = [u"s", u"ms",u'us',"ns"] # the save value + if hasattr(sys.stdout, 'encoding') and sys.stdout.encoding: + try: + u'\xb5'.encode(sys.stdout.encoding) + units = [u"s", u"ms",u'\xb5s',"ns"] + except: + pass + scaling = [1, 1e3, 1e6, 1e9] + + if timespan > 0.0: + order = min(-int(math.floor(math.log10(timespan)) // 3), 3) + else: + order = 3 + ret = u"%.*g %s" % (precision, timespan * scaling[order], units[order]) + return ret diff --git a/IPython/core/tests/test_magic.py b/IPython/core/tests/test_magic.py index 4a7c8fb..1f70569 100644 --- a/IPython/core/tests/test_magic.py +++ b/IPython/core/tests/test_magic.py @@ -262,9 +262,6 @@ def test_reset_in_length(): _ip.run_cell("reset -f in") nt.assert_true(len(_ip.user_ns['In']) == _ip.displayhook.prompt_count+1) -def test_time(): - _ip.magic('time None') - def test_tb_syntaxerror(): """test %tb after a SyntaxError""" ip = get_ipython() @@ -286,13 +283,13 @@ def test_tb_syntaxerror(): def test_time(): ip = get_ipython() - with tt.AssertPrints("CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s"): + with tt.AssertPrints("CPU times: user 0 ns, sys: 0 ns, total: 0 ns"): ip.run_cell("%time None") ip.run_cell("def f(kmjy):\n" " %time print (2*kmjy)") - with tt.AssertPrints("CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s"): + with tt.AssertPrints("CPU times: user 0 ns, sys: 0 ns, total: 0 ns"): with tt.AssertPrints("hihi", suppress=False): ip.run_cell("f('hi')")