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