Enhance the timeit module: display average +- std dev instead of minimum

[vstinner]

BPO	28240
Nosy	@malemburg, @tim-one, @brettcannon, @rhettinger, @jcea, @pitrou, @vstinner, @ned-deily, @stevendaprano, @serhiy-storchaka
PRs	[Do Not Merge] Convert Misc/NEWS so that it is managed by towncrier #552 bpo-28240: timeit: Update repeat() doc #7419 [3.7] bpo-28240: timeit: Update repeat() doc (GH-7419) #7457
Files	timeit.patch

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = None
closed_at = <Date 2018-05-22.14:01:01.227>
created_at = <Date 2016-09-21.14:08:50.857>
labels = ['3.7', 'performance']
title = 'Enhance the timeit module: display average +- std dev instead of minimum'
updated_at = <Date 2018-06-06.17:06:41.368>
user = 'https://github.com/vstinner'

bugs.python.org fields:

activity = <Date 2018-06-06.17:06:41.368>
actor = 'vstinner'
assignee = 'none'
closed = True
closed_date = <Date 2018-05-22.14:01:01.227>
closer = 'serhiy.storchaka'
components = ['Benchmarks']
creation = <Date 2016-09-21.14:08:50.857>
creator = 'vstinner'
dependencies = []
files = ['44780']
hgrepos = []
issue_num = 28240
keywords = ['patch']
message_count = 38.0
messages = ['277142', '277143', '277144', '277145', '277146', '277147', '277148', '277149', '277157', '277161', '277177', '277186', '277251', '277259', '277271', '277292', '277303', '278133', '278890', '278891', '278895', '278896', '278898', '278901', '278903', '278907', '278913', '278914', '278917', '278918', '278919', '278974', '317128', '317279', '317290', '318838', '318851', '318852']
nosy_count = 11.0
nosy_names = ['lemburg', 'tim.peters', 'brett.cannon', 'rhettinger', 'jcea', 'pitrou', 'vstinner', 'ned.deily', 'steven.daprano', 'python-dev', 'serhiy.storchaka']
pr_nums = ['552', '7419', '7457']
priority = 'normal'
resolution = 'fixed'
stage = 'resolved'
status = 'closed'
superseder = None
type = 'performance'
url = 'https://bugs.python.org/issue28240'
versions = ['Python 3.7']

[vstinner]

Attached patch makes different changes to the timeit module:

• Display the average, rather than the minimum, of the timings *and* display the standard deviation. It should help a little bit to get more reproductible results.
• Change the default repeat from 3 to 5 to have a better distribution of timings. It makes the timeit CLI 66% slower (ex: 1 second instead of 600 ms). That's the price of stable benchmarks :-)
• Don't disable the garbage collector anymore! Disabling the GC is not fair: real applications use it.
• autorange: start with 1 loop instead of 10 for slow benchmarks like time.sleep(1)
• Display large number of loops as power of 10 for readability, ex: "10^6" instead of "1000000". Also accept "10^6" syntax for the --num parameter.
• Add support for "ns" unit: nanoseconds (10^-9 second)

I consider that these changes are well contained enough to still be ok for 3.6 beta 2. But I add Ned Deily as CC to double check ;-)

This patch is related to my work on Python benchmarks, see:

• http://perf.readthedocs.io/en/latest/
• https://github.com/python/performance

The perf module runs benchmarks in multiple child processes to test different memory layouts (Linux uses ASRL by default) and different hash functions. It helps to get more stable benchmark results, but it's probably overkill for the tiny timeit module. By the way, the "pyperf timeit" command reuses the timeit module of the stdlib.

Note: The timeit module still uses the old getopt module which is very strict. For example "python3 -m timeit pass -v" is not recognized ("-v" is read as a statement part of the benchmark, not as --verbose). But I was too lazy to also modify this part, I may do it later ;-)

[vstinner]

The perf module displays the median rather than the mean (arithmeric average). The difference between median and mean is probably too subtle for most users :-/ The term "median" is also probably unknown by most users...

I chose to use average: well known, easy to understand (we learn the formula at school: sum/count).

[vstinner]

• Display the average, rather than the minimum, of the timings *and* display the standard deviation. It should help a little bit to get more reproductible results.

Rationale:

• http://blog.kevmod.com/2016/06/benchmarking-minimum-vs-average/
• https://haypo.github.io/journey-to-stable-benchmark-average.html

[pitrou]

Display the average, rather than the minimum, of the timings *and* display the standard deviation. It should help a little bit to get more reproductible results

That entirely depends on which benchmark you are running.

Disabling the GC is not fair: real applications use it

timeit was never meant to benchmark real applications, it is a micro-benchmarking tool.

[vstinner]

Maciej Fijalkowski also sent me the following article a few months ago, it also explains indirectly why using the minimum for benchmarks is not reliable:

"Virtual Machine Warmup Blows Hot and Cold"
http://arxiv.org/pdf/1602.00602.pdf

Even if the article is more focused on JIT compilers, it shows that benchmarks are not straightforward but always full of bad surprises.

A benchmark doesn't have a single value but a *distribution*. The best question is how to summarize the full distribution without loosing too much information.

