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_tgt.h"
14 #include "trace2/tr2_tls.h"
16 static int trace2_enabled;
18 static int tr2_next_child_id; /* modify under lock */
19 static int tr2_next_exec_id; /* modify under lock */
20 static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
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.
27 /* clang-format off */
28 static struct tr2_tgt *tr2_tgt_builtins[] =
37 /* clang-format off */
38 #define for_each_builtin(j, tgt_j) \
39 for (j = 0, tgt_j = tr2_tgt_builtins[j]; \
41 j++, tgt_j = tr2_tgt_builtins[j])
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))
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.
56 * Return the number of builtin targets enabled.
58 static int tr2_tgt_want_builtins(void)
60 struct tr2_tgt *tgt_j;
64 for_each_builtin (j, tgt_j)
65 if (tgt_j->pfn_init())
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.
76 static void tr2_tgt_disable_builtins(void)
78 struct tr2_tgt *tgt_j;
81 for_each_builtin (j, tgt_j)
85 static int tr2main_exit_code;
88 * Our atexit routine should run after everything has finished.
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
95 static void tr2main_atexit_handler(void)
97 struct tr2_tgt *tgt_j;
100 uint64_t us_elapsed_absolute;
102 us_now = getnanotime() / 1000;
103 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
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.
110 tr2tls_pop_unwind_self();
112 for_each_wanted_builtin (j, tgt_j)
113 if (tgt_j->pfn_atexit)
114 tgt_j->pfn_atexit(us_elapsed_absolute,
117 tr2_tgt_disable_builtins();
121 tr2_cmd_name_release();
122 tr2_cfg_free_patterns();
127 static void tr2main_signal_handler(int signo)
129 struct tr2_tgt *tgt_j;
132 uint64_t us_elapsed_absolute;
134 us_now = getnanotime() / 1000;
135 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
137 for_each_wanted_builtin (j, tgt_j)
138 if (tgt_j->pfn_signal)
139 tgt_j->pfn_signal(us_elapsed_absolute, signo);
145 void trace2_initialize_fl(const char *file, int line)
147 struct tr2_tgt *tgt_j;
153 if (!tr2_tgt_want_builtins())
159 atexit(tr2main_atexit_handler);
160 sigchain_push(SIGPIPE, tr2main_signal_handler);
164 * Emit 'version' message on each active builtin target.
166 for_each_wanted_builtin (j, tgt_j)
167 if (tgt_j->pfn_version_fl)
168 tgt_j->pfn_version_fl(file, line);
171 int trace2_is_enabled(void)
173 return trace2_enabled;
176 void trace2_cmd_start_fl(const char *file, int line, const char **argv)
178 struct tr2_tgt *tgt_j;
184 for_each_wanted_builtin (j, tgt_j)
185 if (tgt_j->pfn_start_fl)
186 tgt_j->pfn_start_fl(file, line, argv);
189 int trace2_cmd_exit_fl(const char *file, int line, int code)
191 struct tr2_tgt *tgt_j;
194 uint64_t us_elapsed_absolute;
201 tr2main_exit_code = code;
203 us_now = getnanotime() / 1000;
204 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
206 for_each_wanted_builtin (j, tgt_j)
207 if (tgt_j->pfn_exit_fl)
208 tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
214 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
217 struct tr2_tgt *tgt_j;
224 * We expect each target function to treat 'ap' as constant
225 * and use va_copy (because an 'ap' can only be walked once).
227 for_each_wanted_builtin (j, tgt_j)
228 if (tgt_j->pfn_error_va_fl)
229 tgt_j->pfn_error_va_fl(file, line, fmt, ap);
232 void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
234 struct tr2_tgt *tgt_j;
240 for_each_wanted_builtin (j, tgt_j)
241 if (tgt_j->pfn_command_path_fl)
242 tgt_j->pfn_command_path_fl(file, line, pathname);
245 void trace2_cmd_name_fl(const char *file, int line, const char *name)
247 struct tr2_tgt *tgt_j;
248 const char *hierarchy;
254 tr2_cmd_name_append_hierarchy(name);
255 hierarchy = tr2_cmd_name_get_hierarchy();
257 for_each_wanted_builtin (j, tgt_j)
258 if (tgt_j->pfn_command_name_fl)
259 tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
262 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
264 struct tr2_tgt *tgt_j;
270 for_each_wanted_builtin (j, tgt_j)
271 if (tgt_j->pfn_command_mode_fl)
272 tgt_j->pfn_command_mode_fl(file, line, mode);
275 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
278 struct tr2_tgt *tgt_j;
284 for_each_wanted_builtin (j, tgt_j)
285 if (tgt_j->pfn_alias_fl)
286 tgt_j->pfn_alias_fl(file, line, alias, argv);
289 void trace2_cmd_list_config_fl(const char *file, int line)
294 tr2_cfg_list_config_fl(file, line);
297 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
303 tr2_cfg_set_fl(file, line, key, value);
306 void trace2_child_start_fl(const char *file, int line,
307 struct child_process *cmd)
309 struct tr2_tgt *tgt_j;
312 uint64_t us_elapsed_absolute;
317 us_now = getnanotime() / 1000;
318 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
320 cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
321 cmd->trace2_child_us_start = us_now;
323 for_each_wanted_builtin (j, tgt_j)
324 if (tgt_j->pfn_child_start_fl)
325 tgt_j->pfn_child_start_fl(file, line,
326 us_elapsed_absolute, cmd);
329 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
332 struct tr2_tgt *tgt_j;
335 uint64_t us_elapsed_absolute;
336 uint64_t us_elapsed_child;
341 us_now = getnanotime() / 1000;
342 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
344 if (cmd->trace2_child_us_start)
345 us_elapsed_child = us_now - cmd->trace2_child_us_start;
347 us_elapsed_child = 0;
349 for_each_wanted_builtin (j, tgt_j)
350 if (tgt_j->pfn_child_exit_fl)
351 tgt_j->pfn_child_exit_fl(file, line,
353 cmd->trace2_child_id, cmd->pid,
358 int trace2_exec_fl(const char *file, int line, const char *exe,
361 struct tr2_tgt *tgt_j;
365 uint64_t us_elapsed_absolute;
370 us_now = getnanotime() / 1000;
371 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
373 exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
375 for_each_wanted_builtin (j, tgt_j)
376 if (tgt_j->pfn_exec_fl)
377 tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
383 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
385 struct tr2_tgt *tgt_j;
388 uint64_t us_elapsed_absolute;
393 us_now = getnanotime() / 1000;
394 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
396 for_each_wanted_builtin (j, tgt_j)
397 if (tgt_j->pfn_exec_result_fl)
398 tgt_j->pfn_exec_result_fl(
399 file, line, us_elapsed_absolute, exec_id, code);
402 void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
404 struct tr2_tgt *tgt_j;
407 uint64_t us_elapsed_absolute;
412 if (tr2tls_is_main_thread()) {
414 * We should only be called from the new thread's thread-proc,
415 * so this is technically a bug. But in those cases where the
416 * main thread also runs the thread-proc function (or when we
417 * are built with threading disabled), we need to allow it.
419 * Convert this call to a region-enter so the nesting looks
422 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
423 "thread-proc on main: %s",
428 us_now = getnanotime() / 1000;
429 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
431 tr2tls_create_self(thread_name);
433 for_each_wanted_builtin (j, tgt_j)
434 if (tgt_j->pfn_thread_start_fl)
435 tgt_j->pfn_thread_start_fl(file, line,
436 us_elapsed_absolute);
439 void trace2_thread_exit_fl(const char *file, int line)
441 struct tr2_tgt *tgt_j;
444 uint64_t us_elapsed_absolute;
445 uint64_t us_elapsed_thread;
450 if (tr2tls_is_main_thread()) {
452 * We should only be called from the exiting thread's
453 * thread-proc, so this is technically a bug. But in
454 * those cases where the main thread also runs the
455 * thread-proc function (or when we are built with
456 * threading disabled), we need to allow it.
458 * Convert this call to a region-leave so the nesting
461 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
462 "thread-proc on main");
466 us_now = getnanotime() / 1000;
467 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
470 * Clear any unbalanced regions and then get the relative time
471 * for the outer-most region (which we pushed when the thread
472 * started). This gives us the run time of the thread.
474 tr2tls_pop_unwind_self();
475 us_elapsed_thread = tr2tls_region_elasped_self(us_now);
477 for_each_wanted_builtin (j, tgt_j)
478 if (tgt_j->pfn_thread_exit_fl)
479 tgt_j->pfn_thread_exit_fl(file, line,
486 void trace2_def_param_fl(const char *file, int line, const char *param,
489 struct tr2_tgt *tgt_j;
495 for_each_wanted_builtin (j, tgt_j)
496 if (tgt_j->pfn_param_fl)
497 tgt_j->pfn_param_fl(file, line, param, value);
500 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
502 struct tr2_tgt *tgt_j;
508 if (repo->trace2_repo_id)
511 repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
513 for_each_wanted_builtin (j, tgt_j)
514 if (tgt_j->pfn_repo_fl)
515 tgt_j->pfn_repo_fl(file, line, repo);
518 void trace2_region_enter_printf_va_fl(const char *file, int line,
519 const char *category, const char *label,
520 const struct repository *repo,
521 const char *fmt, va_list ap)
523 struct tr2_tgt *tgt_j;
526 uint64_t us_elapsed_absolute;
531 us_now = getnanotime() / 1000;
532 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
535 * Print the region-enter message at the current nesting
536 * (indentation) level and then push a new level.
538 * We expect each target function to treat 'ap' as constant
541 for_each_wanted_builtin (j, tgt_j)
542 if (tgt_j->pfn_region_enter_printf_va_fl)
543 tgt_j->pfn_region_enter_printf_va_fl(
544 file, line, us_elapsed_absolute, category,
545 label, repo, fmt, ap);
547 tr2tls_push_self(us_now);
550 void trace2_region_enter_fl(const char *file, int line, const char *category,
551 const char *label, const struct repository *repo)
553 trace2_region_enter_printf_va_fl(file, line, category, label, repo,
557 void trace2_region_enter_printf_fl(const char *file, int line,
558 const char *category, const char *label,
559 const struct repository *repo,
560 const char *fmt, ...)
565 trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
570 #ifndef HAVE_VARIADIC_MACROS
571 void trace2_region_enter_printf(const char *category, const char *label,
572 const struct repository *repo, const char *fmt,
578 trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
584 void trace2_region_leave_printf_va_fl(const char *file, int line,
585 const char *category, const char *label,
586 const struct repository *repo,
587 const char *fmt, va_list ap)
589 struct tr2_tgt *tgt_j;
592 uint64_t us_elapsed_absolute;
593 uint64_t us_elapsed_region;
598 us_now = getnanotime() / 1000;
599 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
602 * Get the elapsed time in the current region before we
603 * pop it off the stack. Pop the stack. And then print
604 * the perf message at the new (shallower) level so that
605 * it lines up with the corresponding push/enter.
607 us_elapsed_region = tr2tls_region_elasped_self(us_now);
612 * We expect each target function to treat 'ap' as constant
615 for_each_wanted_builtin (j, tgt_j)
616 if (tgt_j->pfn_region_leave_printf_va_fl)
617 tgt_j->pfn_region_leave_printf_va_fl(
618 file, line, us_elapsed_absolute,
619 us_elapsed_region, category, label, repo, fmt,
623 void trace2_region_leave_fl(const char *file, int line, const char *category,
624 const char *label, const struct repository *repo)
626 trace2_region_leave_printf_va_fl(file, line, category, label, repo,
630 void trace2_region_leave_printf_fl(const char *file, int line,
631 const char *category, const char *label,
632 const struct repository *repo,
633 const char *fmt, ...)
638 trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
643 #ifndef HAVE_VARIADIC_MACROS
644 void trace2_region_leave_printf(const char *category, const char *label,
645 const struct repository *repo, const char *fmt,
651 trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
657 void trace2_data_string_fl(const char *file, int line, const char *category,
658 const struct repository *repo, const char *key,
661 struct tr2_tgt *tgt_j;
664 uint64_t us_elapsed_absolute;
665 uint64_t us_elapsed_region;
670 us_now = getnanotime() / 1000;
671 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
672 us_elapsed_region = tr2tls_region_elasped_self(us_now);
674 for_each_wanted_builtin (j, tgt_j)
675 if (tgt_j->pfn_data_fl)
676 tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
677 us_elapsed_region, category, repo,
681 void trace2_data_intmax_fl(const char *file, int line, const char *category,
682 const struct repository *repo, const char *key,
685 struct strbuf buf_string = STRBUF_INIT;
690 strbuf_addf(&buf_string, "%" PRIdMAX, value);
691 trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
692 strbuf_release(&buf_string);
695 void trace2_data_json_fl(const char *file, int line, const char *category,
696 const struct repository *repo, const char *key,
697 const struct json_writer *value)
699 struct tr2_tgt *tgt_j;
702 uint64_t us_elapsed_absolute;
703 uint64_t us_elapsed_region;
708 us_now = getnanotime() / 1000;
709 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
710 us_elapsed_region = tr2tls_region_elasped_self(us_now);
712 for_each_wanted_builtin (j, tgt_j)
713 if (tgt_j->pfn_data_json_fl)
714 tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
715 us_elapsed_region, category,
719 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
722 struct tr2_tgt *tgt_j;
725 uint64_t us_elapsed_absolute;
730 us_now = getnanotime() / 1000;
731 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
734 * We expect each target function to treat 'ap' as constant
737 for_each_wanted_builtin (j, tgt_j)
738 if (tgt_j->pfn_printf_va_fl)
739 tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
743 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
748 trace2_printf_va_fl(file, line, fmt, ap);
752 #ifndef HAVE_VARIADIC_MACROS
753 void trace2_printf(const char *fmt, ...)
758 trace2_printf_va_fl(NULL, 0, fmt, ap);