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 cleanup(void) {
  62         free(begin_ts);
  63         dispatch_release(spawn_queue);
  64         dispatch_release(processing_queue);
  65         if (tracing_on) {
  66                 ktrace_end(session, 1);
  67         }
  68 }
  69
  70 static dt_stat_time_t
  71 create_stat(int proc_wired_mem, int nthreads)
  72 {
  73         dt_stat_time_t dst = dt_stat_time_create("time");
  74         T_ASSERT_NOTNULL(dst, "created time statistic");
  75
  76         dt_stat_set_variable((dt_stat_t)dst, "proc_threads", nthreads);
  77         dt_stat_set_variable((dt_stat_t)dst, "proc_wired_mem", proc_wired_mem);;
  78
  79         return dst;
  80 }
  81
  82 T_DECL(exit, "exit(2) time from syscall start to end", T_META_TIMEOUT(TEST_TIMEOUT)) {
  83         s = create_stat(test_cases[consumer_i].wired_mem, test_cases[consumer_i].threads);
  84
  85         begin_ts = malloc(sizeof(uint64_t) * PID_MAX);
  86         T_ASSERT_NOTNULL(begin_ts, "created pid array");
  87
  88         T_ATEND(cleanup);
  89
  90         session = ktrace_session_create();
  91         T_ASSERT_NOTNULL(session, "created a trace session");
  92
  93         spawn_queue = dispatch_queue_create("com.apple.perf_exit.spawn_queue", NULL);
  94         processing_queue = dispatch_queue_create("com.apple.perf_exit.processing_queue", NULL);
  95
  96         ktrace_set_completion_handler(session, ^{
  97                 T_ASSERT_EQ(consumer_i, TEST_CASES_COUNT, "ran all the test cases");
  98                 dispatch_sync(spawn_queue, ^(void) {
  99                         tracing_on = false;
 100                 });
 101                 ktrace_session_destroy(session);
 102                 T_END;
 103         });
 104
 105         ktrace_set_signal_handler(session);
 106         ktrace_set_execnames_enabled(session, KTRACE_FEATURE_ENABLED);
 107
 108         // We are only interested in the processes we launched and ourselves
 109         ktrace_filter_process(session, EXIT_BINARY);
 110         ktrace_filter_process(session, "perf_exit");
 111
 112         ktrace_events_single(session, NEXT_CASE_EVENTID, ^(__unused ktrace_event_t e) {
 113                 consumer_i++;
 114                 dt_stat_finalize(s);
 115                 if (consumer_i >= TEST_CASES_COUNT) {
 116                         ktrace_end(session, 1);
 117                 }
 118                 else {
 119                         s = create_stat(test_cases[consumer_i].wired_mem, test_cases[consumer_i].threads);
 120                 }
 121         });
 122
 123         ktrace_events_single(session, (BSDDBG_CODE(DBG_BSD_EXCP_SC, 1) | DBG_FUNC_START), ^(ktrace_event_t e) {
 124                 T_QUIET; T_ASSERT_LE(e->pid, PID_MAX, "pid %d is valid in start tracepoint", e->pid);
 125                 begin_ts[e->pid] = e->timestamp;
 126         });
 127
 128         ktrace_events_single(session, (BSDDBG_CODE(DBG_BSD_PROC, BSD_PROC_EXIT) | DBG_FUNC_END), ^(ktrace_event_t e) {
 129                 T_ASSERT_LE(e->pid, PID_MAX, "pid %d is valid in end tracepoint", e->pid);
 130
 131                 if (begin_ts[e->pid] == 0) {
 132                         return;
 133                 }
 134
 135                 T_QUIET; T_ASSERT_LE(begin_ts[e->pid], e->timestamp, "timestamps are monotonically increasing");
 136                 dt_stat_mach_time_add(s, e->timestamp - begin_ts[e->pid]);
 137
 138
 139                 if (dt_stat_stable(s) && producer_i == consumer_i) {
 140                         dispatch_sync(spawn_queue, ^(void) {
 141                                 producer_i++;
 142                                 T_ASSERT_POSIX_ZERO(kdebug_trace(NEXT_CASE_EVENTID, producer_i, 0, 0, 0), "kdebug_trace returns 0");
 143                         });
 144                 }
 145         });
 146
 147         int ret = ktrace_start(session, processing_queue);
 148         T_ASSERT_POSIX_ZERO(ret, "starting trace");
 149         tracing_on = true;
 150
 151         // Spawn processes continuously until the test is over
 152
 153         __block void (^spawn_process)(void) = Block_copy(^(void) {
 154                 char nthreads_buf[32], mem_buf[32];
 155
 156                 if (producer_i >= TEST_CASES_COUNT || !tracing_on) {
 157                         return;
 158                 }
 159
 160                 snprintf(nthreads_buf, 32, "%d", test_cases[producer_i].threads);
 161                 snprintf(mem_buf, 32, "%d", test_cases[producer_i].wired_mem);
 162
 163                 char *args[] = {EXIT_BINARY_PATH, nthreads_buf, mem_buf, NULL};
 164                 int status;
 165
 166                 pid_t pid;
 167                 int bret = posix_spawn(&pid, args[0], NULL, NULL, args, NULL);
 168                 T_ASSERT_POSIX_ZERO(bret, "spawned process with pid %d (threads=%s mem=%s)", pid, nthreads_buf, mem_buf);
 169
 170                 bret = waitpid(pid, &status, 0);
 171                 T_QUIET; T_ASSERT_POSIX_SUCCESS(bret, "waited for process %d\n", pid);
 172
 173                 if (!WIFEXITED(status) || WEXITSTATUS(status) != 0)
 174                         T_ASSERT_FAIL("child process failed to run");
 175
 176                 // Avoid saturating the CPU with new processes
 177                 usleep(1000);
 178
 179                 dispatch_async(spawn_queue, spawn_process);
 180         });
 181
 182         dispatch_async(spawn_queue, spawn_process);
 183
 184         dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT), dispatch_get_main_queue(), ^{
 185                 ktrace_end(session, 0);
 186         });
 187
 188         dispatch_main();
 189 }
 190