[apple/xnu.git] / tests / kperf_backtracing.c

#ifdef T_NAMESPACE
#undef T_NAMESPACE
#endif

#include <CoreSymbolication/CoreSymbolication.h>
#include <darwintest.h>
#include <dispatch/dispatch.h>
#include <kperf/kperf.h>
#include <ktrace/session.h>
#include <ktrace/private.h>
#include <System/sys/kdebug.h>
#include <pthread.h>

#include "kperf_helpers.h"
#include "ktrace_helpers.h"

#define PERF_STK_KHDR  UINT32_C(0x25020014)
#define PERF_STK_UHDR  UINT32_C(0x25020018)
#define PERF_STK_KDATA UINT32_C(0x2502000c)
#define PERF_STK_UDATA UINT32_C(0x25020010)

#define CALLSTACK_VALID 0x1
#define CALLSTACK_TRUNCATED 0x10

T_GLOBAL_META(
	T_META_NAMESPACE("xnu.ktrace"),
	T_META_CHECK_LEAKS(false));

static void
expect_frame(const char **bt, unsigned int bt_len, CSSymbolRef symbol,
    unsigned long addr, unsigned int bt_idx, unsigned int max_frames)
{
	const char *name;
	unsigned int frame_idx = max_frames - bt_idx - 1;

	if (!bt[frame_idx]) {
		T_LOG("frame %2u: skipping system frame '%s'", frame_idx,
		    CSSymbolGetName(symbol));
		return;
	}

	if (CSIsNull(symbol)) {
		T_FAIL("invalid symbol for address %#lx at frame %d", addr,
		    frame_idx);
		return;
	}

	if (frame_idx >= bt_len) {
		T_FAIL("unexpected frame '%s' (%#lx) at index %u",
		    CSSymbolGetName(symbol), addr, frame_idx);
		return;
	}

	name = CSSymbolGetName(symbol);
	T_QUIET; T_ASSERT_NOTNULL(name, NULL);
	T_EXPECT_EQ_STR(name, bt[frame_idx],
	    "frame %2u: saw '%s', expected '%s'",
	    frame_idx, name, bt[frame_idx]);
}

/*
 * Expect to see either user or kernel stacks on thread with ID `tid` with a
 * signature of `bt` of length `bt_len`.  Updates `stacks_seen` when stack
 * is found.
 *
 * Can also allow stacks to be larger than the signature -- additional frames
 * near the current PC will be ignored.  This allows stacks to potentially be
 * in the middle of a signalling system call (which signals that it is safe to
 * start sampling).
 */
static void
expect_backtrace(ktrace_session_t s, uint64_t tid, unsigned int *stacks_seen,
    bool kern, const char **bt, unsigned int bt_len, unsigned int allow_larger_by)
{
	CSSymbolicatorRef symb;
	uint32_t hdr_debugid;
	uint32_t data_debugid;
	__block unsigned int stacks = 0;
	__block unsigned int frames = 0;
	__block unsigned int hdr_frames = 0;
	__block unsigned int allow_larger = allow_larger_by;

	if (kern) {
		static CSSymbolicatorRef kern_symb;
		static dispatch_once_t kern_symb_once;

		hdr_debugid = PERF_STK_KHDR;
		data_debugid = PERF_STK_KDATA;

		dispatch_once(&kern_symb_once, ^(void) {
			kern_symb = CSSymbolicatorCreateWithMachKernel();
			T_QUIET; T_ASSERT_FALSE(CSIsNull(kern_symb), NULL);
		});
		symb = kern_symb;
	} else {
		static CSSymbolicatorRef user_symb;
		static dispatch_once_t user_symb_once;

		hdr_debugid = PERF_STK_UHDR;
		data_debugid = PERF_STK_UDATA;

		dispatch_once(&user_symb_once, ^(void) {
			user_symb = CSSymbolicatorCreateWithTask(mach_task_self());
			T_QUIET; T_ASSERT_FALSE(CSIsNull(user_symb), NULL);
			T_QUIET; T_ASSERT_TRUE(CSSymbolicatorIsTaskValid(user_symb), NULL);
		});
		symb = user_symb;
	}

	ktrace_events_single(s, hdr_debugid, ^(struct trace_point *tp) {
		if (tid != 0 && tid != tp->threadid) {
		        return;
		}

		T_LOG("found stack from thread %#" PRIx64, tp->threadid);
		stacks++;
		if (!(tp->arg1 & 1)) {
		        T_FAIL("invalid %s stack on thread %#" PRIx64,
		        kern ? "kernel" : "user", tp->threadid);
		        return;
		}

		hdr_frames = (unsigned int)tp->arg2;
		/* ignore extra link register or value pointed to by stack pointer */
		hdr_frames -= 1;

		T_QUIET; T_EXPECT_GE(hdr_frames, bt_len,
		"number of frames in header");
		T_QUIET; T_EXPECT_LE(hdr_frames, bt_len + allow_larger,
		"number of frames in header");
		if (hdr_frames > bt_len && allow_larger > 0) {
		        allow_larger = hdr_frames - bt_len;
		        hdr_frames = bt_len;
		}

		T_LOG("%s stack seen", kern ? "kernel" : "user");
		frames = 0;
	});

	ktrace_events_single(s, data_debugid, ^(struct trace_point *tp) {
		if (tid != 0 && tid != tp->threadid) {
		        return;
		}

		int i = 0;

		if (frames == 0 && hdr_frames > bt_len) {
		        /* skip frames near the PC */
		        i = (int)allow_larger;
		        allow_larger -= 4;
		}

		for (; i < 4 && frames < hdr_frames; i++, frames++) {
		        unsigned long addr = (&tp->arg1)[i];
		        CSSymbolRef symbol = CSSymbolicatorGetSymbolWithAddressAtTime(
				symb, addr, kCSNow);

		        expect_frame(bt, bt_len, symbol, addr, frames, hdr_frames);
		}

		/* saw the end of the user stack */
		if (hdr_frames == frames) {
		        *stacks_seen += 1;
		        if (!kern) {
		                ktrace_end(s, 1);
			}
		}
	});
}

