Coverage Report

Created: 2023-11-27 06:56

/src/git/trace2.c
Line
Count
Source (jump to first uncovered line)
1
#include "git-compat-util.h"
2
#include "config.h"
3
#include "json-writer.h"
4
#include "quote.h"
5
#include "repository.h"
6
#include "run-command.h"
7
#include "sigchain.h"
8
#include "thread-utils.h"
9
#include "version.h"
10
#include "trace.h"
11
#include "trace2.h"
12
#include "trace2/tr2_cfg.h"
13
#include "trace2/tr2_cmd_name.h"
14
#include "trace2/tr2_ctr.h"
15
#include "trace2/tr2_dst.h"
16
#include "trace2/tr2_sid.h"
17
#include "trace2/tr2_sysenv.h"
18
#include "trace2/tr2_tgt.h"
19
#include "trace2/tr2_tls.h"
20
#include "trace2/tr2_tmr.h"
21
22
static int trace2_enabled;
23
24
static int tr2_next_child_id; /* modify under lock */
25
static int tr2_next_exec_id; /* modify under lock */
26
static 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 */
34
static 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
0
  for (j = 0, tgt_j = tr2_tgt_builtins[j];  \
46
0
       tgt_j;         \
47
0
       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
0
  for_each_builtin(j, tgt_j)                   \
53
0
    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
60
 * private data structures and thread-local storage.
61
 *
62
 * Return the number of builtin targets enabled.
63
 */
64
static int tr2_tgt_want_builtins(void)
65
0
{
66
0
  struct tr2_tgt *tgt_j;
67
0
  int j;
68
0
  int sum = 0;
69
70
0
  for_each_builtin (j, tgt_j)
71
0
    if (tgt_j->pfn_init())
72
0
      sum++;
73
74
0
  return sum;
75
0
}
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
 */
82
static void tr2_tgt_disable_builtins(void)
83
0
{
84
0
  struct tr2_tgt *tgt_j;
85
0
  int j;
86
87
0
  for_each_builtin (j, tgt_j)
88
0
    tgt_j->pfn_term();
89
0
}
90
91
/*
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
 */
96
static void tr2_tgt_emit_a_timer(const struct tr2_timer_metadata *meta,
97
         const struct tr2_timer *timer,
98
         int is_final_data)
99
0
{
100
0
  struct tr2_tgt *tgt_j;
101
0
  int j;
102
103
0
  for_each_wanted_builtin (j, tgt_j)
104
0
    if (tgt_j->pfn_timer)
105
0
      tgt_j->pfn_timer(meta, timer, is_final_data);
106
0
}
107
108
/*
109
 * The signature of this function must match the pfn_counter
110
 * method in the targets.
111
 */
112
static void tr2_tgt_emit_a_counter(const struct tr2_counter_metadata *meta,
113
           const struct tr2_counter *counter,
114
           int is_final_data)
115
0
{
116
0
  struct tr2_tgt *tgt_j;
117
0
  int j;
118
119
0
  for_each_wanted_builtin (j, tgt_j)
120
0
    if (tgt_j->pfn_counter)
121
0
      tgt_j->pfn_counter(meta, counter, is_final_data);
122
0
}
123
124
static 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
 */
134
static void tr2main_atexit_handler(void)
135
0
{
136
0
  struct tr2_tgt *tgt_j;
137
0
  int j;
138
0
  uint64_t us_now;
139
0
  uint64_t us_elapsed_absolute;
140
141
0
  us_now = getnanotime() / 1000;
142
0
  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
0
  tr2tls_pop_unwind_self();
150
151
  /*
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).
155
   *
156
   * Likewise for counters.
157
   */
158
0
  tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
159
0
  tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
160
161
  /*
162
   * Add stopwatch timer and counter data for the main thread to
163
   * the final totals.  And then emit the final values.
164
   *
165
   * Technically, we shouldn't need to hold the lock to update
166
   * 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.
169
   */
170
0
  tr2tls_lock();
171
0
  tr2_update_final_timers();
172
0
  tr2_update_final_counters();
173
0
  tr2_emit_final_timers(tr2_tgt_emit_a_timer);
174
0
  tr2_emit_final_counters(tr2_tgt_emit_a_counter);
175
0
  tr2tls_unlock();
176
177
0
  for_each_wanted_builtin (j, tgt_j)
178
0
    if (tgt_j->pfn_atexit)
179
0
      tgt_j->pfn_atexit(us_elapsed_absolute,
180
0
            tr2main_exit_code);
181
182
0
  tr2_tgt_disable_builtins();
183
184
0
  tr2tls_release();
185
0
  tr2_sid_release();
186
0
  tr2_cmd_name_release();
187
0
  tr2_cfg_free_patterns();
188
0
  tr2_cfg_free_env_vars();
189
0
  tr2_sysenv_release();
190
191
0
  trace2_enabled = 0;
192
0
}
193
194
static void tr2main_signal_handler(int signo)
195
0
{
196
0
  struct tr2_tgt *tgt_j;
197
0
  int j;
198
0
  uint64_t us_now;
199
0
  uint64_t us_elapsed_absolute;
200
201
0
  us_now = getnanotime() / 1000;
202
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
203
204
0
  for_each_wanted_builtin (j, tgt_j)
205
0
    if (tgt_j->pfn_signal)
206
0
      tgt_j->pfn_signal(us_elapsed_absolute, signo);
207
208
0
  sigchain_pop(signo);
209
0
  raise(signo);
210
0
}
211
212
void trace2_initialize_clock(void)
213
0
{
214
0
  tr2tls_start_process_clock();
215
0
}
216
217
void trace2_initialize_fl(const char *file, int line)
218
0
{
219
0
  struct tr2_tgt *tgt_j;
220
0
  int j;
221
222
0
  if (trace2_enabled)
223
0
    return;
224
225
0
  tr2_sysenv_load();
226
227
0
  if (!tr2_tgt_want_builtins())
228
0
    return;
229
0
  trace2_enabled = 1;
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
22.8k
{
247
22.8k
  return trace2_enabled;
248
22.8k
}
249
250
void trace2_cmd_start_fl(const char *file, int line, const char **argv)
251
0
{
252
0
  struct tr2_tgt *tgt_j;
253
0
  int j;
254
0
  uint64_t us_now;
255
0
  uint64_t us_elapsed_absolute;
256
257
0
  if (!trace2_enabled)
258
0
    return;
259
260
0
  us_now = getnanotime() / 1000;
261
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
262
263
0
  for_each_wanted_builtin (j, tgt_j)
264
0
    if (tgt_j->pfn_start_fl)
265
0
      tgt_j->pfn_start_fl(file, line, us_elapsed_absolute,
266
0
              argv);
267
0
}
268
269
void trace2_cmd_exit_fl(const char *file, int line, int code)
270
0
{
271
0
  struct tr2_tgt *tgt_j;
272
0
  int j;
273
0
  uint64_t us_now;
274
0
  uint64_t us_elapsed_absolute;
275
276
0
  if (!trace2_enabled)
277
0
    return;
278
279
0
  trace2_collect_process_info(TRACE2_PROCESS_INFO_EXIT);
280
281
0
  tr2main_exit_code = code;
282
283
0
  us_now = getnanotime() / 1000;
284
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
285
286
0
  for_each_wanted_builtin (j, tgt_j)
287
0
    if (tgt_j->pfn_exit_fl)
288
0
      tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
289
0
             code);
290
0
}
291
292
void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
293
          va_list ap)
