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_cfg_free_env_vars();
125 tr2_sysenv_release();
130 static void tr2main_signal_handler(int signo)
132 struct tr2_tgt *tgt_j;
135 uint64_t us_elapsed_absolute;
137 us_now = getnanotime() / 1000;
138 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
140 for_each_wanted_builtin (j, tgt_j)
141 if (tgt_j->pfn_signal)
142 tgt_j->pfn_signal(us_elapsed_absolute, signo);
148 void trace2_initialize_clock(void)
150 tr2tls_start_process_clock();
153 void trace2_initialize_fl(const char *file, int line)
155 struct tr2_tgt *tgt_j;
163 if (!tr2_tgt_want_builtins())
169 atexit(tr2main_atexit_handler);
170 sigchain_push(SIGPIPE, tr2main_signal_handler);
174 * Emit 'version' message on each active builtin target.
176 for_each_wanted_builtin (j, tgt_j)
177 if (tgt_j->pfn_version_fl)
178 tgt_j->pfn_version_fl(file, line);
181 int trace2_is_enabled(void)
183 return trace2_enabled;
186 void trace2_cmd_start_fl(const char *file, int line, const char **argv)
188 struct tr2_tgt *tgt_j;
191 uint64_t us_elapsed_absolute;
196 us_now = getnanotime() / 1000;
197 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
199 for_each_wanted_builtin (j, tgt_j)
200 if (tgt_j->pfn_start_fl)
201 tgt_j->pfn_start_fl(file, line, us_elapsed_absolute,
205 int trace2_cmd_exit_fl(const char *file, int line, int code)
207 struct tr2_tgt *tgt_j;
210 uint64_t us_elapsed_absolute;
217 trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT);
219 tr2main_exit_code = code;
221 us_now = getnanotime() / 1000;
222 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
224 for_each_wanted_builtin (j, tgt_j)
225 if (tgt_j->pfn_exit_fl)
226 tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
232 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
235 struct tr2_tgt *tgt_j;
242 * We expect each target function to treat 'ap' as constant
243 * and use va_copy (because an 'ap' can only be walked once).
245 for_each_wanted_builtin (j, tgt_j)
246 if (tgt_j->pfn_error_va_fl)
247 tgt_j->pfn_error_va_fl(file, line, fmt, ap);
250 void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
252 struct tr2_tgt *tgt_j;
258 for_each_wanted_builtin (j, tgt_j)
259 if (tgt_j->pfn_command_path_fl)
260 tgt_j->pfn_command_path_fl(file, line, pathname);
263 void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names)
265 struct tr2_tgt *tgt_j;
271 for_each_wanted_builtin (j, tgt_j)
272 if (tgt_j->pfn_command_ancestry_fl)
273 tgt_j->pfn_command_ancestry_fl(file, line, parent_names);
276 void trace2_cmd_name_fl(const char *file, int line, const char *name)
278 struct tr2_tgt *tgt_j;
279 const char *hierarchy;
285 tr2_cmd_name_append_hierarchy(name);
286 hierarchy = tr2_cmd_name_get_hierarchy();
288 for_each_wanted_builtin (j, tgt_j)
289 if (tgt_j->pfn_command_name_fl)
290 tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
293 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
295 struct tr2_tgt *tgt_j;
301 for_each_wanted_builtin (j, tgt_j)
302 if (tgt_j->pfn_command_mode_fl)
303 tgt_j->pfn_command_mode_fl(file, line, mode);
306 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
309 struct tr2_tgt *tgt_j;
315 for_each_wanted_builtin (j, tgt_j)
316 if (tgt_j->pfn_alias_fl)
317 tgt_j->pfn_alias_fl(file, line, alias, argv);
320 void trace2_cmd_list_config_fl(const char *file, int line)
325 tr2_cfg_list_config_fl(file, line);
328 void trace2_cmd_list_env_vars_fl(const char *file, int line)
333 tr2_list_env_vars_fl(file, line);
336 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
342 tr2_cfg_set_fl(file, line, key, value);
345 void trace2_child_start_fl(const char *file, int line,
346 struct child_process *cmd)
348 struct tr2_tgt *tgt_j;
351 uint64_t us_elapsed_absolute;
356 us_now = getnanotime() / 1000;
357 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
359 cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
360 cmd->trace2_child_us_start = us_now;
362 for_each_wanted_builtin (j, tgt_j)
363 if (tgt_j->pfn_child_start_fl)
364 tgt_j->pfn_child_start_fl(file, line,
365 us_elapsed_absolute, cmd);
368 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
371 struct tr2_tgt *tgt_j;
374 uint64_t us_elapsed_absolute;
375 uint64_t us_elapsed_child;
380 us_now = getnanotime() / 1000;
381 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
383 if (cmd->trace2_child_us_start)
384 us_elapsed_child = us_now - cmd->trace2_child_us_start;
386 us_elapsed_child = 0;
388 for_each_wanted_builtin (j, tgt_j)
389 if (tgt_j->pfn_child_exit_fl)
390 tgt_j->pfn_child_exit_fl(file, line,
392 cmd->trace2_child_id, cmd->pid,
397 int trace2_exec_fl(const char *file, int line, const char *exe,
400 struct tr2_tgt *tgt_j;
404 uint64_t us_elapsed_absolute;
409 us_now = getnanotime() / 1000;
410 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
412 exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
414 for_each_wanted_builtin (j, tgt_j)
415 if (tgt_j->pfn_exec_fl)
416 tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
422 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
424 struct tr2_tgt *tgt_j;
427 uint64_t us_elapsed_absolute;
432 us_now = getnanotime() / 1000;
433 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
435 for_each_wanted_builtin (j, tgt_j)
436 if (tgt_j->pfn_exec_result_fl)
437 tgt_j->pfn_exec_result_fl(
438 file, line, us_elapsed_absolute, exec_id, code);
441 void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
443 struct tr2_tgt *tgt_j;
446 uint64_t us_elapsed_absolute;
451 if (tr2tls_is_main_thread()) {
453 * We should only be called from the new thread's thread-proc,
454 * so this is technically a bug. But in those cases where the
455 * main thread also runs the thread-proc function (or when we
456 * are built with threading disabled), we need to allow it.
458 * Convert this call to a region-enter so the nesting looks
461 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
462 "thread-proc on main: %s",
467 us_now = getnanotime() / 1000;
468 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
470 tr2tls_create_self(thread_name, us_now);
472 for_each_wanted_builtin (j, tgt_j)
473 if (tgt_j->pfn_thread_start_fl)
474 tgt_j->pfn_thread_start_fl(file, line,
475 us_elapsed_absolute);
478 void trace2_thread_exit_fl(const char *file, int line)
480 struct tr2_tgt *tgt_j;
483 uint64_t us_elapsed_absolute;
484 uint64_t us_elapsed_thread;
489 if (tr2tls_is_main_thread()) {
491 * We should only be called from the exiting thread's
492 * thread-proc, so this is technically a bug. But in
493 * those cases where the main thread also runs the
494 * thread-proc function (or when we are built with
495 * threading disabled), we need to allow it.
497 * Convert this call to a region-leave so the nesting
500 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
501 "thread-proc on main");
505 us_now = getnanotime() / 1000;
506 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
509 * Clear any unbalanced regions and then get the relative time
510 * for the outer-most region (which we pushed when the thread
511 * started). This gives us the run time of the thread.
513 tr2tls_pop_unwind_self();
514 us_elapsed_thread = tr2tls_region_elasped_self(us_now);
516 for_each_wanted_builtin (j, tgt_j)
517 if (tgt_j->pfn_thread_exit_fl)
518 tgt_j->pfn_thread_exit_fl(file, line,
525 void trace2_def_param_fl(const char *file, int line, const char *param,
528 struct tr2_tgt *tgt_j;
534 for_each_wanted_builtin (j, tgt_j)
535 if (tgt_j->pfn_param_fl)
536 tgt_j->pfn_param_fl(file, line, param, value);
539 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
541 struct tr2_tgt *tgt_j;
547 if (repo->trace2_repo_id)
550 repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
552 for_each_wanted_builtin (j, tgt_j)
553 if (tgt_j->pfn_repo_fl)
554 tgt_j->pfn_repo_fl(file, line, repo);
557 void trace2_region_enter_printf_va_fl(const char *file, int line,
558 const char *category, const char *label,
559 const struct repository *repo,
560 const char *fmt, va_list ap)
562 struct tr2_tgt *tgt_j;
565 uint64_t us_elapsed_absolute;
570 us_now = getnanotime() / 1000;
571 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
574 * Print the region-enter message at the current nesting
575 * (indentation) level and then push a new level.
577 * We expect each target function to treat 'ap' as constant
580 for_each_wanted_builtin (j, tgt_j)
581 if (tgt_j->pfn_region_enter_printf_va_fl)
582 tgt_j->pfn_region_enter_printf_va_fl(
583 file, line, us_elapsed_absolute, category,
584 label, repo, fmt, ap);
586 tr2tls_push_self(us_now);
589 void trace2_region_enter_fl(const char *file, int line, const char *category,
590 const char *label, const struct repository *repo, ...)
594 trace2_region_enter_printf_va_fl(file, line, category, label, repo,
600 void trace2_region_enter_printf_fl(const char *file, int line,
601 const char *category, const char *label,
602 const struct repository *repo,
603 const char *fmt, ...)
608 trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
613 #ifndef HAVE_VARIADIC_MACROS
614 void trace2_region_enter_printf(const char *category, const char *label,
615 const struct repository *repo, const char *fmt,
621 trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
627 void trace2_region_leave_printf_va_fl(const char *file, int line,
628 const char *category, const char *label,
629 const struct repository *repo,
630 const char *fmt, va_list ap)
632 struct tr2_tgt *tgt_j;
635 uint64_t us_elapsed_absolute;
636 uint64_t us_elapsed_region;
641 us_now = getnanotime() / 1000;
642 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
645 * Get the elapsed time in the current region before we
646 * pop it off the stack. Pop the stack. And then print
647 * the perf message at the new (shallower) level so that
648 * it lines up with the corresponding push/enter.
650 us_elapsed_region = tr2tls_region_elasped_self(us_now);
655 * We expect each target function to treat 'ap' as constant
658 for_each_wanted_builtin (j, tgt_j)
659 if (tgt_j->pfn_region_leave_printf_va_fl)
660 tgt_j->pfn_region_leave_printf_va_fl(
661 file, line, us_elapsed_absolute,
662 us_elapsed_region, category, label, repo, fmt,
666 void trace2_region_leave_fl(const char *file, int line, const char *category,
667 const char *label, const struct repository *repo, ...)
671 trace2_region_leave_printf_va_fl(file, line, category, label, repo,
676 void trace2_region_leave_printf_fl(const char *file, int line,
677 const char *category, const char *label,
678 const struct repository *repo,
679 const char *fmt, ...)
684 trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
689 #ifndef HAVE_VARIADIC_MACROS
690 void trace2_region_leave_printf(const char *category, const char *label,
691 const struct repository *repo, const char *fmt,
697 trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
703 void trace2_data_string_fl(const char *file, int line, const char *category,
704 const struct repository *repo, const char *key,
707 struct tr2_tgt *tgt_j;
710 uint64_t us_elapsed_absolute;
711 uint64_t us_elapsed_region;
716 us_now = getnanotime() / 1000;
717 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
718 us_elapsed_region = tr2tls_region_elasped_self(us_now);
720 for_each_wanted_builtin (j, tgt_j)
721 if (tgt_j->pfn_data_fl)
722 tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
723 us_elapsed_region, category, repo,
727 void trace2_data_intmax_fl(const char *file, int line, const char *category,
728 const struct repository *repo, const char *key,
731 struct strbuf buf_string = STRBUF_INIT;
736 strbuf_addf(&buf_string, "%" PRIdMAX, value);
737 trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
738 strbuf_release(&buf_string);
741 void trace2_data_json_fl(const char *file, int line, const char *category,
742 const struct repository *repo, const char *key,
743 const struct json_writer *value)
745 struct tr2_tgt *tgt_j;
748 uint64_t us_elapsed_absolute;
749 uint64_t us_elapsed_region;
754 us_now = getnanotime() / 1000;
755 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
756 us_elapsed_region = tr2tls_region_elasped_self(us_now);
758 for_each_wanted_builtin (j, tgt_j)
759 if (tgt_j->pfn_data_json_fl)
760 tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
761 us_elapsed_region, category,
765 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
768 struct tr2_tgt *tgt_j;
771 uint64_t us_elapsed_absolute;
776 us_now = getnanotime() / 1000;
777 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
780 * We expect each target function to treat 'ap' as constant
783 for_each_wanted_builtin (j, tgt_j)
784 if (tgt_j->pfn_printf_va_fl)
785 tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
789 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
794 trace2_printf_va_fl(file, line, fmt, ap);
798 #ifndef HAVE_VARIADIC_MACROS
799 void trace2_printf(const char *fmt, ...)
804 trace2_printf_va_fl(NULL, 0, fmt, ap);
809 const char *trace2_session_id(void)
811 return tr2_sid_get();