trace2.c

   1 #include "cache.h"
   2 #include "config.h"
   3 #include "json-writer.h"
   4 #include "quote.h"
   5 #include "run-command.h"
   6 #include "sigchain.h"
   7 #include "thread-utils.h"
   8 #include "version.h"
   9 #include "trace2/tr2_cfg.h"
  10 #include "trace2/tr2_cmd_name.h"
  11 #include "trace2/tr2_dst.h"
  12 #include "trace2/tr2_sid.h"
  13 #include "trace2/tr2_tgt.h"
  14 #include "trace2/tr2_tls.h"
  15
  16 static int trace2_enabled;
  17
  18 static int tr2_next_child_id; /* modify under lock */
  19 static int tr2_next_exec_id; /* modify under lock */
  20 static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
  21
  22 /*
  23  * A table of the builtin TRACE2 targets.  Each of these may be independently
  24  * enabled or disabled.  Each TRACE2 API method will try to write an event to
  25  * *each* of the enabled targets.
  26  */
  27 /* clang-format off */
  28 static struct tr2_tgt *tr2_tgt_builtins[] =
  29 {
  30         &tr2_tgt_normal,
  31         &tr2_tgt_perf,
  32         &tr2_tgt_event,
  33         NULL
  34 };
  35 /* clang-format on */
  36
  37 /* clang-format off */
  38 #define for_each_builtin(j, tgt_j)                      \
  39         for (j = 0, tgt_j = tr2_tgt_builtins[j];        \
  40              tgt_j;                                     \
  41              j++, tgt_j = tr2_tgt_builtins[j])
  42 /* clang-format on */
  43
  44 /* clang-format off */
  45 #define for_each_wanted_builtin(j, tgt_j)            \
  46         for_each_builtin(j, tgt_j)                   \
  47                 if (tr2_dst_trace_want(tgt_j->pdst))
  48 /* clang-format on */
  49
  50 /*
  51  * Force (rather than lazily) initialize any of the requested
  52  * builtin TRACE2 targets at startup (and before we've seen an
  53  * actual TRACE2 event call) so we can see if we need to setup
  54  * the TR2 and TLS machinery.
  55  *
  56  * Return the number of builtin targets enabled.
  57  */
  58 static int tr2_tgt_want_builtins(void)
  59 {
  60         struct tr2_tgt *tgt_j;
  61         int j;
  62         int sum = 0;
  63
  64         for_each_builtin (j, tgt_j)
  65                 if (tgt_j->pfn_init())
  66                         sum++;
  67
  68         return sum;
  69 }
  70
  71 /*
  72  * Properly terminate each builtin target.  Give each target
  73  * a chance to write a summary event and/or flush if necessary
  74  * and then close the fd.
  75  */
  76 static void tr2_tgt_disable_builtins(void)
  77 {
  78         struct tr2_tgt *tgt_j;
  79         int j;
  80
  81         for_each_builtin (j, tgt_j)
  82                 tgt_j->pfn_term();
  83 }
  84
  85 static int tr2main_exit_code;
  86
  87 /*
  88  * Our atexit routine should run after everything has finished.
  89  *
  90  * Note that events generated here might not actually appear if
  91  * we are writing to fd 1 or 2 and our atexit routine runs after
  92  * the pager's atexit routine (since it closes them to shutdown
  93  * the pipes).
  94  */
  95 static void tr2main_atexit_handler(void)
  96 {
  97         struct tr2_tgt *tgt_j;
  98         int j;
  99         uint64_t us_now;
 100         uint64_t us_elapsed_absolute;
 101
 102         us_now = getnanotime() / 1000;
 103         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 104
 105         /*
 106          * Clear any unbalanced regions so that our atexit message
 107          * does not appear nested.  This improves the appearance of
 108          * the trace output if someone calls die(), for example.
 109          */
 110         tr2tls_pop_unwind_self();
 111
 112         for_each_wanted_builtin (j, tgt_j)
 113                 if (tgt_j->pfn_atexit)
 114                         tgt_j->pfn_atexit(us_elapsed_absolute,
 115                                           tr2main_exit_code);
 116
 117         tr2_tgt_disable_builtins();
 118
 119         tr2tls_release();
 120         tr2_sid_release();
 121         tr2_cmd_name_release();
 122         tr2_cfg_free_patterns();
 123
 124         trace2_enabled = 0;
 125 }
 126
 127 static void tr2main_signal_handler(int signo)
 128 {
 129         struct tr2_tgt *tgt_j;
 130         int j;
 131         uint64_t us_now;
 132         uint64_t us_elapsed_absolute;
 133
 134         us_now = getnanotime() / 1000;
 135         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 136
 137         for_each_wanted_builtin (j, tgt_j)
 138                 if (tgt_j->pfn_signal)
 139                         tgt_j->pfn_signal(us_elapsed_absolute, signo);
 140
 141         sigchain_pop(signo);
 142         raise(signo);
 143 }
 144
 145 void trace2_initialize_clock(void)
 146 {
 147         tr2tls_start_process_clock();
 148 }
 149
 150 void trace2_initialize_fl(const char *file, int line)
 151 {
 152         struct tr2_tgt *tgt_j;
 153         int j;
 154
 155         if (trace2_enabled)
 156                 return;
 157
 158         if (!tr2_tgt_want_builtins())
 159                 return;
 160         trace2_enabled = 1;
 161
 162         tr2_sid_get();
 163
 164         atexit(tr2main_atexit_handler);
 165         sigchain_push(SIGPIPE, tr2main_signal_handler);
 166         tr2tls_init();
 167
 168         /*
 169          * Emit 'version' message on each active builtin target.
 170          */
 171         for_each_wanted_builtin (j, tgt_j)
 172                 if (tgt_j->pfn_version_fl)
 173                         tgt_j->pfn_version_fl(file, line);
 174 }
 175
 176 int trace2_is_enabled(void)
 177 {
 178         return trace2_enabled;
 179 }
 180
 181 void trace2_cmd_start_fl(const char *file, int line, const char **argv)
 182 {
 183         struct tr2_tgt *tgt_j;
 184         int j;
 185         uint64_t us_now;
 186         uint64_t us_elapsed_absolute;
 187
 188         if (!trace2_enabled)
 189                 return;
 190
 191         us_now = getnanotime() / 1000;
 192         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 193
 194         for_each_wanted_builtin (j, tgt_j)
 195                 if (tgt_j->pfn_start_fl)
 196                         tgt_j->pfn_start_fl(file, line, us_elapsed_absolute,
 197                                             argv);
 198 }
 199
 200 int trace2_cmd_exit_fl(const char *file, int line, int code)
 201 {
 202         struct tr2_tgt *tgt_j;
 203         int j;
 204         uint64_t us_now;
 205         uint64_t us_elapsed_absolute;
 206
 207         code &= 0xff;
 208
 209         if (!trace2_enabled)
 210                 return code;
 211
 212         tr2main_exit_code = code;
 213
 214         us_now = getnanotime() / 1000;
 215         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 216
 217         for_each_wanted_builtin (j, tgt_j)
 218                 if (tgt_j->pfn_exit_fl)
 219                         tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
 220                                            code);
 221
 222         return code;
 223 }
 224
 225 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
 226                             va_list ap)
 227 {
 228         struct tr2_tgt *tgt_j;
 229         int j;
 230
 231         if (!trace2_enabled)
 232                 return;
 233
 234         /*
 235          * We expect each target function to treat 'ap' as constant
 236          * and use va_copy (because an 'ap' can only be walked once).
 237          */
 238         for_each_wanted_builtin (j, tgt_j)
 239                 if (tgt_j->pfn_error_va_fl)
 240                         tgt_j->pfn_error_va_fl(file, line, fmt, ap);
 241 }
 242
 243 void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
 244 {
 245         struct tr2_tgt *tgt_j;
 246         int j;
 247
 248         if (!trace2_enabled)
 249                 return;
 250
 251         for_each_wanted_builtin (j, tgt_j)
 252                 if (tgt_j->pfn_command_path_fl)
 253                         tgt_j->pfn_command_path_fl(file, line, pathname);
 254 }
 255
 256 void trace2_cmd_name_fl(const char *file, int line, const char *name)
 257 {
 258         struct tr2_tgt *tgt_j;
 259         const char *hierarchy;
 260         int j;
 261
 262         if (!trace2_enabled)
 263                 return;
 264
 265         tr2_cmd_name_append_hierarchy(name);
 266         hierarchy = tr2_cmd_name_get_hierarchy();
 267
 268         for_each_wanted_builtin (j, tgt_j)
 269                 if (tgt_j->pfn_command_name_fl)
 270                         tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
 271 }
 272
 273 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
 274 {
 275         struct tr2_tgt *tgt_j;
 276         int j;
 277
 278         if (!trace2_enabled)
 279                 return;
 280
 281         for_each_wanted_builtin (j, tgt_j)
 282                 if (tgt_j->pfn_command_mode_fl)
 283                         tgt_j->pfn_command_mode_fl(file, line, mode);
 284 }
 285
 286 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
 287                          const char **argv)
 288 {
 289         struct tr2_tgt *tgt_j;
 290         int j;
 291
 292         if (!trace2_enabled)
 293                 return;
 294
 295         for_each_wanted_builtin (j, tgt_j)
 296                 if (tgt_j->pfn_alias_fl)
 297                         tgt_j->pfn_alias_fl(file, line, alias, argv);
 298 }
 299
 300 void trace2_cmd_list_config_fl(const char *file, int line)
 301 {
 302         if (!trace2_enabled)
 303                 return;
 304
 305         tr2_cfg_list_config_fl(file, line);
 306 }
 307
 308 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
 309                               const char *value)
 310 {
 311         if (!trace2_enabled)
 312                 return;
 313
 314         tr2_cfg_set_fl(file, line, key, value);
 315 }
 316
 317 void trace2_child_start_fl(const char *file, int line,
 318                            struct child_process *cmd)
 319 {
 320         struct tr2_tgt *tgt_j;
 321         int j;
 322         uint64_t us_now;
 323         uint64_t us_elapsed_absolute;
 324
 325         if (!trace2_enabled)
 326                 return;
 327
 328         us_now = getnanotime() / 1000;
 329         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 330
 331         cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
 332         cmd->trace2_child_us_start = us_now;
 333
 334         for_each_wanted_builtin (j, tgt_j)
 335                 if (tgt_j->pfn_child_start_fl)
 336                         tgt_j->pfn_child_start_fl(file, line,
 337                                                   us_elapsed_absolute, cmd);
 338 }
 339
 340 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
 341                           int child_exit_code)
 342 {
 343         struct tr2_tgt *tgt_j;
 344         int j;
 345         uint64_t us_now;
 346         uint64_t us_elapsed_absolute;
 347         uint64_t us_elapsed_child;
 348
 349         if (!trace2_enabled)
 350                 return;
 351
 352         us_now = getnanotime() / 1000;
 353         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 354
 355         if (cmd->trace2_child_us_start)
 356                 us_elapsed_child = us_now - cmd->trace2_child_us_start;
 357         else
 358                 us_elapsed_child = 0;
 359
 360         for_each_wanted_builtin (j, tgt_j)
 361                 if (tgt_j->pfn_child_exit_fl)
 362                         tgt_j->pfn_child_exit_fl(file, line,
 363                                                  us_elapsed_absolute,
 364                                                  cmd->trace2_child_id, cmd->pid,
 365                                                  child_exit_code,
 366                                                  us_elapsed_child);
 367 }
 368
 369 int trace2_exec_fl(const char *file, int line, const char *exe,
 370                    const char **argv)
 371 {
 372         struct tr2_tgt *tgt_j;
 373         int j;
 374         int exec_id;
 375         uint64_t us_now;
 376         uint64_t us_elapsed_absolute;
 377
 378         if (!trace2_enabled)
 379                 return -1;
 380
 381         us_now = getnanotime() / 1000;
 382         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 383
 384         exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
 385
 386         for_each_wanted_builtin (j, tgt_j)
 387                 if (tgt_j->pfn_exec_fl)
 388                         tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
 389                                            exec_id, exe, argv);
 390
 391         return exec_id;
 392 }
 393
 394 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
 395 {
 396         struct tr2_tgt *tgt_j;
 397         int j;
 398         uint64_t us_now;
 399         uint64_t us_elapsed_absolute;
 400
 401         if (!trace2_enabled)
 402                 return;
 403
 404         us_now = getnanotime() / 1000;
 405         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 406
 407         for_each_wanted_builtin (j, tgt_j)
 408                 if (tgt_j->pfn_exec_result_fl)
 409                         tgt_j->pfn_exec_result_fl(
 410                                 file, line, us_elapsed_absolute, exec_id, code);
 411 }
 412
 413 void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
 414 {
 415         struct tr2_tgt *tgt_j;
 416         int j;
 417         uint64_t us_now;
 418         uint64_t us_elapsed_absolute;
 419
 420         if (!trace2_enabled)
 421                 return;
 422
 423         if (tr2tls_is_main_thread()) {
 424                 /*
 425                  * We should only be called from the new thread's thread-proc,
 426                  * so this is technically a bug.  But in those cases where the
 427                  * main thread also runs the thread-proc function (or when we
 428                  * are built with threading disabled), we need to allow it.
 429                  *
 430                  * Convert this call to a region-enter so the nesting looks
 431                  * correct.
 432                  */
 433                 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
 434                                               "thread-proc on main: %s",
 435                                               thread_name);
 436                 return;
 437         }
 438
 439         us_now = getnanotime() / 1000;
 440         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 441
 442         tr2tls_create_self(thread_name, us_now);
 443
 444         for_each_wanted_builtin (j, tgt_j)
 445                 if (tgt_j->pfn_thread_start_fl)
 446                         tgt_j->pfn_thread_start_fl(file, line,
 447                                                    us_elapsed_absolute);
 448 }
 449
 450 void trace2_thread_exit_fl(const char *file, int line)
 451 {
 452         struct tr2_tgt *tgt_j;
 453         int j;
 454         uint64_t us_now;
 455         uint64_t us_elapsed_absolute;
 456         uint64_t us_elapsed_thread;
 457
 458         if (!trace2_enabled)
 459                 return;
 460
 461         if (tr2tls_is_main_thread()) {
 462                 /*
 463                  * We should only be called from the exiting thread's
 464                  * thread-proc, so this is technically a bug.  But in
 465                  * those cases where the main thread also runs the
 466                  * thread-proc function (or when we are built with
 467                  * threading disabled), we need to allow it.
 468                  *
 469                  * Convert this call to a region-leave so the nesting
 470                  * looks correct.
 471                  */
 472                 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
 473                                               "thread-proc on main");
 474                 return;
 475         }
 476
 477         us_now = getnanotime() / 1000;
 478         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 479
 480         /*
 481          * Clear any unbalanced regions and then get the relative time
 482          * for the outer-most region (which we pushed when the thread
 483          * started).  This gives us the run time of the thread.
 484          */
 485         tr2tls_pop_unwind_self();
 486         us_elapsed_thread = tr2tls_region_elasped_self(us_now);
 487
 488         for_each_wanted_builtin (j, tgt_j)
 489                 if (tgt_j->pfn_thread_exit_fl)
 490                         tgt_j->pfn_thread_exit_fl(file, line,
 491                                                   us_elapsed_absolute,
 492                                                   us_elapsed_thread);
 493
 494         tr2tls_unset_self();
 495 }
 496
 497 void trace2_def_param_fl(const char *file, int line, const char *param,
 498                          const char *value)
 499 {
 500         struct tr2_tgt *tgt_j;
 501         int j;
 502
 503         if (!trace2_enabled)
 504                 return;
 505
 506         for_each_wanted_builtin (j, tgt_j)
 507                 if (tgt_j->pfn_param_fl)
 508                         tgt_j->pfn_param_fl(file, line, param, value);
 509 }
 510
 511 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
 512 {
 513         struct tr2_tgt *tgt_j;
 514         int j;
 515
 516         if (!trace2_enabled)
 517                 return;
 518
 519         if (repo->trace2_repo_id)
 520                 return;
 521
 522         repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
 523
 524         for_each_wanted_builtin (j, tgt_j)
 525                 if (tgt_j->pfn_repo_fl)
 526                         tgt_j->pfn_repo_fl(file, line, repo);
 527 }
 528
 529 void trace2_region_enter_printf_va_fl(const char *file, int line,
 530                                       const char *category, const char *label,
 531                                       const struct repository *repo,
 532                                       const char *fmt, va_list ap)
 533 {
 534         struct tr2_tgt *tgt_j;
 535         int j;
 536         uint64_t us_now;
 537         uint64_t us_elapsed_absolute;
 538
 539         if (!trace2_enabled)
 540                 return;
 541
 542         us_now = getnanotime() / 1000;
 543         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 544
 545         /*
 546          * Print the region-enter message at the current nesting
 547          * (indentation) level and then push a new level.
 548          *
 549          * We expect each target function to treat 'ap' as constant
 550          * and use va_copy.
 551          */
 552         for_each_wanted_builtin (j, tgt_j)
 553                 if (tgt_j->pfn_region_enter_printf_va_fl)
 554                         tgt_j->pfn_region_enter_printf_va_fl(
 555                                 file, line, us_elapsed_absolute, category,
 556                                 label, repo, fmt, ap);
 557
 558         tr2tls_push_self(us_now);
 559 }
 560
 561 void trace2_region_enter_fl(const char *file, int line, const char *category,
 562                             const char *label, const struct repository *repo)
 563 {
 564         trace2_region_enter_printf_va_fl(file, line, category, label, repo,
 565                                          NULL, NULL);
 566 }
 567
 568 void trace2_region_enter_printf_fl(const char *file, int line,
 569                                    const char *category, const char *label,
 570                                    const struct repository *repo,
 571                                    const char *fmt, ...)
 572 {
 573         va_list ap;
 574
 575         va_start(ap, fmt);
 576         trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
 577                                          ap);
 578         va_end(ap);
 579 }
 580
 581 #ifndef HAVE_VARIADIC_MACROS
 582 void trace2_region_enter_printf(const char *category, const char *label,
 583                                 const struct repository *repo, const char *fmt,
 584                                 ...)
 585 {
 586         va_list ap;
 587
 588         va_start(ap, fmt);
 589         trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
 590                                          ap);
 591         va_end(ap);
 592 }
 593 #endif
 594
 595 void trace2_region_leave_printf_va_fl(const char *file, int line,
 596                                       const char *category, const char *label,
 597                                       const struct repository *repo,
 598                                       const char *fmt, va_list ap)
 599 {
 600         struct tr2_tgt *tgt_j;
 601         int j;
 602         uint64_t us_now;
 603         uint64_t us_elapsed_absolute;
 604         uint64_t us_elapsed_region;
 605
 606         if (!trace2_enabled)
 607                 return;
 608
 609         us_now = getnanotime() / 1000;
 610         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 611
 612         /*
 613          * Get the elapsed time in the current region before we
 614          * pop it off the stack.  Pop the stack.  And then print
 615          * the perf message at the new (shallower) level so that
 616          * it lines up with the corresponding push/enter.
 617          */
 618         us_elapsed_region = tr2tls_region_elasped_self(us_now);
 619
 620         tr2tls_pop_self();
 621
 622         /*
 623          * We expect each target function to treat 'ap' as constant
 624          * and use va_copy.
 625          */
 626         for_each_wanted_builtin (j, tgt_j)
 627                 if (tgt_j->pfn_region_leave_printf_va_fl)
 628                         tgt_j->pfn_region_leave_printf_va_fl(
 629                                 file, line, us_elapsed_absolute,
 630                                 us_elapsed_region, category, label, repo, fmt,
 631                                 ap);
 632 }
 633
 634 void trace2_region_leave_fl(const char *file, int line, const char *category,
 635                             const char *label, const struct repository *repo)
 636 {
 637         trace2_region_leave_printf_va_fl(file, line, category, label, repo,
 638                                          NULL, NULL);
 639 }
 640
 641 void trace2_region_leave_printf_fl(const char *file, int line,
 642                                    const char *category, const char *label,
 643                                    const struct repository *repo,
 644                                    const char *fmt, ...)
 645 {
 646         va_list ap;
 647
 648         va_start(ap, fmt);
 649         trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
 650                                          ap);
 651         va_end(ap);
 652 }
 653
 654 #ifndef HAVE_VARIADIC_MACROS
 655 void trace2_region_leave_printf(const char *category, const char *label,
 656                                 const struct repository *repo, const char *fmt,
 657                                 ...)
 658 {
 659         va_list ap;
 660
 661         va_start(ap, fmt);
 662         trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
 663                                          ap);
 664         va_end(ap);
 665 }
 666 #endif
 667
 668 void trace2_data_string_fl(const char *file, int line, const char *category,
 669                            const struct repository *repo, const char *key,
 670                            const char *value)
 671 {
 672         struct tr2_tgt *tgt_j;
 673         int j;
 674         uint64_t us_now;
 675         uint64_t us_elapsed_absolute;
 676         uint64_t us_elapsed_region;
 677
 678         if (!trace2_enabled)
 679                 return;
 680
 681         us_now = getnanotime() / 1000;
 682         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 683         us_elapsed_region = tr2tls_region_elasped_self(us_now);
 684
 685         for_each_wanted_builtin (j, tgt_j)
 686                 if (tgt_j->pfn_data_fl)
 687                         tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
 688                                            us_elapsed_region, category, repo,
 689                                            key, value);
 690 }
 691
 692 void trace2_data_intmax_fl(const char *file, int line, const char *category,
 693                            const struct repository *repo, const char *key,
 694                            intmax_t value)
 695 {
 696         struct strbuf buf_string = STRBUF_INIT;
 697
 698         if (!trace2_enabled)
 699                 return;
 700
 701         strbuf_addf(&buf_string, "%" PRIdMAX, value);
 702         trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
 703         strbuf_release(&buf_string);
 704 }
 705
 706 void trace2_data_json_fl(const char *file, int line, const char *category,
 707                          const struct repository *repo, const char *key,
 708                          const struct json_writer *value)
 709 {
 710         struct tr2_tgt *tgt_j;
 711         int j;
 712         uint64_t us_now;
 713         uint64_t us_elapsed_absolute;
 714         uint64_t us_elapsed_region;
 715
 716         if (!trace2_enabled)
 717                 return;
 718
 719         us_now = getnanotime() / 1000;
 720         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 721         us_elapsed_region = tr2tls_region_elasped_self(us_now);
 722
 723         for_each_wanted_builtin (j, tgt_j)
 724                 if (tgt_j->pfn_data_fl)
 725                         tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
 726                                                 us_elapsed_region, category,
 727                                                 repo, key, value);
 728 }
 729
 730 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
 731                          va_list ap)
 732 {
 733         struct tr2_tgt *tgt_j;
 734         int j;
 735         uint64_t us_now;
 736         uint64_t us_elapsed_absolute;
 737
 738         if (!trace2_enabled)
 739                 return;
 740
 741         us_now = getnanotime() / 1000;
 742         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
 743
 744         /*
 745          * We expect each target function to treat 'ap' as constant
 746          * and use va_copy.
 747          */
 748         for_each_wanted_builtin (j, tgt_j)
 749                 if (tgt_j->pfn_printf_va_fl)
 750                         tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
 751                                                 fmt, ap);
 752 }
 753
 754 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
 755 {
 756         va_list ap;
 757
 758         va_start(ap, fmt);
 759         trace2_printf_va_fl(file, line, fmt, ap);
 760         va_end(ap);
 761 }
 762
 763 #ifndef HAVE_VARIADIC_MACROS
 764 void trace2_printf(const char *fmt, ...)
 765 {
 766         va_list ap;
 767
 768         va_start(ap, fmt);
 769         trace2_printf_va_fl(NULL, 0, fmt, ap);
 770         va_end(ap);
 771 }
 772 #endif