#define TRIGGERING_DEBUGID (0xfeff0f00)

/*
 * These functions must return an int to avoid the function prologue being
 * hoisted out of the path to the spin (breaking being able to get a good
 * backtrace).
 */
static int __attribute__((noinline, not_tail_called))
recurse_a(dispatch_semaphore_t spinning, unsigned int frames);
static int __attribute__((noinline, not_tail_called))
recurse_b(dispatch_semaphore_t spinning, unsigned int frames);

static int __attribute__((noinline, not_tail_called))
recurse_a(dispatch_semaphore_t spinning, unsigned int frames)
{
	if (frames == 0) {
		if (spinning) {
			dispatch_semaphore_signal(spinning);
			for (;;) {
				;
			}
		} else {
			kdebug_trace(TRIGGERING_DEBUGID, 0, 0, 0, 0);
			return 0;
		}
	}

	return recurse_b(spinning, frames - 1) + 1;
}

static int __attribute__((noinline, not_tail_called))
recurse_b(dispatch_semaphore_t spinning, unsigned int frames)
{
	if (frames == 0) {
		if (spinning) {
			dispatch_semaphore_signal(spinning);
			for (;;) {
				;
			}
		} else {
			kdebug_trace(TRIGGERING_DEBUGID, 0, 0, 0, 0);
			return 0;
		}
	}

	return recurse_a(spinning, frames - 1) + 1;
}

#define USER_FRAMES (12)

#if defined(__x86_64__)

#define RECURSE_START_OFFSET (3)

#else /* defined(__x86_64__) */

#define RECURSE_START_OFFSET (2)

#endif /* !defined(__x86_64__) */

static const char *user_bt[USER_FRAMES] = {
#if defined(__x86_64__)
	/*
	 * x86_64 has an extra "thread_start" frame here.
	 */
	NULL,
#endif /* defined(__x86_64__) */
	NULL,
	"backtrace_thread",
	"recurse_a", "recurse_b", "recurse_a", "recurse_b",
	"recurse_a", "recurse_b", "recurse_a", "recurse_b",
#if !defined(__x86_64__)
	/*
	 * Pick up the slack to make the number of frames constant.
	 */
	"recurse_a",
#endif /* !defined(__x86_64__) */
	NULL,
};

#if defined(__arm__)

#define KERNEL_FRAMES (2)
static const char *kernel_bt[KERNEL_FRAMES] = {
	"unix_syscall", "kdebug_trace64"
};

#elif defined(__arm64__)

#define KERNEL_FRAMES (4)
static const char *kernel_bt[KERNEL_FRAMES] = {
	"fleh_synchronous", "sleh_synchronous", "unix_syscall", "kdebug_trace64"
};

#elif defined(__x86_64__)

#define KERNEL_FRAMES (2)
static const char *kernel_bt[KERNEL_FRAMES] = {
	"unix_syscall64", "kdebug_trace64"
};

#else
#error "architecture unsupported"
#endif /* defined(__arm__) */

static dispatch_once_t backtrace_once;
static dispatch_semaphore_t backtrace_started;
static dispatch_semaphore_t backtrace_go;

/*
 * Another thread to run with a known backtrace.
 *
 * Take a semaphore that will be signalled when the thread is spinning at the
 * correct frame.  If the semaphore is NULL, don't spin and instead make a
 * kdebug_trace system call, which can trigger a deterministic backtrace itself.
 */
static void *
backtrace_thread(void *arg)
{
	dispatch_semaphore_t notify_spinning;
	unsigned int calls;

	notify_spinning = (dispatch_semaphore_t)arg;

	dispatch_semaphore_signal(backtrace_started);
	if (!notify_spinning) {
		dispatch_semaphore_wait(backtrace_go, DISPATCH_TIME_FOREVER);
	}

	/*
	 * backtrace_thread, recurse_a, recurse_b, ...[, __kdebug_trace64]
	 *
	 * Always make one less call for this frame (backtrace_thread).
	 */
	calls = USER_FRAMES - RECURSE_START_OFFSET - 1 /* backtrace_thread */;
	if (notify_spinning) {
		/*
		 * Spinning doesn't end up calling __kdebug_trace64.
		 */
		calls -= 1;
	}

	T_LOG("backtrace thread calling into %d frames (already at %d frames)",
	    calls, RECURSE_START_OFFSET);
	(void)recurse_a(notify_spinning, calls);
	return NULL;
}

static uint64_t
create_backtrace_thread(void *(*thread_fn)(void *),
    dispatch_semaphore_t notify_spinning)
{
	pthread_t thread = NULL;
	uint64_t tid;

	dispatch_once(&backtrace_once, ^{
		backtrace_started = dispatch_semaphore_create(0);
		T_QUIET; T_ASSERT_NOTNULL(backtrace_started, NULL);

		if (!notify_spinning) {
		        backtrace_go = dispatch_semaphore_create(0);
		        T_QUIET; T_ASSERT_NOTNULL(backtrace_go, NULL);
		}
	});

	T_QUIET; T_ASSERT_POSIX_ZERO(pthread_create(&thread, NULL, thread_fn,
	    (void *)notify_spinning), NULL);
	T_QUIET; T_ASSERT_NOTNULL(thread, "backtrace thread created");
	dispatch_semaphore_wait(backtrace_started, DISPATCH_TIME_FOREVER);

	T_QUIET; T_ASSERT_POSIX_ZERO(pthread_threadid_np(thread, &tid), NULL);
	T_QUIET; T_ASSERT_NE(tid, UINT64_C(0),
	    "backtrace thread created does not have ID 0");

	T_LOG("starting thread with ID 0x%" PRIx64, tid);

	return tid;
}

