trace.h

   1 #ifndef TRACE_H
   2 #define TRACE_H
   3
   4 #include "git-compat-util.h"
   5 #include "strbuf.h"
   6
   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  */
  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
  90 extern struct trace_key trace_default_key;
  91
  92 #define TRACE_KEY_INIT(name) { .key = "GIT_TRACE_" #name }
  93 extern struct trace_key trace_perf_key;
  94 extern struct trace_key trace_setup_key;
  95
  96 void trace_repo_setup(const char *prefix);
  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  */
 102 int trace_want(struct trace_key *key);
 103
 104 /**
 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 /**
 111  * Disables tracing for the specified key, even if the environment variable
 112  * was set.
 113  */
 114 void trace_disable(struct trace_key *key);
 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  */
 123 uint64_t getnanotime(void);
 124
 125 void trace_command_performance(const char **argv);
 126 void trace_verbatim(struct trace_key *key, const void *buf, unsigned len);
 127 uint64_t trace_performance_enter(void);
 128
 129 #ifndef HAVE_VARIADIC_MACROS
 130
 131 /**
 132  * Prints a formatted message, similar to printf.
 133  */
 134 __attribute__((format (printf, 1, 2)))
 135 void trace_printf(const char *format, ...);
 136
 137 __attribute__((format (printf, 2, 3)))
 138 void trace_printf_key(struct trace_key *key, const char *format, ...);
 139
 140 /**
 141  * Prints a formatted message, followed by a quoted list of arguments.
 142  */
 143 __attribute__((format (printf, 2, 3)))
 144 void trace_argv_printf(const char **argv, const char *format, ...);
 145
 146 /**
 147  * Prints the strbuf, without additional formatting (i.e. doesn't
 148  * choke on `%` or even `\0`).
 149  */
 150 void trace_strbuf(struct trace_key *key, const struct strbuf *data);
 151
 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  */
 168 __attribute__((format (printf, 2, 3)))
 169 void trace_performance(uint64_t nanos, const char *format, ...);
 170
 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  */
 181 __attribute__((format (printf, 2, 3)))
 182 void trace_performance_since(uint64_t start, const char *format, ...);
 183
 184 __attribute__((format (printf, 1, 2)))
 185 void trace_performance_leave(const char *format, ...);
 186
 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
 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)
 229
 230 #define trace_printf(...) trace_printf_key(&trace_default_key, __VA_ARGS__)
 231
 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)
 238
 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)
 244
 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)
 251
 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)
 259
 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
 268 /* backend functions, use non-*fl macros instead */
 269 __attribute__((format (printf, 4, 5)))
 270 void trace_printf_key_fl(const char *file, int line, struct trace_key *key,
 271                          const char *format, ...);
 272 __attribute__((format (printf, 4, 5)))
 273 void trace_argv_printf_fl(const char *file, int line, const char **argv,
 274                           const char *format, ...);
 275 void trace_strbuf_fl(const char *file, int line, struct trace_key *key,
 276                      const struct strbuf *data);
 277 __attribute__((format (printf, 4, 5)))
 278 void trace_performance_fl(const char *file, int line,
 279                           uint64_t nanos, const char *fmt, ...);
 280 __attribute__((format (printf, 4, 5)))
 281 void trace_performance_leave_fl(const char *file, int line,
 282                                 uint64_t nanos, const char *fmt, ...);
 283 static inline int trace_pass_fl(struct trace_key *key)
 284 {
 285         return key->fd || !key->initialized;
 286 }
 287
 288 #endif /* HAVE_VARIADIC_MACROS */
 289
 290 #endif /* TRACE_H */