trace: add infrastructure to augment trace output with additional info

To be able to add a common prefix or suffix to all trace output (e.g. a timestamp or file:line of the caller), factor out common setup and cleanup tasks of the trace* functions. When adding a common prefix, it makes sense that the output of each trace call starts on a new line. Add '\n' in case the caller forgot. Note that this explicitly limits trace output to line-by-line, it is no longer possible to trace-print just part of a line. Until now, this was just an implicit assumption (trace-printing part of a line worked, but messed up the trace file if multiple threads or processes were involved). Thread-safety / inter-process-safety is also the reason why we need to do the prefixing and suffixing in memory rather than issuing multiple write() calls. Write_or_whine_pipe() / xwrite() is atomic unless the size exceeds MAX_IO_SIZE (8MB, see wrapper.c). In case of trace_strbuf, this costs an additional string copy (which should be irrelevant for performance in light of actual file IO). While we're at it, rename trace_strbuf's 'buf' argument, which suggests that the function is modifying the buffer. Trace_strbuf() currently is the only trace API that can print arbitrary binary data (without barfing on '%' or stopping at '\0'), so 'data' seems more appropriate. Signed-off-by: Karsten Blees <blees@dcon.de> Signed-off-by: Junio C Hamano <gitster@pobox.com>

Karsten Blees committed Jul 12, 2014 at 02:02 UTC c69dfd24db21be54ec5a17bb3e07c81f4e96861a
2 files changed +34 -15
trace.c
+33 -14
@@ -85,17 +85,37 @@ void trace_disable(struct trace_key *key)
85 static const char err_msg[] = "Could not trace into fd given by "
86 "GIT_TRACE environment variable";
87
88 +static int prepare_trace_line(struct trace_key *key, struct strbuf *buf)
89 +{
90 + if (!trace_want(key))
91 + return 0;
92 +
93 + set_try_to_free_routine(NULL); /* is never reset */
94 +
95 + /* add line prefix here */
96 +
97 + return 1;
98 +}
99 +
100 +static void print_trace_line(struct trace_key *key, struct strbuf *buf)
101 +{
102 + /* append newline if missing */
103 + if (buf->len && buf->buf[buf->len - 1] != '\n')
104 + strbuf_addch(buf, '\n');
105 +
106 + write_or_whine_pipe(get_trace_fd(key), buf->buf, buf->len, err_msg);
107 + strbuf_release(buf);
108 +}
109 +
110 static void trace_vprintf(struct trace_key *key, const char *format, va_list ap)
111 {
112 struct strbuf buf = STRBUF_INIT;
113
92 - if (!trace_want(key))
114 + if (!prepare_trace_line(key, &buf))
115 return;
116
95 - set_try_to_free_routine(NULL); /* is never reset */
117 strbuf_vaddf(&buf, format, ap);
97 - trace_strbuf(key, &buf);
98 - strbuf_release(&buf);
118 + print_trace_line(key, &buf);
119 }
120
121 void trace_printf_key(struct trace_key *key, const char *format, ...)
@@ -114,32 +134,31 @@ void trace_printf(const char *format, ...)
134 va_end(ap);
135 }
136
117 -void trace_strbuf(struct trace_key *key, const struct strbuf *buf)
137 +void trace_strbuf(struct trace_key *key, const struct strbuf *data)
138 {
119 - int fd = get_trace_fd(key);
120 - if (!fd)
139 + struct strbuf buf = STRBUF_INIT;
140 +
141 + if (!prepare_trace_line(key, &buf))
142 return;
143
123 - write_or_whine_pipe(fd, buf->buf, buf->len, err_msg);
144 + strbuf_addbuf(&buf, data);
145 + print_trace_line(key, &buf);
146 }
147
148 void trace_argv_printf(const char **argv, const char *format, ...)
149 {
150 struct strbuf buf = STRBUF_INIT;
151 va_list ap;
130 - int fd = get_trace_fd(NULL);
131 - if (!fd)
152 +
153 + if (!prepare_trace_line(NULL, &buf))
154 return;
155
134 - set_try_to_free_routine(NULL); /* is never reset */
156 va_start(ap, format);
157 strbuf_vaddf(&buf, format, ap);
158 va_end(ap);
159
160 sq_quote_argv(&buf, argv, 0);
140 - strbuf_addch(&buf, '\n');
141 - write_or_whine_pipe(fd, buf.buf, buf.len, err_msg);
142 - strbuf_release(&buf);
161 + print_trace_line(NULL, &buf);
162 }
163
164 static const char *quote_crnl(const char *path)
trace.h
+1 -1
@@ -22,6 +22,6 @@ extern int trace_want(struct trace_key *key);
22 extern void trace_disable(struct trace_key *key);
23 __attribute__((format (printf, 2, 3)))
24 extern void trace_printf_key(struct trace_key *key, const char *format, ...);
25 -extern void trace_strbuf(struct trace_key *key, const struct strbuf *buf);
25 +extern void trace_strbuf(struct trace_key *key, const struct strbuf *data);
26
27 #endif /* TRACE_H */