Chrome tracing

Gregory Szorc gregory.szorc at gmail.com
Tue Feb 14 22:02:31 EST 2017


On Sat, Feb 11, 2017 at 11:34 PM, Bryan O'Sullivan <bos at serpentine.com>
wrote:

> I put together a proof of concept patch tonight that adds the ability to
> use light(ish)weight instrumentation to generate trace files that the
> Chrome trace tool can render.
>
> Here's a local clone --pull of Mercurial itself:
> http://i.imgur.com/efWjFyE.png
>
> And the corresponding trace file, so you can mess around with it:
> http://pastebin.com/qXGfwQ3j
>
> Here's "log -l100" in an old copy of mozilla-central:
> http://i.imgur.com/2pyvT43.png
>
> And its trace file:
> http://pastebin.com/k2Q2WiLu
>
> The patch itself reveals how easy this functionality is to use:
> http://pastebin.com/7zR61UhB
>
> It's not hard to see how you could e.g. get --profile output into this
> format, and with a little massaging get a potentially interesting way of
> drilling into performance in detail.
>
> What's interesting about this patch, even in its current very hacky form,
> is how amenable to fishing expeditions it is. You can easily add temporary
> lightweight instrumentation anywhere. It also seems clear that some of this
> kind of instrumentation would be valuable to add permanently. For example,
> I noticed tonight, just by looking at a trace, that hg-git takes over a
> hundred milliseconds to load.
>

The tracing API and the overall approach used in this patch are eerily
similar to what Mozilla uses to monitor systems when building and testing
Firefox. (But our code is using psutil to monitor system resource usage, so
it can't be recycled for Mercurial's use.) Our approach works pretty well
and I reckon Mercurial would have similar positive results.

I support having dedicated code for annotating well-defined and important
Mercurial operations in tracing/profiling logs. I have a hunch that the
kinds of things we need to annotate shouldn't be called with a high enough
frequency for probe overhead to matter. But if it does, the use of context
managers can be beneficial, as those are evaluated at module load time and
the context manager can be made to no-op and return the original function
unless tracing is enabled. That's *almost* 0 cost. Worst case you would
have a call to a no-op or simple "test and return" function. If that
introduces noticeable overhead, then we're likely failing to call tracing
functions judiciously.

Something else to consider is the interaction between tracing and progress
bars. I posit that most places we use progress bars are places we'd want to
use the proposed tracing.duration() context manager. I reckon we could
integrate tracing into the progress APIs and kill 2 birds with 1 stone.

I'm +1 on this general approach and look forward to having traces of
logical Mercurial operations to help assess performance.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.mercurial-scm.org/pipermail/mercurial-devel/attachments/20170214/e4eedb00/attachment.html>


More information about the Mercurial-devel mailing list