trace: add 'file:line' to all trace output

This is useful to see where trace output came from. Add 'const char *file, int line' parameters to the printing functions and rename them to *_fl. Add trace_printf* and trace_strbuf macros resolving to the *_fl functions and let the preprocessor fill in __FILE__ and __LINE__. As the trace_printf* functions take a variable number of arguments, this requires variadic macros (i.e. '#define foo(...) foo_impl(__VA_ARGS__)'. Though part of C99, it is unclear whether older compilers support this. Thus keep the old functions and only enable variadic macros for GNUC and MSVC 2005+ (_MSC_VER 1400). This has the nice side effect that the old C-style declarations serve as documentation how the macros are to be used. Print 'file:line ' as prefix to each trace line. Align the remaining trace output at column 40 to accommodate 18 char file names + 4 digit line number (currently there are 30 *.c files of length 18 and just 11 of 19). Trace output from longer source files (e.g. builtin/receive-pack.c) will not be aligned. 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:05 UTC e05bed960d3bf3bcfd0f27ab882df3da93e118ed
3 files changed +126 -12
git-compat-util.h
+4
@@ -704,6 +704,10 @@ void git_qsort(void *base, size_t nmemb, size_t size,
704 #endif
705 #endif
706
707 +#if defined(__GNUC__) || (_MSC_VER >= 1400)
708 +#define HAVE_VARIADIC_MACROS 1
709 +#endif
710 +
711 /*
712 * Preserves errno, prints a message, but gives no warning for ENOENT.
713 * Always returns the return value of unlink(2).
trace.c
+60 -12
@@ -85,7 +85,8 @@ 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)
88 +static int prepare_trace_line(const char *file, int line,
89 + struct trace_key *key, struct strbuf *buf)
90 {
91 static struct trace_key trace_bare = TRACE_KEY_INIT(BARE);
92 struct timeval tv;
@@ -108,6 +109,14 @@ static int prepare_trace_line(struct trace_key *key, struct strbuf *buf)
109 strbuf_addf(buf, "%02d:%02d:%02d.%06ld ", tm.tm_hour, tm.tm_min,
110 tm.tm_sec, (long) tv.tv_usec);
111
112 +#ifdef HAVE_VARIADIC_MACROS
113 + /* print file:line */
114 + strbuf_addf(buf, "%s:%d ", file, line);
115 + /* align trace output (column 40 catches most files names in git) */
116 + while (buf->len < 40)
117 + strbuf_addch(buf, ' ');
118 +#endif
119 +
120 return 1;
121 }
122
@@ -121,49 +130,52 @@ static void print_trace_line(struct trace_key *key, struct strbuf *buf)
130 strbuf_release(buf);
131 }
132
124 -static void trace_vprintf(struct trace_key *key, const char *format, va_list ap)
133 +static void trace_vprintf_fl(const char *file, int line, struct trace_key *key,
134 + const char *format, va_list ap)
135 {
136 struct strbuf buf = STRBUF_INIT;
137
128 - if (!prepare_trace_line(key, &buf))
138 + if (!prepare_trace_line(file, line, key, &buf))
139 return;
140
141 strbuf_vaddf(&buf, format, ap);
142 print_trace_line(key, &buf);
143 }
144
135 -void trace_argv_printf(const char **argv, const char *format, ...)
145 +static void trace_argv_vprintf_fl(const char *file, int line,
146 + const char **argv, const char *format,
147 + va_list ap)
148 {
149 struct strbuf buf = STRBUF_INIT;
138 - va_list ap;
150
140 - if (!prepare_trace_line(NULL, &buf))
151 + if (!prepare_trace_line(file, line, NULL, &buf))
152 return;
153
143 - va_start(ap, format);
154 strbuf_vaddf(&buf, format, ap);
145 - va_end(ap);
155
156 sq_quote_argv(&buf, argv, 0);
157 print_trace_line(NULL, &buf);
158 }
159
151 -void trace_strbuf(struct trace_key *key, const struct strbuf *data)
160 +void trace_strbuf_fl(const char *file, int line, struct trace_key *key,
161 + const struct strbuf *data)
162 {
163 struct strbuf buf = STRBUF_INIT;
164
155 - if (!prepare_trace_line(key, &buf))
165 + if (!prepare_trace_line(file, line, key, &buf))
166 return;
167
168 strbuf_addbuf(&buf, data);
169 print_trace_line(key, &buf);
170 }
171
172 +#ifndef HAVE_VARIADIC_MACROS
173 +
174 void trace_printf(const char *format, ...)
175 {
176 va_list ap;
177 va_start(ap, format);
166 - trace_vprintf(NULL, format, ap);
178 + trace_vprintf_fl(NULL, 0, NULL, format, ap);
179 va_end(ap);
180 }
181
@@ -171,10 +183,46 @@ void trace_printf_key(struct trace_key *key, const char *format, ...)
183 {
184 va_list ap;
185 va_start(ap, format);
174 - trace_vprintf(key, format, ap);
186 + trace_vprintf_fl(NULL, 0, key, format, ap);
187 + va_end(ap);
188 +}
189 +
190 +void trace_argv_printf(const char **argv, const char *format, ...)
191 +{
192 + va_list ap;
193 + va_start(ap, format);
194 + trace_argv_vprintf_fl(NULL, 0, argv, format, ap);
195 va_end(ap);
196 }
197
198 +void trace_strbuf(const char *key, const struct strbuf *data)
199 +{
200 + trace_strbuf_fl(NULL, 0, key, data);
201 +}
202 +
203 +#else
204 +
205 +void trace_printf_key_fl(const char *file, int line, struct trace_key *key,
206 + const char *format, ...)
207 +{
208 + va_list ap;
209 + va_start(ap, format);
210 + trace_vprintf_fl(file, line, key, format, ap);
211 + va_end(ap);
212 +}
213 +
214 +void trace_argv_printf_fl(const char *file, int line, const char **argv,
215 + const char *format, ...)
216 +{
217 + va_list ap;
218 + va_start(ap, format);
219 + trace_argv_vprintf_fl(file, line, argv, format, ap);
220 + va_end(ap);
221 +}
222 +
223 +#endif /* HAVE_VARIADIC_MACROS */
224 +
225 +
226 static const char *quote_crnl(const char *path)
227 {
228 static char new_path[PATH_MAX];
trace.h
+62
@@ -17,6 +17,8 @@ extern void trace_repo_setup(const char *prefix);
17 extern int trace_want(struct trace_key *key);
18 extern void trace_disable(struct trace_key *key);
19
20 +#ifndef HAVE_VARIADIC_MACROS
21 +
22 __attribute__((format (printf, 1, 2)))
23 extern void trace_printf(const char *format, ...);
24
@@ -28,4 +30,64 @@ extern void trace_argv_printf(const char **argv, const char *format, ...);
30
31 extern void trace_strbuf(struct trace_key *key, const struct strbuf *data);
32
33 +#else
34 +
35 +/*
36 + * Macros to add file:line - see above for C-style declarations of how these
37 + * should be used.
38 + */
39 +
40 +/*
41 + * TRACE_CONTEXT may be set to __FUNCTION__ if the compiler supports it. The
42 + * default is __FILE__, as it is consistent with assert(), and static function
43 + * names are not necessarily unique.
44 + *
45 + * __FILE__ ":" __FUNCTION__ doesn't work with GNUC, as __FILE__ is supplied
46 + * by the preprocessor as a string literal, and __FUNCTION__ is filled in by
47 + * the compiler as a string constant.
48 + */
49 +#ifndef TRACE_CONTEXT
50 +# define TRACE_CONTEXT __FILE__
51 +#endif
52 +
53 +/*
54 + * Note: with C99 variadic macros, __VA_ARGS__ must include the last fixed
55 + * parameter ('format' in this case). Otherwise, a call without variable
56 + * arguments will have a surplus ','. E.g.:
57 + *
58 + * #define foo(format, ...) bar(format, __VA_ARGS__)
59 + * foo("test");
60 + *
61 + * will expand to
62 + *
63 + * bar("test",);
64 + *
65 + * which is invalid (note the ',)'). With GNUC, '##__VA_ARGS__' drops the
66 + * comma, but this is non-standard.
67 + */
68 +
69 +#define trace_printf(...) \
70 + trace_printf_key_fl(TRACE_CONTEXT, __LINE__, NULL, __VA_ARGS__)
71 +
72 +#define trace_printf_key(key, ...) \
73 + trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, __VA_ARGS__)
74 +
75 +#define trace_argv_printf(argv, ...) \
76 + trace_argv_printf_fl(TRACE_CONTEXT, __LINE__, argv, __VA_ARGS__)
77 +
78 +#define trace_strbuf(key, data) \
79 + trace_strbuf_fl(TRACE_CONTEXT, __LINE__, key, data)
80 +
81 +/* backend functions, use non-*fl macros instead */
82 +__attribute__((format (printf, 4, 5)))
83 +extern void trace_printf_key_fl(const char *file, int line, struct trace_key *key,
84 + const char *format, ...);
85 +__attribute__((format (printf, 4, 5)))
86 +extern void trace_argv_printf_fl(const char *file, int line, const char **argv,
87 + const char *format, ...);
88 +extern void trace_strbuf_fl(const char *file, int line, struct trace_key *key,
89 + const struct strbuf *data);
90 +
91 +#endif /* HAVE_VARIADIC_MACROS */
92 +
93 #endif /* TRACE_H */