]>
Commit | Line | Data |
---|---|---|
5ba3f43e A |
1 | #ifdef T_NAMESPACE |
2 | #undef T_NAMESPACE | |
3 | #endif | |
4 | ||
39037602 A |
5 | #include <CoreSymbolication/CoreSymbolication.h> |
6 | #include <darwintest.h> | |
7 | #include <dispatch/dispatch.h> | |
8 | #include <kperf/kperf.h> | |
5ba3f43e A |
9 | #include <ktrace/session.h> |
10 | #include <System/sys/kdebug.h> | |
39037602 A |
11 | #include <pthread.h> |
12 | ||
13 | #include "kperf_helpers.h" | |
14 | ||
15 | #define PERF_STK_KHDR UINT32_C(0x25020014) | |
16 | #define PERF_STK_UHDR UINT32_C(0x25020018) | |
17 | #define PERF_STK_KDATA UINT32_C(0x2502000c) | |
18 | #define PERF_STK_UDATA UINT32_C(0x25020010) | |
19 | ||
5ba3f43e A |
20 | T_GLOBAL_META( |
21 | T_META_NAMESPACE("xnu.kperf"), | |
22 | T_META_CHECK_LEAKS(false)); | |
23 | ||
39037602 A |
24 | static void |
25 | expect_frame(const char **bt, unsigned int bt_len, CSSymbolRef symbol, | |
26 | unsigned long addr, unsigned int bt_idx, unsigned int max_frames) | |
27 | { | |
28 | const char *name; | |
29 | unsigned int frame_idx = max_frames - bt_idx - 1; | |
30 | ||
31 | if (!bt[frame_idx]) { | |
32 | T_LOG("frame %2u: skipping system frame", frame_idx); | |
33 | return; | |
34 | } | |
35 | ||
36 | if (CSIsNull(symbol)) { | |
37 | T_FAIL("invalid symbol for address %#lx at frame %d", addr, frame_idx); | |
38 | return; | |
39 | } | |
40 | ||
41 | if (frame_idx >= bt_len) { | |
42 | T_FAIL("unexpected frame '%s' (%#lx) at index %u", | |
43 | CSSymbolGetName(symbol), addr, frame_idx); | |
44 | return; | |
45 | } | |
46 | ||
47 | name = CSSymbolGetName(symbol); | |
48 | T_QUIET; T_ASSERT_NOTNULL(name, NULL); | |
49 | T_EXPECT_EQ_STR(name, bt[frame_idx], | |
50 | "frame %2u: saw '%s', expected '%s'", | |
51 | frame_idx, name, bt[frame_idx]); | |
52 | } | |
53 | ||
54 | /* | |
813fb2f6 A |
55 | * Expect to see either user or kernel stacks on thread with ID `tid` with a |
56 | * signature of `bt` of length `bt_len`. Updates `stacks_seen` when stack | |
57 | * is found. | |
58 | * | |
59 | * Can also allow stacks to be larger than the signature -- additional frames | |
60 | * near the current PC will be ignored. This allows stacks to potentially be | |
61 | * in the middle of a signalling system call (which signals that it is safe to | |
62 | * start sampling). | |
39037602 A |
63 | */ |
64 | static void | |
65 | expect_backtrace(ktrace_session_t s, uint64_t tid, unsigned int *stacks_seen, | |
813fb2f6 | 66 | bool kern, const char **bt, unsigned int bt_len, unsigned int allow_larger_by) |
39037602 A |
67 | { |
68 | CSSymbolicatorRef symb; | |
69 | uint32_t hdr_debugid; | |
70 | uint32_t data_debugid; | |
71 | __block unsigned int stacks = 0; | |
72 | __block unsigned int frames = 0; | |
73 | __block unsigned int hdr_frames = 0; | |
813fb2f6 | 74 | __block unsigned int allow_larger = allow_larger_by; |
39037602 A |
75 | |
76 | if (kern) { | |
77 | static CSSymbolicatorRef kern_symb; | |
78 | static dispatch_once_t kern_symb_once; | |
79 | ||
80 | hdr_debugid = PERF_STK_KHDR; | |
81 | data_debugid = PERF_STK_KDATA; | |
82 | ||
83 | dispatch_once(&kern_symb_once, ^(void) { | |
84 | kern_symb = CSSymbolicatorCreateWithMachKernel(); | |
85 | T_QUIET; T_ASSERT_FALSE(CSIsNull(kern_symb), NULL); | |
86 | }); | |
87 | symb = kern_symb; | |
88 | } else { | |
89 | static CSSymbolicatorRef user_symb; | |
90 | static dispatch_once_t user_symb_once; | |
91 | ||
92 | hdr_debugid = PERF_STK_UHDR; | |
93 | data_debugid = PERF_STK_UDATA; | |
94 | ||
95 | dispatch_once(&user_symb_once, ^(void) { | |
96 | user_symb = CSSymbolicatorCreateWithTask(mach_task_self()); | |
97 | T_QUIET; T_ASSERT_FALSE(CSIsNull(user_symb), NULL); | |
98 | T_QUIET; T_ASSERT_TRUE(CSSymbolicatorIsTaskValid(user_symb), NULL); | |
99 | }); | |
100 | symb = user_symb; | |
101 | } | |
102 | ||
103 | ktrace_events_single(s, hdr_debugid, ^(struct trace_point *tp) { | |
104 | if (tid != 0 && tid != tp->threadid) { | |
105 | return; | |
106 | } | |
107 | ||
813fb2f6 | 108 | T_LOG("found stack from thread %#lx", tp->threadid); |
39037602 A |
109 | stacks++; |
110 | if (!(tp->arg1 & 1)) { | |
111 | T_FAIL("invalid %s stack on thread %#lx", kern ? "kernel" : "user", | |
112 | tp->threadid); | |
113 | return; | |
114 | } | |
115 | ||
116 | hdr_frames = (unsigned int)tp->arg2; | |
117 | /* ignore extra link register or value pointed to by stack pointer */ | |
118 | hdr_frames -= 1; | |
119 | ||
813fb2f6 | 120 | T_QUIET; T_EXPECT_GE(hdr_frames, bt_len, |
39037602 | 121 | "number of frames in header"); |
813fb2f6 A |
122 | T_QUIET; T_EXPECT_LE(hdr_frames, bt_len + allow_larger, |
123 | "number of frames in header"); | |
124 | if (hdr_frames > bt_len && allow_larger > 0) { | |
125 | allow_larger = hdr_frames - bt_len; | |
126 | hdr_frames = bt_len; | |
127 | } | |
39037602 A |
128 | |
129 | T_LOG("%s stack seen", kern ? "kernel" : "user"); | |
130 | frames = 0; | |
131 | }); | |
132 | ||
133 | ktrace_events_single(s, data_debugid, ^(struct trace_point *tp) { | |
134 | if (tid != 0 && tid != tp->threadid) { | |
135 | return; | |
136 | } | |
137 | ||
813fb2f6 A |
138 | int i = 0; |
139 | ||
140 | if (frames == 0 && hdr_frames > bt_len) { | |
141 | /* skip frames near the PC */ | |
142 | i = (int)allow_larger; | |
143 | allow_larger -= 4; | |
144 | } | |
145 | ||
146 | for (; i < 4 && frames < hdr_frames; i++, frames++) { | |
39037602 A |
147 | unsigned long addr = (&tp->arg1)[i]; |
148 | CSSymbolRef symbol = CSSymbolicatorGetSymbolWithAddressAtTime( | |
149 | symb, addr, kCSNow); | |
150 | ||
151 | expect_frame(bt, bt_len, symbol, addr, frames, hdr_frames); | |
152 | } | |
153 | ||
154 | /* saw the end of the user stack */ | |
155 | if (hdr_frames == frames) { | |
156 | *stacks_seen += 1; | |
157 | if (!kern) { | |
158 | ktrace_end(s, 1); | |
159 | } | |
160 | } | |
161 | }); | |
162 | } | |
163 | ||
164 | #define TRIGGERING_DEBUGID (0xfeff0f00) | |
165 | ||
166 | /* | |
167 | * These functions must return an int to avoid the function prologue being | |
168 | * hoisted out of the path to the spin (breaking being able to get a good | |
169 | * backtrace). | |
170 | */ | |
171 | static int __attribute__((noinline,not_tail_called)) | |
813fb2f6 | 172 | recurse_a(dispatch_semaphore_t spinning, unsigned int frames); |
39037602 | 173 | static int __attribute__((noinline,not_tail_called)) |
813fb2f6 | 174 | recurse_b(dispatch_semaphore_t spinning, unsigned int frames); |
39037602 A |
175 | |
176 | static int __attribute__((noinline,not_tail_called)) | |
813fb2f6 | 177 | recurse_a(dispatch_semaphore_t spinning, unsigned int frames) |
39037602 A |
178 | { |
179 | if (frames == 0) { | |
813fb2f6 A |
180 | if (spinning) { |
181 | dispatch_semaphore_signal(spinning); | |
39037602 A |
182 | for (;;); |
183 | } else { | |
184 | kdebug_trace(TRIGGERING_DEBUGID, 0, 0, 0, 0); | |
185 | return 0; | |
186 | } | |
187 | } | |
188 | ||
813fb2f6 | 189 | return recurse_b(spinning, frames - 1) + 1; |
39037602 A |
190 | } |
191 | ||
192 | static int __attribute__((noinline,not_tail_called)) | |
813fb2f6 | 193 | recurse_b(dispatch_semaphore_t spinning, unsigned int frames) |
39037602 A |
194 | { |
195 | if (frames == 0) { | |
813fb2f6 A |
196 | if (spinning) { |
197 | dispatch_semaphore_signal(spinning); | |
39037602 A |
198 | for (;;); |
199 | } else { | |
200 | kdebug_trace(TRIGGERING_DEBUGID, 0, 0, 0, 0); | |
201 | return 0; | |
202 | } | |
203 | } | |
204 | ||
813fb2f6 | 205 | return recurse_a(spinning, frames - 1) + 1; |
39037602 A |
206 | } |
207 | ||
208 | #define USER_FRAMES (12) | |
209 | ||
210 | #if defined(__x86_64__) | |
211 | #define RECURSE_START_OFFSET (4) | |
212 | #else /* defined(__x86_64__) */ | |
213 | #define RECURSE_START_OFFSET (3) | |
214 | #endif /* defined(__x86_64__) */ | |
215 | ||
216 | static const char *user_bt[USER_FRAMES] = { | |
217 | #if defined(__x86_64__) | |
218 | NULL, | |
219 | #endif /* defined(__x86_64__) */ | |
220 | NULL, NULL, | |
221 | "backtrace_thread", | |
222 | "recurse_a", "recurse_b", "recurse_a", "recurse_b", | |
223 | "recurse_a", "recurse_b", "recurse_a", | |
224 | #if !defined(__x86_64__) | |
225 | "recurse_b", | |
226 | #endif /* !defined(__x86_64__) */ | |
227 | NULL | |
228 | }; | |
229 | ||
5ba3f43e A |
230 | #if defined(__arm__) |
231 | ||
232 | #define KERNEL_FRAMES (2) | |
233 | static const char *kernel_bt[KERNEL_FRAMES] = { | |
234 | "unix_syscall", "kdebug_trace64" | |
235 | }; | |
236 | ||
237 | #elif defined(__arm64__) | |
238 | ||
239 | #define KERNEL_FRAMES (4) | |
240 | static const char *kernel_bt[KERNEL_FRAMES] = { | |
241 | "fleh_synchronous", "sleh_synchronous", "unix_syscall", "kdebug_trace64" | |
242 | }; | |
243 | ||
244 | #elif defined(__x86_64__) | |
39037602 A |
245 | |
246 | #define KERNEL_FRAMES (2) | |
247 | static const char *kernel_bt[KERNEL_FRAMES] = { | |
248 | "unix_syscall64", "kdebug_trace64" | |
249 | }; | |
250 | ||
251 | #else | |
252 | #error "architecture unsupported" | |
253 | #endif /* defined(__arm__) */ | |
254 | ||
813fb2f6 A |
255 | static dispatch_once_t backtrace_once; |
256 | static dispatch_semaphore_t backtrace_started; | |
257 | static dispatch_semaphore_t backtrace_go; | |
39037602 | 258 | |
813fb2f6 A |
259 | /* |
260 | * Another thread to run with a known backtrace. | |
261 | * | |
262 | * Take a semaphore that will be signalled when the thread is spinning at the | |
263 | * correct frame. If the semaphore is NULL, don't spin and instead make a | |
264 | * kdebug_trace system call, which can trigger a deterministic backtrace itself. | |
265 | */ | |
39037602 A |
266 | static void * |
267 | backtrace_thread(void *arg) | |
268 | { | |
813fb2f6 | 269 | dispatch_semaphore_t notify_spinning; |
39037602 A |
270 | unsigned int calls; |
271 | ||
813fb2f6 A |
272 | notify_spinning = (dispatch_semaphore_t)arg; |
273 | ||
274 | dispatch_semaphore_signal(backtrace_started); | |
275 | if (!notify_spinning) { | |
276 | dispatch_semaphore_wait(backtrace_go, DISPATCH_TIME_FOREVER); | |
277 | } | |
39037602 A |
278 | |
279 | /* | |
280 | * backtrace_thread, recurse_a, recurse_b, ...[, __kdebug_trace64] | |
281 | * | |
282 | * Always make one less call for this frame (backtrace_thread). | |
283 | */ | |
284 | calls = USER_FRAMES - RECURSE_START_OFFSET - 1 /* backtrace_thread */; | |
813fb2f6 | 285 | if (notify_spinning) { |
39037602 A |
286 | /* |
287 | * Spinning doesn't end up calling __kdebug_trace64. | |
288 | */ | |
289 | calls -= 1; | |
290 | } | |
291 | ||
292 | T_LOG("backtrace thread calling into %d frames (already at %d frames)", | |
293 | calls, RECURSE_START_OFFSET); | |
813fb2f6 | 294 | (void)recurse_a(notify_spinning, calls); |
39037602 A |
295 | return NULL; |
296 | } | |
297 | ||
298 | static uint64_t | |
813fb2f6 | 299 | create_backtrace_thread(dispatch_semaphore_t notify_spinning) |
39037602 | 300 | { |
813fb2f6 | 301 | pthread_t thread = NULL; |
39037602 A |
302 | uint64_t tid; |
303 | ||
813fb2f6 A |
304 | dispatch_once(&backtrace_once, ^{ |
305 | backtrace_started = dispatch_semaphore_create(0); | |
306 | T_QUIET; T_ASSERT_NOTNULL(backtrace_started, NULL); | |
307 | ||
308 | if (!notify_spinning) { | |
309 | backtrace_go = dispatch_semaphore_create(0); | |
310 | T_QUIET; T_ASSERT_NOTNULL(backtrace_go, NULL); | |
311 | } | |
39037602 A |
312 | }); |
313 | ||
314 | T_QUIET; T_ASSERT_POSIX_ZERO(pthread_create(&thread, NULL, backtrace_thread, | |
813fb2f6 A |
315 | (void *)notify_spinning), NULL); |
316 | T_QUIET; T_ASSERT_NOTNULL(thread, "backtrace thread created"); | |
317 | dispatch_semaphore_wait(backtrace_started, DISPATCH_TIME_FOREVER); | |
318 | ||
39037602 | 319 | T_QUIET; T_ASSERT_POSIX_ZERO(pthread_threadid_np(thread, &tid), NULL); |
813fb2f6 A |
320 | T_QUIET; T_ASSERT_NE(tid, UINT64_C(0), |
321 | "backtrace thread created does not have ID 0"); | |
322 | ||
323 | T_LOG("starting thread with ID 0x%" PRIx64, tid); | |
39037602 A |
324 | |
325 | return tid; | |
326 | } | |
327 | ||
328 | static void | |
329 | start_backtrace_thread(void) | |
330 | { | |
813fb2f6 | 331 | T_QUIET; T_ASSERT_NOTNULL(backtrace_go, |
39037602 | 332 | "thread to backtrace created before starting it"); |
813fb2f6 | 333 | dispatch_semaphore_signal(backtrace_go); |
39037602 A |
334 | } |
335 | ||
5ba3f43e A |
336 | #if TARGET_OS_WATCH |
337 | #define TEST_TIMEOUT_NS (30 * NSEC_PER_SEC) | |
338 | #else /* TARGET_OS_WATCH */ | |
39037602 | 339 | #define TEST_TIMEOUT_NS (5 * NSEC_PER_SEC) |
5ba3f43e | 340 | #endif /* !TARGET_OS_WATCH */ |
39037602 | 341 | |
5ba3f43e | 342 | T_DECL(backtraces_kdebug_trigger, |
39037602 | 343 | "test that backtraces from kdebug trigger are correct", |
813fb2f6 | 344 | T_META_ASROOT(true)) |
39037602 A |
345 | { |
346 | static unsigned int stacks_seen = 0; | |
347 | ktrace_session_t s; | |
348 | kperf_kdebug_filter_t filter; | |
349 | uint64_t tid; | |
350 | ||
351 | s = ktrace_session_create(); | |
352 | T_ASSERT_NOTNULL(s, "ktrace session was created"); | |
353 | ||
354 | T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL); | |
355 | ||
813fb2f6 A |
356 | tid = create_backtrace_thread(NULL); |
357 | expect_backtrace(s, tid, &stacks_seen, false, user_bt, USER_FRAMES, 0); | |
358 | expect_backtrace(s, tid, &stacks_seen, true, kernel_bt, KERNEL_FRAMES, 0); | |
39037602 A |
359 | |
360 | /* | |
361 | * The triggering event must be traced (and thus registered with libktrace) | |
362 | * to get backtraces. | |
363 | */ | |
364 | ktrace_events_single(s, TRIGGERING_DEBUGID, | |
365 | ^(__unused struct trace_point *tp){ }); | |
366 | ||
367 | ktrace_set_completion_handler(s, ^(void) { | |
368 | T_EXPECT_GE(stacks_seen, 2U, "saw both kernel and user stacks"); | |
369 | ktrace_session_destroy(s); | |
370 | kperf_reset(); | |
371 | T_END; | |
372 | }); | |
373 | ||
374 | filter = kperf_kdebug_filter_create(); | |
375 | T_ASSERT_NOTNULL(filter, "kperf kdebug filter was created"); | |
376 | ||
377 | T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_filter_add_debugid(filter, | |
378 | TRIGGERING_DEBUGID), NULL); | |
379 | T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_filter_set(filter), NULL); | |
380 | (void)kperf_action_count_set(1); | |
381 | T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_action_samplers_set(1, | |
382 | KPERF_SAMPLER_USTACK | KPERF_SAMPLER_KSTACK), NULL); | |
383 | T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_action_set(1), NULL); | |
384 | kperf_kdebug_filter_destroy(filter); | |
385 | ||
386 | T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL); | |
387 | ||
388 | T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()), NULL); | |
389 | ||
390 | start_backtrace_thread(); | |
391 | ||
392 | dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS), | |
393 | dispatch_get_main_queue(), ^(void) | |
394 | { | |
813fb2f6 | 395 | T_LOG("ending test after timeout"); |
39037602 A |
396 | ktrace_end(s, 0); |
397 | }); | |
398 | ||
399 | dispatch_main(); | |
400 | } | |
401 | ||
5ba3f43e | 402 | T_DECL(backtraces_user_timer, |
39037602 | 403 | "test that user backtraces on a timer are correct", |
813fb2f6 | 404 | T_META_ASROOT(true)) |
39037602 A |
405 | { |
406 | static unsigned int stacks_seen = 0; | |
407 | ktrace_session_t s; | |
408 | uint64_t tid; | |
813fb2f6 | 409 | dispatch_semaphore_t wait_for_spinning = dispatch_semaphore_create(0); |
39037602 A |
410 | |
411 | s = ktrace_session_create(); | |
412 | T_QUIET; T_ASSERT_NOTNULL(s, "ktrace_session_create"); | |
413 | ||
414 | ktrace_filter_pid(s, getpid()); | |
415 | ||
416 | configure_kperf_stacks_timer(getpid(), 10); | |
417 | ||
813fb2f6 A |
418 | tid = create_backtrace_thread(wait_for_spinning); |
419 | /* potentially calling dispatch function and system call */ | |
420 | expect_backtrace(s, tid, &stacks_seen, false, user_bt, USER_FRAMES - 1, 2); | |
39037602 A |
421 | |
422 | ktrace_set_completion_handler(s, ^(void) { | |
423 | T_EXPECT_GE(stacks_seen, 1U, "saw at least one stack"); | |
424 | ktrace_session_destroy(s); | |
425 | kperf_reset(); | |
426 | T_END; | |
427 | }); | |
428 | ||
429 | T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL); | |
430 | ||
813fb2f6 A |
431 | /* wait until the thread that will be backtraced is spinning */ |
432 | dispatch_semaphore_wait(wait_for_spinning, DISPATCH_TIME_FOREVER); | |
39037602 | 433 | |
813fb2f6 | 434 | T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()), NULL); |
39037602 A |
435 | |
436 | dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS), | |
437 | dispatch_get_main_queue(), ^(void) | |
438 | { | |
813fb2f6 | 439 | T_LOG("ending test after timeout"); |
39037602 A |
440 | ktrace_end(s, 0); |
441 | }); | |
442 | ||
443 | dispatch_main(); | |
444 | } | |
445 | ||
446 | /* TODO test kernel stacks in all modes */ | |
813fb2f6 | 447 | /* TODO legacy PET mode backtracing */ |
39037602 A |
448 | /* TODO test deep stacks, further than 128 frames, make sure they are truncated */ |
449 | /* TODO test constrained stacks */ |