3 #include "run-command.h"
6 #include "json-writer.h"
7 #include "trace2/tr2_dst.h"
8 #include "trace2/tr2_sid.h"
9 #include "trace2/tr2_sysenv.h"
10 #include "trace2/tr2_tbuf.h"
11 #include "trace2/tr2_tgt.h"
12 #include "trace2/tr2_tls.h"
13 #include "trace2/tr2_tmr.h"
15 static struct tr2_dst tr2dst_perf
= {
16 .sysenv_var
= TR2_SYSENV_PERF
,
20 * Use TR2_SYSENV_PERF_BRIEF to omit the "<time> <file>:<line>"
21 * fields from each line written to the builtin performance target.
23 * Unit tests may want to use this to help with testing.
25 static int tr2env_perf_be_brief
;
27 #define TR2FMT_PERF_FL_WIDTH (28)
28 #define TR2FMT_PERF_MAX_EVENT_NAME (12)
29 #define TR2FMT_PERF_REPO_WIDTH (3)
30 #define TR2FMT_PERF_CATEGORY_WIDTH (12)
32 #define TR2_INDENT (2)
33 #define TR2_INDENT_LENGTH(ctx) (((ctx)->nr_open_regions - 1) * TR2_INDENT)
35 static int fn_init(void)
37 int want
= tr2_dst_trace_want(&tr2dst_perf
);
44 brief
= tr2_sysenv_get(TR2_SYSENV_PERF_BRIEF
);
45 if (brief
&& *brief
&&
46 ((want_brief
= git_parse_maybe_bool(brief
)) != -1))
47 tr2env_perf_be_brief
= want_brief
;
52 static void fn_term(void)
54 tr2_dst_trace_disable(&tr2dst_perf
);
58 * Format trace line prefix in human-readable classic format for
59 * the performance target:
60 * "[<time> [<file>:<line>] <bar>] <nr_parents> <bar>
61 * <thread_name> <bar> <event_name> <bar> [<repo>] <bar>
62 * [<elapsed_absolute>] [<elapsed_relative>] <bar>
63 * [<category>] <bar> [<dots>] "
65 static void perf_fmt_prepare(const char *event_name
,
66 struct tr2tls_thread_ctx
*ctx
, const char *file
,
67 int line
, const struct repository
*repo
,
68 uint64_t *p_us_elapsed_absolute
,
69 uint64_t *p_us_elapsed_relative
,
70 const char *category
, struct strbuf
*buf
)
74 strbuf_setlen(buf
, 0);
76 if (!tr2env_perf_be_brief
) {
77 struct tr2_tbuf tb_now
;
80 tr2_tbuf_local_time(&tb_now
);
81 strbuf_addstr(buf
, tb_now
.buf
);
82 strbuf_addch(buf
, ' ');
84 fl_end_col
= buf
->len
+ TR2FMT_PERF_FL_WIDTH
;
87 struct strbuf buf_fl
= STRBUF_INIT
;
89 strbuf_addf(&buf_fl
, "%s:%d", file
, line
);
91 if (buf_fl
.len
<= TR2FMT_PERF_FL_WIDTH
)
92 strbuf_addbuf(buf
, &buf_fl
);
94 size_t avail
= TR2FMT_PERF_FL_WIDTH
- 3;
95 strbuf_addstr(buf
, "...");
97 &buf_fl
.buf
[buf_fl
.len
- avail
],
101 strbuf_release(&buf_fl
);
104 while (buf
->len
< fl_end_col
)
105 strbuf_addch(buf
, ' ');
107 strbuf_addstr(buf
, " | ");
110 strbuf_addf(buf
, "d%d | ", tr2_sid_depth());
111 strbuf_addf(buf
, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME
,
112 ctx
->thread_name
, TR2FMT_PERF_MAX_EVENT_NAME
,
115 len
= buf
->len
+ TR2FMT_PERF_REPO_WIDTH
;
117 strbuf_addf(buf
, "r%d ", repo
->trace2_repo_id
);
118 while (buf
->len
< len
)
119 strbuf_addch(buf
, ' ');
120 strbuf_addstr(buf
, " | ");
122 if (p_us_elapsed_absolute
)
123 strbuf_addf(buf
, "%9.6f | ",
124 ((double)(*p_us_elapsed_absolute
)) / 1000000.0);
126 strbuf_addf(buf
, "%9s | ", " ");
128 if (p_us_elapsed_relative
)
129 strbuf_addf(buf
, "%9.6f | ",
130 ((double)(*p_us_elapsed_relative
)) / 1000000.0);
132 strbuf_addf(buf
, "%9s | ", " ");
134 strbuf_addf(buf
, "%-*.*s | ", TR2FMT_PERF_CATEGORY_WIDTH
,
135 TR2FMT_PERF_CATEGORY_WIDTH
, (category
? category
: ""));
137 if (ctx
->nr_open_regions
> 0)
138 strbuf_addchars(buf
, '.', TR2_INDENT_LENGTH(ctx
));
141 static void perf_io_write_fl(const char *file
, int line
, const char *event_name
,
142 const struct repository
*repo
,
143 uint64_t *p_us_elapsed_absolute
,
144 uint64_t *p_us_elapsed_relative
,
145 const char *category
,
146 const struct strbuf
*buf_payload
)
148 struct tr2tls_thread_ctx
*ctx
= tr2tls_get_self();
149 struct strbuf buf_line
= STRBUF_INIT
;
151 perf_fmt_prepare(event_name
, ctx
, file
, line
, repo
,
152 p_us_elapsed_absolute
, p_us_elapsed_relative
, category
,
154 strbuf_addbuf(&buf_line
, buf_payload
);
155 tr2_dst_write_line(&tr2dst_perf
, &buf_line
);
156 strbuf_release(&buf_line
);
159 static void fn_version_fl(const char *file
, int line
)
161 const char *event_name
= "version";
162 struct strbuf buf_payload
= STRBUF_INIT
;
164 strbuf_addstr(&buf_payload
, git_version_string
);
166 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
168 strbuf_release(&buf_payload
);
171 static void fn_start_fl(const char *file
, int line
,
172 uint64_t us_elapsed_absolute
, const char **argv
)
174 const char *event_name
= "start";
175 struct strbuf buf_payload
= STRBUF_INIT
;
177 sq_append_quote_argv_pretty(&buf_payload
, argv
);
179 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
180 NULL
, NULL
, &buf_payload
);
181 strbuf_release(&buf_payload
);
184 static void fn_exit_fl(const char *file
, int line
, uint64_t us_elapsed_absolute
,
187 const char *event_name
= "exit";
188 struct strbuf buf_payload
= STRBUF_INIT
;
190 strbuf_addf(&buf_payload
, "code:%d", code
);
192 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
193 NULL
, NULL
, &buf_payload
);
194 strbuf_release(&buf_payload
);
197 static void fn_signal(uint64_t us_elapsed_absolute
, int signo
)
199 const char *event_name
= "signal";
200 struct strbuf buf_payload
= STRBUF_INIT
;
202 strbuf_addf(&buf_payload
, "signo:%d", signo
);
204 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
,
205 &us_elapsed_absolute
, NULL
, NULL
, &buf_payload
);
206 strbuf_release(&buf_payload
);
209 static void fn_atexit(uint64_t us_elapsed_absolute
, int code
)
211 const char *event_name
= "atexit";
212 struct strbuf buf_payload
= STRBUF_INIT
;
214 strbuf_addf(&buf_payload
, "code:%d", code
);
216 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
,
217 &us_elapsed_absolute
, NULL
, NULL
, &buf_payload
);
218 strbuf_release(&buf_payload
);
221 static void maybe_append_string_va(struct strbuf
*buf
, const char *fmt
,
227 va_copy(copy_ap
, ap
);
228 strbuf_vaddf(buf
, fmt
, copy_ap
);
234 static void fn_error_va_fl(const char *file
, int line
, const char *fmt
,
237 const char *event_name
= "error";
238 struct strbuf buf_payload
= STRBUF_INIT
;
240 maybe_append_string_va(&buf_payload
, fmt
, ap
);
242 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
244 strbuf_release(&buf_payload
);
247 static void fn_command_path_fl(const char *file
, int line
, const char *pathname
)
249 const char *event_name
= "cmd_path";
250 struct strbuf buf_payload
= STRBUF_INIT
;
252 strbuf_addstr(&buf_payload
, pathname
);
254 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
256 strbuf_release(&buf_payload
);
259 static void fn_command_ancestry_fl(const char *file
, int line
, const char **parent_names
)
261 const char *event_name
= "cmd_ancestry";
262 struct strbuf buf_payload
= STRBUF_INIT
;
264 strbuf_addstr(&buf_payload
, "ancestry:[");
265 /* It's not an argv but the rules are basically the same. */
266 sq_append_quote_argv_pretty(&buf_payload
, parent_names
);
267 strbuf_addch(&buf_payload
, ']');
269 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
271 strbuf_release(&buf_payload
);
274 static void fn_command_name_fl(const char *file
, int line
, const char *name
,
275 const char *hierarchy
)
277 const char *event_name
= "cmd_name";
278 struct strbuf buf_payload
= STRBUF_INIT
;
280 strbuf_addstr(&buf_payload
, name
);
281 if (hierarchy
&& *hierarchy
)
282 strbuf_addf(&buf_payload
, " (%s)", hierarchy
);
284 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
286 strbuf_release(&buf_payload
);
289 static void fn_command_mode_fl(const char *file
, int line
, const char *mode
)
291 const char *event_name
= "cmd_mode";
292 struct strbuf buf_payload
= STRBUF_INIT
;
294 strbuf_addstr(&buf_payload
, mode
);
296 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
298 strbuf_release(&buf_payload
);
301 static void fn_alias_fl(const char *file
, int line
, const char *alias
,
304 const char *event_name
= "alias";
305 struct strbuf buf_payload
= STRBUF_INIT
;
307 strbuf_addf(&buf_payload
, "alias:%s argv:[", alias
);
308 sq_append_quote_argv_pretty(&buf_payload
, argv
);
309 strbuf_addch(&buf_payload
, ']');
311 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
, NULL
,
313 strbuf_release(&buf_payload
);
316 static void fn_child_start_fl(const char *file
, int line
,
317 uint64_t us_elapsed_absolute
,
318 const struct child_process
*cmd
)
320 const char *event_name
= "child_start";
321 struct strbuf buf_payload
= STRBUF_INIT
;
323 if (cmd
->trace2_hook_name
) {
324 strbuf_addf(&buf_payload
, "[ch%d] class:hook hook:%s",
325 cmd
->trace2_child_id
, cmd
->trace2_hook_name
);
327 const char *child_class
=
328 cmd
->trace2_child_class
? cmd
->trace2_child_class
: "?";
329 strbuf_addf(&buf_payload
, "[ch%d] class:%s",
330 cmd
->trace2_child_id
, child_class
);
334 strbuf_addstr(&buf_payload
, " cd:");
335 sq_quote_buf_pretty(&buf_payload
, cmd
->dir
);
338 strbuf_addstr(&buf_payload
, " argv:[");
340 strbuf_addstr(&buf_payload
, "git");
342 strbuf_addch(&buf_payload
, ' ');
344 sq_append_quote_argv_pretty(&buf_payload
, cmd
->args
.v
);
345 strbuf_addch(&buf_payload
, ']');
347 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
348 NULL
, NULL
, &buf_payload
);
349 strbuf_release(&buf_payload
);
352 static void fn_child_exit_fl(const char *file
, int line
,
353 uint64_t us_elapsed_absolute
, int cid
, int pid
,
354 int code
, uint64_t us_elapsed_child
)
356 const char *event_name
= "child_exit";
357 struct strbuf buf_payload
= STRBUF_INIT
;
359 strbuf_addf(&buf_payload
, "[ch%d] pid:%d code:%d", cid
, pid
, code
);
361 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
362 &us_elapsed_child
, NULL
, &buf_payload
);
363 strbuf_release(&buf_payload
);
366 static void fn_child_ready_fl(const char *file
, int line
,
367 uint64_t us_elapsed_absolute
, int cid
, int pid
,
368 const char *ready
, uint64_t us_elapsed_child
)
370 const char *event_name
= "child_ready";
371 struct strbuf buf_payload
= STRBUF_INIT
;
373 strbuf_addf(&buf_payload
, "[ch%d] pid:%d ready:%s", cid
, pid
, ready
);
375 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
376 &us_elapsed_child
, NULL
, &buf_payload
);
377 strbuf_release(&buf_payload
);
380 static void fn_thread_start_fl(const char *file
, int line
,
381 uint64_t us_elapsed_absolute
)
383 const char *event_name
= "thread_start";
384 struct strbuf buf_payload
= STRBUF_INIT
;
386 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
387 NULL
, NULL
, &buf_payload
);
388 strbuf_release(&buf_payload
);
391 static void fn_thread_exit_fl(const char *file
, int line
,
392 uint64_t us_elapsed_absolute
,
393 uint64_t us_elapsed_thread
)
395 const char *event_name
= "thread_exit";
396 struct strbuf buf_payload
= STRBUF_INIT
;
398 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
399 &us_elapsed_thread
, NULL
, &buf_payload
);
400 strbuf_release(&buf_payload
);
403 static void fn_exec_fl(const char *file
, int line
, uint64_t us_elapsed_absolute
,
404 int exec_id
, const char *exe
, const char **argv
)
406 const char *event_name
= "exec";
407 struct strbuf buf_payload
= STRBUF_INIT
;
409 strbuf_addf(&buf_payload
, "id:%d ", exec_id
);
410 strbuf_addstr(&buf_payload
, "argv:[");
412 strbuf_addstr(&buf_payload
, exe
);
414 strbuf_addch(&buf_payload
, ' ');
416 sq_append_quote_argv_pretty(&buf_payload
, argv
);
417 strbuf_addch(&buf_payload
, ']');
419 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
420 NULL
, NULL
, &buf_payload
);
421 strbuf_release(&buf_payload
);
424 static void fn_exec_result_fl(const char *file
, int line
,
425 uint64_t us_elapsed_absolute
, int exec_id
,
428 const char *event_name
= "exec_result";
429 struct strbuf buf_payload
= STRBUF_INIT
;
431 strbuf_addf(&buf_payload
, "id:%d code:%d", exec_id
, code
);
433 strbuf_addf(&buf_payload
, " err:%s", strerror(code
));
435 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
436 NULL
, NULL
, &buf_payload
);
437 strbuf_release(&buf_payload
);
440 static void fn_param_fl(const char *file
, int line
, const char *param
,
443 const char *event_name
= "def_param";
444 struct strbuf buf_payload
= STRBUF_INIT
;
445 struct strbuf scope_payload
= STRBUF_INIT
;
446 enum config_scope scope
= current_config_scope();
447 const char *scope_name
= config_scope_name(scope
);
449 strbuf_addf(&buf_payload
, "%s:%s", param
, value
);
450 strbuf_addf(&scope_payload
, "%s:%s", "scope", scope_name
);
452 perf_io_write_fl(file
, line
, event_name
, NULL
, NULL
, NULL
,
453 scope_payload
.buf
, &buf_payload
);
454 strbuf_release(&buf_payload
);
455 strbuf_release(&scope_payload
);
458 static void fn_repo_fl(const char *file
, int line
,
459 const struct repository
*repo
)
461 const char *event_name
= "def_repo";
462 struct strbuf buf_payload
= STRBUF_INIT
;
464 strbuf_addstr(&buf_payload
, "worktree:");
465 sq_quote_buf_pretty(&buf_payload
, repo
->worktree
);
467 perf_io_write_fl(file
, line
, event_name
, repo
, NULL
, NULL
, NULL
,
469 strbuf_release(&buf_payload
);
472 static void fn_region_enter_printf_va_fl(const char *file
, int line
,
473 uint64_t us_elapsed_absolute
,
474 const char *category
,
476 const struct repository
*repo
,
477 const char *fmt
, va_list ap
)
479 const char *event_name
= "region_enter";
480 struct strbuf buf_payload
= STRBUF_INIT
;
483 strbuf_addf(&buf_payload
, "label:%s", label
);
485 strbuf_addch(&buf_payload
, ' ');
486 maybe_append_string_va(&buf_payload
, fmt
, ap
);
489 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
490 NULL
, category
, &buf_payload
);
491 strbuf_release(&buf_payload
);
494 static void fn_region_leave_printf_va_fl(
495 const char *file
, int line
, uint64_t us_elapsed_absolute
,
496 uint64_t us_elapsed_region
, const char *category
, const char *label
,
497 const struct repository
*repo
, const char *fmt
, va_list ap
)
499 const char *event_name
= "region_leave";
500 struct strbuf buf_payload
= STRBUF_INIT
;
503 strbuf_addf(&buf_payload
, "label:%s", label
);
505 strbuf_addch(&buf_payload
, ' ' );
506 maybe_append_string_va(&buf_payload
, fmt
, ap
);
509 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
510 &us_elapsed_region
, category
, &buf_payload
);
511 strbuf_release(&buf_payload
);
514 static void fn_data_fl(const char *file
, int line
, uint64_t us_elapsed_absolute
,
515 uint64_t us_elapsed_region
, const char *category
,
516 const struct repository
*repo
, const char *key
,
519 const char *event_name
= "data";
520 struct strbuf buf_payload
= STRBUF_INIT
;
522 strbuf_addf(&buf_payload
, "%s:%s", key
, value
);
524 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
525 &us_elapsed_region
, category
, &buf_payload
);
526 strbuf_release(&buf_payload
);
529 static void fn_data_json_fl(const char *file
, int line
,
530 uint64_t us_elapsed_absolute
,
531 uint64_t us_elapsed_region
, const char *category
,
532 const struct repository
*repo
, const char *key
,
533 const struct json_writer
*value
)
535 const char *event_name
= "data_json";
536 struct strbuf buf_payload
= STRBUF_INIT
;
538 strbuf_addf(&buf_payload
, "%s:%s", key
, value
->json
.buf
);
540 perf_io_write_fl(file
, line
, event_name
, repo
, &us_elapsed_absolute
,
541 &us_elapsed_region
, category
, &buf_payload
);
542 strbuf_release(&buf_payload
);
545 static void fn_printf_va_fl(const char *file
, int line
,
546 uint64_t us_elapsed_absolute
, const char *fmt
,
549 const char *event_name
= "printf";
550 struct strbuf buf_payload
= STRBUF_INIT
;
552 maybe_append_string_va(&buf_payload
, fmt
, ap
);
554 perf_io_write_fl(file
, line
, event_name
, NULL
, &us_elapsed_absolute
,
555 NULL
, NULL
, &buf_payload
);
556 strbuf_release(&buf_payload
);
559 static void fn_timer(const struct tr2_timer_metadata
*meta
,
560 const struct tr2_timer
*timer
,
563 const char *event_name
= is_final_data
? "timer" : "th_timer";
564 struct strbuf buf_payload
= STRBUF_INIT
;
565 double t_total
= NS_TO_SEC(timer
->total_ns
);
566 double t_min
= NS_TO_SEC(timer
->min_ns
);
567 double t_max
= NS_TO_SEC(timer
->max_ns
);
569 strbuf_addf(&buf_payload
, ("name:%s"
571 " total:%8.6f min:%8.6f max:%8.6f"),
573 timer
->interval_count
,
574 t_total
, t_min
, t_max
);
576 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
, NULL
, NULL
,
577 meta
->category
, &buf_payload
);
578 strbuf_release(&buf_payload
);
581 static void fn_counter(const struct tr2_counter_metadata
*meta
,
582 const struct tr2_counter
*counter
,
585 const char *event_name
= is_final_data
? "counter" : "th_counter";
586 struct strbuf buf_payload
= STRBUF_INIT
;
588 strbuf_addf(&buf_payload
, "name:%s value:%"PRIu64
,
592 perf_io_write_fl(__FILE__
, __LINE__
, event_name
, NULL
, NULL
, NULL
,
593 meta
->category
, &buf_payload
);
594 strbuf_release(&buf_payload
);
597 struct tr2_tgt tr2_tgt_perf
= {
598 .pdst
= &tr2dst_perf
,
603 .pfn_version_fl
= fn_version_fl
,
604 .pfn_start_fl
= fn_start_fl
,
605 .pfn_exit_fl
= fn_exit_fl
,
606 .pfn_signal
= fn_signal
,
607 .pfn_atexit
= fn_atexit
,
608 .pfn_error_va_fl
= fn_error_va_fl
,
609 .pfn_command_path_fl
= fn_command_path_fl
,
610 .pfn_command_ancestry_fl
= fn_command_ancestry_fl
,
611 .pfn_command_name_fl
= fn_command_name_fl
,
612 .pfn_command_mode_fl
= fn_command_mode_fl
,
613 .pfn_alias_fl
= fn_alias_fl
,
614 .pfn_child_start_fl
= fn_child_start_fl
,
615 .pfn_child_exit_fl
= fn_child_exit_fl
,
616 .pfn_child_ready_fl
= fn_child_ready_fl
,
617 .pfn_thread_start_fl
= fn_thread_start_fl
,
618 .pfn_thread_exit_fl
= fn_thread_exit_fl
,
619 .pfn_exec_fl
= fn_exec_fl
,
620 .pfn_exec_result_fl
= fn_exec_result_fl
,
621 .pfn_param_fl
= fn_param_fl
,
622 .pfn_repo_fl
= fn_repo_fl
,
623 .pfn_region_enter_printf_va_fl
= fn_region_enter_printf_va_fl
,
624 .pfn_region_leave_printf_va_fl
= fn_region_leave_printf_va_fl
,
625 .pfn_data_fl
= fn_data_fl
,
626 .pfn_data_json_fl
= fn_data_json_fl
,
627 .pfn_printf_va_fl
= fn_printf_va_fl
,
628 .pfn_timer
= fn_timer
,
629 .pfn_counter
= fn_counter
,