Karsten Blees | 5991a55 | 2014-06-11 09:56:49 +0200 | [diff] [blame] | 1 | #ifndef TRACE_H |
| 2 | #define TRACE_H |
| 3 | |
| 4 | #include "git-compat-util.h" |
| 5 | #include "strbuf.h" |
| 6 | |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 7 | /** |
| 8 | * The trace API can be used to print debug messages to stderr or a file. Trace |
| 9 | * code is inactive unless explicitly enabled by setting `GIT_TRACE*` environment |
| 10 | * variables. |
| 11 | * |
| 12 | * The trace implementation automatically adds `timestamp file:line ... \n` to |
| 13 | * all trace messages. E.g.: |
| 14 | * |
| 15 | * ------------ |
| 16 | * 23:59:59.123456 git.c:312 trace: built-in: git 'foo' |
| 17 | * 00:00:00.000001 builtin/foo.c:99 foo: some message |
| 18 | * ------------ |
| 19 | * |
| 20 | * Bugs & Caveats |
| 21 | * -------------- |
| 22 | * |
| 23 | * GIT_TRACE_* environment variables can be used to tell Git to show |
| 24 | * trace output to its standard error stream. Git can often spawn a pager |
| 25 | * internally to run its subcommand and send its standard output and |
| 26 | * standard error to it. |
| 27 | * |
| 28 | * Because GIT_TRACE_PERFORMANCE trace is generated only at the very end |
| 29 | * of the program with atexit(), which happens after the pager exits, it |
| 30 | * would not work well if you send its log to the standard error output |
| 31 | * and let Git spawn the pager at the same time. |
| 32 | * |
| 33 | * As a work around, you can for example use '--no-pager', or set |
| 34 | * GIT_TRACE_PERFORMANCE to another file descriptor which is redirected |
| 35 | * to stderr, or set GIT_TRACE_PERFORMANCE to a file specified by its |
| 36 | * absolute path. |
| 37 | * |
| 38 | * For example instead of the following command which by default may not |
| 39 | * print any performance information: |
| 40 | * |
| 41 | * ------------ |
| 42 | * GIT_TRACE_PERFORMANCE=2 git log -1 |
| 43 | * ------------ |
| 44 | * |
| 45 | * you may want to use: |
| 46 | * |
| 47 | * ------------ |
| 48 | * GIT_TRACE_PERFORMANCE=2 git --no-pager log -1 |
| 49 | * ------------ |
| 50 | * |
| 51 | * or: |
| 52 | * |
| 53 | * ------------ |
| 54 | * GIT_TRACE_PERFORMANCE=3 3>&2 git log -1 |
| 55 | * ------------ |
| 56 | * |
| 57 | * or: |
| 58 | * |
| 59 | * ------------ |
| 60 | * GIT_TRACE_PERFORMANCE=/path/to/log/file git log -1 |
| 61 | * ------------ |
| 62 | * |
| 63 | */ |
| 64 | |
| 65 | /** |
| 66 | * Defines a trace key (or category). The default (for API functions that |
| 67 | * don't take a key) is `GIT_TRACE`. |
| 68 | * |
| 69 | * E.g. to define a trace key controlled by environment variable `GIT_TRACE_FOO`: |
| 70 | * |
| 71 | * ------------ |
| 72 | * static struct trace_key trace_foo = TRACE_KEY_INIT(FOO); |
| 73 | * |
| 74 | * static void trace_print_foo(const char *message) |
| 75 | * { |
| 76 | * trace_printf_key(&trace_foo, "%s", message); |
| 77 | * } |
| 78 | * ------------ |
| 79 | * |
| 80 | * Note: don't use `const` as the trace implementation stores internal state in |
| 81 | * the `trace_key` structure. |
| 82 | */ |
Karsten Blees | 6aa3085 | 2014-07-12 02:00:06 +0200 | [diff] [blame] | 83 | struct trace_key { |
| 84 | const char * const key; |
| 85 | int fd; |
| 86 | unsigned int initialized : 1; |
| 87 | unsigned int need_close : 1; |
| 88 | }; |
| 89 | |
Gennady Kupava | 406102a | 2017-11-26 20:11:18 +0000 | [diff] [blame] | 90 | extern struct trace_key trace_default_key; |
| 91 | |
Karsten Blees | 6aa3085 | 2014-07-12 02:00:06 +0200 | [diff] [blame] | 92 | #define TRACE_KEY_INIT(name) { "GIT_TRACE_" #name, 0, 0, 0 } |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 93 | extern struct trace_key trace_perf_key; |
Nguyễn Thái Ngọc Duy | cb50761 | 2018-03-30 14:34:59 -0400 | [diff] [blame] | 94 | extern struct trace_key trace_setup_key; |
Karsten Blees | 6aa3085 | 2014-07-12 02:00:06 +0200 | [diff] [blame] | 95 | |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 96 | void trace_repo_setup(const char *prefix); |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 97 | |
| 98 | /** |
| 99 | * Checks whether the trace key is enabled. Used to prevent expensive |
| 100 | * string formatting before calling one of the printing APIs. |
| 101 | */ |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 102 | int trace_want(struct trace_key *key); |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 103 | |
| 104 | /** |
Jonathan Tan | 7167a62 | 2020-05-11 10:43:10 -0700 | [diff] [blame] | 105 | * Enables or disables tracing for the specified key, as if the environment |
| 106 | * variable was set to the given value. |
| 107 | */ |
| 108 | void trace_override_envvar(struct trace_key *key, const char *value); |
| 109 | |
| 110 | /** |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 111 | * Disables tracing for the specified key, even if the environment variable |
| 112 | * was set. |
| 113 | */ |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 114 | void trace_disable(struct trace_key *key); |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 115 | |
| 116 | /** |
| 117 | * Returns nanoseconds since the epoch (01/01/1970), typically used |
| 118 | * for performance measurements. |
| 119 | * Currently there are high precision timer implementations for Linux (using |
| 120 | * `clock_gettime(CLOCK_MONOTONIC)`) and Windows (`QueryPerformanceCounter`). |
| 121 | * Other platforms use `gettimeofday` as time source. |
| 122 | */ |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 123 | uint64_t getnanotime(void); |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 124 | |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 125 | void trace_command_performance(const char **argv); |
| 126 | void trace_verbatim(struct trace_key *key, const void *buf, unsigned len); |
Nguyễn Thái Ngọc Duy | c46c406 | 2018-08-18 16:41:22 +0200 | [diff] [blame] | 127 | uint64_t trace_performance_enter(void); |
Karsten Blees | 66f66c5 | 2014-07-12 02:04:29 +0200 | [diff] [blame] | 128 | |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 129 | #ifndef HAVE_VARIADIC_MACROS |
| 130 | |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 131 | /** |
| 132 | * Prints a formatted message, similar to printf. |
| 133 | */ |
Karsten Blees | 66f66c5 | 2014-07-12 02:04:29 +0200 | [diff] [blame] | 134 | __attribute__((format (printf, 1, 2))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 135 | void trace_printf(const char *format, ...); |
Karsten Blees | 66f66c5 | 2014-07-12 02:04:29 +0200 | [diff] [blame] | 136 | |
Karsten Blees | 5991a55 | 2014-06-11 09:56:49 +0200 | [diff] [blame] | 137 | __attribute__((format (printf, 2, 3))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 138 | void trace_printf_key(struct trace_key *key, const char *format, ...); |
Karsten Blees | 66f66c5 | 2014-07-12 02:04:29 +0200 | [diff] [blame] | 139 | |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 140 | /** |
| 141 | * Prints a formatted message, followed by a quoted list of arguments. |
| 142 | */ |
Karsten Blees | 66f66c5 | 2014-07-12 02:04:29 +0200 | [diff] [blame] | 143 | __attribute__((format (printf, 2, 3))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 144 | void trace_argv_printf(const char **argv, const char *format, ...); |
Karsten Blees | 66f66c5 | 2014-07-12 02:04:29 +0200 | [diff] [blame] | 145 | |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 146 | /** |
| 147 | * Prints the strbuf, without additional formatting (i.e. doesn't |
| 148 | * choke on `%` or even `\0`). |
| 149 | */ |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 150 | void trace_strbuf(struct trace_key *key, const struct strbuf *data); |
Karsten Blees | 5991a55 | 2014-06-11 09:56:49 +0200 | [diff] [blame] | 151 | |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 152 | /** |
| 153 | * Prints elapsed time (in nanoseconds) if GIT_TRACE_PERFORMANCE is enabled. |
| 154 | * |
| 155 | * Example: |
| 156 | * ------------ |
| 157 | * uint64_t t = 0; |
| 158 | * for (;;) { |
| 159 | * // ignore |
| 160 | * t -= getnanotime(); |
| 161 | * // code section to measure |
| 162 | * t += getnanotime(); |
| 163 | * // ignore |
| 164 | * } |
| 165 | * trace_performance(t, "frotz"); |
| 166 | * ------------ |
| 167 | */ |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 168 | __attribute__((format (printf, 2, 3))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 169 | void trace_performance(uint64_t nanos, const char *format, ...); |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 170 | |
Heba Waly | f1ecbe0 | 2019-11-17 21:04:56 +0000 | [diff] [blame] | 171 | /** |
| 172 | * Prints elapsed time since 'start' if GIT_TRACE_PERFORMANCE is enabled. |
| 173 | * |
| 174 | * Example: |
| 175 | * ------------ |
| 176 | * uint64_t start = getnanotime(); |
| 177 | * // code section to measure |
| 178 | * trace_performance_since(start, "foobar"); |
| 179 | * ------------ |
| 180 | */ |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 181 | __attribute__((format (printf, 2, 3))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 182 | void trace_performance_since(uint64_t start, const char *format, ...); |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 183 | |
Nguyễn Thái Ngọc Duy | c46c406 | 2018-08-18 16:41:22 +0200 | [diff] [blame] | 184 | __attribute__((format (printf, 1, 2))) |
| 185 | void trace_performance_leave(const char *format, ...); |
| 186 | |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 187 | #else |
| 188 | |
| 189 | /* |
| 190 | * Macros to add file:line - see above for C-style declarations of how these |
| 191 | * should be used. |
| 192 | */ |
| 193 | |
| 194 | /* |
| 195 | * TRACE_CONTEXT may be set to __FUNCTION__ if the compiler supports it. The |
| 196 | * default is __FILE__, as it is consistent with assert(), and static function |
| 197 | * names are not necessarily unique. |
| 198 | * |
| 199 | * __FILE__ ":" __FUNCTION__ doesn't work with GNUC, as __FILE__ is supplied |
| 200 | * by the preprocessor as a string literal, and __FUNCTION__ is filled in by |
| 201 | * the compiler as a string constant. |
| 202 | */ |
| 203 | #ifndef TRACE_CONTEXT |
| 204 | # define TRACE_CONTEXT __FILE__ |
| 205 | #endif |
| 206 | |
| 207 | /* |
| 208 | * Note: with C99 variadic macros, __VA_ARGS__ must include the last fixed |
| 209 | * parameter ('format' in this case). Otherwise, a call without variable |
| 210 | * arguments will have a surplus ','. E.g.: |
| 211 | * |
| 212 | * #define foo(format, ...) bar(format, __VA_ARGS__) |
| 213 | * foo("test"); |
| 214 | * |
| 215 | * will expand to |
| 216 | * |
| 217 | * bar("test",); |
| 218 | * |
| 219 | * which is invalid (note the ',)'). With GNUC, '##__VA_ARGS__' drops the |
| 220 | * comma, but this is non-standard. |
| 221 | */ |
| 222 | |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 223 | #define trace_printf_key(key, ...) \ |
| 224 | do { \ |
| 225 | if (trace_pass_fl(key)) \ |
| 226 | trace_printf_key_fl(TRACE_CONTEXT, __LINE__, key, \ |
| 227 | __VA_ARGS__); \ |
| 228 | } while (0) |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 229 | |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 230 | #define trace_printf(...) trace_printf_key(&trace_default_key, __VA_ARGS__) |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 231 | |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 232 | #define trace_argv_printf(argv, ...) \ |
| 233 | do { \ |
| 234 | if (trace_pass_fl(&trace_default_key)) \ |
| 235 | trace_argv_printf_fl(TRACE_CONTEXT, __LINE__, \ |
| 236 | argv, __VA_ARGS__); \ |
| 237 | } while (0) |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 238 | |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 239 | #define trace_strbuf(key, data) \ |
| 240 | do { \ |
| 241 | if (trace_pass_fl(key)) \ |
| 242 | trace_strbuf_fl(TRACE_CONTEXT, __LINE__, key, data);\ |
| 243 | } while (0) |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 244 | |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 245 | #define trace_performance(nanos, ...) \ |
| 246 | do { \ |
| 247 | if (trace_pass_fl(&trace_perf_key)) \ |
| 248 | trace_performance_fl(TRACE_CONTEXT, __LINE__, nanos,\ |
| 249 | __VA_ARGS__); \ |
| 250 | } while (0) |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 251 | |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 252 | #define trace_performance_since(start, ...) \ |
| 253 | do { \ |
| 254 | if (trace_pass_fl(&trace_perf_key)) \ |
| 255 | trace_performance_fl(TRACE_CONTEXT, __LINE__, \ |
| 256 | getnanotime() - (start), \ |
| 257 | __VA_ARGS__); \ |
| 258 | } while (0) |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 259 | |
Nguyễn Thái Ngọc Duy | c46c406 | 2018-08-18 16:41:22 +0200 | [diff] [blame] | 260 | #define trace_performance_leave(...) \ |
| 261 | do { \ |
| 262 | if (trace_pass_fl(&trace_perf_key)) \ |
| 263 | trace_performance_leave_fl(TRACE_CONTEXT, __LINE__, \ |
| 264 | getnanotime(), \ |
| 265 | __VA_ARGS__); \ |
| 266 | } while (0) |
| 267 | |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 268 | /* backend functions, use non-*fl macros instead */ |
| 269 | __attribute__((format (printf, 4, 5))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 270 | void trace_printf_key_fl(const char *file, int line, struct trace_key *key, |
Denton Liu | ad6dad0 | 2019-04-29 04:28:23 -0400 | [diff] [blame] | 271 | const char *format, ...); |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 272 | __attribute__((format (printf, 4, 5))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 273 | void trace_argv_printf_fl(const char *file, int line, const char **argv, |
Denton Liu | ad6dad0 | 2019-04-29 04:28:23 -0400 | [diff] [blame] | 274 | const char *format, ...); |
Denton Liu | 5545442 | 2019-04-29 04:28:14 -0400 | [diff] [blame] | 275 | void trace_strbuf_fl(const char *file, int line, struct trace_key *key, |
Denton Liu | ad6dad0 | 2019-04-29 04:28:23 -0400 | [diff] [blame] | 276 | const struct strbuf *data); |
Karsten Blees | 09b2c1c | 2014-07-12 02:06:28 +0200 | [diff] [blame] | 277 | __attribute__((format (printf, 4, 5))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 278 | void trace_performance_fl(const char *file, int line, |
Denton Liu | ad6dad0 | 2019-04-29 04:28:23 -0400 | [diff] [blame] | 279 | uint64_t nanos, const char *fmt, ...); |
Nguyễn Thái Ngọc Duy | c46c406 | 2018-08-18 16:41:22 +0200 | [diff] [blame] | 280 | __attribute__((format (printf, 4, 5))) |
Denton Liu | b199d71 | 2019-04-29 04:28:20 -0400 | [diff] [blame] | 281 | void trace_performance_leave_fl(const char *file, int line, |
Denton Liu | ad6dad0 | 2019-04-29 04:28:23 -0400 | [diff] [blame] | 282 | uint64_t nanos, const char *fmt, ...); |
Gennady Kupava | 8eeb25c | 2017-11-26 20:11:19 +0000 | [diff] [blame] | 283 | static inline int trace_pass_fl(struct trace_key *key) |
| 284 | { |
| 285 | return key->fd || !key->initialized; |
| 286 | } |
Karsten Blees | e05bed9 | 2014-07-12 02:05:03 +0200 | [diff] [blame] | 287 | |
| 288 | #endif /* HAVE_VARIADIC_MACROS */ |
| 289 | |
Karsten Blees | 5991a55 | 2014-06-11 09:56:49 +0200 | [diff] [blame] | 290 | #endif /* TRACE_H */ |