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