trace2.con commit trace2: add absolute elapsed time to start event (39f4317)
   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
  16static int trace2_enabled;
  17
  18static int tr2_next_child_id; /* modify under lock */
  19static int tr2_next_exec_id; /* modify under lock */
  20static 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 */
  28static 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 */
  58static 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 */
  76static 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
  85static 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 */
  95static 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
 127static 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
 145void trace2_initialize_clock(void)
 146{
 147        tr2tls_start_process_clock();
 148}
 149
 150void 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
 176int trace2_is_enabled(void)
 177{
 178        return trace2_enabled;
 179}
 180
 181void 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
 200int 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
 225void 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
 243void 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
 256void 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
 273void 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
 286void 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
 300void 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
 308void 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
 317void 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
 340void 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
 369int 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
 394void 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
 413void 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
 450void 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
 497void 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
 511void 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
 529void 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
 561void 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
 568void 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
 582void 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
 595void 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
 634void 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
 641void 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
 655void 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
 668void 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
 692void 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
 706void 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
 730void 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
 754void 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
 764void 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