trace2.c

   1 #include "git-compat-util.h"
   2 #include "config.h"
   3 #include "json-writer.h"
   4 #include "quote.h"
   5 #include "repository.h"
   6 #include "run-command.h"
   7 #include "sigchain.h"
   8 #include "thread-utils.h"
   9 #include "version.h"
  10 #include "trace.h"
  11 #include "trace2.h"
  12 #include "trace2/tr2_cfg.h"
  13 #include "trace2/tr2_cmd_name.h"
  14 #include "trace2/tr2_ctr.h"
  15 #include "trace2/tr2_dst.h"
  16 #include "trace2/tr2_sid.h"
  17 #include "trace2/tr2_sysenv.h"
  18 #include "trace2/tr2_tgt.h"
  19 #include "trace2/tr2_tls.h"
  20 #include "trace2/tr2_tmr.h"
  21
  22 static int trace2_enabled;
  23 static int trace2_redact = 1;
  24
  25 static int tr2_next_child_id; /* modify under lock */
  26 static int tr2_next_exec_id; /* modify under lock */
  27 static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
  28
  29 /*
  30  * A table of the builtin TRACE2 targets.  Each of these may be independently
  31  * enabled or disabled.  Each TRACE2 API method will try to write an event to
  32  * *each* of the enabled targets.
  33  */
  34 /* clang-format off */
  35 static struct tr2_tgt *tr2_tgt_builtins[] =
  36 {
  37         &tr2_tgt_normal,
  38         &tr2_tgt_perf,
  39         &tr2_tgt_event,
  40         NULL
  41 };
  42 /* clang-format on */
  43
  44 /* clang-format off */
  45 #define for_each_builtin(j, tgt_j)                      \
  46         for (j = 0, tgt_j = tr2_tgt_builtins[j];        \
  47              tgt_j;                                     \
  48              j++, tgt_j = tr2_tgt_builtins[j])
  49 /* clang-format on */
  50
  51 /* clang-format off */
  52 #define for_each_wanted_builtin(j, tgt_j)            \
  53         for_each_builtin(j, tgt_j)                   \
  54                 if (tr2_dst_trace_want(tgt_j->pdst))
  55 /* clang-format on */
  56
  57 /*
  58  * Force (rather than lazily) initialize any of the requested
  59  * builtin TRACE2 targets at startup (and before we've seen an
  60  * actual TRACE2 event call) so we can see if we need to setup
  61  * private data structures and thread-local storage.
  62  *
  63  * Return the number of builtin targets enabled.
  64  */
  65 static int tr2_tgt_want_builtins(void)
  66 {
  67         struct tr2_tgt *tgt_j;
  68         int j;
  69         int sum = 0;
  70
  71         for_each_builtin (j, tgt_j)
  72                 if (tgt_j->pfn_init())
  73                         sum++;
  74
  75         return sum;
  76 }
  77
  78 /*
  79  * Properly terminate each builtin target.  Give each target
  80  * a chance to write a summary event and/or flush if necessary
  81  * and then close the fd.
  82  */
  83 static void tr2_tgt_disable_builtins(void)
  84 {
  85         struct tr2_tgt *tgt_j;
  86         int j;
  87
  88         for_each_builtin (j, tgt_j)
  89                 tgt_j->pfn_term();
  90 }
  91
  92 /*
  93  * The signature of this function must match the pfn_timer
  94  * method in the targets.  (Think of this is an apply operation
  95  * across the set of active targets.)
  96  */
  97 static void tr2_tgt_emit_a_timer(const struct tr2_timer_metadata *meta,
  98                                  const struct tr2_timer *timer,
  99                                  int is_final_data)
 100 {
 101         struct tr2_tgt *tgt_j;
 102         int j;
 103
 104         for_each_wanted_builtin (j, tgt_j)
 105                 if (tgt_j->pfn_timer)
 106                         tgt_j->pfn_timer(meta, timer, is_final_data);
 107 }
 108
 109 /*
 110  * The signature of this function must match the pfn_counter
 111  * method in the targets.
 112  */
 113 static void tr2_tgt_emit_a_counter(const struct tr2_counter_metadata *meta,
 114                                    const struct tr2_counter *counter,
 115                                    int is_final_data)
 116 {
 117         struct tr2_tgt *tgt_j;
 118         int j;
 119
 120         for_each_wanted_builtin (j, tgt_j)
 121                 if (tgt_j->pfn_counter)
 122                         tgt_j->pfn_counter(meta, counter, is_final_data);
 123 }
 124
 125 static int tr2main_exit_code;
 126
 127 /*
 128  * Our atexit routine should run after everything has finished.
 129  *
 130  * Note that events generated here might not actually appear if
 131  * we are writing to fd 1 or 2 and our atexit routine runs after
 132  * the pager's atexit routine (since it closes them to shutdown
 133  * the pipes).
 134  */
 135 static void tr2main_atexit_handler(void)
 136 {
 137         struct tr2_tgt *tgt_j;
 138         int j;
 139         uint64_t us_now;
 140         uint64_t us_elapsed_absolute;
 141
 142         us_now = getnanotime() / 1000;
 143         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 144
 145         /*
 146          * Clear any unbalanced regions so that our atexit message
 147          * does not appear nested.  This improves the appearance of
 148          * the trace output if someone calls die(), for example.
 149          */
 150         tr2tls_pop_unwind_self();
 151
 152         /*
 153          * Some timers want per-thread details.  If the main thread
 154          * used one of those timers, emit the details now (before
 155          * we emit the aggregate timer values).
 156          *
 157          * Likewise for counters.
 158          */
 159         tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
 160         tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
 161
 162         /*
 163          * Add stopwatch timer and counter data for the main thread to
 164          * the final totals.  And then emit the final values.
 165          *
 166          * Technically, we shouldn't need to hold the lock to update
 167          * and output the final_timer_block and final_counter_block
 168          * (since all other threads should be dead by now), but it
 169          * doesn't hurt anything.
 170          */
 171         tr2tls_lock();
 172         tr2_update_final_timers();
 173         tr2_update_final_counters();
 174         tr2_emit_final_timers(tr2_tgt_emit_a_timer);
 175         tr2_emit_final_counters(tr2_tgt_emit_a_counter);
 176         tr2tls_unlock();
 177
 178         for_each_wanted_builtin (j, tgt_j)
 179                 if (tgt_j->pfn_atexit)
 180                         tgt_j->pfn_atexit(us_elapsed_absolute,
 181                                           tr2main_exit_code);
 182
 183         tr2_tgt_disable_builtins();
 184
 185         tr2tls_release();
 186         tr2_sid_release();
 187         tr2_cmd_name_release();
 188         tr2_cfg_free_patterns();
 189         tr2_cfg_free_env_vars();
 190         tr2_sysenv_release();
 191
 192         trace2_enabled = 0;
 193 }
 194
 195 static void tr2main_signal_handler(int signo)
 196 {
 197         struct tr2_tgt *tgt_j;
 198         int j;
 199         uint64_t us_now;
 200         uint64_t us_elapsed_absolute;
 201
 202         us_now = getnanotime() / 1000;
 203         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 204
 205         for_each_wanted_builtin (j, tgt_j)
 206                 if (tgt_j->pfn_signal)
 207                         tgt_j->pfn_signal(us_elapsed_absolute, signo);
 208
 209         sigchain_pop(signo);
 210         raise(signo);
 211 }
 212
 213 void trace2_initialize_clock(void)
 214 {
 215         tr2tls_start_process_clock();
 216 }
 217
 218 void trace2_initialize_fl(const char *file, int line)
 219 {
 220         struct tr2_tgt *tgt_j;
 221         int j;
 222
 223         if (trace2_enabled)
 224                 return;
 225
 226         tr2_sysenv_load();
 227
 228         if (!tr2_tgt_want_builtins())
 229                 return;
 230         trace2_enabled = 1;
 231         if (!git_env_bool("GIT_TRACE2_REDACT", 1))
 232                 trace2_redact = 0;
 233
 234         tr2_sid_get();
 235
 236         atexit(tr2main_atexit_handler);
 237         sigchain_push(SIGPIPE, tr2main_signal_handler);
 238         tr2tls_init();
 239
 240         /*
 241          * Emit 'version' message on each active builtin target.
 242          */
 243         for_each_wanted_builtin (j, tgt_j)
 244                 if (tgt_j->pfn_version_fl)
 245                         tgt_j->pfn_version_fl(file, line);
 246 }
 247
 248 int trace2_is_enabled(void)
 249 {
 250         return trace2_enabled;
 251 }
 252
 253 /*
 254  * Redacts an argument, i.e. ensures that no password in
 255  * https://user:password@host/-style URLs is logged.
 256  *
 257  * Returns the original if nothing needed to be redacted.
 258  * Returns a pointer that needs to be `free()`d otherwise.
 259  */
 260 static const char *redact_arg(const char *arg)
 261 {
 262         const char *p, *colon;
 263         size_t at;
 264
 265         if (!trace2_redact ||
 266             (!skip_prefix(arg, "https://", &p) &&
 267              !skip_prefix(arg, "http://", &p)))
 268                 return arg;
 269
 270         at = strcspn(p, "@/");
 271         if (p[at] != '@')
 272                 return arg;
 273
 274         colon = memchr(p, ':', at);
 275         if (!colon)
 276                 return arg;
 277
 278         return xstrfmt("%.*s:<REDACTED>%s", (int)(colon - arg), arg, p + at);
 279 }
 280
 281 /*
 282  * Redacts arguments in an argument list.
 283  *
 284  * Returns the original if nothing needed to be redacted.
 285  * Otherwise, returns a new array that needs to be released
 286  * via `free_redacted_argv()`.
 287  */
 288 static const char **redact_argv(const char **argv)
 289 {
 290         int i, j;
 291         const char *redacted = NULL;
 292         const char **ret;
 293
 294         if (!trace2_redact)
 295                 return argv;
 296
 297         for (i = 0; argv[i]; i++)
 298                 if ((redacted = redact_arg(argv[i])) != argv[i])
 299                         break;
 300
 301         if (!argv[i])
 302                 return argv;
 303
 304         for (j = 0; argv[j]; j++)
 305                 ; /* keep counting */
 306
 307         ALLOC_ARRAY(ret, j + 1);
 308         ret[j] = NULL;
 309
 310         for (j = 0; j < i; j++)
 311                 ret[j] = argv[j];
 312         ret[i] = redacted;
 313         for (++i; argv[i]; i++) {
 314                 redacted = redact_arg(argv[i]);
 315                 ret[i] = redacted ? redacted : argv[i];
 316         }
 317
 318         return ret;
 319 }
 320
 321 static void free_redacted_argv(const char **redacted, const char **argv)
 322 {
 323         int i;
 324
 325         if (redacted != argv) {
 326                 for (i = 0; argv[i]; i++)
 327                         if (redacted[i] != argv[i])
 328                                 free((void *)redacted[i]);
 329                 free((void *)redacted);
 330         }
 331 }
 332
 333 void trace2_cmd_start_fl(const char *file, int line, const char **argv)
 334 {
 335         struct tr2_tgt *tgt_j;
 336         int j;
 337         uint64_t us_now;
 338         uint64_t us_elapsed_absolute;
 339         const char **redacted;
 340
 341         if (!trace2_enabled)
 342                 return;
 343
 344         us_now = getnanotime() / 1000;
 345         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 346
 347         redacted = redact_argv(argv);
 348
 349         for_each_wanted_builtin (j, tgt_j)
 350                 if (tgt_j->pfn_start_fl)
 351                         tgt_j->pfn_start_fl(file, line, us_elapsed_absolute,
 352                                             redacted);
 353
 354         free_redacted_argv(redacted, argv);
 355 }
 356
 357 void trace2_cmd_exit_fl(const char *file, int line, int code)
 358 {
 359         struct tr2_tgt *tgt_j;
 360         int j;
 361         uint64_t us_now;
 362         uint64_t us_elapsed_absolute;
 363
 364         if (!trace2_enabled)
 365                 return;
 366
 367         trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT);
 368
 369         tr2main_exit_code = code;
 370
 371         us_now = getnanotime() / 1000;
 372         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 373
 374         for_each_wanted_builtin (j, tgt_j)
 375                 if (tgt_j->pfn_exit_fl)
 376                         tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
 377                                            code);
 378 }
 379
 380 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
 381                             va_list ap)
 382 {
 383         struct tr2_tgt *tgt_j;
 384         int j;
 385
 386         if (!trace2_enabled)
 387                 return;
 388
 389         /*
 390          * We expect each target function to treat 'ap' as constant
 391          * and use va_copy (because an 'ap' can only be walked once).
 392          */
 393         for_each_wanted_builtin (j, tgt_j)
 394                 if (tgt_j->pfn_error_va_fl)
 395                         tgt_j->pfn_error_va_fl(file, line, fmt, ap);
 396 }
 397
 398 void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
 399 {
 400         struct tr2_tgt *tgt_j;
 401         int j;
 402
 403         if (!trace2_enabled)
 404                 return;
 405
 406         for_each_wanted_builtin (j, tgt_j)
 407                 if (tgt_j->pfn_command_path_fl)
 408                         tgt_j->pfn_command_path_fl(file, line, pathname);
 409 }
 410
 411 void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names)
 412 {
 413         struct tr2_tgt *tgt_j;
 414         int j;
 415
 416         if (!trace2_enabled)
 417                 return;
 418
 419         for_each_wanted_builtin (j, tgt_j)
 420                 if (tgt_j->pfn_command_ancestry_fl)
 421                         tgt_j->pfn_command_ancestry_fl(file, line, parent_names);
 422 }
 423
 424 void trace2_cmd_name_fl(const char *file, int line, const char *name)
 425 {
 426         struct tr2_tgt *tgt_j;
 427         const char *hierarchy;
 428         int j;
 429
 430         if (!trace2_enabled)
 431                 return;
 432
 433         tr2_cmd_name_append_hierarchy(name);
 434         hierarchy = tr2_cmd_name_get_hierarchy();
 435
 436         for_each_wanted_builtin (j, tgt_j)
 437                 if (tgt_j->pfn_command_name_fl)
 438                         tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
 439 }
 440
 441 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
 442 {
 443         struct tr2_tgt *tgt_j;
 444         int j;
 445
 446         if (!trace2_enabled)
 447                 return;
 448
 449         for_each_wanted_builtin (j, tgt_j)
 450                 if (tgt_j->pfn_command_mode_fl)
 451                         tgt_j->pfn_command_mode_fl(file, line, mode);
 452 }
 453
 454 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
 455                          const char **argv)
 456 {
 457         struct tr2_tgt *tgt_j;
 458         int j;
 459
 460         if (!trace2_enabled)
 461                 return;
 462
 463         for_each_wanted_builtin (j, tgt_j)
 464                 if (tgt_j->pfn_alias_fl)
 465                         tgt_j->pfn_alias_fl(file, line, alias, argv);
 466 }
 467
 468 void trace2_cmd_list_config_fl(const char *file, int line)
 469 {
 470         if (!trace2_enabled)
 471                 return;
 472
 473         tr2_cfg_list_config_fl(file, line);
 474 }
 475
 476 void trace2_cmd_list_env_vars_fl(const char *file, int line)
 477 {
 478         if (!trace2_enabled)
 479                 return;
 480
 481         tr2_list_env_vars_fl(file, line);
 482 }
 483
 484 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
 485                               const char *value)
 486 {
 487         if (!trace2_enabled)
 488                 return;
 489
 490         tr2_cfg_set_fl(file, line, key, value);
 491 }
 492
 493 void trace2_child_start_fl(const char *file, int line,
 494                            struct child_process *cmd)
 495 {
 496         struct tr2_tgt *tgt_j;
 497         int j;
 498         uint64_t us_now;
 499         uint64_t us_elapsed_absolute;
 500         const char **orig_argv = cmd->args.v;
 501
 502         if (!trace2_enabled)
 503                 return;
 504
 505         us_now = getnanotime() / 1000;
 506         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 507
 508         cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
 509         cmd->trace2_child_us_start = us_now;
 510
 511         /*
 512          * The `pfn_child_start_fl` API takes a `struct child_process`
 513          * rather than a simple `argv` for the child because some
 514          * targets make use of the additional context bits/values. So
 515          * temporarily replace the original argv (inside the `strvec`)
 516          * with a possibly redacted version.
 517          */
 518         cmd->args.v = redact_argv(orig_argv);
 519
 520         for_each_wanted_builtin (j, tgt_j)
 521                 if (tgt_j->pfn_child_start_fl)
 522                         tgt_j->pfn_child_start_fl(file, line,
 523                                                   us_elapsed_absolute, cmd);
 524
 525         if (cmd->args.v != orig_argv) {
 526                 free_redacted_argv(cmd->args.v, orig_argv);
 527                 cmd->args.v = orig_argv;
 528         }
 529 }
 530
 531 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
 532                           int child_exit_code)
 533 {
 534         struct tr2_tgt *tgt_j;
 535         int j;
 536         uint64_t us_now;
 537         uint64_t us_elapsed_absolute;
 538         uint64_t us_elapsed_child;
 539
 540         if (!trace2_enabled)
 541                 return;
 542
 543         us_now = getnanotime() / 1000;
 544         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 545
 546         if (cmd->trace2_child_us_start)
 547                 us_elapsed_child = us_now - cmd->trace2_child_us_start;
 548         else
 549                 us_elapsed_child = 0;
 550
 551         for_each_wanted_builtin (j, tgt_j)
 552                 if (tgt_j->pfn_child_exit_fl)
 553                         tgt_j->pfn_child_exit_fl(file, line,
 554                                                  us_elapsed_absolute,
 555                                                  cmd->trace2_child_id, cmd->pid,
 556                                                  child_exit_code,
 557                                                  us_elapsed_child);
 558 }
 559
 560 void trace2_child_ready_fl(const char *file, int line,
 561                            struct child_process *cmd,
 562                            const char *ready)
 563 {
 564         struct tr2_tgt *tgt_j;
 565         int j;
 566         uint64_t us_now;
 567         uint64_t us_elapsed_absolute;
 568         uint64_t us_elapsed_child;
 569
 570         if (!trace2_enabled)
 571                 return;
 572
 573         us_now = getnanotime() / 1000;
 574         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 575
 576         if (cmd->trace2_child_us_start)
 577                 us_elapsed_child = us_now - cmd->trace2_child_us_start;
 578         else
 579                 us_elapsed_child = 0;
 580
 581         for_each_wanted_builtin (j, tgt_j)
 582                 if (tgt_j->pfn_child_ready_fl)
 583                         tgt_j->pfn_child_ready_fl(file, line,
 584                                                   us_elapsed_absolute,
 585                                                   cmd->trace2_child_id,
 586                                                   cmd->pid,
 587                                                   ready,
 588                                                   us_elapsed_child);
 589 }
 590
 591 int trace2_exec_fl(const char *file, int line, const char *exe,
 592                    const char **argv)
 593 {
 594         struct tr2_tgt *tgt_j;
 595         int j;
 596         int exec_id;
 597         uint64_t us_now;
 598         uint64_t us_elapsed_absolute;
 599         const char **redacted;
 600
 601         if (!trace2_enabled)
 602                 return -1;
 603
 604         us_now = getnanotime() / 1000;
 605         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 606
 607         exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
 608
 609         redacted = redact_argv(argv);
 610
 611         for_each_wanted_builtin (j, tgt_j)
 612                 if (tgt_j->pfn_exec_fl)
 613                         tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
 614                                            exec_id, exe, redacted);
 615
 616         free_redacted_argv(redacted, argv);
 617
 618         return exec_id;
 619 }
 620
 621 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
 622 {
 623         struct tr2_tgt *tgt_j;
 624         int j;
 625         uint64_t us_now;
 626         uint64_t us_elapsed_absolute;
 627
 628         if (!trace2_enabled)
 629                 return;
 630
 631         us_now = getnanotime() / 1000;
 632         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 633
 634         for_each_wanted_builtin (j, tgt_j)
 635                 if (tgt_j->pfn_exec_result_fl)
 636                         tgt_j->pfn_exec_result_fl(
 637                                 file, line, us_elapsed_absolute, exec_id, code);
 638 }
 639
 640 void trace2_thread_start_fl(const char *file, int line, const char *thread_base_name)
 641 {
 642         struct tr2_tgt *tgt_j;
 643         int j;
 644         uint64_t us_now;
 645         uint64_t us_elapsed_absolute;
 646
 647         if (!trace2_enabled)
 648                 return;
 649
 650         if (tr2tls_is_main_thread()) {
 651                 /*
 652                  * We should only be called from the new thread's thread-proc,
 653                  * so this is technically a bug.  But in those cases where the
 654                  * main thread also runs the thread-proc function (or when we
 655                  * are built with threading disabled), we need to allow it.
 656                  *
 657                  * Convert this call to a region-enter so the nesting looks
 658                  * correct.
 659                  */
 660                 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
 661                                               "thread-proc on main: %s",
 662                                               thread_base_name);
 663                 return;
 664         }
 665
 666         us_now = getnanotime() / 1000;
 667         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 668
 669         tr2tls_create_self(thread_base_name, us_now);
 670
 671         for_each_wanted_builtin (j, tgt_j)
 672                 if (tgt_j->pfn_thread_start_fl)
 673                         tgt_j->pfn_thread_start_fl(file, line,
 674                                                    us_elapsed_absolute);
 675 }
 676
 677 void trace2_thread_exit_fl(const char *file, int line)
 678 {
 679         struct tr2_tgt *tgt_j;
 680         int j;
 681         uint64_t us_now;
 682         uint64_t us_elapsed_absolute;
 683         uint64_t us_elapsed_thread;
 684
 685         if (!trace2_enabled)
 686                 return;
 687
 688         if (tr2tls_is_main_thread()) {
 689                 /*
 690                  * We should only be called from the exiting thread's
 691                  * thread-proc, so this is technically a bug.  But in
 692                  * those cases where the main thread also runs the
 693                  * thread-proc function (or when we are built with
 694                  * threading disabled), we need to allow it.
 695                  *
 696                  * Convert this call to a region-leave so the nesting
 697                  * looks correct.
 698                  */
 699                 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
 700                                               "thread-proc on main");
 701                 return;
 702         }
 703
 704         us_now = getnanotime() / 1000;
 705         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 706
 707         /*
 708          * Clear any unbalanced regions and then get the relative time
 709          * for the outer-most region (which we pushed when the thread
 710          * started).  This gives us the run time of the thread.
 711          */
 712         tr2tls_pop_unwind_self();
 713         us_elapsed_thread = tr2tls_region_elasped_self(us_now);
 714
 715         /*
 716          * Some timers want per-thread details.  If this thread used
 717          * one of those timers, emit the details now.
 718          *
 719          * Likewise for counters.
 720          */
 721         tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
 722         tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
 723
 724         /*
 725          * Add stopwatch timer and counter data from the current
 726          * (non-main) thread to the final totals.  (We'll accumulate
 727          * data for the main thread later during "atexit".)
 728          */
 729         tr2tls_lock();
 730         tr2_update_final_timers();
 731         tr2_update_final_counters();
 732         tr2tls_unlock();
 733
 734         for_each_wanted_builtin (j, tgt_j)
 735                 if (tgt_j->pfn_thread_exit_fl)
 736                         tgt_j->pfn_thread_exit_fl(file, line,
 737                                                   us_elapsed_absolute,
 738                                                   us_elapsed_thread);
 739
 740         tr2tls_unset_self();
 741 }
 742
 743 void trace2_def_param_fl(const char *file, int line, const char *param,
 744                          const char *value, const struct key_value_info *kvi)
 745 {
 746         struct tr2_tgt *tgt_j;
 747         int j;
 748         const char *redacted;
 749
 750         if (!trace2_enabled)
 751                 return;
 752
 753         redacted = redact_arg(value);
 754
 755         for_each_wanted_builtin (j, tgt_j)
 756                 if (tgt_j->pfn_param_fl)
 757                         tgt_j->pfn_param_fl(file, line, param, redacted, kvi);
 758
 759         if (redacted != value)
 760                 free((void *)redacted);
 761 }
 762
 763 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
 764 {
 765         struct tr2_tgt *tgt_j;
 766         int j;
 767
 768         if (!trace2_enabled)
 769                 return;
 770
 771         if (repo->trace2_repo_id)
 772                 return;
 773
 774         repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
 775
 776         for_each_wanted_builtin (j, tgt_j)
 777                 if (tgt_j->pfn_repo_fl)
 778                         tgt_j->pfn_repo_fl(file, line, repo);
 779 }
 780
 781 void trace2_region_enter_printf_va_fl(const char *file, int line,
 782                                       const char *category, const char *label,
 783                                       const struct repository *repo,
 784                                       const char *fmt, va_list ap)
 785 {
 786         struct tr2_tgt *tgt_j;
 787         int j;
 788         uint64_t us_now;
 789         uint64_t us_elapsed_absolute;
 790
 791         if (!trace2_enabled)
 792                 return;
 793
 794         us_now = getnanotime() / 1000;
 795         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 796
 797         /*
 798          * Print the region-enter message at the current nesting
 799          * (indentation) level and then push a new level.
 800          *
 801          * We expect each target function to treat 'ap' as constant
 802          * and use va_copy.
 803          */
 804         for_each_wanted_builtin (j, tgt_j)
 805                 if (tgt_j->pfn_region_enter_printf_va_fl)
 806                         tgt_j->pfn_region_enter_printf_va_fl(
 807                                 file, line, us_elapsed_absolute, category,
 808                                 label, repo, fmt, ap);
 809
 810         tr2tls_push_self(us_now);
 811 }
 812
 813 void trace2_region_enter_fl(const char *file, int line, const char *category,
 814                             const char *label, const struct repository *repo, ...)
 815 {
 816         va_list ap;
 817         va_start(ap, repo);
 818         trace2_region_enter_printf_va_fl(file, line, category, label, repo,
 819                                          NULL, ap);
 820         va_end(ap);
 821
 822 }
 823
 824 void trace2_region_enter_printf_fl(const char *file, int line,
 825                                    const char *category, const char *label,
 826                                    const struct repository *repo,
 827                                    const char *fmt, ...)
 828 {
 829         va_list ap;
 830
 831         va_start(ap, fmt);
 832         trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
 833                                          ap);
 834         va_end(ap);
 835 }
 836
 837 void trace2_region_leave_printf_va_fl(const char *file, int line,
 838                                       const char *category, const char *label,
 839                                       const struct repository *repo,
 840                                       const char *fmt, va_list ap)
 841 {
 842         struct tr2_tgt *tgt_j;
 843         int j;
 844         uint64_t us_now;
 845         uint64_t us_elapsed_absolute;
 846         uint64_t us_elapsed_region;
 847
 848         if (!trace2_enabled)
 849                 return;
 850
 851         us_now = getnanotime() / 1000;
 852         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 853
 854         /*
 855          * Get the elapsed time in the current region before we
 856          * pop it off the stack.  Pop the stack.  And then print
 857          * the perf message at the new (shallower) level so that
 858          * it lines up with the corresponding push/enter.
 859          */
 860         us_elapsed_region = tr2tls_region_elasped_self(us_now);
 861
 862         tr2tls_pop_self();
 863
 864         /*
 865          * We expect each target function to treat 'ap' as constant
 866          * and use va_copy.
 867          */
 868         for_each_wanted_builtin (j, tgt_j)
 869                 if (tgt_j->pfn_region_leave_printf_va_fl)
 870                         tgt_j->pfn_region_leave_printf_va_fl(
 871                                 file, line, us_elapsed_absolute,
 872                                 us_elapsed_region, category, label, repo, fmt,
 873                                 ap);
 874 }
 875
 876 void trace2_region_leave_fl(const char *file, int line, const char *category,
 877                             const char *label, const struct repository *repo, ...)
 878 {
 879         va_list ap;
 880         va_start(ap, repo);
 881         trace2_region_leave_printf_va_fl(file, line, category, label, repo,
 882                                          NULL, ap);
 883         va_end(ap);
 884 }
 885
 886 void trace2_region_leave_printf_fl(const char *file, int line,
 887                                    const char *category, const char *label,
 888                                    const struct repository *repo,
 889                                    const char *fmt, ...)
 890 {
 891         va_list ap;
 892
 893         va_start(ap, fmt);
 894         trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
 895                                          ap);
 896         va_end(ap);
 897 }
 898
 899 void trace2_data_string_fl(const char *file, int line, const char *category,
 900                            const struct repository *repo, const char *key,
 901                            const char *value)
 902 {
 903         struct tr2_tgt *tgt_j;
 904         int j;
 905         uint64_t us_now;
 906         uint64_t us_elapsed_absolute;
 907         uint64_t us_elapsed_region;
 908
 909         if (!trace2_enabled)
 910                 return;
 911
 912         us_now = getnanotime() / 1000;
 913         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 914         us_elapsed_region = tr2tls_region_elasped_self(us_now);
 915
 916         for_each_wanted_builtin (j, tgt_j)
 917                 if (tgt_j->pfn_data_fl)
 918                         tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
 919                                            us_elapsed_region, category, repo,
 920                                            key, value);
 921 }
 922
 923 void trace2_data_intmax_fl(const char *file, int line, const char *category,
 924                            const struct repository *repo, const char *key,
 925                            intmax_t value)
 926 {
 927         struct strbuf buf_string = STRBUF_INIT;
 928
 929         if (!trace2_enabled)
 930                 return;
 931
 932         strbuf_addf(&buf_string, "%" PRIdMAX, value);
 933         trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
 934         strbuf_release(&buf_string);
 935 }
 936
 937 void trace2_data_json_fl(const char *file, int line, const char *category,
 938                          const struct repository *repo, const char *key,
 939                          const struct json_writer *value)
 940 {
 941         struct tr2_tgt *tgt_j;
 942         int j;
 943         uint64_t us_now;
 944         uint64_t us_elapsed_absolute;
 945         uint64_t us_elapsed_region;
 946
 947         if (!trace2_enabled)
 948                 return;
 949
 950         us_now = getnanotime() / 1000;
 951         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 952         us_elapsed_region = tr2tls_region_elasped_self(us_now);
 953
 954         for_each_wanted_builtin (j, tgt_j)
 955                 if (tgt_j->pfn_data_json_fl)
 956                         tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
 957                                                 us_elapsed_region, category,
 958                                                 repo, key, value);
 959 }
 960
 961 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
 962                          va_list ap)
 963 {
 964         struct tr2_tgt *tgt_j;
 965         int j;
 966         uint64_t us_now;
 967         uint64_t us_elapsed_absolute;
 968
 969         if (!trace2_enabled)
 970                 return;
 971
 972         us_now = getnanotime() / 1000;
 973         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 974
 975         /*
 976          * We expect each target function to treat 'ap' as constant
 977          * and use va_copy.
 978          */
 979         for_each_wanted_builtin (j, tgt_j)
 980                 if (tgt_j->pfn_printf_va_fl)
 981                         tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
 982                                                 fmt, ap);
 983 }
 984
 985 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
 986 {
 987         va_list ap;
 988
 989         va_start(ap, fmt);
 990         trace2_printf_va_fl(file, line, fmt, ap);
 991         va_end(ap);
 992 }
 993
 994 void trace2_timer_start(enum trace2_timer_id tid)
 995 {
 996         if (!trace2_enabled)
 997                 return;
 998
 999         if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
1000                 BUG("trace2_timer_start: invalid timer id: %d", tid);
1001
1002         tr2_start_timer(tid);
1003 }
1004
1005 void trace2_timer_stop(enum trace2_timer_id tid)
1006 {
1007         if (!trace2_enabled)
1008                 return;
1009
1010         if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
1011                 BUG("trace2_timer_stop: invalid timer id: %d", tid);
1012
1013         tr2_stop_timer(tid);
1014 }
1015
1016 void trace2_counter_add(enum trace2_counter_id cid, uint64_t value)
1017 {
1018         if (!trace2_enabled)
1019                 return;
1020
1021         if (cid < 0 || cid >= TRACE2_NUMBER_OF_COUNTERS)
1022                 BUG("trace2_counter_add: invalid counter id: %d", cid);
1023
1024         tr2_counter_increment(cid, value);
1025 }
1026
1027 const char *trace2_session_id(void)
1028 {
1029         return tr2_sid_get();
1030 }