294
1.03k
{
295
1.03k
  struct tr2_tgt *tgt_j;
296
1.03k
  int j;
297
298
1.03k
  if (!trace2_enabled)
299
1.03k
    return;
300
301
  /*
302
   * We expect each target function to treat 'ap' as constant
303
   * and use va_copy (because an 'ap' can only be walked once).
304
   */
305
1.03k
  for_each_wanted_builtin (j, tgt_j)
306
0
    if (tgt_j->pfn_error_va_fl)
307
0
      tgt_j->pfn_error_va_fl(file, line, fmt, ap);
308
0
}
309
310
void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
311
0
{
312
0
  struct tr2_tgt *tgt_j;
313
0
  int j;
314
315
0
  if (!trace2_enabled)
316
0
    return;
317
318
0
  for_each_wanted_builtin (j, tgt_j)
319
0
    if (tgt_j->pfn_command_path_fl)
320
0
      tgt_j->pfn_command_path_fl(file, line, pathname);
321
0
}
322
323
void trace2_cmd_ancestry_fl(const char *file, int line, const char **parent_names)
324
0
{
325
0
  struct tr2_tgt *tgt_j;
326
0
  int j;
327
328
0
  if (!trace2_enabled)
329
0
    return;
330
331
0
  for_each_wanted_builtin (j, tgt_j)
332
0
    if (tgt_j->pfn_command_ancestry_fl)
333
0
      tgt_j->pfn_command_ancestry_fl(file, line, parent_names);
334
0
}
335
336
void trace2_cmd_name_fl(const char *file, int line, const char *name)
337
0
{
338
0
  struct tr2_tgt *tgt_j;
339
0
  const char *hierarchy;
340
0
  int j;
341
342
0
  if (!trace2_enabled)
343
0
    return;
344
345
0
  tr2_cmd_name_append_hierarchy(name);
346
0
  hierarchy = tr2_cmd_name_get_hierarchy();
347
348
0
  for_each_wanted_builtin (j, tgt_j)
349
0
    if (tgt_j->pfn_command_name_fl)
350
0
      tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
351
0
}
352
353
void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
354
0
{
355
0
  struct tr2_tgt *tgt_j;
356
0
  int j;
357
358
0
  if (!trace2_enabled)
359
0
    return;
360
361
0
  for_each_wanted_builtin (j, tgt_j)
362
0
    if (tgt_j->pfn_command_mode_fl)
363
0
      tgt_j->pfn_command_mode_fl(file, line, mode);
364
0
}
365
366
void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
367
       const char **argv)
