Re: [RFC/PATCH v4 3/3] add command performance tracing to debug scripted commands

Jeff King [off-list ref] writes:

On Tue, May 20, 2014 at 09:11:24PM +0200, Karsten Blees wrote:

quoted

Add performance tracing to identify which git commands are called and how
long they execute. This is particularly useful to debug performance issues
of scripted commands.

Usage example: > GIT_TRACE_PERFORMANCE=~/git-trace.log git stash list

Creates a log file like this:
performance: at trace.c:319, time: 0.000303280 s: git command: 'git' 'rev-parse' '--git-dir'
performance: at trace.c:319, time: 0.000334409 s: git command: 'git' 'rev-parse' '--is-inside-work-tree'
performance: at trace.c:319, time: 0.000215243 s: git command: 'git' 'rev-parse' '--show-toplevel'
performance: at trace.c:319, time: 0.000410639 s: git command: 'git' 'config' '--get-colorbool' 'color.interactive'
performance: at trace.c:319, time: 0.000394077 s: git command: 'git' 'config' '--get-color' 'color.interactive.help' 'red bold'
performance: at trace.c:319, time: 0.000280701 s: git command: 'git' 'config' '--get-color' '' 'reset'
performance: at trace.c:319, time: 0.000908185 s: git command: 'git' 'rev-parse' '--verify' 'refs/stash'
performance: at trace.c:319, time: 0.028827774 s: git command: 'git' 'stash' 'list'

Neat. I actually wanted something like this just yesterday. It looks
like you are mainly tracing the execution of programs. Would it make
sense to just tie this to regular trace_* calls, and if
GIT_TRACE_PERFORMANCE is set, add a timestamp to each line?

Yeah, I very much like both, the output and your suggestion to hook
it into the existing infrastructure.

Then we would not need to add separate trace_command_performance calls,
and other parts of the code that are already instrumented with GIT_TRACE
would get the feature for free.

-Peff

--