t/helper/test-trace2.c

   1 #include "test-tool.h"
   2 #include "strvec.h"
   3 #include "run-command.h"
   4 #include "exec-cmd.h"
   5 #include "config.h"
   6 #include "repository.h"
   7 #include "trace2.h"
   8
   9 typedef int(fn_unit_test)(int argc, const char **argv);
  10
  11 struct unit_test {
  12         fn_unit_test *ut_fn;
  13         const char *ut_name;
  14         const char *ut_usage;
  15 };
  16
  17 #define MyOk 0
  18 #define MyError 1
  19
  20 static int get_i(int *p_value, const char *data)
  21 {
  22         char *endptr;
  23
  24         if (!data || !*data)
  25                 return MyError;
  26
  27         *p_value = strtol(data, &endptr, 10);
  28         if (*endptr || errno == ERANGE)
  29                 return MyError;
  30
  31         return MyOk;
  32 }
  33
  34 /*
  35  * Cause process to exit with the requested value via "return".
  36  *
  37  * Rely on test-tool.c:cmd_main() to call trace2_cmd_exit()
  38  * with our result.
  39  *
  40  * Test harness can confirm:
  41  * [] the process-exit value.
  42  * [] the "code" field in the "exit" trace2 event.
  43  * [] the "code" field in the "atexit" trace2 event.
  44  * [] the "name" field in the "cmd_name" trace2 event.
  45  * [] "def_param" events for all of the "interesting" pre-defined
  46  * config settings.
  47  */
  48 static int ut_001return(int argc UNUSED, const char **argv)
  49 {
  50         int rc;
  51
  52         if (get_i(&rc, argv[0]))
  53                 die("expect <exit_code>");
  54
  55         return rc;
  56 }
  57
  58 /*
  59  * Cause the process to exit with the requested value via "exit()".
  60  *
  61  * Test harness can confirm:
  62  * [] the "code" field in the "exit" trace2 event.
  63  * [] the "code" field in the "atexit" trace2 event.
  64  * [] the "name" field in the "cmd_name" trace2 event.
  65  * [] "def_param" events for all of the "interesting" pre-defined
  66  * config settings.
  67  */
  68 static int ut_002exit(int argc UNUSED, const char **argv)
  69 {
  70         int rc;
  71
  72         if (get_i(&rc, argv[0]))
  73                 die("expect <exit_code>");
  74
  75         exit(rc);
  76 }
  77
  78 /*
  79  * Send an "error" event with each value in argv.  Normally, git only issues
  80  * a single "error" event immediately before issuing an "exit" event (such
  81  * as in die() or BUG()), but multiple "error" events are allowed.
  82  *
  83  * Test harness can confirm:
  84  * [] a trace2 "error" event for each value in argv.
  85  * [] the "name" field in the "cmd_name" trace2 event.
  86  * [] (optional) the file:line in the "exit" event refers to this function.
  87  */
  88 static int ut_003error(int argc, const char **argv)
  89 {
  90         int k;
  91
  92         if (!argv[0] || !*argv[0])
  93                 die("expect <error_message>");
  94
  95         for (k = 0; k < argc; k++)
  96                 error("%s", argv[k]);
  97
  98         return 0;
  99 }
 100
 101 /*
 102  * Run a child process and wait for it to finish and exit with its return code.
 103  * test-tool trace2 004child [<child-command-line>]
 104  *
 105  * For example:
 106  * test-tool trace2 004child git version
 107  * test-tool trace2 004child test-tool trace2 001return 0
 108  * test-tool trace2 004child test-tool trace2 004child test-tool trace2 004child
 109  * test-tool trace2 004child git -c alias.xyz=version xyz
 110  *
 111  * Test harness can confirm:
 112  * [] the "name" field in the "cmd_name" trace2 event.
 113  * [] that the outer process has a single component SID (or depth "d0" in
 114  *    the PERF stream).
 115  * [] that "child_start" and "child_exit" events are generated for the child.
 116  * [] if the child process is an instrumented executable:
 117  *    [] that "version", "start", ..., "exit", and "atexit" events are
 118  *       generated by the child process.
 119  *    [] that the child process events have a multiple component SID (or
 120  *       depth "dN+1" in the PERF stream).
 121  * [] that the child exit code is propagated to the parent process "exit"
 122  *    and "atexit" events..
 123  * [] (optional) that the "t_abs" field in the child process "atexit" event
 124  *    is less than the "t_rel" field in the "child_exit" event of the parent
 125  *    process.
 126  * [] if the child process is like the alias example above,
 127  *    [] (optional) the child process attempts to run "git-xyx" as a dashed
 128  *       command.
 129  *    [] the child process emits an "alias" event with "xyz" => "version"
 130  *    [] the child process runs "git version" as a child process.
 131  *    [] the child process has a 3 component SID (or depth "d2" in the PERF
 132  *       stream).
 133  */
 134 static int ut_004child(int argc, const char **argv)
 135 {
 136         struct child_process cmd = CHILD_PROCESS_INIT;
 137         int result;
 138
 139         /*
 140          * Allow empty <child_command_line> so we can do arbitrarily deep
 141          * command nesting and let the last one be null.
 142          */
 143         if (!argc)
 144                 return 0;
 145
 146         strvec_pushv(&cmd.args, argv);
 147         result = run_command(&cmd);
 148         exit(result);
 149 }
 150
 151 /*
 152  * Exec a git command.  This may either create a child process (Windows)
 153  * or replace the existing process.
 154  * test-tool trace2 005exec <git_command_args>
 155  *
 156  * For example:
 157  * test-tool trace2 005exec version
 158  *
 159  * Test harness can confirm (on Windows):
 160  * [] the "name" field in the "cmd_name" trace2 event.
 161  * [] that the outer process has a single component SID (or depth "d0" in
 162  *    the PERF stream).
 163  * [] that "exec" and "exec_result" events are generated for the child
 164  *    process (since the Windows compatibility layer fakes an exec() with
 165  *    a CreateProcess(), WaitForSingleObject(), and exit()).
 166  * [] that the child process has multiple component SID (or depth "dN+1"
 167  *    in the PERF stream).
 168  *
 169  * Test harness can confirm (on platforms with a real exec() function):
 170  * [] TODO talk about process replacement and how it affects SID.
 171  */
 172 static int ut_005exec(int argc, const char **argv)
 173 {
 174         int result;
 175
 176         if (!argc)
 177                 return 0;
 178
 179         result = execv_git_cmd(argv);
 180         return result;
 181 }
 182
 183 static int ut_006data(int argc, const char **argv)
 184 {
 185         const char *usage_error =
 186                 "expect <cat0> <k0> <v0> [<cat1> <k1> <v1> [...]]";
 187
 188         if (argc % 3 != 0)
 189                 die("%s", usage_error);
 190
 191         while (argc) {
 192                 if (!argv[0] || !*argv[0] || !argv[1] || !*argv[1] ||
 193                     !argv[2] || !*argv[2])
 194                         die("%s", usage_error);
 195
 196                 trace2_data_string(argv[0], the_repository, argv[1], argv[2]);
 197                 argv += 3;
 198                 argc -= 3;
 199         }
 200
 201         return 0;
 202 }
 203
 204 static int ut_007BUG(int argc UNUSED, const char **argv UNUSED)
 205 {
 206         /*
 207          * Exercise BUG() to ensure that the message is printed to trace2.
 208          */
 209         BUG("the bug message");
 210 }
 211
 212 static int ut_008bug(int argc UNUSED, const char **argv UNUSED)
 213 {
 214         bug("a bug message");
 215         bug("another bug message");
 216         BUG_if_bug("an explicit BUG_if_bug() following bug() call(s) is nice, but not required");
 217         return 0;
 218 }
 219
 220 static int ut_009bug_BUG(int argc UNUSED, const char **argv UNUSED)
 221 {
 222         bug("a bug message");
 223         bug("another bug message");
 224         /* The BUG_if_bug(...) isn't here, but we'll spot bug() calls on exit()! */
 225         return 0;
 226 }
 227
 228 static int ut_010bug_BUG(int argc UNUSED, const char **argv UNUSED)
 229 {
 230         bug("a %s message", "bug");
 231         BUG("a %s message", "BUG");
 232 }
 233
 234 /*
 235  * Single-threaded timer test.  Create several intervals using the
 236  * TEST1 timer.  The test script can verify that an aggregate Trace2
 237  * "timer" event is emitted indicating that we started+stopped the
 238  * timer the requested number of times.
 239  */
 240 static int ut_100timer(int argc, const char **argv)
 241 {
 242         const char *usage_error =
 243                 "expect <count> <ms_delay>";
 244
 245         int count = 0;
 246         int delay = 0;
 247         int k;
 248
 249         if (argc != 2)
 250                 die("%s", usage_error);
 251         if (get_i(&count, argv[0]))
 252                 die("%s", usage_error);
 253         if (get_i(&delay, argv[1]))
 254                 die("%s", usage_error);
 255
 256         for (k = 0; k < count; k++) {
 257                 trace2_timer_start(TRACE2_TIMER_ID_TEST1);
 258                 sleep_millisec(delay);
 259                 trace2_timer_stop(TRACE2_TIMER_ID_TEST1);
 260         }
 261
 262         return 0;
 263 }
 264
 265 struct ut_101_data {
 266         int count;
 267         int delay;
 268 };
 269
 270 static void *ut_101timer_thread_proc(void *_ut_101_data)
 271 {
 272         struct ut_101_data *data = _ut_101_data;
 273         int k;
 274
 275         trace2_thread_start("ut_101");
 276
 277         for (k = 0; k < data->count; k++) {
 278                 trace2_timer_start(TRACE2_TIMER_ID_TEST2);
 279                 sleep_millisec(data->delay);
 280                 trace2_timer_stop(TRACE2_TIMER_ID_TEST2);
 281         }
 282
 283         trace2_thread_exit();
 284         return NULL;
 285 }
 286
 287 /*
 288  * Multi-threaded timer test.  Create several threads that each create
 289  * several intervals using the TEST2 timer.  The test script can verify
 290  * that an individual Trace2 "th_timer" events for each thread and an
 291  * aggregate "timer" event are generated.
 292  */
 293 static int ut_101timer(int argc, const char **argv)
 294 {
 295         const char *usage_error =
 296                 "expect <count> <ms_delay> <threads>";
 297
 298         struct ut_101_data data = { 0, 0 };
 299         int nr_threads = 0;
 300         int k;
 301         pthread_t *pids = NULL;
 302
 303         if (argc != 3)
 304                 die("%s", usage_error);
 305         if (get_i(&data.count, argv[0]))
 306                 die("%s", usage_error);
 307         if (get_i(&data.delay, argv[1]))
 308                 die("%s", usage_error);
 309         if (get_i(&nr_threads, argv[2]))
 310                 die("%s", usage_error);
 311
 312         CALLOC_ARRAY(pids, nr_threads);
 313
 314         for (k = 0; k < nr_threads; k++) {
 315                 if (pthread_create(&pids[k], NULL, ut_101timer_thread_proc, &data))
 316                         die("failed to create thread[%d]", k);
 317         }
 318
 319         for (k = 0; k < nr_threads; k++) {
 320                 if (pthread_join(pids[k], NULL))
 321                         die("failed to join thread[%d]", k);
 322         }
 323
 324         free(pids);
 325
 326         return 0;
 327 }
 328
 329 /*
 330  * Single-threaded counter test.  Add several values to the TEST1 counter.
 331  * The test script can verify that the final sum is reported in the "counter"
 332  * event.
 333  */
 334 static int ut_200counter(int argc, const char **argv)
 335 {
 336         const char *usage_error =
 337                 "expect <v1> [<v2> [...]]";
 338         int value;
 339         int k;
 340
 341         if (argc < 1)
 342                 die("%s", usage_error);
 343
 344         for (k = 0; k < argc; k++) {
 345                 if (get_i(&value, argv[k]))
 346                         die("invalid value[%s] -- %s",
 347                             argv[k], usage_error);
 348                 trace2_counter_add(TRACE2_COUNTER_ID_TEST1, value);
 349         }
 350
 351         return 0;
 352 }
 353
 354 /*
 355  * Multi-threaded counter test.  Create seveal threads that each increment
 356  * the TEST2 global counter.  The test script can verify that an individual
 357  * "th_counter" event is generated with a partial sum for each thread and
 358  * that a final aggregate "counter" event is generated.
 359  */
 360
 361 struct ut_201_data {
 362         int v1;
 363         int v2;
 364 };
 365
 366 static void *ut_201counter_thread_proc(void *_ut_201_data)
 367 {
 368         struct ut_201_data *data = _ut_201_data;
 369
 370         trace2_thread_start("ut_201");
 371
 372         trace2_counter_add(TRACE2_COUNTER_ID_TEST2, data->v1);
 373         trace2_counter_add(TRACE2_COUNTER_ID_TEST2, data->v2);
 374
 375         trace2_thread_exit();
 376         return NULL;
 377 }
 378
 379 static int ut_201counter(int argc, const char **argv)
 380 {
 381         const char *usage_error =
 382                 "expect <v1> <v2> <threads>";
 383
 384         struct ut_201_data data = { 0, 0 };
 385         int nr_threads = 0;
 386         int k;
 387         pthread_t *pids = NULL;
 388
 389         if (argc != 3)
 390                 die("%s", usage_error);
 391         if (get_i(&data.v1, argv[0]))
 392                 die("%s", usage_error);
 393         if (get_i(&data.v2, argv[1]))
 394                 die("%s", usage_error);
 395         if (get_i(&nr_threads, argv[2]))
 396                 die("%s", usage_error);
 397
 398         CALLOC_ARRAY(pids, nr_threads);
 399
 400         for (k = 0; k < nr_threads; k++) {
 401                 if (pthread_create(&pids[k], NULL, ut_201counter_thread_proc, &data))
 402                         die("failed to create thread[%d]", k);
 403         }
 404
 405         for (k = 0; k < nr_threads; k++) {
 406                 if (pthread_join(pids[k], NULL))
 407                         die("failed to join thread[%d]", k);
 408         }
 409
 410         free(pids);
 411
 412         return 0;
 413 }
 414
 415 static int ut_300redact_start(int argc, const char **argv)
 416 {
 417         if (!argc)
 418                 die("expect <argv...>");
 419
 420         trace2_cmd_start(argv);
 421
 422         return 0;
 423 }
 424
 425 static int ut_301redact_child_start(int argc, const char **argv)
 426 {
 427         struct child_process cmd = CHILD_PROCESS_INIT;
 428         int k;
 429
 430         if (!argc)
 431                 die("expect <argv...>");
 432
 433         for (k = 0; argv[k]; k++)
 434                 strvec_push(&cmd.args, argv[k]);
 435
 436         trace2_child_start(&cmd);
 437
 438         strvec_clear(&cmd.args);
 439
 440         return 0;
 441 }
 442
 443 static int ut_302redact_exec(int argc, const char **argv)
 444 {
 445         if (!argc)
 446                 die("expect <exe> <argv...>");
 447
 448         trace2_exec(argv[0], &argv[1]);
 449
 450         return 0;
 451 }
 452
 453 static int ut_303redact_def_param(int argc, const char **argv)
 454 {
 455         struct key_value_info kvi = KVI_INIT;
 456
 457         if (argc < 2)
 458                 die("expect <key> <value>");
 459
 460         trace2_def_param(argv[0], argv[1], &kvi);
 461
 462         return 0;
 463 }
 464
 465 /*
 466  * Usage:
 467  *     test-tool trace2 <ut_name_1> <ut_usage_1>
 468  *     test-tool trace2 <ut_name_2> <ut_usage_2>
 469  *     ...
 470  */
 471 #define USAGE_PREFIX "test-tool trace2"
 472
 473 /* clang-format off */
 474 static struct unit_test ut_table[] = {
 475         { ut_001return,   "001return", "<exit_code>" },
 476         { ut_002exit,     "002exit",   "<exit_code>" },
 477         { ut_003error,    "003error",  "<error_message>+" },
 478         { ut_004child,    "004child",  "[<child_command_line>]" },
 479         { ut_005exec,     "005exec",   "<git_command_args>" },
 480         { ut_006data,     "006data",   "[<category> <key> <value>]+" },
 481         { ut_007BUG,      "007bug",    "" },
 482         { ut_008bug,      "008bug",    "" },
 483         { ut_009bug_BUG,  "009bug_BUG","" },
 484         { ut_010bug_BUG,  "010bug_BUG","" },
 485
 486         { ut_100timer,    "100timer",  "<count> <ms_delay>" },
 487         { ut_101timer,    "101timer",  "<count> <ms_delay> <threads>" },
 488
 489         { ut_200counter,  "200counter", "<v1> [<v2> [<v3> [...]]]" },
 490         { ut_201counter,  "201counter", "<v1> <v2> <threads>" },
 491
 492         { ut_300redact_start,       "300redact_start",       "<argv...>" },
 493         { ut_301redact_child_start, "301redact_child_start", "<argv...>" },
 494         { ut_302redact_exec,        "302redact_exec",        "<exe> <argv...>" },
 495         { ut_303redact_def_param,   "303redact_def_param",   "<key> <value>" },
 496 };
 497 /* clang-format on */
 498
 499 /* clang-format off */
 500 #define for_each_ut(k, ut_k)                    \
 501         for (k = 0, ut_k = &ut_table[k];        \
 502              k < ARRAY_SIZE(ut_table);          \
 503              k++, ut_k = &ut_table[k])
 504 /* clang-format on */
 505
 506 static int print_usage(void)
 507 {
 508         int k;
 509         struct unit_test *ut_k;
 510
 511         fprintf(stderr, "usage:\n");
 512         for_each_ut (k, ut_k)
 513                 fprintf(stderr, "\t%s %s %s\n", USAGE_PREFIX, ut_k->ut_name,
 514                         ut_k->ut_usage);
 515
 516         return 129;
 517 }
 518
 519 /*
 520  * Issue various trace2 events for testing.
 521  *
 522  * We assume that these trace2 routines has already been called:
 523  *    [] trace2_initialize()      [common-main.c:main()]
 524  *    [] trace2_cmd_start()       [common-main.c:main()]
 525  *    [] trace2_cmd_name()        [test-tool.c:cmd_main()]
 526  *    [] tracd2_cmd_list_config() [test-tool.c:cmd_main()]
 527  * So that:
 528  *    [] the various trace2 streams are open.
 529  *    [] the process SID has been created.
 530  *    [] the "version" event has been generated.
 531  *    [] the "start" event has been generated.
 532  *    [] the "cmd_name" event has been generated.
 533  *    [] this writes various "def_param" events for interesting config values.
 534  *
 535  * We return from here and let test-tool.c::cmd_main() pass the exit
 536  * code to common-main.c::main(), which will use it to call
 537  * trace2_cmd_exit().
 538  */
 539 int cmd__trace2(int argc, const char **argv)
 540 {
 541         int k;
 542         struct unit_test *ut_k;
 543
 544         argc--; /* skip over "trace2" arg */
 545         argv++;
 546
 547         if (argc)
 548                 for_each_ut (k, ut_k)
 549                         if (!strcmp(argv[0], ut_k->ut_name))
 550                                 return ut_k->ut_fn(argc - 1, argv + 1);
 551
 552         return print_usage();
 553 }