368
0
{
369
0
  struct tr2_tgt *tgt_j;
370
0
  int j;
371
372
0
  if (!trace2_enabled)
373
0
    return;
374
375
0
  for_each_wanted_builtin (j, tgt_j)
376
0
    if (tgt_j->pfn_alias_fl)
377
0
      tgt_j->pfn_alias_fl(file, line, alias, argv);
378
0
}
379
380
void trace2_cmd_list_config_fl(const char *file, int line)
381
0
{
382
0
  if (!trace2_enabled)
383
0
    return;
384
385
0
  tr2_cfg_list_config_fl(file, line);
386
0
}
387
388
void trace2_cmd_list_env_vars_fl(const char *file, int line)
389
0
{
390
0
  if (!trace2_enabled)
391
0
    return;
392
393
0
  tr2_list_env_vars_fl(file, line);
394
0
}
395
396
void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
397
            const char *value)
398
3.66k
{
399
3.66k
  if (!trace2_enabled)
400
3.66k
    return;
401
402
0
  tr2_cfg_set_fl(file, line, key, value);
403
0
}
404
405
void trace2_child_start_fl(const char *file, int line,
406
         struct child_process *cmd)
407
7.35k
{
408
7.35k
  struct tr2_tgt *tgt_j;
409
7.35k
  int j;
410
7.35k
  uint64_t us_now;
411
7.35k
  uint64_t us_elapsed_absolute;
412
413
7.35k
  if (!trace2_enabled)
414
7.35k
    return;
415
416
0
  us_now = getnanotime() / 1000;
417
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
418
419
0
  cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
420
0
  cmd->trace2_child_us_start = us_now;
421
422
0
  for_each_wanted_builtin (j, tgt_j)
423
0
    if (tgt_j->pfn_child_start_fl)
424
0
      tgt_j->pfn_child_start_fl(file, line,
425
0
              us_elapsed_absolute, cmd);
426
0
}
427
428
void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
429
        int child_exit_code)
