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