Merge branch 'nd/sha1-name-c-wo-the-repository'
[git] / trace2.c
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_tgt.h"
14 #include "trace2/tr2_tls.h"
15
16 static int trace2_enabled;
17
18 static int tr2_next_child_id; /* modify under lock */
19 static int tr2_next_exec_id; /* modify under lock */
20 static int tr2_next_repo_id = 1; /* modify under lock. zero is reserved */
21
22 /*
23  * A table of the builtin TRACE2 targets.  Each of these may be independently
24  * enabled or disabled.  Each TRACE2 API method will try to write an event to
25  * *each* of the enabled targets.
26  */
27 /* clang-format off */
28 static struct tr2_tgt *tr2_tgt_builtins[] =
29 {
30         &tr2_tgt_normal,
31         &tr2_tgt_perf,
32         &tr2_tgt_event,
33         NULL
34 };
35 /* clang-format on */
36
37 /* clang-format off */
38 #define for_each_builtin(j, tgt_j)                      \
39         for (j = 0, tgt_j = tr2_tgt_builtins[j];        \
40              tgt_j;                                     \
41              j++, tgt_j = tr2_tgt_builtins[j])
42 /* clang-format on */
43
44 /* clang-format off */
45 #define for_each_wanted_builtin(j, tgt_j)            \
46         for_each_builtin(j, tgt_j)                   \
47                 if (tr2_dst_trace_want(tgt_j->pdst))
48 /* clang-format on */
49
50 /*
51  * Force (rather than lazily) initialize any of the requested
52  * builtin TRACE2 targets at startup (and before we've seen an
53  * actual TRACE2 event call) so we can see if we need to setup
54  * the TR2 and TLS machinery.
55  *
56  * Return the number of builtin targets enabled.
57  */
58 static int tr2_tgt_want_builtins(void)
59 {
60         struct tr2_tgt *tgt_j;
61         int j;
62         int sum = 0;
63
64         for_each_builtin (j, tgt_j)
65                 if (tgt_j->pfn_init())
66                         sum++;
67
68         return sum;
69 }
70
71 /*
72  * Properly terminate each builtin target.  Give each target
73  * a chance to write a summary event and/or flush if necessary
74  * and then close the fd.
75  */
76 static void tr2_tgt_disable_builtins(void)
77 {
78         struct tr2_tgt *tgt_j;
79         int j;
80
81         for_each_builtin (j, tgt_j)
82                 tgt_j->pfn_term();
83 }
84
85 static int tr2main_exit_code;
86
87 /*
88  * Our atexit routine should run after everything has finished.
89  *
90  * Note that events generated here might not actually appear if
91  * we are writing to fd 1 or 2 and our atexit routine runs after
92  * the pager's atexit routine (since it closes them to shutdown
93  * the pipes).
94  */
95 static void tr2main_atexit_handler(void)
96 {
97         struct tr2_tgt *tgt_j;
98         int j;
99         uint64_t us_now;
100         uint64_t us_elapsed_absolute;
101
102         us_now = getnanotime() / 1000;
103         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
104
105         /*
106          * Clear any unbalanced regions so that our atexit message
107          * does not appear nested.  This improves the appearance of
108          * the trace output if someone calls die(), for example.
109          */
110         tr2tls_pop_unwind_self();
111
112         for_each_wanted_builtin (j, tgt_j)
113                 if (tgt_j->pfn_atexit)
114                         tgt_j->pfn_atexit(us_elapsed_absolute,
115                                           tr2main_exit_code);
116
117         tr2_tgt_disable_builtins();
118
119         tr2tls_release();
120         tr2_sid_release();
121         tr2_cmd_name_release();
122         tr2_cfg_free_patterns();
123
124         trace2_enabled = 0;
125 }
126
127 static void tr2main_signal_handler(int signo)
128 {
129         struct tr2_tgt *tgt_j;
130         int j;
131         uint64_t us_now;
132         uint64_t us_elapsed_absolute;
133
134         us_now = getnanotime() / 1000;
135         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
136
137         for_each_wanted_builtin (j, tgt_j)
138                 if (tgt_j->pfn_signal)
139                         tgt_j->pfn_signal(us_elapsed_absolute, signo);
140
141         sigchain_pop(signo);
142         raise(signo);
143 }
144
145 void trace2_initialize_fl(const char *file, int line)
146 {
147         struct tr2_tgt *tgt_j;
148         int j;
149
150         if (trace2_enabled)
151                 return;
152
153         if (!tr2_tgt_want_builtins())
154                 return;
155         trace2_enabled = 1;
156
157         tr2_sid_get();
158
159         atexit(tr2main_atexit_handler);
160         sigchain_push(SIGPIPE, tr2main_signal_handler);
161         tr2tls_init();
162
163         /*
164          * Emit 'version' message on each active builtin target.
165          */
166         for_each_wanted_builtin (j, tgt_j)
167                 if (tgt_j->pfn_version_fl)
168                         tgt_j->pfn_version_fl(file, line);
169 }
170
171 int trace2_is_enabled(void)
172 {
173         return trace2_enabled;
174 }
175
176 void trace2_cmd_start_fl(const char *file, int line, const char **argv)
177 {
178         struct tr2_tgt *tgt_j;
179         int j;
180
181         if (!trace2_enabled)
182                 return;
183
184         for_each_wanted_builtin (j, tgt_j)
185                 if (tgt_j->pfn_start_fl)
186                         tgt_j->pfn_start_fl(file, line, argv);
187 }
188
189 int trace2_cmd_exit_fl(const char *file, int line, int code)
190 {
191         struct tr2_tgt *tgt_j;
192         int j;
193         uint64_t us_now;
194         uint64_t us_elapsed_absolute;
195
196         code &= 0xff;
197
198         if (!trace2_enabled)
199                 return code;
200
201         tr2main_exit_code = code;
202
203         us_now = getnanotime() / 1000;
204         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
205
206         for_each_wanted_builtin (j, tgt_j)
207                 if (tgt_j->pfn_exit_fl)
208                         tgt_j->pfn_exit_fl(file, line, us_elapsed_absolute,
209                                            code);
210
211         return code;
212 }
213
214 void trace2_cmd_error_va_fl(const char *file, int line, const char *fmt,
215                             va_list ap)
216 {
217         struct tr2_tgt *tgt_j;
218         int j;
219
220         if (!trace2_enabled)
221                 return;
222
223         /*
224          * We expect each target function to treat 'ap' as constant
225          * and use va_copy (because an 'ap' can only be walked once).
226          */
227         for_each_wanted_builtin (j, tgt_j)
228                 if (tgt_j->pfn_error_va_fl)
229                         tgt_j->pfn_error_va_fl(file, line, fmt, ap);
230 }
231
232 void trace2_cmd_path_fl(const char *file, int line, const char *pathname)
233 {
234         struct tr2_tgt *tgt_j;
235         int j;
236
237         if (!trace2_enabled)
238                 return;
239
240         for_each_wanted_builtin (j, tgt_j)
241                 if (tgt_j->pfn_command_path_fl)
242                         tgt_j->pfn_command_path_fl(file, line, pathname);
243 }
244
245 void trace2_cmd_name_fl(const char *file, int line, const char *name)
246 {
247         struct tr2_tgt *tgt_j;
248         const char *hierarchy;
249         int j;
250
251         if (!trace2_enabled)
252                 return;
253
254         tr2_cmd_name_append_hierarchy(name);
255         hierarchy = tr2_cmd_name_get_hierarchy();
256
257         for_each_wanted_builtin (j, tgt_j)
258                 if (tgt_j->pfn_command_name_fl)
259                         tgt_j->pfn_command_name_fl(file, line, name, hierarchy);
260 }
261
262 void trace2_cmd_mode_fl(const char *file, int line, const char *mode)
263 {
264         struct tr2_tgt *tgt_j;
265         int j;
266
267         if (!trace2_enabled)
268                 return;
269
270         for_each_wanted_builtin (j, tgt_j)
271                 if (tgt_j->pfn_command_mode_fl)
272                         tgt_j->pfn_command_mode_fl(file, line, mode);
273 }
274
275 void trace2_cmd_alias_fl(const char *file, int line, const char *alias,
276                          const char **argv)
277 {
278         struct tr2_tgt *tgt_j;
279         int j;
280
281         if (!trace2_enabled)
282                 return;
283
284         for_each_wanted_builtin (j, tgt_j)
285                 if (tgt_j->pfn_alias_fl)
286                         tgt_j->pfn_alias_fl(file, line, alias, argv);
287 }
288
289 void trace2_cmd_list_config_fl(const char *file, int line)
290 {
291         if (!trace2_enabled)
292                 return;
293
294         tr2_cfg_list_config_fl(file, line);
295 }
296
297 void trace2_cmd_set_config_fl(const char *file, int line, const char *key,
298                               const char *value)
299 {
300         if (!trace2_enabled)
301                 return;
302
303         tr2_cfg_set_fl(file, line, key, value);
304 }
305
306 void trace2_child_start_fl(const char *file, int line,
307                            struct child_process *cmd)
308 {
309         struct tr2_tgt *tgt_j;
310         int j;
311         uint64_t us_now;
312         uint64_t us_elapsed_absolute;
313
314         if (!trace2_enabled)
315                 return;
316
317         us_now = getnanotime() / 1000;
318         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
319
320         cmd->trace2_child_id = tr2tls_locked_increment(&tr2_next_child_id);
321         cmd->trace2_child_us_start = us_now;
322
323         for_each_wanted_builtin (j, tgt_j)
324                 if (tgt_j->pfn_child_start_fl)
325                         tgt_j->pfn_child_start_fl(file, line,
326                                                   us_elapsed_absolute, cmd);
327 }
328
329 void trace2_child_exit_fl(const char *file, int line, struct child_process *cmd,
330                           int child_exit_code)
331 {
332         struct tr2_tgt *tgt_j;
333         int j;
334         uint64_t us_now;
335         uint64_t us_elapsed_absolute;
336         uint64_t us_elapsed_child;
337
338         if (!trace2_enabled)
339                 return;
340
341         us_now = getnanotime() / 1000;
342         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
343
344         if (cmd->trace2_child_us_start)
345                 us_elapsed_child = us_now - cmd->trace2_child_us_start;
346         else
347                 us_elapsed_child = 0;
348
349         for_each_wanted_builtin (j, tgt_j)
350                 if (tgt_j->pfn_child_exit_fl)
351                         tgt_j->pfn_child_exit_fl(file, line,
352                                                  us_elapsed_absolute,
353                                                  cmd->trace2_child_id, cmd->pid,
354                                                  child_exit_code,
355                                                  us_elapsed_child);
356 }
357
358 int trace2_exec_fl(const char *file, int line, const char *exe,
359                    const char **argv)
360 {
361         struct tr2_tgt *tgt_j;
362         int j;
363         int exec_id;
364         uint64_t us_now;
365         uint64_t us_elapsed_absolute;
366
367         if (!trace2_enabled)
368                 return -1;
369
370         us_now = getnanotime() / 1000;
371         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
372
373         exec_id = tr2tls_locked_increment(&tr2_next_exec_id);
374
375         for_each_wanted_builtin (j, tgt_j)
376                 if (tgt_j->pfn_exec_fl)
377                         tgt_j->pfn_exec_fl(file, line, us_elapsed_absolute,
378                                            exec_id, exe, argv);
379
380         return exec_id;
381 }
382
383 void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
384 {
385         struct tr2_tgt *tgt_j;
386         int j;
387         uint64_t us_now;
388         uint64_t us_elapsed_absolute;
389
390         if (!trace2_enabled)
391                 return;
392
393         us_now = getnanotime() / 1000;
394         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
395
396         for_each_wanted_builtin (j, tgt_j)
397                 if (tgt_j->pfn_exec_result_fl)
398                         tgt_j->pfn_exec_result_fl(
399                                 file, line, us_elapsed_absolute, exec_id, code);
400 }
401
402 void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
403 {
404         struct tr2_tgt *tgt_j;
405         int j;
406         uint64_t us_now;
407         uint64_t us_elapsed_absolute;
408
409         if (!trace2_enabled)
410                 return;
411
412         if (tr2tls_is_main_thread()) {
413                 /*
414                  * We should only be called from the new thread's thread-proc,
415                  * so this is technically a bug.  But in those cases where the
416                  * main thread also runs the thread-proc function (or when we
417                  * are built with threading disabled), we need to allow it.
418                  *
419                  * Convert this call to a region-enter so the nesting looks
420                  * correct.
421                  */
422                 trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
423                                               "thread-proc on main: %s",
424                                               thread_name);
425                 return;
426         }
427
428         us_now = getnanotime() / 1000;
429         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
430
431         tr2tls_create_self(thread_name);
432
433         for_each_wanted_builtin (j, tgt_j)
434                 if (tgt_j->pfn_thread_start_fl)
435                         tgt_j->pfn_thread_start_fl(file, line,
436                                                    us_elapsed_absolute);
437 }
438
439 void trace2_thread_exit_fl(const char *file, int line)
440 {
441         struct tr2_tgt *tgt_j;
442         int j;
443         uint64_t us_now;
444         uint64_t us_elapsed_absolute;
445         uint64_t us_elapsed_thread;
446
447         if (!trace2_enabled)
448                 return;
449
450         if (tr2tls_is_main_thread()) {
451                 /*
452                  * We should only be called from the exiting thread's
453                  * thread-proc, so this is technically a bug.  But in
454                  * those cases where the main thread also runs the
455                  * thread-proc function (or when we are built with
456                  * threading disabled), we need to allow it.
457                  *
458                  * Convert this call to a region-leave so the nesting
459                  * looks correct.
460                  */
461                 trace2_region_leave_printf_fl(file, line, NULL, NULL, NULL,
462                                               "thread-proc on main");
463                 return;
464         }
465
466         us_now = getnanotime() / 1000;
467         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
468
469         /*
470          * Clear any unbalanced regions and then get the relative time
471          * for the outer-most region (which we pushed when the thread
472          * started).  This gives us the run time of the thread.
473          */
474         tr2tls_pop_unwind_self();
475         us_elapsed_thread = tr2tls_region_elasped_self(us_now);
476
477         for_each_wanted_builtin (j, tgt_j)
478                 if (tgt_j->pfn_thread_exit_fl)
479                         tgt_j->pfn_thread_exit_fl(file, line,
480                                                   us_elapsed_absolute,
481                                                   us_elapsed_thread);
482
483         tr2tls_unset_self();
484 }
485
486 void trace2_def_param_fl(const char *file, int line, const char *param,
487                          const char *value)
488 {
489         struct tr2_tgt *tgt_j;
490         int j;
491
492         if (!trace2_enabled)
493                 return;
494
495         for_each_wanted_builtin (j, tgt_j)
496                 if (tgt_j->pfn_param_fl)
497                         tgt_j->pfn_param_fl(file, line, param, value);
498 }
499
500 void trace2_def_repo_fl(const char *file, int line, struct repository *repo)
501 {
502         struct tr2_tgt *tgt_j;
503         int j;
504
505         if (!trace2_enabled)
506                 return;
507
508         if (repo->trace2_repo_id)
509                 return;
510
511         repo->trace2_repo_id = tr2tls_locked_increment(&tr2_next_repo_id);
512
513         for_each_wanted_builtin (j, tgt_j)
514                 if (tgt_j->pfn_repo_fl)
515                         tgt_j->pfn_repo_fl(file, line, repo);
516 }
517
518 void trace2_region_enter_printf_va_fl(const char *file, int line,
519                                       const char *category, const char *label,
520                                       const struct repository *repo,
521                                       const char *fmt, va_list ap)
522 {
523         struct tr2_tgt *tgt_j;
524         int j;
525         uint64_t us_now;
526         uint64_t us_elapsed_absolute;
527
528         if (!trace2_enabled)
529                 return;
530
531         us_now = getnanotime() / 1000;
532         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
533
534         /*
535          * Print the region-enter message at the current nesting
536          * (indentation) level and then push a new level.
537          *
538          * We expect each target function to treat 'ap' as constant
539          * and use va_copy.
540          */
541         for_each_wanted_builtin (j, tgt_j)
542                 if (tgt_j->pfn_region_enter_printf_va_fl)
543                         tgt_j->pfn_region_enter_printf_va_fl(
544                                 file, line, us_elapsed_absolute, category,
545                                 label, repo, fmt, ap);
546
547         tr2tls_push_self(us_now);
548 }
549
550 void trace2_region_enter_fl(const char *file, int line, const char *category,
551                             const char *label, const struct repository *repo, ...)
552 {
553         va_list ap;
554         va_start(ap, repo);
555         trace2_region_enter_printf_va_fl(file, line, category, label, repo,
556                                          NULL, ap);
557         va_end(ap);
558
559 }
560
561 void trace2_region_enter_printf_fl(const char *file, int line,
562                                    const char *category, const char *label,
563                                    const struct repository *repo,
564                                    const char *fmt, ...)
565 {
566         va_list ap;
567
568         va_start(ap, fmt);
569         trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
570                                          ap);
571         va_end(ap);
572 }
573
574 #ifndef HAVE_VARIADIC_MACROS
575 void trace2_region_enter_printf(const char *category, const char *label,
576                                 const struct repository *repo, const char *fmt,
577                                 ...)
578 {
579         va_list ap;
580
581         va_start(ap, fmt);
582         trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
583                                          ap);
584         va_end(ap);
585 }
586 #endif
587
588 void trace2_region_leave_printf_va_fl(const char *file, int line,
589                                       const char *category, const char *label,
590                                       const struct repository *repo,
591                                       const char *fmt, va_list ap)
592 {
593         struct tr2_tgt *tgt_j;
594         int j;
595         uint64_t us_now;
596         uint64_t us_elapsed_absolute;
597         uint64_t us_elapsed_region;
598
599         if (!trace2_enabled)
600                 return;
601
602         us_now = getnanotime() / 1000;
603         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
604
605         /*
606          * Get the elapsed time in the current region before we
607          * pop it off the stack.  Pop the stack.  And then print
608          * the perf message at the new (shallower) level so that
609          * it lines up with the corresponding push/enter.
610          */
611         us_elapsed_region = tr2tls_region_elasped_self(us_now);
612
613         tr2tls_pop_self();
614
615         /*
616          * We expect each target function to treat 'ap' as constant
617          * and use va_copy.
618          */
619         for_each_wanted_builtin (j, tgt_j)
620                 if (tgt_j->pfn_region_leave_printf_va_fl)
621                         tgt_j->pfn_region_leave_printf_va_fl(
622                                 file, line, us_elapsed_absolute,
623                                 us_elapsed_region, category, label, repo, fmt,
624                                 ap);
625 }
626
627 void trace2_region_leave_fl(const char *file, int line, const char *category,
628                             const char *label, const struct repository *repo, ...)
629 {
630         va_list ap;
631         va_start(ap, repo);
632         trace2_region_leave_printf_va_fl(file, line, category, label, repo,
633                                          NULL, ap);
634         va_end(ap);
635 }
636
637 void trace2_region_leave_printf_fl(const char *file, int line,
638                                    const char *category, const char *label,
639                                    const struct repository *repo,
640                                    const char *fmt, ...)
641 {
642         va_list ap;
643
644         va_start(ap, fmt);
645         trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
646                                          ap);
647         va_end(ap);
648 }
649
650 #ifndef HAVE_VARIADIC_MACROS
651 void trace2_region_leave_printf(const char *category, const char *label,
652                                 const struct repository *repo, const char *fmt,
653                                 ...)
654 {
655         va_list ap;
656
657         va_start(ap, fmt);
658         trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
659                                          ap);
660         va_end(ap);
661 }
662 #endif
663
664 void trace2_data_string_fl(const char *file, int line, const char *category,
665                            const struct repository *repo, const char *key,
666                            const char *value)
667 {
668         struct tr2_tgt *tgt_j;
669         int j;
670         uint64_t us_now;
671         uint64_t us_elapsed_absolute;
672         uint64_t us_elapsed_region;
673
674         if (!trace2_enabled)
675                 return;
676
677         us_now = getnanotime() / 1000;
678         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
679         us_elapsed_region = tr2tls_region_elasped_self(us_now);
680
681         for_each_wanted_builtin (j, tgt_j)
682                 if (tgt_j->pfn_data_fl)
683                         tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
684                                            us_elapsed_region, category, repo,
685                                            key, value);
686 }
687
688 void trace2_data_intmax_fl(const char *file, int line, const char *category,
689                            const struct repository *repo, const char *key,
690                            intmax_t value)
691 {
692         struct strbuf buf_string = STRBUF_INIT;
693
694         if (!trace2_enabled)
695                 return;
696
697         strbuf_addf(&buf_string, "%" PRIdMAX, value);
698         trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
699         strbuf_release(&buf_string);
700 }
701
702 void trace2_data_json_fl(const char *file, int line, const char *category,
703                          const struct repository *repo, const char *key,
704                          const struct json_writer *value)
705 {
706         struct tr2_tgt *tgt_j;
707         int j;
708         uint64_t us_now;
709         uint64_t us_elapsed_absolute;
710         uint64_t us_elapsed_region;
711
712         if (!trace2_enabled)
713                 return;
714
715         us_now = getnanotime() / 1000;
716         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
717         us_elapsed_region = tr2tls_region_elasped_self(us_now);
718
719         for_each_wanted_builtin (j, tgt_j)
720                 if (tgt_j->pfn_data_fl)
721                         tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
722                                                 us_elapsed_region, category,
723                                                 repo, key, value);
724 }
725
726 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
727                          va_list ap)
728 {
729         struct tr2_tgt *tgt_j;
730         int j;
731         uint64_t us_now;
732         uint64_t us_elapsed_absolute;
733
734         if (!trace2_enabled)
735                 return;
736
737         us_now = getnanotime() / 1000;
738         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
739
740         /*
741          * We expect each target function to treat 'ap' as constant
742          * and use va_copy.
743          */
744         for_each_wanted_builtin (j, tgt_j)
745                 if (tgt_j->pfn_printf_va_fl)
746                         tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
747                                                 fmt, ap);
748 }
749
750 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
751 {
752         va_list ap;
753
754         va_start(ap, fmt);
755         trace2_printf_va_fl(file, line, fmt, ap);
756         va_end(ap);
757 }
758
759 #ifndef HAVE_VARIADIC_MACROS
760 void trace2_printf(const char *fmt, ...)
761 {
762         va_list ap;
763
764         va_start(ap, fmt);
765         trace2_printf_va_fl(NULL, 0, fmt, ap);
766         va_end(ap);
767 }
768 #endif