430
7.35k
{
431
7.35k
  struct tr2_tgt *tgt_j;
432
7.35k
  int j;
433
7.35k
  uint64_t us_now;
434
7.35k
  uint64_t us_elapsed_absolute;
435
7.35k
  uint64_t us_elapsed_child;
436
437
7.35k
  if (!trace2_enabled)
438
7.35k
    return;
439
440
0
  us_now = getnanotime() / 1000;
441
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
442
443
0
  if (cmd->trace2_child_us_start)
444
0
    us_elapsed_child = us_now - cmd->trace2_child_us_start;
445
0
  else
446
0
    us_elapsed_child = 0;
447
448
0
  for_each_wanted_builtin (j, tgt_j)
449
0
    if (tgt_j->pfn_child_exit_fl)
450
0
      tgt_j->pfn_child_exit_fl(file, line,
451
0
             us_elapsed_absolute,
452
0
             cmd->trace2_child_id, cmd->pid,
453
0
             child_exit_code,
454
0
             us_elapsed_child);
455
0
}
456
457
void trace2_child_ready_fl(const char *file, int line,
458
         struct child_process *cmd,
459
         const char *ready)
460
0
{
461
0
  struct tr2_tgt *tgt_j;
462
0
  int j;
463
0
  uint64_t us_now;
464
0
  uint64_t us_elapsed_absolute;
465
0
  uint64_t us_elapsed_child;
466
467
0
  if (!trace2_enabled)
468
0
    return;
469
470
0
  us_now = getnanotime() / 1000;
471
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
472
473
0
  if (cmd->trace2_child_us_start)
474
0
    us_elapsed_child = us_now - cmd->trace2_child_us_start;
475
0
  else
476
0
    us_elapsed_child = 0;
477
478
0
  for_each_wanted_builtin (j, tgt_j)
479
0
    if (tgt_j->pfn_child_ready_fl)
480
0
      tgt_j->pfn_child_ready_fl(file, line,
481
0
              us_elapsed_absolute,
482
0
              cmd->trace2_child_id,
483
0
              cmd->pid,
484
0
              ready,
485
0
              us_elapsed_child);
486
0
}
487
488
int trace2_exec_fl(const char *file, int line, const char *exe,
489
       const char **argv)
490
0
{
491
0
  struct tr2_tgt *tgt_j;
492
0
  int j;
493
0
  int exec_id;
494
0
  uint64_t us_now;
495
0
  uint64_t us_elapsed_absolute;
496
497
0
  if (!trace2_enabled)
498
0
    return -1;
499
500
0
  us_now = getnanotime() / 1000;
501
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
502
503
0
  exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
504
505
0
  for_each_wanted_builtin (j, tgt_j)
506
0
    if (tgt_j->pfn_exec_fl)
507
0
      tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
508
0
             exec_id, exe, argv);
509
510
0
  return exec_id;
511
0
}
512
513
void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
514
0
{
515
0
  struct tr2_tgt *tgt_j;
516
0
  int j;
517
0
  uint64_t us_now;
518
0
  uint64_t us_elapsed_absolute;
519
520
0
  if (!trace2_enabled)
521
0
    return;
522
523
0
  us_now = getnanotime() / 1000;
524
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
525
526
0
  for_each_wanted_builtin (j, tgt_j)
527
0
    if (tgt_j->pfn_exec_result_fl)
528
0
      tgt_j->pfn_exec_result_fl(
529
0
        file, line, us_elapsed_absolute, exec_id, code);
530
0
}
531
532
void trace2_thread_start_fl(const char *file, int line, const char *thread_base_name)
533
0
{
534
0
  struct tr2_tgt *tgt_j;
535
0
  int j;
536
0
  uint64_t us_now;
537
0
  uint64_t us_elapsed_absolute;
538
539
0
  if (!trace2_enabled)
540
0
    return;
541
542
0
  if (tr2tls_is_main_thread()) {
543
    /*
544
     * We should only be called from the new thread's thread-proc,
545
     * so this is technically a bug.  But in those cases where the
546
     * main thread also runs the thread-proc function (or when we
547
     * are built with threading disabled), we need to allow it.
548
     *
549
     * Convert this call to a region-enter so the nesting looks
550
     * correct.
551
     */
552
0
    trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
553
0
                "thread-proc on main: %s",
554
0
                thread_base_name);
555
0
    return;
556
0
  }
