pkt-line: support tracing verbatim pack contents

When debugging the pack protocol, it is sometimes useful to store the verbatim pack that we sent or received on the wire. Looking at the on-disk result is often not helpful for a few reasons: 1. If the operation is a clone, we destroy the repo on failure, leaving nothing on disk. 2. If the pack is small, we unpack it immediately, and the full pack never hits the disk. 3. If we feed the pack to "index-pack --fix-thin", the resulting pack has the extra delta bases added to it. We already have a GIT_TRACE_PACKET mechanism for tracing packets. Let's extend it with GIT_TRACE_PACKFILE to dump the verbatim packfile. There are a few other positive fallouts that come from rearranging this code: - We currently disable the packet trace after seeing the PACK header, even though we may get human-readable lines on other sidebands; now we include them in the trace. - We currently try to print "PACK ..." in the trace to indicate that the packfile has started. But because we disable packet tracing, we never printed this line. We will now do so. Signed-off-by: Jeff King <peff@peff.net> Signed-off-by: Junio C Hamano <gitster@pobox.com>

Jeff King committed Jun 16, 2015 at 13:23 UTC 323598387d900263c4980b43b8a96c43cdd7b6c7
5 files changed +71 -16
Documentation/git.txt
+12 -1
@@ -1000,9 +1000,20 @@ Unsetting the variable, or setting it to empty, "0" or
1000 Enables trace messages for all packets coming in or out of a
1001 given program. This can help with debugging object negotiation
1002 or other protocol issues. Tracing is turned off at a packet
1003 - starting with "PACK".
1003 + starting with "PACK" (but see 'GIT_TRACE_PACKFILE' below).
1004 See 'GIT_TRACE' for available trace output options.
1005
1006 +'GIT_TRACE_PACKFILE'::
1007 + Enables tracing of packfiles sent or received by a
1008 + given program. Unlike other trace output, this trace is
1009 + verbatim: no headers, and no quoting of binary data. You almost
1010 + certainly want to direct into a file (e.g.,
1011 + `GIT_TRACE_PACKFILE=/tmp/my.pack`) rather than displaying it on
1012 + the terminal or mixing it with other trace output.
1013 ++
1014 +Note that this is currently only implemented for the client side
1015 +of clones and fetches.
1016 +
1017 'GIT_TRACE_PERFORMANCE'::
1018 Enables performance related trace messages, e.g. total execution
1019 time of each Git command.
pkt-line.c
+44 -15
@@ -4,16 +4,51 @@
4 char packet_buffer[LARGE_PACKET_MAX];
5 static const char *packet_trace_prefix = "git";
6 static struct trace_key trace_packet = TRACE_KEY_INIT(PACKET);
7 +static struct trace_key trace_pack = TRACE_KEY_INIT(PACKFILE);
8
9 void packet_trace_identity(const char *prog)
10 {
11 packet_trace_prefix = xstrdup(prog);
12 }
13
14 +static int packet_trace_pack(const char *buf, unsigned int len, int sideband)
15 +{
16 + if (!sideband) {
17 + trace_verbatim(&trace_pack, buf, len);
18 + return 1;
19 + } else if (len && *buf == '\1') {
20 + trace_verbatim(&trace_pack, buf + 1, len - 1);
21 + return 1;
22 + } else {
23 + /* it's another non-pack sideband */
24 + return 0;
25 + }
26 +}
27 +
28 static void packet_trace(const char *buf, unsigned int len, int write)
29 {
30 int i;
31 struct strbuf out;
32 + static int in_pack, sideband;
33 +
34 + if (!trace_want(&trace_packet) && !trace_want(&trace_pack))
35 + return;
36 +
37 + if (in_pack) {
38 + if (packet_trace_pack(buf, len, sideband))
39 + return;
40 + } else if (starts_with(buf, "PACK") || starts_with(buf, "\1PACK")) {
41 + in_pack = 1;
42 + sideband = *buf == '\1';
43 + packet_trace_pack(buf, len, sideband);
44 +
45 + /*
46 + * Make a note in the human-readable trace that the pack data
47 + * started.
48 + */
49 + buf = "PACK ...";
50 + len = strlen(buf);
51 + }
52
53 if (!trace_want(&trace_packet))
54 return;
@@ -24,21 +59,15 @@ static void packet_trace(const char *buf, unsigned int len, int write)
59 strbuf_addf(&out, "packet: %12s%c ",
60 packet_trace_prefix, write ? '>' : '<');
61
27 - if (starts_with(buf, "PACK") || starts_with(buf, "\1PACK")) {
28 - strbuf_addstr(&out, "PACK ...");
29 - trace_disable(&trace_packet);
30 - }
31 - else {
32 - /* XXX we should really handle printable utf8 */
33 - for (i = 0; i < len; i++) {
34 - /* suppress newlines */
35 - if (buf[i] == '\n')
36 - continue;
37 - if (buf[i] >= 0x20 && buf[i] <= 0x7e)
38 - strbuf_addch(&out, buf[i]);
39 - else
40 - strbuf_addf(&out, "\\%o", buf[i]);
41 - }
62 + /* XXX we should really handle printable utf8 */
63 + for (i = 0; i < len; i++) {
64 + /* suppress newlines */
65 + if (buf[i] == '\n')
66 + continue;
67 + if (buf[i] >= 0x20 && buf[i] <= 0x7e)
68 + strbuf_addch(&out, buf[i]);
69 + else
70 + strbuf_addf(&out, "\\%o", buf[i]);
71 }
72
73 strbuf_addch(&out, '\n');
t/t5601-clone.sh
+7
@@ -496,4 +496,11 @@ test_expect_success 'shallow clone locally' '
496 ( cd ddsstt && git fsck )
497 '
498
499 +test_expect_success 'GIT_TRACE_PACKFILE produces a usable pack' '
500 + rm -rf dst.git &&
501 + GIT_TRACE_PACKFILE=$PWD/tmp.pack git clone --no-local --bare src dst.git &&
502 + git init --bare replay.git &&
503 + git -C replay.git index-pack -v --stdin <tmp.pack
504 +'
505 +
506 test_done
trace.c
+7
@@ -120,6 +120,13 @@ static int prepare_trace_line(const char *file, int line,
120 return 1;
121 }
122
123 +void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)
124 +{
125 + if (!trace_want(key))
126 + return;
127 + write_or_whine_pipe(get_trace_fd(key), buf, len, err_msg);
128 +}
129 +
130 static void print_trace_line(struct trace_key *key, struct strbuf *buf)
131 {
132 strbuf_complete_line(buf);
trace.h
+1
@@ -18,6 +18,7 @@ extern int trace_want(struct trace_key *key);
18 extern void trace_disable(struct trace_key *key);
19 extern uint64_t getnanotime(void);
20 extern void trace_command_performance(const char **argv);
21 +extern void trace_verbatim(struct trace_key *key, const void *buf, unsigned len);
22
23 #ifndef HAVE_VARIADIC_MACROS
24