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_tbuf.h"
  10 #include "trace2/tr2_tgt.h"
  11 #include "trace2/tr2_tls.h"
  12
  13 static 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"
  22 static 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
  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         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
  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_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, 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
 174 static 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
 187 static 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
 199 static 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
 211 static 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
 229 static 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
 242 static 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
 254 static 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
 269 static 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
 281 static 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
 295 static 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
 327 static 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
 341 static 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
 352 static 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
 364 static 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
 381 static 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
 397 static 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
 410 static 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
 424 static 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
 443 static 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
 460 static 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
 475 static 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
 491 static 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
 505 struct 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 };