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