Am 21.05.2014 18:55, schrieb Jeff King: > 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? > > 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 >
IMO printing timestamps in all trace output would be a useful feature on its own, but its not what I'm trying to achieve here. Timestamps only give you a broad overview of when things started, not how long they took. And calculating the durations from timestamps in the log output is tedious work, esp. if multiple processes and threads are involved (would need pid and thread-id as well). The first patch helps calculating durations (without having to mess with struct timespec/timeval), and the second helps logging the results. Its basically a utility for manual profiling. Printing total command execution time (this patch) is just one possible use case. E.g. if I'm interested in a particular code section, I throw in 2 lines of code (before and after the code section). This gives very accurate results, without significantly affecting overall performance. I can then push the changes to my Linux/Windows box and get comparable results there. No need to disable optimization. No worries that the profiling tool isn't available on the other platform. No analyzing megabytes of mostly irrelevant profiling data. Does that make sense? -- To unsubscribe from this list: send the line "unsubscribe git" in the body of a message to majord...@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
