diff options
Diffstat (limited to 'trace2.c')
| -rw-r--r-- | trace2.c | 267 |
1 files changed, 254 insertions, 13 deletions
@@ -1,20 +1,23 @@ -#include "cache.h" +#include "git-compat-util.h" #include "config.h" -#include "json-writer.h" -#include "quote.h" +#include "repository.h" #include "run-command.h" #include "sigchain.h" #include "thread-utils.h" -#include "version.h" +#include "trace.h" +#include "trace2.h" #include "trace2/tr2_cfg.h" #include "trace2/tr2_cmd_name.h" +#include "trace2/tr2_ctr.h" #include "trace2/tr2_dst.h" #include "trace2/tr2_sid.h" #include "trace2/tr2_sysenv.h" #include "trace2/tr2_tgt.h" #include "trace2/tr2_tls.h" +#include "trace2/tr2_tmr.h" static int trace2_enabled; +static int trace2_redact = 1; static int tr2_next_child_id; /* modify under lock */ static int tr2_next_exec_id; /* modify under lock */ @@ -52,7 +55,7 @@ static struct tr2_tgt *tr2_tgt_builtins[] = * Force (rather than lazily) initialize any of the requested * builtin TRACE2 targets at startup (and before we've seen an * actual TRACE2 event call) so we can see if we need to setup - * the TR2 and TLS machinery. + * private data structures and thread-local storage. * * Return the number of builtin targets enabled. */ @@ -83,6 +86,39 @@ static void tr2_tgt_disable_builtins(void) tgt_j->pfn_term(); } +/* + * The signature of this function must match the pfn_timer + * method in the targets. (Think of this is an apply operation + * across the set of active targets.) + */ +static void tr2_tgt_emit_a_timer(const struct tr2_timer_metadata *meta, + const struct tr2_timer *timer, + int is_final_data) +{ + struct tr2_tgt *tgt_j; + int j; + + for_each_wanted_builtin (j, tgt_j) + if (tgt_j->pfn_timer) + tgt_j->pfn_timer(meta, timer, is_final_data); +} + +/* + * The signature of this function must match the pfn_counter + * method in the targets. + */ +static void tr2_tgt_emit_a_counter(const struct tr2_counter_metadata *meta, + const struct tr2_counter *counter, + int is_final_data) +{ + struct tr2_tgt *tgt_j; + int j; + + for_each_wanted_builtin (j, tgt_j) + if (tgt_j->pfn_counter) + tgt_j->pfn_counter(meta, counter, is_final_data); +} + static int tr2main_exit_code; /* @@ -110,6 +146,32 @@ static void tr2main_atexit_handler(void) */ tr2tls_pop_unwind_self(); + /* + * Some timers want per-thread details. If the main thread + * used one of those timers, emit the details now (before + * we emit the aggregate timer values). + * + * Likewise for counters. + */ + tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer); + tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter); + + /* + * Add stopwatch timer and counter data for the main thread to + * the final totals. And then emit the final values. + * + * Technically, we shouldn't need to hold the lock to update + * and output the final_timer_block and final_counter_block + * (since all other threads should be dead by now), but it + * doesn't hurt anything. + */ + tr2tls_lock(); + tr2_update_final_timers(); + tr2_update_final_counters(); + tr2_emit_final_timers(tr2_tgt_emit_a_timer); + tr2_emit_final_counters(tr2_tgt_emit_a_counter); + tr2tls_unlock(); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_atexit) tgt_j->pfn_atexit(us_elapsed_absolute, @@ -163,6 +225,8 @@ void trace2_initialize_fl(const char *file, int line) if (!tr2_tgt_want_builtins()) return; trace2_enabled = 1; + if (!git_env_bool("GIT_TRACE2_REDACT", 1)) + trace2_redact = 0; tr2_sid_get(); @@ -183,12 +247,93 @@ int trace2_is_enabled(void) return trace2_enabled; } +/* + * Redacts an argument, i.e. ensures that no password in + * https://user:password@host/-style URLs is logged. + * + * Returns the original if nothing needed to be redacted. + * Returns a pointer that needs to be `free()`d otherwise. + */ +static const char *redact_arg(const char *arg) +{ + const char *p, *colon; + size_t at; + + if (!trace2_redact || + (!skip_prefix(arg, "https://", &p) && + !skip_prefix(arg, "http://", &p))) + return arg; + + at = strcspn(p, "@/"); + if (p[at] != '@') + return arg; + + colon = memchr(p, ':', at); + if (!colon) + return arg; + + return xstrfmt("%.*s:<REDACTED>%s", (int)(colon - arg), arg, p + at); +} + +/* + * Redacts arguments in an argument list. + * + * Returns the original if nothing needed to be redacted. + * Otherwise, returns a new array that needs to be released + * via `free_redacted_argv()`. + */ +static const char **redact_argv(const char **argv) +{ + int i, j; + const char *redacted = NULL; + const char **ret; + + if (!trace2_redact) + return argv; + + for (i = 0; argv[i]; i++) + if ((redacted = redact_arg(argv[i])) != argv[i]) + break; + + if (!argv[i]) + return argv; + + for (j = 0; argv[j]; j++) + ; /* keep counting */ + + ALLOC_ARRAY(ret, j + 1); + ret[j] = NULL; + + for (j = 0; j < i; j++) + ret[j] = argv[j]; + ret[i] = redacted; + for (++i; argv[i]; i++) { + redacted = redact_arg(argv[i]); + ret[i] = redacted ? redacted : argv[i]; + } + + return ret; +} + +static void free_redacted_argv(const char **redacted, const char **argv) +{ + int i; + + if (redacted != argv) { + for (i = 0; argv[i]; i++) + if (redacted[i] != argv[i]) + free((void *)redacted[i]); + free((void *)redacted); + } +} + void trace2_cmd_start_fl(const char *file, int line, const char **argv) { struct tr2_tgt *tgt_j; int j; uint64_t us_now; uint64_t us_elapsed_absolute; + const char **redacted; if (!trace2_enabled) return; @@ -196,10 +341,14 @@ void trace2_cmd_start_fl(const char *file, int line, const char **argv) us_now = getnanotime() / 1000; us_elapsed_absolute = tr2tls_absolute_elapsed(us_now); + redacted = redact_argv(argv); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_start_fl) tgt_j->pfn_start_fl(file, line, us_elapsed_absolute, - argv); + redacted); + + free_redacted_argv(redacted, argv); } void trace2_cmd_exit_fl(const char *file, int line, int code) @@ -212,7 +361,6 @@ void trace2_cmd_exit_fl(const char *file, int line, int code) if (!trace2_enabled) return; - trace_git_fsync_stats(); trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT); tr2main_exit_code = code; @@ -285,6 +433,9 @@ void trace2_cmd_name_fl(const char *file, int line, const char *name) for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_command_name_fl) tgt_j->pfn_command_name_fl(file, line, name, hierarchy); + + trace2_cmd_list_config(); + trace2_cmd_list_env_vars(); } void trace2_cmd_mode_fl(const char *file, int line, const char *mode) @@ -316,17 +467,29 @@ void trace2_cmd_alias_fl(const char *file, int line, const char *alias, void trace2_cmd_list_config_fl(const char *file, int line) { + static int emitted = 0; + if (!trace2_enabled) return; + if (emitted) + return; + emitted = 1; + tr2_cfg_list_config_fl(file, line); } void trace2_cmd_list_env_vars_fl(const char *file, int line) { + static int emitted = 0; + if (!trace2_enabled) return; + if (emitted) + return; + emitted = 1; + tr2_list_env_vars_fl(file, line); } @@ -346,6 +509,7 @@ void trace2_child_start_fl(const char *file, int line, int j; uint64_t us_now; uint64_t us_elapsed_absolute; + const char **orig_argv = cmd->args.v; if (!trace2_enabled) return; @@ -356,10 +520,24 @@ void trace2_child_start_fl(const char *file, int line, cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id); cmd->trace2_child_us_start = us_now; + /* + * The `pfn_child_start_fl` API takes a `struct child_process` + * rather than a simple `argv` for the child because some + * targets make use of the additional context bits/values. So + * temporarily replace the original argv (inside the `strvec`) + * with a possibly redacted version. + */ + cmd->args.v = redact_argv(orig_argv); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_child_start_fl) tgt_j->pfn_child_start_fl(file, line, us_elapsed_absolute, cmd); + + if (cmd->args.v != orig_argv) { + free_redacted_argv(cmd->args.v, orig_argv); + cmd->args.v = orig_argv; + } } void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd, @@ -430,6 +608,7 @@ int trace2_exec_fl(const char *file, int line, const char *exe, int exec_id; uint64_t us_now; uint64_t us_elapsed_absolute; + const char **redacted; if (!trace2_enabled) return -1; @@ -439,10 +618,14 @@ int trace2_exec_fl(const char *file, int line, const char *exe, exec_id = tr2tls_locked_increment(&tr2_next_exec_id); + redacted = redact_argv(argv); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_exec_fl) tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute, - exec_id, exe, argv); + exec_id, exe, redacted); + + free_redacted_argv(redacted, argv); return exec_id; } @@ -466,7 +649,7 @@ void trace2_exec_result_fl(const char *file, int line, int exec_id, int code) file, line, us_elapsed_absolute, exec_id, code); } -void trace2_thread_start_fl(const char *file, int line, const char *thread_name) +void trace2_thread_start_fl(const char *file, int line, const char *thread_base_name) { struct tr2_tgt *tgt_j; int j; @@ -488,14 +671,14 @@ void trace2_thread_start_fl(const char *file, int line, const char *thread_name) */ trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL, "thread-proc on main: %s", - thread_name); + thread_base_name); return; } us_now = getnanotime() / 1000; us_elapsed_absolute = tr2tls_absolute_elapsed(us_now); - tr2tls_create_self(thread_name, us_now); + tr2tls_create_self(thread_base_name, us_now); for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_thread_start_fl) @@ -541,6 +724,25 @@ void trace2_thread_exit_fl(const char *file, int line) tr2tls_pop_unwind_self(); us_elapsed_thread = tr2tls_region_elasped_self(us_now); + /* + * Some timers want per-thread details. If this thread used + * one of those timers, emit the details now. + * + * Likewise for counters. + */ + tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer); + tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter); + + /* + * Add stopwatch timer and counter data from the current + * (non-main) thread to the final totals. (We'll accumulate + * data for the main thread later during "atexit".) + */ + tr2tls_lock(); + tr2_update_final_timers(); + tr2_update_final_counters(); + tr2tls_unlock(); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_thread_exit_fl) tgt_j->pfn_thread_exit_fl(file, line, @@ -551,17 +753,23 @@ void trace2_thread_exit_fl(const char *file, int line) } void trace2_def_param_fl(const char *file, int line, const char *param, - const char *value) + const char *value, const struct key_value_info *kvi) { struct tr2_tgt *tgt_j; int j; + const char *redacted; if (!trace2_enabled) return; + redacted = redact_arg(value); + for_each_wanted_builtin (j, tgt_j) if (tgt_j->pfn_param_fl) - tgt_j->pfn_param_fl(file, line, param, value); + tgt_j->pfn_param_fl(file, line, param, redacted, kvi); + + if (redacted != value) + free((void *)redacted); } void trace2_def_repo_fl(const char *file, int line, struct repository *repo) @@ -795,6 +1003,39 @@ void trace2_printf_fl(const char *file, int line, const char *fmt, ...) va_end(ap); } +void trace2_timer_start(enum trace2_timer_id tid) +{ + if (!trace2_enabled) + return; + + if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS) + BUG("trace2_timer_start: invalid timer id: %d", tid); + + tr2_start_timer(tid); +} + +void trace2_timer_stop(enum trace2_timer_id tid) +{ + if (!trace2_enabled) + return; + + if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS) + BUG("trace2_timer_stop: invalid timer id: %d", tid); + + tr2_stop_timer(tid); +} + +void trace2_counter_add(enum trace2_counter_id cid, uint64_t value) +{ + if (!trace2_enabled) + return; + + if (cid < 0 || cid >= TRACE2_NUMBER_OF_COUNTERS) + BUG("trace2_counter_add: invalid counter id: %d", cid); + + tr2_counter_increment(cid, value); +} + const char *trace2_session_id(void) { return tr2_sid_get(); |