Coverage Report

Created: 2024-09-08 06:23

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