557
558
0
  us_now = getnanotime() / 1000;
559
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
560
561
0
  tr2tls_create_self(thread_base_name, us_now);
562
563
0
  for_each_wanted_builtin (j, tgt_j)
564
0
    if (tgt_j->pfn_thread_start_fl)
565
0
      tgt_j->pfn_thread_start_fl(file, line,
566
0
               us_elapsed_absolute);
567
0
}
568
569
void trace2_thread_exit_fl(const char *file, int line)
570
0
{
571
0
  struct tr2_tgt *tgt_j;
572
0
  int j;
573
0
  uint64_t us_now;
574
0
  uint64_t us_elapsed_absolute;
575
0
  uint64_t us_elapsed_thread;
576
577
0
  if (!trace2_enabled)
578
0
    return;
579
580
0
  if (tr2tls_is_main_thread()) {
581
    /*
582
     * We should only be called from the exiting thread's
583
     * thread-proc, so this is technically a bug.  But in
584
     * those cases where the main thread also runs the
585
     * thread-proc function (or when we are built with
586
     * threading disabled), we need to allow it.
587
     *
588
     * Convert this call to a region-leave so the nesting
589
     * looks correct.
590
     */
591
0
    trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
592
0
                "thread-proc on main");
593
0
    return;
594
0
  }
595
596
0
  us_now = getnanotime() / 1000;
597
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
598
599
  /*
600
   * Clear any unbalanced regions and then get the relative time
601
   * for the outer-most region (which we pushed when the thread
602
   * started).  This gives us the run time of the thread.
603
   */
604
0
  tr2tls_pop_unwind_self();
605
0
  us_elapsed_thread = tr2tls_region_elasped_self(us_now);
606
607
  /*
608
   * Some timers want per-thread details.  If this thread used
609
   * one of those timers, emit the details now.
610
   *
611
   * Likewise for counters.
612
   */
613
0
  tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
614
0
  tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
615
616
  /*
617
   * Add stopwatch timer and counter data from the current
618
   * (non-main) thread to the final totals.  (We'll accumulate
619
   * data for the main thread later during "atexit".)
620
   */
621
0
  tr2tls_lock();
622
0
  tr2_update_final_timers();
623
0
  tr2_update_final_counters();
624
0
  tr2tls_unlock();
625
626
0
  for_each_wanted_builtin (j, tgt_j)
627
0
    if (tgt_j->pfn_thread_exit_fl)
628
0
      tgt_j->pfn_thread_exit_fl(file, line,
629
0
              us_elapsed_absolute,
630
0
              us_elapsed_thread);
631
632
0
  tr2tls_unset_self();
633
0
}
634
635
void trace2_def_param_fl(const char *file, int line, const char *param,
636
       const char *value, const struct key_value_info *kvi)
637
0
{
638
0
  struct tr2_tgt *tgt_j;
639
0
  int j;
640
641
0
  if (!trace2_enabled)
642
0
    return;
643
644
0
  for_each_wanted_builtin (j, tgt_j)
645
0
    if (tgt_j->pfn_param_fl)
646
0
      tgt_j->pfn_param_fl(file, line, param, value, kvi);
647
0
}
648
649
void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
650
11.4k
{
651
11.4k
  struct tr2_tgt *tgt_j;
652
11.4k
  int j;
653
654
11.4k
  if (!trace2_enabled)
655
11.4k
    return;
656
657
0
  if (repo->trace2_repo_id)
658
0
    return;
659
660
0
  repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
661
662
0
  for_each_wanted_builtin (j, tgt_j)
663
0
    if (tgt_j->pfn_repo_fl)
664
0
      tgt_j->pfn_repo_fl(file, line, repo);
665
0
}
666
667
void trace2_region_enter_printf_va_fl(const char *file, int line,
668
              const char *category, const char *label,
669
              const struct repository *repo,
670
              const char *fmt, va_list ap)
