kernel/git - git - PowerEL Git System

Commit Graph

Author	SHA1	Message	Date
Nguyễn Thái Ngọc Duy	c46c406ae1	trace.h: support nested performance tracing Performance measurements are listed right now as a flat list, which is fine when we measure big blocks. But when we start adding more and more measurements, some of them could be just part of a bigger measurement and a flat list gives a wrong impression that they are executed at the same level instead of nested. Add trace_performance_enter() and trace_performance_leave() to allow indent these nested measurements. For now it does not help much because the only nested thing is (lazy) name hash initialization (e.g. called in diff-index from "git status"). This will help more because I'm going to add some more tracing that's actually nested. Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com> Signed-off-by: Junio C Hamano <gitster@pobox.com>	7 years ago
Nguyễn Thái Ngọc Duy	cb50761959	trace.c: export trace_setup_key This is so that we can print traces based on this key outside trace.c. Signed-off-by: Nguyễn Thái Ngọc Duy <pclouds@gmail.com> Signed-off-by: Jeff King <peff@peff.net> Signed-off-by: Junio C Hamano <gitster@pobox.com>	7 years ago
Gennady Kupava	8eeb25c679	trace: improve performance while category is disabled Move just enough code from trace.c into trace.h header so all code necessary to determine that trace is disabled could be inlined to calling functions. Then perform the check if the trace key is enabled sooner in call chain. Signed-off-by: Gennady Kupava <gkupava@bloomberg.net> Signed-off-by: Junio C Hamano <gitster@pobox.com>	7 years ago
Gennady Kupava	406102a731	trace: remove trace key normalization Trace key normalization is not used, not strictly necessary, complicates the code and would negatively affect compilation speed if moved to header. New trace_default_key key or existing separate marco could be used instead of passing NULL as a key. Signed-off-by: Gennady Kupava <gkupava@bloomberg.net> Signed-off-by: Junio C Hamano <gitster@pobox.com>	7 years ago
Jeff King	323598387d	pkt-line: support tracing verbatim pack contents When debugging the pack protocol, it is sometimes useful to store the verbatim pack that we sent or received on the wire. Looking at the on-disk result is often not helpful for a few reasons: 1. If the operation is a clone, we destroy the repo on failure, leaving nothing on disk. 2. If the pack is small, we unpack it immediately, and the full pack never hits the disk. 3. If we feed the pack to "index-pack --fix-thin", the resulting pack has the extra delta bases added to it. We already have a GIT_TRACE_PACKET mechanism for tracing packets. Let's extend it with GIT_TRACE_PACKFILE to dump the verbatim packfile. There are a few other positive fallouts that come from rearranging this code: - We currently disable the packet trace after seeing the PACK header, even though we may get human-readable lines on other sidebands; now we include them in the trace. - We currently try to print "PACK ..." in the trace to indicate that the packfile has started. But because we disable packet tracing, we never printed this line. We will now do so. Signed-off-by: Jeff King <peff@peff.net> Signed-off-by: Junio C Hamano <gitster@pobox.com>	10 years ago
Karsten Blees	578da0391a	git: add performance tracing for git's main() function to debug scripts Use trace_performance to measure and print execution time and command line arguments of the entire main() function. In constrast to the shell's 'time' utility, which measures total time of the parent process, this logs all involved git commands recursively. This is particularly useful to debug performance issues of scripted commands (i.e. which git commands were called with which parameters, and how long did they execute). Due to git's deliberate use of exit(), the implementation uses an atexit routine rather than just adding trace_performance_since() at the end of main(). Usage example: > GIT_TRACE_PERFORMANCE=~/git-trace.log git stash list Creates a log file like this: 23:57:38.638765 trace.c:405 performance: 0.000310107 s: git command: 'git' 'rev-parse' '--git-dir' 23:57:38.644387 trace.c:405 performance: 0.000261759 s: git command: 'git' 'rev-parse' '--show-toplevel' 23:57:38.646207 trace.c:405 performance: 0.000304468 s: git command: 'git' 'config' '--get-colorbool' 'color.interactive' 23:57:38.648491 trace.c:405 performance: 0.000241667 s: git command: 'git' 'config' '--get-color' 'color.interactive.help' 'red bold' 23:57:38.650465 trace.c:405 performance: 0.000243063 s: git command: 'git' 'config' '--get-color' '' 'reset' 23:57:38.654850 trace.c:405 performance: 0.025126313 s: git command: 'git' 'stash' 'list' Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	09b2c1c769	trace: add trace_performance facility to debug performance issues Add trace_performance and trace_performance_since macros that print a duration and an optional printf-formatted text to the file specified in environment variable GIT_TRACE_PERFORMANCE. These macros, in conjunction with getnanotime(), are intended to simplify performance measurements from within the application (i.e. profiling via manual instrumentation, rather than using an external profiling tool). Unless enabled via GIT_TRACE_PERFORMANCE, these macros have no noticeable impact on performance, so that test code for well known time killers may be shipped in release builds. Alternatively, a developer could provide an additional performance patch (not meant for master) that allows reviewers to reproduce performance tests more easily, e.g. on other platforms or using their own repositories. Usage examples: Simple use case (measure one code section): uint64_t start = getnanotime(); /* code section to measure / trace_performance_since(start, "foobar"); Complex use case (measure repetitive code sections): uint64_t t = 0; for (;;) { / ignore / t -= getnanotime(); / code section to measure / t += getnanotime(); / ignore */ } trace_performance(t, "frotz"); Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	148d6771bf	trace: add high resolution timer function to debug performance issues Add a getnanotime() function that returns nanoseconds since 01/01/1970 as unsigned 64-bit integer (i.e. overflows in july 2554). This is easier to work with than e.g. struct timeval or struct timespec. Basing the timer on the epoch allows using the results with other time-related APIs. To simplify adaption to different platforms, split the implementation into a common getnanotime() and a platform-specific highres_nanos() function. The common getnanotime() function handles errors, falling back to gettimeofday() if highres_nanos() isn't implemented or doesn't work. getnanotime() is also responsible for normalizing to the epoch. The offset to the system clock is calculated only once on initialization, i.e. manually setting the system clock has no impact on the timer (except if the fallback gettimeofday() is in use). Git processes are typically short lived, so we don't need to handle clock drift. The highres_nanos() function returns monotonically increasing nanoseconds relative to some arbitrary point in time (e.g. system boot), or 0 on failure. Providing platform-specific implementations should be relatively easy, e.g. adapting to clock_gettime() as defined by the POSIX realtime extensions is seven lines of code. This version includes highres_nanos() implementations for: * Linux: using clock_gettime(CLOCK_MONOTONIC) * Windows: using QueryPerformanceCounter() Todo: * enable clock_gettime() on more platforms * add Mac OSX version, e.g. using mach_absolute_time + mach_timebase_info Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	e05bed960d	trace: add 'file:line' to all trace output This is useful to see where trace output came from. Add 'const char file, int line' parameters to the printing functions and rename them to _fl. Add trace_printf* and trace_strbuf macros resolving to the _fl functions and let the preprocessor fill in __FILE__ and __LINE__. As the trace_printf functions take a variable number of arguments, this requires variadic macros (i.e. '#define foo(...) foo_impl(__VA_ARGS__)'. Though part of C99, it is unclear whether older compilers support this. Thus keep the old functions and only enable variadic macros for GNUC and MSVC 2005+ (_MSC_VER 1400). This has the nice side effect that the old C-style declarations serve as documentation how the macros are to be used. Print 'file:line ' as prefix to each trace line. Align the remaining trace output at column 40 to accommodate 18 char file names + 4 digit line number (currently there are 30 *.c files of length 18 and just 11 of 19). Trace output from longer source files (e.g. builtin/receive-pack.c) will not be aligned. Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	66f66c596f	trace: move code around, in preparation to file:line output No functional changes, just move stuff around so that the next patch isn't that ugly... Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	c69dfd24db	trace: add infrastructure to augment trace output with additional info To be able to add a common prefix or suffix to all trace output (e.g. a timestamp or file:line of the caller), factor out common setup and cleanup tasks of the trace* functions. When adding a common prefix, it makes sense that the output of each trace call starts on a new line. Add '\n' in case the caller forgot. Note that this explicitly limits trace output to line-by-line, it is no longer possible to trace-print just part of a line. Until now, this was just an implicit assumption (trace-printing part of a line worked, but messed up the trace file if multiple threads or processes were involved). Thread-safety / inter-process-safety is also the reason why we need to do the prefixing and suffixing in memory rather than issuing multiple write() calls. Write_or_whine_pipe() / xwrite() is atomic unless the size exceeds MAX_IO_SIZE (8MB, see wrapper.c). In case of trace_strbuf, this costs an additional string copy (which should be irrelevant for performance in light of actual file IO). While we're at it, rename trace_strbuf's 'buf' argument, which suggests that the function is modifying the buffer. Trace_strbuf() currently is the only trace API that can print arbitrary binary data (without barfing on '%' or stopping at '\0'), so 'data' seems more appropriate. Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	6aa3085702	trace: improve trace performance The trace API currently rechecks the environment variable and reopens the trace file on every API call. This has the ugly side effect that errors (e.g. file cannot be opened, or the user specified a relative path) are also reported on every call. Performance can be improved by about factor three by remembering the environment state and keeping the file open. Replace the 'const char *key' parameter in the API with a pointer to a 'struct trace_key' that bundles the environment variable name with additional, trace-internal state. Change the call sites of these APIs to use a static 'struct trace_key' instead of a string constant. In trace.c::get_trace_fd(), save and reuse the file descriptor in 'struct trace_key'. Add a 'trace_disable()' API, so that packet_trace() can cleanly disable tracing when it encounters packed data (instead of using unsetenv()). Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	4a3b0b25f1	trace: consistently name the format parameter The format parameter to trace_printf functions is sometimes abbreviated 'fmt'. Rename to 'format' everywhere (consistent with POSIX' printf specification). Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago
Karsten Blees	5991a55c54	trace: move trace declarations from cache.h to new trace.h Also include direct dependencies (strbuf.h and git-compat-util.h for __attribute__) so that trace.h can be used independently of cache.h, e.g. in test programs. Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>	11 years ago

14 Commits (6804ba3a58ff2999533af28ca5af3901e30fd1f2)