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 };
  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 (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
  33 static struct strbuf dots = STRBUF_INIT;
  34
  35 static int fn_init(void)
  36 {
  37         int want = tr2_dst_trace_want(&tr2dst_perf);
  38         int want_brief;
  39         const char *brief;
  40
  41         if (!want)
  42                 return want;
  43
  44         strbuf_addchars(&dots, '.', TR2_DOTS_BUFFER_SIZE);
  45
  46         brief = tr2_sysenv_get(TR2_SYSENV_PERF_BRIEF);
  47         if (brief && *brief &&
  48             ((want_brief = git_parse_maybe_bool(brief)) != -1))
  49                 tr2env_perf_be_brief = want_brief;
  50
  51         return want;
  52 }
  53
  54 static 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  */
  69 static 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_be_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
 132 static 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
 150 static 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
 162 static void fn_start_fl(const char *file, int line,
 163                         uint64_t us_elapsed_absolute, const char **argv)
 164 {
 165         const char *event_name = "start";
 166         struct strbuf buf_payload = STRBUF_INIT;
 167
 168         sq_quote_argv_pretty(&buf_payload, argv);
 169
 170         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 171                          NULL, NULL, &buf_payload);
 172         strbuf_release(&buf_payload);
 173 }
 174
 175 static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 176                        int code)
 177 {
 178         const char *event_name = "exit";
 179         struct strbuf buf_payload = STRBUF_INIT;
 180
 181         strbuf_addf(&buf_payload, "code:%d", code);
 182
 183         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 184                          NULL, NULL, &buf_payload);
 185         strbuf_release(&buf_payload);
 186 }
 187
 188 static void fn_signal(uint64_t us_elapsed_absolute, int signo)
 189 {
 190         const char *event_name = "signal";
 191         struct strbuf buf_payload = STRBUF_INIT;
 192
 193         strbuf_addf(&buf_payload, "signo:%d", signo);
 194
 195         perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
 196                          &us_elapsed_absolute, NULL, NULL, &buf_payload);
 197         strbuf_release(&buf_payload);
 198 }
 199
 200 static void fn_atexit(uint64_t us_elapsed_absolute, int code)
 201 {
 202         const char *event_name = "atexit";
 203         struct strbuf buf_payload = STRBUF_INIT;
 204
 205         strbuf_addf(&buf_payload, "code:%d", code);
 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 maybe_append_string_va(struct strbuf *buf, const char *fmt,
 213                                    va_list ap)
 214 {
 215         if (fmt && *fmt) {
 216                 va_list copy_ap;
 217
 218                 va_copy(copy_ap, ap);
 219                 strbuf_vaddf(buf, fmt, copy_ap);
 220                 va_end(copy_ap);
 221                 return;
 222         }
 223
 224         if (fmt && *fmt) {
 225                 strbuf_addstr(buf, fmt);
 226                 return;
 227         }
 228 }
 229
 230 static void fn_error_va_fl(const char *file, int line, const char *fmt,
 231                            va_list ap)
 232 {
 233         const char *event_name = "error";
 234         struct strbuf buf_payload = STRBUF_INIT;
 235
 236         maybe_append_string_va(&buf_payload, fmt, ap);
 237
 238         perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 239                          &buf_payload);
 240         strbuf_release(&buf_payload);
 241 }
 242
 243 static void fn_command_path_fl(const char *file, int line, const char *pathname)
 244 {
 245         const char *event_name = "cmd_path";
 246         struct strbuf buf_payload = STRBUF_INIT;
 247
 248         strbuf_addstr(&buf_payload, pathname);
 249
 250         perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 251                          &buf_payload);
 252         strbuf_release(&buf_payload);
 253 }
 254
 255 static void fn_command_name_fl(const char *file, int line, const char *name,
 256                                const char *hierarchy)
 257 {
 258         const char *event_name = "cmd_name";
 259         struct strbuf buf_payload = STRBUF_INIT;
 260
 261         strbuf_addstr(&buf_payload, name);
 262         if (hierarchy && *hierarchy)
 263                 strbuf_addf(&buf_payload, " (%s)", hierarchy);
 264
 265         perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 266                          &buf_payload);
 267         strbuf_release(&buf_payload);
 268 }
 269
 270 static void fn_command_mode_fl(const char *file, int line, const char *mode)
 271 {
 272         const char *event_name = "cmd_mode";
 273         struct strbuf buf_payload = STRBUF_INIT;
 274
 275         strbuf_addstr(&buf_payload, mode);
 276
 277         perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 278                          &buf_payload);
 279         strbuf_release(&buf_payload);
 280 }
 281
 282 static void fn_alias_fl(const char *file, int line, const char *alias,
 283                         const char **argv)
 284 {
 285         const char *event_name = "alias";
 286         struct strbuf buf_payload = STRBUF_INIT;
 287
 288         strbuf_addf(&buf_payload, "alias:%s argv:", alias);
 289         sq_quote_argv_pretty(&buf_payload, argv);
 290
 291         perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 292                          &buf_payload);
 293         strbuf_release(&buf_payload);
 294 }
 295
 296 static void fn_child_start_fl(const char *file, int line,
 297                               uint64_t us_elapsed_absolute,
 298                               const struct child_process *cmd)
 299 {
 300         const char *event_name = "child_start";
 301         struct strbuf buf_payload = STRBUF_INIT;
 302
 303         if (cmd->trace2_hook_name) {
 304                 strbuf_addf(&buf_payload, "[ch%d] class:hook hook:%s",
 305                             cmd->trace2_child_id, cmd->trace2_hook_name);
 306         } else {
 307                 const char *child_class =
 308                         cmd->trace2_child_class ? cmd->trace2_child_class : "?";
 309                 strbuf_addf(&buf_payload, "[ch%d] class:%s",
 310                             cmd->trace2_child_id, child_class);
 311         }
 312
 313         if (cmd->dir) {
 314                 strbuf_addstr(&buf_payload, " cd:");
 315                 sq_quote_buf_pretty(&buf_payload, cmd->dir);
 316         }
 317
 318         strbuf_addstr(&buf_payload, " argv:");
 319         if (cmd->git_cmd)
 320                 strbuf_addstr(&buf_payload, " git");
 321         sq_quote_argv_pretty(&buf_payload, cmd->argv);
 322
 323         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 324                          NULL, NULL, &buf_payload);
 325         strbuf_release(&buf_payload);
 326 }
 327
 328 static void fn_child_exit_fl(const char *file, int line,
 329                              uint64_t us_elapsed_absolute, int cid, int pid,
 330                              int code, uint64_t us_elapsed_child)
 331 {
 332         const char *event_name = "child_exit";
 333         struct strbuf buf_payload = STRBUF_INIT;
 334
 335         strbuf_addf(&buf_payload, "[ch%d] pid:%d code:%d", cid, pid, code);
 336
 337         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 338                          &us_elapsed_child, NULL, &buf_payload);
 339         strbuf_release(&buf_payload);
 340 }
 341
 342 static void fn_thread_start_fl(const char *file, int line,
 343                                uint64_t us_elapsed_absolute)
 344 {
 345         const char *event_name = "thread_start";
 346         struct strbuf buf_payload = STRBUF_INIT;
 347
 348         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 349                          NULL, NULL, &buf_payload);
 350         strbuf_release(&buf_payload);
 351 }
 352
 353 static void fn_thread_exit_fl(const char *file, int line,
 354                               uint64_t us_elapsed_absolute,
 355                               uint64_t us_elapsed_thread)
 356 {
 357         const char *event_name = "thread_exit";
 358         struct strbuf buf_payload = STRBUF_INIT;
 359
 360         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 361                          &us_elapsed_thread, NULL, &buf_payload);
 362         strbuf_release(&buf_payload);
 363 }
 364
 365 static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 366                        int exec_id, const char *exe, const char **argv)
 367 {
 368         const char *event_name = "exec";
 369         struct strbuf buf_payload = STRBUF_INIT;
 370
 371         strbuf_addf(&buf_payload, "id:%d ", exec_id);
 372         strbuf_addstr(&buf_payload, "argv:");
 373         if (exe)
 374                 strbuf_addf(&buf_payload, " %s", exe);
 375         sq_quote_argv_pretty(&buf_payload, argv);
 376
 377         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 378                          NULL, NULL, &buf_payload);
 379         strbuf_release(&buf_payload);
 380 }
 381
 382 static void fn_exec_result_fl(const char *file, int line,
 383                               uint64_t us_elapsed_absolute, int exec_id,
 384                               int code)
 385 {
 386         const char *event_name = "exec_result";
 387         struct strbuf buf_payload = STRBUF_INIT;
 388
 389         strbuf_addf(&buf_payload, "id:%d code:%d", exec_id, code);
 390         if (code > 0)
 391                 strbuf_addf(&buf_payload, " err:%s", strerror(code));
 392
 393         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 394                          NULL, NULL, &buf_payload);
 395         strbuf_release(&buf_payload);
 396 }
 397
 398 static void fn_param_fl(const char *file, int line, const char *param,
 399                         const char *value)
 400 {
 401         const char *event_name = "def_param";
 402         struct strbuf buf_payload = STRBUF_INIT;
 403
 404         strbuf_addf(&buf_payload, "%s:%s", param, value);
 405
 406         perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 407                          &buf_payload);
 408         strbuf_release(&buf_payload);
 409 }
 410
 411 static void fn_repo_fl(const char *file, int line,
 412                        const struct repository *repo)
 413 {
 414         const char *event_name = "def_repo";
 415         struct strbuf buf_payload = STRBUF_INIT;
 416
 417         strbuf_addstr(&buf_payload, "worktree:");
 418         sq_quote_buf_pretty(&buf_payload, repo->worktree);
 419
 420         perf_io_write_fl(file, line, event_name, repo, NULL, NULL, NULL,
 421                          &buf_payload);
 422         strbuf_release(&buf_payload);
 423 }
 424
 425 static void fn_region_enter_printf_va_fl(const char *file, int line,
 426                                          uint64_t us_elapsed_absolute,
 427                                          const char *category,
 428                                          const char *label,
 429                                          const struct repository *repo,
 430                                          const char *fmt, va_list ap)
 431 {
 432         const char *event_name = "region_enter";
 433         struct strbuf buf_payload = STRBUF_INIT;
 434
 435         if (label)
 436                 strbuf_addf(&buf_payload, "label:%s ", label);
 437         maybe_append_string_va(&buf_payload, fmt, ap);
 438
 439         perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 440                          NULL, category, &buf_payload);
 441         strbuf_release(&buf_payload);
 442 }
 443
 444 static void fn_region_leave_printf_va_fl(
 445         const char *file, int line, uint64_t us_elapsed_absolute,
 446         uint64_t us_elapsed_region, const char *category, const char *label,
 447         const struct repository *repo, const char *fmt, va_list ap)
 448 {
 449         const char *event_name = "region_leave";
 450         struct strbuf buf_payload = STRBUF_INIT;
 451
 452         if (label)
 453                 strbuf_addf(&buf_payload, "label:%s ", label);
 454         maybe_append_string_va(&buf_payload, fmt, ap);
 455
 456         perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 457                          &us_elapsed_region, category, &buf_payload);
 458         strbuf_release(&buf_payload);
 459 }
 460
 461 static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 462                        uint64_t us_elapsed_region, const char *category,
 463                        const struct repository *repo, const char *key,
 464                        const char *value)
 465 {
 466         const char *event_name = "data";
 467         struct strbuf buf_payload = STRBUF_INIT;
 468
 469         strbuf_addf(&buf_payload, "%s:%s", key, value);
 470
 471         perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 472                          &us_elapsed_region, category, &buf_payload);
 473         strbuf_release(&buf_payload);
 474 }
 475
 476 static void fn_data_json_fl(const char *file, int line,
 477                             uint64_t us_elapsed_absolute,
 478                             uint64_t us_elapsed_region, const char *category,
 479                             const struct repository *repo, const char *key,
 480                             const struct json_writer *value)
 481 {
 482         const char *event_name = "data_json";
 483         struct strbuf buf_payload = STRBUF_INIT;
 484
 485         strbuf_addf(&buf_payload, "%s:%s", key, value->json.buf);
 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_printf_va_fl(const char *file, int line,
 493                             uint64_t us_elapsed_absolute, const char *fmt,
 494                             va_list ap)
 495 {
 496         const char *event_name = "printf";
 497         struct strbuf buf_payload = STRBUF_INIT;
 498
 499         maybe_append_string_va(&buf_payload, fmt, ap);
 500
 501         perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 502                          NULL, NULL, &buf_payload);
 503         strbuf_release(&buf_payload);
 504 }
 505
 506 struct tr2_tgt tr2_tgt_perf = {
 507         &tr2dst_perf,
 508
 509         fn_init,
 510         fn_term,
 511
 512         fn_version_fl,
 513         fn_start_fl,
 514         fn_exit_fl,
 515         fn_signal,
 516         fn_atexit,
 517         fn_error_va_fl,
 518         fn_command_path_fl,
 519         fn_command_name_fl,
 520         fn_command_mode_fl,
 521         fn_alias_fl,
 522         fn_child_start_fl,
 523         fn_child_exit_fl,
 524         fn_thread_start_fl,
 525         fn_thread_exit_fl,
 526         fn_exec_fl,
 527         fn_exec_result_fl,
 528         fn_param_fl,
 529         fn_repo_fl,
 530         fn_region_enter_printf_va_fl,
 531         fn_region_leave_printf_va_fl,
 532         fn_data_fl,
 533         fn_data_json_fl,
 534         fn_printf_va_fl,
 535 };