3 #include "json-writer.h"
5 #include "run-command.h"
7 #include "thread-utils.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_sysenv.h"
14 #include "trace2/tr2_tgt.h"
15 #include "trace2/tr2_tls.h"
17 static int trace2_enabled;
19 static int tr2_next_child_id; /* modify under lock */
20 static int tr2_next_exec_id; /* modify under lock */
21 static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
24 * A table of the builtin TRACE2 targets. Each of these may be independently
25 * enabled or disabled. Each TRACE2 API method will try to write an event to
26 * *each* of the enabled targets.
28 /* clang-format off */
29 static struct tr2_tgt *tr2_tgt_builtins[] =
38 /* clang-format off */
39 #define for_each_builtin(j, tgt_j) \
40 for (j = 0, tgt_j = tr2_tgt_builtins[j]; \
42 j++, tgt_j = tr2_tgt_builtins[j])
45 /* clang-format off */
46 #define for_each_wanted_builtin(j, tgt_j) \
47 for_each_builtin(j, tgt_j) \
48 if (tr2_dst_trace_want(tgt_j->pdst))
52 * Force (rather than lazily) initialize any of the requested
53 * builtin TRACE2 targets at startup (and before we've seen an
54 * actual TRACE2 event call) so we can see if we need to setup
55 * the TR2 and TLS machinery.
57 * Return the number of builtin targets enabled.
59 static int tr2_tgt_want_builtins(void)
61 struct tr2_tgt *tgt_j;
65 for_each_builtin (j, tgt_j)
66 if (tgt_j->pfn_init())
73 * Properly terminate each builtin target. Give each target
74 * a chance to write a summary event and/or flush if necessary
75 * and then close the fd.
77 static void tr2_tgt_disable_builtins(void)
79 struct tr2_tgt *tgt_j;
82 for_each_builtin (j, tgt_j)
86 static int tr2main_exit_code;
89 * Our atexit routine should run after everything has finished.
91 * Note that events generated here might not actually appear if
92 * we are writing to fd 1 or 2 and our atexit routine runs after
93 * the pager's atexit routine (since it closes them to shutdown
96 static void tr2main_atexit_handler(void)
98 struct tr2_tgt *tgt_j;
101 uint64_t us_elapsed_absolute;
103 us_now = getnanotime() / 1000;
104 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
107 * Clear any unbalanced regions so that our atexit message
108 * does not appear nested. This improves the appearance of
109 * the trace output if someone calls die(), for example.
111 tr2tls_pop_unwind_self();
113 for_each_wanted_builtin (j, tgt_j)
114 if (tgt_j->pfn_atexit)
115 tgt_j->pfn_atexit(us_elapsed_absolute,
118 tr2_tgt_disable_builtins();
122 tr2_cmd_name_release();
123 tr2_cfg_free_patterns();
124 tr2_sysenv_release();
129 static void tr2main_signal_handler(int signo)
131 struct tr2_tgt *tgt_j;
134 uint64_t us_elapsed_absolute;
136 us_now = getnanotime() / 1000;
137 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
139 for_each_wanted_builtin (j, tgt_j)
140 if (tgt_j->pfn_signal)
141 tgt_j->pfn_signal(us_elapsed_absolute, signo);
147 void trace2_initialize_clock(void)
149 tr2tls_start_process_clock();
152 void trace2_initialize_fl(const char *file, int line)
154 struct tr2_tgt *tgt_j;
162 if (!tr2_tgt_want_builtins())
168 atexit(tr2main_atexit_handler);
169 sigchain_push(SIGPIPE, tr2main_signal_handler);
173 * Emit 'version' message on each active builtin target.
175 for_each_wanted_builtin (j, tgt_j)
176 if (tgt_j->pfn_version_fl)
177 tgt_j->pfn_version_fl(file, line);
180 int trace2_is_enabled(void)
182 return trace2_enabled;
185 void trace2_cmd_start_fl(const char *file, int line, const char **argv)
187 struct tr2_tgt *tgt_j;
190 uint64_t us_elapsed_absolute;
195 us_now = getnanotime() / 1000;
196 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
198 for_each_wanted_builtin (j, tgt_j)
199 if (tgt_j->pfn_start_fl)
200 tgt_j->pfn_start_fl(file, line, us_elapsed_absolute,
204 int trace2_cmd_exit_fl(const char *file, int line, int code)
206 struct tr2_tgt *tgt_j;
209 uint64_t us_elapsed_absolute;
216 trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT);
218 tr2main_exit_code = code;
220 us_now = getnanotime() / 1000;
221 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
223 for_each_wanted_builtin (j, tgt_j)
224 if (tgt_j->pfn_exit_fl)
225 tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
231 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
234 struct tr2_tgt *tgt_j;
241 * We expect each target function to treat 'ap' as constant
242 * and use va_copy (because an 'ap' can only be walked once).
244 for_each_wanted_builtin (j, tgt_j)
245 if (tgt_j->pfn_error_va_fl)
246 tgt_j->pfn_error_va_fl(file, line, fmt, ap);
249 void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
251 struct tr2_tgt *tgt_j;
257 for_each_wanted_builtin (j, tgt_j)
258 if (tgt_j->pfn_command_path_fl)
259 tgt_j->pfn_command_path_fl(file, line, pathname);
262 void trace2_cmd_name_fl(const char *file, int line, const char *name)
264 struct tr2_tgt *tgt_j;
265 const char *hierarchy;
271 tr2_cmd_name_append_hierarchy(name);
272 hierarchy = tr2_cmd_name_get_hierarchy();
274 for_each_wanted_builtin (j, tgt_j)
275 if (tgt_j->pfn_command_name_fl)
276 tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
279 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
281 struct tr2_tgt *tgt_j;
287 for_each_wanted_builtin (j, tgt_j)
288 if (tgt_j->pfn_command_mode_fl)
289 tgt_j->pfn_command_mode_fl(file, line, mode);
292 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
295 struct tr2_tgt *tgt_j;
301 for_each_wanted_builtin (j, tgt_j)
302 if (tgt_j->pfn_alias_fl)
303 tgt_j->pfn_alias_fl(file, line, alias, argv);
306 void trace2_cmd_list_config_fl(const char *file, int line)
311 tr2_cfg_list_config_fl(file, line);
314 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
320 tr2_cfg_set_fl(file, line, key, value);
323 void trace2_child_start_fl(const char *file, int line,
324 struct child_process *cmd)
326 struct tr2_tgt *tgt_j;
329 uint64_t us_elapsed_absolute;
334 us_now = getnanotime() / 1000;
335 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
337 cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
338 cmd->trace2_child_us_start = us_now;
340 for_each_wanted_builtin (j, tgt_j)
341 if (tgt_j->pfn_child_start_fl)
342 tgt_j->pfn_child_start_fl(file, line,
343 us_elapsed_absolute, cmd);
346 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
349 struct tr2_tgt *tgt_j;
352 uint64_t us_elapsed_absolute;
353 uint64_t us_elapsed_child;
358 us_now = getnanotime() / 1000;
359 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
361 if (cmd->trace2_child_us_start)
362 us_elapsed_child = us_now - cmd->trace2_child_us_start;
364 us_elapsed_child = 0;
366 for_each_wanted_builtin (j, tgt_j)
367 if (tgt_j->pfn_child_exit_fl)
368 tgt_j->pfn_child_exit_fl(file, line,
370 cmd->trace2_child_id, cmd->pid,
375 int trace2_exec_fl(const char *file, int line, const char *exe,
378 struct tr2_tgt *tgt_j;
382 uint64_t us_elapsed_absolute;
387 us_now = getnanotime() / 1000;
388 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
390 exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
392 for_each_wanted_builtin (j, tgt_j)
393 if (tgt_j->pfn_exec_fl)
394 tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
400 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
402 struct tr2_tgt *tgt_j;
405 uint64_t us_elapsed_absolute;
410 us_now = getnanotime() / 1000;
411 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
413 for_each_wanted_builtin (j, tgt_j)
414 if (tgt_j->pfn_exec_result_fl)
415 tgt_j->pfn_exec_result_fl(
416 file, line, us_elapsed_absolute, exec_id, code);
419 void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
421 struct tr2_tgt *tgt_j;
424 uint64_t us_elapsed_absolute;
429 if (tr2tls_is_main_thread()) {
431 * We should only be called from the new thread's thread-proc,
432 * so this is technically a bug. But in those cases where the
433 * main thread also runs the thread-proc function (or when we
434 * are built with threading disabled), we need to allow it.
436 * Convert this call to a region-enter so the nesting looks
439 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
440 "thread-proc on main: %s",
445 us_now = getnanotime() / 1000;
446 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
448 tr2tls_create_self(thread_name, us_now);
450 for_each_wanted_builtin (j, tgt_j)
451 if (tgt_j->pfn_thread_start_fl)
452 tgt_j->pfn_thread_start_fl(file, line,
453 us_elapsed_absolute);
456 void trace2_thread_exit_fl(const char *file, int line)
458 struct tr2_tgt *tgt_j;
461 uint64_t us_elapsed_absolute;
462 uint64_t us_elapsed_thread;
467 if (tr2tls_is_main_thread()) {
469 * We should only be called from the exiting thread's
470 * thread-proc, so this is technically a bug. But in
471 * those cases where the main thread also runs the
472 * thread-proc function (or when we are built with
473 * threading disabled), we need to allow it.
475 * Convert this call to a region-leave so the nesting
478 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
479 "thread-proc on main");
483 us_now = getnanotime() / 1000;
484 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
487 * Clear any unbalanced regions and then get the relative time
488 * for the outer-most region (which we pushed when the thread
489 * started). This gives us the run time of the thread.
491 tr2tls_pop_unwind_self();
492 us_elapsed_thread = tr2tls_region_elasped_self(us_now);
494 for_each_wanted_builtin (j, tgt_j)
495 if (tgt_j->pfn_thread_exit_fl)
496 tgt_j->pfn_thread_exit_fl(file, line,
503 void trace2_def_param_fl(const char *file, int line, const char *param,
506 struct tr2_tgt *tgt_j;
512 for_each_wanted_builtin (j, tgt_j)
513 if (tgt_j->pfn_param_fl)
514 tgt_j->pfn_param_fl(file, line, param, value);
517 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
519 struct tr2_tgt *tgt_j;
525 if (repo->trace2_repo_id)
528 repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
530 for_each_wanted_builtin (j, tgt_j)
531 if (tgt_j->pfn_repo_fl)
532 tgt_j->pfn_repo_fl(file, line, repo);
535 void trace2_region_enter_printf_va_fl(const char *file, int line,
536 const char *category, const char *label,
537 const struct repository *repo,
538 const char *fmt, va_list ap)
540 struct tr2_tgt *tgt_j;
543 uint64_t us_elapsed_absolute;
548 us_now = getnanotime() / 1000;
549 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
552 * Print the region-enter message at the current nesting
553 * (indentation) level and then push a new level.
555 * We expect each target function to treat 'ap' as constant
558 for_each_wanted_builtin (j, tgt_j)
559 if (tgt_j->pfn_region_enter_printf_va_fl)
560 tgt_j->pfn_region_enter_printf_va_fl(
561 file, line, us_elapsed_absolute, category,
562 label, repo, fmt, ap);
564 tr2tls_push_self(us_now);
567 void trace2_region_enter_fl(const char *file, int line, const char *category,
568 const char *label, const struct repository *repo, ...)
572 trace2_region_enter_printf_va_fl(file, line, category, label, repo,
578 void trace2_region_enter_printf_fl(const char *file, int line,
579 const char *category, const char *label,
580 const struct repository *repo,
581 const char *fmt, ...)
586 trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
591 #ifndef HAVE_VARIADIC_MACROS
592 void trace2_region_enter_printf(const char *category, const char *label,
593 const struct repository *repo, const char *fmt,
599 trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
605 void trace2_region_leave_printf_va_fl(const char *file, int line,
606 const char *category, const char *label,
607 const struct repository *repo,
608 const char *fmt, va_list ap)
610 struct tr2_tgt *tgt_j;
613 uint64_t us_elapsed_absolute;
614 uint64_t us_elapsed_region;
619 us_now = getnanotime() / 1000;
620 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
623 * Get the elapsed time in the current region before we
624 * pop it off the stack. Pop the stack. And then print
625 * the perf message at the new (shallower) level so that
626 * it lines up with the corresponding push/enter.
628 us_elapsed_region = tr2tls_region_elasped_self(us_now);
633 * We expect each target function to treat 'ap' as constant
636 for_each_wanted_builtin (j, tgt_j)
637 if (tgt_j->pfn_region_leave_printf_va_fl)
638 tgt_j->pfn_region_leave_printf_va_fl(
639 file, line, us_elapsed_absolute,
640 us_elapsed_region, category, label, repo, fmt,
644 void trace2_region_leave_fl(const char *file, int line, const char *category,
645 const char *label, const struct repository *repo, ...)
649 trace2_region_leave_printf_va_fl(file, line, category, label, repo,
654 void trace2_region_leave_printf_fl(const char *file, int line,
655 const char *category, const char *label,
656 const struct repository *repo,
657 const char *fmt, ...)
662 trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
667 #ifndef HAVE_VARIADIC_MACROS
668 void trace2_region_leave_printf(const char *category, const char *label,
669 const struct repository *repo, const char *fmt,
675 trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
681 void trace2_data_string_fl(const char *file, int line, const char *category,
682 const struct repository *repo, const char *key,
685 struct tr2_tgt *tgt_j;
688 uint64_t us_elapsed_absolute;
689 uint64_t us_elapsed_region;
694 us_now = getnanotime() / 1000;
695 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
696 us_elapsed_region = tr2tls_region_elasped_self(us_now);
698 for_each_wanted_builtin (j, tgt_j)
699 if (tgt_j->pfn_data_fl)
700 tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
701 us_elapsed_region, category, repo,
705 void trace2_data_intmax_fl(const char *file, int line, const char *category,
706 const struct repository *repo, const char *key,
709 struct strbuf buf_string = STRBUF_INIT;
714 strbuf_addf(&buf_string, "%" PRIdMAX, value);
715 trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
716 strbuf_release(&buf_string);
719 void trace2_data_json_fl(const char *file, int line, const char *category,
720 const struct repository *repo, const char *key,
721 const struct json_writer *value)
723 struct tr2_tgt *tgt_j;
726 uint64_t us_elapsed_absolute;
727 uint64_t us_elapsed_region;
732 us_now = getnanotime() / 1000;
733 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
734 us_elapsed_region = tr2tls_region_elasped_self(us_now);
736 for_each_wanted_builtin (j, tgt_j)
737 if (tgt_j->pfn_data_json_fl)
738 tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
739 us_elapsed_region, category,
743 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
746 struct tr2_tgt *tgt_j;
749 uint64_t us_elapsed_absolute;
754 us_now = getnanotime() / 1000;
755 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
758 * We expect each target function to treat 'ap' as constant
761 for_each_wanted_builtin (j, tgt_j)
762 if (tgt_j->pfn_printf_va_fl)
763 tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
767 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
772 trace2_printf_va_fl(file, line, fmt, ap);
776 #ifndef HAVE_VARIADIC_MACROS
777 void trace2_printf(const char *fmt, ...)
782 trace2_printf_va_fl(NULL, 0, fmt, ap);