static void
start_backtrace_thread(void)
{
	T_QUIET; T_ASSERT_NOTNULL(backtrace_go,
	    "thread to backtrace created before starting it");
	dispatch_semaphore_signal(backtrace_go);
}

#if TARGET_OS_WATCH
#define TEST_TIMEOUT_NS (30 * NSEC_PER_SEC)
#else /* TARGET_OS_WATCH */
#define TEST_TIMEOUT_NS (5 * NSEC_PER_SEC)
#endif /* !TARGET_OS_WATCH */

T_DECL(kdebug_trigger,
    "test that backtraces from kdebug trigger are correct",
    T_META_ASROOT(true))
{
	static unsigned int stacks_seen = 0;
	ktrace_session_t s;
	kperf_kdebug_filter_t filter;
	uint64_t tid;

	start_controlling_ktrace();

	s = ktrace_session_create();
	T_ASSERT_NOTNULL(s, "ktrace session was created");

	ktrace_set_collection_interval(s, 100);

	T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL);

	tid = create_backtrace_thread(backtrace_thread, NULL);
	expect_backtrace(s, tid, &stacks_seen, false, user_bt, USER_FRAMES, 0);
	expect_backtrace(s, tid, &stacks_seen, true, kernel_bt, KERNEL_FRAMES, 0);

	/*
	 * The triggering event must be traced (and thus registered with libktrace)
	 * to get backtraces.
	 */
	ktrace_events_single(s, TRIGGERING_DEBUGID,
	    ^(__unused struct trace_point *tp){ });

	ktrace_set_completion_handler(s, ^(void) {
		T_EXPECT_GE(stacks_seen, 2U, "saw both kernel and user stacks");
		ktrace_session_destroy(s);
		kperf_reset();
		T_END;
	});

	filter = kperf_kdebug_filter_create();
	T_ASSERT_NOTNULL(filter, "kperf kdebug filter was created");

	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_filter_add_debugid(filter,
	    TRIGGERING_DEBUGID), NULL);
	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_filter_set(filter), NULL);
	(void)kperf_action_count_set(1);
	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_action_samplers_set(1,
	    KPERF_SAMPLER_USTACK | KPERF_SAMPLER_KSTACK), NULL);
	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_action_set(1), NULL);
	kperf_kdebug_filter_destroy(filter);

	T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);

	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()), NULL);

	start_backtrace_thread();

	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
	    dispatch_get_main_queue(), ^(void)
	{
		T_LOG("ending test after timeout");
		ktrace_end(s, 0);
	});

	dispatch_main();
}

T_DECL(user_timer,
    "test that user backtraces on a timer are correct",
    T_META_ASROOT(true))
{
	static unsigned int stacks_seen = 0;
	ktrace_session_t s;
	uint64_t tid;
	dispatch_semaphore_t wait_for_spinning = dispatch_semaphore_create(0);

	start_controlling_ktrace();

	s = ktrace_session_create();
	T_QUIET; T_ASSERT_NOTNULL(s, "ktrace_session_create");

	ktrace_set_collection_interval(s, 100);

	ktrace_filter_pid(s, getpid());

	configure_kperf_stacks_timer(getpid(), 10);

	tid = create_backtrace_thread(backtrace_thread, wait_for_spinning);
	/* potentially calling dispatch function and system call */
	expect_backtrace(s, tid, &stacks_seen, false, user_bt, USER_FRAMES - 1, 2);

	ktrace_set_completion_handler(s, ^(void) {
		T_EXPECT_GE(stacks_seen, 1U, "saw at least one stack");
		ktrace_session_destroy(s);
		kperf_reset();
		T_END;
	});

	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);

	/* wait until the thread that will be backtraced is spinning */
	dispatch_semaphore_wait(wait_for_spinning, DISPATCH_TIME_FOREVER);

	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()), NULL);

	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
	    dispatch_get_main_queue(), ^(void)
	{
		T_LOG("ending test after timeout");
		ktrace_end(s, 0);
	});

	dispatch_main();
}

static volatile bool spin = true;

__attribute__((noinline, not_tail_called))
static void
recurse_spin(dispatch_semaphore_t notify_sema, int depth)
{
	if (depth > 0) {
		recurse_spin(notify_sema, depth - 1);
	} else {
		dispatch_semaphore_signal(notify_sema);
		while (spin);
	}
}

static void *
spin_thread(void *arg)
{
	dispatch_semaphore_t notify_sema = arg;
	dispatch_semaphore_signal(backtrace_started);
	recurse_spin(notify_sema, 257);
	return NULL;
}

