trace2: refactor setting process starting time
[git/git.git] / trace2 / tr2_tgt_perf.c
CommitLineData
ee4512ed
JH
1#include "cache.h"
2#include "config.h"
3#include "run-command.h"
4#include "quote.h"
5#include "version.h"
6#include "json-writer.h"
7#include "trace2/tr2_dst.h"
8#include "trace2/tr2_sid.h"
9#include "trace2/tr2_tbuf.h"
10#include "trace2/tr2_tgt.h"
11#include "trace2/tr2_tls.h"
12
13static struct tr2_dst tr2dst_perf = { "GIT_TR2_PERF", 0, 0, 0 };
14
15/*
16 * Set this environment variable to true to omit the "<time> <file>:<line>"
17 * fields from each line written to the builtin performance target.
18 *
19 * Unit tests may want to use this to help with testing.
20 */
21#define TR2_ENVVAR_PERF_BRIEF "GIT_TR2_PERF_BRIEF"
22static int tr2env_perf_brief;
23
24#define TR2FMT_PERF_FL_WIDTH (50)
25#define TR2FMT_PERF_MAX_EVENT_NAME (12)
26#define TR2FMT_PERF_REPO_WIDTH (4)
27#define TR2FMT_PERF_CATEGORY_WIDTH (10)
28
29#define TR2_DOTS_BUFFER_SIZE (100)
30#define TR2_INDENT (2)
31#define TR2_INDENT_LENGTH(ctx) (((ctx)->nr_open_regions - 1) * TR2_INDENT)
32
33static struct strbuf dots = STRBUF_INIT;
34
35static int fn_init(void)
36{
37 int want = tr2_dst_trace_want(&tr2dst_perf);
38 int want_brief;
39 char *brief;
40
41 if (!want)
42 return want;
43
44 strbuf_addchars(&dots, '.', TR2_DOTS_BUFFER_SIZE);
45
46 brief = getenv(TR2_ENVVAR_PERF_BRIEF);
47 if (brief && *brief &&
48 ((want_brief = git_parse_maybe_bool(brief)) != -1))
49 tr2env_perf_brief = want_brief;
50
51 return want;
52}
53
54static void fn_term(void)
55{
56 tr2_dst_trace_disable(&tr2dst_perf);
57
58 strbuf_release(&dots);
59}
60
61/*
62 * Format trace line prefix in human-readable classic format for
63 * the performance target:
64 * "[<time> [<file>:<line>] <bar>] <nr_parents> <bar>
65 * <thread_name> <bar> <event_name> <bar> [<repo>] <bar>
66 * [<elapsed_absolute>] [<elapsed_relative>] <bar>
67 * [<category>] <bar> [<dots>] "
68 */
69static void perf_fmt_prepare(const char *event_name,
70 struct tr2tls_thread_ctx *ctx, const char *file,
71 int line, const struct repository *repo,
72 uint64_t *p_us_elapsed_absolute,
73 uint64_t *p_us_elapsed_relative,
74 const char *category, struct strbuf *buf)
75{
76 int len;
77
78 strbuf_setlen(buf, 0);
79
80 if (!tr2env_perf_brief) {
81 struct tr2_tbuf tb_now;
82
83 tr2_tbuf_local_time(&tb_now);
84 strbuf_addstr(buf, tb_now.buf);
85 strbuf_addch(buf, ' ');
86
87 if (file && *file)
88 strbuf_addf(buf, "%s:%d ", file, line);
89 while (buf->len < TR2FMT_PERF_FL_WIDTH)
90 strbuf_addch(buf, ' ');
91
92 strbuf_addstr(buf, "| ");
93 }
94
95 strbuf_addf(buf, "d%d | ", tr2_sid_depth());
96 strbuf_addf(buf, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME,
97 ctx->thread_name.buf, TR2FMT_PERF_MAX_EVENT_NAME,
98 event_name);
99
100 len = buf->len + TR2FMT_PERF_REPO_WIDTH;
101 if (repo)
102 strbuf_addf(buf, "r%d ", repo->trace2_repo_id);
103 while (buf->len < len)
104 strbuf_addch(buf, ' ');
105 strbuf_addstr(buf, "| ");
106
107 if (p_us_elapsed_absolute)
108 strbuf_addf(buf, "%9.6f | ",
109 ((double)(*p_us_elapsed_absolute)) / 1000000.0);
110 else
111 strbuf_addf(buf, "%9s | ", " ");
112
113 if (p_us_elapsed_relative)
114 strbuf_addf(buf, "%9.6f | ",
115 ((double)(*p_us_elapsed_relative)) / 1000000.0);
116 else
117 strbuf_addf(buf, "%9s | ", " ");
118
119 strbuf_addf(buf, "%-*s | ", TR2FMT_PERF_CATEGORY_WIDTH,
120 (category ? category : ""));
121
122 if (ctx->nr_open_regions > 0) {
123 int len_indent = TR2_INDENT_LENGTH(ctx);
124 while (len_indent > dots.len) {
125 strbuf_addbuf(buf, &dots);
126 len_indent -= dots.len;
127 }
128 strbuf_addf(buf, "%.*s", len_indent, dots.buf);
129 }
130}
131
132static void perf_io_write_fl(const char *file, int line, const char *event_name,
133 const struct repository *repo,
134 uint64_t *p_us_elapsed_absolute,
135 uint64_t *p_us_elapsed_relative,
136 const char *category,
137 const struct strbuf *buf_payload)
138{
139 struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
140 struct strbuf buf_line = STRBUF_INIT;
141
142 perf_fmt_prepare(event_name, ctx, file, line, repo,
143 p_us_elapsed_absolute, p_us_elapsed_relative, category,
144 &buf_line);
145 strbuf_addbuf(&buf_line, buf_payload);
146 tr2_dst_write_line(&tr2dst_perf, &buf_line);
147 strbuf_release(&buf_line);
148}
149
150static void fn_version_fl(const char *file, int line)
151{
152 const char *event_name = "version";
153 struct strbuf buf_payload = STRBUF_INIT;
154
155 strbuf_addstr(&buf_payload, git_version_string);
156
157 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
158 &buf_payload);
159 strbuf_release(&buf_payload);
160}
161
162static void fn_start_fl(const char *file, int line, const char **argv)
163{
164 const char *event_name = "start";
165 struct strbuf buf_payload = STRBUF_INIT;
166
167 sq_quote_argv_pretty(&buf_payload, argv);
168
169 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
170 &buf_payload);
171 strbuf_release(&buf_payload);
172}
173
174static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
175 int code)
176{
177 const char *event_name = "exit";
178 struct strbuf buf_payload = STRBUF_INIT;
179
180 strbuf_addf(&buf_payload, "code:%d", code);
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
187static void fn_signal(uint64_t us_elapsed_absolute, int signo)
188{
189 const char *event_name = "signal";
190 struct strbuf buf_payload = STRBUF_INIT;
191
192 strbuf_addf(&buf_payload, "signo:%d", signo);
193
194 perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
195 &us_elapsed_absolute, NULL, NULL, &buf_payload);
196 strbuf_release(&buf_payload);
197}
198
199static void fn_atexit(uint64_t us_elapsed_absolute, int code)
200{
201 const char *event_name = "atexit";
202 struct strbuf buf_payload = STRBUF_INIT;
203
204 strbuf_addf(&buf_payload, "code:%d", code);
205
206 perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
207 &us_elapsed_absolute, NULL, NULL, &buf_payload);
208 strbuf_release(&buf_payload);
209}
210
211static void maybe_append_string_va(struct strbuf *buf, const char *fmt,
212 va_list ap)
213{
214 if (fmt && *fmt && ap) {
215 va_list copy_ap;
216
217 va_copy(copy_ap, ap);
218 strbuf_vaddf(buf, fmt, copy_ap);
219 va_end(copy_ap);
220 return;
221 }
222
223 if (fmt && *fmt) {
224 strbuf_addstr(buf, fmt);
225 return;
226 }
227}
228
229static void fn_error_va_fl(const char *file, int line, const char *fmt,
230 va_list ap)
231{
232 const char *event_name = "error";
233 struct strbuf buf_payload = STRBUF_INIT;
234
235 maybe_append_string_va(&buf_payload, fmt, ap);
236
237 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
238 &buf_payload);
239 strbuf_release(&buf_payload);
240}
241
242static void fn_command_path_fl(const char *file, int line, const char *pathname)
243{
244 const char *event_name = "cmd_path";
245 struct strbuf buf_payload = STRBUF_INIT;
246
247 strbuf_addstr(&buf_payload, pathname);
248
249 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
250 &buf_payload);
251 strbuf_release(&buf_payload);
252}
253
254static void fn_command_name_fl(const char *file, int line, const char *name,
255 const char *hierarchy)
256{
257 const char *event_name = "cmd_name";
258 struct strbuf buf_payload = STRBUF_INIT;
259
260 strbuf_addstr(&buf_payload, name);
261 if (hierarchy && *hierarchy)
262 strbuf_addf(&buf_payload, " (%s)", hierarchy);
263
264 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
265 &buf_payload);
266 strbuf_release(&buf_payload);
267}
268
269static void fn_command_mode_fl(const char *file, int line, const char *mode)
270{
271 const char *event_name = "cmd_mode";
272 struct strbuf buf_payload = STRBUF_INIT;
273
274 strbuf_addstr(&buf_payload, mode);
275
276 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
277 &buf_payload);
278 strbuf_release(&buf_payload);
279}
280
281static void fn_alias_fl(const char *file, int line, const char *alias,
282 const char **argv)
283{
284 const char *event_name = "alias";
285 struct strbuf buf_payload = STRBUF_INIT;
286
287 strbuf_addf(&buf_payload, "alias:%s argv:", alias);
288 sq_quote_argv_pretty(&buf_payload, argv);
289
290 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
291 &buf_payload);
292 strbuf_release(&buf_payload);
293}
294
295static void fn_child_start_fl(const char *file, int line,
296 uint64_t us_elapsed_absolute,
297 const struct child_process *cmd)
298{
299 const char *event_name = "child_start";
300 struct strbuf buf_payload = STRBUF_INIT;
301
302 if (cmd->trace2_hook_name) {
303 strbuf_addf(&buf_payload, "[ch%d] class:hook hook:%s",
304 cmd->trace2_child_id, cmd->trace2_hook_name);
305 } else {
306 const char *child_class =
307 cmd->trace2_child_class ? cmd->trace2_child_class : "?";
308 strbuf_addf(&buf_payload, "[ch%d] class:%s",
309 cmd->trace2_child_id, child_class);
310 }
311
312 if (cmd->dir) {
313 strbuf_addstr(&buf_payload, " cd:");
314 sq_quote_buf_pretty(&buf_payload, cmd->dir);
315 }
316
317 strbuf_addstr(&buf_payload, " argv:");
318 if (cmd->git_cmd)
319 strbuf_addstr(&buf_payload, " git");
320 sq_quote_argv_pretty(&buf_payload, cmd->argv);
321
322 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
323 NULL, NULL, &buf_payload);
324 strbuf_release(&buf_payload);
325}
326
327static void fn_child_exit_fl(const char *file, int line,
328 uint64_t us_elapsed_absolute, int cid, int pid,
329 int code, uint64_t us_elapsed_child)
330{
331 const char *event_name = "child_exit";
332 struct strbuf buf_payload = STRBUF_INIT;
333
334 strbuf_addf(&buf_payload, "[ch%d] pid:%d code:%d", cid, pid, code);
335
336 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
337 &us_elapsed_child, NULL, &buf_payload);
338 strbuf_release(&buf_payload);
339}
340
341static void fn_thread_start_fl(const char *file, int line,
342 uint64_t us_elapsed_absolute)
343{
344 const char *event_name = "thread_start";
345 struct strbuf buf_payload = STRBUF_INIT;
346
347 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
348 NULL, NULL, &buf_payload);
349 strbuf_release(&buf_payload);
350}
351
352static void fn_thread_exit_fl(const char *file, int line,
353 uint64_t us_elapsed_absolute,
354 uint64_t us_elapsed_thread)
355{
356 const char *event_name = "thread_exit";
357 struct strbuf buf_payload = STRBUF_INIT;
358
359 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
360 &us_elapsed_thread, NULL, &buf_payload);
361 strbuf_release(&buf_payload);
362}
363
364static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
365 int exec_id, const char *exe, const char **argv)
366{
367 const char *event_name = "exec";
368 struct strbuf buf_payload = STRBUF_INIT;
369
370 strbuf_addf(&buf_payload, "id:%d ", exec_id);
371 strbuf_addstr(&buf_payload, "argv:");
372 if (exe)
373 strbuf_addf(&buf_payload, " %s", exe);
374 sq_quote_argv_pretty(&buf_payload, argv);
375
376 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
377 NULL, NULL, &buf_payload);
378 strbuf_release(&buf_payload);
379}
380
381static void fn_exec_result_fl(const char *file, int line,
382 uint64_t us_elapsed_absolute, int exec_id,
383 int code)
384{
385 const char *event_name = "exec_result";
386 struct strbuf buf_payload = STRBUF_INIT;
387
388 strbuf_addf(&buf_payload, "id:%d code:%d", exec_id, code);
389 if (code > 0)
390 strbuf_addf(&buf_payload, " err:%s", strerror(code));
391
392 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
393 NULL, NULL, &buf_payload);
394 strbuf_release(&buf_payload);
395}
396
397static void fn_param_fl(const char *file, int line, const char *param,
398 const char *value)
399{
400 const char *event_name = "def_param";
401 struct strbuf buf_payload = STRBUF_INIT;
402
403 strbuf_addf(&buf_payload, "%s:%s", param, value);
404
405 perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
406 &buf_payload);
407 strbuf_release(&buf_payload);
408}
409
410static void fn_repo_fl(const char *file, int line,
411 const struct repository *repo)
412{
413 const char *event_name = "def_repo";
414 struct strbuf buf_payload = STRBUF_INIT;
415
416 strbuf_addstr(&buf_payload, "worktree:");
417 sq_quote_buf_pretty(&buf_payload, repo->worktree);
418
419 perf_io_write_fl(file, line, event_name, repo, NULL, NULL, NULL,
420 &buf_payload);
421 strbuf_release(&buf_payload);
422}
423
424static void fn_region_enter_printf_va_fl(const char *file, int line,
425 uint64_t us_elapsed_absolute,
426 const char *category,
427 const char *label,
428 const struct repository *repo,
429 const char *fmt, va_list ap)
430{
431 const char *event_name = "region_enter";
432 struct strbuf buf_payload = STRBUF_INIT;
433
434 if (label)
435 strbuf_addf(&buf_payload, "label:%s ", label);
436 maybe_append_string_va(&buf_payload, fmt, ap);
437
438 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
439 NULL, category, &buf_payload);
440 strbuf_release(&buf_payload);
441}
442
443static void fn_region_leave_printf_va_fl(
444 const char *file, int line, uint64_t us_elapsed_absolute,
445 uint64_t us_elapsed_region, const char *category, const char *label,
446 const struct repository *repo, const char *fmt, va_list ap)
447{
448 const char *event_name = "region_leave";
449 struct strbuf buf_payload = STRBUF_INIT;
450
451 if (label)
452 strbuf_addf(&buf_payload, "label:%s ", label);
453 maybe_append_string_va(&buf_payload, fmt, ap);
454
455 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
456 &us_elapsed_region, category, &buf_payload);
457 strbuf_release(&buf_payload);
458}
459
460static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
461 uint64_t us_elapsed_region, const char *category,
462 const struct repository *repo, const char *key,
463 const char *value)
464{
465 const char *event_name = "data";
466 struct strbuf buf_payload = STRBUF_INIT;
467
468 strbuf_addf(&buf_payload, "%s:%s", key, value);
469
470 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
471 &us_elapsed_region, category, &buf_payload);
472 strbuf_release(&buf_payload);
473}
474
475static void fn_data_json_fl(const char *file, int line,
476 uint64_t us_elapsed_absolute,
477 uint64_t us_elapsed_region, const char *category,
478 const struct repository *repo, const char *key,
479 const struct json_writer *value)
480{
481 const char *event_name = "data_json";
482 struct strbuf buf_payload = STRBUF_INIT;
483
484 strbuf_addf(&buf_payload, "%s:%s", key, value->json.buf);
485
486 perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
487 &us_elapsed_region, category, &buf_payload);
488 strbuf_release(&buf_payload);
489}
490
491static void fn_printf_va_fl(const char *file, int line,
492 uint64_t us_elapsed_absolute, const char *fmt,
493 va_list ap)
494{
495 const char *event_name = "printf";
496 struct strbuf buf_payload = STRBUF_INIT;
497
498 maybe_append_string_va(&buf_payload, fmt, ap);
499
500 perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
501 NULL, NULL, &buf_payload);
502 strbuf_release(&buf_payload);
503}
504
505struct tr2_tgt tr2_tgt_perf = {
506 &tr2dst_perf,
507
508 fn_init,
509 fn_term,
510
511 fn_version_fl,
512 fn_start_fl,
513 fn_exit_fl,
514 fn_signal,
515 fn_atexit,
516 fn_error_va_fl,
517 fn_command_path_fl,
518 fn_command_name_fl,
519 fn_command_mode_fl,
520 fn_alias_fl,
521 fn_child_start_fl,
522 fn_child_exit_fl,
523 fn_thread_start_fl,
524 fn_thread_exit_fl,
525 fn_exec_fl,
526 fn_exec_result_fl,
527 fn_param_fl,
528 fn_repo_fl,
529 fn_region_enter_printf_va_fl,
530 fn_region_leave_printf_va_fl,
531 fn_data_fl,
532 fn_data_json_fl,
533 fn_printf_va_fl,
534};