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