In the perf module I decided to not take a decision: a JSON file stores *all* data :-D But by default, perf displays mean +- std dev.

[pitrou]

Another point: timeit is often used to compare performance between Python versions. By changing the behaviour of timeit in a given Python version, you'll make it more difficult to compare results.

[stevendaprano]

• Display the average, rather than the minimum, of the timings *and*
  display the standard deviation. It should help a little bit to get
  more reproductible results.

I'm still not convinced that the average is the right statistic to use
here. I cannot comment about Victor's perf project, but for timeit, it
seems to me that Tim's original warning that the mean is not useful is
correct.

Fundamentally, the problem with taking an average is that the timing
errors are all one sided. If the unknown "true" or "real" time taken by
a piece of code is T, then the random error epsilon is always positive:
we're measuring T + ε, not T ± ε.

If the errors are evenly divided into positive and negative, then on
average the mean() or median() of the measurements will tend to cancel
the errors, and you get a good estimate of T. But if the errors are all
one-sided, then they don't cancel and you are actually estimating T plus
some unknown, average error. In that case, min() is the estimate which
is closest to T.

Unless you know that average error is tiny compared to T, I don't think
the average is very useful. Since these are typically micro-benchmarks,
the error is often quite large relative to the unknown T.

• Change the default repeat from 3 to 5 to have a better distribution
  of timings. It makes the timeit CLI 66% slower (ex: 1 second instead
  of 600 ms). That's the price of stable benchmarks :-)

I nearly always run with repeat=5, so I agree with this.

• Don't disable the garbage collector anymore! Disabling the GC is not
  fair: real applications use it.

But that's just adding noise: you're not timing code snippet, you're
timing code snippet plus garbage collector.

I disagree with this change, although I would accept it if there was an
optional flag to control the gc.

• autorange: start with 1 loop instead of 10 for slow benchmarks like
  time.sleep(1)

That seems reasonable.

• Display large number of loops as power of 10 for readability, ex:
  "10^6" instead of "1000000". Also accept "10^6" syntax for the --num
  parameter.

Shouldn't we use 10**6 or 1e6 rather than bitwise XOR? :-)

This is aimed at Python programmers. We expect ** to mean
exponentiation, not ^.

• Add support for "ns" unit: nanoseconds (10^-9 second)

Seems reasonable.

[vstinner]

Another point: timeit is often used to compare performance between Python versions. By changing the behaviour of timeit in a given Python version, you'll make it more difficult to compare results.

Hum, that's a good argument against my change :-)

So to be able to compare Python 3.5 vs 3.6 or Python 2.7 vs Python 3.6, we need to backport somehow the average feature to the timeit module of older Python versions. One option would be to put the timeit module on the Python Cheeseshop (PyPI). Hum, but there is already such module: my perf module.

A solution would be to redirect users to the perf module in the timeit documentation, and maybe also document that timeit results are not reliable?

A different solution would be to add a --python parameter to timeit to run the benchmark on a specific Python version (ex: "python3 -m timeit --python=python2 ..."). But this solution is more complex to be developed since we have to make the timeit.py compatible with Python 2.7 and find a reliable way to load it in the other tested Python program.

Note: I plan to add a --python parameter in my perf module, but I didn't implemented yet. Since my perf module spawn child processes and the perf module is a third party module, it is simpler to implement this option.

--

A more general remark: the timeit is commonly used to compare performances of two Python versions. They run timeit twice and then compare manually results. But only two numbers are compared. It would be more reliable to compare all timings and make sure that the comparison is significant. Again, the perf module implements such function:
http://perf.readthedocs.io/en/latest/api.html#perf.is_significant

I didn't implement a full CLI for perf timeit to directly compares two Python versions. You have to run timeit twice and store all timings in JSON files and then use the "perf compare" command to reload timings and compare them.

[serhiy-storchaka]

• Display the average, rather than the minimum, of the timings *and* display the standard deviation. It should help a little bit to get more reproductible results.

This makes hard to compare results with older Python versions.

• Change the default repeat from 3 to 5 to have a better distribution of timings. It makes the timeit CLI 66% slower (ex: 1 second instead of 600 ms). That's the price of stable benchmarks :-)

For now default timeit run takes from 0.8 to 8 sec. Adding yet 5 sec makes a user more angry.

• Don't disable the garbage collector anymore! Disabling the GC is not fair: real applications use it.

But this makes short microbenchmarks less stable.

• autorange: start with 1 loop instead of 10 for slow benchmarks like time.sleep(1)

This is good if you run relatively slow benchmark, but it makes the result less reliable. You always can specify -n1, but on your own risk.

• Display large number of loops as power of 10 for readability, ex: "10^6" instead of "1000000". Also accept "10^6" syntax for the --num parameter.

10^6 syntax doesn't look Pythonic. And this change breaks third-party scripts that run timeit.

• Add support for "ns" unit: nanoseconds (10^-9 second)

Even "pass" takes at least 0.02 usec on my computer. What you want to measure that takes < 1 ns? I think timeit is just wrong tool for this.

The patch also makes a warning about unreliable results output to stdout and always visible. This is yet one compatibility break. Current code allows the user to control the visibility of the warning by the -W Python option, and don't mix the warning with result output.