tr2: log parent process name
It can be useful to tell who invoked Git - was it invoked manually by a user via CLI or script? By an IDE? In some cases - like 'repo' tool - we can influence the source code and set the GIT_TRACE2_PARENT_SID environment variable from the caller process. In 'repo''s case, that parent SID is manipulated to include the string "repo", which means we can positively identify when Git was invoked by 'repo' tool. However, identifying parents that way requires both that we know which tools invoke Git and that we have the ability to modify the source code of those tools. It cannot scale to keep up with the various IDEs and wrappers which use Git, most of which we don't know about. Learning which tools and wrappers invoke Git, and how, would give us insight to decide where to improve Git's usability and performance. Unfortunately, there's no cross-platform reliable way to gather the name of the parent process. If procfs is present, we can use that; otherwise we will need to discover the name another way. However, the process ID should be sufficient to look up the process name on most platforms, so that code may be shareable. Git for Windows gathers similar information and logs it as a "data_json" event. However, since "data_json" has a variable format, it is difficult to parse effectively in some languages; instead, let's pursue a dedicated "cmd_ancestry" event to record information about the ancestry of the current process and a consistent, parseable way. Git for Windows also gathers information about more than one generation of parent. In Linux further ancestry info can be gathered with procfs, but it's unwieldy to do so. In the interest of later moving Git for Windows ancestry logging to the 'cmd_ancestry' event, and in the interest of later adding more ancestry to the Linux implementation - or of adding this functionality to other platforms which have an easier time walking the process tree - let's make 'cmd_ancestry' accept an array of parentage. Signed-off-by: Emily Shaffer <emilyshaffer@google.com> Signed-off-by: Junio C Hamano <gitster@pobox.com>
Emily Shaffer committed
Jul 21, 2021 at 18:27 UTC
2f732bf15e6dc9c2caf210784f180c6c059c570a
12 files changed
+168
-1
Documentation/technical/api-trace2.txt
+14
@@ -493,6 +493,20 @@ about specific error arguments.
493
}
494
------------
495
496
+`"cmd_ancestry"`::
497
+ This event contains the text command name for the parent (and earlier
498
+ generations of parents) of the current process, in an array ordered from
499
+ nearest parent to furthest great-grandparent. It may not be implemented
500
+ on all platforms.
501
++
502
+------------
503
+{
504
+ "event":"cmd_ancestry",
505
+ ...
506
+ "ancestry":["bash","tmux: server","systemd"]
507
+}
508
+------------
509
+
510
`"cmd_name"`::
511
This event contains the command name for this git process
512
and the hierarchy of commands from parent git processes.
compat/linux/procinfo.c
new
+55
@@ -0,0 +1,55 @@
1
+#include "cache.h"
2
+
3
+#include "strbuf.h"
4
+#include "strvec.h"
5
+#include "trace2.h"
6
+
7
+static void get_ancestry_names(struct strvec *names)
8
+{
9
+ /*
10
+ * NEEDSWORK: We could gather the entire pstree into an array to match
11
+ * functionality with compat/win32/trace2_win32_process_info.c.
12
+ * To do so, we may want to examine /proc/<pid>/stat. For now, just
13
+ * gather the immediate parent name which is readily accessible from
14
+ * /proc/$(getppid())/comm.
15
+ */
16
+ struct strbuf procfs_path = STRBUF_INIT;
17
+ struct strbuf name = STRBUF_INIT;
18
+
19
+ /* try to use procfs if it's present. */
20
+ strbuf_addf(&procfs_path, "/proc/%d/comm", getppid());
21
+ if (strbuf_read_file(&name, procfs_path.buf, 0)) {
22
+ strbuf_release(&procfs_path);
23
+ strbuf_trim_trailing_newline(&name);
24
+ strvec_push(names, strbuf_detach(&name, NULL));
25
+ }
26
+
27
+ return;
28
+ /* NEEDSWORK: add non-procfs-linux implementations here */
29
+}
30
+
31
+void trace2_collect_process_info(enum trace2_process_info_reason reason)
32
+{
33
+ if (!trace2_is_enabled())
34
+ return;
35
+
36
+ /* someday we may want to write something extra here, but not today */
37
+ if (reason == TRACE2_PROCESS_INFO_EXIT)
38
+ return;
39
+
40
+ if (reason == TRACE2_PROCESS_INFO_STARTUP) {
41
+ /*
42
+ * NEEDSWORK: we could do the entire ptree in an array instead,
43
+ * see compat/win32/trace2_win32_process_info.c.
44
+ */
45
+ struct strvec names = STRVEC_INIT;
46
+
47
+ get_ancestry_names(&names);
48
+
49
+ if (names.nr)
50
+ trace2_cmd_ancestry(names.v);
51
+ strvec_clear(&names);
52
+ }
53
+
54
+ return;
55
+}
config.mak.uname
+2
@@ -58,6 +58,8 @@ ifeq ($(uname_S),Linux)
58
FREAD_READS_DIRECTORIES = UnfortunatelyYes
59
BASIC_CFLAGS += -DHAVE_SYSINFO
60
PROCFS_EXECUTABLE_PATH = /proc/self/exe
61
+ HAVE_PLATFORM_PROCINFO = YesPlease
62
+ COMPAT_OBJS += compat/linux/procinfo.o
63
endif
64
ifeq ($(uname_S),GNU/kFreeBSD)
65
HAVE_ALLOCA_H = YesPlease
t/t0210/scrub_normal.perl
+6
@@ -42,6 +42,12 @@ while (<>) {
42
# so just omit it for testing purposes.
43
# print "cmd_path _EXE_\n";
44
}
45
+ elsif ($line =~ m/^cmd_ancestry/) {
46
+ # 'cmd_ancestry' is not implemented everywhere, so for portability's
47
+ # sake, skip it when parsing normal.
48
+ #
49
+ # print "$line";
50
+ }
51
else {
52
print "$line";
53
}
t/t0211/scrub_perf.perl
+5
@@ -44,6 +44,11 @@ while (<>) {
44
# $tokens[$col_rest] = "_EXE_";
45
goto SKIP_LINE;
46
}
47
+ elsif ($tokens[$col_event] =~ m/cmd_ancestry/) {
48
+ # 'cmd_ancestry' is platform-specific and not implemented everywhere,
49
+ # so skip it.
50
+ goto SKIP_LINE;
51
+ }
52
elsif ($tokens[$col_event] =~ m/child_exit/) {
53
$tokens[$col_rest] =~ s/ pid:\d* / pid:_PID_ /;
54
}
t/t0212/parse_events.perl
+4
-1
@@ -132,7 +132,10 @@ while (<>) {
132
# just omit it for testing purposes.
133
# $processes->{$sid}->{'path'} = "_EXE_";
134
}
135
-
135
+ elsif ($event eq 'cmd_ancestry') {
136
+ # 'cmd_ancestry' is platform-specific and not implemented everywhere, so
137
+ # just skip it for testing purposes.
138
+ }
139
elsif ($event eq 'cmd_name') {
140
$processes->{$sid}->{'name'} = $line->{'name'};
141
$processes->{$sid}->{'hierarchy'} = $line->{'hierarchy'};
trace2.c
+13
@@ -260,6 +260,19 @@ void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
260
tgt_j->pfn_command_path_fl(file, line, pathname);
261
}
262
263
+void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names)
264
+{
265
+ struct tr2_tgt *tgt_j;
266
+ int j;
267
+
268
+ if (!trace2_enabled)
269
+ return;
270
+
271
+ for_each_wanted_builtin (j, tgt_j)
272
+ if (tgt_j->pfn_command_ancestry_fl)
273
+ tgt_j->pfn_command_ancestry_fl(file, line, parent_names);
274
+}
275
+
276
void trace2_cmd_name_fl(const char *file, int line, const char *name)
277
{
278
struct tr2_tgt *tgt_j;
trace2.h
+10
@@ -133,6 +133,16 @@ void trace2_cmd_path_fl(const char *file, int line, const char *pathname);
133
134
#define trace2_cmd_path(p) trace2_cmd_path_fl(__FILE__, __LINE__, (p))
135
136
+/*
137
+ * Emit an 'ancestry' event with the process name of the current process's
138
+ * parent process.
139
+ * This gives post-processors a way to determine what invoked the command and
140
+ * learn more about usage patterns.
141
+ */
142
+void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names);
143
+
144
+#define trace2_cmd_ancestry(v) trace2_cmd_ancestry_fl(__FILE__, __LINE__, (v))
145
+
146
/*
147
* Emit a 'cmd_name' event with the canonical name of the command.
148
* This gives post-processors a simple field to identify the command
trace2/tr2_tgt.h
+3
@@ -27,6 +27,8 @@ typedef void(tr2_tgt_evt_error_va_fl_t)(const char *file, int line,
27
28
typedef void(tr2_tgt_evt_command_path_fl_t)(const char *file, int line,
29
const char *command_path);
30
+typedef void(tr2_tgt_evt_command_ancestry_fl_t)(const char *file, int line,
31
+ const char **parent_names);
32
typedef void(tr2_tgt_evt_command_name_fl_t)(const char *file, int line,
33
const char *name,
34
const char *hierarchy);
@@ -108,6 +110,7 @@ struct tr2_tgt {
110
tr2_tgt_evt_atexit_t *pfn_atexit;
111
tr2_tgt_evt_error_va_fl_t *pfn_error_va_fl;
112
tr2_tgt_evt_command_path_fl_t *pfn_command_path_fl;
113
+ tr2_tgt_evt_command_ancestry_fl_t *pfn_command_ancestry_fl;
114
tr2_tgt_evt_command_name_fl_t *pfn_command_name_fl;
115
tr2_tgt_evt_command_mode_fl_t *pfn_command_mode_fl;
116
tr2_tgt_evt_alias_fl_t *pfn_alias_fl;
trace2/tr2_tgt_event.c
+21
@@ -261,6 +261,26 @@ static void fn_command_path_fl(const char *file, int line, const char *pathname)
261
jw_release(&jw);
262
}
263
264
+static void fn_command_ancestry_fl(const char *file, int line, const char **parent_names)
265
+{
266
+ const char *event_name = "cmd_ancestry";
267
+ const char *parent_name = NULL;
268
+ struct json_writer jw = JSON_WRITER_INIT;
269
+
270
+ jw_object_begin(&jw, 0);
271
+ event_fmt_prepare(event_name, file, line, NULL, &jw);
272
+ jw_object_inline_begin_array(&jw, "ancestry");
273
+
274
+ while ((parent_name = *parent_names++))
275
+ jw_array_string(&jw, parent_name);
276
+
277
+ jw_end(&jw); /* 'ancestry' array */
278
+ jw_end(&jw); /* event object */
279
+
280
+ tr2_dst_write_line(&tr2dst_event, &jw.json);
281
+ jw_release(&jw);
282
+}
283
+
284
static void fn_command_name_fl(const char *file, int line, const char *name,
285
const char *hierarchy)
286
{
@@ -584,6 +604,7 @@ struct tr2_tgt tr2_tgt_event = {
604
fn_atexit,
605
fn_error_va_fl,
606
fn_command_path_fl,
607
+ fn_command_ancestry_fl,
608
fn_command_name_fl,
609
fn_command_mode_fl,
610
fn_alias_fl,
trace2/tr2_tgt_normal.c
+19
@@ -160,6 +160,24 @@ static void fn_command_path_fl(const char *file, int line, const char *pathname)
160
strbuf_release(&buf_payload);
161
}
162
163
+static void fn_command_ancestry_fl(const char *file, int line, const char **parent_names)
164
+{
165
+ const char *parent_name = NULL;
166
+ struct strbuf buf_payload = STRBUF_INIT;
167
+
168
+ /* cmd_ancestry parent <- grandparent <- great-grandparent */
169
+ strbuf_addstr(&buf_payload, "cmd_ancestry ");
170
+ while ((parent_name = *parent_names++)) {
171
+ strbuf_addstr(&buf_payload, parent_name);
172
+ /* if we'll write another one after this, add a delimiter */
173
+ if (parent_names && *parent_names)
174
+ strbuf_addstr(&buf_payload, " <- ");
175
+ }
176
+
177
+ normal_io_write_fl(file, line, &buf_payload);
178
+ strbuf_release(&buf_payload);
179
+}
180
+
181
static void fn_command_name_fl(const char *file, int line, const char *name,
182
const char *hierarchy)
183
{
@@ -306,6 +324,7 @@ struct tr2_tgt tr2_tgt_normal = {
324
fn_atexit,
325
fn_error_va_fl,
326
fn_command_path_fl,
327
+ fn_command_ancestry_fl,
328
fn_command_name_fl,
329
fn_command_mode_fl,
330
fn_alias_fl,
trace2/tr2_tgt_perf.c
+16
@@ -253,6 +253,21 @@ static void fn_command_path_fl(const char *file, int line, const char *pathname)
253
strbuf_release(&buf_payload);
254
}
255
256
+static void fn_command_ancestry_fl(const char *file, int line, const char **parent_names)
257
+{
258
+ const char *event_name = "cmd_ancestry";
259
+ struct strbuf buf_payload = STRBUF_INIT;
260
+
261
+ strbuf_addstr(&buf_payload, "ancestry:[");
262
+ /* It's not an argv but the rules are basically the same. */
263
+ sq_append_quote_argv_pretty(&buf_payload, parent_names);
264
+ strbuf_addch(&buf_payload, ']');
265
+
266
+ perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
267
+ &buf_payload);
268
+ strbuf_release(&buf_payload);
269
+}
270
+
271
static void fn_command_name_fl(const char *file, int line, const char *name,
272
const char *hierarchy)
273
{
@@ -532,6 +547,7 @@ struct tr2_tgt tr2_tgt_perf = {
547
fn_atexit,
548
fn_error_va_fl,
549
fn_command_path_fl,
550
+ fn_command_ancestry_fl,
551
fn_command_name_fl,
552
fn_command_mode_fl,
553
fn_alias_fl,