T_DECL(truncated_user_stacks, "ensure stacks are marked as truncated")
{
	start_controlling_ktrace();

	ktrace_session_t s = ktrace_session_create();
	T_ASSERT_NOTNULL(s, "ktrace session was created");

	ktrace_set_collection_interval(s, 100);

	T_QUIET;
	T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL);

	configure_kperf_stacks_timer(getpid(), 10);

	__block bool saw_stack = false;
	ktrace_set_completion_handler(s, ^{
	    T_EXPECT_TRUE(saw_stack, "saw the user stack");
	    T_END;
	});

	dispatch_semaphore_t notify_sema = dispatch_semaphore_create(0);
	uint64_t tid = create_backtrace_thread(spin_thread, notify_sema);

	ktrace_events_single(s, PERF_STK_UHDR, ^(struct trace_point *tp) {
		if (tp->threadid != tid) {
			return;
		}
		T_LOG("found %llu frame stack", tp->arg2);
		T_EXPECT_BITS_SET(tp->arg1, CALLSTACK_VALID,
		    "found valid callstack");
		T_EXPECT_BITS_SET(tp->arg1, CALLSTACK_TRUNCATED,
		    "found truncated callstack");
		saw_stack = true;
		ktrace_end(s, 1);
	});

	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);

	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()),
	    "start tracing");

	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
	    dispatch_get_main_queue(), ^(void)
	{
		T_LOG("ending test after timeout");
		ktrace_end(s, 0);
	});

	dispatch_main();
}

T_DECL(max_user_stacks, "ensure stacks up to 256 frames can be captured")
{
	start_controlling_ktrace();

	ktrace_session_t s = ktrace_session_create();
	T_ASSERT_NOTNULL(s, "ktrace session was created");

	ktrace_set_collection_interval(s, 100);

	T_QUIET;
	T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL);

	configure_kperf_stacks_timer(getpid(), 10);

	__block bool saw_stack = false;
	__block bool saw_stack_data = false;
	__block uint64_t nevents = 0;
	ktrace_set_completion_handler(s, ^{
	    T_EXPECT_TRUE(saw_stack, "saw the user stack");
	    T_LOG("saw %" PRIu64 " stack data events", nevents);
	    T_EXPECT_TRUE(saw_stack_data, "saw all frames of the user stack");
	    T_END;
	});

	dispatch_semaphore_t notify_sema = dispatch_semaphore_create(0);
	uint64_t tid = create_backtrace_thread(spin_thread, notify_sema);

	ktrace_events_single(s, PERF_STK_UHDR, ^(struct trace_point *tp) {
		if (tp->threadid != tid) {
			return;
		}
		T_LOG("found %llu frame stack", tp->arg2);
		T_EXPECT_BITS_SET(tp->arg1, CALLSTACK_VALID,
		    "found valid callstack");
		T_EXPECT_EQ(tp->arg2, UINT64_C(256),
		    "found the correct number of frames");
		saw_stack = true;
	});

	ktrace_events_single(s, PERF_STK_UDATA, ^(struct trace_point *tp) {
		if (tp->threadid != tid && !saw_stack) {
			return;
		}
		nevents++;
		if (nevents == 256 / 4) {
			ktrace_end(s, 1);
		}
		saw_stack_data = true;
	});

	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);

	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()),
	    "start tracing");

	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
	    dispatch_get_main_queue(), ^(void)
	{
		T_LOG("ending test after timeout");
		ktrace_end(s, 0);
	});

	dispatch_main();
}

/* TODO test kernel stacks in all modes */
/* TODO legacy PET mode backtracing */
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	9	#include <ktrace/session.h>
cb323159	10	#include <ktrace/private.h>
5ba3f43e	11	#include <System/sys/kdebug.h>
39037602 A	12	#include <pthread.h>
	13
	14	#include "kperf_helpers.h"
cb323159	15	#include "ktrace_helpers.h"
39037602 A	16
	17	#define PERF_STK_KHDR UINT32_C(0x25020014)
	18	#define PERF_STK_UHDR UINT32_C(0x25020018)
	19	#define PERF_STK_KDATA UINT32_C(0x2502000c)
	20	#define PERF_STK_UDATA UINT32_C(0x25020010)
	21
cb323159 A	22	#define CALLSTACK_VALID 0x1
	23	#define CALLSTACK_TRUNCATED 0x10
	24
