trace2 / tr2_tgt_perf.con commit Merge branch 'ds/include-exclude' (9755f70)
   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
  14static 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 */
  22static 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_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        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
  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_be_brief) {
  81                struct tr2_tbuf tb_now;
  82                size_t fl_end_col;
  83
  84                tr2_tbuf_local_time(&tb_now);
  85                strbuf_addstr(buf, tb_now.buf);
  86                strbuf_addch(buf, ' ');
  87
  88                fl_end_col = buf->len + TR2FMT_PERF_FL_WIDTH;
  89
  90                if (file && *file) {
  91                        struct strbuf buf_fl = STRBUF_INIT;
  92
  93                        strbuf_addf(&buf_fl, "%s:%d", file, line);
  94
  95                        if (buf_fl.len <= TR2FMT_PERF_FL_WIDTH)
  96                                strbuf_addbuf(buf, &buf_fl);
  97                        else {
  98                                size_t avail = TR2FMT_PERF_FL_WIDTH - 3;
  99                                strbuf_addstr(buf, "...");
 100                                strbuf_add(buf,
 101                                           &buf_fl.buf[buf_fl.len - avail],
 102                                           avail);
 103                        }
 104
 105                        strbuf_release(&buf_fl);
 106                }
 107
 108                while (buf->len < fl_end_col)
 109                        strbuf_addch(buf, ' ');
 110
 111                strbuf_addstr(buf, " | ");
 112        }
 113
 114        strbuf_addf(buf, "d%d | ", tr2_sid_depth());
 115        strbuf_addf(buf, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME,
 116                    ctx->thread_name.buf, TR2FMT_PERF_MAX_EVENT_NAME,
 117                    event_name);
 118
 119        len = buf->len + TR2FMT_PERF_REPO_WIDTH;
 120        if (repo)
 121                strbuf_addf(buf, "r%d ", repo->trace2_repo_id);
 122        while (buf->len < len)
 123                strbuf_addch(buf, ' ');
 124        strbuf_addstr(buf, " | ");
 125
 126        if (p_us_elapsed_absolute)
 127                strbuf_addf(buf, "%9.6f | ",
 128                            ((double)(*p_us_elapsed_absolute)) / 1000000.0);
 129        else
 130                strbuf_addf(buf, "%9s | ", " ");
 131
 132        if (p_us_elapsed_relative)
 133                strbuf_addf(buf, "%9.6f | ",
 134                            ((double)(*p_us_elapsed_relative)) / 1000000.0);
 135        else
 136                strbuf_addf(buf, "%9s | ", " ");
 137
 138        strbuf_addf(buf, "%-*.*s | ", TR2FMT_PERF_CATEGORY_WIDTH,
 139                    TR2FMT_PERF_CATEGORY_WIDTH, (category ? category : ""));
 140
 141        if (ctx->nr_open_regions > 0) {
 142                int len_indent = TR2_INDENT_LENGTH(ctx);
 143                while (len_indent > dots.len) {
 144                        strbuf_addbuf(buf, &dots);
 145                        len_indent -= dots.len;
 146                }
 147                strbuf_addf(buf, "%.*s", len_indent, dots.buf);
 148        }
 149}
 150
 151static void perf_io_write_fl(const char *file, int line, const char *event_name,
 152                             const struct repository *repo,
 153                             uint64_t *p_us_elapsed_absolute,
 154                             uint64_t *p_us_elapsed_relative,
 155                             const char *category,
 156                             const struct strbuf *buf_payload)
 157{
 158        struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
 159        struct strbuf buf_line = STRBUF_INIT;
 160
 161        perf_fmt_prepare(event_name, ctx, file, line, repo,
 162                         p_us_elapsed_absolute, p_us_elapsed_relative, category,
 163                         &buf_line);
 164        strbuf_addbuf(&buf_line, buf_payload);
 165        tr2_dst_write_line(&tr2dst_perf, &buf_line);
 166        strbuf_release(&buf_line);
 167}
 168
 169static void fn_version_fl(const char *file, int line)
 170{
 171        const char *event_name = "version";
 172        struct strbuf buf_payload = STRBUF_INIT;
 173
 174        strbuf_addstr(&buf_payload, git_version_string);
 175
 176        perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 177                         &buf_payload);
 178        strbuf_release(&buf_payload);
 179}
 180
 181static void fn_start_fl(const char *file, int line,
 182                        uint64_t us_elapsed_absolute, const char **argv)
 183{
 184        const char *event_name = "start";
 185        struct strbuf buf_payload = STRBUF_INIT;
 186
 187        sq_append_quote_argv_pretty(&buf_payload, argv);
 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
 194static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 195                       int code)
 196{
 197        const char *event_name = "exit";
 198        struct strbuf buf_payload = STRBUF_INIT;
 199
 200        strbuf_addf(&buf_payload, "code:%d", code);
 201
 202        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 203                         NULL, NULL, &buf_payload);
 204        strbuf_release(&buf_payload);
 205}
 206
 207static void fn_signal(uint64_t us_elapsed_absolute, int signo)
 208{
 209        const char *event_name = "signal";
 210        struct strbuf buf_payload = STRBUF_INIT;
 211
 212        strbuf_addf(&buf_payload, "signo:%d", signo);
 213
 214        perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
 215                         &us_elapsed_absolute, NULL, NULL, &buf_payload);
 216        strbuf_release(&buf_payload);
 217}
 218
 219static void fn_atexit(uint64_t us_elapsed_absolute, int code)
 220{
 221        const char *event_name = "atexit";
 222        struct strbuf buf_payload = STRBUF_INIT;
 223
 224        strbuf_addf(&buf_payload, "code:%d", code);
 225
 226        perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
 227                         &us_elapsed_absolute, NULL, NULL, &buf_payload);
 228        strbuf_release(&buf_payload);
 229}
 230
 231static void maybe_append_string_va(struct strbuf *buf, const char *fmt,
 232                                   va_list ap)
 233{
 234        if (fmt && *fmt) {
 235                va_list copy_ap;
 236
 237                va_copy(copy_ap, ap);
 238                strbuf_vaddf(buf, fmt, copy_ap);
 239                va_end(copy_ap);
 240                return;
 241        }
 242}
 243
 244static void fn_error_va_fl(const char *file, int line, const char *fmt,
 245                           va_list ap)
 246{
 247        const char *event_name = "error";
 248        struct strbuf buf_payload = STRBUF_INIT;
 249
 250        maybe_append_string_va(&buf_payload, fmt, ap);
 251
 252        perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 253                         &buf_payload);
 254        strbuf_release(&buf_payload);
 255}
 256
 257static void fn_command_path_fl(const char *file, int line, const char *pathname)
 258{
 259        const char *event_name = "cmd_path";
 260        struct strbuf buf_payload = STRBUF_INIT;
 261
 262        strbuf_addstr(&buf_payload, pathname);
 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_name_fl(const char *file, int line, const char *name,
 270                               const char *hierarchy)
 271{
 272        const char *event_name = "cmd_name";
 273        struct strbuf buf_payload = STRBUF_INIT;
 274
 275        strbuf_addstr(&buf_payload, name);
 276        if (hierarchy && *hierarchy)
 277                strbuf_addf(&buf_payload, " (%s)", hierarchy);
 278
 279        perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 280                         &buf_payload);
 281        strbuf_release(&buf_payload);
 282}
 283
 284static void fn_command_mode_fl(const char *file, int line, const char *mode)
 285{
 286        const char *event_name = "cmd_mode";
 287        struct strbuf buf_payload = STRBUF_INIT;
 288
 289        strbuf_addstr(&buf_payload, mode);
 290
 291        perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 292                         &buf_payload);
 293        strbuf_release(&buf_payload);
 294}
 295
 296static void fn_alias_fl(const char *file, int line, const char *alias,
 297                        const char **argv)
 298{
 299        const char *event_name = "alias";
 300        struct strbuf buf_payload = STRBUF_INIT;
 301
 302        strbuf_addf(&buf_payload, "alias:%s argv:[", alias);
 303        sq_append_quote_argv_pretty(&buf_payload, argv);
 304        strbuf_addch(&buf_payload, ']');
 305
 306        perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 307                         &buf_payload);
 308        strbuf_release(&buf_payload);
 309}
 310
 311static void fn_child_start_fl(const char *file, int line,
 312                              uint64_t us_elapsed_absolute,
 313                              const struct child_process *cmd)
 314{
 315        const char *event_name = "child_start";
 316        struct strbuf buf_payload = STRBUF_INIT;
 317
 318        if (cmd->trace2_hook_name) {
 319                strbuf_addf(&buf_payload, "[ch%d] class:hook hook:%s",
 320                            cmd->trace2_child_id, cmd->trace2_hook_name);
 321        } else {
 322                const char *child_class =
 323                        cmd->trace2_child_class ? cmd->trace2_child_class : "?";
 324                strbuf_addf(&buf_payload, "[ch%d] class:%s",
 325                            cmd->trace2_child_id, child_class);
 326        }
 327
 328        if (cmd->dir) {
 329                strbuf_addstr(&buf_payload, " cd:");
 330                sq_quote_buf_pretty(&buf_payload, cmd->dir);
 331        }
 332
 333        strbuf_addstr(&buf_payload, " argv:[");
 334        if (cmd->git_cmd) {
 335                strbuf_addstr(&buf_payload, "git");
 336                if (cmd->argv[0])
 337                        strbuf_addch(&buf_payload, ' ');
 338        }
 339        sq_append_quote_argv_pretty(&buf_payload, cmd->argv);
 340        strbuf_addch(&buf_payload, ']');
 341
 342        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 343                         NULL, NULL, &buf_payload);
 344        strbuf_release(&buf_payload);
 345}
 346
 347static void fn_child_exit_fl(const char *file, int line,
 348                             uint64_t us_elapsed_absolute, int cid, int pid,
 349                             int code, uint64_t us_elapsed_child)
 350{
 351        const char *event_name = "child_exit";
 352        struct strbuf buf_payload = STRBUF_INIT;
 353
 354        strbuf_addf(&buf_payload, "[ch%d] pid:%d code:%d", cid, pid, code);
 355
 356        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 357                         &us_elapsed_child, NULL, &buf_payload);
 358        strbuf_release(&buf_payload);
 359}
 360
 361static void fn_thread_start_fl(const char *file, int line,
 362                               uint64_t us_elapsed_absolute)
 363{
 364        const char *event_name = "thread_start";
 365        struct strbuf buf_payload = STRBUF_INIT;
 366
 367        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 368                         NULL, NULL, &buf_payload);
 369        strbuf_release(&buf_payload);
 370}
 371
 372static void fn_thread_exit_fl(const char *file, int line,
 373                              uint64_t us_elapsed_absolute,
 374                              uint64_t us_elapsed_thread)
 375{
 376        const char *event_name = "thread_exit";
 377        struct strbuf buf_payload = STRBUF_INIT;
 378
 379        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 380                         &us_elapsed_thread, NULL, &buf_payload);
 381        strbuf_release(&buf_payload);
 382}
 383
 384static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 385                       int exec_id, const char *exe, const char **argv)
 386{
 387        const char *event_name = "exec";
 388        struct strbuf buf_payload = STRBUF_INIT;
 389
 390        strbuf_addf(&buf_payload, "id:%d ", exec_id);
 391        strbuf_addstr(&buf_payload, "argv:[");
 392        if (exe) {
 393                strbuf_addstr(&buf_payload, exe);
 394                if (argv[0])
 395                        strbuf_addch(&buf_payload, ' ');
 396        }
 397        sq_append_quote_argv_pretty(&buf_payload, argv);
 398        strbuf_addch(&buf_payload, ']');
 399
 400        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 401                         NULL, NULL, &buf_payload);
 402        strbuf_release(&buf_payload);
 403}
 404
 405static void fn_exec_result_fl(const char *file, int line,
 406                              uint64_t us_elapsed_absolute, int exec_id,
 407                              int code)
 408{
 409        const char *event_name = "exec_result";
 410        struct strbuf buf_payload = STRBUF_INIT;
 411
 412        strbuf_addf(&buf_payload, "id:%d code:%d", exec_id, code);
 413        if (code > 0)
 414                strbuf_addf(&buf_payload, " err:%s", strerror(code));
 415
 416        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 417                         NULL, NULL, &buf_payload);
 418        strbuf_release(&buf_payload);
 419}
 420
 421static void fn_param_fl(const char *file, int line, const char *param,
 422                        const char *value)
 423{
 424        const char *event_name = "def_param";
 425        struct strbuf buf_payload = STRBUF_INIT;
 426
 427        strbuf_addf(&buf_payload, "%s:%s", param, value);
 428
 429        perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
 430                         &buf_payload);
 431        strbuf_release(&buf_payload);
 432}
 433
 434static void fn_repo_fl(const char *file, int line,
 435                       const struct repository *repo)
 436{
 437        const char *event_name = "def_repo";
 438        struct strbuf buf_payload = STRBUF_INIT;
 439
 440        strbuf_addstr(&buf_payload, "worktree:");
 441        sq_quote_buf_pretty(&buf_payload, repo->worktree);
 442
 443        perf_io_write_fl(file, line, event_name, repo, NULL, NULL, NULL,
 444                         &buf_payload);
 445        strbuf_release(&buf_payload);
 446}
 447
 448static void fn_region_enter_printf_va_fl(const char *file, int line,
 449                                         uint64_t us_elapsed_absolute,
 450                                         const char *category,
 451                                         const char *label,
 452                                         const struct repository *repo,
 453                                         const char *fmt, va_list ap)
 454{
 455        const char *event_name = "region_enter";
 456        struct strbuf buf_payload = STRBUF_INIT;
 457
 458        if (label)
 459                strbuf_addf(&buf_payload, "label:%s", label);
 460        if (fmt && *fmt) {
 461                strbuf_addch(&buf_payload, ' ');
 462                maybe_append_string_va(&buf_payload, fmt, ap);
 463        }
 464
 465        perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 466                         NULL, category, &buf_payload);
 467        strbuf_release(&buf_payload);
 468}
 469
 470static void fn_region_leave_printf_va_fl(
 471        const char *file, int line, uint64_t us_elapsed_absolute,
 472        uint64_t us_elapsed_region, const char *category, const char *label,
 473        const struct repository *repo, const char *fmt, va_list ap)
 474{
 475        const char *event_name = "region_leave";
 476        struct strbuf buf_payload = STRBUF_INIT;
 477
 478        if (label)
 479                strbuf_addf(&buf_payload, "label:%s", label);
 480        if (fmt && *fmt) {
 481                strbuf_addch(&buf_payload, ' ' );
 482                maybe_append_string_va(&buf_payload, fmt, ap);
 483        }
 484
 485        perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 486                         &us_elapsed_region, category, &buf_payload);
 487        strbuf_release(&buf_payload);
 488}
 489
 490static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 491                       uint64_t us_elapsed_region, const char *category,
 492                       const struct repository *repo, const char *key,
 493                       const char *value)
 494{
 495        const char *event_name = "data";
 496        struct strbuf buf_payload = STRBUF_INIT;
 497
 498        strbuf_addf(&buf_payload, "%s:%s", key, value);
 499
 500        perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 501                         &us_elapsed_region, category, &buf_payload);
 502        strbuf_release(&buf_payload);
 503}
 504
 505static void fn_data_json_fl(const char *file, int line,
 506                            uint64_t us_elapsed_absolute,
 507                            uint64_t us_elapsed_region, const char *category,
 508                            const struct repository *repo, const char *key,
 509                            const struct json_writer *value)
 510{
 511        const char *event_name = "data_json";
 512        struct strbuf buf_payload = STRBUF_INIT;
 513
 514        strbuf_addf(&buf_payload, "%s:%s", key, value->json.buf);
 515
 516        perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
 517                         &us_elapsed_region, category, &buf_payload);
 518        strbuf_release(&buf_payload);
 519}
 520
 521static void fn_printf_va_fl(const char *file, int line,
 522                            uint64_t us_elapsed_absolute, const char *fmt,
 523                            va_list ap)
 524{
 525        const char *event_name = "printf";
 526        struct strbuf buf_payload = STRBUF_INIT;
 527
 528        maybe_append_string_va(&buf_payload, fmt, ap);
 529
 530        perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
 531                         NULL, NULL, &buf_payload);
 532        strbuf_release(&buf_payload);
 533}
 534
 535struct tr2_tgt tr2_tgt_perf = {
 536        &tr2dst_perf,
 537
 538        fn_init,
 539        fn_term,
 540
 541        fn_version_fl,
 542        fn_start_fl,
 543        fn_exit_fl,
 544        fn_signal,
 545        fn_atexit,
 546        fn_error_va_fl,
 547        fn_command_path_fl,
 548        fn_command_name_fl,
 549        fn_command_mode_fl,
 550        fn_alias_fl,
 551        fn_child_start_fl,
 552        fn_child_exit_fl,
 553        fn_thread_start_fl,
 554        fn_thread_exit_fl,
 555        fn_exec_fl,
 556        fn_exec_result_fl,
 557        fn_param_fl,
 558        fn_repo_fl,
 559        fn_region_enter_printf_va_fl,
 560        fn_region_leave_printf_va_fl,
 561        fn_data_fl,
 562        fn_data_json_fl,
 563        fn_printf_va_fl,
 564};