Seventh batch for 2.19 cycle
[git/git.git] / trace.c
CommitLineData
6ce4e61f
CC
1/*
2 * GIT - The information manager from hell
3 *
4 * Copyright (C) 2000-2002 Michael R. Elkins <me@mutt.org>
5 * Copyright (C) 2002-2004 Oswald Buddenhagen <ossi@users.sf.net>
6 * Copyright (C) 2004 Theodore Y. Ts'o <tytso@mit.edu>
7 * Copyright (C) 2006 Mike McCormack
8 * Copyright (C) 2006 Christian Couder
9 *
10 * This program is free software; you can redistribute it and/or modify
11 * it under the terms of the GNU General Public License as published by
12 * the Free Software Foundation; either version 2 of the License, or
13 * (at your option) any later version.
14 *
15 * This program is distributed in the hope that it will be useful,
16 * but WITHOUT ANY WARRANTY; without even the implied warranty of
17 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
18 * GNU General Public License for more details.
19 *
20 * You should have received a copy of the GNU General Public License
48425792 21 * along with this program; if not, see <http://www.gnu.org/licenses/>.
6ce4e61f
CC
22 */
23
24#include "cache.h"
25#include "quote.h"
26
406102a7 27struct trace_key trace_default_key = { "GIT_TRACE", 0, 0, 0 };
8eeb25c6 28struct trace_key trace_perf_key = TRACE_KEY_INIT(PERFORMANCE);
cb507619 29struct trace_key trace_setup_key = TRACE_KEY_INIT(SETUP);
c81539b5 30
06796607 31/* Get a trace file descriptor from "key" env variable. */
6aa30857 32static int get_trace_fd(struct trace_key *key)
6ce4e61f 33{
6aa30857
KB
34 const char *trace;
35
6aa30857
KB
36 /* don't open twice */
37 if (key->initialized)
38 return key->fd;
39
40 trace = getenv(key->key);
6ce4e61f 41
6844fc80
CC
42 if (!trace || !strcmp(trace, "") ||
43 !strcmp(trace, "0") || !strcasecmp(trace, "false"))
6aa30857
KB
44 key->fd = 0;
45 else if (!strcmp(trace, "1") || !strcasecmp(trace, "true"))
46 key->fd = STDERR_FILENO;
47 else if (strlen(trace) == 1 && isdigit(*trace))
48 key->fd = atoi(trace);
49 else if (is_absolute_path(trace)) {
6ce4e61f
CC
50 int fd = open(trace, O_WRONLY | O_APPEND | O_CREAT, 0666);
51 if (fd == -1) {
6f253057 52 warning("could not open '%s' for tracing: %s",
6ce4e61f 53 trace, strerror(errno));
6f253057 54 trace_disable(key);
6aa30857
KB
55 } else {
56 key->fd = fd;
57 key->need_close = 1;
6ce4e61f 58 }
6aa30857 59 } else {
b3a1c5da
JK
60 warning("unknown trace value for '%s': %s\n"
61 " If you want to trace into a file, then please set %s\n"
6f253057 62 " to an absolute pathname (starting with /)",
b3a1c5da 63 key->key, trace, key->key);
6f253057 64 trace_disable(key);
6ce4e61f
CC
65 }
66
6aa30857
KB
67 key->initialized = 1;
68 return key->fd;
69}
6ce4e61f 70
6aa30857
KB
71void trace_disable(struct trace_key *key)
72{
73 if (key->need_close)
74 close(key->fd);
75 key->fd = 0;
76 key->initialized = 1;
77 key->need_close = 0;
6ce4e61f
CC
78}
79
e05bed96
KB
80static int prepare_trace_line(const char *file, int line,
81 struct trace_key *key, struct strbuf *buf)
c69dfd24 82{
124647c4 83 static struct trace_key trace_bare = TRACE_KEY_INIT(BARE);
b72be02c
KB
84 struct timeval tv;
85 struct tm tm;
86 time_t secs;
124647c4 87
c69dfd24
KB
88 if (!trace_want(key))
89 return 0;
90
91 set_try_to_free_routine(NULL); /* is never reset */
92
124647c4
KB
93 /* unit tests may want to disable additional trace output */
94 if (trace_want(&trace_bare))
95 return 1;
96
b72be02c
KB
97 /* print current timestamp */
98 gettimeofday(&tv, NULL);
99 secs = tv.tv_sec;
100 localtime_r(&secs, &tm);
101 strbuf_addf(buf, "%02d:%02d:%02d.%06ld ", tm.tm_hour, tm.tm_min,
102 tm.tm_sec, (long) tv.tv_usec);
c69dfd24 103
e05bed96
KB
104#ifdef HAVE_VARIADIC_MACROS
105 /* print file:line */
106 strbuf_addf(buf, "%s:%d ", file, line);
107 /* align trace output (column 40 catches most files names in git) */
108 while (buf->len < 40)
109 strbuf_addch(buf, ' ');
110#endif
111
c69dfd24
KB
112 return 1;
113}
114
c0222e76
JK
115static void trace_write(struct trace_key *key, const void *buf, unsigned len)
116{
3b0c3ab7 117 if (write_in_full(get_trace_fd(key), buf, len) < 0) {
3b0c3ab7
JK
118 warning("unable to write trace for %s: %s",
119 key->key, strerror(errno));
46ac74b7 120 trace_disable(key);
3b0c3ab7 121 }
c0222e76
JK
122}
123
32359838
JK
124void trace_verbatim(struct trace_key *key, const void *buf, unsigned len)
125{
126 if (!trace_want(key))
127 return;
c0222e76 128 trace_write(key, buf, len);
32359838
JK
129}
130
c69dfd24
KB
131static void print_trace_line(struct trace_key *key, struct strbuf *buf)
132{
a0d4923d 133 strbuf_complete_line(buf);
c0222e76 134 trace_write(key, buf->buf, buf->len);
c69dfd24
KB
135}
136
e05bed96
KB
137static void trace_vprintf_fl(const char *file, int line, struct trace_key *key,
138 const char *format, va_list ap)
6ce4e61f 139{
ebeb6090 140 struct strbuf buf = STRBUF_INIT;
6ce4e61f 141
e05bed96 142 if (!prepare_trace_line(file, line, key, &buf))
6ce4e61f
CC
143 return;
144
4a3b0b25 145 strbuf_vaddf(&buf, format, ap);
c69dfd24 146 print_trace_line(key, &buf);
33011e76 147 strbuf_release(&buf);
6ce4e61f
CC
148}
149
e05bed96
KB
150static void trace_argv_vprintf_fl(const char *file, int line,
151 const char **argv, const char *format,
152 va_list ap)
06796607 153{
66f66c59 154 struct strbuf buf = STRBUF_INIT;
06796607 155
406102a7 156 if (!prepare_trace_line(file, line, &trace_default_key, &buf))
66f66c59
KB
157 return;
158
66f66c59 159 strbuf_vaddf(&buf, format, ap);
66f66c59 160
1fbdab21 161 sq_quote_argv_pretty(&buf, argv);
406102a7 162 print_trace_line(&trace_default_key, &buf);
33011e76 163 strbuf_release(&buf);
c6053543
JK
164}
165
e05bed96
KB
166void trace_strbuf_fl(const char *file, int line, struct trace_key *key,
167 const struct strbuf *data)
94b3b374 168{
c69dfd24
KB
169 struct strbuf buf = STRBUF_INIT;
170
e05bed96 171 if (!prepare_trace_line(file, line, key, &buf))
94b3b374
JK
172 return;
173
c69dfd24
KB
174 strbuf_addbuf(&buf, data);
175 print_trace_line(key, &buf);
33011e76 176 strbuf_release(&buf);
94b3b374
JK
177}
178
09b2c1c7
KB
179static void trace_performance_vprintf_fl(const char *file, int line,
180 uint64_t nanos, const char *format,
181 va_list ap)
182{
183 struct strbuf buf = STRBUF_INIT;
184
185 if (!prepare_trace_line(file, line, &trace_perf_key, &buf))
186 return;
187
188 strbuf_addf(&buf, "performance: %.9f s", (double) nanos / 1000000000);
189
190 if (format && *format) {
191 strbuf_addstr(&buf, ": ");
192 strbuf_vaddf(&buf, format, ap);
193 }
194
195 print_trace_line(&trace_perf_key, &buf);
33011e76 196 strbuf_release(&buf);
09b2c1c7
KB
197}
198
e05bed96
KB
199#ifndef HAVE_VARIADIC_MACROS
200
66f66c59 201void trace_printf(const char *format, ...)
6ce4e61f 202{
19247e55 203 va_list ap;
4a3b0b25 204 va_start(ap, format);
406102a7 205 trace_vprintf_fl(NULL, 0, &trace_default_key, format, ap);
19247e55 206 va_end(ap);
66f66c59 207}
6ce4e61f 208
66f66c59
KB
209void trace_printf_key(struct trace_key *key, const char *format, ...)
210{
211 va_list ap;
212 va_start(ap, format);
e05bed96
KB
213 trace_vprintf_fl(NULL, 0, key, format, ap);
214 va_end(ap);
215}
216
217void trace_argv_printf(const char **argv, const char *format, ...)
218{
219 va_list ap;
220 va_start(ap, format);
221 trace_argv_vprintf_fl(NULL, 0, argv, format, ap);
66f66c59 222 va_end(ap);
6ce4e61f 223}
a9ca8a85 224
792a646a 225void trace_strbuf(struct trace_key *key, const struct strbuf *data)
e05bed96
KB
226{
227 trace_strbuf_fl(NULL, 0, key, data);
228}
229
09b2c1c7
KB
230void trace_performance(uint64_t nanos, const char *format, ...)
231{
232 va_list ap;
233 va_start(ap, format);
234 trace_performance_vprintf_fl(NULL, 0, nanos, format, ap);
235 va_end(ap);
236}
237
238void trace_performance_since(uint64_t start, const char *format, ...)
239{
240 va_list ap;
241 va_start(ap, format);
242 trace_performance_vprintf_fl(NULL, 0, getnanotime() - start,
243 format, ap);
244 va_end(ap);
245}
246
e05bed96
KB
247#else
248
249void trace_printf_key_fl(const char *file, int line, struct trace_key *key,
250 const char *format, ...)
251{
252 va_list ap;
253 va_start(ap, format);
254 trace_vprintf_fl(file, line, key, format, ap);
255 va_end(ap);
256}
257
258void trace_argv_printf_fl(const char *file, int line, const char **argv,
259 const char *format, ...)
260{
261 va_list ap;
262 va_start(ap, format);
263 trace_argv_vprintf_fl(file, line, argv, format, ap);
264 va_end(ap);
265}
266
09b2c1c7
KB
267void trace_performance_fl(const char *file, int line, uint64_t nanos,
268 const char *format, ...)
269{
270 va_list ap;
271 va_start(ap, format);
272 trace_performance_vprintf_fl(file, line, nanos, format, ap);
273 va_end(ap);
274}
275
e05bed96
KB
276#endif /* HAVE_VARIADIC_MACROS */
277
278
a9ca8a85
NTND
279static const char *quote_crnl(const char *path)
280{
0bb443fd 281 static struct strbuf new_path = STRBUF_INIT;
a9ca8a85
NTND
282
283 if (!path)
284 return NULL;
285
0bb443fd
JK
286 strbuf_reset(&new_path);
287
288 while (*path) {
289 switch (*path) {
290 case '\\': strbuf_addstr(&new_path, "\\\\"); break;
291 case '\n': strbuf_addstr(&new_path, "\\n"); break;
292 case '\r': strbuf_addstr(&new_path, "\\r"); break;
a9ca8a85 293 default:
0bb443fd 294 strbuf_addch(&new_path, *path);
a9ca8a85 295 }
0bb443fd 296 path++;
a9ca8a85 297 }
0bb443fd 298 return new_path.buf;
a9ca8a85
NTND
299}
300
301/* FIXME: move prefix to startup_info struct and get rid of this arg */
302void trace_repo_setup(const char *prefix)
303{
e83c267f 304 const char *git_work_tree;
56b9f6e7 305 char *cwd;
a9ca8a85 306
cb507619 307 if (!trace_want(&trace_setup_key))
a9ca8a85
NTND
308 return;
309
56b9f6e7 310 cwd = xgetcwd();
a9ca8a85 311
e83c267f
BC
312 if (!(git_work_tree = get_git_work_tree()))
313 git_work_tree = "(null)";
314
315 if (!prefix)
316 prefix = "(null)";
317
cb507619
NTND
318 trace_printf_key(&trace_setup_key, "setup: git_dir: %s\n", quote_crnl(get_git_dir()));
319 trace_printf_key(&trace_setup_key, "setup: git_common_dir: %s\n", quote_crnl(get_git_common_dir()));
320 trace_printf_key(&trace_setup_key, "setup: worktree: %s\n", quote_crnl(git_work_tree));
321 trace_printf_key(&trace_setup_key, "setup: cwd: %s\n", quote_crnl(cwd));
322 trace_printf_key(&trace_setup_key, "setup: prefix: %s\n", quote_crnl(prefix));
56b9f6e7
RS
323
324 free(cwd);
a9ca8a85 325}
39bc5e46 326
6aa30857 327int trace_want(struct trace_key *key)
39bc5e46 328{
6aa30857 329 return !!get_trace_fd(key);
39bc5e46 330}
148d6771 331
a6c3c638 332#if defined(HAVE_CLOCK_GETTIME) && defined(HAVE_CLOCK_MONOTONIC)
148d6771
KB
333
334static inline uint64_t highres_nanos(void)
335{
336 struct timespec ts;
337 if (clock_gettime(CLOCK_MONOTONIC, &ts))
338 return 0;
339 return (uint64_t) ts.tv_sec * 1000000000 + ts.tv_nsec;
340}
341
342#elif defined (GIT_WINDOWS_NATIVE)
343
344static inline uint64_t highres_nanos(void)
345{
346 static uint64_t high_ns, scaled_low_ns;
347 static int scale;
348 LARGE_INTEGER cnt;
349
350 if (!scale) {
351 if (!QueryPerformanceFrequency(&cnt))
352 return 0;
353
354 /* high_ns = number of ns per cnt.HighPart */
355 high_ns = (1000000000LL << 32) / (uint64_t) cnt.QuadPart;
356
357 /*
358 * Number of ns per cnt.LowPart is 10^9 / frequency (or
359 * high_ns >> 32). For maximum precision, we scale this factor
360 * so that it just fits within 32 bit (i.e. won't overflow if
361 * multiplied with cnt.LowPart).
362 */
363 scaled_low_ns = high_ns;
364 scale = 32;
365 while (scaled_low_ns >= 0x100000000LL) {
366 scaled_low_ns >>= 1;
367 scale--;
368 }
369 }
370
371 /* if QPF worked on initialization, we expect QPC to work as well */
372 QueryPerformanceCounter(&cnt);
373
374 return (high_ns * cnt.HighPart) +
375 ((scaled_low_ns * cnt.LowPart) >> scale);
376}
377
378#else
379# define highres_nanos() 0
380#endif
381
382static inline uint64_t gettimeofday_nanos(void)
383{
384 struct timeval tv;
385 gettimeofday(&tv, NULL);
386 return (uint64_t) tv.tv_sec * 1000000000 + tv.tv_usec * 1000;
387}
388
389/*
390 * Returns nanoseconds since the epoch (01/01/1970), for performance tracing
391 * (i.e. favoring high precision over wall clock time accuracy).
392 */
6433d569 393uint64_t getnanotime(void)
148d6771
KB
394{
395 static uint64_t offset;
396 if (offset > 1) {
397 /* initialization succeeded, return offset + high res time */
398 return offset + highres_nanos();
399 } else if (offset == 1) {
400 /* initialization failed, fall back to gettimeofday */
401 return gettimeofday_nanos();
402 } else {
403 /* initialize offset if high resolution timer works */
404 uint64_t now = gettimeofday_nanos();
405 uint64_t highres = highres_nanos();
406 if (highres)
407 offset = now - highres;
408 else
409 offset = 1;
410 return now;
411 }
412}
578da039
KB
413
414static uint64_t command_start_time;
415static struct strbuf command_line = STRBUF_INIT;
416
417static void print_command_performance_atexit(void)
418{
419 trace_performance_since(command_start_time, "git command:%s",
420 command_line.buf);
421}
422
423void trace_command_performance(const char **argv)
424{
425 if (!trace_want(&trace_perf_key))
426 return;
427
428 if (!command_start_time)
429 atexit(print_command_performance_atexit);
430
431 strbuf_reset(&command_line);
1fbdab21 432 sq_quote_argv_pretty(&command_line, argv);
578da039
KB
433 command_start_time = getnanotime();
434}