Skip to content
Permalink
Browse files

trace2: create new combined trace facility

Create a new unified tracing facility for git.  The eventual intent is to
replace the current trace_printf* and trace_performance* routines with a
unified set of git_trace2* routines.

In addition to the usual printf-style API, trace2 provides higer-level
event verbs with fixed-fields allowing structured data to be written.
This makes post-processing and analysis easier for external tools.

Trace2 defines 3 output targets.  These are set using the environment
variables "GIT_TR2", "GIT_TR2_PERF", and "GIT_TR2_EVENT".  These may be
set to "1" or to an absolute pathname (just like the current GIT_TRACE).

* GIT_TR2 is intended to be a replacement for GIT_TRACE and logs command
  summary data.

* GIT_TR2_PERF is intended as a replacement for GIT_TRACE_PERFORMANCE.
  It extends the output with columns for the command process, thread,
  repo, absolute and relative elapsed times.  It reports events for
  child process start/stop, thread start/stop, and per-thread function
  nesting.

* GIT_TR2_EVENT is a new structured format. It writes event data as a
  series of JSON records.

Calls to trace2 functions log to any of the 3 output targets enabled
without the need to call different trace_printf* or trace_performance*
routines.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
Signed-off-by: Junio C Hamano <gitster@pobox.com>
  • Loading branch information...
jeffhostetler authored and gitster committed Feb 22, 2019
1 parent e544221 commit ee4512ed481a126dadd33334186e0e759d7f2f47
@@ -1017,6 +1017,16 @@ LIB_OBJS += tempfile.o
LIB_OBJS += thread-utils.o
LIB_OBJS += tmp-objdir.o
LIB_OBJS += trace.o
LIB_OBJS += trace2.o
LIB_OBJS += trace2/tr2_cfg.o
LIB_OBJS += trace2/tr2_cmd_name.o
LIB_OBJS += trace2/tr2_dst.o
LIB_OBJS += trace2/tr2_sid.o
LIB_OBJS += trace2/tr2_tbuf.o
LIB_OBJS += trace2/tr2_tgt_event.o
LIB_OBJS += trace2/tr2_tgt_normal.o
LIB_OBJS += trace2/tr2_tgt_perf.o
LIB_OBJS += trace2/tr2_tls.o
LIB_OBJS += trailer.o
LIB_OBJS += transport.o
LIB_OBJS += transport-helper.o
@@ -1596,7 +1606,9 @@ ifdef NO_INET_PTON
LIB_OBJS += compat/inet_pton.o
BASIC_CFLAGS += -DNO_INET_PTON
endif
ifndef NO_UNIX_SOCKETS
ifdef NO_UNIX_SOCKETS
BASIC_CFLAGS += -DNO_UNIX_SOCKETS
else
LIB_OBJS += unix-socket.o
PROGRAM_OBJS += credential-cache.o
PROGRAM_OBJS += credential-cache--daemon.o
@@ -1816,11 +1816,10 @@ static int update_submodules(struct submodule_update_clone *suc)
{
int i;

run_processes_parallel(suc->max_jobs,
update_clone_get_next_task,
update_clone_start_failure,
update_clone_task_finished,
suc);
run_processes_parallel_tr2(suc->max_jobs, update_clone_get_next_task,
update_clone_start_failure,
update_clone_task_finished, suc, "submodule",
"parallel/update");

/*
* We saved the output and put it out all at once now.
@@ -9,6 +9,7 @@
#include "gettext.h"
#include "convert.h"
#include "trace.h"
#include "trace2.h"
#include "string-list.h"
#include "pack-revindex.h"
#include "hash.h"
@@ -25,12 +25,18 @@ static void restore_sigpipe_to_default(void)

int main(int argc, const char **argv)
{
int result;

/*
* Always open file descriptors 0/1/2 to avoid clobbering files
* in die(). It also avoids messing up when the pipes are dup'ed
* onto stdin/stdout/stderr in the child processes we spawn.
*/
sanitize_stdfds();
restore_sigpipe_to_default();

trace2_initialize();
trace2_cmd_start(argv);

git_resolve_executable_dir(argv[0]);

@@ -40,7 +46,9 @@ int main(int argc, const char **argv)

attr_start();

restore_sigpipe_to_default();
result = cmd_main(argc, argv);

trace2_cmd_exit(result);

return cmd_main(argc, argv);
return result;
}
@@ -1551,19 +1551,23 @@ static int try_shell_exec(const char *cmd, char *const *argv)
return 0;
prog = path_lookup(interpr, 1);
if (prog) {
int exec_id;
int argc = 0;
const char **argv2;
while (argv[argc]) argc++;
ALLOC_ARRAY(argv2, argc + 1);
argv2[0] = (char *)cmd; /* full path to the script file */
memcpy(&argv2[1], &argv[1], sizeof(*argv) * argc);
exec_id = trace2_exec(prog, argv2);
pid = mingw_spawnv(prog, argv2, 1);
if (pid >= 0) {
int status;
if (waitpid(pid, &status, 0) < 0)
status = 255;
trace2_exec_result(exec_id, status);
exit(status);
}
trace2_exec_result(exec_id, -1);
pid = 1; /* indicate that we tried but failed */
free(prog);
free(argv2);
@@ -1576,12 +1580,17 @@ int mingw_execv(const char *cmd, char *const *argv)
/* check if git_command is a shell script */
if (!try_shell_exec(cmd, argv)) {
int pid, status;
int exec_id;

exec_id = trace2_exec(cmd, (const char **)argv);
pid = mingw_spawnv(cmd, (const char **)argv, 0);
if (pid < 0)
if (pid < 0) {
trace2_exec_result(exec_id, -1);
return -1;
}
if (waitpid(pid, &status, 0) < 0)
status = 255;
trace2_exec_result(exec_id, status);
exit(status);
}
return -1;
@@ -147,8 +147,7 @@ static inline int fcntl(int fd, int cmd, ...)
errno = EINVAL;
return -1;
}
/* bash cannot reliably detect negative return codes as failure */
#define exit(code) exit((code) & 0xff)

