timeit.py 13 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381
  1. #! /usr/bin/env python3
  2. """Tool for measuring execution time of small code snippets.
  3. This module avoids a number of common traps for measuring execution
  4. times. See also Tim Peters' introduction to the Algorithms chapter in
  5. the Python Cookbook, published by O'Reilly.
  6. Library usage: see the Timer class.
  7. Command line usage:
  8. python timeit.py [-n N] [-r N] [-s S] [-p] [-h] [--] [statement]
  9. Options:
  10. -n/--number N: how many times to execute 'statement' (default: see below)
  11. -r/--repeat N: how many times to repeat the timer (default 5)
  12. -s/--setup S: statement to be executed once initially (default 'pass').
  13. Execution time of this setup statement is NOT timed.
  14. -p/--process: use time.process_time() (default is time.perf_counter())
  15. -v/--verbose: print raw timing results; repeat for more digits precision
  16. -u/--unit: set the output time unit (nsec, usec, msec, or sec)
  17. -h/--help: print this usage message and exit
  18. --: separate options from statement, use when statement starts with -
  19. statement: statement to be timed (default 'pass')
  20. A multi-line statement may be given by specifying each line as a
  21. separate argument; indented lines are possible by enclosing an
  22. argument in quotes and using leading spaces. Multiple -s options are
  23. treated similarly.
  24. If -n is not given, a suitable number of loops is calculated by trying
  25. increasing numbers from the sequence 1, 2, 5, 10, 20, 50, ... until the
  26. total time is at least 0.2 seconds.
  27. Note: there is a certain baseline overhead associated with executing a
  28. pass statement. It differs between versions. The code here doesn't try
  29. to hide it, but you should be aware of it. The baseline overhead can be
  30. measured by invoking the program without arguments.
  31. Classes:
  32. Timer
  33. Functions:
  34. timeit(string, string) -> float
  35. repeat(string, string) -> list
  36. default_timer() -> float
  37. """
  38. import gc
  39. import itertools
  40. import sys
  41. import time
  42. __all__ = ["Timer", "timeit", "repeat", "default_timer"]
  43. dummy_src_name = "<timeit-src>"
  44. default_number = 1000000
  45. default_repeat = 5
  46. default_timer = time.perf_counter
  47. _globals = globals
  48. # Don't change the indentation of the template; the reindent() calls
  49. # in Timer.__init__() depend on setup being indented 4 spaces and stmt
  50. # being indented 8 spaces.
  51. template = """
  52. def inner(_it, _timer{init}):
  53. {setup}
  54. _t0 = _timer()
  55. for _i in _it:
  56. {stmt}
  57. pass
  58. _t1 = _timer()
  59. return _t1 - _t0
  60. """
  61. def reindent(src, indent):
  62. """Helper to reindent a multi-line statement."""
  63. return src.replace("\n", "\n" + " " * indent)
  64. class Timer:
  65. """Class for timing execution speed of small code snippets.
  66. The constructor takes a statement to be timed, an additional
  67. statement used for setup, and a timer function. Both statements
  68. default to 'pass'; the timer function is platform-dependent (see
  69. module doc string). If 'globals' is specified, the code will be
  70. executed within that namespace (as opposed to inside timeit's
  71. namespace).
  72. To measure the execution time of the first statement, use the
  73. timeit() method. The repeat() method is a convenience to call
  74. timeit() multiple times and return a list of results.
  75. The statements may contain newlines, as long as they don't contain
  76. multi-line string literals.
  77. """
  78. def __init__(self, stmt="pass", setup="pass", timer=default_timer,
  79. globals=None):
  80. """Constructor. See class doc string."""
  81. self.timer = timer
  82. local_ns = {}
  83. global_ns = _globals() if globals is None else globals
  84. init = ''
  85. if isinstance(setup, str):
  86. # Check that the code can be compiled outside a function
  87. compile(setup, dummy_src_name, "exec")
  88. stmtprefix = setup + '\n'
  89. setup = reindent(setup, 4)
  90. elif callable(setup):
  91. local_ns['_setup'] = setup
  92. init += ', _setup=_setup'
  93. stmtprefix = ''
  94. setup = '_setup()'
  95. else:
  96. raise ValueError("setup is neither a string nor callable")
  97. if isinstance(stmt, str):
  98. # Check that the code can be compiled outside a function
  99. compile(stmtprefix + stmt, dummy_src_name, "exec")
  100. stmt = reindent(stmt, 8)
  101. elif callable(stmt):
  102. local_ns['_stmt'] = stmt
  103. init += ', _stmt=_stmt'
  104. stmt = '_stmt()'
  105. else:
  106. raise ValueError("stmt is neither a string nor callable")
  107. src = template.format(stmt=stmt, setup=setup, init=init)
  108. self.src = src # Save for traceback display
  109. code = compile(src, dummy_src_name, "exec")
  110. exec(code, global_ns, local_ns)
  111. self.inner = local_ns["inner"]
  112. def print_exc(self, file=None):
  113. """Helper to print a traceback from the timed code.
  114. Typical use:
  115. t = Timer(...) # outside the try/except
  116. try:
  117. t.timeit(...) # or t.repeat(...)
  118. except:
  119. t.print_exc()
  120. The advantage over the standard traceback is that source lines
  121. in the compiled template will be displayed.
  122. The optional file argument directs where the traceback is
  123. sent; it defaults to sys.stderr.
  124. """
  125. import linecache, traceback
  126. if self.src is not None:
  127. linecache.cache[dummy_src_name] = (len(self.src),
  128. None,
  129. self.src.split("\n"),
  130. dummy_src_name)
  131. # else the source is already stored somewhere else
  132. traceback.print_exc(file=file)
  133. def timeit(self, number=default_number):
  134. """Time 'number' executions of the main statement.
  135. To be precise, this executes the setup statement once, and
  136. then returns the time it takes to execute the main statement
  137. a number of times, as float seconds if using the default timer. The
  138. argument is the number of times through the loop, defaulting
  139. to one million. The main statement, the setup statement and
  140. the timer function to be used are passed to the constructor.
  141. """
  142. it = itertools.repeat(None, number)
  143. gcold = gc.isenabled()
  144. gc.disable()
  145. try:
  146. timing = self.inner(it, self.timer)
  147. finally:
  148. if gcold:
  149. gc.enable()
  150. return timing
  151. def repeat(self, repeat=default_repeat, number=default_number):
  152. """Call timeit() a few times.
  153. This is a convenience function that calls the timeit()
  154. repeatedly, returning a list of results. The first argument
  155. specifies how many times to call timeit(), defaulting to 5;
  156. the second argument specifies the timer argument, defaulting
  157. to one million.
  158. Note: it's tempting to calculate mean and standard deviation
  159. from the result vector and report these. However, this is not
  160. very useful. In a typical case, the lowest value gives a
  161. lower bound for how fast your machine can run the given code
  162. snippet; higher values in the result vector are typically not
  163. caused by variability in Python's speed, but by other
  164. processes interfering with your timing accuracy. So the min()
  165. of the result is probably the only number you should be
  166. interested in. After that, you should look at the entire
  167. vector and apply common sense rather than statistics.
  168. """
  169. r = []
  170. for i in range(repeat):
  171. t = self.timeit(number)
  172. r.append(t)
  173. return r
  174. def autorange(self, callback=None):
  175. """Return the number of loops and time taken so that total time >= 0.2.
  176. Calls the timeit method with increasing numbers from the sequence
  177. 1, 2, 5, 10, 20, 50, ... until the time taken is at least 0.2
  178. second. Returns (number, time_taken).
  179. If *callback* is given and is not None, it will be called after
  180. each trial with two arguments: ``callback(number, time_taken)``.
  181. """
  182. i = 1
  183. while True:
  184. for j in 1, 2, 5:
  185. number = i * j
  186. time_taken = self.timeit(number)
  187. if callback:
  188. callback(number, time_taken)
  189. if time_taken >= 0.2:
  190. return (number, time_taken)
  191. i *= 10
  192. def timeit(stmt="pass", setup="pass", timer=default_timer,
  193. number=default_number, globals=None):
  194. """Convenience function to create Timer object and call timeit method."""
  195. return Timer(stmt, setup, timer, globals).timeit(number)
  196. def repeat(stmt="pass", setup="pass", timer=default_timer,
  197. repeat=default_repeat, number=default_number, globals=None):
  198. """Convenience function to create Timer object and call repeat method."""
  199. return Timer(stmt, setup, timer, globals).repeat(repeat, number)
  200. def main(args=None, *, _wrap_timer=None):
  201. """Main program, used when run as a script.
  202. The optional 'args' argument specifies the command line to be parsed,
  203. defaulting to sys.argv[1:].
  204. The return value is an exit code to be passed to sys.exit(); it
  205. may be None to indicate success.
  206. When an exception happens during timing, a traceback is printed to
  207. stderr and the return value is 1. Exceptions at other times
  208. (including the template compilation) are not caught.
  209. '_wrap_timer' is an internal interface used for unit testing. If it
  210. is not None, it must be a callable that accepts a timer function
  211. and returns another timer function (used for unit testing).
  212. """
  213. if args is None:
  214. args = sys.argv[1:]
  215. import getopt
  216. try:
  217. opts, args = getopt.getopt(args, "n:u:s:r:pvh",
  218. ["number=", "setup=", "repeat=",
  219. "process", "verbose", "unit=", "help"])
  220. except getopt.error as err:
  221. print(err)
  222. print("use -h/--help for command line help")
  223. return 2
  224. timer = default_timer
  225. stmt = "\n".join(args) or "pass"
  226. number = 0 # auto-determine
  227. setup = []
  228. repeat = default_repeat
  229. verbose = 0
  230. time_unit = None
  231. units = {"nsec": 1e-9, "usec": 1e-6, "msec": 1e-3, "sec": 1.0}
  232. precision = 3
  233. for o, a in opts:
  234. if o in ("-n", "--number"):
  235. number = int(a)
  236. if o in ("-s", "--setup"):
  237. setup.append(a)
  238. if o in ("-u", "--unit"):
  239. if a in units:
  240. time_unit = a
  241. else:
  242. print("Unrecognized unit. Please select nsec, usec, msec, or sec.",
  243. file=sys.stderr)
  244. return 2
  245. if o in ("-r", "--repeat"):
  246. repeat = int(a)
  247. if repeat <= 0:
  248. repeat = 1
  249. if o in ("-p", "--process"):
  250. timer = time.process_time
  251. if o in ("-v", "--verbose"):
  252. if verbose:
  253. precision += 1
  254. verbose += 1
  255. if o in ("-h", "--help"):
  256. print(__doc__, end=' ')
  257. return 0
  258. setup = "\n".join(setup) or "pass"
  259. # Include the current directory, so that local imports work (sys.path
  260. # contains the directory of this script, rather than the current
  261. # directory)
  262. import os
  263. sys.path.insert(0, os.curdir)
  264. if _wrap_timer is not None:
  265. timer = _wrap_timer(timer)
  266. t = Timer(stmt, setup, timer)
  267. if number == 0:
  268. # determine number so that 0.2 <= total time < 2.0
  269. callback = None
  270. if verbose:
  271. def callback(number, time_taken):
  272. msg = "{num} loop{s} -> {secs:.{prec}g} secs"
  273. plural = (number != 1)
  274. print(msg.format(num=number, s='s' if plural else '',
  275. secs=time_taken, prec=precision))
  276. try:
  277. number, _ = t.autorange(callback)
  278. except:
  279. t.print_exc()
  280. return 1
  281. if verbose:
  282. print()
  283. try:
  284. raw_timings = t.repeat(repeat, number)
  285. except:
  286. t.print_exc()
  287. return 1
  288. def format_time(dt):
  289. unit = time_unit
  290. if unit is not None:
  291. scale = units[unit]
  292. else:
  293. scales = [(scale, unit) for unit, scale in units.items()]
  294. scales.sort(reverse=True)
  295. for scale, unit in scales:
  296. if dt >= scale:
  297. break
  298. return "%.*g %s" % (precision, dt / scale, unit)
  299. if verbose:
  300. print("raw times: %s" % ", ".join(map(format_time, raw_timings)))
  301. print()
  302. timings = [dt / number for dt in raw_timings]
  303. best = min(timings)
  304. print("%d loop%s, best of %d: %s per loop"
  305. % (number, 's' if number != 1 else '',
  306. repeat, format_time(best)))
  307. best = min(timings)
  308. worst = max(timings)
  309. if worst >= best * 4:
  310. import warnings
  311. warnings.warn_explicit("The test results are likely unreliable. "
  312. "The worst time (%s) was more than four times "
  313. "slower than the best time (%s)."
  314. % (format_time(worst), format_time(best)),
  315. UserWarning, '', 0)
  316. return None
  317. if __name__ == "__main__":
  318. sys.exit(main())