trace.h

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