trace2.h

   1 #ifndef TRACE2_H
   2 #define TRACE2_H
   3
   4 /**
   5  * The Trace2 API can be used to print debug, performance, and telemetry
   6  * information to stderr or a file.  The Trace2 feature is inactive unless
   7  * explicitly enabled by enabling one or more Trace2 Targets.
   8  *
   9  * The Trace2 API is intended to replace the existing (Trace1)
  10  * printf-style tracing provided by the existing `GIT_TRACE` and
  11  * `GIT_TRACE_PERFORMANCE` facilities.  During initial implementation,
  12  * Trace2 and Trace1 may operate in parallel.
  13  *
  14  * The Trace2 API defines a set of high-level messages with known fields,
  15  * such as (`start`: `argv`) and (`exit`: {`exit-code`, `elapsed-time`}).
  16  *
  17  * Trace2 instrumentation throughout the Git code base sends Trace2
  18  * messages to the enabled Trace2 Targets.  Targets transform these
  19  * messages content into purpose-specific formats and write events to
  20  * their data streams.  In this manner, the Trace2 API can drive
  21  * many different types of analysis.
  22  *
  23  * Targets are defined using a VTable allowing easy extension to other
  24  * formats in the future.  This might be used to define a binary format,
  25  * for example.
  26  *
  27  * Trace2 is controlled using `trace2.*` config values in the system and
  28  * global config files and `GIT_TRACE2*` environment variables.  Trace2 does
  29  * not read from repo local or worktree config files or respect `-c`
  30  * command line config settings.
  31  *
  32  * For more info about: trace2 targets, conventions for public functions and
  33  * macros, trace2 target formats and examples on trace2 API usage refer to
  34  * Documentation/technical/api-trace2.txt
  35  *
  36  */
  37
  38 struct child_process;
  39 struct repository;
  40 struct json_writer;
  41
  42 /*
  43  * The public TRACE2 routines are grouped into the following groups:
  44  *
  45  * [] trace2_initialize -- initialization.
  46  * [] trace2_cmd_*      -- emit command/control messages.
  47  * [] trace2_child*     -- emit child start/stop messages.
  48  * [] trace2_exec*      -- emit exec start/stop messages.
  49  * [] trace2_thread*    -- emit thread start/stop messages.
  50  * [] trace2_def*       -- emit definition/parameter mesasges.
  51  * [] trace2_region*    -- emit region nesting messages.
  52  * [] trace2_data*      -- emit region/thread/repo data messages.
  53  * [] trace2_printf*    -- legacy trace[1] messages.
  54  * [] trace2_timer*     -- stopwatch timers (messages are deferred).
  55  * [] trace2_counter*   -- global counters (messages are deferred).
  56  */
  57
  58 /*
  59  * Initialize the TRACE2 clock and do nothing else, in particular
  60  * no mallocs, no system inspection, and no environment inspection.
  61  *
  62  * This should be called at the very top of main() to capture the
  63  * process start time.  This is intended to reduce chicken-n-egg
  64  * bootstrap pressure.
  65  *
  66  * It is safe to call this more than once.  This allows capturing
  67  * absolute startup costs on Windows which uses a little trickery
  68  * to do setup work before common-main.c:main() is called.
  69  *
  70  * The main trace2_initialize_fl() may be called a little later
  71  * after more infrastructure is established.
  72  */
  73 void trace2_initialize_clock(void);
  74
  75 /*
  76  * Initialize TRACE2 tracing facility if any of the builtin TRACE2
  77  * targets are enabled in the system config or the environment.
  78  * This emits a 'version' message containing the version of git
  79  * and the Trace2 protocol.
  80  *
  81  * This function should be called from `main()` as early as possible in
  82  * the life of the process after essential process initialization.
  83  *
  84  * Cleanup/Termination is handled automatically by a registered
  85  * atexit() routine.
  86  */
  87 void trace2_initialize_fl(const char *file, int line);
  88
  89 #define trace2_initialize() trace2_initialize_fl(__FILE__, __LINE__)
  90
  91 /*
  92  * Return 1 if trace2 is enabled (at least one target is active).
  93  */
  94 int trace2_is_enabled(void);
  95
  96 /*
  97  * Emit a 'start' event with the original (unmodified) argv.
  98  */
  99 void trace2_cmd_start_fl(const char *file, int line, const char **argv);
 100
 101 #define trace2_cmd_start(argv) trace2_cmd_start_fl(__FILE__, __LINE__, (argv))
 102
 103 /*
 104  * Emit an 'exit' event.
 105  */
 106 void trace2_cmd_exit_fl(const char *file, int line, int code);
 107
 108 #define trace2_cmd_exit(code) (trace2_cmd_exit_fl(__FILE__, __LINE__, (code)))
 109
 110 /*
 111  * Emit an 'error' event.
 112  *
 113  * Write an error message to the TRACE2 targets.
 114  */
 115 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
 116                             va_list ap);
 117
 118 #define trace2_cmd_error_va(fmt, ap) \
 119         trace2_cmd_error_va_fl(__FILE__, __LINE__, (fmt), (ap))
 120
 121 /*
 122  * Emit a 'pathname' event with the canonical pathname of the current process
 123  * This gives post-processors a simple field to identify the command without
 124  * having to parse the argv.  For example, to distinguish invocations from
 125  * installed versus debug executables.
 126  */
 127 void trace2_cmd_path_fl(const char *file, int line, const char *pathname);
 128
 129 #define trace2_cmd_path(p) trace2_cmd_path_fl(__FILE__, __LINE__, (p))
 130
 131 /*
 132  * Emit an 'ancestry' event with the process name of the current process's
 133  * parent process.
 134  * This gives post-processors a way to determine what invoked the command and
 135  * learn more about usage patterns.
 136  */
 137 void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names);
 138
 139 #define trace2_cmd_ancestry(v) trace2_cmd_ancestry_fl(__FILE__, __LINE__, (v))
 140
 141 /*
 142  * Emit a 'cmd_name' event with the canonical name of the command.
 143  * This gives post-processors a simple field to identify the command
 144  * without having to parse the argv.
 145  */
 146 void trace2_cmd_name_fl(const char *file, int line, const char *name);
 147
 148 #define trace2_cmd_name(v) trace2_cmd_name_fl(__FILE__, __LINE__, (v))
 149
 150 /*
 151  * Emit a 'cmd_mode' event to further describe the command being run.
 152  * For example, "checkout" can checkout a single file or can checkout a
 153  * different branch.  This gives post-processors a simple field to compare
 154  * equivalent commands without having to parse the argv.
 155  */
 156 void trace2_cmd_mode_fl(const char *file, int line, const char *mode);
 157
 158 #define trace2_cmd_mode(sv) trace2_cmd_mode_fl(__FILE__, __LINE__, (sv))
 159
 160 /*
 161  * Emits an "alias" message containing the alias used and the argument
 162  * expansion.
 163  */
 164 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
 165                          const char **argv);
 166
 167 #define trace2_cmd_alias(alias, argv) \
 168         trace2_cmd_alias_fl(__FILE__, __LINE__, (alias), (argv))
 169
 170 /*
 171  * Emit one or more 'def_param' events for "important" configuration
 172  * settings.
 173  *
 174  * Use the TR2_SYSENV_CFG_PARAM setting to register a comma-separated
 175  * list of patterns configured important.  For example:
 176  *     git config --system trace2.configParams 'core.*,remote.*.url'
 177  * or:
 178  *     GIT_TRACE2_CONFIG_PARAMS=core.*,remote.*.url"
 179  *
 180  * Note: this routine does a read-only iteration on the config data
 181  * (using read_early_config()), so it must not be called until enough
 182  * of the process environment has been established.  This includes the
 183  * location of the git and worktree directories, expansion of any "-c"
 184  * and "-C" command line options, and etc.
 185  */
 186 void trace2_cmd_list_config_fl(const char *file, int line);
 187
 188 #define trace2_cmd_list_config() trace2_cmd_list_config_fl(__FILE__, __LINE__)
 189
 190 /*
 191  * Emit one or more 'def_param' events for "important" environment variables.
 192  *
 193  * Use the TR2_SYSENV_ENV_VARS setting to register a comma-separated list of
 194  * environment variables considered important.  For example:
 195  *     git config --system trace2.envVars 'GIT_HTTP_USER_AGENT,GIT_CONFIG'
 196  * or:
 197  *     GIT_TRACE2_ENV_VARS="GIT_HTTP_USER_AGENT,GIT_CONFIG"
 198  */
 199 void trace2_cmd_list_env_vars_fl(const char *file, int line);
 200
 201 #define trace2_cmd_list_env_vars() trace2_cmd_list_env_vars_fl(__FILE__, __LINE__)
 202
 203 /*
 204  * Emit a "def_param" event for the given config key/value pair IF
 205  * we consider the key to be "important".
 206  *
 207  * Use this for new/updated config settings created/updated after
 208  * trace2_cmd_list_config() is called.
 209  */
 210 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
 211                               const char *value);
 212
 213 #define trace2_cmd_set_config(k, v) \
 214         trace2_cmd_set_config_fl(__FILE__, __LINE__, (k), (v))
 215
 216 /**
 217  * Emits a "child_start" message containing the "child-id",
 218  * "child-argv", and "child-classification".
 219  *
 220  * Before calling optionally set "cmd->trace2_child_class" to a string
 221  * describing the type of the child process.  For example, "editor" or
 222  * "pager".
 223  *
 224  * This function assigns a unique "child-id" to `cmd->trace2_child_id`.
 225  * This field is used later during the "child_exit" message to associate
 226  * it with the "child_start" message.
 227  *
 228  * This function should be called before spawning the child process.
 229  */
 230 void trace2_child_start_fl(const char *file, int line,
 231                            struct child_process *cmd);
 232
 233 #define trace2_child_start(cmd) trace2_child_start_fl(__FILE__, __LINE__, (cmd))
 234
 235 /**
 236  * Emits a "child_exit" message containing the "child-id",
 237  * the child's elapsed time and exit-code.
 238  *
 239  * The reported elapsed time includes the process creation overhead and
 240  * time spend waiting for it to exit, so it may be slightly longer than
 241  * the time reported by the child itself.
 242  *
 243  * This function should be called after reaping the child process.
 244  */
 245 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
 246                           int child_exit_code);
 247
 248 #define trace2_child_exit(cmd, code) \
 249         trace2_child_exit_fl(__FILE__, __LINE__, (cmd), (code))
 250
 251 /**
 252  * Emits a "child_ready" message containing the "child-id" and a flag
 253  * indicating whether the child was considered "ready" when we
 254  * released it.
 255  *
 256  * This function should be called after starting a daemon process in
 257  * the background (and after giving it sufficient time to boot
 258  * up) to indicate that we no longer control or own it.
 259  *
 260  * The "ready" argument should contain one of { "ready", "timeout",
 261  * "error" } to indicate the state of the running daemon when we
 262  * released it.
 263  *
 264  * If the daemon process fails to start or it exits or is terminated
 265  * while we are still waiting for it, the caller should emit a
 266  * regular "child_exit" to report the normal process exit information.
 267  *
 268  */
 269 void trace2_child_ready_fl(const char *file, int line,
 270                            struct child_process *cmd,
 271                            const char *ready);
 272
 273 #define trace2_child_ready(cmd, ready) \
 274         trace2_child_ready_fl(__FILE__, __LINE__, (cmd), (ready))
 275
 276 /**
 277  * Emit an 'exec' event prior to calling one of exec(), execv(),
 278  * execvp(), and etc.  On Unix-derived systems, this will be the
 279  * last event emitted for the current process, unless the exec
 280  * fails.  On Windows, exec() behaves like 'child_start' and a
 281  * waitpid(), so additional events may be emitted.
 282  *
 283  * Returns a unique "exec-id".  This value is used later
 284  * if the exec() fails and a "exec-result" message is necessary.
 285  */
 286 int trace2_exec_fl(const char *file, int line, const char *exe,
 287                    const char **argv);
 288
 289 #define trace2_exec(exe, argv) trace2_exec_fl(__FILE__, __LINE__, (exe), (argv))
 290
 291 /**
 292  * Emit an 'exec_result' when possible.  On Unix-derived systems,
 293  * this should be called after exec() returns (which only happens
 294  * when there is an error starting the new process).  On Windows,
 295  * this should be called after the waitpid().
 296  *
 297  * The "exec_id" should be the value returned from trace2_exec().
 298  */
 299 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code);
 300
 301 #define trace2_exec_result(id, code) \
 302         trace2_exec_result_fl(__FILE__, __LINE__, (id), (code))
 303
 304 /*
 305  * Emit a 'thread_start' event.  This must be called from inside the
 306  * thread-proc to allow the thread to create its own thread-local
 307  * storage.
 308  *
 309  * The thread base name should be descriptive, like "preload_index" or
 310  * taken from the thread-proc function.  A unique thread name will be
 311  * created from the given base name and the thread id automatically.
 312  */
 313 void trace2_thread_start_fl(const char *file, int line,
 314                             const char *thread_base_name);
 315
 316 #define trace2_thread_start(thread_base_name) \
 317         trace2_thread_start_fl(__FILE__, __LINE__, (thread_base_name))
 318
 319 /*
 320  * Emit a 'thread_exit' event.  This must be called from inside the
 321  * thread-proc so that the thread can access and clean up its
 322  * thread-local storage.
 323  */
 324 void trace2_thread_exit_fl(const char *file, int line);
 325
 326 #define trace2_thread_exit() trace2_thread_exit_fl(__FILE__, __LINE__)
 327
 328 struct key_value_info;
 329 /*
 330  * Emits a "def_param" message containing a key/value pair.
 331  *
 332  * This message is intended to report some global aspect of the current
 333  * command, such as a configuration setting or command line switch that
 334  * significantly affects program performance or behavior, such as
 335  * `core.abbrev`, `status.showUntrackedFiles`, or `--no-ahead-behind`.
 336  */
 337 void trace2_def_param_fl(const char *file, int line, const char *param,
 338                          const char *value, const struct key_value_info *kvi);
 339
 340 #define trace2_def_param(param, value, kvi) \
 341         trace2_def_param_fl(__FILE__, __LINE__, (param), (value), (kvi))
 342
 343 /*
 344  * Tell trace2 about a newly instantiated repo object and assign
 345  * a trace2-repo-id to be used in subsequent activity events.
 346  *
 347  * Emits a 'worktree' event for this repo instance.
 348  *
 349  * Region and data messages may refer to this repo-id.
 350  *
 351  * The main/top-level repository will have repo-id value 1 (aka "r1").
 352  *
 353  * The repo-id field is in anticipation of future in-proc submodule
 354  * repositories.
 355  */
 356 void trace2_def_repo_fl(const char *file, int line, struct repository *repo);
 357
 358 #define trace2_def_repo(repo) trace2_def_repo_fl(__FILE__, __LINE__, repo)
 359
 360 /**
 361  * Emit a 'region_enter' event for <category>.<label> with optional
 362  * repo-id and printf message.
 363  *
 364  * This function pushes a new region nesting stack level on the current
 365  * thread and starts a clock for the new stack frame.
 366  *
 367  * The `category` field is an arbitrary category name used to classify
 368  * regions by feature area, such as "status" or "index".  At this time
 369  * it is only just printed along with the rest of the message.  It may
 370  * be used in the future to filter messages.
 371  *
 372  * The `label` field is an arbitrary label used to describe the activity
 373  * being started, such as "read_recursive" or "do_read_index".
 374  *
 375  * The `repo` field, if set, will be used to get the "repo-id", so that
 376  * recursive operations can be attributed to the correct repository.
 377  */
 378 void trace2_region_enter_fl(const char *file, int line, const char *category,
 379                             const char *label, const struct repository *repo, ...);
 380
 381 #define trace2_region_enter(category, label, repo) \
 382         trace2_region_enter_fl(__FILE__, __LINE__, (category), (label), (repo))
 383
 384 void trace2_region_enter_printf_va_fl(const char *file, int line,
 385                                       const char *category, const char *label,
 386                                       const struct repository *repo,
 387                                       const char *fmt, va_list ap);
 388
 389 #define trace2_region_enter_printf_va(category, label, repo, fmt, ap)    \
 390         trace2_region_enter_printf_va_fl(__FILE__, __LINE__, (category), \
 391                                          (label), (repo), (fmt), (ap))
 392
 393 void trace2_region_enter_printf_fl(const char *file, int line,
 394                                    const char *category, const char *label,
 395                                    const struct repository *repo,
 396                                    const char *fmt, ...);
 397
 398 #define trace2_region_enter_printf(category, label, repo, ...)                 \
 399         trace2_region_enter_printf_fl(__FILE__, __LINE__, (category), (label), \
 400                                       (repo), __VA_ARGS__)
 401
 402 /**
 403  * Emit a 'region_leave' event for <category>.<label> with optional
 404  * repo-id and printf message.
 405  *
 406  * Leave current nesting level and report the elapsed time spent
 407  * in this nesting level.
 408  *
 409  * The `category`, `label`, and `repo` fields are the same as
 410  * trace2_region_enter_fl. The `category` and `label` do not
 411  * need to match the corresponding "region_enter" message,
 412  * but it makes the data stream easier to understand.
 413  */
 414 void trace2_region_leave_fl(const char *file, int line, const char *category,
 415                             const char *label, const struct repository *repo, ...);
 416
 417 #define trace2_region_leave(category, label, repo) \
 418         trace2_region_leave_fl(__FILE__, __LINE__, (category), (label), (repo))
 419
 420 void trace2_region_leave_printf_va_fl(const char *file, int line,
 421                                       const char *category, const char *label,
 422                                       const struct repository *repo,
 423                                       const char *fmt, va_list ap);
 424
 425 #define trace2_region_leave_printf_va(category, label, repo, fmt, ap)    \
 426         trace2_region_leave_printf_va_fl(__FILE__, __LINE__, (category), \
 427                                          (label), (repo), (fmt), (ap))
 428
 429 void trace2_region_leave_printf_fl(const char *file, int line,
 430                                    const char *category, const char *label,
 431                                    const struct repository *repo,
 432                                    const char *fmt, ...);
 433
 434 #define trace2_region_leave_printf(category, label, repo, ...)                 \
 435         trace2_region_leave_printf_fl(__FILE__, __LINE__, (category), (label), \
 436                                       (repo), __VA_ARGS__)
 437
 438 /**
 439  * Emit a key-value pair 'data' event of the form <category>.<key> = <value>.
 440  * This event implicitly contains information about thread, nesting region,
 441  * and optional repo-id.
 442  * This could be used to print the number of files in a directory during
 443  * a multi-threaded recursive tree walk.
 444  *
 445  * On event-based TRACE2 targets, this generates a 'data' event suitable
 446  * for post-processing.  On printf-based TRACE2 targets, this is converted
 447  * into a fixed-format printf message.
 448  */
 449 void trace2_data_string_fl(const char *file, int line, const char *category,
 450                            const struct repository *repo, const char *key,
 451                            const char *value);
 452
 453 #define trace2_data_string(category, repo, key, value)                       \
 454         trace2_data_string_fl(__FILE__, __LINE__, (category), (repo), (key), \
 455                               (value))
 456
 457 void trace2_data_intmax_fl(const char *file, int line, const char *category,
 458                            const struct repository *repo, const char *key,
 459                            intmax_t value);
 460
 461 #define trace2_data_intmax(category, repo, key, value)                       \
 462         trace2_data_intmax_fl(__FILE__, __LINE__, (category), (repo), (key), \
 463                               (value))
 464
 465 void trace2_data_json_fl(const char *file, int line, const char *category,
 466                          const struct repository *repo, const char *key,
 467                          const struct json_writer *jw);
 468
 469 #define trace2_data_json(category, repo, key, value)                       \
 470         trace2_data_json_fl(__FILE__, __LINE__, (category), (repo), (key), \
 471                             (value))
 472
 473 /*
 474  * Emit a 'printf' event.
 475  *
 476  * Write an arbitrary formatted message to the TRACE2 targets.  These
 477  * text messages should be considered as human-readable strings without
 478  * any formatting guidelines.  Post-processors may choose to ignore
 479  * them.
 480  */
 481 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
 482                          va_list ap);
 483
 484 #define trace2_printf_va(fmt, ap) \
 485         trace2_printf_va_fl(__FILE__, __LINE__, (fmt), (ap))
 486
 487 void trace2_printf_fl(const char *file, int line, const char *fmt, ...);
 488
 489 #define trace2_printf(...) trace2_printf_fl(__FILE__, __LINE__, __VA_ARGS__)
 490
 491 /*
 492  * Define the set of stopwatch timers.
 493  *
 494  * We can add more at any time, but they must be defined at compile
 495  * time (to avoid the need to dynamically allocate and synchronize
 496  * them between different threads).
 497  *
 498  * These must start at 0 and be contiguous (because we use them
 499  * elsewhere as array indexes).
 500  *
 501  * Any values added to this enum must also be added to the
 502  * `tr2_timer_metadata[]` in `trace2/tr2_tmr.c`.
 503  */
 504 enum trace2_timer_id {
 505         /*
 506          * Define two timers for testing.  See `t/helper/test-trace2.c`.
 507          * These can be used for ad hoc testing, but should not be used
 508          * for permanent analysis code.
 509          */
 510         TRACE2_TIMER_ID_TEST1 = 0, /* emits summary event only */
 511         TRACE2_TIMER_ID_TEST2,     /* emits summary and thread events */
 512
 513         /* Add additional timer definitions before here. */
 514         TRACE2_NUMBER_OF_TIMERS
 515 };
 516
 517 /*
 518  * Start/Stop the indicated stopwatch timer in the current thread.
 519  *
 520  * The time spent by the current thread between the _start and _stop
 521  * calls will be added to the thread's partial sum for this timer.
 522  *
 523  * Timer events are emitted at thread and program exit.
 524  *
 525  * Note: Since the stopwatch API routines do not generate individual
 526  * events, they do not take (file, line) arguments.  Similarly, the
 527  * category and timer name values are defined at compile-time in the
 528  * timer definitions array, so they are not needed here in the API.
 529  */
 530 void trace2_timer_start(enum trace2_timer_id tid);
 531 void trace2_timer_stop(enum trace2_timer_id tid);
 532
 533 /*
 534  * Define the set of global counters.
 535  *
 536  * We can add more at any time, but they must be defined at compile
 537  * time (to avoid the need to dynamically allocate and synchronize
 538  * them between different threads).
 539  *
 540  * These must start at 0 and be contiguous (because we use them
 541  * elsewhere as array indexes).
 542  *
 543  * Any values added to this enum be also be added to the
 544  * `tr2_counter_metadata[]` in `trace2/tr2_ctr.c`.
 545  */
 546 enum trace2_counter_id {
 547         /*
 548          * Define two counters for testing.  See `t/helper/test-trace2.c`.
 549          * These can be used for ad hoc testing, but should not be used
 550          * for permanent analysis code.
 551          */
 552         TRACE2_COUNTER_ID_TEST1 = 0, /* emits summary event only */
 553         TRACE2_COUNTER_ID_TEST2,     /* emits summary and thread events */
 554
 555         TRACE2_COUNTER_ID_PACKED_REFS_JUMPS, /* counts number of jumps */
 556
 557         /* counts number of fsyncs */
 558         TRACE2_COUNTER_ID_FSYNC_WRITEOUT_ONLY,
 559         TRACE2_COUNTER_ID_FSYNC_HARDWARE_FLUSH,
 560
 561         /* Add additional counter definitions before here. */
 562         TRACE2_NUMBER_OF_COUNTERS
 563 };
 564
 565 /*
 566  * Increase the named global counter by value.
 567  *
 568  * Note that this adds `value` to the current thread's partial sum for
 569  * this counter (without locking) and that the complete sum is not
 570  * available until all threads have exited, so it does not return the
 571  * new value of the counter.
 572  */
 573 void trace2_counter_add(enum trace2_counter_id cid, uint64_t value);
 574
 575 /*
 576  * Optional platform-specific code to dump information about the
 577  * current and any parent process(es).  This is intended to allow
 578  * post-processors to know who spawned this git instance and anything
 579  * else that the platform may be able to tell us about the current process.
 580  */
 581
 582 enum trace2_process_info_reason {
 583         TRACE2_PROCESS_INFO_STARTUP,
 584         TRACE2_PROCESS_INFO_EXIT,
 585 };
 586
 587 void trace2_collect_process_info(enum trace2_process_info_reason reason);
 588
 589 const char *trace2_session_id(void);
 590
 591 #endif /* TRACE2_H */