5ba3f43e	25	T_GLOBAL_META(
cb323159	26	T_META_NAMESPACE("xnu.ktrace"),
0a7de745	27	T_META_CHECK_LEAKS(false));
5ba3f43e	28
39037602 A	29	static void
	30	expect_frame(const char **bt, unsigned int bt_len, CSSymbolRef symbol,
	31	unsigned long addr, unsigned int bt_idx, unsigned int max_frames)
	32	{
0a7de745 A	33	const char *name;
	34	unsigned int frame_idx = max_frames - bt_idx - 1;
	35
	36	if (!bt[frame_idx]) {
cb323159 A	37	T_LOG("frame %2u: skipping system frame '%s'", frame_idx,
cb323159 A	38	CSSymbolGetName(symbol));
0a7de745 A	39	return;
	40	}
	41
	42	if (CSIsNull(symbol)) {
cb323159 A	43	T_FAIL("invalid symbol for address %#lx at frame %d", addr,
cb323159 A	44	frame_idx);
0a7de745 A	45	return;
	46	}
	47
	48	if (frame_idx >= bt_len) {
	49	T_FAIL("unexpected frame '%s' (%#lx) at index %u",
	50	CSSymbolGetName(symbol), addr, frame_idx);
	51	return;
	52	}
	53
	54	name = CSSymbolGetName(symbol);
	55	T_QUIET; T_ASSERT_NOTNULL(name, NULL);
	56	T_EXPECT_EQ_STR(name, bt[frame_idx],
	57	"frame %2u: saw '%s', expected '%s'",
	58	frame_idx, name, bt[frame_idx]);
39037602 A	59	}
	60
	61	/*
813fb2f6 A	62	* Expect to see either user or kernel stacks on thread with ID `tid` with a
	63	* signature of `bt` of length `bt_len`. Updates `stacks_seen` when stack
	64	* is found.
	65	*
	66	* Can also allow stacks to be larger than the signature -- additional frames
	67	* near the current PC will be ignored. This allows stacks to potentially be
	68	* in the middle of a signalling system call (which signals that it is safe to
	69	* start sampling).
39037602 A	70	*/
	71	static void
	72	expect_backtrace(ktrace_session_t s, uint64_t tid, unsigned int *stacks_seen,
813fb2f6	73	bool kern, const char **bt, unsigned int bt_len, unsigned int allow_larger_by)
39037602	74	{
0a7de745 A	75	CSSymbolicatorRef symb;
	76	uint32_t hdr_debugid;
	77	uint32_t data_debugid;
	78	__block unsigned int stacks = 0;
	79	__block unsigned int frames = 0;
	80	__block unsigned int hdr_frames = 0;
	81	__block unsigned int allow_larger = allow_larger_by;
	82
	83	if (kern) {
	84	static CSSymbolicatorRef kern_symb;
	85	static dispatch_once_t kern_symb_once;
	86
	87	hdr_debugid = PERF_STK_KHDR;
	88	data_debugid = PERF_STK_KDATA;
	89
	90	dispatch_once(&kern_symb_once, ^(void) {
	91	kern_symb = CSSymbolicatorCreateWithMachKernel();
	92	T_QUIET; T_ASSERT_FALSE(CSIsNull(kern_symb), NULL);
	93	});
	94	symb = kern_symb;
	95	} else {
	96	static CSSymbolicatorRef user_symb;
	97	static dispatch_once_t user_symb_once;
	98
	99	hdr_debugid = PERF_STK_UHDR;
	100	data_debugid = PERF_STK_UDATA;
	101
	102	dispatch_once(&user_symb_once, ^(void) {
	103	user_symb = CSSymbolicatorCreateWithTask(mach_task_self());
	104	T_QUIET; T_ASSERT_FALSE(CSIsNull(user_symb), NULL);
	105	T_QUIET; T_ASSERT_TRUE(CSSymbolicatorIsTaskValid(user_symb), NULL);
	106	});
	107	symb = user_symb;
	108	}
	109
	110	ktrace_events_single(s, hdr_debugid, ^(struct trace_point *tp) {
	111	if (tid != 0 && tid != tp->threadid) {
	112	return;
	113	}
	114
cb323159	115	T_LOG("found stack from thread %#" PRIx64, tp->threadid);
0a7de745 A	116	stacks++;
0a7de745 A	117	if (!(tp->arg1 & 1)) {
cb323159 A	118	T_FAIL("invalid %s stack on thread %#" PRIx64,
cb323159 A	119	kern ? "kernel" : "user", tp->threadid);
0a7de745 A	120	return;
	121	}
	122
	123	hdr_frames = (unsigned int)tp->arg2;
	124	/* ignore extra link register or value pointed to by stack pointer */
	125	hdr_frames -= 1;
	126
	127	T_QUIET; T_EXPECT_GE(hdr_frames, bt_len,
	128	"number of frames in header");
	129	T_QUIET; T_EXPECT_LE(hdr_frames, bt_len + allow_larger,
	130	"number of frames in header");
	131	if (hdr_frames > bt_len && allow_larger > 0) {
	132	allow_larger = hdr_frames - bt_len;
	133	hdr_frames = bt_len;
	134	}
	135
	136	T_LOG("%s stack seen", kern ? "kernel" : "user");
	137	frames = 0;
	138	});
	139
	140	ktrace_events_single(s, data_debugid, ^(struct trace_point *tp) {
	141	if (tid != 0 && tid != tp->threadid) {
	142	return;
	143	}
	144
	145	int i = 0;
	146
	147	if (frames == 0 && hdr_frames > bt_len) {
	148	/* skip frames near the PC */
	149	i = (int)allow_larger;
	150	allow_larger -= 4;
	151	}
	152
	153	for (; i < 4 && frames < hdr_frames; i++, frames++) {
	154	unsigned long addr = (&tp->arg1)[i];
	155	CSSymbolRef symbol = CSSymbolicatorGetSymbolWithAddressAtTime(
	156	symb, addr, kCSNow);
	157
	158	expect_frame(bt, bt_len, symbol, addr, frames, hdr_frames);
	159	}
	160
	161	/* saw the end of the user stack */
	162	if (hdr_frames == frames) {
	163	*stacks_seen += 1;
	164	if (!kern) {
	165	ktrace_end(s, 1);
	166	}
	167	}
	168	});
39037602 A	169	}
	170
	171	#define TRIGGERING_DEBUGID (0xfeff0f00)
	172
	173	/*
	174	* These functions must return an int to avoid the function prologue being
	175	* hoisted out of the path to the spin (breaking being able to get a good
	176	* backtrace).
	177	*/
