Raw
1 #define DISABLE_SIGN_COMPARE_WARNINGS
2
3 #include "git-compat-util.h"
4 #include "config.h"
5 #include "repository.h"
6 #include "run-command.h"
7 #include "quote.h"
8 #include "version.h"
9 #include "json-writer.h"
10 #include "trace2/tr2_dst.h"
11 #include "trace2/tr2_sid.h"
12 #include "trace2/tr2_sysenv.h"
13 #include "trace2/tr2_tbuf.h"
14 #include "trace2/tr2_tgt.h"
15 #include "trace2/tr2_tls.h"
16 #include "trace2/tr2_tmr.h"
17
18 static struct tr2_dst tr2dst_perf = {
19 .sysenv_var = TR2_SYSENV_PERF,
20 };
21
22 /*
23 * Use TR2_SYSENV_PERF_BRIEF to omit the "<time> <file>:<line>"
24 * fields from each line written to the builtin performance target.
25 *
26 * Unit tests may want to use this to help with testing.
27 */
28 static int tr2env_perf_be_brief;
29
30 #define TR2FMT_PERF_FL_WIDTH (28)
31 #define TR2FMT_PERF_MAX_EVENT_NAME (12)
32 #define TR2FMT_PERF_REPO_WIDTH (3)
33 #define TR2FMT_PERF_CATEGORY_WIDTH (12)
34
35 #define TR2_INDENT (2)
36 #define TR2_INDENT_LENGTH(ctx) (((ctx)->nr_open_regions - 1) * TR2_INDENT)
37
38 static int fn_init(void)
39 {
40 int want = tr2_dst_trace_want(&tr2dst_perf);
41 int want_brief;
42 const char *brief;
43
44 if (!want)
45 return want;
46
47 brief = tr2_sysenv_get(TR2_SYSENV_PERF_BRIEF);
48 if (brief && *brief &&
49 ((want_brief = git_parse_maybe_bool(brief)) != -1))
50 tr2env_perf_be_brief = want_brief;
51
52 return want;
53 }
54
55 static void fn_term(void)
56 {
57 tr2_dst_trace_disable(&tr2dst_perf);
58 }
59
60 /*
61 * Format trace line prefix in human-readable classic format for
62 * the performance target:
63 * "[<time> [<file>:<line>] <bar>] <nr_parents> <bar>
64 * <thread_name> <bar> <event_name> <bar> [<repo>] <bar>
65 * [<elapsed_absolute>] [<elapsed_relative>] <bar>
66 * [<category>] <bar> [<dots>] "
67 */
68 static void perf_fmt_prepare(const char *event_name,
69 struct tr2tls_thread_ctx *ctx, const char *file,
70 int line, const struct repository *repo,
71 uint64_t *p_us_elapsed_absolute,
72 uint64_t *p_us_elapsed_relative,
73 const char *category, struct strbuf *buf)
74 {
75 int len;
76
77 strbuf_setlen(buf, 0);
78
79 if (!tr2env_perf_be_brief) {
80 struct tr2_tbuf tb_now;
81 size_t fl_end_col;
82
83 tr2_tbuf_local_time(&tb_now);
84 strbuf_addstr(buf, tb_now.buf);
85 strbuf_addch(buf, ' ');
86
87 fl_end_col = buf->len + TR2FMT_PERF_FL_WIDTH;
88
89 if (file && *file) {
90 struct strbuf buf_fl = STRBUF_INIT;
91
92 strbuf_addf(&buf_fl, "%s:%d", file, line);
93
94 if (buf_fl.len <= TR2FMT_PERF_FL_WIDTH)
95 strbuf_addbuf(buf, &buf_fl);
96 else {
97 size_t avail = TR2FMT_PERF_FL_WIDTH - 3;
98 strbuf_addstr(buf, "...");
99 strbuf_add(buf,
100 &buf_fl.buf[buf_fl.len - avail],
101 avail);
102 }
103
104 strbuf_release(&buf_fl);
105 }
106
107 while (buf->len < fl_end_col)
108 strbuf_addch(buf, ' ');
109
110 strbuf_addstr(buf, " | ");
111 }
112
113 strbuf_addf(buf, "d%d | ", tr2_sid_depth());
114 strbuf_addf(buf, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME,
115 ctx->thread_name, TR2FMT_PERF_MAX_EVENT_NAME,
116 event_name);
117
118 len = buf->len + TR2FMT_PERF_REPO_WIDTH;
119 if (repo)
120 strbuf_addf(buf, "r%d ", repo->trace2_repo_id);
121 while (buf->len < len)
122 strbuf_addch(buf, ' ');
123 strbuf_addstr(buf, " | ");
124
125 if (p_us_elapsed_absolute)
126 strbuf_addf(buf, "%9.6f | ",
127 ((double)(*p_us_elapsed_absolute)) / 1000000.0);
128 else
129 strbuf_addf(buf, "%9s | ", " ");
130
131 if (p_us_elapsed_relative)
132 strbuf_addf(buf, "%9.6f | ",
133 ((double)(*p_us_elapsed_relative)) / 1000000.0);
134 else
135 strbuf_addf(buf, "%9s | ", " ");
136
137 strbuf_addf(buf, "%-*.*s | ", TR2FMT_PERF_CATEGORY_WIDTH,
138 TR2FMT_PERF_CATEGORY_WIDTH, (category ? category : ""));
139
140 if (ctx->nr_open_regions > 0)
141 strbuf_addchars(buf, '.', TR2_INDENT_LENGTH(ctx));
142 }
143
144 static void perf_io_write_fl(const char *file, int line, const char *event_name,
145 const struct repository *repo,
146 uint64_t *p_us_elapsed_absolute,
147 uint64_t *p_us_elapsed_relative,
148 const char *category,
149 const struct strbuf *buf_payload)
150 {
151 struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
152 struct strbuf buf_line = STRBUF_INIT;
153
154 perf_fmt_prepare(event_name, ctx, file, line, repo,
155 p_us_elapsed_absolute, p_us_elapsed_relative, category,
156 &buf_line);
157 strbuf_addbuf(&buf_line, buf_payload);
158 tr2_dst_write_line(&tr2dst_perf, &buf_line);
159 strbuf_release(&buf_line);
160 }
161
162 static void fn_version_fl(const char *file, int line)
163 {
164 const char *event_name = "version";
165 struct strbuf buf_payload = STRBUF_INIT;
166
167 strbuf_addstr(&buf_payload, git_version_string);
168
169 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
170 &buf_payload);
171 strbuf_release(&buf_payload);
172 }
173
174 static void fn_start_fl(const char *file, int line,
175 uint64_t us_elapsed_absolute, const char **argv)
176 {
177 const char *event_name = "start";
178 struct strbuf buf_payload = STRBUF_INIT;
179
180 sq_append_quote_argv_pretty(&buf_payload, argv);
181
182 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
183 NULL, NULL, &buf_payload);
184 strbuf_release(&buf_payload);
185 }
186
187 static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
188 int code)
189 {
190 const char *event_name = "exit";
191 struct strbuf buf_payload = STRBUF_INIT;
192
193 strbuf_addf(&buf_payload, "code:%d", code);
194
195 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
196 NULL, NULL, &buf_payload);
197 strbuf_release(&buf_payload);
198 }
199
200 static void fn_signal(uint64_t us_elapsed_absolute, int signo)
201 {
202 const char *event_name = "signal";
203 struct strbuf buf_payload = STRBUF_INIT;
204
205 strbuf_addf(&buf_payload, "signo:%d", signo);
206
207 perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
208 &us_elapsed_absolute, NULL, NULL, &buf_payload);
209 strbuf_release(&buf_payload);
210 }
211
212 static void fn_atexit(uint64_t us_elapsed_absolute, int code)
213 {
214 const char *event_name = "atexit";
215 struct strbuf buf_payload = STRBUF_INIT;
216
217 strbuf_addf(&buf_payload, "code:%d", code);
218
219 perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
220 &us_elapsed_absolute, NULL, NULL, &buf_payload);
221 strbuf_release(&buf_payload);
222 }
223
224 static void maybe_append_string_va(struct strbuf *buf, const char *fmt,
225 va_list ap)
226 {
227 if (fmt && *fmt) {
228 va_list copy_ap;
229
230 va_copy(copy_ap, ap);
231 strbuf_vaddf(buf, fmt, copy_ap);
232 va_end(copy_ap);
233 return;
234 }
235 }
236
237 static void fn_error_va_fl(const char *file, int line, const char *fmt,
238 va_list ap)
239 {
240 const char *event_name = "error";
241 struct strbuf buf_payload = STRBUF_INIT;
242
243 maybe_append_string_va(&buf_payload, fmt, ap);
244
245 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
246 &buf_payload);
247 strbuf_release(&buf_payload);
248 }
249
250 static void fn_command_path_fl(const char *file, int line, const char *pathname)
251 {
252 const char *event_name = "cmd_path";
253 struct strbuf buf_payload = STRBUF_INIT;
254
255 strbuf_addstr(&buf_payload, pathname);
256
257 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
258 &buf_payload);
259 strbuf_release(&buf_payload);
260 }
261
262 static void fn_command_ancestry_fl(const char *file, int line, const char **parent_names)
263 {
264 const char *event_name = "cmd_ancestry";
265 struct strbuf buf_payload = STRBUF_INIT;
266
267 strbuf_addstr(&buf_payload, "ancestry:[");
268 /* It's not an argv but the rules are basically the same. */
269 sq_append_quote_argv_pretty(&buf_payload, parent_names);
270 strbuf_addch(&buf_payload, ']');
271
272 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
273 &buf_payload);
274 strbuf_release(&buf_payload);
275 }
276
277 static void fn_command_name_fl(const char *file, int line, const char *name,
278 const char *hierarchy)
279 {
280 const char *event_name = "cmd_name";
281 struct strbuf buf_payload = STRBUF_INIT;
282
283 strbuf_addstr(&buf_payload, name);
284 if (hierarchy && *hierarchy)
285 strbuf_addf(&buf_payload, " (%s)", hierarchy);
286
287 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
288 &buf_payload);
289 strbuf_release(&buf_payload);
290 }
291
292 static void fn_command_mode_fl(const char *file, int line, const char *mode)
293 {
294 const char *event_name = "cmd_mode";
295 struct strbuf buf_payload = STRBUF_INIT;
296
297 strbuf_addstr(&buf_payload, mode);
298
299 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
300 &buf_payload);
301 strbuf_release(&buf_payload);
302 }
303
304 static void fn_alias_fl(const char *file, int line, const char *alias,
305 const char **argv)
306 {
307 const char *event_name = "alias";
308 struct strbuf buf_payload = STRBUF_INIT;
309
310 strbuf_addf(&buf_payload, "alias:%s argv:[", alias);
311 sq_append_quote_argv_pretty(&buf_payload, argv);
312 strbuf_addch(&buf_payload, ']');
313
314 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
315 &buf_payload);
316 strbuf_release(&buf_payload);
317 }
318
319 static void fn_child_start_fl(const char *file, int line,
320 uint64_t us_elapsed_absolute,
321 const struct child_process *cmd)
322 {
323 const char *event_name = "child_start";
324 struct strbuf buf_payload = STRBUF_INIT;
325
326 if (cmd->trace2_hook_name) {
327 strbuf_addf(&buf_payload, "[ch%d] class:hook hook:%s",
328 cmd->trace2_child_id, cmd->trace2_hook_name);
329 } else {
330 const char *child_class =
331 cmd->trace2_child_class ? cmd->trace2_child_class : "?";
332 strbuf_addf(&buf_payload, "[ch%d] class:%s",
333 cmd->trace2_child_id, child_class);
334 }
335
336 if (cmd->dir) {
337 strbuf_addstr(&buf_payload, " cd:");
338 sq_quote_buf_pretty(&buf_payload, cmd->dir);
339 }
340
341 strbuf_addstr(&buf_payload, " argv:[");
342 if (cmd->git_cmd) {
343 strbuf_addstr(&buf_payload, "git");
344 if (cmd->args.nr)
345 strbuf_addch(&buf_payload, ' ');
346 }
347 sq_append_quote_argv_pretty(&buf_payload, cmd->args.v);
348 strbuf_addch(&buf_payload, ']');
349
350 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
351 NULL, NULL, &buf_payload);
352 strbuf_release(&buf_payload);
353 }
354
355 static void fn_child_exit_fl(const char *file, int line,
356 uint64_t us_elapsed_absolute, int cid, int pid,
357 int code, uint64_t us_elapsed_child)
358 {
359 const char *event_name = "child_exit";
360 struct strbuf buf_payload = STRBUF_INIT;
361
362 strbuf_addf(&buf_payload, "[ch%d] pid:%d code:%d", cid, pid, code);
363
364 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
365 &us_elapsed_child, NULL, &buf_payload);
366 strbuf_release(&buf_payload);
367 }
368
369 static void fn_child_ready_fl(const char *file, int line,
370 uint64_t us_elapsed_absolute, int cid, int pid,
371 const char *ready, uint64_t us_elapsed_child)
372 {
373 const char *event_name = "child_ready";
374 struct strbuf buf_payload = STRBUF_INIT;
375
376 strbuf_addf(&buf_payload, "[ch%d] pid:%d ready:%s", cid, pid, ready);
377
378 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
379 &us_elapsed_child, NULL, &buf_payload);
380 strbuf_release(&buf_payload);
381 }
382
383 static void fn_thread_start_fl(const char *file, int line,
384 uint64_t us_elapsed_absolute)
385 {
386 const char *event_name = "thread_start";
387 struct strbuf buf_payload = STRBUF_INIT;
388
389 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
390 NULL, NULL, &buf_payload);
391 strbuf_release(&buf_payload);
392 }
393
394 static void fn_thread_exit_fl(const char *file, int line,
395 uint64_t us_elapsed_absolute,
396 uint64_t us_elapsed_thread)
397 {
398 const char *event_name = "thread_exit";
399 struct strbuf buf_payload = STRBUF_INIT;
400
401 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
402 &us_elapsed_thread, NULL, &buf_payload);
403 strbuf_release(&buf_payload);
404 }
405
406 static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
407 int exec_id, const char *exe, const char **argv)
408 {
409 const char *event_name = "exec";
410 struct strbuf buf_payload = STRBUF_INIT;
411
412 strbuf_addf(&buf_payload, "id:%d ", exec_id);
413 strbuf_addstr(&buf_payload, "argv:[");
414 if (exe) {
415 strbuf_addstr(&buf_payload, exe);
416 if (argv[0])
417 strbuf_addch(&buf_payload, ' ');
418 }
419 sq_append_quote_argv_pretty(&buf_payload, argv);
420 strbuf_addch(&buf_payload, ']');
421
422 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
423 NULL, NULL, &buf_payload);
424 strbuf_release(&buf_payload);
425 }
426
427 static void fn_exec_result_fl(const char *file, int line,
428 uint64_t us_elapsed_absolute, int exec_id,
429 int code)
430 {
431 const char *event_name = "exec_result";
432 struct strbuf buf_payload = STRBUF_INIT;
433
434 strbuf_addf(&buf_payload, "id:%d code:%d", exec_id, code);
435 if (code > 0)
436 strbuf_addf(&buf_payload, " err:%s", strerror(code));
437
438 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
439 NULL, NULL, &buf_payload);
440 strbuf_release(&buf_payload);
441 }
442
443 static void fn_param_fl(const char *file, int line, const char *param,
444 const char *value, const struct key_value_info *kvi)
445 {
446 const char *event_name = "def_param";
447 struct strbuf buf_payload = STRBUF_INIT;
448 struct strbuf scope_payload = STRBUF_INIT;
449 enum config_scope scope = kvi->scope;
450 const char *scope_name = config_scope_name(scope);
451 strbuf_addstr(&buf_payload, param);
452 if (value)
453 strbuf_addf(&buf_payload, ":%s", value);
454 strbuf_addf(&scope_payload, "%s:%s", "scope", scope_name);
455
456 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL,
457 scope_payload.buf, &buf_payload);
458 strbuf_release(&buf_payload);
459 strbuf_release(&scope_payload);
460 }
461
462 static void fn_repo_fl(const char *file, int line,
463 const struct repository *repo)
464 {
465 const char *event_name = "def_repo";
466 struct strbuf buf_payload = STRBUF_INIT;
467
468 strbuf_addstr(&buf_payload, "worktree:");
469 sq_quote_buf_pretty(&buf_payload, repo->worktree);
470
471 perf_io_write_fl(file, line, event_name, repo, NULL, NULL, NULL,
472 &buf_payload);
473 strbuf_release(&buf_payload);
474 }
475
476 static void fn_region_enter_printf_va_fl(const char *file, int line,
477 uint64_t us_elapsed_absolute,
478 const char *category,
479 const char *label,
480 const struct repository *repo,
481 const char *fmt, va_list ap)
482 {
483 const char *event_name = "region_enter";
484 struct strbuf buf_payload = STRBUF_INIT;
485
486 if (label)
487 strbuf_addf(&buf_payload, "label:%s", label);
488 if (fmt && *fmt) {
489 strbuf_addch(&buf_payload, ' ');
490 maybe_append_string_va(&buf_payload, fmt, ap);
491 }
492
493 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
494 NULL, category, &buf_payload);
495 strbuf_release(&buf_payload);
496 }
497
498 static void fn_region_leave_printf_va_fl(
499 const char *file, int line, uint64_t us_elapsed_absolute,
500 uint64_t us_elapsed_region, const char *category, const char *label,
501 const struct repository *repo, const char *fmt, va_list ap)
502 {
503 const char *event_name = "region_leave";
504 struct strbuf buf_payload = STRBUF_INIT;
505
506 if (label)
507 strbuf_addf(&buf_payload, "label:%s", label);
508 if (fmt && *fmt) {
509 strbuf_addch(&buf_payload, ' ' );
510 maybe_append_string_va(&buf_payload, fmt, ap);
511 }
512
513 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
514 &us_elapsed_region, category, &buf_payload);
515 strbuf_release(&buf_payload);
516 }
517
518 static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
519 uint64_t us_elapsed_region, const char *category,
520 const struct repository *repo, const char *key,
521 const char *value)
522 {
523 const char *event_name = "data";
524 struct strbuf buf_payload = STRBUF_INIT;
525
526 strbuf_addf(&buf_payload, "%s:%s", key, value);
527
528 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
529 &us_elapsed_region, category, &buf_payload);
530 strbuf_release(&buf_payload);
531 }
532
533 static void fn_data_json_fl(const char *file, int line,
534 uint64_t us_elapsed_absolute,
535 uint64_t us_elapsed_region, const char *category,
536 const struct repository *repo, const char *key,
537 const struct json_writer *value)
538 {
539 const char *event_name = "data_json";
540 struct strbuf buf_payload = STRBUF_INIT;
541
542 strbuf_addf(&buf_payload, "%s:%s", key, value->json.buf);
543
544 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
545 &us_elapsed_region, category, &buf_payload);
546 strbuf_release(&buf_payload);
547 }
548
549 static void fn_printf_va_fl(const char *file, int line,
550 uint64_t us_elapsed_absolute, const char *fmt,
551 va_list ap)
552 {
553 const char *event_name = "printf";
554 struct strbuf buf_payload = STRBUF_INIT;
555
556 maybe_append_string_va(&buf_payload, fmt, ap);
557
558 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
559 NULL, NULL, &buf_payload);
560 strbuf_release(&buf_payload);
561 }
562
563 static void fn_timer(const struct tr2_timer_metadata *meta,
564 const struct tr2_timer *timer,
565 int is_final_data)
566 {
567 const char *event_name = is_final_data ? "timer" : "th_timer";
568 struct strbuf buf_payload = STRBUF_INIT;
569 double t_total = NS_TO_SEC(timer->total_ns);
570 double t_min = NS_TO_SEC(timer->min_ns);
571 double t_max = NS_TO_SEC(timer->max_ns);
572
573 strbuf_addf(&buf_payload, ("name:%s"
574 " intervals:%"PRIu64
575 " total:%8.6f min:%8.6f max:%8.6f"),
576 meta->name,
577 timer->interval_count,
578 t_total, t_min, t_max);
579
580 perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, NULL, NULL,
581 meta->category, &buf_payload);
582 strbuf_release(&buf_payload);
583 }
584
585 static void fn_counter(const struct tr2_counter_metadata *meta,
586 const struct tr2_counter *counter,
587 int is_final_data)
588 {
589 const char *event_name = is_final_data ? "counter" : "th_counter";
590 struct strbuf buf_payload = STRBUF_INIT;
591
592 strbuf_addf(&buf_payload, "name:%s value:%"PRIu64,
593 meta->name,
594 counter->value);
595
596 perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, NULL, NULL,
597 meta->category, &buf_payload);
598 strbuf_release(&buf_payload);
599 }
600
601 struct tr2_tgt tr2_tgt_perf = {
602 .pdst = &tr2dst_perf,
603
604 .pfn_init = fn_init,
605 .pfn_term = fn_term,
606
607 .pfn_version_fl = fn_version_fl,
608 .pfn_start_fl = fn_start_fl,
609 .pfn_exit_fl = fn_exit_fl,
610 .pfn_signal = fn_signal,
611 .pfn_atexit = fn_atexit,
612 .pfn_error_va_fl = fn_error_va_fl,
613 .pfn_command_path_fl = fn_command_path_fl,
614 .pfn_command_ancestry_fl = fn_command_ancestry_fl,
615 .pfn_command_name_fl = fn_command_name_fl,
616 .pfn_command_mode_fl = fn_command_mode_fl,
617 .pfn_alias_fl = fn_alias_fl,
618 .pfn_child_start_fl = fn_child_start_fl,
619 .pfn_child_exit_fl = fn_child_exit_fl,
620 .pfn_child_ready_fl = fn_child_ready_fl,
621 .pfn_thread_start_fl = fn_thread_start_fl,
622 .pfn_thread_exit_fl = fn_thread_exit_fl,
623 .pfn_exec_fl = fn_exec_fl,
624 .pfn_exec_result_fl = fn_exec_result_fl,
625 .pfn_param_fl = fn_param_fl,
626 .pfn_repo_fl = fn_repo_fl,
627 .pfn_region_enter_printf_va_fl = fn_region_enter_printf_va_fl,
628 .pfn_region_leave_printf_va_fl = fn_region_leave_printf_va_fl,
629 .pfn_data_fl = fn_data_fl,
630 .pfn_data_json_fl = fn_data_json_fl,
631 .pfn_printf_va_fl = fn_printf_va_fl,
632 .pfn_timer = fn_timer,
633 .pfn_counter = fn_counter,
634 };