mergetools/bc: add `bc4` to the alias list for Beyond Compare
[git.git] / trace2.c
blob2c6b570077b3980e9ecfeb088d49a125362610f7
1 #include "cache.h"
2 #include "config.h"
3 #include "json-writer.h"
4 #include "quote.h"
5 #include "run-command.h"
6 #include "sigchain.h"
7 #include "thread-utils.h"
8 #include "version.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[] =
31 &tr2_tgt_normal,
32 &tr2_tgt_perf,
33 &tr2_tgt_event,
34 NULL
36 /* clang-format on */
38 /* clang-format off */
39 #define for_each_builtin(j, tgt_j) \
40 for (j = 0, tgt_j = tr2_tgt_builtins[j]; \
41 tgt_j; \
42 j++, tgt_j = tr2_tgt_builtins[j])
43 /* clang-format on */
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))
49 /* clang-format on */
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;
62 int j;
63 int sum = 0;
65 for_each_builtin (j, tgt_j)
66 if (tgt_j->pfn_init())
67 sum++;
69 return sum;
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;
80 int j;
82 for_each_builtin (j, tgt_j)
83 tgt_j->pfn_term();
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
94 * the pipes).
96 static void tr2main_atexit_handler(void)
98 struct tr2_tgt *tgt_j;
99 int j;
100 uint64_t us_now;
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,
116 tr2main_exit_code);
118 tr2_tgt_disable_builtins();
120 tr2tls_release();
121 tr2_sid_release();
122 tr2_cmd_name_release();
123 tr2_cfg_free_patterns();
124 tr2_cfg_free_env_vars();
125 tr2_sysenv_release();
127 trace2_enabled = 0;
130 static void tr2main_signal_handler(int signo)
132 struct tr2_tgt *tgt_j;
133 int j;
134 uint64_t us_now;
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);
144 sigchain_pop(signo);
145 raise(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;
156 int j;
158 if (trace2_enabled)
159 return;
161 tr2_sysenv_load();
163 if (!tr2_tgt_want_builtins())
164 return;
165 trace2_enabled = 1;
167 tr2_sid_get();
169 atexit(tr2main_atexit_handler);
170 sigchain_push(SIGPIPE, tr2main_signal_handler);
171 tr2tls_init();
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;
189 int j;
190 uint64_t us_now;
191 uint64_t us_elapsed_absolute;
193 if (!trace2_enabled)
194 return;
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,
202 argv);
205 int trace2_cmd_exit_fl(const char *file, int line, int code)
207 struct tr2_tgt *tgt_j;
208 int j;
209 uint64_t us_now;
210 uint64_t us_elapsed_absolute;
212 code &= 0xff;
214 if (!trace2_enabled)
215 return code;
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,
227 code);
229 return code;
232 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
233 va_list ap)
235 struct tr2_tgt *tgt_j;
236 int j;
238 if (!trace2_enabled)
239 return;
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;
253 int j;
255 if (!trace2_enabled)
256 return;
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_name_fl(const char *file, int line, const char *name)
265 struct tr2_tgt *tgt_j;
266 const char *hierarchy;
267 int j;
269 if (!trace2_enabled)
270 return;
272 tr2_cmd_name_append_hierarchy(name);
273 hierarchy = tr2_cmd_name_get_hierarchy();
275 for_each_wanted_builtin (j, tgt_j)
276 if (tgt_j->pfn_command_name_fl)
277 tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
280 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
282 struct tr2_tgt *tgt_j;
283 int j;
285 if (!trace2_enabled)
286 return;
288 for_each_wanted_builtin (j, tgt_j)
289 if (tgt_j->pfn_command_mode_fl)
290 tgt_j->pfn_command_mode_fl(file, line, mode);
293 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
294 const char **argv)
296 struct tr2_tgt *tgt_j;
297 int j;
299 if (!trace2_enabled)
300 return;
302 for_each_wanted_builtin (j, tgt_j)
303 if (tgt_j->pfn_alias_fl)
304 tgt_j->pfn_alias_fl(file, line, alias, argv);
307 void trace2_cmd_list_config_fl(const char *file, int line)
309 if (!trace2_enabled)
310 return;
312 tr2_cfg_list_config_fl(file, line);
315 void trace2_cmd_list_env_vars_fl(const char *file, int line)
317 if (!trace2_enabled)
318 return;
320 tr2_list_env_vars_fl(file, line);
323 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
324 const char *value)
326 if (!trace2_enabled)
327 return;
329 tr2_cfg_set_fl(file, line, key, value);
332 void trace2_child_start_fl(const char *file, int line,
333 struct child_process *cmd)
335 struct tr2_tgt *tgt_j;
336 int j;
337 uint64_t us_now;
338 uint64_t us_elapsed_absolute;
340 if (!trace2_enabled)
341 return;
343 us_now = getnanotime() / 1000;
344 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
346 cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
347 cmd->trace2_child_us_start = us_now;
349 for_each_wanted_builtin (j, tgt_j)
350 if (tgt_j->pfn_child_start_fl)
351 tgt_j->pfn_child_start_fl(file, line,
352 us_elapsed_absolute, cmd);
355 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
356 int child_exit_code)
358 struct tr2_tgt *tgt_j;
359 int j;
360 uint64_t us_now;
361 uint64_t us_elapsed_absolute;
362 uint64_t us_elapsed_child;
364 if (!trace2_enabled)
365 return;
367 us_now = getnanotime() / 1000;
368 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
370 if (cmd->trace2_child_us_start)
371 us_elapsed_child = us_now - cmd->trace2_child_us_start;
372 else
373 us_elapsed_child = 0;
375 for_each_wanted_builtin (j, tgt_j)
376 if (tgt_j->pfn_child_exit_fl)
377 tgt_j->pfn_child_exit_fl(file, line,
378 us_elapsed_absolute,
379 cmd->trace2_child_id, cmd->pid,
380 child_exit_code,
381 us_elapsed_child);
384 int trace2_exec_fl(const char *file, int line, const char *exe,
385 const char **argv)
387 struct tr2_tgt *tgt_j;
388 int j;
389 int exec_id;
390 uint64_t us_now;
391 uint64_t us_elapsed_absolute;
393 if (!trace2_enabled)
394 return -1;
396 us_now = getnanotime() / 1000;
397 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
399 exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
401 for_each_wanted_builtin (j, tgt_j)
402 if (tgt_j->pfn_exec_fl)
403 tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
404 exec_id, exe, argv);
406 return exec_id;
409 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
411 struct tr2_tgt *tgt_j;
412 int j;
413 uint64_t us_now;
414 uint64_t us_elapsed_absolute;
416 if (!trace2_enabled)
417 return;
419 us_now = getnanotime() / 1000;
420 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
422 for_each_wanted_builtin (j, tgt_j)
423 if (tgt_j->pfn_exec_result_fl)
424 tgt_j->pfn_exec_result_fl(
425 file, line, us_elapsed_absolute, exec_id, code);
428 void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
430 struct tr2_tgt *tgt_j;
431 int j;
432 uint64_t us_now;
433 uint64_t us_elapsed_absolute;
435 if (!trace2_enabled)
436 return;
438 if (tr2tls_is_main_thread()) {
440 * We should only be called from the new thread's thread-proc,
441 * so this is technically a bug. But in those cases where the
442 * main thread also runs the thread-proc function (or when we
443 * are built with threading disabled), we need to allow it.
445 * Convert this call to a region-enter so the nesting looks
446 * correct.
448 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
449 "thread-proc on main: %s",
450 thread_name);
451 return;
454 us_now = getnanotime() / 1000;
455 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
457 tr2tls_create_self(thread_name, us_now);
459 for_each_wanted_builtin (j, tgt_j)
460 if (tgt_j->pfn_thread_start_fl)
461 tgt_j->pfn_thread_start_fl(file, line,
462 us_elapsed_absolute);
465 void trace2_thread_exit_fl(const char *file, int line)
467 struct tr2_tgt *tgt_j;
468 int j;
469 uint64_t us_now;
470 uint64_t us_elapsed_absolute;
471 uint64_t us_elapsed_thread;
473 if (!trace2_enabled)
474 return;
476 if (tr2tls_is_main_thread()) {
478 * We should only be called from the exiting thread's
479 * thread-proc, so this is technically a bug. But in
480 * those cases where the main thread also runs the
481 * thread-proc function (or when we are built with
482 * threading disabled), we need to allow it.
484 * Convert this call to a region-leave so the nesting
485 * looks correct.
487 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
488 "thread-proc on main");
489 return;
492 us_now = getnanotime() / 1000;
493 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
496 * Clear any unbalanced regions and then get the relative time
497 * for the outer-most region (which we pushed when the thread
498 * started). This gives us the run time of the thread.
500 tr2tls_pop_unwind_self();
501 us_elapsed_thread = tr2tls_region_elasped_self(us_now);
503 for_each_wanted_builtin (j, tgt_j)
504 if (tgt_j->pfn_thread_exit_fl)
505 tgt_j->pfn_thread_exit_fl(file, line,
506 us_elapsed_absolute,
507 us_elapsed_thread);
509 tr2tls_unset_self();
512 void trace2_def_param_fl(const char *file, int line, const char *param,
513 const char *value)
515 struct tr2_tgt *tgt_j;
516 int j;
518 if (!trace2_enabled)
519 return;
521 for_each_wanted_builtin (j, tgt_j)
522 if (tgt_j->pfn_param_fl)
523 tgt_j->pfn_param_fl(file, line, param, value);
526 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
528 struct tr2_tgt *tgt_j;
529 int j;
531 if (!trace2_enabled)
532 return;
534 if (repo->trace2_repo_id)
535 return;
537 repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
539 for_each_wanted_builtin (j, tgt_j)
540 if (tgt_j->pfn_repo_fl)
541 tgt_j->pfn_repo_fl(file, line, repo);
544 void trace2_region_enter_printf_va_fl(const char *file, int line,
545 const char *category, const char *label,
546 const struct repository *repo,
547 const char *fmt, va_list ap)
549 struct tr2_tgt *tgt_j;
550 int j;
551 uint64_t us_now;
552 uint64_t us_elapsed_absolute;
554 if (!trace2_enabled)
555 return;
557 us_now = getnanotime() / 1000;
558 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
561 * Print the region-enter message at the current nesting
562 * (indentation) level and then push a new level.
564 * We expect each target function to treat 'ap' as constant
565 * and use va_copy.
567 for_each_wanted_builtin (j, tgt_j)
568 if (tgt_j->pfn_region_enter_printf_va_fl)
569 tgt_j->pfn_region_enter_printf_va_fl(
570 file, line, us_elapsed_absolute, category,
571 label, repo, fmt, ap);
573 tr2tls_push_self(us_now);
576 void trace2_region_enter_fl(const char *file, int line, const char *category,
577 const char *label, const struct repository *repo, ...)
579 va_list ap;
580 va_start(ap, repo);
581 trace2_region_enter_printf_va_fl(file, line, category, label, repo,
582 NULL, ap);
583 va_end(ap);
587 void trace2_region_enter_printf_fl(const char *file, int line,
588 const char *category, const char *label,
589 const struct repository *repo,
590 const char *fmt, ...)
592 va_list ap;
594 va_start(ap, fmt);
595 trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
596 ap);
597 va_end(ap);
600 #ifndef HAVE_VARIADIC_MACROS
601 void trace2_region_enter_printf(const char *category, const char *label,
602 const struct repository *repo, const char *fmt,
603 ...)
605 va_list ap;
607 va_start(ap, fmt);
608 trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
609 ap);
610 va_end(ap);
612 #endif
614 void trace2_region_leave_printf_va_fl(const char *file, int line,
615 const char *category, const char *label,
616 const struct repository *repo,
617 const char *fmt, va_list ap)
619 struct tr2_tgt *tgt_j;
620 int j;
621 uint64_t us_now;
622 uint64_t us_elapsed_absolute;
623 uint64_t us_elapsed_region;
625 if (!trace2_enabled)
626 return;
628 us_now = getnanotime() / 1000;
629 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
632 * Get the elapsed time in the current region before we
633 * pop it off the stack. Pop the stack. And then print
634 * the perf message at the new (shallower) level so that
635 * it lines up with the corresponding push/enter.
637 us_elapsed_region = tr2tls_region_elasped_self(us_now);
639 tr2tls_pop_self();
642 * We expect each target function to treat 'ap' as constant
643 * and use va_copy.
645 for_each_wanted_builtin (j, tgt_j)
646 if (tgt_j->pfn_region_leave_printf_va_fl)
647 tgt_j->pfn_region_leave_printf_va_fl(
648 file, line, us_elapsed_absolute,
649 us_elapsed_region, category, label, repo, fmt,
650 ap);
653 void trace2_region_leave_fl(const char *file, int line, const char *category,
654 const char *label, const struct repository *repo, ...)
656 va_list ap;
657 va_start(ap, repo);
658 trace2_region_leave_printf_va_fl(file, line, category, label, repo,
659 NULL, ap);
660 va_end(ap);
663 void trace2_region_leave_printf_fl(const char *file, int line,
664 const char *category, const char *label,
665 const struct repository *repo,
666 const char *fmt, ...)
668 va_list ap;
670 va_start(ap, fmt);
671 trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
672 ap);
673 va_end(ap);
676 #ifndef HAVE_VARIADIC_MACROS
677 void trace2_region_leave_printf(const char *category, const char *label,
678 const struct repository *repo, const char *fmt,
679 ...)
681 va_list ap;
683 va_start(ap, fmt);
684 trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
685 ap);
686 va_end(ap);
688 #endif
690 void trace2_data_string_fl(const char *file, int line, const char *category,
691 const struct repository *repo, const char *key,
692 const char *value)
694 struct tr2_tgt *tgt_j;
695 int j;
696 uint64_t us_now;
697 uint64_t us_elapsed_absolute;
698 uint64_t us_elapsed_region;
700 if (!trace2_enabled)
701 return;
703 us_now = getnanotime() / 1000;
704 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
705 us_elapsed_region = tr2tls_region_elasped_self(us_now);
707 for_each_wanted_builtin (j, tgt_j)
708 if (tgt_j->pfn_data_fl)
709 tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
710 us_elapsed_region, category, repo,
711 key, value);
714 void trace2_data_intmax_fl(const char *file, int line, const char *category,
715 const struct repository *repo, const char *key,
716 intmax_t value)
718 struct strbuf buf_string = STRBUF_INIT;
720 if (!trace2_enabled)
721 return;
723 strbuf_addf(&buf_string, "%" PRIdMAX, value);
724 trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
725 strbuf_release(&buf_string);
728 void trace2_data_json_fl(const char *file, int line, const char *category,
729 const struct repository *repo, const char *key,
730 const struct json_writer *value)
732 struct tr2_tgt *tgt_j;
733 int j;
734 uint64_t us_now;
735 uint64_t us_elapsed_absolute;
736 uint64_t us_elapsed_region;
738 if (!trace2_enabled)
739 return;
741 us_now = getnanotime() / 1000;
742 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
743 us_elapsed_region = tr2tls_region_elasped_self(us_now);
745 for_each_wanted_builtin (j, tgt_j)
746 if (tgt_j->pfn_data_json_fl)
747 tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
748 us_elapsed_region, category,
749 repo, key, value);
752 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
753 va_list ap)
755 struct tr2_tgt *tgt_j;
756 int j;
757 uint64_t us_now;
758 uint64_t us_elapsed_absolute;
760 if (!trace2_enabled)
761 return;
763 us_now = getnanotime() / 1000;
764 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
767 * We expect each target function to treat 'ap' as constant
768 * and use va_copy.
770 for_each_wanted_builtin (j, tgt_j)
771 if (tgt_j->pfn_printf_va_fl)
772 tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
773 fmt, ap);
776 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
778 va_list ap;
780 va_start(ap, fmt);
781 trace2_printf_va_fl(file, line, fmt, ap);
782 va_end(ap);
785 #ifndef HAVE_VARIADIC_MACROS
786 void trace2_printf(const char *fmt, ...)
788 va_list ap;
790 va_start(ap, fmt);
791 trace2_printf_va_fl(NULL, 0, fmt, ap);
792 va_end(ap);
794 #endif