1 #include "git-compat-util.h"
3 #include "repository.h"
4 #include "run-command.h"
7 #include "json-writer.h"
8 #include "trace2/tr2_dst.h"
9 #include "trace2/tr2_sid.h"
10 #include "trace2/tr2_sysenv.h"
11 #include "trace2/tr2_tbuf.h"
12 #include "trace2/tr2_tgt.h"
13 #include "trace2/tr2_tls.h"
14 #include "trace2/tr2_tmr.h"
16 static struct tr2_dst tr2dst_perf
= {
17 .sysenv_var
= TR2_SYSENV_PERF
,
21 * Use TR2_SYSENV_PERF_BRIEF to omit the "<time> <file>:<line>"
22 * fields from each line written to the builtin performance target.
24 * Unit tests may want to use this to help with testing.
26 static int tr2env_perf_be_brief
;
28 #define TR2FMT_PERF_FL_WIDTH (28)
29 #define TR2FMT_PERF_MAX_EVENT_NAME (12)
30 #define TR2FMT_PERF_REPO_WIDTH (3)
31 #define TR2FMT_PERF_CATEGORY_WIDTH (12)
33 #define TR2_INDENT (2)
34 #define TR2_INDENT_LENGTH(ctx) (((ctx)->nr_open_regions - 1) * TR2_INDENT)
36 static int fn_init(void)
38 int want
= tr2_dst_trace_want(&tr2dst_perf
);
45 brief
= tr2_sysenv_get(TR2_SYSENV_PERF_BRIEF
);
46 if (brief
&& *brief
&&
47 ((want_brief
= git_parse_maybe_bool(brief
)) != -1))
48 tr2env_perf_be_brief
= want_brief
;
53 static void fn_term(void)
55 tr2_dst_trace_disable(&tr2dst_perf
);
59 * Format trace line prefix in human-readable classic format for
60 * the performance target:
61 * "[<time> [<file>:<line>] <bar>] <nr_parents> <bar>
62 * <thread_name> <bar> <event_name> <bar> [<repo>] <bar>
63 * [<elapsed_absolute>] [<elapsed_relative>] <bar>
64 * [<category>] <bar> [<dots>] "
66 static void perf_fmt_prepare(const char *event_name
,
67 struct tr2tls_thread_ctx
*ctx
, const char *file
,
68 int line
, const struct repository
*repo
,
69 uint64_t *p_us_elapsed_absolute
,
70 uint64_t *p_us_elapsed_relative
,
71 const char *category
, struct strbuf
*buf
)
75 strbuf_setlen(buf
, 0);
77 if (!tr2env_perf_be_brief
) {
78 struct tr2_tbuf tb_now
;
81 tr2_tbuf_local_time(&tb_now
);
82 strbuf_addstr(buf
, tb_now
.buf
);
83 strbuf_addch(buf
, ' ');
85 fl_end_col
= buf
->len
+ TR2FMT_PERF_FL_WIDTH
;
88 struct strbuf buf_fl
= STRBUF_INIT
;
90 strbuf_addf(&buf_fl
, "%s:%d", file
, line
);
92 if (buf_fl
.len
<= TR2FMT_PERF_FL_WIDTH
)
93 strbuf_addbuf(buf
, &buf_fl
);
95 size_t avail
= TR2FMT_PERF_FL_WIDTH
- 3;
96 strbuf_addstr(buf
, "...");
98 &buf_fl
.buf
[buf_fl
.len
- avail
],
102 strbuf_release(&buf_fl
);
105 while (buf
->len
< fl_end_col
)
106 strbuf_addch(buf
, ' ');
108 strbuf_addstr(buf
, " | ");
111 strbuf_addf(buf
, "d%d | ", tr2_sid_depth());
112 strbuf_addf(buf
, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME
,
113 ctx
->thread_name
, TR2FMT_PERF_MAX_EVENT_NAME
,
116 len
= buf
->len
+ TR2FMT_PERF_REPO_WIDTH
;
118 strbuf_addf(buf
, "r%d ", repo
->trace2_repo_id
);
119 while (buf
->len
< len
)
120 strbuf_addch(buf
, ' ');
121 strbuf_addstr(buf
, " | ");
123 if (p_us_elapsed_absolute
)
124 strbuf_addf(buf
, "%9.6f | ",
125 ((double)(*p_us_elapsed_absolute
)) / 1000000.0);
127 strbuf_addf(buf
, "%9s | ", " ");
129 if (p_us_elapsed_relative
)
130 strbuf_addf(buf
, "%9.6f | ",
131 ((double)(*p_us_elapsed_relative
)) / 1000000.0);
133 strbuf_addf(buf
, "%9s | ", " ");
135 strbuf_addf(buf
, "%-*.*s | ", TR2FMT_PERF_CATEGORY_WIDTH
,
136 TR2FMT_PERF_CATEGORY_WIDTH
, (category
? category
: ""));
138 if (ctx
->nr_open_regions
> 0)
139 strbuf_addchars(buf
, '.', TR2_INDENT_LENGTH(ctx
));
142 static void perf_io_write_fl(const char *file
, int line
, const char *event_name
,
143 const struct repository
*repo
,
144 uint64_t *p_us_elapsed_absolute
,
145 uint64_t *p_us_elapsed_relative
,
146 const char *category
,
147 const struct strbuf
*buf_payload
)
149 struct tr2tls_thread_ctx
*ctx
= tr2tls_get_self();
150 struct strbuf buf_line
= STRBUF_INIT
;
152 perf_fmt_prepare(event_name
, ctx
, file
, line
, repo
,
153 p_us_elapsed_absolute
, p_us_elapsed_relative
, category
,
155 strbuf_addbuf(&buf_line
, buf_payload
);
156 tr2_dst_write_line(&tr2dst_perf
, &buf_line
);
157 strbuf_release(&buf_line
);
160 static void fn_version_fl(const char *file
, int line
)
162 const char *event_name
= "version";
163 struct strbuf buf_payload
= STRBUF_INIT
;
165 strbuf_addstr(&buf_payload
, git_version_string
);
167 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
169 strbuf_release(&buf_payload
);
172 static void fn_start_fl(const char *file
, int line
,
173 uint64_t us_elapsed_absolute
, const char **argv
)
175 const char *event_name
= "start";
176 struct strbuf buf_payload
= STRBUF_INIT
;
178 sq_append_quote_argv_pretty(&buf_payload
, argv
);
180 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
181 NULL
, NULL
, &buf_payload
);
182 strbuf_release(&buf_payload
);
185 static void fn_exit_fl(const char *file
, int line
, uint64_t us_elapsed_absolute
,
188 const char *event_name
= "exit";
189 struct strbuf buf_payload
= STRBUF_INIT
;
191 strbuf_addf(&buf_payload
, "code:%d", code
);
193 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
194 NULL
, NULL
, &buf_payload
);
195 strbuf_release(&buf_payload
);
198 static void fn_signal(uint64_t us_elapsed_absolute
, int signo
)
200 const char *event_name
= "signal";
201 struct strbuf buf_payload
= STRBUF_INIT
;
203 strbuf_addf(&buf_payload
, "signo:%d", signo
);
205 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
,
206 &us_elapsed_absolute
, NULL
, NULL
, &buf_payload
);
207 strbuf_release(&buf_payload
);
210 static void fn_atexit(uint64_t us_elapsed_absolute
, int code
)
212 const char *event_name
= "atexit";
213 struct strbuf buf_payload
= STRBUF_INIT
;
215 strbuf_addf(&buf_payload
, "code:%d", code
);
217 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
,
218 &us_elapsed_absolute
, NULL
, NULL
, &buf_payload
);
219 strbuf_release(&buf_payload
);
222 static void maybe_append_string_va(struct strbuf
*buf
, const char *fmt
,
228 va_copy(copy_ap
, ap
);
229 strbuf_vaddf(buf
, fmt
, copy_ap
);
235 static void fn_error_va_fl(const char *file
, int line
, const char *fmt
,
238 const char *event_name
= "error";
239 struct strbuf buf_payload
= STRBUF_INIT
;
241 maybe_append_string_va(&buf_payload
, fmt
, ap
);
243 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
245 strbuf_release(&buf_payload
);
248 static void fn_command_path_fl(const char *file
, int line
, const char *pathname
)
250 const char *event_name
= "cmd_path";
251 struct strbuf buf_payload
= STRBUF_INIT
;
253 strbuf_addstr(&buf_payload
, pathname
);
255 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
257 strbuf_release(&buf_payload
);
260 static void fn_command_ancestry_fl(const char *file
, int line
, const char **parent_names
)
262 const char *event_name
= "cmd_ancestry";
263 struct strbuf buf_payload
= STRBUF_INIT
;
265 strbuf_addstr(&buf_payload
, "ancestry:[");
266 /* It's not an argv but the rules are basically the same. */
267 sq_append_quote_argv_pretty(&buf_payload
, parent_names
);
268 strbuf_addch(&buf_payload
, ']');
270 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
272 strbuf_release(&buf_payload
);
275 static void fn_command_name_fl(const char *file
, int line
, const char *name
,
276 const char *hierarchy
)
278 const char *event_name
= "cmd_name";
279 struct strbuf buf_payload
= STRBUF_INIT
;
281 strbuf_addstr(&buf_payload
, name
);
282 if (hierarchy
&& *hierarchy
)
283 strbuf_addf(&buf_payload
, " (%s)", hierarchy
);
285 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
287 strbuf_release(&buf_payload
);
290 static void fn_command_mode_fl(const char *file
, int line
, const char *mode
)
292 const char *event_name
= "cmd_mode";
293 struct strbuf buf_payload
= STRBUF_INIT
;
295 strbuf_addstr(&buf_payload
, mode
);
297 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
299 strbuf_release(&buf_payload
);
302 static void fn_alias_fl(const char *file
, int line
, const char *alias
,
305 const char *event_name
= "alias";
306 struct strbuf buf_payload
= STRBUF_INIT
;
308 strbuf_addf(&buf_payload
, "alias:%s argv:[", alias
);
309 sq_append_quote_argv_pretty(&buf_payload
, argv
);
310 strbuf_addch(&buf_payload
, ']');
312 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
314 strbuf_release(&buf_payload
);
317 static void fn_child_start_fl(const char *file
, int line
,
318 uint64_t us_elapsed_absolute
,
319 const struct child_process
*cmd
)
321 const char *event_name
= "child_start";
322 struct strbuf buf_payload
= STRBUF_INIT
;
324 if (cmd
->trace2_hook_name
) {
325 strbuf_addf(&buf_payload
, "[ch%d] class:hook hook:%s",
326 cmd
->trace2_child_id
, cmd
->trace2_hook_name
);
328 const char *child_class
=
329 cmd
->trace2_child_class
? cmd
->trace2_child_class
: "?";
330 strbuf_addf(&buf_payload
, "[ch%d] class:%s",
331 cmd
->trace2_child_id
, child_class
);
335 strbuf_addstr(&buf_payload
, " cd:");
336 sq_quote_buf_pretty(&buf_payload
, cmd
->dir
);
339 strbuf_addstr(&buf_payload
, " argv:[");
341 strbuf_addstr(&buf_payload
, "git");
343 strbuf_addch(&buf_payload
, ' ');
345 sq_append_quote_argv_pretty(&buf_payload
, cmd
->args
.v
);
346 strbuf_addch(&buf_payload
, ']');
348 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
349 NULL
, NULL
, &buf_payload
);
350 strbuf_release(&buf_payload
);
353 static void fn_child_exit_fl(const char *file
, int line
,
354 uint64_t us_elapsed_absolute
, int cid
, int pid
,
355 int code
, uint64_t us_elapsed_child
)
357 const char *event_name
= "child_exit";
358 struct strbuf buf_payload
= STRBUF_INIT
;
360 strbuf_addf(&buf_payload
, "[ch%d] pid:%d code:%d", cid
, pid
, code
);
362 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
363 &us_elapsed_child
, NULL
, &buf_payload
);
364 strbuf_release(&buf_payload
);
367 static void fn_child_ready_fl(const char *file
, int line
,
368 uint64_t us_elapsed_absolute
, int cid
, int pid
,
369 const char *ready
, uint64_t us_elapsed_child
)
371 const char *event_name
= "child_ready";
372 struct strbuf buf_payload
= STRBUF_INIT
;
374 strbuf_addf(&buf_payload
, "[ch%d] pid:%d ready:%s", cid
, pid
, ready
);
376 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
377 &us_elapsed_child
, NULL
, &buf_payload
);
378 strbuf_release(&buf_payload
);
381 static void fn_thread_start_fl(const char *file
, int line
,
382 uint64_t us_elapsed_absolute
)
384 const char *event_name
= "thread_start";
385 struct strbuf buf_payload
= STRBUF_INIT
;
387 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
388 NULL
, NULL
, &buf_payload
);
389 strbuf_release(&buf_payload
);
392 static void fn_thread_exit_fl(const char *file
, int line
,
393 uint64_t us_elapsed_absolute
,
394 uint64_t us_elapsed_thread
)
396 const char *event_name
= "thread_exit";
397 struct strbuf buf_payload
= STRBUF_INIT
;
399 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
400 &us_elapsed_thread
, NULL
, &buf_payload
);
401 strbuf_release(&buf_payload
);
404 static void fn_exec_fl(const char *file
, int line
, uint64_t us_elapsed_absolute
,
405 int exec_id
, const char *exe
, const char **argv
)
407 const char *event_name
= "exec";
408 struct strbuf buf_payload
= STRBUF_INIT
;
410 strbuf_addf(&buf_payload
, "id:%d ", exec_id
);
411 strbuf_addstr(&buf_payload
, "argv:[");
413 strbuf_addstr(&buf_payload
, exe
);
415 strbuf_addch(&buf_payload
, ' ');
417 sq_append_quote_argv_pretty(&buf_payload
, argv
);
418 strbuf_addch(&buf_payload
, ']');
420 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
421 NULL
, NULL
, &buf_payload
);
422 strbuf_release(&buf_payload
);
425 static void fn_exec_result_fl(const char *file
, int line
,
426 uint64_t us_elapsed_absolute
, int exec_id
,
429 const char *event_name
= "exec_result";
430 struct strbuf buf_payload
= STRBUF_INIT
;
432 strbuf_addf(&buf_payload
, "id:%d code:%d", exec_id
, code
);
434 strbuf_addf(&buf_payload
, " err:%s", strerror(code
));
436 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
437 NULL
, NULL
, &buf_payload
);
438 strbuf_release(&buf_payload
);
441 static void fn_param_fl(const char *file
, int line
, const char *param
,
442 const char *value
, const struct key_value_info
*kvi
)
444 const char *event_name
= "def_param";
445 struct strbuf buf_payload
= STRBUF_INIT
;
446 struct strbuf scope_payload
= STRBUF_INIT
;
447 enum config_scope scope
= kvi
->scope
;
448 const char *scope_name
= config_scope_name(scope
);
450 strbuf_addf(&buf_payload
, "%s:%s", param
, value
);
451 strbuf_addf(&scope_payload
, "%s:%s", "scope", scope_name
);
453 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
,
454 scope_payload
.buf
, &buf_payload
);
455 strbuf_release(&buf_payload
);
456 strbuf_release(&scope_payload
);
459 static void fn_repo_fl(const char *file
, int line
,
460 const struct repository
*repo
)
462 const char *event_name
= "def_repo";
463 struct strbuf buf_payload
= STRBUF_INIT
;
465 strbuf_addstr(&buf_payload
, "worktree:");
466 sq_quote_buf_pretty(&buf_payload
, repo
->worktree
);
468 perf_io_write_fl(file
, line
, event_name
, repo
, NULL
, NULL
, NULL
,
470 strbuf_release(&buf_payload
);
473 static void fn_region_enter_printf_va_fl(const char *file
, int line
,
474 uint64_t us_elapsed_absolute
,
475 const char *category
,
477 const struct repository
*repo
,
478 const char *fmt
, va_list ap
)
480 const char *event_name
= "region_enter";
481 struct strbuf buf_payload
= STRBUF_INIT
;
484 strbuf_addf(&buf_payload
, "label:%s", label
);
486 strbuf_addch(&buf_payload
, ' ');
487 maybe_append_string_va(&buf_payload
, fmt
, ap
);
490 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
491 NULL
, category
, &buf_payload
);
492 strbuf_release(&buf_payload
);
495 static void fn_region_leave_printf_va_fl(
496 const char *file
, int line
, uint64_t us_elapsed_absolute
,
497 uint64_t us_elapsed_region
, const char *category
, const char *label
,
498 const struct repository
*repo
, const char *fmt
, va_list ap
)
500 const char *event_name
= "region_leave";
501 struct strbuf buf_payload
= STRBUF_INIT
;
504 strbuf_addf(&buf_payload
, "label:%s", label
);
506 strbuf_addch(&buf_payload
, ' ' );
507 maybe_append_string_va(&buf_payload
, fmt
, ap
);
510 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
511 &us_elapsed_region
, category
, &buf_payload
);
512 strbuf_release(&buf_payload
);
515 static void fn_data_fl(const char *file
, int line
, uint64_t us_elapsed_absolute
,
516 uint64_t us_elapsed_region
, const char *category
,
517 const struct repository
*repo
, const char *key
,
520 const char *event_name
= "data";
521 struct strbuf buf_payload
= STRBUF_INIT
;
523 strbuf_addf(&buf_payload
, "%s:%s", key
, value
);
525 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
526 &us_elapsed_region
, category
, &buf_payload
);
527 strbuf_release(&buf_payload
);
530 static void fn_data_json_fl(const char *file
, int line
,
531 uint64_t us_elapsed_absolute
,
532 uint64_t us_elapsed_region
, const char *category
,
533 const struct repository
*repo
, const char *key
,
534 const struct json_writer
*value
)
536 const char *event_name
= "data_json";
537 struct strbuf buf_payload
= STRBUF_INIT
;
539 strbuf_addf(&buf_payload
, "%s:%s", key
, value
->json
.buf
);
541 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
542 &us_elapsed_region
, category
, &buf_payload
);
543 strbuf_release(&buf_payload
);
546 static void fn_printf_va_fl(const char *file
, int line
,
547 uint64_t us_elapsed_absolute
, const char *fmt
,
550 const char *event_name
= "printf";
551 struct strbuf buf_payload
= STRBUF_INIT
;
553 maybe_append_string_va(&buf_payload
, fmt
, ap
);
555 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
556 NULL
, NULL
, &buf_payload
);
557 strbuf_release(&buf_payload
);
560 static void fn_timer(const struct tr2_timer_metadata
*meta
,
561 const struct tr2_timer
*timer
,
564 const char *event_name
= is_final_data
? "timer" : "th_timer";
565 struct strbuf buf_payload
= STRBUF_INIT
;
566 double t_total
= NS_TO_SEC(timer
->total_ns
);
567 double t_min
= NS_TO_SEC(timer
->min_ns
);
568 double t_max
= NS_TO_SEC(timer
->max_ns
);
570 strbuf_addf(&buf_payload
, ("name:%s"
572 " total:%8.6f min:%8.6f max:%8.6f"),
574 timer
->interval_count
,
575 t_total
, t_min
, t_max
);
577 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
, NULL
, NULL
,
578 meta
->category
, &buf_payload
);
579 strbuf_release(&buf_payload
);
582 static void fn_counter(const struct tr2_counter_metadata
*meta
,
583 const struct tr2_counter
*counter
,
586 const char *event_name
= is_final_data
? "counter" : "th_counter";
587 struct strbuf buf_payload
= STRBUF_INIT
;
589 strbuf_addf(&buf_payload
, "name:%s value:%"PRIu64
,
593 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
, NULL
, NULL
,
594 meta
->category
, &buf_payload
);
595 strbuf_release(&buf_payload
);
598 struct tr2_tgt tr2_tgt_perf
= {
599 .pdst
= &tr2dst_perf
,
604 .pfn_version_fl
= fn_version_fl
,
605 .pfn_start_fl
= fn_start_fl
,
606 .pfn_exit_fl
= fn_exit_fl
,
607 .pfn_signal
= fn_signal
,
608 .pfn_atexit
= fn_atexit
,
609 .pfn_error_va_fl
= fn_error_va_fl
,
610 .pfn_command_path_fl
= fn_command_path_fl
,
611 .pfn_command_ancestry_fl
= fn_command_ancestry_fl
,
612 .pfn_command_name_fl
= fn_command_name_fl
,
613 .pfn_command_mode_fl
= fn_command_mode_fl
,
614 .pfn_alias_fl
= fn_alias_fl
,
615 .pfn_child_start_fl
= fn_child_start_fl
,
616 .pfn_child_exit_fl
= fn_child_exit_fl
,
617 .pfn_child_ready_fl
= fn_child_ready_fl
,
618 .pfn_thread_start_fl
= fn_thread_start_fl
,
619 .pfn_thread_exit_fl
= fn_thread_exit_fl
,
620 .pfn_exec_fl
= fn_exec_fl
,
621 .pfn_exec_result_fl
= fn_exec_result_fl
,
622 .pfn_param_fl
= fn_param_fl
,
623 .pfn_repo_fl
= fn_repo_fl
,
624 .pfn_region_enter_printf_va_fl
= fn_region_enter_printf_va_fl
,
625 .pfn_region_leave_printf_va_fl
= fn_region_leave_printf_va_fl
,
626 .pfn_data_fl
= fn_data_fl
,
627 .pfn_data_json_fl
= fn_data_json_fl
,
628 .pfn_printf_va_fl
= fn_printf_va_fl
,
629 .pfn_timer
= fn_timer
,
630 .pfn_counter
= fn_counter
,