[PATCH v7 00/15] Trace2 tracing facility
- From
- Jeff Hostetler via GitGitGadget <gitgitgadget@gmail.com>
- Date
- Feb 22, 2019, 22:24 UTC
- Message-ID
- <pull.108.v7.git.gitgitgadget@gmail.com>
- In-Reply-To
- <pull.108.v6.git.gitgitgadget@gmail.com>
V7 addresses: [] squashes in the fixup for windows process ancestry calculation. [] adds optional socket_type parameter to the unix domain socket syntax. [] allow unix domain socket syntax to try both stream and dgram if socket_type not specified. [] add Perl prereq checks for JSON:PP in trace2 tests. [] minor clang-format cleanup.
Thanks Jeff
Cc: gitster@pobox.comCc: peff@peff.netCc: avarab@gmail.com
Derrick Stolee (1): trace2:data: pack-objects: add trace2 regions
Jeff Hostetler (14): trace2: Documentation/technical/api-trace2.txt trace2: create new combined trace facility trace2: collect Windows-specific process information trace2:data: add trace2 regions to wt-status trace2:data: add editor/pager child classification trace2:data: add trace2 sub-process classification trace2:data: add trace2 transport child classification trace2:data: add trace2 hook classification trace2:data: add trace2 instrumentation to index read/write trace2:data: add subverb to checkout command trace2:data: add subverb to reset command trace2:data: add subverb for rebase trace2: t/helper/test-trace2, t0210.sh, t0211.sh, t0212.sh trace2: add for_each macros to clang-format
.clang-format | 2 +- Documentation/technical/api-trace2.txt | 1350 ++++++++++++++++++++++ Makefile | 15 +- builtin/am.c | 1 + builtin/checkout.c | 7 + builtin/pack-objects.c | 16 +- builtin/rebase.c | 17 + builtin/receive-pack.c | 4 + builtin/reset.c | 6 + builtin/submodule--helper.c | 9 +- builtin/worktree.c | 1 + cache.h | 1 + common-main.c | 13 +- compat/mingw.c | 11 +- compat/mingw.h | 3 +- compat/win32/trace2_win32_process_info.c | 147 +++ config.c | 2 + config.mak.uname | 2 + connect.c | 3 + editor.c | 1 + exec-cmd.c | 2 + git-compat-util.h | 7 + git.c | 65 ++ pager.c | 1 + read-cache.c | 51 +- remote-curl.c | 7 + repository.c | 2 + repository.h | 3 + run-command.c | 59 +- run-command.h | 13 +- sequencer.c | 2 + sh-i18n--envsubst.c | 3 + sub-process.c | 1 + submodule.c | 11 +- t/helper/test-parse-options.c | 3 + t/helper/test-tool.c | 4 + t/helper/test-tool.h | 1 + t/helper/test-trace2.c | 273 +++++ t/t0001-init.sh | 1 + t/t0210-trace2-normal.sh | 135 +++ t/t0210/scrub_normal.perl | 48 + t/t0211-trace2-perf.sh | 153 +++ t/t0211/scrub_perf.perl | 76 ++ t/t0212-trace2-event.sh | 236 ++++ t/t0212/parse_events.perl | 251 ++++ trace2.c | 761 ++++++++++++ trace2.h | 385 ++++++ trace2/tr2_cfg.c | 90 ++ trace2/tr2_cfg.h | 19 + trace2/tr2_cmd_name.c | 30 + trace2/tr2_cmd_name.h | 24 + trace2/tr2_dst.c | 252 ++++ trace2/tr2_dst.h | 36 + trace2/tr2_sid.c | 67 ++ trace2/tr2_sid.h | 18 + trace2/tr2_tbuf.c | 32 + trace2/tr2_tbuf.h | 23 + trace2/tr2_tgt.h | 133 +++ trace2/tr2_tgt_event.c | 588 ++++++++++ trace2/tr2_tgt_normal.c | 323 ++++++ trace2/tr2_tgt_perf.c | 534 +++++++++ trace2/tr2_tls.c | 164 +++ trace2/tr2_tls.h | 97 ++ transport-helper.c | 2 + transport.c | 1 + usage.c | 31 + wt-status.c | 24 +- 67 files changed, 6630 insertions(+), 23 deletions(-) create mode 100644 Documentation/technical/api-trace2.txt create mode 100644 compat/win32/trace2_win32_process_info.c create mode 100644 t/helper/test-trace2.c create mode 100755 t/t0210-trace2-normal.sh create mode 100644 t/t0210/scrub_normal.perl create mode 100755 t/t0211-trace2-perf.sh create mode 100644 t/t0211/scrub_perf.perl create mode 100755 t/t0212-trace2-event.sh create mode 100644 t/t0212/parse_events.perl create mode 100644 trace2.c create mode 100644 trace2.h create mode 100644 trace2/tr2_cfg.c create mode 100644 trace2/tr2_cfg.h create mode 100644 trace2/tr2_cmd_name.c create mode 100644 trace2/tr2_cmd_name.h create mode 100644 trace2/tr2_dst.c create mode 100644 trace2/tr2_dst.h create mode 100644 trace2/tr2_sid.c create mode 100644 trace2/tr2_sid.h create mode 100644 trace2/tr2_tbuf.c create mode 100644 trace2/tr2_tbuf.h create mode 100644 trace2/tr2_tgt.h create mode 100644 trace2/tr2_tgt_event.c create mode 100644 trace2/tr2_tgt_normal.c create mode 100644 trace2/tr2_tgt_perf.c create mode 100644 trace2/tr2_tls.c create mode 100644 trace2/tr2_tls.h
base-commit: b5101f929789889c2e536d915698f58d5c5c6b7a Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-108%2Fjeffhostetler%2Fcore-trace2-2019-v0-v7 Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-108/jeffhostetler/core-trace2-2019-v0-v7 Pull-Request: https://github.com/gitgitgadget/git/pull/108
Range-diff vs v6:
1: 4c006f4995 ! 1: 8ac6acf88d trace2: Documentation/technical/api-trace2.txt
@@ -122,10 +122,13 @@
+
+ Enables the target, opens and writes to the file in append mode.
+
-+`af_unix:<absolute-pathname>`::
++`af_unix:[<socket_type>:]<absolute-pathname>`::
+
+ Enables the target, opens and writes to a Unix Domain Socket
+ (on platforms that support them).
+++
++Socket type can be either `stream` or `dgram`. If the socket type is
++omitted, Git will try both.
+
+== Trace2 API
+
2: 6bad326bbd ! 2: 90e4e6af93 trace2: create new combined trace facility
@@ -947,8 +947,7 @@
+
+ for_each_wanted_builtin (j, tgt_j)
+ if (tgt_j->pfn_command_name_fl)
-+ tgt_j->pfn_command_name_fl(file, line, name,
-+ hierarchy);
++ tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
+}
+
+void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
@@ -2080,37 +2079,103 @@
+
+#ifndef NO_UNIX_SOCKETS
+#define PREFIX_AF_UNIX "af_unix:"
-+#define PREFIX_AF_UNIX_LEN (8)
++#define PREFIX_AF_UNIX_STREAM "af_unix:stream:"
++#define PREFIX_AF_UNIX_DGRAM "af_unix:dgram:"
++
++static int tr2_dst_try_uds_connect(const char *path, int sock_type, int *out_fd)
++{
++ int fd;
++ struct sockaddr_un sa;
++
++ fd = socket(AF_UNIX, sock_type, 0);
++ if (fd == -1)
++ return errno;
++
++ sa.sun_family = AF_UNIX;
++ strlcpy(sa.sun_path, path, sizeof(sa.sun_path));
++
++ if (connect(fd, (struct sockaddr *)&sa, sizeof(sa)) == -1) {
++ int e = errno;
++ close(fd);
++ return e;
++ }
++
++ *out_fd = fd;
++ return 0;
++}
++
++#define TR2_DST_UDS_TRY_STREAM (1 << 0)
++#define TR2_DST_UDS_TRY_DGRAM (1 << 1)
+
+static int tr2_dst_try_unix_domain_socket(struct tr2_dst *dst,
+ const char *tgt_value)
+{
++ unsigned int uds_try = 0;
+ int fd;
-+ struct sockaddr_un sa;
-+ const char *path = tgt_value + PREFIX_AF_UNIX_LEN;
-+ int path_len = strlen(path);
++ int e;
++ const char *path = NULL;
++
++ /*
++ * Allow "af_unix:[<type>:]<absolute_path>"
++ *
++ * Trace2 always writes complete individual messages (without
++ * chunking), so we can talk to either DGRAM or STREAM type sockets.
++ *
++ * Allow the user to explicitly request the socket type.
++ *
++ * If they omit the socket type, try one and then the other.
++ */
+
-+ if (!is_absolute_path(path) || path_len >= sizeof(sa.sun_path)) {
++ if (skip_prefix(tgt_value, PREFIX_AF_UNIX_STREAM, &path))
++ uds_try |= TR2_DST_UDS_TRY_STREAM;
++
++ else if (skip_prefix(tgt_value, PREFIX_AF_UNIX_DGRAM, &path))
++ uds_try |= TR2_DST_UDS_TRY_DGRAM;
++
++ else if (skip_prefix(tgt_value, PREFIX_AF_UNIX, &path))
++ uds_try |= TR2_DST_UDS_TRY_STREAM | TR2_DST_UDS_TRY_DGRAM;
++
++ if (!path || !*path) {
+ if (tr2_dst_want_warning())
-+ warning("trace2: invalid AF_UNIX path '%s' for '%s' tracing",
-+ path, dst->env_var_name);
++ warning("trace2: invalid AF_UNIX value '%s' for '%s' tracing",
++ tgt_value, dst->env_var_name);
+
+ tr2_dst_trace_disable(dst);
+ return 0;
+ }
+
-+ sa.sun_family = AF_UNIX;
-+ strlcpy(sa.sun_path, path, sizeof(sa.sun_path));
-+ if ((fd = socket(AF_UNIX, SOCK_STREAM, 0)) == -1 ||
-+ connect(fd, (struct sockaddr *)&sa, sizeof(sa)) == -1) {
++ if (!is_absolute_path(path) ||
++ strlen(path) >= sizeof(((struct sockaddr_un *)0)->sun_path)) {
+ if (tr2_dst_want_warning())
-+ warning("trace2: could not connect to socket '%s' for '%s' tracing: %s",
-+ path, dst->env_var_name, strerror(errno));
++ warning("trace2: invalid AF_UNIX path '%s' for '%s' tracing",
++ path, dst->env_var_name);
+
+ tr2_dst_trace_disable(dst);
+ return 0;
+ }
+
++ if (uds_try & TR2_DST_UDS_TRY_STREAM) {
++ e = tr2_dst_try_uds_connect(path, SOCK_STREAM, &fd);
++ if (!e)
++ goto connected;
++ if (e != EPROTOTYPE)
++ goto error;
++ }
++ if (uds_try & TR2_DST_UDS_TRY_DGRAM) {
++ e = tr2_dst_try_uds_connect(path, SOCK_DGRAM, &fd);
++ if (!e)
++ goto connected;
++ }
++
++error:
++ if (tr2_dst_want_warning())
++ warning("trace2: could not connect to socket '%s' for '%s' tracing: %s",
++ path, dst->env_var_name, strerror(e));
++
++ tr2_dst_trace_disable(dst);
++ return 0;
++
++connected:
+ dst->fd = fd;
+ dst->need_close = 1;
+ dst->initialized = 1;
@@ -2124,19 +2189,8 @@
+{
+ struct strbuf buf = STRBUF_INIT;
+
-+ strbuf_addf(&buf, "trace2: unknown trace value for '%s': '%s'",
++ strbuf_addf(&buf, "trace2: unknown value for '%s': '%s'",
+ dst->env_var_name, tgt_value);
-+ strbuf_addstr(
-+ &buf,
-+ "\n If you want to trace into a file, then please set it"
-+ "\n to an absolute pathname.");
-+#ifndef NO_UNIX_SOCKETS
-+ strbuf_addstr(
-+ &buf,
-+ "\n If you want to trace to a unix domain socket, prefix"
-+ "\n the absolute pathname with \"af_unix:\".");
-+#endif
-+
+ warning("%s", buf.buf);
+
+ strbuf_release(&buf);
@@ -2174,7 +2228,7 @@
+ return tr2_dst_try_path(dst, tgt_value);
+
+#ifndef NO_UNIX_SOCKETS
-+ if (!strncmp(tgt_value, PREFIX_AF_UNIX, PREFIX_AF_UNIX_LEN))
++ if (starts_with(tgt_value, PREFIX_AF_UNIX))
+ return tr2_dst_try_unix_domain_socket(dst, tgt_value);
+#endif
+
@@ -2817,8 +2871,7 @@
+ jw_release(&jw);
+}
+
-+static void fn_command_name_fl(const char *file, int line,
-+ const char *name,
++static void fn_command_name_fl(const char *file, int line, const char *name,
+ const char *hierarchy)
+{
+ const char *event_name = "cmd_name";
@@ -3327,8 +3380,7 @@
+ strbuf_release(&buf_payload);
+}
+
-+static void fn_command_name_fl(const char *file, int line,
-+ const char *name,
++static void fn_command_name_fl(const char *file, int line, const char *name,
+ const char *hierarchy)
+{
+ struct strbuf buf_payload = STRBUF_INIT;
@@ -3747,8 +3799,7 @@
+ strbuf_release(&buf_payload);
+}
+
-+static void fn_command_name_fl(const char *file, int line,
-+ const char *name,
++static void fn_command_name_fl(const char *file, int line, const char *name,
+ const char *hierarchy)
+{
+ const char *event_name = "cmd_name";
3: 12de7e42de ! 3: 50f689dc95 trace2: collect Windows-specific process information
@@ -35,6 +35,12 @@
+#include <tlHelp32.h>
+
+/*
++ * An arbitrarily chosen value to limit the size of the ancestor
++ * array built in git_processes().
++ */
++#define NR_PIDS_LIMIT 10
++
++/*
+ * Find the process data for the given PID in the given snapshot
+ * and update the PROCESSENTRY32 data.
+ */
@@ -52,7 +58,7 @@
+}
+
+/*
-+ * Accumulate JSON array:
++ * Accumulate JSON array of our parent processes:
+ * [
+ * exe-name-parent,
+ * exe-name-grand-parent,
@@ -64,21 +70,61 @@
+ * and GetModuleFileNameEx() or QueryfullProcessImageName()
+ * and that seems rather expensive (on top of the cost of
+ * getting the snapshot).
++ *
++ * Note: we compute the set of parent processes by walking the PPID
++ * link in each visited PROCESSENTRY32 record. This search
++ * stops when an ancestor process is not found in the snapshot
++ * (because it exited before the current or intermediate parent
++ * process exited).
++ *
++ * This search may compute an incorrect result if the PPID link
++ * refers to the PID of an exited parent and that PID has been
++ * recycled and given to a new unrelated process.
++ *
++ * Worse, it is possible for a child or descendant of the
++ * current process to be given the recycled PID and cause a
++ * PPID-cycle. This would cause an infinite loop building our
++ * parent process array.
++ *
++ * Note: for completeness, the "System Idle" process has PID=0 and
++ * PPID=0 and could cause another PPID-cycle. We don't expect
++ * Git to be a descendant of the idle process, but because of
++ * PID recycling, it might be possible to get a PPID link value
++ * of 0. This too would cause an infinite loop.
++ *
++ * Therefore, we keep an array of the visited PPIDs to guard against
++ * cycles.
++ *
++ * We use a fixed-size array rather than ALLOC_GROW to keep things
++ * simple and avoid the alloc/realloc overhead. It is OK if we
++ * truncate the search and return a partial answer.
+ */
+static void get_processes(struct json_writer *jw, HANDLE hSnapshot)
+{
+ PROCESSENTRY32 pe32;
+ DWORD pid;
++ DWORD pid_list[NR_PIDS_LIMIT];
++ int k, nr_pids = 0;
+
+ pid = GetCurrentProcessId();
-+
-+ /* We only want parent processes, so skip self. */
-+ if (!find_pid(pid, hSnapshot, &pe32))
-+ return;
-+ pid = pe32.th32ParentProcessID;
-+
+ while (find_pid(pid, hSnapshot, &pe32)) {
-+ jw_array_string(jw, pe32.szExeFile);
++ /* Only report parents. Omit self from the JSON output. */
++ if (nr_pids)
++ jw_array_string(jw, pe32.szExeFile);
++
++ /* Check for cycle in snapshot. (Yes, it happened.) */
++ for (k = 0; k < nr_pids; k++)
++ if (pid == pid_list[k]) {
++ jw_array_string(jw, "(cycle)");
++ return;
++ }
++
++ if (nr_pids == NR_PIDS_LIMIT) {
++ jw_array_string(jw, "(truncated)");
++ return;
++ }
++
++ pid_list[nr_pids++] = pid;
+
+ pid = pe32.th32ParentProcessID;
+ }
4: 5835edbd01 = 4: 40411100c3 trace2:data: add trace2 regions to wt-status
5: 99d13ef478 = 5: 18ff59d6fe trace2:data: add editor/pager child classification
6: d7ce85b702 = 6: ec7d7cd4c7 trace2:data: add trace2 sub-process classification
7: b70c289903 = 7: 485a4f2a68 trace2:data: add trace2 transport child classification
8: 2a0da88579 = 8: 18659d61da trace2:data: add trace2 hook classification
9: bca6a7f0d6 = 9: 08be5aadbe trace2:data: add trace2 instrumentation to index read/write
10: 68269ee060 = 10: 4e679241fc trace2:data: pack-objects: add trace2 regions
11: 0191283fff = 11: 2a5aa3a8dc trace2:data: add subverb to checkout command
12: 24d8d8d768 = 12: ebaa9b1d80 trace2:data: add subverb to reset command
13: 90cec071cf = 13: 3e6fee40b0 trace2:data: add subverb for rebase
14: b9f0c6fd66 ! 14: 398edb7738 trace2: t/helper/test-trace2, t0210.sh, t0211.sh, t0212.sh
@@ -767,6 +767,8 @@
+test_description='test trace2 facility'
+. ./test-lib.sh
+
++perl -MJSON::PP -e 0 >/dev/null 2>&1 && test_set_prereq JSON_PP
++
+# Add t/helper directory to PATH so that we can use a relative
+# path to run nested instances of test-tool.exe (see 004child).
+# This helps with HEREDOC comparisons later.
@@ -802,7 +804,7 @@
+#
+# To the above, add multiple 'error <msg>' events
+
-+test_expect_success 'event stream, error event' '
++test_expect_success JSON_PP 'event stream, error event' '
+ test_when_finished "rm trace.event actual expect" &&
+ GIT_TR2_EVENT="$(pwd)/trace.event" test-tool trace2 003error "hello world" "this is a test" &&
+ perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
@@ -839,7 +841,7 @@
+# P2: |--- TT trace2 004child
+# P3: |--- TT trace2 001return 0
+
-+test_expect_success 'event stream, return code 0' '
++test_expect_success JSON_PP 'event stream, return code 0' '
+ test_when_finished "rm trace.event actual expect" &&
+ GIT_TR2_EVENT="$(pwd)/trace.event" test-tool trace2 004child test-tool trace2 004child test-tool trace2 001return 0 &&
+ perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
@@ -926,7 +928,7 @@
+
+# Test listing of all "interesting" config settings.
+
-+test_expect_success 'event stream, list config' '
++test_expect_success JSON_PP 'event stream, list config' '
+ test_when_finished "rm trace.event actual expect" &&
+ git config --local t0212.abc 1 &&
+ git config --local t0212.def "hello world" &&
@@ -961,7 +963,7 @@
+ test_cmp expect actual
+'
+
-+test_expect_success 'basic trace2_data' '
++test_expect_success JSON_PP 'basic trace2_data' '
+ test_when_finished "rm trace.event actual expect" &&
+ GIT_TR2_EVENT="$(pwd)/trace.event" test-tool trace2 006data test_category k1 v1 test_category k2 v2 &&
+ perl "$TEST_DIRECTORY/t0212/parse_events.perl" <trace.event >actual &&
15: 93a25d09a1 = 15: 662201f49e trace2: add for_each macros to clang-format-- gitgitgadget