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

[Junio C Hamano <gitster@pobox.com>]

Jeff King <peff@peff.net> writes:

> On Tue, May 20, 2014 at 09:11:24PM +0200, Karsten Blees wrote:
>
>> 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
>
> --