0a7de745	178	static int __attribute__((noinline, not_tail_called))
813fb2f6	179	recurse_a(dispatch_semaphore_t spinning, unsigned int frames);
0a7de745	180	static int __attribute__((noinline, not_tail_called))
813fb2f6	181	recurse_b(dispatch_semaphore_t spinning, unsigned int frames);
39037602	182
0a7de745	183	static int __attribute__((noinline, not_tail_called))
813fb2f6	184	recurse_a(dispatch_semaphore_t spinning, unsigned int frames)
39037602	185	{
0a7de745 A	186	if (frames == 0) {
	187	if (spinning) {
	188	dispatch_semaphore_signal(spinning);
	189	for (;;) {
	190	;
	191	}
	192	} else {
	193	kdebug_trace(TRIGGERING_DEBUGID, 0, 0, 0, 0);
	194	return 0;
	195	}
	196	}
	197
	198	return recurse_b(spinning, frames - 1) + 1;
39037602 A	199	}
39037602 A	200
0a7de745	201	static int __attribute__((noinline, not_tail_called))
813fb2f6	202	recurse_b(dispatch_semaphore_t spinning, unsigned int frames)
39037602	203	{
0a7de745 A	204	if (frames == 0) {
	205	if (spinning) {
	206	dispatch_semaphore_signal(spinning);
	207	for (;;) {
	208	;
	209	}
	210	} else {
	211	kdebug_trace(TRIGGERING_DEBUGID, 0, 0, 0, 0);
	212	return 0;
	213	}
	214	}
	215
	216	return recurse_a(spinning, frames - 1) + 1;
39037602 A	217	}
39037602 A	218
cb323159	219	#define USER_FRAMES (12)
39037602 A	220
39037602 A	221	#if defined(__x86_64__)
cb323159	222
39037602	223	#define RECURSE_START_OFFSET (3)
cb323159 A	224
	225	#else /* defined(__x86_64__) */
	226
	227	#define RECURSE_START_OFFSET (2)
	228
	229	#endif /* !defined(__x86_64__) */
39037602 A	230
	231	static const char *user_bt[USER_FRAMES] = {
	232	#if defined(__x86_64__)
cb323159 A	233	/*
	234	* x86_64 has an extra "thread_start" frame here.
	235	*/
0a7de745	236	NULL,
39037602	237	#endif /* defined(__x86_64__) */
cb323159	238	NULL,
0a7de745 A	239	"backtrace_thread",
0a7de745 A	240	"recurse_a", "recurse_b", "recurse_a", "recurse_b",
cb323159	241	"recurse_a", "recurse_b", "recurse_a", "recurse_b",
39037602	242	#if !defined(__x86_64__)
cb323159 A	243	/*
	244	* Pick up the slack to make the number of frames constant.
	245	*/
	246	"recurse_a",
39037602	247	#endif /* !defined(__x86_64__) */
cb323159	248	NULL,
39037602 A	249	};
39037602 A	250
5ba3f43e A	251	#if defined(__arm__)
	252
	253	#define KERNEL_FRAMES (2)
	254	static const char *kernel_bt[KERNEL_FRAMES] = {
0a7de745	255	"unix_syscall", "kdebug_trace64"
5ba3f43e A	256	};
	257
	258	#elif defined(__arm64__)
	259
	260	#define KERNEL_FRAMES (4)
	261	static const char *kernel_bt[KERNEL_FRAMES] = {
0a7de745	262	"fleh_synchronous", "sleh_synchronous", "unix_syscall", "kdebug_trace64"
5ba3f43e A	263	};
	264
	265	#elif defined(__x86_64__)
39037602 A	266
	267	#define KERNEL_FRAMES (2)
	268	static const char *kernel_bt[KERNEL_FRAMES] = {
0a7de745	269	"unix_syscall64", "kdebug_trace64"
39037602 A	270	};
	271
	272	#else
	273	#error "architecture unsupported"
	274	#endif /* defined(__arm__) */
	275
813fb2f6 A	276	static dispatch_once_t backtrace_once;
	277	static dispatch_semaphore_t backtrace_started;
	278	static dispatch_semaphore_t backtrace_go;
39037602	279
813fb2f6 A	280	/*
	281	* Another thread to run with a known backtrace.
	282	*
	283	* Take a semaphore that will be signalled when the thread is spinning at the
	284	* correct frame. If the semaphore is NULL, don't spin and instead make a
	285	* kdebug_trace system call, which can trigger a deterministic backtrace itself.
	286	*/
39037602 A	287	static void *
	288	backtrace_thread(void *arg)
	289	{
0a7de745 A	290	dispatch_semaphore_t notify_spinning;
	291	unsigned int calls;
	292
	293	notify_spinning = (dispatch_semaphore_t)arg;
	294
	295	dispatch_semaphore_signal(backtrace_started);
	296	if (!notify_spinning) {
	297	dispatch_semaphore_wait(backtrace_go, DISPATCH_TIME_FOREVER);
	298	}
	299
	300	/*
	301	* backtrace_thread, recurse_a, recurse_b, ...[, __kdebug_trace64]
	302	*
	303	* Always make one less call for this frame (backtrace_thread).
	304	*/
	305	calls = USER_FRAMES - RECURSE_START_OFFSET - 1 /* backtrace_thread */;
	306	if (notify_spinning) {
	307	/*
	308	* Spinning doesn't end up calling __kdebug_trace64.
	309	*/
	310	calls -= 1;
	311	}
	312
	313	T_LOG("backtrace thread calling into %d frames (already at %d frames)",
	314	calls, RECURSE_START_OFFSET);
	315	(void)recurse_a(notify_spinning, calls);
	316	return NULL;
39037602 A	317	}
	318
	319	static uint64_t