#define sigemptyset(x) (void)0
static inline int sigaddset(sigset_t *set, int signum)
{ return 0; }
@@ -2655,6 +2655,8 @@ int git_config_set_gently(const char *key, const char *value)
void git_config_set(const char *key, const char *value)
{
git_config_set_multivar(key, value, NULL, 0);

trace2_cmd_set_config(key, value);
}

/*
@@ -209,6 +209,8 @@ static int git_get_exec_path(struct strbuf *buf, const char *argv0)
return -1;
}

trace2_cmd_path(buf->buf);

return 0;
}

@@ -1259,6 +1259,13 @@ static inline int is_missing_file_error(int errno_)

extern int cmd_main(int, const char **);

/*
* Intercept all calls to exit() and route them to trace2 to
* optionally emit a message before calling the real exit().
*/
int trace2_cmd_exit_fl(const char *file, int line, int code);
#define exit(code) exit(trace2_cmd_exit_fl(__FILE__, __LINE__, (code)))

/*
* You can mark a stack variable with UNLEAK(var) to avoid it being
* reported as a leak by tools like LSAN or valgrind. The argument
65 git.c
@@ -147,16 +147,20 @@ static int handle_options(const char ***argv, int *argc, int *envchanged)
git_set_exec_path(cmd + 1);
else {
puts(git_exec_path());
trace2_cmd_name("_query_");
exit(0);
}
} else if (!strcmp(cmd, "--html-path")) {
puts(system_path(GIT_HTML_PATH));
trace2_cmd_name("_query_");
exit(0);
} else if (!strcmp(cmd, "--man-path")) {
puts(system_path(GIT_MAN_PATH));
trace2_cmd_name("_query_");
exit(0);
} else if (!strcmp(cmd, "--info-path")) {
puts(system_path(GIT_INFO_PATH));
trace2_cmd_name("_query_");
exit(0);
} else if (!strcmp(cmd, "-p") || !strcmp(cmd, "--paginate")) {
use_pager = 1;
@@ -285,6 +289,7 @@ static int handle_options(const char ***argv, int *argc, int *envchanged)
(*argv)++;
(*argc)--;
} else if (skip_prefix(cmd, "--list-cmds=", &cmd)) {
trace2_cmd_name("_query_");
if (!strcmp(cmd, "parseopt")) {
struct string_list list = STRING_LIST_INIT_DUP;
int i;
@@ -332,9 +337,14 @@ static int handle_alias(int *argcp, const char ***argv)
commit_pager_choice();

child.use_shell = 1;
child.trace2_child_class = "shell_alias";
argv_array_push(&child.args, alias_string + 1);
argv_array_pushv(&child.args, (*argv) + 1);

trace2_cmd_alias(alias_command, child.args.argv);
trace2_cmd_list_config();
trace2_cmd_name("_run_shell_alias_");

ret = run_command(&child);
if (ret >= 0) /* normal exit */
exit(ret);
@@ -369,6 +379,9 @@ static int handle_alias(int *argcp, const char ***argv)
/* insert after command name */
memcpy(new_argv + count, *argv + 1, sizeof(char *) * *argcp);

