Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:34:06 -0800] rev 31003
histedit: log the time taken to read in the commands list
If we're being fed an external command list from stdin (histedit --commands -),
then the time spent reading stdin is outside our control. Log it.
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:34:06 -0800] rev 31002
extdiff: log time spent in external diff program
We can't fix the time external diff programs take to run. Log that duration
for us to remove from any stats we gather
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:34:06 -0800] rev 31001
crecord: log blocked time waiting for curses input
We want to know when we're blocked waiting for the user - log the time spent
waiting in the curses keyboard handlers
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:38:00 -0800] rev 31000
ui: give editor() a tag of its own
We know that calls to ui.editor() always block on the user's configured editor.
Use a blocking tag that ensures that we don't see a huge variety of editor
options in our logging.
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:29:12 -0800] rev 30999
ui: time calls to ui.system
We want to know when we're blocked on ui.system, and why. Allow the user to
supply a tag - otherwise we record on an unspecific tag derived from cmd.
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:50:06 -0800] rev 30998
ui: log time spent blocked on stdio
We use a wrapper around Mercurial at Facebook that logs key statistics (like
elpased time) to our standard performance tooling.
This is less useful than it could be, because we currently can't tell when a
command is slow because we need to fix Mercurial versus when a command is
slow because the user isn't interacting quickly.
Teach Mercurial to log the time it spends blocked, so that our tooling can
pick it up and submit it with the elapsed time - we can then do the math in
our tooling to see if Mercurial is slow, or if the user simply failed to
interact.
Combining this with the command duration log means that we can ensure that
we concentrate performance efforts on the things that bite Facebook users.
The perfwrite microbenchmark shifts from:
Linux:
! wall 3.213560 comb 0.410000 user 0.350000 sys 0.060000 (best of 4)
Mac:
! wall 0.342325 comb 0.180000 user 0.110000 sys 0.070000 (best of 20)
before this change to:
! wall 3.478070 comb 0.500000 user 0.420000 sys 0.080000 (best of 3)
Mac:
! wall 0.218112 comb 0.220000 user 0.150000 sys 0.070000 (best of 15)
showing a small hit in comb time, but firmly in the noise on wall time.
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:07:26 -0800] rev 30997
contrib: add a write microbenchmark to perf.py
I'm adding some performance logging to ui.write - this benchmark lets us
confirm that the cost of that logging is acceptably low.
At this point, the microbenchmark on Linux over SSH shows:
! wall 3.213560 comb 0.410000 user 0.350000 sys 0.060000 (best of 4)
while on the Mac locally, it shows:
! wall 0.342325 comb 0.180000 user 0.110000 sys 0.070000 (best of 20)
Simon Farnsworth <simonfar@fb.com> [Wed, 15 Feb 2017 13:17:45 -0800] rev 30996
ui: provide a mechanism to track and log blocked time
We want to log the time Mercurial spends trapped in things outside
programmatic control. Provide a mechanism to give us both command runtime
and as many different sources of blocking as we deem useful.