tests/perf_exit.c

   1 #ifdef T_NAMESPACE
   2 #undef T_NAMESPACE
   3 #endif
   4 #include <darwintest.h>
   5 #include <darwintest_utils.h>
   6
   7 #include <sys/kdebug.h>
   8 #include <ktrace/session.h>
   9 #include <spawn.h>
  10 #include <stdio.h>
  11 #include <stdlib.h>
  12 #include <stdatomic.h>
  13
  14 T_GLOBAL_META(
  15         T_META_NAMESPACE("xnu.perf"),
  16         T_META_ASROOT(true),
  17         T_META_LTEPHASE(LTE_SINGLEUSER),
  18         T_META_TAG_PERF
  19         );
  20 #if TARGET_OS_WATCH
  21 #define TEST_TIMEOUT 3600 * (NSEC_PER_SEC)
  22 #else
  23 #define TEST_TIMEOUT 1800 * (NSEC_PER_SEC)
  24 #endif
  25 // From bsd/sys/proc_internal.h
  26 #define PID_MAX 99999
  27
  28 #define EXIT_BINARY "perf_exit_proc"
  29 #define EXIT_BINARY_PATH "./" EXIT_BINARY
  30
  31 #define NEXT_CASE_EVENTID (0xfedcbb00)
  32
  33 struct test_case {
  34         int wired_mem;
  35         int threads;
  36 };
  37
  38 static struct test_case test_cases[] = {
  39         {0, 0},
  40         {0, 10},
  41         {1000000, 0},
  42 #if !TARGET_OS_WATCH
  43         {10000000, 0}
  44 #endif
  45 };
  46
  47 #define TEST_CASES_COUNT (sizeof(test_cases) / sizeof(struct test_case))
  48
  49 static _Atomic int producer_i, consumer_i;
  50
  51 static ktrace_session_t session;
  52
  53 static dispatch_queue_t spawn_queue, processing_queue;
  54
  55 static uint64_t *begin_ts;
  56 static dt_stat_time_t s;
  57 static _Atomic bool tracing_on = false;
  58
  59 void run_exit_test(int proc_wired_mem, int nthreads);
  60
  61 static void
  62 cleanup(void)
  63 {
  64         free(begin_ts);
  65         dispatch_release(spawn_queue);
  66         dispatch_release(processing_queue);
  67         if (tracing_on) {
  68                 ktrace_end(session, 1);
  69         }
  70 }
  71
  72 static dt_stat_time_t
  73 create_stat(int proc_wired_mem, int nthreads)
  74 {
  75         dt_stat_time_t dst = dt_stat_time_create("time");
  76         T_ASSERT_NOTNULL(dst, "created time statistic");
  77
  78         dt_stat_set_variable((dt_stat_t)dst, "proc_threads", nthreads);
  79         dt_stat_set_variable((dt_stat_t)dst, "proc_wired_mem", proc_wired_mem);;
  80
  81         return dst;
  82 }
  83
  84 T_DECL(exit, "exit(2) time from syscall start to end", T_META_TIMEOUT(TEST_TIMEOUT)) {
  85         s = create_stat(test_cases[consumer_i].wired_mem, test_cases[consumer_i].threads);
  86
  87         begin_ts = malloc(sizeof(uint64_t) * PID_MAX);
  88         T_ASSERT_NOTNULL(begin_ts, "created pid array");
  89
  90         T_ATEND(cleanup);
  91
  92         session = ktrace_session_create();
  93         T_ASSERT_NOTNULL(session, "created a trace session");
  94
  95         spawn_queue = dispatch_queue_create("com.apple.perf_exit.spawn_queue", NULL);
  96         processing_queue = dispatch_queue_create("com.apple.perf_exit.processing_queue", NULL);
  97
  98         ktrace_set_completion_handler(session, ^{
  99                 T_ASSERT_EQ(consumer_i, TEST_CASES_COUNT, "ran all the test cases");
 100                 dispatch_sync(spawn_queue, ^(void) {
 101                         tracing_on = false;
 102                 });
 103                 ktrace_session_destroy(session);
 104                 T_END;
 105         });
 106
 107         ktrace_set_signal_handler(session);
 108         ktrace_set_execnames_enabled(session, KTRACE_FEATURE_ENABLED);
 109
 110         // We are only interested in the processes we launched and ourselves
 111         ktrace_filter_process(session, EXIT_BINARY);
 112         ktrace_filter_process(session, "perf_exit");
 113
 114         ktrace_events_single(session, NEXT_CASE_EVENTID, ^(__unused ktrace_event_t e) {
 115                 consumer_i++;
 116                 dt_stat_finalize(s);
 117                 if (consumer_i >= TEST_CASES_COUNT) {
 118                         ktrace_end(session, 1);
 119                 } else {
 120                         s = create_stat(test_cases[consumer_i].wired_mem, test_cases[consumer_i].threads);
 121                 }
 122         });
 123
 124         ktrace_events_single(session, (BSDDBG_CODE(DBG_BSD_EXCP_SC, 1) | DBG_FUNC_START), ^(ktrace_event_t e) {
 125                 T_QUIET; T_ASSERT_LE(e->pid, PID_MAX, "pid %d is valid in start tracepoint", e->pid);
 126                 begin_ts[e->pid] = e->timestamp;
 127         });
 128
 129         ktrace_events_single(session, (BSDDBG_CODE(DBG_BSD_PROC, BSD_PROC_EXIT) | DBG_FUNC_END), ^(ktrace_event_t e) {
 130                 T_ASSERT_LE(e->pid, PID_MAX, "pid %d is valid in end tracepoint", e->pid);
 131
 132                 if (begin_ts[e->pid] == 0) {
 133                         return;
 134                 }
 135
 136                 T_QUIET; T_ASSERT_LE(begin_ts[e->pid], e->timestamp, "timestamps are monotonically increasing");
 137                 dt_stat_mach_time_add(s, e->timestamp - begin_ts[e->pid]);
 138
 139
 140                 if (dt_stat_stable(s) && producer_i == consumer_i) {
 141                         dispatch_sync(spawn_queue, ^(void) {
 142                                 producer_i++;
 143                                 T_ASSERT_POSIX_ZERO(kdebug_trace(NEXT_CASE_EVENTID, producer_i, 0, 0, 0), "kdebug_trace returns 0");
 144                         });
 145                 }
 146         });
 147
 148         int ret = ktrace_start(session, processing_queue);
 149         T_ASSERT_POSIX_ZERO(ret, "starting trace");
 150         tracing_on = true;
 151
 152         // Spawn processes continuously until the test is over
 153
 154         __block void (^spawn_process)(void) = Block_copy(^(void) {
 155                 char nthreads_buf[32], mem_buf[32];
 156
 157                 if (producer_i >= TEST_CASES_COUNT || !tracing_on) {
 158                         return;
 159                 }
 160
 161                 snprintf(nthreads_buf, 32, "%d", test_cases[producer_i].threads);
 162                 snprintf(mem_buf, 32, "%d", test_cases[producer_i].wired_mem);
 163
 164                 char *args[] = {EXIT_BINARY_PATH, nthreads_buf, mem_buf, NULL};
 165                 int status;
 166
 167                 pid_t pid;
 168                 int bret = posix_spawn(&pid, args[0], NULL, NULL, args, NULL);
 169                 T_ASSERT_POSIX_ZERO(bret, "spawned process with pid %d (threads=%s mem=%s)", pid, nthreads_buf, mem_buf);
 170
 171                 bret = waitpid(pid, &status, 0);
 172                 T_QUIET; T_ASSERT_POSIX_SUCCESS(bret, "waited for process %d\n", pid);
 173
 174                 if (!WIFEXITED(status) || WEXITSTATUS(status) != 0) {
 175                         T_ASSERT_FAIL("child process failed to run");
 176                 }
 177
 178                 // Avoid saturating the CPU with new processes
 179                 usleep(1000);
 180
 181                 dispatch_async(spawn_queue, spawn_process);
 182         });
 183
 184         dispatch_async(spawn_queue, spawn_process);
 185
 186         dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT), dispatch_get_main_queue(), ^{
 187                 ktrace_end(session, 0);
 188         });
 189
 190         dispatch_main();
 191 }