1 #include "git-compat-util.h"
3 #include "repository.h"
4 #include "run-command.h"
6 #include "thread-utils.h"
9 #include "trace2/tr2_cfg.h"
10 #include "trace2/tr2_cmd_name.h"
11 #include "trace2/tr2_ctr.h"
12 #include "trace2/tr2_dst.h"
13 #include "trace2/tr2_sid.h"
14 #include "trace2/tr2_sysenv.h"
15 #include "trace2/tr2_tgt.h"
16 #include "trace2/tr2_tls.h"
17 #include "trace2/tr2_tmr.h"
19 static int trace2_enabled
;
21 static int tr2_next_child_id
; /* modify under lock */
22 static int tr2_next_exec_id
; /* modify under lock */
23 static int tr2_next_repo_id
= 1; /* modify under lock. zero is reserved */
26 * A table of the builtin TRACE2 targets. Each of these may be independently
27 * enabled or disabled. Each TRACE2 API method will try to write an event to
28 * *each* of the enabled targets.
30 /* clang-format off */
31 static struct tr2_tgt
*tr2_tgt_builtins
[] =
40 /* clang-format off */
41 #define for_each_builtin(j, tgt_j) \
42 for (j = 0, tgt_j = tr2_tgt_builtins[j]; \
44 j++, tgt_j = tr2_tgt_builtins[j])
47 /* clang-format off */
48 #define for_each_wanted_builtin(j, tgt_j) \
49 for_each_builtin(j, tgt_j) \
50 if (tr2_dst_trace_want(tgt_j->pdst))
54 * Force (rather than lazily) initialize any of the requested
55 * builtin TRACE2 targets at startup (and before we've seen an
56 * actual TRACE2 event call) so we can see if we need to setup
57 * private data structures and thread-local storage.
59 * Return the number of builtin targets enabled.
61 static int tr2_tgt_want_builtins(void)
63 struct tr2_tgt
*tgt_j
;
67 for_each_builtin (j
, tgt_j
)
68 if (tgt_j
->pfn_init())
75 * Properly terminate each builtin target. Give each target
76 * a chance to write a summary event and/or flush if necessary
77 * and then close the fd.
79 static void tr2_tgt_disable_builtins(void)
81 struct tr2_tgt
*tgt_j
;
84 for_each_builtin (j
, tgt_j
)
89 * The signature of this function must match the pfn_timer
90 * method in the targets. (Think of this is an apply operation
91 * across the set of active targets.)
93 static void tr2_tgt_emit_a_timer(const struct tr2_timer_metadata
*meta
,
94 const struct tr2_timer
*timer
,
97 struct tr2_tgt
*tgt_j
;
100 for_each_wanted_builtin (j
, tgt_j
)
101 if (tgt_j
->pfn_timer
)
102 tgt_j
->pfn_timer(meta
, timer
, is_final_data
);
106 * The signature of this function must match the pfn_counter
107 * method in the targets.
109 static void tr2_tgt_emit_a_counter(const struct tr2_counter_metadata
*meta
,
110 const struct tr2_counter
*counter
,
113 struct tr2_tgt
*tgt_j
;
116 for_each_wanted_builtin (j
, tgt_j
)
117 if (tgt_j
->pfn_counter
)
118 tgt_j
->pfn_counter(meta
, counter
, is_final_data
);
121 static int tr2main_exit_code
;
124 * Our atexit routine should run after everything has finished.
126 * Note that events generated here might not actually appear if
127 * we are writing to fd 1 or 2 and our atexit routine runs after
128 * the pager's atexit routine (since it closes them to shutdown
131 static void tr2main_atexit_handler(void)
133 struct tr2_tgt
*tgt_j
;
136 uint64_t us_elapsed_absolute
;
138 us_now
= getnanotime() / 1000;
139 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
142 * Clear any unbalanced regions so that our atexit message
143 * does not appear nested. This improves the appearance of
144 * the trace output if someone calls die(), for example.
146 tr2tls_pop_unwind_self();
149 * Some timers want per-thread details. If the main thread
150 * used one of those timers, emit the details now (before
151 * we emit the aggregate timer values).
153 * Likewise for counters.
155 tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer
);
156 tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter
);
159 * Add stopwatch timer and counter data for the main thread to
160 * the final totals. And then emit the final values.
162 * Technically, we shouldn't need to hold the lock to update
163 * and output the final_timer_block and final_counter_block
164 * (since all other threads should be dead by now), but it
165 * doesn't hurt anything.
168 tr2_update_final_timers();
169 tr2_update_final_counters();
170 tr2_emit_final_timers(tr2_tgt_emit_a_timer
);
171 tr2_emit_final_counters(tr2_tgt_emit_a_counter
);
174 for_each_wanted_builtin (j
, tgt_j
)
175 if (tgt_j
->pfn_atexit
)
176 tgt_j
->pfn_atexit(us_elapsed_absolute
,
179 tr2_tgt_disable_builtins();
183 tr2_cmd_name_release();
184 tr2_cfg_free_patterns();
185 tr2_cfg_free_env_vars();
186 tr2_sysenv_release();
191 static void tr2main_signal_handler(int signo
)
193 struct tr2_tgt
*tgt_j
;
196 uint64_t us_elapsed_absolute
;
198 us_now
= getnanotime() / 1000;
199 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
201 for_each_wanted_builtin (j
, tgt_j
)
202 if (tgt_j
->pfn_signal
)
203 tgt_j
->pfn_signal(us_elapsed_absolute
, signo
);
209 void trace2_initialize_clock(void)
211 tr2tls_start_process_clock();
214 void trace2_initialize_fl(const char *file
, int line
)
216 struct tr2_tgt
*tgt_j
;
224 if (!tr2_tgt_want_builtins())
230 atexit(tr2main_atexit_handler
);
231 sigchain_push(SIGPIPE
, tr2main_signal_handler
);
235 * Emit 'version' message on each active builtin target.
237 for_each_wanted_builtin (j
, tgt_j
)
238 if (tgt_j
->pfn_version_fl
)
239 tgt_j
->pfn_version_fl(file
, line
);
242 int trace2_is_enabled(void)
244 return trace2_enabled
;
247 void trace2_cmd_start_fl(const char *file
, int line
, const char **argv
)
249 struct tr2_tgt
*tgt_j
;
252 uint64_t us_elapsed_absolute
;
257 us_now
= getnanotime() / 1000;
258 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
260 for_each_wanted_builtin (j
, tgt_j
)
261 if (tgt_j
->pfn_start_fl
)
262 tgt_j
->pfn_start_fl(file
, line
, us_elapsed_absolute
,
266 void trace2_cmd_exit_fl(const char *file
, int line
, int code
)
268 struct tr2_tgt
*tgt_j
;
271 uint64_t us_elapsed_absolute
;
276 trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT
);
278 tr2main_exit_code
= code
;
280 us_now
= getnanotime() / 1000;
281 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
283 for_each_wanted_builtin (j
, tgt_j
)
284 if (tgt_j
->pfn_exit_fl
)
285 tgt_j
->pfn_exit_fl(file
, line
, us_elapsed_absolute
,
289 void trace2_cmd_error_va_fl(const char *file
, int line
, const char *fmt
,
292 struct tr2_tgt
*tgt_j
;
299 * We expect each target function to treat 'ap' as constant
300 * and use va_copy (because an 'ap' can only be walked once).
302 for_each_wanted_builtin (j
, tgt_j
)
303 if (tgt_j
->pfn_error_va_fl
)
304 tgt_j
->pfn_error_va_fl(file
, line
, fmt
, ap
);
307 void trace2_cmd_path_fl(const char *file
, int line
, const char *pathname
)
309 struct tr2_tgt
*tgt_j
;
315 for_each_wanted_builtin (j
, tgt_j
)
316 if (tgt_j
->pfn_command_path_fl
)
317 tgt_j
->pfn_command_path_fl(file
, line
, pathname
);
320 void trace2_cmd_ancestry_fl(const char *file
, int line
, const char **parent_names
)
322 struct tr2_tgt
*tgt_j
;
328 for_each_wanted_builtin (j
, tgt_j
)
329 if (tgt_j
->pfn_command_ancestry_fl
)
330 tgt_j
->pfn_command_ancestry_fl(file
, line
, parent_names
);
333 void trace2_cmd_name_fl(const char *file
, int line
, const char *name
)
335 struct tr2_tgt
*tgt_j
;
336 const char *hierarchy
;
342 tr2_cmd_name_append_hierarchy(name
);
343 hierarchy
= tr2_cmd_name_get_hierarchy();
345 for_each_wanted_builtin (j
, tgt_j
)
346 if (tgt_j
->pfn_command_name_fl
)
347 tgt_j
->pfn_command_name_fl(file
, line
, name
, hierarchy
);
350 void trace2_cmd_mode_fl(const char *file
, int line
, const char *mode
)
352 struct tr2_tgt
*tgt_j
;
358 for_each_wanted_builtin (j
, tgt_j
)
359 if (tgt_j
->pfn_command_mode_fl
)
360 tgt_j
->pfn_command_mode_fl(file
, line
, mode
);
363 void trace2_cmd_alias_fl(const char *file
, int line
, const char *alias
,
366 struct tr2_tgt
*tgt_j
;
372 for_each_wanted_builtin (j
, tgt_j
)
373 if (tgt_j
->pfn_alias_fl
)
374 tgt_j
->pfn_alias_fl(file
, line
, alias
, argv
);
377 void trace2_cmd_list_config_fl(const char *file
, int line
)
382 tr2_cfg_list_config_fl(file
, line
);
385 void trace2_cmd_list_env_vars_fl(const char *file
, int line
)
390 tr2_list_env_vars_fl(file
, line
);
393 void trace2_cmd_set_config_fl(const char *file
, int line
, const char *key
,
399 tr2_cfg_set_fl(file
, line
, key
, value
);
402 void trace2_child_start_fl(const char *file
, int line
,
403 struct child_process
*cmd
)
405 struct tr2_tgt
*tgt_j
;
408 uint64_t us_elapsed_absolute
;
413 us_now
= getnanotime() / 1000;
414 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
416 cmd
->trace2_child_id
= tr2tls_locked_increment(&tr2_next_child_id
);
417 cmd
->trace2_child_us_start
= us_now
;
419 for_each_wanted_builtin (j
, tgt_j
)
420 if (tgt_j
->pfn_child_start_fl
)
421 tgt_j
->pfn_child_start_fl(file
, line
,
422 us_elapsed_absolute
, cmd
);
425 void trace2_child_exit_fl(const char *file
, int line
, struct child_process
*cmd
,
428 struct tr2_tgt
*tgt_j
;
431 uint64_t us_elapsed_absolute
;
432 uint64_t us_elapsed_child
;
437 us_now
= getnanotime() / 1000;
438 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
440 if (cmd
->trace2_child_us_start
)
441 us_elapsed_child
= us_now
- cmd
->trace2_child_us_start
;
443 us_elapsed_child
= 0;
445 for_each_wanted_builtin (j
, tgt_j
)
446 if (tgt_j
->pfn_child_exit_fl
)
447 tgt_j
->pfn_child_exit_fl(file
, line
,
449 cmd
->trace2_child_id
, cmd
->pid
,
454 void trace2_child_ready_fl(const char *file
, int line
,
455 struct child_process
*cmd
,
458 struct tr2_tgt
*tgt_j
;
461 uint64_t us_elapsed_absolute
;
462 uint64_t us_elapsed_child
;
467 us_now
= getnanotime() / 1000;
468 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
470 if (cmd
->trace2_child_us_start
)
471 us_elapsed_child
= us_now
- cmd
->trace2_child_us_start
;
473 us_elapsed_child
= 0;
475 for_each_wanted_builtin (j
, tgt_j
)
476 if (tgt_j
->pfn_child_ready_fl
)
477 tgt_j
->pfn_child_ready_fl(file
, line
,
479 cmd
->trace2_child_id
,
485 int trace2_exec_fl(const char *file
, int line
, const char *exe
,
488 struct tr2_tgt
*tgt_j
;
492 uint64_t us_elapsed_absolute
;
497 us_now
= getnanotime() / 1000;
498 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
500 exec_id
= tr2tls_locked_increment(&tr2_next_exec_id
);
502 for_each_wanted_builtin (j
, tgt_j
)
503 if (tgt_j
->pfn_exec_fl
)
504 tgt_j
->pfn_exec_fl(file
, line
, us_elapsed_absolute
,
510 void trace2_exec_result_fl(const char *file
, int line
, int exec_id
, int code
)
512 struct tr2_tgt
*tgt_j
;
515 uint64_t us_elapsed_absolute
;
520 us_now
= getnanotime() / 1000;
521 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
523 for_each_wanted_builtin (j
, tgt_j
)
524 if (tgt_j
->pfn_exec_result_fl
)
525 tgt_j
->pfn_exec_result_fl(
526 file
, line
, us_elapsed_absolute
, exec_id
, code
);
529 void trace2_thread_start_fl(const char *file
, int line
, const char *thread_base_name
)
531 struct tr2_tgt
*tgt_j
;
534 uint64_t us_elapsed_absolute
;
539 if (tr2tls_is_main_thread()) {
541 * We should only be called from the new thread's thread-proc,
542 * so this is technically a bug. But in those cases where the
543 * main thread also runs the thread-proc function (or when we
544 * are built with threading disabled), we need to allow it.
546 * Convert this call to a region-enter so the nesting looks
549 trace2_region_enter_printf_fl(file
, line
, NULL
, NULL
, NULL
,
550 "thread-proc on main: %s",
555 us_now
= getnanotime() / 1000;
556 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
558 tr2tls_create_self(thread_base_name
, us_now
);
560 for_each_wanted_builtin (j
, tgt_j
)
561 if (tgt_j
->pfn_thread_start_fl
)
562 tgt_j
->pfn_thread_start_fl(file
, line
,
563 us_elapsed_absolute
);
566 void trace2_thread_exit_fl(const char *file
, int line
)
568 struct tr2_tgt
*tgt_j
;
571 uint64_t us_elapsed_absolute
;
572 uint64_t us_elapsed_thread
;
577 if (tr2tls_is_main_thread()) {
579 * We should only be called from the exiting thread's
580 * thread-proc, so this is technically a bug. But in
581 * those cases where the main thread also runs the
582 * thread-proc function (or when we are built with
583 * threading disabled), we need to allow it.
585 * Convert this call to a region-leave so the nesting
588 trace2_region_leave_printf_fl(file
, line
, NULL
, NULL
, NULL
,
589 "thread-proc on main");
593 us_now
= getnanotime() / 1000;
594 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
597 * Clear any unbalanced regions and then get the relative time
598 * for the outer-most region (which we pushed when the thread
599 * started). This gives us the run time of the thread.
601 tr2tls_pop_unwind_self();
602 us_elapsed_thread
= tr2tls_region_elasped_self(us_now
);
605 * Some timers want per-thread details. If this thread used
606 * one of those timers, emit the details now.
608 * Likewise for counters.
610 tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer
);
611 tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter
);
614 * Add stopwatch timer and counter data from the current
615 * (non-main) thread to the final totals. (We'll accumulate
616 * data for the main thread later during "atexit".)
619 tr2_update_final_timers();
620 tr2_update_final_counters();
623 for_each_wanted_builtin (j
, tgt_j
)
624 if (tgt_j
->pfn_thread_exit_fl
)
625 tgt_j
->pfn_thread_exit_fl(file
, line
,
632 void trace2_def_param_fl(const char *file
, int line
, const char *param
,
633 const char *value
, const struct key_value_info
*kvi
)
635 struct tr2_tgt
*tgt_j
;
641 for_each_wanted_builtin (j
, tgt_j
)
642 if (tgt_j
->pfn_param_fl
)
643 tgt_j
->pfn_param_fl(file
, line
, param
, value
, kvi
);
646 void trace2_def_repo_fl(const char *file
, int line
, struct repository
*repo
)
648 struct tr2_tgt
*tgt_j
;
654 if (repo
->trace2_repo_id
)
657 repo
->trace2_repo_id
= tr2tls_locked_increment(&tr2_next_repo_id
);
659 for_each_wanted_builtin (j
, tgt_j
)
660 if (tgt_j
->pfn_repo_fl
)
661 tgt_j
->pfn_repo_fl(file
, line
, repo
);
664 void trace2_region_enter_printf_va_fl(const char *file
, int line
,
665 const char *category
, const char *label
,
666 const struct repository
*repo
,
667 const char *fmt
, va_list ap
)
669 struct tr2_tgt
*tgt_j
;
672 uint64_t us_elapsed_absolute
;
677 us_now
= getnanotime() / 1000;
678 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
681 * Print the region-enter message at the current nesting
682 * (indentation) level and then push a new level.
684 * We expect each target function to treat 'ap' as constant
687 for_each_wanted_builtin (j
, tgt_j
)
688 if (tgt_j
->pfn_region_enter_printf_va_fl
)
689 tgt_j
->pfn_region_enter_printf_va_fl(
690 file
, line
, us_elapsed_absolute
, category
,
691 label
, repo
, fmt
, ap
);
693 tr2tls_push_self(us_now
);
696 void trace2_region_enter_fl(const char *file
, int line
, const char *category
,
697 const char *label
, const struct repository
*repo
, ...)
701 trace2_region_enter_printf_va_fl(file
, line
, category
, label
, repo
,
707 void trace2_region_enter_printf_fl(const char *file
, int line
,
708 const char *category
, const char *label
,
709 const struct repository
*repo
,
710 const char *fmt
, ...)
715 trace2_region_enter_printf_va_fl(file
, line
, category
, label
, repo
, fmt
,
720 void trace2_region_leave_printf_va_fl(const char *file
, int line
,
721 const char *category
, const char *label
,
722 const struct repository
*repo
,
723 const char *fmt
, va_list ap
)
725 struct tr2_tgt
*tgt_j
;
728 uint64_t us_elapsed_absolute
;
729 uint64_t us_elapsed_region
;
734 us_now
= getnanotime() / 1000;
735 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
738 * Get the elapsed time in the current region before we
739 * pop it off the stack. Pop the stack. And then print
740 * the perf message at the new (shallower) level so that
741 * it lines up with the corresponding push/enter.
743 us_elapsed_region
= tr2tls_region_elasped_self(us_now
);
748 * We expect each target function to treat 'ap' as constant
751 for_each_wanted_builtin (j
, tgt_j
)
752 if (tgt_j
->pfn_region_leave_printf_va_fl
)
753 tgt_j
->pfn_region_leave_printf_va_fl(
754 file
, line
, us_elapsed_absolute
,
755 us_elapsed_region
, category
, label
, repo
, fmt
,
759 void trace2_region_leave_fl(const char *file
, int line
, const char *category
,
760 const char *label
, const struct repository
*repo
, ...)
764 trace2_region_leave_printf_va_fl(file
, line
, category
, label
, repo
,
769 void trace2_region_leave_printf_fl(const char *file
, int line
,
770 const char *category
, const char *label
,
771 const struct repository
*repo
,
772 const char *fmt
, ...)
777 trace2_region_leave_printf_va_fl(file
, line
, category
, label
, repo
, fmt
,
782 void trace2_data_string_fl(const char *file
, int line
, const char *category
,
783 const struct repository
*repo
, const char *key
,
786 struct tr2_tgt
*tgt_j
;
789 uint64_t us_elapsed_absolute
;
790 uint64_t us_elapsed_region
;
795 us_now
= getnanotime() / 1000;
796 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
797 us_elapsed_region
= tr2tls_region_elasped_self(us_now
);
799 for_each_wanted_builtin (j
, tgt_j
)
800 if (tgt_j
->pfn_data_fl
)
801 tgt_j
->pfn_data_fl(file
, line
, us_elapsed_absolute
,
802 us_elapsed_region
, category
, repo
,
806 void trace2_data_intmax_fl(const char *file
, int line
, const char *category
,
807 const struct repository
*repo
, const char *key
,
810 struct strbuf buf_string
= STRBUF_INIT
;
815 strbuf_addf(&buf_string
, "%" PRIdMAX
, value
);
816 trace2_data_string_fl(file
, line
, category
, repo
, key
, buf_string
.buf
);
817 strbuf_release(&buf_string
);
820 void trace2_data_json_fl(const char *file
, int line
, const char *category
,
821 const struct repository
*repo
, const char *key
,
822 const struct json_writer
*value
)
824 struct tr2_tgt
*tgt_j
;
827 uint64_t us_elapsed_absolute
;
828 uint64_t us_elapsed_region
;
833 us_now
= getnanotime() / 1000;
834 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
835 us_elapsed_region
= tr2tls_region_elasped_self(us_now
);
837 for_each_wanted_builtin (j
, tgt_j
)
838 if (tgt_j
->pfn_data_json_fl
)
839 tgt_j
->pfn_data_json_fl(file
, line
, us_elapsed_absolute
,
840 us_elapsed_region
, category
,
844 void trace2_printf_va_fl(const char *file
, int line
, const char *fmt
,
847 struct tr2_tgt
*tgt_j
;
850 uint64_t us_elapsed_absolute
;
855 us_now
= getnanotime() / 1000;
856 us_elapsed_absolute
= tr2tls_absolute_elapsed(us_now
);
859 * We expect each target function to treat 'ap' as constant
862 for_each_wanted_builtin (j
, tgt_j
)
863 if (tgt_j
->pfn_printf_va_fl
)
864 tgt_j
->pfn_printf_va_fl(file
, line
, us_elapsed_absolute
,
868 void trace2_printf_fl(const char *file
, int line
, const char *fmt
, ...)
873 trace2_printf_va_fl(file
, line
, fmt
, ap
);
877 void trace2_timer_start(enum trace2_timer_id tid
)
882 if (tid
< 0 || tid
>= TRACE2_NUMBER_OF_TIMERS
)
883 BUG("trace2_timer_start: invalid timer id: %d", tid
);
885 tr2_start_timer(tid
);
888 void trace2_timer_stop(enum trace2_timer_id tid
)
893 if (tid
< 0 || tid
>= TRACE2_NUMBER_OF_TIMERS
)
894 BUG("trace2_timer_stop: invalid timer id: %d", tid
);
899 void trace2_counter_add(enum trace2_counter_id cid
, uint64_t value
)
904 if (cid
< 0 || cid
>= TRACE2_NUMBER_OF_COUNTERS
)
905 BUG("trace2_counter_add: invalid counter id: %d", cid
);
907 tr2_counter_increment(cid
, value
);
910 const char *trace2_session_id(void)
912 return tr2_sid_get();