cb323159 A	320	create_backtrace_thread(void (thread_fn)(void *),
cb323159 A	321	dispatch_semaphore_t notify_spinning)
39037602	322	{
0a7de745 A	323	pthread_t thread = NULL;
0a7de745 A	324	uint64_t tid;
39037602	325
0a7de745 A	326	dispatch_once(&backtrace_once, ^{
	327	backtrace_started = dispatch_semaphore_create(0);
	328	T_QUIET; T_ASSERT_NOTNULL(backtrace_started, NULL);
813fb2f6	329
0a7de745 A	330	if (!notify_spinning) {
	331	backtrace_go = dispatch_semaphore_create(0);
	332	T_QUIET; T_ASSERT_NOTNULL(backtrace_go, NULL);
	333	}
	334	});
39037602	335
cb323159	336	T_QUIET; T_ASSERT_POSIX_ZERO(pthread_create(&thread, NULL, thread_fn,
0a7de745 A	337	(void *)notify_spinning), NULL);
	338	T_QUIET; T_ASSERT_NOTNULL(thread, "backtrace thread created");
	339	dispatch_semaphore_wait(backtrace_started, DISPATCH_TIME_FOREVER);
813fb2f6	340
0a7de745 A	341	T_QUIET; T_ASSERT_POSIX_ZERO(pthread_threadid_np(thread, &tid), NULL);
	342	T_QUIET; T_ASSERT_NE(tid, UINT64_C(0),
	343	"backtrace thread created does not have ID 0");
813fb2f6	344
0a7de745	345	T_LOG("starting thread with ID 0x%" PRIx64, tid);
39037602	346
0a7de745	347	return tid;
39037602 A	348	}
	349
	350	static void
	351	start_backtrace_thread(void)
	352	{
0a7de745 A	353	T_QUIET; T_ASSERT_NOTNULL(backtrace_go,
	354	"thread to backtrace created before starting it");
	355	dispatch_semaphore_signal(backtrace_go);
39037602 A	356	}
39037602 A	357
5ba3f43e A	358	#if TARGET_OS_WATCH
	359	#define TEST_TIMEOUT_NS (30 * NSEC_PER_SEC)
	360	#else /* TARGET_OS_WATCH */
39037602	361	#define TEST_TIMEOUT_NS (5 * NSEC_PER_SEC)
5ba3f43e	362	#endif /* !TARGET_OS_WATCH */
39037602	363
cb323159	364	T_DECL(kdebug_trigger,
39037602	365	"test that backtraces from kdebug trigger are correct",
813fb2f6	366	T_META_ASROOT(true))
39037602	367	{
0a7de745 A	368	static unsigned int stacks_seen = 0;
	369	ktrace_session_t s;
	370	kperf_kdebug_filter_t filter;
	371	uint64_t tid;
	372
cb323159 A	373	start_controlling_ktrace();
cb323159 A	374
0a7de745 A	375	s = ktrace_session_create();
	376	T_ASSERT_NOTNULL(s, "ktrace session was created");
	377
cb323159 A	378	ktrace_set_collection_interval(s, 100);
cb323159 A	379
0a7de745 A	380	T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL);
0a7de745 A	381
cb323159	382	tid = create_backtrace_thread(backtrace_thread, NULL);
0a7de745 A	383	expect_backtrace(s, tid, &stacks_seen, false, user_bt, USER_FRAMES, 0);
	384	expect_backtrace(s, tid, &stacks_seen, true, kernel_bt, KERNEL_FRAMES, 0);
	385
	386	/*
	387	* The triggering event must be traced (and thus registered with libktrace)
	388	* to get backtraces.
	389	*/
	390	ktrace_events_single(s, TRIGGERING_DEBUGID,
	391	^(__unused struct trace_point *tp){ });
	392
	393	ktrace_set_completion_handler(s, ^(void) {
	394	T_EXPECT_GE(stacks_seen, 2U, "saw both kernel and user stacks");
	395	ktrace_session_destroy(s);
	396	kperf_reset();
	397	T_END;
	398	});
	399
	400	filter = kperf_kdebug_filter_create();
	401	T_ASSERT_NOTNULL(filter, "kperf kdebug filter was created");
	402
	403	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_filter_add_debugid(filter,
	404	TRIGGERING_DEBUGID), NULL);
	405	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_filter_set(filter), NULL);
	406	(void)kperf_action_count_set(1);
	407	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_action_samplers_set(1,
	408	KPERF_SAMPLER_USTACK \| KPERF_SAMPLER_KSTACK), NULL);
	409	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_kdebug_action_set(1), NULL);
	410	kperf_kdebug_filter_destroy(filter);
	411
	412	T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);
	413
	414	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()), NULL);
	415
	416	start_backtrace_thread();
	417
	418	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
	419	dispatch_get_main_queue(), ^(void)
	420	{
	421	T_LOG("ending test after timeout");
	422	ktrace_end(s, 0);
	423	});
	424
	425	dispatch_main();
39037602 A	426	}
39037602 A	427
cb323159	428	T_DECL(user_timer,
39037602	429	"test that user backtraces on a timer are correct",
813fb2f6	430	T_META_ASROOT(true))
39037602	431	{
0a7de745 A	432	static unsigned int stacks_seen = 0;
	433	ktrace_session_t s;
	434	uint64_t tid;
	435	dispatch_semaphore_t wait_for_spinning = dispatch_semaphore_create(0);
39037602	436
cb323159 A	437	start_controlling_ktrace();
cb323159 A	438
0a7de745 A	439	s = ktrace_session_create();
0a7de745 A	440	T_QUIET; T_ASSERT_NOTNULL(s, "ktrace_session_create");
39037602	441
cb323159 A	442	ktrace_set_collection_interval(s, 100);
cb323159 A	443
0a7de745	444	ktrace_filter_pid(s, getpid());
39037602	445
0a7de745	446	configure_kperf_stacks_timer(getpid(), 10);
39037602	447
cb323159	448	tid = create_backtrace_thread(backtrace_thread, wait_for_spinning);
0a7de745 A	449	/* potentially calling dispatch function and system call */
0a7de745 A	450	expect_backtrace(s, tid, &stacks_seen, false, user_bt, USER_FRAMES - 1, 2);
39037602	451
0a7de745 A	452	ktrace_set_completion_handler(s, ^(void) {
	453	T_EXPECT_GE(stacks_seen, 1U, "saw at least one stack");
	454	ktrace_session_destroy(s);
	455	kperf_reset();
	456	T_END;
	457	});
39037602	458
0a7de745	459	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);
39037602	460
0a7de745 A	461	/* wait until the thread that will be backtraced is spinning */
0a7de745 A	462	dispatch_semaphore_wait(wait_for_spinning, DISPATCH_TIME_FOREVER);
39037602	463
0a7de745	464	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()), NULL);
39037602	465
0a7de745 A	466	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
	467	dispatch_get_main_queue(), ^(void)
	468	{
	469	T_LOG("ending test after timeout");
	470	ktrace_end(s, 0);
	471	});
