undef/git-commit-vandalism
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity
a4d3a283db
git-commit-vandalism/trace2/tr2_tgt_event.c
Jeff Hostetler ee4512ed48 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>
2019-02-22 15:27:59 -08:00

589 lines
16 KiB
C
Raw Blame History

#include "cache.h"
#include "config.h"
#include "json-writer.h"
#include "run-command.h"
#include "version.h"
#include "trace2/tr2_dst.h"
#include "trace2/tr2_tbuf.h"
#include "trace2/tr2_sid.h"
#include "trace2/tr2_tgt.h"
#include "trace2/tr2_tls.h"
static struct tr2_dst tr2dst_event = { "GIT_TR2_EVENT", 0, 0, 0 };
/*
* The version number of the JSON data generated by the EVENT target
* in this source file. Update this if you make a significant change
* to the JSON fields or message structure. You probably do not need
* to update this if you just add another call to one of the existing
* TRACE2 API methods.
*/
#define TR2_EVENT_VERSION "1"
/*
* Region nesting limit for messages written to the event target.
*
* The "region_enter" and "region_leave" messages (especially recursive
* messages such as those produced while diving the worktree or index)
* are primarily intended for the performance target during debugging.
*
* Some of the outer-most messages, however, may be of interest to the
* event target. Set this environment variable to a larger integer for
* more detail in the event target.
*/
#define TR2_ENVVAR_EVENT_NESTING "GIT_TR2_EVENT_NESTING"
static int tr2env_event_nesting_wanted = 2;
/*
* Set this environment variable to true to omit the <time>, <file>, and
* <line> fields from most events.
*/
#define TR2_ENVVAR_EVENT_BRIEF "GIT_TR2_EVENT_BRIEF"
static int tr2env_event_brief;
static int fn_init(void)
{
int want = tr2_dst_trace_want(&tr2dst_event);
int want_nesting;
int want_brief;
char *nesting;
char *brief;
if (!want)
return want;
nesting = getenv(TR2_ENVVAR_EVENT_NESTING);
if (nesting && ((want_nesting = atoi(nesting)) > 0))
tr2env_event_nesting_wanted = want_nesting;
brief = getenv(TR2_ENVVAR_EVENT_BRIEF);
if (brief && ((want_brief = atoi(brief)) > 0))
tr2env_event_brief = want_brief;
return want;
}
static void fn_term(void)
{
tr2_dst_trace_disable(&tr2dst_event);
}
/*
* Append common key-value pairs to the currently open JSON object.
* "event:"<event_name>"
* "sid":"<sid>"
* "thread":"<thread_name>"
* "time":"<time>"
* "file":"<filename>"
* "line":<line_number>
* "repo":<repo_id>
*/
static void event_fmt_prepare(const char *event_name, const char *file,
int line, const struct repository *repo,
struct json_writer *jw)
{
struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
struct tr2_tbuf tb_now;
jw_object_string(jw, "event", event_name);
jw_object_string(jw, "sid", tr2_sid_get());
jw_object_string(jw, "thread", ctx->thread_name.buf);
/*
* In brief mode, only emit <time> on these 2 event types.
*/
if (!tr2env_event_brief || !strcmp(event_name, "version") ||
!strcmp(event_name, "atexit")) {
tr2_tbuf_utc_time(&tb_now);
jw_object_string(jw, "time", tb_now.buf);
}
if (!tr2env_event_brief && file && *file) {
jw_object_string(jw, "file", file);
jw_object_intmax(jw, "line", line);
}
if (repo)
jw_object_intmax(jw, "repo", repo->trace2_repo_id);
}
static void fn_version_fl(const char *file, int line)
{
const char *event_name = "version";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_string(&jw, "evt", TR2_EVENT_VERSION);
jw_object_string(&jw, "exe", git_version_string);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_start_fl(const char *file, int line, const char **argv)
{
const char *event_name = "start";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_inline_begin_array(&jw, "argv");
jw_array_argv(&jw, argv);
jw_end(&jw);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
int code)
{
const char *event_name = "exit";
struct json_writer jw = JSON_WRITER_INIT;
double t_abs = (double)us_elapsed_absolute / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_double(&jw, "t_abs", 6, t_abs);
jw_object_intmax(&jw, "code", code);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_signal(uint64_t us_elapsed_absolute, int signo)
{
const char *event_name = "signal";
struct json_writer jw = JSON_WRITER_INIT;
double t_abs = (double)us_elapsed_absolute / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
jw_object_double(&jw, "t_abs", 6, t_abs);
jw_object_intmax(&jw, "signo", signo);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_atexit(uint64_t us_elapsed_absolute, int code)
{
const char *event_name = "atexit";
struct json_writer jw = JSON_WRITER_INIT;
double t_abs = (double)us_elapsed_absolute / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
jw_object_double(&jw, "t_abs", 6, t_abs);
jw_object_intmax(&jw, "code", code);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void maybe_add_string_va(struct json_writer *jw, const char *field_name,
const char *fmt, va_list ap)
{
if (fmt && *fmt && ap) {
va_list copy_ap;
struct strbuf buf = STRBUF_INIT;
va_copy(copy_ap, ap);
strbuf_vaddf(&buf, fmt, copy_ap);
va_end(copy_ap);
jw_object_string(jw, field_name, buf.buf);
strbuf_release(&buf);
return;
}
if (fmt && *fmt) {
jw_object_string(jw, field_name, fmt);
return;
}
}
static void fn_error_va_fl(const char *file, int line, const char *fmt,
va_list ap)
{
const char *event_name = "error";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
maybe_add_string_va(&jw, "msg", fmt, ap);
/*
* Also emit the format string as a field in case
* post-processors want to aggregate common error
* messages by type without argument fields (such
* as pathnames or branch names) cluttering it up.
*/
if (fmt && *fmt)
jw_object_string(&jw, "fmt", fmt);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_command_path_fl(const char *file, int line, const char *pathname)
{
const char *event_name = "cmd_path";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_string(&jw, "path", pathname);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_command_name_fl(const char *file, int line, const char *name,
const char *hierarchy)
{
const char *event_name = "cmd_name";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_string(&jw, "name", name);
if (hierarchy && *hierarchy)
jw_object_string(&jw, "hierarchy", hierarchy);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_command_mode_fl(const char *file, int line, const char *mode)
{
const char *event_name = "cmd_mode";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_string(&jw, "name", mode);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_alias_fl(const char *file, int line, const char *alias,
const char **argv)
{
const char *event_name = "alias";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_string(&jw, "alias", alias);
jw_object_inline_begin_array(&jw, "argv");
jw_array_argv(&jw, argv);
jw_end(&jw);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_child_start_fl(const char *file, int line,
uint64_t us_elapsed_absolute,
const struct child_process *cmd)
{
const char *event_name = "child_start";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_intmax(&jw, "child_id", cmd->trace2_child_id);
if (cmd->trace2_hook_name) {
jw_object_string(&jw, "child_class", "hook");
jw_object_string(&jw, "hook_name", cmd->trace2_hook_name);
} else {
const char *child_class =
cmd->trace2_child_class ? cmd->trace2_child_class : "?";
jw_object_string(&jw, "child_class", child_class);
}
if (cmd->dir)
jw_object_string(&jw, "cd", cmd->dir);
jw_object_bool(&jw, "use_shell", cmd->use_shell);
jw_object_inline_begin_array(&jw, "argv");
if (cmd->git_cmd)
jw_array_string(&jw, "git");
jw_array_argv(&jw, cmd->argv);
jw_end(&jw);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_child_exit_fl(const char *file, int line,
uint64_t us_elapsed_absolute, int cid, int pid,
int code, uint64_t us_elapsed_child)
{
const char *event_name = "child_exit";
struct json_writer jw = JSON_WRITER_INIT;
double t_rel = (double)us_elapsed_child / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_intmax(&jw, "child_id", cid);
jw_object_intmax(&jw, "pid", pid);
jw_object_intmax(&jw, "code", code);
jw_object_double(&jw, "t_rel", 6, t_rel);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_thread_start_fl(const char *file, int line,
uint64_t us_elapsed_absolute)
{
const char *event_name = "thread_start";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_thread_exit_fl(const char *file, int line,
uint64_t us_elapsed_absolute,
uint64_t us_elapsed_thread)
{
const char *event_name = "thread_exit";
struct json_writer jw = JSON_WRITER_INIT;
double t_rel = (double)us_elapsed_thread / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_double(&jw, "t_rel", 6, t_rel);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
int exec_id, const char *exe, const char **argv)
{
const char *event_name = "exec";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_intmax(&jw, "exec_id", exec_id);
if (exe)
jw_object_string(&jw, "exe", exe);
jw_object_inline_begin_array(&jw, "argv");
jw_array_argv(&jw, argv);
jw_end(&jw);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_exec_result_fl(const char *file, int line,
uint64_t us_elapsed_absolute, int exec_id,
int code)
{
const char *event_name = "exec_result";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_intmax(&jw, "exec_id", exec_id);
jw_object_intmax(&jw, "code", code);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_param_fl(const char *file, int line, const char *param,
const char *value)
{
const char *event_name = "def_param";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, NULL, &jw);
jw_object_string(&jw, "param", param);
jw_object_string(&jw, "value", value);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_repo_fl(const char *file, int line,
const struct repository *repo)
{
const char *event_name = "def_repo";
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, repo, &jw);
jw_object_string(&jw, "worktree", repo->worktree);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
static void fn_region_enter_printf_va_fl(const char *file, int line,
uint64_t us_elapsed_absolute,
const char *category,
const char *label,
const struct repository *repo,
const char *fmt, va_list ap)
{
const char *event_name = "region_enter";
struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) {
struct json_writer jw = JSON_WRITER_INIT;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, repo, &jw);
jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
if (category)
jw_object_string(&jw, "category", category);
if (label)
jw_object_string(&jw, "label", label);
maybe_add_string_va(&jw, "msg", fmt, ap);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
}
static void fn_region_leave_printf_va_fl(
const char *file, int line, uint64_t us_elapsed_absolute,
uint64_t us_elapsed_region, const char *category, const char *label,
const struct repository *repo, const char *fmt, va_list ap)
{
const char *event_name = "region_leave";
struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) {
struct json_writer jw = JSON_WRITER_INIT;
double t_rel = (double)us_elapsed_region / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, repo, &jw);
jw_object_double(&jw, "t_rel", 6, t_rel);
jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
if (category)
jw_object_string(&jw, "category", category);
if (label)
jw_object_string(&jw, "label", label);
maybe_add_string_va(&jw, "msg", fmt, ap);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
}
static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
uint64_t us_elapsed_region, const char *category,
const struct repository *repo, const char *key,
const char *value)
{
const char *event_name = "data";
struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) {
struct json_writer jw = JSON_WRITER_INIT;
double t_abs = (double)us_elapsed_absolute / 1000000.0;
double t_rel = (double)us_elapsed_region / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, repo, &jw);
jw_object_double(&jw, "t_abs", 6, t_abs);
jw_object_double(&jw, "t_rel", 6, t_rel);
jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
jw_object_string(&jw, "category", category);
jw_object_string(&jw, "key", key);
jw_object_string(&jw, "value", value);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
}
static void fn_data_json_fl(const char *file, int line,
uint64_t us_elapsed_absolute,
uint64_t us_elapsed_region, const char *category,
const struct repository *repo, const char *key,
const struct json_writer *value)
{
const char *event_name = "data_json";
struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
if (ctx->nr_open_regions <= tr2env_event_nesting_wanted) {
struct json_writer jw = JSON_WRITER_INIT;
double t_abs = (double)us_elapsed_absolute / 1000000.0;
double t_rel = (double)us_elapsed_region / 1000000.0;
jw_object_begin(&jw, 0);
event_fmt_prepare(event_name, file, line, repo, &jw);
jw_object_double(&jw, "t_abs", 6, t_abs);
jw_object_double(&jw, "t_rel", 6, t_rel);
jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
jw_object_string(&jw, "category", category);
jw_object_string(&jw, "key", key);
jw_object_sub_jw(&jw, "value", value);
jw_end(&jw);
tr2_dst_write_line(&tr2dst_event, &jw.json);
jw_release(&jw);
}
}
struct tr2_tgt tr2_tgt_event = {
&tr2dst_event,
fn_init,
fn_term,
fn_version_fl,
fn_start_fl,
fn_exit_fl,
fn_signal,
fn_atexit,
fn_error_va_fl,
fn_command_path_fl,
fn_command_name_fl,
fn_command_mode_fl,
fn_alias_fl,
fn_child_start_fl,
fn_child_exit_fl,
fn_thread_start_fl,
fn_thread_exit_fl,
fn_exec_fl,
fn_exec_result_fl,
fn_param_fl,
fn_repo_fl,
fn_region_enter_printf_va_fl,
fn_region_leave_printf_va_fl,
fn_data_fl,
fn_data_json_fl,
NULL, /* printf */
};
Reference in New Issue View Git Blame Copy Permalink