Startup overhead, test suite run times
Gregory Szorc
gregory.szorc at gmail.com
Tue May 8 18:56:04 UTC 2018
Many have noticed that running the test harness has been getting slower
over the past several months.
I don't have access to the low-level data I collected as I write this
email, but I'm very confident that the primary driver making the test
harness slower is the combination of more tests and `hg` process startup
overhead. My data shows a steady increase in the number of `hg` process
invocations over time.
More importantly, it frequently takes 50+ ms to get a `hg` process to a
point where it can execute useful Mercurial bytecode. We have ~25,000 " $
hg" lines in our .t files. If you do the math, we spend *minutes* of CPU
time initializing `hg` processes during the test suite.
I posted to python-dev about this issue last week [1]. It generated a
substantial number of replies on that list, including some offshoot
threads. Websites like Hacker News also took part in the discussion. I
intentionally sent that post before PyCon in hopes of it spawning
meaningful discussions and actions at PyCon. Hopefully I succeeded.
Anyway, patches like 856f381ad74b [2] that reduce the `hg` startup time
overhead have a *major* impact on test harness run times. In that
changeset, a ~6.94ms startup time reduction dropped total CPU time for the
test harness by ~470s and dropped total CPU consumption to ~90% of original.
To reiterate what I wrote to python-dev: milliseconds - and fractions of
milliseconds - matter for performance. Especially for the run-time of the
test harness.
There has been a long-held belief that we should minimize the number of .t
files in our test suite to reduce overhead. While there is some concern
about excessive .t files requiring more repositories to be created and this
adds I/O overhead, I think the bigger problem is the number of `hg`
invocations in .t files.
There are some tricks we can do to eliminate `hg` invocations in tests. One
is to use `hg debugdrawdag`. Using this command, we can populate a new
repository with 2 `hg` invocations (init + debugdrawdag)` and avoid
overhead of several `hg add`, `hg commit`, etc invocations.
A better trick is to run tests with `chg`. However, it appears we still
have intermittent test failures when run with `chg` (probably due to global
state lingering in persistent `hg` processes). These are hard to reproduce
because they likely rely on specific sequences of command invocations.
Hopefully if enough people start running tests with `chg` we can track
those problems down. Or if we run tests with chg + -j1 + shuffle, we could
at least reproduce the failures. We could probably write some run-tests.py
automation that reduces a failure chain to its minimum reproduction case
and tease out the underlying bugs.
Because `hg` startup overhead has a significant impact on user-perceived
performance and test suite run time, I think it would be worthwhile to
spend some time adding tests for startup (e.g. perhaps requiring that
modules loaded for dispatch be in an allow list so we catch changes). It is
certainly worthwhile to spend time auditing what is being done during
startup and optimizing that as much as possible. I have a *very* hacky
patch for Python 3 that modifies the import mechanism to collect low-level
timings. My data shows that exec()ing a module is the slowest part of
import by far. Compiling regular expressions and calling functions as part
of loading the module are notably slow. configitems.py is currently the
slowest module to import (probably because it performs dozens if not
hundreds of Python function calls).
Anyway, I may try to post more data later. I figured people would be
interested in what I've found so far.
[1] https://mail.python.org/pipermail/python-dev/2018-May/153296.html
[2] https://www.mercurial-scm.org/repo/hg/rev/856f381ad74b
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.mercurial-scm.org/pipermail/mercurial-devel/attachments/20180508/3562546c/attachment.html>
More information about the Mercurial-devel
mailing list