Show changes to 9 files +76 −10
Documentation/technical/api-trace2.txt, git-compat-util.h, t/t0210-trace2-normal.sh, trace2.c, trace2.h, trace2/tr2_tgt.h, trace2/tr2_tgt_event.c, trace2/tr2_tgt_normal.c, trace2/tr2_tgt_perf.c
diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt
index f4a8a690878..55ecfd8c30c 100644
--- a/Documentation/technical/api-trace2.txt
+++ b/Documentation/technical/api-trace2.txt
@@ -421,7 +421,9 @@ only present on the "start" and "atexit" events.
------------
`"exit"`::
- This event is emitted when git calls `exit()`.
+ This event is emitted when git calls `exit()`. This event will
+ be produced for all regular ending of the git process, but it
+ might also exit via a "signal".
+
------------
{
@@ -435,7 +437,7 @@ only present on the "start" and "atexit" events.
`"atexit"`::
This event is emitted by the Trace2 `atexit` routine during
final shutdown. It should be the last event emitted by the
- process.
+ process, unless it was aborted (see "signal").
+
(The elapsed time reported here is greater than the time reported in
the "exit" event because it runs after all other atexit tasks have
@@ -452,8 +454,11 @@ completed.)
`"signal"`::
This event is emitted when the program is terminated by a user
- signal. Depending on the platform, the signal event may
- prevent the "atexit" event from being generated.
+ signal, which includes git itself calling abort(3). Depending
+ on the platform, the signal event may prevent the "exit"
+ and/or "atexit" events from being generated. E.g. if BUG() was
+ invoked we'll emit an "error" event followed by a "signal"
+ event, and nothing else.
+
------------
{
diff --git a/git-compat-util.h b/git-compat-util.h
index 58fd813bd01..ea3177b2771 100644
--- a/git-compat-util.h
+++ b/git-compat-util.h
@@ -1403,6 +1403,15 @@ int cmd_main(int, const char **);
int trace2_cmd_exit_fl(const char *file, int line, int code);
#define exit(code) exit(trace2_cmd_exit_fl(__FILE__, __LINE__, (code)))
+/*
+ * Intercept calls to abort() to log that we aborted.
+ */
+void trace2_cmd_signal_fl(const char *file, int line, int signo);
+#define abort() do { \
+ trace2_cmd_signal_fl(__FILE__, __LINE__, SIGABRT); \
+ abort(); \
+} while (0)
+
/*
* 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
diff --git a/t/t0210-trace2-normal.sh b/t/t0210-trace2-normal.sh
index 910a6af8058..25fffdba80e 100755
--- a/t/t0210-trace2-normal.sh
+++ b/t/t0210-trace2-normal.sh
@@ -162,6 +162,7 @@ test_expect_success 'BUG messages are written to trace2' '
start _EXE_ trace2 007bug
cmd_name trace2 (trace2)
error the bug message
+ signal elapsed:_TIME_ code:6
EOF
test_cmp expect actual
'
diff --git a/trace2.c b/trace2.c
index e01cf77f1a8..250b2424bfa 100644
--- a/trace2.c
+++ b/trace2.c
@@ -230,6 +230,25 @@ int trace2_cmd_exit_fl(const char *file, int line, int code)
return code;
}
+void trace2_cmd_signal_fl(const char *file, int line, int signo)
+{
+ struct tr2_tgt *tgt_j;
+ int j;
+ uint64_t us_now;
+ uint64_t us_elapsed_absolute;
+
+ if (!trace2_enabled)
+ return;
+
+ us_now = getnanotime() / 1000;
+ us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
+
+ for_each_wanted_builtin (j, tgt_j)
+ if (tgt_j->pfn_signal_fl)
+ tgt_j->pfn_signal_fl(file, line, us_elapsed_absolute,
+ signo);
+}
+
void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
va_list ap)
{
diff --git a/trace2.h b/trace2.h
index 1b109f57d0a..4f456f2fc62 100644
--- a/trace2.h
+++ b/trace2.h
@@ -112,6 +112,14 @@ int trace2_cmd_exit_fl(const char *file, int line, int code);
#define trace2_cmd_exit(code) (trace2_cmd_exit_fl(__FILE__, __LINE__, (code)))
+/*
+ * Emit a 'signal' event. Used to log that we called abort() e.g. via
+ * the BUG() function.
+ */
+void trace2_cmd_signal_fl(const char *file, int line, int signo);
+
+#define trace2_cmd_signal(signo) (trace2_cmd_signal_fl(__FILE__, __LINE__, (signo)))
+
/*
* Emit an 'error' event.
*
diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h
index 65f94e15748..fbc33650c5d 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -20,6 +20,8 @@ typedef void(tr2_tgt_evt_start_fl_t)(const char *file, int line,
typedef void(tr2_tgt_evt_exit_fl_t)(const char *file, int line,
uint64_t us_elapsed_absolute, int code);
typedef void(tr2_tgt_evt_signal_t)(uint64_t us_elapsed_absolute, int signo);
+typedef void(tr2_tgt_evt_signal_fl_t)(const char *file, int line,
+ uint64_t us_elapsed_absolute, int signo);
typedef void(tr2_tgt_evt_atexit_t)(uint64_t us_elapsed_absolute, int code);
typedef void(tr2_tgt_evt_error_va_fl_t)(const char *file, int line,
@@ -111,6 +113,7 @@ struct tr2_tgt {
tr2_tgt_evt_start_fl_t *pfn_start_fl;
tr2_tgt_evt_exit_fl_t *pfn_exit_fl;
tr2_tgt_evt_signal_t *pfn_signal;
+ tr2_tgt_evt_signal_fl_t *pfn_signal_fl;
tr2_tgt_evt_atexit_t *pfn_atexit;
tr2_tgt_evt_error_va_fl_t *pfn_error_va_fl;
tr2_tgt_evt_command_path_fl_t *pfn_command_path_fl;
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index c5c8cfbbaa0..df947378a51 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -177,14 +177,15 @@ static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
jw_release(&jw);
}
-static void fn_signal(uint64_t us_elapsed_absolute, int signo)
+static void fn_signal_fl(const char *file, int line,
+ 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);
+ 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);
@@ -193,6 +194,11 @@ static void fn_signal(uint64_t us_elapsed_absolute, int signo)
jw_release(&jw);
}
+static void fn_signal(uint64_t us_elapsed_absolute, int signo)
+{
+ fn_signal_fl(__FILE__, __LINE__, us_elapsed_absolute, signo);
+}
+
static void fn_atexit(uint64_t us_elapsed_absolute, int code)
{
const char *event_name = "atexit";
@@ -624,6 +630,7 @@ struct tr2_tgt tr2_tgt_event = {
.pfn_start_fl = fn_start_fl,
.pfn_exit_fl = fn_exit_fl,
.pfn_signal = fn_signal,
+ .pfn_signal_fl = fn_signal_fl,
.pfn_atexit = fn_atexit,
.pfn_error_va_fl = fn_error_va_fl,
.pfn_command_path_fl = fn_command_path_fl,
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index c42fbade7f0..8e2bc5027fe 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -105,17 +105,23 @@ static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
strbuf_release(&buf_payload);
}
-static void fn_signal(uint64_t us_elapsed_absolute, int signo)
+static void fn_signal_fl(const char *file, int line,
+ uint64_t us_elapsed_absolute, int signo)
{
struct strbuf buf_payload = STRBUF_INIT;
double elapsed = (double)us_elapsed_absolute / 1000000.0;
strbuf_addf(&buf_payload, "signal elapsed:%.6f code:%d", elapsed,
signo);
- normal_io_write_fl(__FILE__, __LINE__, &buf_payload);
+ normal_io_write_fl(file, line, &buf_payload);
strbuf_release(&buf_payload);
}
+static void fn_signal(uint64_t us_elapsed_absolute, int signo)
+{
+ fn_signal_fl(__FILE__, __LINE__, us_elapsed_absolute, signo);
+}
+
static void fn_atexit(uint64_t us_elapsed_absolute, int code)
{
struct strbuf buf_payload = STRBUF_INIT;
@@ -336,6 +342,7 @@ struct tr2_tgt tr2_tgt_normal = {
.pfn_start_fl = fn_start_fl,
.pfn_exit_fl = fn_exit_fl,
.pfn_signal = fn_signal,
+ .pfn_signal_fl = fn_signal_fl,
.pfn_atexit = fn_atexit,
.pfn_error_va_fl = fn_error_va_fl,
.pfn_command_path_fl = fn_command_path_fl,
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index a1eff8bea31..4ce18d3f12e 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -193,18 +193,24 @@ static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
strbuf_release(&buf_payload);
}
-static void fn_signal(uint64_t us_elapsed_absolute, int signo)
+static void fn_signal_fl(const char *file, int line,
+ uint64_t us_elapsed_absolute, int signo)
{
const char *event_name = "signal";
struct strbuf buf_payload = STRBUF_INIT;
strbuf_addf(&buf_payload, "signo:%d", signo);
- perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
+ perf_io_write_fl(file, line, event_name, NULL,
&us_elapsed_absolute, NULL, NULL, &buf_payload);
strbuf_release(&buf_payload);
}
+static void fn_signal(uint64_t us_elapsed_absolute, int signo)
+{
+ fn_signal_fl(__FILE__, __LINE__, us_elapsed_absolute, signo);
+}
+
static void fn_atexit(uint64_t us_elapsed_absolute, int code)
{
const char *event_name = "atexit";
@@ -560,6 +566,7 @@ struct tr2_tgt tr2_tgt_perf = {
.pfn_start_fl = fn_start_fl,
.pfn_exit_fl = fn_exit_fl,
.pfn_signal = fn_signal,
+ .pfn_signal_fl = fn_signal_fl,
.pfn_atexit = fn_atexit,
.pfn_error_va_fl = fn_error_va_fl,
.pfn_command_path_fl = fn_command_path_fl,