trace2: fix incorrect function pointer check
[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         trace2_region_enter_printf_va_fl(file, line, category, label, repo,
554                                          NULL, NULL);
555 }
556
557 void trace2_region_enter_printf_fl(const char *file, int line,
558                                    const char *category, const char *label,
559                                    const struct repository *repo,
560                                    const char *fmt, ...)
561 {
562         va_list ap;
563
564         va_start(ap, fmt);
565         trace2_region_enter_printf_va_fl(file, line, category, label, repo, fmt,
566                                          ap);
567         va_end(ap);
568 }
569
570 #ifndef HAVE_VARIADIC_MACROS
571 void trace2_region_enter_printf(const char *category, const char *label,
572                                 const struct repository *repo, const char *fmt,
573                                 ...)
574 {
575         va_list ap;
576
577         va_start(ap, fmt);
578         trace2_region_enter_printf_va_fl(NULL, 0, category, label, repo, fmt,
579                                          ap);
580         va_end(ap);
581 }
582 #endif
583
584 void trace2_region_leave_printf_va_fl(const char *file, int line,
585                                       const char *category, const char *label,
586                                       const struct repository *repo,
587                                       const char *fmt, va_list ap)
588 {
589         struct tr2_tgt *tgt_j;
590         int j;
591         uint64_t us_now;
592         uint64_t us_elapsed_absolute;
593         uint64_t us_elapsed_region;
594
595         if (!trace2_enabled)
596                 return;
597
598         us_now = getnanotime() / 1000;
599         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
600
601         /*
602          * Get the elapsed time in the current region before we
603          * pop it off the stack.  Pop the stack.  And then print
604          * the perf message at the new (shallower) level so that
605          * it lines up with the corresponding push/enter.
606          */
607         us_elapsed_region = tr2tls_region_elasped_self(us_now);
608
609         tr2tls_pop_self();
610
611         /*
612          * We expect each target function to treat 'ap' as constant
613          * and use va_copy.
614          */
615         for_each_wanted_builtin (j, tgt_j)
616                 if (tgt_j->pfn_region_leave_printf_va_fl)
617                         tgt_j->pfn_region_leave_printf_va_fl(
618                                 file, line, us_elapsed_absolute,
619                                 us_elapsed_region, category, label, repo, fmt,
620                                 ap);
621 }
622
623 void trace2_region_leave_fl(const char *file, int line, const char *category,
624                             const char *label, const struct repository *repo)
625 {
626         trace2_region_leave_printf_va_fl(file, line, category, label, repo,
627                                          NULL, NULL);
628 }
629
630 void trace2_region_leave_printf_fl(const char *file, int line,
631                                    const char *category, const char *label,
632                                    const struct repository *repo,
633                                    const char *fmt, ...)
634 {
635         va_list ap;
636
637         va_start(ap, fmt);
638         trace2_region_leave_printf_va_fl(file, line, category, label, repo, fmt,
639                                          ap);
640         va_end(ap);
641 }
642
643 #ifndef HAVE_VARIADIC_MACROS
644 void trace2_region_leave_printf(const char *category, const char *label,
645                                 const struct repository *repo, const char *fmt,
646                                 ...)
647 {
648         va_list ap;
649
650         va_start(ap, fmt);
651         trace2_region_leave_printf_va_fl(NULL, 0, category, label, repo, fmt,
652                                          ap);
653         va_end(ap);
654 }
655 #endif
656
657 void trace2_data_string_fl(const char *file, int line, const char *category,
658                            const struct repository *repo, const char *key,
659                            const char *value)
660 {
661         struct tr2_tgt *tgt_j;
662         int j;
663         uint64_t us_now;
664         uint64_t us_elapsed_absolute;
665         uint64_t us_elapsed_region;
666
667         if (!trace2_enabled)
668                 return;
669
670         us_now = getnanotime() / 1000;
671         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
672         us_elapsed_region = tr2tls_region_elasped_self(us_now);
673
674         for_each_wanted_builtin (j, tgt_j)
675                 if (tgt_j->pfn_data_fl)
676                         tgt_j->pfn_data_fl(file, line, us_elapsed_absolute,
677                                            us_elapsed_region, category, repo,
678                                            key, value);
679 }
680
681 void trace2_data_intmax_fl(const char *file, int line, const char *category,
682                            const struct repository *repo, const char *key,
683                            intmax_t value)
684 {
685         struct strbuf buf_string = STRBUF_INIT;
686
687         if (!trace2_enabled)
688                 return;
689
690         strbuf_addf(&buf_string, "%" PRIdMAX, value);
691         trace2_data_string_fl(file, line, category, repo, key, buf_string.buf);
692         strbuf_release(&buf_string);
693 }
694
695 void trace2_data_json_fl(const char *file, int line, const char *category,
696                          const struct repository *repo, const char *key,
697                          const struct json_writer *value)
698 {
699         struct tr2_tgt *tgt_j;
700         int j;
701         uint64_t us_now;
702         uint64_t us_elapsed_absolute;
703         uint64_t us_elapsed_region;
704
705         if (!trace2_enabled)
706                 return;
707
708         us_now = getnanotime() / 1000;
709         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
710         us_elapsed_region = tr2tls_region_elasped_self(us_now);
711
712         for_each_wanted_builtin (j, tgt_j)
713                 if (tgt_j->pfn_data_json_fl)
714                         tgt_j->pfn_data_json_fl(file, line, us_elapsed_absolute,
715                                                 us_elapsed_region, category,
716                                                 repo, key, value);
717 }
718
719 void trace2_printf_va_fl(const char *file, int line, const char *fmt,
720                          va_list ap)
721 {
722         struct tr2_tgt *tgt_j;
723         int j;
724         uint64_t us_now;
725         uint64_t us_elapsed_absolute;
726
727         if (!trace2_enabled)
728                 return;
729
730         us_now = getnanotime() / 1000;
731         us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
732
733         /*
734          * We expect each target function to treat 'ap' as constant
735          * and use va_copy.
736          */
737         for_each_wanted_builtin (j, tgt_j)
738                 if (tgt_j->pfn_printf_va_fl)
739                         tgt_j->pfn_printf_va_fl(file, line, us_elapsed_absolute,
740                                                 fmt, ap);
741 }
742
743 void trace2_printf_fl(const char *file, int line, const char *fmt, ...)
744 {
745         va_list ap;
746
747         va_start(ap, fmt);
748         trace2_printf_va_fl(file, line, fmt, ap);
749         va_end(ap);
750 }
751
752 #ifndef HAVE_VARIADIC_MACROS
753 void trace2_printf(const char *fmt, ...)
754 {
755         va_list ap;
756
757         va_start(ap, fmt);
758         trace2_printf_va_fl(NULL, 0, fmt, ap);
759         va_end(ap);
760 }
761 #endif