##// END OF EJS Templates
Refactor part for "%run -t"
Takafumi Arakaki -
Show More
@@ -1,1118 +1,1124 b''
1 1 # -*- coding: utf-8 -*-
2 2 """Implementation of execution-related magic functions.
3 3 """
4 4 #-----------------------------------------------------------------------------
5 5 # Copyright (c) 2012 The IPython Development Team.
6 6 #
7 7 # Distributed under the terms of the Modified BSD License.
8 8 #
9 9 # The full license is in the file COPYING.txt, distributed with this software.
10 10 #-----------------------------------------------------------------------------
11 11
12 12 #-----------------------------------------------------------------------------
13 13 # Imports
14 14 #-----------------------------------------------------------------------------
15 15
16 16 # Stdlib
17 17 import __builtin__ as builtin_mod
18 18 import ast
19 19 import bdb
20 20 import os
21 21 import sys
22 22 import time
23 23 from StringIO import StringIO
24 24
25 25 # cProfile was added in Python2.5
26 26 try:
27 27 import cProfile as profile
28 28 import pstats
29 29 except ImportError:
30 30 # profile isn't bundled by default in Debian for license reasons
31 31 try:
32 32 import profile, pstats
33 33 except ImportError:
34 34 profile = pstats = None
35 35
36 36 # Our own packages
37 37 from IPython.core import debugger, oinspect
38 38 from IPython.core import magic_arguments
39 39 from IPython.core import page
40 40 from IPython.core.error import UsageError
41 41 from IPython.core.macro import Macro
42 42 from IPython.core.magic import (Magics, magics_class, line_magic, cell_magic,
43 43 line_cell_magic, on_off, needs_local_scope)
44 44 from IPython.testing.skipdoctest import skip_doctest
45 45 from IPython.utils import py3compat
46 46 from IPython.utils.contexts import preserve_keys
47 47 from IPython.utils.io import capture_output
48 48 from IPython.utils.ipstruct import Struct
49 49 from IPython.utils.module_paths import find_mod
50 50 from IPython.utils.path import get_py_filename, unquote_filename, shellglob
51 51 from IPython.utils.timing import clock, clock2
52 52 from IPython.utils.warn import warn, error
53 53
54 54
55 55 #-----------------------------------------------------------------------------
56 56 # Magic implementation classes
57 57 #-----------------------------------------------------------------------------
58 58
59 59 @magics_class
60 60 class ExecutionMagics(Magics):
61 61 """Magics related to code execution, debugging, profiling, etc.
62 62
63 63 """
64 64
65 65 def __init__(self, shell):
66 66 super(ExecutionMagics, self).__init__(shell)
67 67 if profile is None:
68 68 self.prun = self.profile_missing_notice
69 69 # Default execution function used to actually run user code.
70 70 self.default_runner = None
71 71
72 72 def profile_missing_notice(self, *args, **kwargs):
73 73 error("""\
74 74 The profile module could not be found. It has been removed from the standard
75 75 python packages because of its non-free license. To use profiling, install the
76 76 python-profiler package from non-free.""")
77 77
78 78 @skip_doctest
79 79 @line_cell_magic
80 80 def prun(self, parameter_s='', cell=None, user_mode=True,
81 81 opts=None,arg_lst=None,prog_ns=None):
82 82
83 83 """Run a statement through the python code profiler.
84 84
85 85 Usage, in line mode:
86 86 %prun [options] statement
87 87
88 88 Usage, in cell mode:
89 89 %%prun [options] [statement]
90 90 code...
91 91 code...
92 92
93 93 In cell mode, the additional code lines are appended to the (possibly
94 94 empty) statement in the first line. Cell mode allows you to easily
95 95 profile multiline blocks without having to put them in a separate
96 96 function.
97 97
98 98 The given statement (which doesn't require quote marks) is run via the
99 99 python profiler in a manner similar to the profile.run() function.
100 100 Namespaces are internally managed to work correctly; profile.run
101 101 cannot be used in IPython because it makes certain assumptions about
102 102 namespaces which do not hold under IPython.
103 103
104 104 Options:
105 105
106 106 -l <limit>: you can place restrictions on what or how much of the
107 107 profile gets printed. The limit value can be:
108 108
109 109 * A string: only information for function names containing this string
110 110 is printed.
111 111
112 112 * An integer: only these many lines are printed.
113 113
114 114 * A float (between 0 and 1): this fraction of the report is printed
115 115 (for example, use a limit of 0.4 to see the topmost 40% only).
116 116
117 117 You can combine several limits with repeated use of the option. For
118 118 example, '-l __init__ -l 5' will print only the topmost 5 lines of
119 119 information about class constructors.
120 120
121 121 -r: return the pstats.Stats object generated by the profiling. This
122 122 object has all the information about the profile in it, and you can
123 123 later use it for further analysis or in other functions.
124 124
125 125 -s <key>: sort profile by given key. You can provide more than one key
126 126 by using the option several times: '-s key1 -s key2 -s key3...'. The
127 127 default sorting key is 'time'.
128 128
129 129 The following is copied verbatim from the profile documentation
130 130 referenced below:
131 131
132 132 When more than one key is provided, additional keys are used as
133 133 secondary criteria when the there is equality in all keys selected
134 134 before them.
135 135
136 136 Abbreviations can be used for any key names, as long as the
137 137 abbreviation is unambiguous. The following are the keys currently
138 138 defined:
139 139
140 140 Valid Arg Meaning
141 141 "calls" call count
142 142 "cumulative" cumulative time
143 143 "file" file name
144 144 "module" file name
145 145 "pcalls" primitive call count
146 146 "line" line number
147 147 "name" function name
148 148 "nfl" name/file/line
149 149 "stdname" standard name
150 150 "time" internal time
151 151
152 152 Note that all sorts on statistics are in descending order (placing
153 153 most time consuming items first), where as name, file, and line number
154 154 searches are in ascending order (i.e., alphabetical). The subtle
155 155 distinction between "nfl" and "stdname" is that the standard name is a
156 156 sort of the name as printed, which means that the embedded line
157 157 numbers get compared in an odd way. For example, lines 3, 20, and 40
158 158 would (if the file names were the same) appear in the string order
159 159 "20" "3" and "40". In contrast, "nfl" does a numeric compare of the
160 160 line numbers. In fact, sort_stats("nfl") is the same as
161 161 sort_stats("name", "file", "line").
162 162
163 163 -T <filename>: save profile results as shown on screen to a text
164 164 file. The profile is still shown on screen.
165 165
166 166 -D <filename>: save (via dump_stats) profile statistics to given
167 167 filename. This data is in a format understood by the pstats module, and
168 168 is generated by a call to the dump_stats() method of profile
169 169 objects. The profile is still shown on screen.
170 170
171 171 -q: suppress output to the pager. Best used with -T and/or -D above.
172 172
173 173 If you want to run complete programs under the profiler's control, use
174 174 '%run -p [prof_opts] filename.py [args to program]' where prof_opts
175 175 contains profiler specific options as described here.
176 176
177 177 You can read the complete documentation for the profile module with::
178 178
179 179 In [1]: import profile; profile.help()
180 180 """
181 181
182 182 opts_def = Struct(D=[''],l=[],s=['time'],T=[''])
183 183
184 184 if user_mode: # regular user call
185 185 opts,arg_str = self.parse_options(parameter_s,'D:l:rs:T:q',
186 186 list_all=True, posix=False)
187 187 namespace = self.shell.user_ns
188 188 if cell is not None:
189 189 arg_str += '\n' + cell
190 190 else: # called to run a program by %run -p
191 191 try:
192 192 filename = get_py_filename(arg_lst[0])
193 193 except IOError as e:
194 194 try:
195 195 msg = str(e)
196 196 except UnicodeError:
197 197 msg = e.message
198 198 error(msg)
199 199 return
200 200
201 201 arg_str = 'execfile(filename,prog_ns)'
202 202 namespace = {
203 203 'execfile': self.shell.safe_execfile,
204 204 'prog_ns': prog_ns,
205 205 'filename': filename
206 206 }
207 207
208 208 opts.merge(opts_def)
209 209
210 210 prof = profile.Profile()
211 211 try:
212 212 prof = prof.runctx(arg_str,namespace,namespace)
213 213 sys_exit = ''
214 214 except SystemExit:
215 215 sys_exit = """*** SystemExit exception caught in code being profiled."""
216 216
217 217 stats = pstats.Stats(prof).strip_dirs().sort_stats(*opts.s)
218 218
219 219 lims = opts.l
220 220 if lims:
221 221 lims = [] # rebuild lims with ints/floats/strings
222 222 for lim in opts.l:
223 223 try:
224 224 lims.append(int(lim))
225 225 except ValueError:
226 226 try:
227 227 lims.append(float(lim))
228 228 except ValueError:
229 229 lims.append(lim)
230 230
231 231 # Trap output.
232 232 stdout_trap = StringIO()
233 233 stats_stream = stats.stream
234 234 try:
235 235 stats.stream = stdout_trap
236 236 stats.print_stats(*lims)
237 237 finally:
238 238 stats.stream = stats_stream
239 239
240 240 output = stdout_trap.getvalue()
241 241 output = output.rstrip()
242 242
243 243 if 'q' not in opts:
244 244 page.page(output)
245 245 print sys_exit,
246 246
247 247 dump_file = opts.D[0]
248 248 text_file = opts.T[0]
249 249 if dump_file:
250 250 dump_file = unquote_filename(dump_file)
251 251 prof.dump_stats(dump_file)
252 252 print '\n*** Profile stats marshalled to file',\
253 253 repr(dump_file)+'.',sys_exit
254 254 if text_file:
255 255 text_file = unquote_filename(text_file)
256 256 pfile = open(text_file,'w')
257 257 pfile.write(output)
258 258 pfile.close()
259 259 print '\n*** Profile printout saved to text file',\
260 260 repr(text_file)+'.',sys_exit
261 261
262 262 if 'r' in opts:
263 263 return stats
264 264 else:
265 265 return None
266 266
267 267 @line_magic
268 268 def pdb(self, parameter_s=''):
269 269 """Control the automatic calling of the pdb interactive debugger.
270 270
271 271 Call as '%pdb on', '%pdb 1', '%pdb off' or '%pdb 0'. If called without
272 272 argument it works as a toggle.
273 273
274 274 When an exception is triggered, IPython can optionally call the
275 275 interactive pdb debugger after the traceback printout. %pdb toggles
276 276 this feature on and off.
277 277
278 278 The initial state of this feature is set in your configuration
279 279 file (the option is ``InteractiveShell.pdb``).
280 280
281 281 If you want to just activate the debugger AFTER an exception has fired,
282 282 without having to type '%pdb on' and rerunning your code, you can use
283 283 the %debug magic."""
284 284
285 285 par = parameter_s.strip().lower()
286 286
287 287 if par:
288 288 try:
289 289 new_pdb = {'off':0,'0':0,'on':1,'1':1}[par]
290 290 except KeyError:
291 291 print ('Incorrect argument. Use on/1, off/0, '
292 292 'or nothing for a toggle.')
293 293 return
294 294 else:
295 295 # toggle
296 296 new_pdb = not self.shell.call_pdb
297 297
298 298 # set on the shell
299 299 self.shell.call_pdb = new_pdb
300 300 print 'Automatic pdb calling has been turned',on_off(new_pdb)
301 301
302 302 @line_magic
303 303 def debug(self, parameter_s=''):
304 304 """Activate the interactive debugger in post-mortem mode.
305 305
306 306 If an exception has just occurred, this lets you inspect its stack
307 307 frames interactively. Note that this will always work only on the last
308 308 traceback that occurred, so you must call this quickly after an
309 309 exception that you wish to inspect has fired, because if another one
310 310 occurs, it clobbers the previous one.
311 311
312 312 If you want IPython to automatically do this on every exception, see
313 313 the %pdb magic for more details.
314 314 """
315 315 self.shell.debugger(force=True)
316 316
317 317 @line_magic
318 318 def tb(self, s):
319 319 """Print the last traceback with the currently active exception mode.
320 320
321 321 See %xmode for changing exception reporting modes."""
322 322 self.shell.showtraceback()
323 323
324 324 @skip_doctest
325 325 @line_magic
326 326 def run(self, parameter_s='', runner=None,
327 327 file_finder=get_py_filename):
328 328 """Run the named file inside IPython as a program.
329 329
330 330 Usage:\\
331 331 %run [-n -i -t [-N<N>] -d [-b<N>] -p [profile options] -G] file [args]
332 332
333 333 Parameters after the filename are passed as command-line arguments to
334 334 the program (put in sys.argv). Then, control returns to IPython's
335 335 prompt.
336 336
337 337 This is similar to running at a system prompt:\\
338 338 $ python file args\\
339 339 but with the advantage of giving you IPython's tracebacks, and of
340 340 loading all variables into your interactive namespace for further use
341 341 (unless -p is used, see below).
342 342
343 343 The file is executed in a namespace initially consisting only of
344 344 __name__=='__main__' and sys.argv constructed as indicated. It thus
345 345 sees its environment as if it were being run as a stand-alone program
346 346 (except for sharing global objects such as previously imported
347 347 modules). But after execution, the IPython interactive namespace gets
348 348 updated with all variables defined in the program (except for __name__
349 349 and sys.argv). This allows for very convenient loading of code for
350 350 interactive work, while giving each program a 'clean sheet' to run in.
351 351
352 352 Arguments are expanded using shell-like glob match. Patterns
353 353 '*', '?', '[seq]' and '[!seq]' can be used. Additionally,
354 354 tilde '~' will be expanded into user's home directory. Unlike
355 355 real shells, quotation does not suppress expansions. Use
356 356 *two* back slashes (e.g., '\\\\*') to suppress expansions.
357 357 To completely disable these expansions, you can use -G flag.
358 358
359 359 Options:
360 360
361 361 -n: __name__ is NOT set to '__main__', but to the running file's name
362 362 without extension (as python does under import). This allows running
363 363 scripts and reloading the definitions in them without calling code
364 364 protected by an ' if __name__ == "__main__" ' clause.
365 365
366 366 -i: run the file in IPython's namespace instead of an empty one. This
367 367 is useful if you are experimenting with code written in a text editor
368 368 which depends on variables defined interactively.
369 369
370 370 -e: ignore sys.exit() calls or SystemExit exceptions in the script
371 371 being run. This is particularly useful if IPython is being used to
372 372 run unittests, which always exit with a sys.exit() call. In such
373 373 cases you are interested in the output of the test results, not in
374 374 seeing a traceback of the unittest module.
375 375
376 376 -t: print timing information at the end of the run. IPython will give
377 377 you an estimated CPU time consumption for your script, which under
378 378 Unix uses the resource module to avoid the wraparound problems of
379 379 time.clock(). Under Unix, an estimate of time spent on system tasks
380 380 is also given (for Windows platforms this is reported as 0.0).
381 381
382 382 If -t is given, an additional -N<N> option can be given, where <N>
383 383 must be an integer indicating how many times you want the script to
384 384 run. The final timing report will include total and per run results.
385 385
386 386 For example (testing the script uniq_stable.py)::
387 387
388 388 In [1]: run -t uniq_stable
389 389
390 390 IPython CPU timings (estimated):\\
391 391 User : 0.19597 s.\\
392 392 System: 0.0 s.\\
393 393
394 394 In [2]: run -t -N5 uniq_stable
395 395
396 396 IPython CPU timings (estimated):\\
397 397 Total runs performed: 5\\
398 398 Times : Total Per run\\
399 399 User : 0.910862 s, 0.1821724 s.\\
400 400 System: 0.0 s, 0.0 s.
401 401
402 402 -d: run your program under the control of pdb, the Python debugger.
403 403 This allows you to execute your program step by step, watch variables,
404 404 etc. Internally, what IPython does is similar to calling:
405 405
406 406 pdb.run('execfile("YOURFILENAME")')
407 407
408 408 with a breakpoint set on line 1 of your file. You can change the line
409 409 number for this automatic breakpoint to be <N> by using the -bN option
410 410 (where N must be an integer). For example::
411 411
412 412 %run -d -b40 myscript
413 413
414 414 will set the first breakpoint at line 40 in myscript.py. Note that
415 415 the first breakpoint must be set on a line which actually does
416 416 something (not a comment or docstring) for it to stop execution.
417 417
418 418 Or you can specify a breakpoint in a different file::
419 419
420 420 %run -d -b myotherfile.py:20 myscript
421 421
422 422 When the pdb debugger starts, you will see a (Pdb) prompt. You must
423 423 first enter 'c' (without quotes) to start execution up to the first
424 424 breakpoint.
425 425
426 426 Entering 'help' gives information about the use of the debugger. You
427 427 can easily see pdb's full documentation with "import pdb;pdb.help()"
428 428 at a prompt.
429 429
430 430 -p: run program under the control of the Python profiler module (which
431 431 prints a detailed report of execution times, function calls, etc).
432 432
433 433 You can pass other options after -p which affect the behavior of the
434 434 profiler itself. See the docs for %prun for details.
435 435
436 436 In this mode, the program's variables do NOT propagate back to the
437 437 IPython interactive namespace (because they remain in the namespace
438 438 where the profiler executes them).
439 439
440 440 Internally this triggers a call to %prun, see its documentation for
441 441 details on the options available specifically for profiling.
442 442
443 443 There is one special usage for which the text above doesn't apply:
444 444 if the filename ends with .ipy, the file is run as ipython script,
445 445 just as if the commands were written on IPython prompt.
446 446
447 447 -m: specify module name to load instead of script path. Similar to
448 448 the -m option for the python interpreter. Use this option last if you
449 449 want to combine with other %run options. Unlike the python interpreter
450 450 only source modules are allowed no .pyc or .pyo files.
451 451 For example::
452 452
453 453 %run -m example
454 454
455 455 will run the example module.
456 456
457 457 -G: disable shell-like glob expansion of arguments.
458 458
459 459 """
460 460
461 461 # get arguments and set sys.argv for program to be run.
462 462 opts, arg_lst = self.parse_options(parameter_s,
463 463 'nidtN:b:pD:l:rs:T:em:G',
464 464 mode='list', list_all=1)
465 465 if "m" in opts:
466 466 modulename = opts["m"][0]
467 467 modpath = find_mod(modulename)
468 468 if modpath is None:
469 469 warn('%r is not a valid modulename on sys.path'%modulename)
470 470 return
471 471 arg_lst = [modpath] + arg_lst
472 472 try:
473 473 filename = file_finder(arg_lst[0])
474 474 except IndexError:
475 475 warn('you must provide at least a filename.')
476 476 print '\n%run:\n', oinspect.getdoc(self.run)
477 477 return
478 478 except IOError as e:
479 479 try:
480 480 msg = str(e)
481 481 except UnicodeError:
482 482 msg = e.message
483 483 error(msg)
484 484 return
485 485
486 486 if filename.lower().endswith('.ipy'):
487 487 with preserve_keys(self.shell.user_ns, '__file__'):
488 488 self.shell.user_ns['__file__'] = filename
489 489 self.shell.safe_execfile_ipy(filename)
490 490 return
491 491
492 492 # Control the response to exit() calls made by the script being run
493 493 exit_ignore = 'e' in opts
494 494
495 495 # Make sure that the running script gets a proper sys.argv as if it
496 496 # were run from a system shell.
497 497 save_argv = sys.argv # save it for later restoring
498 498
499 499 if 'G' in opts:
500 500 args = arg_lst[1:]
501 501 else:
502 502 # tilde and glob expansion
503 503 args = shellglob(map(os.path.expanduser, arg_lst[1:]))
504 504
505 505 sys.argv = [filename] + args # put in the proper filename
506 506 # protect sys.argv from potential unicode strings on Python 2:
507 507 if not py3compat.PY3:
508 508 sys.argv = [ py3compat.cast_bytes(a) for a in sys.argv ]
509 509
510 510 if 'i' in opts:
511 511 # Run in user's interactive namespace
512 512 prog_ns = self.shell.user_ns
513 513 __name__save = self.shell.user_ns['__name__']
514 514 prog_ns['__name__'] = '__main__'
515 515 main_mod = self.shell.new_main_mod(prog_ns)
516 516 else:
517 517 # Run in a fresh, empty namespace
518 518 if 'n' in opts:
519 519 name = os.path.splitext(os.path.basename(filename))[0]
520 520 else:
521 521 name = '__main__'
522 522
523 523 main_mod = self.shell.new_main_mod()
524 524 prog_ns = main_mod.__dict__
525 525 prog_ns['__name__'] = name
526 526
527 527 # Since '%run foo' emulates 'python foo.py' at the cmd line, we must
528 528 # set the __file__ global in the script's namespace
529 529 prog_ns['__file__'] = filename
530 530
531 531 # pickle fix. See interactiveshell for an explanation. But we need to
532 532 # make sure that, if we overwrite __main__, we replace it at the end
533 533 main_mod_name = prog_ns['__name__']
534 534
535 535 if main_mod_name == '__main__':
536 536 restore_main = sys.modules['__main__']
537 537 else:
538 538 restore_main = False
539 539
540 540 # This needs to be undone at the end to prevent holding references to
541 541 # every single object ever created.
542 542 sys.modules[main_mod_name] = main_mod
543 543
544 544 try:
545 545 stats = None
546 546 with self.shell.readline_no_record:
547 547 if 'p' in opts:
548 548 stats = self.prun('', None, False, opts, arg_lst, prog_ns)
549 549 else:
550 550 if 'd' in opts:
551 551 deb = debugger.Pdb(self.shell.colors)
552 552 # reset Breakpoint state, which is moronically kept
553 553 # in a class
554 554 bdb.Breakpoint.next = 1
555 555 bdb.Breakpoint.bplist = {}
556 556 bdb.Breakpoint.bpbynumber = [None]
557 557 # Set an initial breakpoint to stop execution
558 558 maxtries = 10
559 559 bp_file, bp_line = parse_breakpoint(opts.get('b', ['1'])[0], filename)
560 560 checkline = deb.checkline(bp_file, bp_line)
561 561 if not checkline:
562 562 for bp in range(bp_line + 1, bp_line + maxtries + 1):
563 563 if deb.checkline(bp_file, bp):
564 564 break
565 565 else:
566 566 msg = ("\nI failed to find a valid line to set "
567 567 "a breakpoint\n"
568 568 "after trying up to line: %s.\n"
569 569 "Please set a valid breakpoint manually "
570 570 "with the -b option." % bp)
571 571 error(msg)
572 572 return
573 573 # if we find a good linenumber, set the breakpoint
574 574 deb.do_break('%s:%s' % (bp_file, bp_line))
575 575
576 576 # Mimic Pdb._runscript(...)
577 577 deb._wait_for_mainpyfile = True
578 578 deb.mainpyfile = deb.canonic(filename)
579 579
580 580 # Start file run
581 581 print "NOTE: Enter 'c' at the",
582 582 print "%s prompt to start your script." % deb.prompt
583 583 ns = {'execfile': py3compat.execfile, 'prog_ns': prog_ns}
584 584 try:
585 585 #save filename so it can be used by methods on the deb object
586 586 deb._exec_filename = filename
587 587 deb.run('execfile("%s", prog_ns)' % filename, ns)
588 588
589 589 except:
590 590 etype, value, tb = sys.exc_info()
591 591 # Skip three frames in the traceback: the %run one,
592 592 # one inside bdb.py, and the command-line typed by the
593 593 # user (run by exec in pdb itself).
594 594 self.shell.InteractiveTB(etype, value, tb, tb_offset=3)
595 595 else:
596 596 if runner is None:
597 597 runner = self.default_runner
598 598 if runner is None:
599 599 runner = self.shell.safe_execfile
600
601 def run():
602 runner(filename, prog_ns, prog_ns,
603 exit_ignore=exit_ignore)
604
600 605 if 't' in opts:
601 606 # timed execution
602 607 try:
603 608 nruns = int(opts['N'][0])
604 609 if nruns < 1:
605 610 error('Number of runs must be >=1')
606 611 return
607 612 except (KeyError):
608 613 nruns = 1
609 twall0 = time.time()
610 if nruns == 1:
611 t0 = clock2()
612 runner(filename, prog_ns, prog_ns,
613 exit_ignore=exit_ignore)
614 t1 = clock2()
615 t_usr = t1[0] - t0[0]
616 t_sys = t1[1] - t0[1]
617 print "\nIPython CPU timings (estimated):"
618 print " User : %10.2f s." % t_usr
619 print " System : %10.2f s." % t_sys
620 else:
621 runs = range(nruns)
622 t0 = clock2()
623 for nr in runs:
624 runner(filename, prog_ns, prog_ns,
625 exit_ignore=exit_ignore)
626 t1 = clock2()
627 t_usr = t1[0] - t0[0]
628 t_sys = t1[1] - t0[1]
629 print "\nIPython CPU timings (estimated):"
630 print "Total runs performed:", nruns
631 print " Times : %10s %10s" % ('Total', 'Per run')
632 print " User : %10.2f s, %10.2f s." % (t_usr, t_usr / nruns)
633 print " System : %10.2f s, %10.2f s." % (t_sys, t_sys / nruns)
634 twall1 = time.time()
635 print "Wall time: %10.2f s." % (twall1 - twall0)
636
614 self._run_with_timing(run, nruns)
637 615 else:
638 616 # regular execution
639 runner(filename, prog_ns, prog_ns, exit_ignore=exit_ignore)
617 run()
640 618
641 619 if 'i' in opts:
642 620 self.shell.user_ns['__name__'] = __name__save
643 621 else:
644 622 # The shell MUST hold a reference to prog_ns so after %run
645 623 # exits, the python deletion mechanism doesn't zero it out
646 624 # (leaving dangling references).
647 625 self.shell.cache_main_mod(prog_ns, filename)
648 626 # update IPython interactive namespace
649 627
650 628 # Some forms of read errors on the file may mean the
651 629 # __name__ key was never set; using pop we don't have to
652 630 # worry about a possible KeyError.
653 631 prog_ns.pop('__name__', None)
654 632
655 633 with preserve_keys(self.shell.user_ns, '__file__'):
656 634 self.shell.user_ns.update(prog_ns)
657 635 finally:
658 636 # It's a bit of a mystery why, but __builtins__ can change from
659 637 # being a module to becoming a dict missing some key data after
660 638 # %run. As best I can see, this is NOT something IPython is doing
661 639 # at all, and similar problems have been reported before:
662 640 # http://coding.derkeiler.com/Archive/Python/comp.lang.python/2004-10/0188.html
663 641 # Since this seems to be done by the interpreter itself, the best
664 642 # we can do is to at least restore __builtins__ for the user on
665 643 # exit.
666 644 self.shell.user_ns['__builtins__'] = builtin_mod
667 645
668 646 # Ensure key global structures are restored
669 647 sys.argv = save_argv
670 648 if restore_main:
671 649 sys.modules['__main__'] = restore_main
672 650 else:
673 651 # Remove from sys.modules the reference to main_mod we'd
674 652 # added. Otherwise it will trap references to objects
675 653 # contained therein.
676 654 del sys.modules[main_mod_name]
677 655
678 656 return stats
679
657
658 @staticmethod
659 def _run_with_timing(run, nruns):
660 twall0 = time.time()
661 if nruns == 1:
662 t0 = clock2()
663 run()
664 t1 = clock2()
665 t_usr = t1[0] - t0[0]
666 t_sys = t1[1] - t0[1]
667 print "\nIPython CPU timings (estimated):"
668 print " User : %10.2f s." % t_usr
669 print " System : %10.2f s." % t_sys
670 else:
671 runs = range(nruns)
672 t0 = clock2()
673 for nr in runs:
674 run()
675 t1 = clock2()
676 t_usr = t1[0] - t0[0]
677 t_sys = t1[1] - t0[1]
678 print "\nIPython CPU timings (estimated):"
679 print "Total runs performed:", nruns
680 print " Times : %10s %10s" % ('Total', 'Per run')
681 print " User : %10.2f s, %10.2f s." % (t_usr, t_usr / nruns)
682 print " System : %10.2f s, %10.2f s." % (t_sys, t_sys / nruns)
683 twall1 = time.time()
684 print "Wall time: %10.2f s." % (twall1 - twall0)
685
680 686 @skip_doctest
681 687 @line_cell_magic
682 688 def timeit(self, line='', cell=None):
683 689 """Time execution of a Python statement or expression
684 690
685 691 Usage, in line mode:
686 692 %timeit [-n<N> -r<R> [-t|-c]] statement
687 693 or in cell mode:
688 694 %%timeit [-n<N> -r<R> [-t|-c]] setup_code
689 695 code
690 696 code...
691 697
692 698 Time execution of a Python statement or expression using the timeit
693 699 module. This function can be used both as a line and cell magic:
694 700
695 701 - In line mode you can time a single-line statement (though multiple
696 702 ones can be chained with using semicolons).
697 703
698 704 - In cell mode, the statement in the first line is used as setup code
699 705 (executed but not timed) and the body of the cell is timed. The cell
700 706 body has access to any variables created in the setup code.
701 707
702 708 Options:
703 709 -n<N>: execute the given statement <N> times in a loop. If this value
704 710 is not given, a fitting value is chosen.
705 711
706 712 -r<R>: repeat the loop iteration <R> times and take the best result.
707 713 Default: 3
708 714
709 715 -t: use time.time to measure the time, which is the default on Unix.
710 716 This function measures wall time.
711 717
712 718 -c: use time.clock to measure the time, which is the default on
713 719 Windows and measures wall time. On Unix, resource.getrusage is used
714 720 instead and returns the CPU user time.
715 721
716 722 -p<P>: use a precision of <P> digits to display the timing result.
717 723 Default: 3
718 724
719 725
720 726 Examples
721 727 --------
722 728 ::
723 729
724 730 In [1]: %timeit pass
725 731 10000000 loops, best of 3: 53.3 ns per loop
726 732
727 733 In [2]: u = None
728 734
729 735 In [3]: %timeit u is None
730 736 10000000 loops, best of 3: 184 ns per loop
731 737
732 738 In [4]: %timeit -r 4 u == None
733 739 1000000 loops, best of 4: 242 ns per loop
734 740
735 741 In [5]: import time
736 742
737 743 In [6]: %timeit -n1 time.sleep(2)
738 744 1 loops, best of 3: 2 s per loop
739 745
740 746
741 747 The times reported by %timeit will be slightly higher than those
742 748 reported by the timeit.py script when variables are accessed. This is
743 749 due to the fact that %timeit executes the statement in the namespace
744 750 of the shell, compared with timeit.py, which uses a single setup
745 751 statement to import function or create variables. Generally, the bias
746 752 does not matter as long as results from timeit.py are not mixed with
747 753 those from %timeit."""
748 754
749 755 import timeit
750 756
751 757 opts, stmt = self.parse_options(line,'n:r:tcp:',
752 758 posix=False, strict=False)
753 759 if stmt == "" and cell is None:
754 760 return
755 761
756 762 timefunc = timeit.default_timer
757 763 number = int(getattr(opts, "n", 0))
758 764 repeat = int(getattr(opts, "r", timeit.default_repeat))
759 765 precision = int(getattr(opts, "p", 3))
760 766 if hasattr(opts, "t"):
761 767 timefunc = time.time
762 768 if hasattr(opts, "c"):
763 769 timefunc = clock
764 770
765 771 timer = timeit.Timer(timer=timefunc)
766 772 # this code has tight coupling to the inner workings of timeit.Timer,
767 773 # but is there a better way to achieve that the code stmt has access
768 774 # to the shell namespace?
769 775 transform = self.shell.input_splitter.transform_cell
770 776
771 777 if cell is None:
772 778 # called as line magic
773 779 ast_setup = ast.parse("pass")
774 780 ast_stmt = ast.parse(transform(stmt))
775 781 else:
776 782 ast_setup = ast.parse(transform(stmt))
777 783 ast_stmt = ast.parse(transform(cell))
778 784
779 785 ast_setup = self.shell.transform_ast(ast_setup)
780 786 ast_stmt = self.shell.transform_ast(ast_stmt)
781 787
782 788 # This codestring is taken from timeit.template - we fill it in as an
783 789 # AST, so that we can apply our AST transformations to the user code
784 790 # without affecting the timing code.
785 791 timeit_ast_template = ast.parse('def inner(_it, _timer):\n'
786 792 ' setup\n'
787 793 ' _t0 = _timer()\n'
788 794 ' for _i in _it:\n'
789 795 ' stmt\n'
790 796 ' _t1 = _timer()\n'
791 797 ' return _t1 - _t0\n')
792 798
793 799 class TimeitTemplateFiller(ast.NodeTransformer):
794 800 "This is quite tightly tied to the template definition above."
795 801 def visit_FunctionDef(self, node):
796 802 "Fill in the setup statement"
797 803 self.generic_visit(node)
798 804 if node.name == "inner":
799 805 node.body[:1] = ast_setup.body
800 806
801 807 return node
802 808
803 809 def visit_For(self, node):
804 810 "Fill in the statement to be timed"
805 811 if getattr(getattr(node.body[0], 'value', None), 'id', None) == 'stmt':
806 812 node.body = ast_stmt.body
807 813 return node
808 814
809 815 timeit_ast = TimeitTemplateFiller().visit(timeit_ast_template)
810 816 timeit_ast = ast.fix_missing_locations(timeit_ast)
811 817
812 818 # Track compilation time so it can be reported if too long
813 819 # Minimum time above which compilation time will be reported
814 820 tc_min = 0.1
815 821
816 822 t0 = clock()
817 823 code = compile(timeit_ast, "<magic-timeit>", "exec")
818 824 tc = clock()-t0
819 825
820 826 ns = {}
821 827 exec code in self.shell.user_ns, ns
822 828 timer.inner = ns["inner"]
823 829
824 830 if number == 0:
825 831 # determine number so that 0.2 <= total time < 2.0
826 832 number = 1
827 833 for i in range(1, 10):
828 834 if timer.timeit(number) >= 0.2:
829 835 break
830 836 number *= 10
831 837
832 838 best = min(timer.repeat(repeat, number)) / number
833 839
834 840 print u"%d loops, best of %d: %s per loop" % (number, repeat,
835 841 _format_time(best, precision))
836 842 if tc > tc_min:
837 843 print "Compiler time: %.2f s" % tc
838 844
839 845 @skip_doctest
840 846 @needs_local_scope
841 847 @line_cell_magic
842 848 def time(self,line='', cell=None, local_ns=None):
843 849 """Time execution of a Python statement or expression.
844 850
845 851 The CPU and wall clock times are printed, and the value of the
846 852 expression (if any) is returned. Note that under Win32, system time
847 853 is always reported as 0, since it can not be measured.
848 854
849 855 This function can be used both as a line and cell magic:
850 856
851 857 - In line mode you can time a single-line statement (though multiple
852 858 ones can be chained with using semicolons).
853 859
854 860 - In cell mode, you can time the cell body (a directly
855 861 following statement raises an error).
856 862
857 863 This function provides very basic timing functionality. Use the timeit
858 864 magic for more controll over the measurement.
859 865
860 866 Examples
861 867 --------
862 868 ::
863 869
864 870 In [1]: %time 2**128
865 871 CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s
866 872 Wall time: 0.00
867 873 Out[1]: 340282366920938463463374607431768211456L
868 874
869 875 In [2]: n = 1000000
870 876
871 877 In [3]: %time sum(range(n))
872 878 CPU times: user 1.20 s, sys: 0.05 s, total: 1.25 s
873 879 Wall time: 1.37
874 880 Out[3]: 499999500000L
875 881
876 882 In [4]: %time print 'hello world'
877 883 hello world
878 884 CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s
879 885 Wall time: 0.00
880 886
881 887 Note that the time needed by Python to compile the given expression
882 888 will be reported if it is more than 0.1s. In this example, the
883 889 actual exponentiation is done by Python at compilation time, so while
884 890 the expression can take a noticeable amount of time to compute, that
885 891 time is purely due to the compilation:
886 892
887 893 In [5]: %time 3**9999;
888 894 CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s
889 895 Wall time: 0.00 s
890 896
891 897 In [6]: %time 3**999999;
892 898 CPU times: user 0.00 s, sys: 0.00 s, total: 0.00 s
893 899 Wall time: 0.00 s
894 900 Compiler : 0.78 s
895 901 """
896 902
897 903 # fail immediately if the given expression can't be compiled
898 904
899 905 if line and cell:
900 906 raise UsageError("Can't use statement directly after '%%time'!")
901 907
902 908 if cell:
903 909 expr = self.shell.prefilter(cell,False)
904 910 else:
905 911 expr = self.shell.prefilter(line,False)
906 912
907 913 # Minimum time above which parse time will be reported
908 914 tp_min = 0.1
909 915
910 916 t0 = clock()
911 917 expr_ast = ast.parse(expr)
912 918 tp = clock()-t0
913 919
914 920 # Apply AST transformations
915 921 expr_ast = self.shell.transform_ast(expr_ast)
916 922
917 923 # Minimum time above which compilation time will be reported
918 924 tc_min = 0.1
919 925
920 926 if len(expr_ast.body)==1 and isinstance(expr_ast.body[0], ast.Expr):
921 927 mode = 'eval'
922 928 source = '<timed eval>'
923 929 expr_ast = ast.Expression(expr_ast.body[0].value)
924 930 else:
925 931 mode = 'exec'
926 932 source = '<timed exec>'
927 933 t0 = clock()
928 934 code = compile(expr_ast, source, mode)
929 935 tc = clock()-t0
930 936
931 937 # skew measurement as little as possible
932 938 glob = self.shell.user_ns
933 939 wtime = time.time
934 940 # time execution
935 941 wall_st = wtime()
936 942 if mode=='eval':
937 943 st = clock2()
938 944 out = eval(code, glob, local_ns)
939 945 end = clock2()
940 946 else:
941 947 st = clock2()
942 948 exec code in glob, local_ns
943 949 end = clock2()
944 950 out = None
945 951 wall_end = wtime()
946 952 # Compute actual times and report
947 953 wall_time = wall_end-wall_st
948 954 cpu_user = end[0]-st[0]
949 955 cpu_sys = end[1]-st[1]
950 956 cpu_tot = cpu_user+cpu_sys
951 957 # On windows cpu_sys is always zero, so no new information to the next print
952 958 if sys.platform != 'win32':
953 959 print "CPU times: user %s, sys: %s, total: %s" % \
954 960 (_format_time(cpu_user),_format_time(cpu_sys),_format_time(cpu_tot))
955 961 print "Wall time: %s" % _format_time(wall_time)
956 962 if tc > tc_min:
957 963 print "Compiler : %s" % _format_time(tc)
958 964 if tp > tp_min:
959 965 print "Parser : %s" % _format_time(tp)
960 966 return out
961 967
962 968 @skip_doctest
963 969 @line_magic
964 970 def macro(self, parameter_s=''):
965 971 """Define a macro for future re-execution. It accepts ranges of history,
966 972 filenames or string objects.
967 973
968 974 Usage:\\
969 975 %macro [options] name n1-n2 n3-n4 ... n5 .. n6 ...
970 976
971 977 Options:
972 978
973 979 -r: use 'raw' input. By default, the 'processed' history is used,
974 980 so that magics are loaded in their transformed version to valid
975 981 Python. If this option is given, the raw input as typed as the
976 982 command line is used instead.
977 983
978 984 This will define a global variable called `name` which is a string
979 985 made of joining the slices and lines you specify (n1,n2,... numbers
980 986 above) from your input history into a single string. This variable
981 987 acts like an automatic function which re-executes those lines as if
982 988 you had typed them. You just type 'name' at the prompt and the code
983 989 executes.
984 990
985 991 The syntax for indicating input ranges is described in %history.
986 992
987 993 Note: as a 'hidden' feature, you can also use traditional python slice
988 994 notation, where N:M means numbers N through M-1.
989 995
990 996 For example, if your history contains (%hist prints it)::
991 997
992 998 44: x=1
993 999 45: y=3
994 1000 46: z=x+y
995 1001 47: print x
996 1002 48: a=5
997 1003 49: print 'x',x,'y',y
998 1004
999 1005 you can create a macro with lines 44 through 47 (included) and line 49
1000 1006 called my_macro with::
1001 1007
1002 1008 In [55]: %macro my_macro 44-47 49
1003 1009
1004 1010 Now, typing `my_macro` (without quotes) will re-execute all this code
1005 1011 in one pass.
1006 1012
1007 1013 You don't need to give the line-numbers in order, and any given line
1008 1014 number can appear multiple times. You can assemble macros with any
1009 1015 lines from your input history in any order.
1010 1016
1011 1017 The macro is a simple object which holds its value in an attribute,
1012 1018 but IPython's display system checks for macros and executes them as
1013 1019 code instead of printing them when you type their name.
1014 1020
1015 1021 You can view a macro's contents by explicitly printing it with::
1016 1022
1017 1023 print macro_name
1018 1024
1019 1025 """
1020 1026 opts,args = self.parse_options(parameter_s,'r',mode='list')
1021 1027 if not args: # List existing macros
1022 1028 return sorted(k for k,v in self.shell.user_ns.iteritems() if\
1023 1029 isinstance(v, Macro))
1024 1030 if len(args) == 1:
1025 1031 raise UsageError(
1026 1032 "%macro insufficient args; usage '%macro name n1-n2 n3-4...")
1027 1033 name, codefrom = args[0], " ".join(args[1:])
1028 1034
1029 1035 #print 'rng',ranges # dbg
1030 1036 try:
1031 1037 lines = self.shell.find_user_code(codefrom, 'r' in opts)
1032 1038 except (ValueError, TypeError) as e:
1033 1039 print e.args[0]
1034 1040 return
1035 1041 macro = Macro(lines)
1036 1042 self.shell.define_macro(name, macro)
1037 1043 print 'Macro `%s` created. To execute, type its name (without quotes).' % name
1038 1044 print '=== Macro contents: ==='
1039 1045 print macro,
1040 1046
1041 1047 @magic_arguments.magic_arguments()
1042 1048 @magic_arguments.argument('output', type=str, default='', nargs='?',
1043 1049 help="""The name of the variable in which to store output.
1044 1050 This is a utils.io.CapturedIO object with stdout/err attributes
1045 1051 for the text of the captured output.
1046 1052
1047 1053 CapturedOutput also has a show() method for displaying the output,
1048 1054 and __call__ as well, so you can use that to quickly display the
1049 1055 output.
1050 1056
1051 1057 If unspecified, captured output is discarded.
1052 1058 """
1053 1059 )
1054 1060 @magic_arguments.argument('--no-stderr', action="store_true",
1055 1061 help="""Don't capture stderr."""
1056 1062 )
1057 1063 @magic_arguments.argument('--no-stdout', action="store_true",
1058 1064 help="""Don't capture stdout."""
1059 1065 )
1060 1066 @cell_magic
1061 1067 def capture(self, line, cell):
1062 1068 """run the cell, capturing stdout/err"""
1063 1069 args = magic_arguments.parse_argstring(self.capture, line)
1064 1070 out = not args.no_stdout
1065 1071 err = not args.no_stderr
1066 1072 with capture_output(out, err) as io:
1067 1073 self.shell.run_cell(cell)
1068 1074 if args.output:
1069 1075 self.shell.user_ns[args.output] = io
1070 1076
1071 1077 def parse_breakpoint(text, current_file):
1072 1078 '''Returns (file, line) for file:line and (current_file, line) for line'''
1073 1079 colon = text.find(':')
1074 1080 if colon == -1:
1075 1081 return current_file, int(text)
1076 1082 else:
1077 1083 return text[:colon], int(text[colon+1:])
1078 1084
1079 1085 def _format_time(timespan, precision=3):
1080 1086 """Formats the timespan in a human readable form"""
1081 1087 import math
1082 1088
1083 1089 if timespan >= 60.0:
1084 1090 # we have more than a minute, format that in a human readable form
1085 1091 # Idea from http://snipplr.com/view/5713/
1086 1092 parts = [("d", 60*60*24),("h", 60*60),("min", 60), ("s", 1)]
1087 1093 time = []
1088 1094 leftover = timespan
1089 1095 for suffix, length in parts:
1090 1096 value = int(leftover / length)
1091 1097 if value > 0:
1092 1098 leftover = leftover % length
1093 1099 time.append(u'%s%s' % (str(value), suffix))
1094 1100 if leftover < 1:
1095 1101 break
1096 1102 return " ".join(time)
1097 1103
1098 1104
1099 1105 # Unfortunately the unicode 'micro' symbol can cause problems in
1100 1106 # certain terminals.
1101 1107 # See bug: https://bugs.launchpad.net/ipython/+bug/348466
1102 1108 # Try to prevent crashes by being more secure than it needs to
1103 1109 # E.g. eclipse is able to print a µ, but has no sys.stdout.encoding set.
1104 1110 units = [u"s", u"ms",u'us',"ns"] # the save value
1105 1111 if hasattr(sys.stdout, 'encoding') and sys.stdout.encoding:
1106 1112 try:
1107 1113 u'\xb5'.encode(sys.stdout.encoding)
1108 1114 units = [u"s", u"ms",u'\xb5s',"ns"]
1109 1115 except:
1110 1116 pass
1111 1117 scaling = [1, 1e3, 1e6, 1e9]
1112 1118
1113 1119 if timespan > 0.0:
1114 1120 order = min(-int(math.floor(math.log10(timespan)) // 3), 3)
1115 1121 else:
1116 1122 order = 3
1117 1123 ret = u"%.*g %s" % (precision, timespan * scaling[order], units[order])
1118 1124 return ret
General Comments 0
You need to be logged in to leave comments. Login now