trace2_cmd_alias(alias_command, new_argv);
trace2_cmd_list_config();

*argv = new_argv;
*argcp += count - 1;

@@ -417,6 +430,8 @@ static int run_builtin(struct cmd_struct *p, int argc, const char **argv)
setup_work_tree();

trace_argv_printf(argv, "trace: built-in: git");
trace2_cmd_name(p->cmd);
trace2_cmd_list_config();

validate_cache_entries(the_repository->index);
status = p->fn(argc, argv, prefix);
@@ -666,7 +681,14 @@ static void execv_dashed_external(const char **argv)
cmd.clean_on_exit = 1;
cmd.wait_after_clean = 1;
cmd.silent_exec_failure = 1;
cmd.trace2_child_class = "dashed";

trace2_cmd_name("_run_dashed_");

/*
* The code in run_command() logs trace2 child_start/child_exit
* events, so we do not need to report exec/exec_result events here.
*/
trace_argv_printf(cmd.args.argv, "trace: exec:");

/*
@@ -676,6 +698,12 @@ static void execv_dashed_external(const char **argv)
* the program.
*/
status = run_command(&cmd);

/*
* If the child process ran and we are now going to exit, emit a
* generic string as our trace2 command verb to indicate that we
* launched a dashed command.
*/
if (status >= 0)
exit(status);
else if (errno != ENOENT)
@@ -701,6 +729,43 @@ static int run_argv(int *argcp, const char ***argv)
if (!done_alias)
handle_builtin(*argcp, *argv);

#if 0 // TODO In GFW, need to amend a7924b655e940b06cb547c235d6bed9767929673 to include trace2_ and _tr2 lines.
else if (get_builtin(**argv)) {
struct argv_array args = ARGV_ARRAY_INIT;
int i;

/*
* The current process is committed to launching a
* child process to run the command named in (**argv)
* and exiting. Log a generic string as the trace2
* command verb to indicate this. Note that the child
* process will log the actual verb when it runs.
*/
trace2_cmd_name("_run_git_alias_");

if (get_super_prefix())
die("%s doesn't support --super-prefix", **argv);

commit_pager_choice();

argv_array_push(&args, "git");
for (i = 0; i < *argcp; i++)
argv_array_push(&args, (*argv)[i]);

trace_argv_printf(args.argv, "trace: exec:");

/*
* if we fail because the command is not found, it is
* OK to return. Otherwise, we just pass along the status code.
*/
i = run_command_v_opt_tr2(args.argv, RUN_SILENT_EXEC_FAILURE |
RUN_CLEAN_ON_EXIT, "git_alias");
if (i >= 0 || errno != ENOENT)
exit(i);
die("could not execute builtin %s", **argv);
}
#endif // a7924b655e940b06cb547c235d6bed9767929673

/* .. then try the external ones */
execv_dashed_external(*argv);

@@ -1385,6 +1385,13 @@ int cmd_main(int argc, const char **argv)
string_list_init(&options.deepen_not, 1);
string_list_init(&options.push_options, 1);

/*
* Just report "remote-curl" here (folding all the various aliases
* ("git-remote-http", "git-remote-https", and etc.) here since they
* are all just copies of the same actual executable.
*/
trace2_cmd_name("remote-curl");

remote = remote_get(argv[1]);

if (argc > 2) {
@@ -126,6 +126,8 @@ static int repo_init_gitdir(struct repository *repo, const char *gitdir)
void repo_set_worktree(struct repository *repo, const char *path)
{
repo->worktree = real_pathdup(path, 1);

trace2_def_repo(repo);
}

static int read_and_verify_repository_format(struct repository_format *format,
@@ -92,6 +92,9 @@ struct repository {
/* Repository's current hash algorithm, as serialized on disk. */
const struct git_hash_algo *hash_algo;

/* A unique-id for tracing purposes. */
int trace2_repo_id;

/* Configurations */

/* Indicate if a repository has a different 'commondir' from 'gitdir' */
Oops, something went wrong.

0 comments on commit ee4512e

Please sign in to comment.
You can’t perform that action at this time.