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