From eb9250dfd5fbd7c9f95d0d3134006cd19a0c9099 Mon Sep 17 00:00:00 2001 From: Karsten Blees Date: Sat, 12 Jul 2014 02:00:53 +0200 Subject: Documentation/git.txt: improve documentation of 'GIT_TRACE*' variables Separate GIT_TRACE description into what it prints and how to configure where trace output is printed to. Change other GIT_TRACE_* descriptions to refer to GIT_TRACE. Add descriptions for GIT_TRACE_SETUP and GIT_TRACE_SHALLOW. Signed-off-by: Karsten Blees Signed-off-by: Junio C Hamano --- Documentation/git.txt | 50 ++++++++++++++++++++++++++++++++++---------------- 1 file changed, 34 insertions(+), 16 deletions(-) (limited to 'Documentation/git.txt') diff --git a/Documentation/git.txt b/Documentation/git.txt index 3bd68b0167..75633e65da 100644 --- a/Documentation/git.txt +++ b/Documentation/git.txt @@ -904,18 +904,25 @@ for further details. based on whether stdout appears to be redirected to a file or not. 'GIT_TRACE':: - If this variable is set to "1", "2" or "true" (comparison - is case insensitive), Git will print `trace:` messages on - stderr telling about alias expansion, built-in command - execution and external command execution. - If this variable is set to an integer value greater than 1 - and lower than 10 (strictly) then Git will interpret this - value as an open file descriptor and will try to write the - trace messages into this file descriptor. - Alternatively, if this variable is set to an absolute path - (starting with a '/' character), Git will interpret this - as a file path and will try to write the trace messages - into it. + Enables general trace messages, e.g. alias expansion, built-in + command execution and external command execution. ++ +If this variable is set to "1", "2" or "true" (comparison +is case insensitive), trace messages will be printed to +stderr. ++ +If the variable is set to an integer value greater than 2 +and lower than 10 (strictly) then Git will interpret this +value as an open file descriptor and will try to write the +trace messages into this file descriptor. ++ +Alternatively, if the variable is set to an absolute path +(starting with a '/' character), Git will interpret this +as a file path and will try to write the trace messages +into it. ++ +Unsetting the variable, or setting it to empty, "0" or +"false" (case insensitive) disables trace messages. 'GIT_TRACE_PACK_ACCESS':: If this variable is set to a path, a file will be created at @@ -925,10 +932,21 @@ for further details. pack-related performance problems. 'GIT_TRACE_PACKET':: - If this variable is set, it shows a trace of all packets - coming in or out of a given program. This can help with - debugging object negotiation or other protocol issues. Tracing - is turned off at a packet starting with "PACK". + Enables trace messages for all packets coming in or out of a + given program. This can help with debugging object negotiation + or other protocol issues. Tracing is turned off at a packet + starting with "PACK". + See 'GIT_TRACE' for available trace output options. + +'GIT_TRACE_SETUP':: + Enables trace messages printing the .git, working tree and current + working directory after Git has completed its setup phase. + See 'GIT_TRACE' for available trace output options. + +'GIT_TRACE_SHALLOW':: + Enables trace messages that can help debugging fetching / + cloning of shallow repositories. + See 'GIT_TRACE' for available trace output options. GIT_LITERAL_PATHSPECS:: Setting this variable to `1` will cause Git to treat all -- cgit v1.3 From 67dc598ec42ea25cda94ed8d283396c4ab385f50 Mon Sep 17 00:00:00 2001 From: Karsten Blees Date: Sat, 12 Jul 2014 02:01:38 +0200 Subject: sha1_file: change GIT_TRACE_PACK_ACCESS logging to use trace API This changes GIT_TRACE_PACK_ACCESS functionality as follows: * supports the same options as GIT_TRACE (e.g. printing to stderr) * no longer supports relative paths * appends to the trace file rather than overwriting Signed-off-by: Karsten Blees Signed-off-by: Junio C Hamano --- Documentation/git.txt | 4 ++-- sha1_file.c | 30 ++++-------------------------- 2 files changed, 6 insertions(+), 28 deletions(-) (limited to 'Documentation/git.txt') diff --git a/Documentation/git.txt b/Documentation/git.txt index 75633e65da..9d073f6adc 100644 --- a/Documentation/git.txt +++ b/Documentation/git.txt @@ -925,11 +925,11 @@ Unsetting the variable, or setting it to empty, "0" or "false" (case insensitive) disables trace messages. 'GIT_TRACE_PACK_ACCESS':: - If this variable is set to a path, a file will be created at - the given path logging all accesses to any packs. For each + Enables trace messages for all accesses to any packs. For each access, the pack file name and an offset in the pack is recorded. This may be helpful for troubleshooting some pack-related performance problems. + See 'GIT_TRACE' for available trace output options. 'GIT_TRACE_PACKET':: Enables trace messages for all packets coming in or out of a diff --git a/sha1_file.c b/sha1_file.c index 34d527f670..7a110b513e 100644 --- a/sha1_file.c +++ b/sha1_file.c @@ -36,9 +36,6 @@ static inline uintmax_t sz_fmt(size_t s) { return s; } const unsigned char null_sha1[20]; -static const char *no_log_pack_access = "no_log_pack_access"; -static const char *log_pack_access; - /* * This is meant to hold a *small* number of objects that you would * want read_sha1_file() to be able to return, but yet you do not want @@ -2085,27 +2082,9 @@ static void *read_object(const unsigned char *sha1, enum object_type *type, static void write_pack_access_log(struct packed_git *p, off_t obj_offset) { - static FILE *log_file; - - if (!log_pack_access) - log_pack_access = getenv("GIT_TRACE_PACK_ACCESS"); - if (!log_pack_access) - log_pack_access = no_log_pack_access; - if (log_pack_access == no_log_pack_access) - return; - - if (!log_file) { - log_file = fopen(log_pack_access, "w"); - if (!log_file) { - error("cannot open pack access log '%s' for writing: %s", - log_pack_access, strerror(errno)); - log_pack_access = no_log_pack_access; - return; - } - } - fprintf(log_file, "%s %"PRIuMAX"\n", - p->pack_name, (uintmax_t)obj_offset); - fflush(log_file); + static struct trace_key pack_access = TRACE_KEY_INIT(PACK_ACCESS); + trace_printf_key(&pack_access, "%s %"PRIuMAX"\n", + p->pack_name, (uintmax_t)obj_offset); } int do_check_packed_object_crc; @@ -2130,8 +2109,7 @@ void *unpack_entry(struct packed_git *p, off_t obj_offset, int delta_stack_nr = 0, delta_stack_alloc = UNPACK_ENTRY_STACK_PREALLOC; int base_from_cache = 0; - if (log_pack_access != no_log_pack_access) - write_pack_access_log(p, obj_offset); + write_pack_access_log(p, obj_offset); /* PHASE 1: drill down to the innermost base object */ for (;;) { -- cgit v1.3 From 578da0391a7958510b960eaf1ef30d13e791554e Mon Sep 17 00:00:00 2001 From: Karsten Blees Date: Sat, 12 Jul 2014 02:07:01 +0200 Subject: 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 Signed-off-by: Junio C Hamano --- Documentation/git.txt | 5 +++++ git.c | 2 ++ trace.c | 22 ++++++++++++++++++++++ trace.h | 1 + 4 files changed, 30 insertions(+) (limited to 'Documentation/git.txt') diff --git a/Documentation/git.txt b/Documentation/git.txt index 9d073f6adc..fcb8afa200 100644 --- a/Documentation/git.txt +++ b/Documentation/git.txt @@ -938,6 +938,11 @@ Unsetting the variable, or setting it to empty, "0" or starting with "PACK". See 'GIT_TRACE' for available trace output options. +'GIT_TRACE_PERFORMANCE':: + Enables performance related trace messages, e.g. total execution + time of each Git command. + See 'GIT_TRACE' for available trace output options. + 'GIT_TRACE_SETUP':: Enables trace messages printing the .git, working tree and current working directory after Git has completed its setup phase. diff --git a/git.c b/git.c index 7780572948..d4daeb8604 100644 --- a/git.c +++ b/git.c @@ -568,6 +568,8 @@ int main(int argc, char **av) git_setup_gettext(); + trace_command_performance(argv); + /* * "git-xxxx" is the same as "git xxxx", but we obviously: * diff --git a/trace.c b/trace.c index af64dbbcf3..e583dc63bb 100644 --- a/trace.c +++ b/trace.c @@ -404,3 +404,25 @@ inline uint64_t getnanotime(void) return now; } } + +static uint64_t command_start_time; +static struct strbuf command_line = STRBUF_INIT; + +static void print_command_performance_atexit(void) +{ + trace_performance_since(command_start_time, "git command:%s", + command_line.buf); +} + +void trace_command_performance(const char **argv) +{ + if (!trace_want(&trace_perf_key)) + return; + + if (!command_start_time) + atexit(print_command_performance_atexit); + + strbuf_reset(&command_line); + sq_quote_argv(&command_line, argv, 0); + command_start_time = getnanotime(); +} diff --git a/trace.h b/trace.h index c843e681a7..ae6a332947 100644 --- a/trace.h +++ b/trace.h @@ -17,6 +17,7 @@ extern void trace_repo_setup(const char *prefix); extern int trace_want(struct trace_key *key); extern void trace_disable(struct trace_key *key); extern uint64_t getnanotime(void); +extern void trace_command_performance(const char **argv); #ifndef HAVE_VARIADIC_MACROS -- cgit v1.3