671
172k
{
672
172k
  struct tr2_tgt *tgt_j;
673
172k
  int j;
674
172k
  uint64_t us_now;
675
172k
  uint64_t us_elapsed_absolute;
676
677
172k
  if (!trace2_enabled)
678
172k
    return;
679
680
0
  us_now = getnanotime() / 1000;
681
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
682
683
  /*
684
   * Print the region-enter message at the current nesting
685
   * (indentation) level and then push a new level.
686
   *
687
   * We expect each target function to treat 'ap' as constant
688
   * and use va_copy.
689
   */
690
0
  for_each_wanted_builtin (j, tgt_j)
691
0
    if (tgt_j->pfn_region_enter_printf_va_fl)
692
0
      tgt_j->pfn_region_enter_printf_va_fl(
693
0
        file, line, us_elapsed_absolute, category,
694
0
        label, repo, fmt, ap);
695
696
0
  tr2tls_push_self(us_now);
697
0
}
698
699
void trace2_region_enter_fl(const char *file, int line, const char *category,
700
          const char *label, const struct repository *repo, ...)
701
156k
{
702
156k
  va_list ap;
703
156k
  va_start(ap, repo);
704
156k
  trace2_region_enter_printf_va_fl(file, line, category, label, repo,
705
156k
           NULL, ap);
706
156k
  va_end(ap);
707
708
156k
}
709
710
void trace2_region_enter_printf_fl(const char *file, int line,
711
           const char *category, const char *label,
712
           const struct repository *repo,
713
           const char *fmt, ...)
714
16.1k
{
715
16.1k
  va_list ap;
716
717
16.1k
  va_start(ap, fmt);
718
16.1k
  trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
719
16.1k
           ap);
720
16.1k
  va_end(ap);
721
16.1k
}
722
723
void trace2_region_leave_printf_va_fl(const char *file, int line,
724
              const char *category, const char *label,
725
              const struct repository *repo,
726
              const char *fmt, va_list ap)
727
172k
{
728
172k
  struct tr2_tgt *tgt_j;
729
172k
  int j;
730
172k
  uint64_t us_now;
731
172k
  uint64_t us_elapsed_absolute;
732
172k
  uint64_t us_elapsed_region;
733
734
172k
  if (!trace2_enabled)
735
172k
    return;
736
737
0
  us_now = getnanotime() / 1000;
738
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
739
740
  /*
741
   * Get the elapsed time in the current region before we
742
   * pop it off the stack.  Pop the stack.  And then print
743
   * the perf message at the new (shallower) level so that
744
   * it lines up with the corresponding push/enter.
745
   */
746
0
  us_elapsed_region = tr2tls_region_elasped_self(us_now);
747
748
0
  tr2tls_pop_self();
749
750
  /*
751
   * We expect each target function to treat 'ap' as constant
752
   * and use va_copy.
753
   */
754
0
  for_each_wanted_builtin (j, tgt_j)
755
0
    if (tgt_j->pfn_region_leave_printf_va_fl)
756
0
      tgt_j->pfn_region_leave_printf_va_fl(
757
0
        file, line, us_elapsed_absolute,
758
0
        us_elapsed_region, category, label, repo, fmt,
759
0
        ap);
760
0
}
761
762
void trace2_region_leave_fl(const char *file, int line, const char *category,
763
          const char *label, const struct repository *repo, ...)
764
156k
{
765
156k
  va_list ap;
766
156k
  va_start(ap, repo);
767
156k
  trace2_region_leave_printf_va_fl(file, line, category, label, repo,
768
156k
           NULL, ap);
769
156k
  va_end(ap);
770
156k
}
771
772
void trace2_region_leave_printf_fl(const char *file, int line,
773
           const char *category, const char *label,
774
           const struct repository *repo,
775
           const char *fmt, ...)
776
16.1k
{
777
16.1k
  va_list ap;
778
779
16.1k
  va_start(ap, fmt);
780
16.1k
  trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
781
16.1k
           ap);
782
16.1k
  va_end(ap);
783
16.1k
}
784
785
void trace2_data_string_fl(const char *file, int line, const char *category,
786
         const struct repository *repo, const char *key,
787
         const char *value)
