diff options
Diffstat (limited to 'trace.c')
| -rw-r--r-- | trace.c | 91 |
1 files changed, 79 insertions, 12 deletions
@@ -29,7 +29,7 @@ struct trace_key trace_perf_key = TRACE_KEY_INIT(PERFORMANCE); struct trace_key trace_setup_key = TRACE_KEY_INIT(SETUP); /* Get a trace file descriptor from "key" env variable. */ -static int get_trace_fd(struct trace_key *key) +static int get_trace_fd(struct trace_key *key, const char *override_envvar) { const char *trace; @@ -37,7 +37,7 @@ static int get_trace_fd(struct trace_key *key) if (key->initialized) return key->fd; - trace = getenv(key->key); + trace = override_envvar ? override_envvar : getenv(key->key); if (!trace || !strcmp(trace, "") || !strcmp(trace, "0") || !strcasecmp(trace, "false")) @@ -68,6 +68,18 @@ static int get_trace_fd(struct trace_key *key) return key->fd; } +void trace_override_envvar(struct trace_key *key, const char *value) +{ + trace_disable(key); + key->initialized = 0; + + /* + * Invoke get_trace_fd() to initialize key using the given value + * instead of the value of the environment variable. + */ + get_trace_fd(key, value); +} + void trace_disable(struct trace_key *key) { if (key->need_close) @@ -88,8 +100,6 @@ static int prepare_trace_line(const char *file, int line, if (!trace_want(key)) return 0; - set_try_to_free_routine(NULL); /* is never reset */ - /* unit tests may want to disable additional trace output */ if (trace_want(&trace_bare)) return 1; @@ -114,7 +124,7 @@ static int prepare_trace_line(const char *file, int line, static void trace_write(struct trace_key *key, const void *buf, unsigned len) { - if (write_in_full(get_trace_fd(key), buf, len) < 0) { + if (write_in_full(get_trace_fd(key, NULL), buf, len) < 0) { warning("unable to write trace for %s: %s", key->key, strerror(errno)); trace_disable(key); @@ -176,10 +186,30 @@ void trace_strbuf_fl(const char *file, int line, struct trace_key *key, strbuf_release(&buf); } +static uint64_t perf_start_times[10]; +static int perf_indent; + +uint64_t trace_performance_enter(void) +{ + uint64_t now; + + if (!trace_want(&trace_perf_key)) + return 0; + + now = getnanotime(); + perf_start_times[perf_indent] = now; + if (perf_indent + 1 < ARRAY_SIZE(perf_start_times)) + perf_indent++; + else + BUG("Too deep indentation"); + return now; +} + static void trace_performance_vprintf_fl(const char *file, int line, uint64_t nanos, const char *format, va_list ap) { + static const char space[] = " "; struct strbuf buf = STRBUF_INIT; if (!prepare_trace_line(file, line, &trace_perf_key, &buf)) @@ -188,7 +218,10 @@ static void trace_performance_vprintf_fl(const char *file, int line, strbuf_addf(&buf, "performance: %.9f s", (double) nanos / 1000000000); if (format && *format) { - strbuf_addstr(&buf, ": "); + if (perf_indent >= strlen(space)) + BUG("Too deep indentation"); + + strbuf_addf(&buf, ":%.*s ", perf_indent, space); strbuf_vaddf(&buf, format, ap); } @@ -244,6 +277,24 @@ void trace_performance_since(uint64_t start, const char *format, ...) va_end(ap); } +void trace_performance_leave(const char *format, ...) +{ + va_list ap; + uint64_t since; + + if (perf_indent) + perf_indent--; + + if (!format) /* Allow callers to leave without tracing anything */ + return; + + since = perf_start_times[perf_indent]; + va_start(ap, format); + trace_performance_vprintf_fl(NULL, 0, getnanotime() - since, + format, ap); + va_end(ap); +} + #else void trace_printf_key_fl(const char *file, int line, struct trace_key *key, @@ -273,6 +324,24 @@ void trace_performance_fl(const char *file, int line, uint64_t nanos, va_end(ap); } +void trace_performance_leave_fl(const char *file, int line, + uint64_t nanos, const char *format, ...) +{ + va_list ap; + uint64_t since; + + if (perf_indent) + perf_indent--; + + if (!format) /* Allow callers to leave without tracing anything */ + return; + + since = perf_start_times[perf_indent]; + va_start(ap, format); + trace_performance_vprintf_fl(file, line, nanos - since, format, ap); + va_end(ap); +} + #endif /* HAVE_VARIADIC_MACROS */ @@ -326,7 +395,7 @@ void trace_repo_setup(const char *prefix) int trace_want(struct trace_key *key) { - return !!get_trace_fd(key); + return !!get_trace_fd(key, NULL); } #if defined(HAVE_CLOCK_GETTIME) && defined(HAVE_CLOCK_MONOTONIC) @@ -411,13 +480,11 @@ uint64_t getnanotime(void) } } -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); + trace_performance_leave("git command:%s", command_line.buf); } void trace_command_performance(const char **argv) @@ -425,10 +492,10 @@ void trace_command_performance(const char **argv) if (!trace_want(&trace_perf_key)) return; - if (!command_start_time) + if (!command_line.len) atexit(print_command_performance_atexit); strbuf_reset(&command_line); sq_quote_argv_pretty(&command_line, argv); - command_start_time = getnanotime(); + trace_performance_enter(); } |