blob: 82d16e2783d98690a72934f873f145fc890d5f1a [file] [log] [blame]
Patrick Steinhardt41f43b82024-12-06 11:27:19 +01001#define DISABLE_SIGN_COMPARE_WARNINGS
2
Elijah Newren15db4e72023-02-24 00:09:23 +00003#include "git-compat-util.h"
Jeff Hostetleree4512e2019-02-22 14:25:01 -08004#include "config.h"
Elijah Newrend1cbe1e2023-04-22 20:17:20 +00005#include "repository.h"
Jeff Hostetleree4512e2019-02-22 14:25:01 -08006#include "run-command.h"
7#include "sigchain.h"
8#include "thread-utils.h"
Elijah Newren15db4e72023-02-24 00:09:23 +00009#include "trace.h"
Elijah Newren74ea5c92023-04-11 03:00:38 +000010#include "trace2.h"
Jeff Hostetleree4512e2019-02-22 14:25:01 -080011#include "trace2/tr2_cfg.h"
12#include "trace2/tr2_cmd_name.h"
Jeff Hostetler81071622022-10-24 13:41:07 +000013#include "trace2/tr2_ctr.h"
Jeff Hostetleree4512e2019-02-22 14:25:01 -080014#include "trace2/tr2_dst.h"
15#include "trace2/tr2_sid.h"
Jeff Hostetlerbce9db62019-04-15 13:39:47 -070016#include "trace2/tr2_sysenv.h"
Jeff Hostetleree4512e2019-02-22 14:25:01 -080017#include "trace2/tr2_tgt.h"
18#include "trace2/tr2_tls.h"
Jeff Hostetler8ad57562022-10-24 13:41:06 +000019#include "trace2/tr2_tmr.h"
Jeff Hostetleree4512e2019-02-22 14:25:01 -080020
21static int trace2_enabled;
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +000022static int trace2_redact = 1;
Jeff Hostetleree4512e2019-02-22 14:25:01 -080023
24static int tr2_next_child_id; /* modify under lock */
25static int tr2_next_exec_id; /* modify under lock */
26static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
27
28/*
29 * A table of the builtin TRACE2 targets. Each of these may be independently
30 * enabled or disabled. Each TRACE2 API method will try to write an event to
31 * *each* of the enabled targets.
32 */
33/* clang-format off */
34static struct tr2_tgt *tr2_tgt_builtins[] =
35{
36 &tr2_tgt_normal,
37 &tr2_tgt_perf,
38 &tr2_tgt_event,
39 NULL
40};
41/* clang-format on */
42
43/* clang-format off */
44#define for_each_builtin(j, tgt_j) \
45 for (j = 0, tgt_j = tr2_tgt_builtins[j]; \
46 tgt_j; \
47 j++, tgt_j = tr2_tgt_builtins[j])
48/* clang-format on */
49
50/* clang-format off */
51#define for_each_wanted_builtin(j, tgt_j) \
52 for_each_builtin(j, tgt_j) \
53 if (tr2_dst_trace_want(tgt_j->pdst))
54/* clang-format on */
55
56/*
57 * Force (rather than lazily) initialize any of the requested
58 * builtin TRACE2 targets at startup (and before we've seen an
59 * actual TRACE2 event call) so we can see if we need to setup
Jeff Hostetler5bbb9252022-10-24 13:41:01 +000060 * private data structures and thread-local storage.
Jeff Hostetleree4512e2019-02-22 14:25:01 -080061 *
62 * Return the number of builtin targets enabled.
63 */
64static int tr2_tgt_want_builtins(void)
65{
66 struct tr2_tgt *tgt_j;
67 int j;
68 int sum = 0;
69
70 for_each_builtin (j, tgt_j)
71 if (tgt_j->pfn_init())
72 sum++;
73
74 return sum;
75}
76
77/*
78 * Properly terminate each builtin target. Give each target
79 * a chance to write a summary event and/or flush if necessary
80 * and then close the fd.
81 */
82static void tr2_tgt_disable_builtins(void)
83{
84 struct tr2_tgt *tgt_j;
85 int j;
86
87 for_each_builtin (j, tgt_j)
88 tgt_j->pfn_term();
89}
90
Jeff Hostetler8ad57562022-10-24 13:41:06 +000091/*
92 * The signature of this function must match the pfn_timer
93 * method in the targets. (Think of this is an apply operation
94 * across the set of active targets.)
95 */
96static void tr2_tgt_emit_a_timer(const struct tr2_timer_metadata *meta,
97 const struct tr2_timer *timer,
98 int is_final_data)
99{
100 struct tr2_tgt *tgt_j;
101 int j;
102
103 for_each_wanted_builtin (j, tgt_j)
104 if (tgt_j->pfn_timer)
105 tgt_j->pfn_timer(meta, timer, is_final_data);
106}
107
Jeff Hostetler81071622022-10-24 13:41:07 +0000108/*
109 * The signature of this function must match the pfn_counter
110 * method in the targets.
111 */
112static void tr2_tgt_emit_a_counter(const struct tr2_counter_metadata *meta,
113 const struct tr2_counter *counter,
114 int is_final_data)
115{
116 struct tr2_tgt *tgt_j;
117 int j;
118
119 for_each_wanted_builtin (j, tgt_j)
120 if (tgt_j->pfn_counter)
121 tgt_j->pfn_counter(meta, counter, is_final_data);
122}
123
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800124static int tr2main_exit_code;
125
126/*
127 * Our atexit routine should run after everything has finished.
128 *
129 * Note that events generated here might not actually appear if
130 * we are writing to fd 1 or 2 and our atexit routine runs after
131 * the pager's atexit routine (since it closes them to shutdown
132 * the pipes).
133 */
134static void tr2main_atexit_handler(void)
135{
136 struct tr2_tgt *tgt_j;
137 int j;
138 uint64_t us_now;
139 uint64_t us_elapsed_absolute;
140
141 us_now = getnanotime() / 1000;
142 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
143
144 /*
145 * Clear any unbalanced regions so that our atexit message
146 * does not appear nested. This improves the appearance of
147 * the trace output if someone calls die(), for example.
148 */
149 tr2tls_pop_unwind_self();
150
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000151 /*
152 * Some timers want per-thread details. If the main thread
153 * used one of those timers, emit the details now (before
154 * we emit the aggregate timer values).
Jeff Hostetler81071622022-10-24 13:41:07 +0000155 *
156 * Likewise for counters.
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000157 */
158 tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
Jeff Hostetler81071622022-10-24 13:41:07 +0000159 tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000160
161 /*
Jeff Hostetler81071622022-10-24 13:41:07 +0000162 * Add stopwatch timer and counter data for the main thread to
163 * the final totals. And then emit the final values.
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000164 *
165 * Technically, we shouldn't need to hold the lock to update
Jeff Hostetler81071622022-10-24 13:41:07 +0000166 * and output the final_timer_block and final_counter_block
167 * (since all other threads should be dead by now), but it
168 * doesn't hurt anything.
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000169 */
170 tr2tls_lock();
171 tr2_update_final_timers();
Jeff Hostetler81071622022-10-24 13:41:07 +0000172 tr2_update_final_counters();
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000173 tr2_emit_final_timers(tr2_tgt_emit_a_timer);
Jeff Hostetler81071622022-10-24 13:41:07 +0000174 tr2_emit_final_counters(tr2_tgt_emit_a_counter);
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000175 tr2tls_unlock();
176
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800177 for_each_wanted_builtin (j, tgt_j)
178 if (tgt_j->pfn_atexit)
179 tgt_j->pfn_atexit(us_elapsed_absolute,
180 tr2main_exit_code);
181
182 tr2_tgt_disable_builtins();
183
184 tr2tls_release();
185 tr2_sid_release();
186 tr2_cmd_name_release();
187 tr2_cfg_free_patterns();
Josh Steadmon3d3adaa2020-03-20 14:06:15 -0700188 tr2_cfg_free_env_vars();
Jeff Hostetlerbce9db62019-04-15 13:39:47 -0700189 tr2_sysenv_release();
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800190
191 trace2_enabled = 0;
192}
193
194static void tr2main_signal_handler(int signo)
195{
196 struct tr2_tgt *tgt_j;
197 int j;
198 uint64_t us_now;
199 uint64_t us_elapsed_absolute;
200
201 us_now = getnanotime() / 1000;
202 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
203
204 for_each_wanted_builtin (j, tgt_j)
205 if (tgt_j->pfn_signal)
206 tgt_j->pfn_signal(us_elapsed_absolute, signo);
207
208 sigchain_pop(signo);
209 raise(signo);
210}
211
Jeff Hostetlera0897242019-04-15 13:39:43 -0700212void trace2_initialize_clock(void)
213{
214 tr2tls_start_process_clock();
215}
216
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800217void trace2_initialize_fl(const char *file, int line)
218{
219 struct tr2_tgt *tgt_j;
220 int j;
221
222 if (trace2_enabled)
223 return;
224
Jeff Hostetlerbce9db62019-04-15 13:39:47 -0700225 tr2_sysenv_load();
226
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800227 if (!tr2_tgt_want_builtins())
228 return;
229 trace2_enabled = 1;
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000230 if (!git_env_bool("GIT_TRACE2_REDACT", 1))
231 trace2_redact = 0;
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800232
233 tr2_sid_get();
234
235 atexit(tr2main_atexit_handler);
236 sigchain_push(SIGPIPE, tr2main_signal_handler);
237 tr2tls_init();
238
239 /*
240 * Emit 'version' message on each active builtin target.
241 */
242 for_each_wanted_builtin (j, tgt_j)
243 if (tgt_j->pfn_version_fl)
244 tgt_j->pfn_version_fl(file, line);
245}
246
247int trace2_is_enabled(void)
248{
249 return trace2_enabled;
250}
251
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000252/*
253 * Redacts an argument, i.e. ensures that no password in
254 * https://user:password@host/-style URLs is logged.
255 *
256 * Returns the original if nothing needed to be redacted.
257 * Returns a pointer that needs to be `free()`d otherwise.
258 */
259static const char *redact_arg(const char *arg)
260{
261 const char *p, *colon;
262 size_t at;
263
264 if (!trace2_redact ||
265 (!skip_prefix(arg, "https://", &p) &&
266 !skip_prefix(arg, "http://", &p)))
267 return arg;
268
269 at = strcspn(p, "@/");
270 if (p[at] != '@')
271 return arg;
272
273 colon = memchr(p, ':', at);
274 if (!colon)
275 return arg;
276
277 return xstrfmt("%.*s:<REDACTED>%s", (int)(colon - arg), arg, p + at);
278}
279
280/*
281 * Redacts arguments in an argument list.
282 *
283 * Returns the original if nothing needed to be redacted.
284 * Otherwise, returns a new array that needs to be released
285 * via `free_redacted_argv()`.
286 */
287static const char **redact_argv(const char **argv)
288{
289 int i, j;
290 const char *redacted = NULL;
291 const char **ret;
292
293 if (!trace2_redact)
294 return argv;
295
296 for (i = 0; argv[i]; i++)
297 if ((redacted = redact_arg(argv[i])) != argv[i])
298 break;
299
300 if (!argv[i])
301 return argv;
302
303 for (j = 0; argv[j]; j++)
304 ; /* keep counting */
305
306 ALLOC_ARRAY(ret, j + 1);
307 ret[j] = NULL;
308
309 for (j = 0; j < i; j++)
310 ret[j] = argv[j];
311 ret[i] = redacted;
312 for (++i; argv[i]; i++) {
313 redacted = redact_arg(argv[i]);
314 ret[i] = redacted ? redacted : argv[i];
315 }
316
317 return ret;
318}
319
320static void free_redacted_argv(const char **redacted, const char **argv)
321{
322 int i;
323
324 if (redacted != argv) {
325 for (i = 0; argv[i]; i++)
326 if (redacted[i] != argv[i])
327 free((void *)redacted[i]);
328 free((void *)redacted);
329 }
330}
331
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800332void trace2_cmd_start_fl(const char *file, int line, const char **argv)
333{
334 struct tr2_tgt *tgt_j;
335 int j;
Jeff Hostetler39f43172019-04-15 13:39:44 -0700336 uint64_t us_now;
337 uint64_t us_elapsed_absolute;
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000338 const char **redacted;
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800339
340 if (!trace2_enabled)
341 return;
342
Jeff Hostetler39f43172019-04-15 13:39:44 -0700343 us_now = getnanotime() / 1000;
344 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
345
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000346 redacted = redact_argv(argv);
347
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800348 for_each_wanted_builtin (j, tgt_j)
349 if (tgt_j->pfn_start_fl)
Jeff Hostetler39f43172019-04-15 13:39:44 -0700350 tgt_j->pfn_start_fl(file, line, us_elapsed_absolute,
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000351 redacted);
352
353 free_redacted_argv(redacted, argv);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800354}
355
Ævar Arnfjörð Bjarmason19d75942022-06-02 14:25:32 +0200356void trace2_cmd_exit_fl(const char *file, int line, int code)
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800357{
358 struct tr2_tgt *tgt_j;
359 int j;
360 uint64_t us_now;
361 uint64_t us_elapsed_absolute;
362
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800363 if (!trace2_enabled)
Ævar Arnfjörð Bjarmason19d75942022-06-02 14:25:32 +0200364 return;
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800365
Jeff Hostetler26c6f252019-04-15 13:39:48 -0700366 trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT);
367
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800368 tr2main_exit_code = code;
369
370 us_now = getnanotime() / 1000;
371 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
372
373 for_each_wanted_builtin (j, tgt_j)
374 if (tgt_j->pfn_exit_fl)
375 tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
376 code);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800377}
378
379void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
380 va_list ap)
381{
382 struct tr2_tgt *tgt_j;
383 int j;
384
385 if (!trace2_enabled)
386 return;
387
388 /*
389 * We expect each target function to treat 'ap' as constant
390 * and use va_copy (because an 'ap' can only be walked once).
391 */
392 for_each_wanted_builtin (j, tgt_j)
393 if (tgt_j->pfn_error_va_fl)
394 tgt_j->pfn_error_va_fl(file, line, fmt, ap);
395}
396
397void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
398{
399 struct tr2_tgt *tgt_j;
400 int j;
401
402 if (!trace2_enabled)
403 return;
404
405 for_each_wanted_builtin (j, tgt_j)
406 if (tgt_j->pfn_command_path_fl)
407 tgt_j->pfn_command_path_fl(file, line, pathname);
408}
409
Emily Shaffer2f732bf2021-07-21 18:27:07 -0700410void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names)
411{
412 struct tr2_tgt *tgt_j;
413 int j;
414
415 if (!trace2_enabled)
416 return;
417
418 for_each_wanted_builtin (j, tgt_j)
419 if (tgt_j->pfn_command_ancestry_fl)
420 tgt_j->pfn_command_ancestry_fl(file, line, parent_names);
421}
422
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800423void trace2_cmd_name_fl(const char *file, int line, const char *name)
424{
425 struct tr2_tgt *tgt_j;
426 const char *hierarchy;
427 int j;
428
429 if (!trace2_enabled)
430 return;
431
432 tr2_cmd_name_append_hierarchy(name);
433 hierarchy = tr2_cmd_name_get_hierarchy();
434
435 for_each_wanted_builtin (j, tgt_j)
436 if (tgt_j->pfn_command_name_fl)
437 tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
Jeff Hostetler61112522024-03-07 15:22:29 +0000438
439 trace2_cmd_list_config();
440 trace2_cmd_list_env_vars();
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800441}
442
443void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
444{
445 struct tr2_tgt *tgt_j;
446 int j;
447
448 if (!trace2_enabled)
449 return;
450
451 for_each_wanted_builtin (j, tgt_j)
452 if (tgt_j->pfn_command_mode_fl)
453 tgt_j->pfn_command_mode_fl(file, line, mode);
454}
455
456void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
457 const char **argv)
458{
459 struct tr2_tgt *tgt_j;
460 int j;
461
462 if (!trace2_enabled)
463 return;
464
465 for_each_wanted_builtin (j, tgt_j)
466 if (tgt_j->pfn_alias_fl)
467 tgt_j->pfn_alias_fl(file, line, alias, argv);
468}
469
470void trace2_cmd_list_config_fl(const char *file, int line)
471{
Jeff Hostetler520cf662024-03-07 15:22:28 +0000472 static int emitted = 0;
473
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800474 if (!trace2_enabled)
475 return;
476
Jeff Hostetler520cf662024-03-07 15:22:28 +0000477 if (emitted)
478 return;
479 emitted = 1;
480
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800481 tr2_cfg_list_config_fl(file, line);
482}
483
Josh Steadmon3d3adaa2020-03-20 14:06:15 -0700484void trace2_cmd_list_env_vars_fl(const char *file, int line)
485{
Jeff Hostetler520cf662024-03-07 15:22:28 +0000486 static int emitted = 0;
487
Josh Steadmon3d3adaa2020-03-20 14:06:15 -0700488 if (!trace2_enabled)
489 return;
490
Jeff Hostetler520cf662024-03-07 15:22:28 +0000491 if (emitted)
492 return;
493 emitted = 1;
494
Josh Steadmon3d3adaa2020-03-20 14:06:15 -0700495 tr2_list_env_vars_fl(file, line);
496}
497
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800498void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
499 const char *value)
500{
501 if (!trace2_enabled)
502 return;
503
504 tr2_cfg_set_fl(file, line, key, value);
505}
506
507void trace2_child_start_fl(const char *file, int line,
508 struct child_process *cmd)
509{
510 struct tr2_tgt *tgt_j;
511 int j;
512 uint64_t us_now;
513 uint64_t us_elapsed_absolute;
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000514 const char **orig_argv = cmd->args.v;
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800515
516 if (!trace2_enabled)
517 return;
518
519 us_now = getnanotime() / 1000;
520 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
521
522 cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
523 cmd->trace2_child_us_start = us_now;
524
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000525 /*
526 * The `pfn_child_start_fl` API takes a `struct child_process`
527 * rather than a simple `argv` for the child because some
528 * targets make use of the additional context bits/values. So
529 * temporarily replace the original argv (inside the `strvec`)
530 * with a possibly redacted version.
531 */
532 cmd->args.v = redact_argv(orig_argv);
533
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800534 for_each_wanted_builtin (j, tgt_j)
535 if (tgt_j->pfn_child_start_fl)
536 tgt_j->pfn_child_start_fl(file, line,
537 us_elapsed_absolute, cmd);
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000538
539 if (cmd->args.v != orig_argv) {
540 free_redacted_argv(cmd->args.v, orig_argv);
541 cmd->args.v = orig_argv;
542 }
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800543}
544
545void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
546 int child_exit_code)
547{
548 struct tr2_tgt *tgt_j;
549 int j;
550 uint64_t us_now;
551 uint64_t us_elapsed_absolute;
552 uint64_t us_elapsed_child;
553
554 if (!trace2_enabled)
555 return;
556
557 us_now = getnanotime() / 1000;
558 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
559
560 if (cmd->trace2_child_us_start)
561 us_elapsed_child = us_now - cmd->trace2_child_us_start;
562 else
563 us_elapsed_child = 0;
564
565 for_each_wanted_builtin (j, tgt_j)
566 if (tgt_j->pfn_child_exit_fl)
567 tgt_j->pfn_child_exit_fl(file, line,
568 us_elapsed_absolute,
569 cmd->trace2_child_id, cmd->pid,
570 child_exit_code,
571 us_elapsed_child);
572}
573
Jeff Hostetler64bc7522021-09-20 15:36:12 +0000574void trace2_child_ready_fl(const char *file, int line,
575 struct child_process *cmd,
576 const char *ready)
577{
578 struct tr2_tgt *tgt_j;
579 int j;
580 uint64_t us_now;
581 uint64_t us_elapsed_absolute;
582 uint64_t us_elapsed_child;
583
584 if (!trace2_enabled)
585 return;
586
587 us_now = getnanotime() / 1000;
588 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
589
590 if (cmd->trace2_child_us_start)
591 us_elapsed_child = us_now - cmd->trace2_child_us_start;
592 else
593 us_elapsed_child = 0;
594
595 for_each_wanted_builtin (j, tgt_j)
596 if (tgt_j->pfn_child_ready_fl)
597 tgt_j->pfn_child_ready_fl(file, line,
598 us_elapsed_absolute,
599 cmd->trace2_child_id,
600 cmd->pid,
601 ready,
602 us_elapsed_child);
603}
604
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800605int trace2_exec_fl(const char *file, int line, const char *exe,
606 const char **argv)
607{
608 struct tr2_tgt *tgt_j;
609 int j;
610 int exec_id;
611 uint64_t us_now;
612 uint64_t us_elapsed_absolute;
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000613 const char **redacted;
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800614
615 if (!trace2_enabled)
616 return -1;
617
618 us_now = getnanotime() / 1000;
619 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
620
621 exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
622
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000623 redacted = redact_argv(argv);
624
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800625 for_each_wanted_builtin (j, tgt_j)
626 if (tgt_j->pfn_exec_fl)
627 tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000628 exec_id, exe, redacted);
629
630 free_redacted_argv(redacted, argv);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800631
632 return exec_id;
633}
634
635void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
636{
637 struct tr2_tgt *tgt_j;
638 int j;
639 uint64_t us_now;
640 uint64_t us_elapsed_absolute;
641
642 if (!trace2_enabled)
643 return;
644
645 us_now = getnanotime() / 1000;
646 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
647
648 for_each_wanted_builtin (j, tgt_j)
649 if (tgt_j->pfn_exec_result_fl)
650 tgt_j->pfn_exec_result_fl(
651 file, line, us_elapsed_absolute, exec_id, code);
652}
653
Jeff Hostetlera70839c2022-10-24 13:41:03 +0000654void trace2_thread_start_fl(const char *file, int line, const char *thread_base_name)
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800655{
656 struct tr2_tgt *tgt_j;
657 int j;
658 uint64_t us_now;
659 uint64_t us_elapsed_absolute;
660
661 if (!trace2_enabled)
662 return;
663
664 if (tr2tls_is_main_thread()) {
665 /*
666 * We should only be called from the new thread's thread-proc,
667 * so this is technically a bug. But in those cases where the
668 * main thread also runs the thread-proc function (or when we
669 * are built with threading disabled), we need to allow it.
670 *
671 * Convert this call to a region-enter so the nesting looks
672 * correct.
673 */
674 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
675 "thread-proc on main: %s",
Jeff Hostetlera70839c2022-10-24 13:41:03 +0000676 thread_base_name);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800677 return;
678 }
679
680 us_now = getnanotime() / 1000;
681 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
682
Jeff Hostetlera70839c2022-10-24 13:41:03 +0000683 tr2tls_create_self(thread_base_name, us_now);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800684
685 for_each_wanted_builtin (j, tgt_j)
686 if (tgt_j->pfn_thread_start_fl)
687 tgt_j->pfn_thread_start_fl(file, line,
688 us_elapsed_absolute);
689}
690
691void trace2_thread_exit_fl(const char *file, int line)
692{
693 struct tr2_tgt *tgt_j;
694 int j;
695 uint64_t us_now;
696 uint64_t us_elapsed_absolute;
697 uint64_t us_elapsed_thread;
698
699 if (!trace2_enabled)
700 return;
701
702 if (tr2tls_is_main_thread()) {
703 /*
704 * We should only be called from the exiting thread's
705 * thread-proc, so this is technically a bug. But in
706 * those cases where the main thread also runs the
707 * thread-proc function (or when we are built with
708 * threading disabled), we need to allow it.
709 *
710 * Convert this call to a region-leave so the nesting
711 * looks correct.
712 */
713 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
714 "thread-proc on main");
715 return;
716 }
717
718 us_now = getnanotime() / 1000;
719 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
720
721 /*
722 * Clear any unbalanced regions and then get the relative time
723 * for the outer-most region (which we pushed when the thread
724 * started). This gives us the run time of the thread.
725 */
726 tr2tls_pop_unwind_self();
727 us_elapsed_thread = tr2tls_region_elasped_self(us_now);
728
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000729 /*
730 * Some timers want per-thread details. If this thread used
731 * one of those timers, emit the details now.
Jeff Hostetler81071622022-10-24 13:41:07 +0000732 *
733 * Likewise for counters.
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000734 */
735 tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
Jeff Hostetler81071622022-10-24 13:41:07 +0000736 tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000737
738 /*
Jeff Hostetler81071622022-10-24 13:41:07 +0000739 * Add stopwatch timer and counter data from the current
740 * (non-main) thread to the final totals. (We'll accumulate
741 * data for the main thread later during "atexit".)
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000742 */
743 tr2tls_lock();
744 tr2_update_final_timers();
Jeff Hostetler81071622022-10-24 13:41:07 +0000745 tr2_update_final_counters();
Jeff Hostetler8ad57562022-10-24 13:41:06 +0000746 tr2tls_unlock();
747
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800748 for_each_wanted_builtin (j, tgt_j)
749 if (tgt_j->pfn_thread_exit_fl)
750 tgt_j->pfn_thread_exit_fl(file, line,
751 us_elapsed_absolute,
752 us_elapsed_thread);
753
754 tr2tls_unset_self();
755}
756
757void trace2_def_param_fl(const char *file, int line, const char *param,
Glen Choodc902082023-06-28 19:26:26 +0000758 const char *value, const struct key_value_info *kvi)
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800759{
760 struct tr2_tgt *tgt_j;
761 int j;
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000762 const char *redacted;
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800763
764 if (!trace2_enabled)
765 return;
766
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000767 redacted = redact_arg(value);
768
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800769 for_each_wanted_builtin (j, tgt_j)
770 if (tgt_j->pfn_param_fl)
Johannes Schindelinb7d49ac2023-11-22 19:18:35 +0000771 tgt_j->pfn_param_fl(file, line, param, redacted, kvi);
772
773 if (redacted != value)
774 free((void *)redacted);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800775}
776
777void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
778{
779 struct tr2_tgt *tgt_j;
780 int j;
781
782 if (!trace2_enabled)
783 return;
784
785 if (repo->trace2_repo_id)
786 return;
787
788 repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
789
790 for_each_wanted_builtin (j, tgt_j)
791 if (tgt_j->pfn_repo_fl)
792 tgt_j->pfn_repo_fl(file, line, repo);
793}
794
795void trace2_region_enter_printf_va_fl(const char *file, int line,
796 const char *category, const char *label,
797 const struct repository *repo,
798 const char *fmt, va_list ap)
799{
800 struct tr2_tgt *tgt_j;
801 int j;
802 uint64_t us_now;
803 uint64_t us_elapsed_absolute;
804
805 if (!trace2_enabled)
806 return;
807
808 us_now = getnanotime() / 1000;
809 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
810
811 /*
812 * Print the region-enter message at the current nesting
813 * (indentation) level and then push a new level.
814 *
815 * We expect each target function to treat 'ap' as constant
816 * and use va_copy.
817 */
818 for_each_wanted_builtin (j, tgt_j)
819 if (tgt_j->pfn_region_enter_printf_va_fl)
820 tgt_j->pfn_region_enter_printf_va_fl(
821 file, line, us_elapsed_absolute, category,
822 label, repo, fmt, ap);
823
824 tr2tls_push_self(us_now);
825}
826
827void trace2_region_enter_fl(const char *file, int line, const char *category,
Torsten Bögershausenad006fe2019-03-19 17:13:46 +0000828 const char *label, const struct repository *repo, ...)
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800829{
Torsten Bögershausenad006fe2019-03-19 17:13:46 +0000830 va_list ap;
831 va_start(ap, repo);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800832 trace2_region_enter_printf_va_fl(file, line, category, label, repo,
Torsten Bögershausenad006fe2019-03-19 17:13:46 +0000833 NULL, ap);
834 va_end(ap);
835
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800836}
837
838void trace2_region_enter_printf_fl(const char *file, int line,
839 const char *category, const char *label,
840 const struct repository *repo,
841 const char *fmt, ...)
842{
843 va_list ap;
844
845 va_start(ap, fmt);
846 trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
847 ap);
848 va_end(ap);
849}
850
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800851void trace2_region_leave_printf_va_fl(const char *file, int line,
852 const char *category, const char *label,
853 const struct repository *repo,
854 const char *fmt, va_list ap)
855{
856 struct tr2_tgt *tgt_j;
857 int j;
858 uint64_t us_now;
859 uint64_t us_elapsed_absolute;
860 uint64_t us_elapsed_region;
861
862 if (!trace2_enabled)
863 return;
864
865 us_now = getnanotime() / 1000;
866 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
867
868 /*
869 * Get the elapsed time in the current region before we
870 * pop it off the stack. Pop the stack. And then print
871 * the perf message at the new (shallower) level so that
872 * it lines up with the corresponding push/enter.
873 */
874 us_elapsed_region = tr2tls_region_elasped_self(us_now);
875
876 tr2tls_pop_self();
877
878 /*
879 * We expect each target function to treat 'ap' as constant
880 * and use va_copy.
881 */
882 for_each_wanted_builtin (j, tgt_j)
883 if (tgt_j->pfn_region_leave_printf_va_fl)
884 tgt_j->pfn_region_leave_printf_va_fl(
885 file, line, us_elapsed_absolute,
886 us_elapsed_region, category, label, repo, fmt,
887 ap);
888}
889
890void trace2_region_leave_fl(const char *file, int line, const char *category,
Torsten Bögershausenad006fe2019-03-19 17:13:46 +0000891 const char *label, const struct repository *repo, ...)
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800892{
Torsten Bögershausenad006fe2019-03-19 17:13:46 +0000893 va_list ap;
894 va_start(ap, repo);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800895 trace2_region_leave_printf_va_fl(file, line, category, label, repo,
Torsten Bögershausenad006fe2019-03-19 17:13:46 +0000896 NULL, ap);
897 va_end(ap);
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800898}
899
900void trace2_region_leave_printf_fl(const char *file, int line,
901 const char *category, const char *label,
902 const struct repository *repo,
903 const char *fmt, ...)
904{
905 va_list ap;
906
907 va_start(ap, fmt);
908 trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
909 ap);
910 va_end(ap);
911}
912
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800913void trace2_data_string_fl(const char *file, int line, const char *category,
914 const struct repository *repo, const char *key,
915 const char *value)
916{
917 struct tr2_tgt *tgt_j;
918 int j;
919 uint64_t us_now;
920 uint64_t us_elapsed_absolute;
921 uint64_t us_elapsed_region;
922
923 if (!trace2_enabled)
924 return;
925
926 us_now = getnanotime() / 1000;
927 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
928 us_elapsed_region = tr2tls_region_elasped_self(us_now);
929
930 for_each_wanted_builtin (j, tgt_j)
931 if (tgt_j->pfn_data_fl)
932 tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
933 us_elapsed_region, category, repo,
934 key, value);
935}
936
937void trace2_data_intmax_fl(const char *file, int line, const char *category,
938 const struct repository *repo, const char *key,
939 intmax_t value)
940{
941 struct strbuf buf_string = STRBUF_INIT;
942
943 if (!trace2_enabled)
944 return;
945
946 strbuf_addf(&buf_string, "%" PRIdMAX, value);
947 trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
948 strbuf_release(&buf_string);
949}
950
951void trace2_data_json_fl(const char *file, int line, const char *category,
952 const struct repository *repo, const char *key,
953 const struct json_writer *value)
954{
955 struct tr2_tgt *tgt_j;
956 int j;
957 uint64_t us_now;
958 uint64_t us_elapsed_absolute;
959 uint64_t us_elapsed_region;
960
961 if (!trace2_enabled)
962 return;
963
964 us_now = getnanotime() / 1000;
965 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
966 us_elapsed_region = tr2tls_region_elasped_self(us_now);
967
968 for_each_wanted_builtin (j, tgt_j)
Josh Steadmon22a73382019-04-25 10:08:53 -0700969 if (tgt_j->pfn_data_json_fl)
Jeff Hostetleree4512e2019-02-22 14:25:01 -0800970 tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
971 us_elapsed_region, category,
972 repo, key, value);
973}
974
975void trace2_printf_va_fl(const char *file, int line, const char *fmt,
976 va_list ap)
977{
978 struct tr2_tgt *tgt_j;
979 int j;
980 uint64_t us_now;
981 uint64_t us_elapsed_absolute;
982
983 if (!trace2_enabled)
984 return;
985
986 us_now = getnanotime() / 1000;
987 us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
988
989 /*
990 * We expect each target function to treat 'ap' as constant
991 * and use va_copy.
992 */
993 for_each_wanted_builtin (j, tgt_j)
994 if (tgt_j->pfn_printf_va_fl)
995 tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
996 fmt, ap);
997}
998
999void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
1000{
1001 va_list ap;
1002
1003 va_start(ap, fmt);
1004 trace2_printf_va_fl(file, line, fmt, ap);
1005 va_end(ap);
1006}
1007
Jeff Hostetler8ad57562022-10-24 13:41:06 +00001008void trace2_timer_start(enum trace2_timer_id tid)
1009{
1010 if (!trace2_enabled)
1011 return;
1012
1013 if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
1014 BUG("trace2_timer_start: invalid timer id: %d", tid);
1015
1016 tr2_start_timer(tid);
1017}
1018
1019void trace2_timer_stop(enum trace2_timer_id tid)
1020{
1021 if (!trace2_enabled)
1022 return;
1023
1024 if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
1025 BUG("trace2_timer_stop: invalid timer id: %d", tid);
1026
1027 tr2_stop_timer(tid);
1028}
1029
Jeff Hostetler81071622022-10-24 13:41:07 +00001030void trace2_counter_add(enum trace2_counter_id cid, uint64_t value)
1031{
1032 if (!trace2_enabled)
1033 return;
1034
1035 if (cid < 0 || cid >= TRACE2_NUMBER_OF_COUNTERS)
1036 BUG("trace2_counter_add: invalid counter id: %d", cid);
1037
1038 tr2_counter_increment(cid, value);
1039}
1040
Josh Steadmone97e1cf2020-11-11 15:29:26 -08001041const char *trace2_session_id(void)
1042{
1043 return tr2_sid_get();
1044}