788
0
{
789
0
  struct tr2_tgt *tgt_j;
790
0
  int j;
791
0
  uint64_t us_now;
792
0
  uint64_t us_elapsed_absolute;
793
0
  uint64_t us_elapsed_region;
794
795
0
  if (!trace2_enabled)
796
0
    return;
797
798
0
  us_now = getnanotime() / 1000;
799
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
800
0
  us_elapsed_region = tr2tls_region_elasped_self(us_now);
801
802
0
  for_each_wanted_builtin (j, tgt_j)
803
0
    if (tgt_j->pfn_data_fl)
804
0
      tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
805
0
             us_elapsed_region, category, repo,
806
0
             key, value);
807
0
}
808
809
void trace2_data_intmax_fl(const char *file, int line, const char *category,
810
         const struct repository *repo, const char *key,
811
         intmax_t value)
812
44.9k
{
813
44.9k
  struct strbuf buf_string = STRBUF_INIT;
814
815
44.9k
  if (!trace2_enabled)
816
44.9k
    return;
817
818
0
  strbuf_addf(&buf_string, "%" PRIdMAX, value);
819
0
  trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
820
0
  strbuf_release(&buf_string);
821
0
}
822
823
void trace2_data_json_fl(const char *file, int line, const char *category,
824
       const struct repository *repo, const char *key,
825
       const struct json_writer *value)
826
0
{
827
0
  struct tr2_tgt *tgt_j;
828
0
  int j;
829
0
  uint64_t us_now;
830
0
  uint64_t us_elapsed_absolute;
831
0
  uint64_t us_elapsed_region;
832
833
0
  if (!trace2_enabled)
834
0
    return;
835
836
0
  us_now = getnanotime() / 1000;
837
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
838
0
  us_elapsed_region = tr2tls_region_elasped_self(us_now);
839
840
0
  for_each_wanted_builtin (j, tgt_j)
841
0
    if (tgt_j->pfn_data_json_fl)
842
0
      tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
843
0
            us_elapsed_region, category,
844
0
            repo, key, value);
845
0
}
846
847
void trace2_printf_va_fl(const char *file, int line, const char *fmt,
848
       va_list ap)
849
0
{
850
0
  struct tr2_tgt *tgt_j;
851
0
  int j;
852
0
  uint64_t us_now;
853
0
  uint64_t us_elapsed_absolute;
854
855
0
  if (!trace2_enabled)
856
0
    return;
857
858
0
  us_now = getnanotime() / 1000;
859
0
  us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
860
861
  /*
862
   * We expect each target function to treat 'ap' as constant
863
   * and use va_copy.
864
   */
865
0
  for_each_wanted_builtin (j, tgt_j)
866
0
    if (tgt_j->pfn_printf_va_fl)
867
0
      tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
868
0
            fmt, ap);
869
0
}
870
871
void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
872
0
{
873
0
  va_list ap;
874
875
0
  va_start(ap, fmt);
876
0
  trace2_printf_va_fl(file, line, fmt, ap);
877
0
  va_end(ap);
878
0
}
879
880
void trace2_timer_start(enum trace2_timer_id tid)
881
0
{
882
0
  if (!trace2_enabled)
883
0
    return;
884
885
0
  if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
886
0
    BUG("trace2_timer_start: invalid timer id: %d", tid);
887
888
0
  tr2_start_timer(tid);
889
0
}
890
891
void trace2_timer_stop(enum trace2_timer_id tid)
892
0
{
893
0
  if (!trace2_enabled)
894
0
    return;
895
896
0
  if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
897
0
    BUG("trace2_timer_stop: invalid timer id: %d", tid);
898
899
0
  tr2_stop_timer(tid);
900
0
}
901
902
void trace2_counter_add(enum trace2_counter_id cid, uint64_t value)
903
0
{
904
0
  if (!trace2_enabled)
905
0
    return;
906
907
0
  if (cid < 0 || cid >= TRACE2_NUMBER_OF_COUNTERS)
908
0
    BUG("trace2_counter_add: invalid counter id: %d", cid);
909
910
0
  tr2_counter_increment(cid, value);
911
0
}
912
913
const char *trace2_session_id(void)
914
0
{
915
0
  return tr2_sid_get();
916
0
}