39037602	472
0a7de745	473	dispatch_main();
39037602 A	474	}
39037602 A	475
cb323159 A	476	static volatile bool spin = true;
	477
	478	__attribute__((noinline, not_tail_called))
	479	static void
	480	recurse_spin(dispatch_semaphore_t notify_sema, int depth)
	481	{
	482	if (depth > 0) {
	483	recurse_spin(notify_sema, depth - 1);
	484	} else {
	485	dispatch_semaphore_signal(notify_sema);
	486	while (spin);
	487	}
	488	}
	489
	490	static void *
	491	spin_thread(void *arg)
	492	{
	493	dispatch_semaphore_t notify_sema = arg;
	494	dispatch_semaphore_signal(backtrace_started);
	495	recurse_spin(notify_sema, 257);
	496	return NULL;
	497	}
	498
	499	T_DECL(truncated_user_stacks, "ensure stacks are marked as truncated")
	500	{
	501	start_controlling_ktrace();
	502
	503	ktrace_session_t s = ktrace_session_create();
	504	T_ASSERT_NOTNULL(s, "ktrace session was created");
	505
	506	ktrace_set_collection_interval(s, 100);
	507
	508	T_QUIET;
	509	T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL);
	510
	511	configure_kperf_stacks_timer(getpid(), 10);
	512
	513	__block bool saw_stack = false;
	514	ktrace_set_completion_handler(s, ^{
	515	T_EXPECT_TRUE(saw_stack, "saw the user stack");
	516	T_END;
	517	});
	518
	519	dispatch_semaphore_t notify_sema = dispatch_semaphore_create(0);
	520	uint64_t tid = create_backtrace_thread(spin_thread, notify_sema);
	521
	522	ktrace_events_single(s, PERF_STK_UHDR, ^(struct trace_point *tp) {
	523	if (tp->threadid != tid) {
	524	return;
	525	}
	526	T_LOG("found %llu frame stack", tp->arg2);
	527	T_EXPECT_BITS_SET(tp->arg1, CALLSTACK_VALID,
	528	"found valid callstack");
	529	T_EXPECT_BITS_SET(tp->arg1, CALLSTACK_TRUNCATED,
	530	"found truncated callstack");
	531	saw_stack = true;
	532	ktrace_end(s, 1);
	533	});
	534
	535	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);
	536
	537	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()),
	538	"start tracing");
	539
540	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
541	dispatch_get_main_queue(), ^(void)
542	{
543	T_LOG("ending test after timeout");
544	ktrace_end(s, 0);
545	});
546
547	dispatch_main();
548	}
549
550	T_DECL(max_user_stacks, "ensure stacks up to 256 frames can be captured")
551	{
552	start_controlling_ktrace();
553
554	ktrace_session_t s = ktrace_session_create();
555	T_ASSERT_NOTNULL(s, "ktrace session was created");
556
557	ktrace_set_collection_interval(s, 100);
558
559	T_QUIET;
560	T_ASSERT_POSIX_ZERO(ktrace_filter_pid(s, getpid()), NULL);
561
562	configure_kperf_stacks_timer(getpid(), 10);
563
564	__block bool saw_stack = false;
565	__block bool saw_stack_data = false;
566	__block uint64_t nevents = 0;
567	ktrace_set_completion_handler(s, ^{
568	T_EXPECT_TRUE(saw_stack, "saw the user stack");
569	T_LOG("saw %" PRIu64 " stack data events", nevents);
570	T_EXPECT_TRUE(saw_stack_data, "saw all frames of the user stack");
571	T_END;
572	});
573
574	dispatch_semaphore_t notify_sema = dispatch_semaphore_create(0);
575	uint64_t tid = create_backtrace_thread(spin_thread, notify_sema);
576
577	ktrace_events_single(s, PERF_STK_UHDR, ^(struct trace_point *tp) {
578	if (tp->threadid != tid) {
579	return;
580	}
581	T_LOG("found %llu frame stack", tp->arg2);
582	T_EXPECT_BITS_SET(tp->arg1, CALLSTACK_VALID,
583	"found valid callstack");
584	T_EXPECT_EQ(tp->arg2, UINT64_C(256),
585	"found the correct number of frames");
586	saw_stack = true;
587	});
588
589	ktrace_events_single(s, PERF_STK_UDATA, ^(struct trace_point *tp) {
590	if (tp->threadid != tid && !saw_stack) {
591	return;
592	}
593	nevents++;
594	if (nevents == 256 / 4) {
595	ktrace_end(s, 1);
596	}
597	saw_stack_data = true;
598	});
599
600	T_QUIET; T_ASSERT_POSIX_SUCCESS(kperf_sample_set(1), NULL);
601
602	T_ASSERT_POSIX_ZERO(ktrace_start(s, dispatch_get_main_queue()),
603	"start tracing");
604
605	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, TEST_TIMEOUT_NS),
606	dispatch_get_main_queue(), ^(void)
607	{
608	T_LOG("ending test after timeout");
609	ktrace_end(s, 0);
610	});
611
612	dispatch_main();
613	}
614
39037602	615	/* TODO test kernel stacks in all modes */
813fb2f6	616	/* TODO legacy PET mode backtracing */