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

/* Copyright (c) 2018 Apple Inc.  All rights reserved. */

#include <CoreFoundation/CoreFoundation.h>
#include <darwintest.h>
#include <dispatch/dispatch.h>
#include <ktrace/ktrace.h>
#include <kern/debug.h>
#include <notify.h>
#include <sys/kdebug.h>
#include <TargetConditionals.h>

enum telemetry_pmi {
	TELEMETRY_PMI_NONE,
	TELEMETRY_PMI_INSTRS,
	TELEMETRY_PMI_CYCLES,
};
#define TELEMETRY_CMD_PMI_SETUP 3

T_GLOBAL_META(T_META_NAMESPACE("xnu.debugging.telemetry"),
    T_META_CHECK_LEAKS(false),
    T_META_ASROOT(true));

extern int __telemetry(uint64_t cmd, uint64_t deadline, uint64_t interval,
    uint64_t leeway, uint64_t arg4, uint64_t arg5);

/*
 * Data Analytics (da) also has a microstackshot configuration -- set a PMI
 * cycle interval of 0 to force it to disable microstackshot on PMI.
 */

static void
set_da_microstackshot_period(CFNumberRef num)
{
	CFPreferencesSetValue(CFSTR("microstackshotPMICycleInterval"), num,
	    CFSTR("com.apple.da"),
#if TARGET_OS_IPHONE
	    CFSTR("mobile"),
#else // TARGET_OS_IPHONE
	    CFSTR("root"),
#endif // !TARGET_OS_IPHONE
	    kCFPreferencesCurrentHost);

	notify_post("com.apple.da.tasking_changed");
}

static void
disable_da_microstackshots(void)
{
	int64_t zero = 0;
	CFNumberRef num = CFNumberCreate(NULL, kCFNumberSInt64Type, &zero);
	set_da_microstackshot_period(num);
	T_LOG("notified da of tasking change, sleeping");
	sleep(3);
}

/*
 * Unset the preference to allow da to reset its configuration.
 */
static void
reenable_da_microstackshots(void)
{
	set_da_microstackshot_period(NULL);
}

/*
 * Clean up the test's configuration and allow da to activate again.
 */
static void
telemetry_cleanup(void)
{
	int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_NONE, 0, 0, 0, 0);
	T_EXPECT_POSIX_SUCCESS(ret, "telemetry(... NONE ...)");
	reenable_da_microstackshots();
}

/*
 * Make sure da hasn't configured the microstackshots -- otherwise the PMI
 * setup command will return EBUSY.
 */
static void
telemetry_init(void)
{
	disable_da_microstackshots();
	T_LOG("installing cleanup handler");
	T_ATEND(telemetry_cleanup);
}

volatile static bool spinning = true;

static void *
thread_spin(__unused void *arg)
{
	while (spinning) {
	}
	return NULL;
}

#define MT_MICROSTACKSHOT KDBG_EVENTID(DBG_MONOTONIC, 2, 1)
#define MS_RECORD MACHDBG_CODE(DBG_MACH_STACKSHOT, \
	        MICROSTACKSHOT_RECORD)
#if defined(__arm64__) || defined(__arm__)
#define INSTRS_PERIOD (100ULL * 1000 * 1000)
#else /* defined(__arm64__) || defined(__arm__) */
#define INSTRS_PERIOD (1ULL * 1000 * 1000 * 1000)
#endif /* !defined(__arm64__) && !defined(__arm__) */
#define SLEEP_SECS 10

T_DECL(microstackshot_pmi, "attempt to configure microstackshots on PMI")
{
#if TARGET_OS_WATCH
	T_SKIP("unsupported platform");
#endif /* TARGET_OS_WATCH */

	T_SETUPBEGIN;
	ktrace_session_t s = ktrace_session_create();
	T_QUIET; T_WITH_ERRNO; T_ASSERT_NOTNULL(s, "session create");

	__block int pmi_events = 0;
	__block int microstackshot_record_events = 0;
	__block int pmi_records = 0;
	__block int io_records = 0;
	__block int interrupt_records = 0;
	__block int timer_arm_records = 0;
	__block int unknown_records = 0;

	ktrace_events_single(s, MT_MICROSTACKSHOT, ^(__unused struct trace_point *tp) {
		pmi_events++;
	});
	ktrace_events_single_paired(s, MS_RECORD,
	    ^(struct trace_point *start, __unused struct trace_point *end) {
		if (start->arg1 & kPMIRecord) {
		        pmi_records++;
		}
		if (start->arg1 & kIORecord) {
		        io_records++;
		}
		if (start->arg1 & kInterruptRecord) {
		        interrupt_records++;
		}
		if (start->arg1 & kTimerArmingRecord) {
		        timer_arm_records++;
		}

		const uint8_t any_record = kPMIRecord | kIORecord | kInterruptRecord |
		kTimerArmingRecord;
		if ((start->arg1 & any_record) == 0) {
		        unknown_records++;
		}

		microstackshot_record_events++;
	});

	ktrace_set_completion_handler(s, ^{
		ktrace_session_destroy(s);
		T_EXPECT_GT(pmi_events, 0,
		"saw non-zero PMIs (%g/sec)", pmi_events / (double)SLEEP_SECS);
		T_EXPECT_GT(pmi_records, 0, "saw non-zero PMI record events (%g/sec)",
		pmi_records / (double)SLEEP_SECS);
		T_EXPECT_EQ(unknown_records, 0, "saw zero unknown record events");
		T_EXPECT_GT(microstackshot_record_events, 0,
		"saw non-zero microstackshot record events (%g/sec)",
		microstackshot_record_events / (double)SLEEP_SECS);

		if (interrupt_records > 0) {
		        T_LOG("saw %g interrupt records per second",
		        interrupt_records / (double)SLEEP_SECS);
		} else {
		        T_LOG("saw no interrupt records");
		}
		if (io_records > 0) {
		        T_LOG("saw %g I/O records per second",
		        io_records / (double)SLEEP_SECS);
		} else {
		        T_LOG("saw no I/O records");
		}
		if (timer_arm_records > 0) {
		        T_LOG("saw %g timer arming records per second",
		        timer_arm_records / (double)SLEEP_SECS);
		} else {
		        T_LOG("saw no timer arming records");
		}

		T_END;
	});

	T_SETUPEND;

	telemetry_init();

	/*
	 * Start sampling via telemetry on the instructions PMI.
	 */
	int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
	    INSTRS_PERIOD, 0, 0, 0);
	T_ASSERT_POSIX_SUCCESS(ret,
	    "telemetry syscall succeeded, started microstackshots");

	pthread_t thread;
	int error = pthread_create(&thread, NULL, thread_spin, NULL);
	T_ASSERT_POSIX_ZERO(error, "started thread to spin");

	error = ktrace_start(s, dispatch_get_main_queue());
	T_ASSERT_POSIX_ZERO(error, "started tracing");

	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, SLEEP_SECS * NSEC_PER_SEC),
	    dispatch_get_main_queue(), ^{
		spinning = false;
		ktrace_end(s, 0);
		(void)pthread_join(thread, NULL);
		T_LOG("ending trace session after %d seconds", SLEEP_SECS);
	});

	dispatch_main();
}

T_DECL(error_handling,
    "ensure that error conditions for the telemetry syscall are observed")
{
	telemetry_init();

	int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
	    1, 0, 0, 0);
	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every instruction");

	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
	    1000 * 1000, 0, 0, 0);
	T_EXPECT_EQ(ret, -1,
	    "telemetry shouldn't allow PMI every million instructions");

	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
	    1, 0, 0, 0);
	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every cycle");

	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
	    1000 * 1000, 0, 0, 0);
	T_EXPECT_EQ(ret, -1,
	    "telemetry shouldn't allow PMI every million cycles");

	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
	    UINT64_MAX, 0, 0, 0);
	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every UINT64_MAX cycles");

	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
	    (1ULL << 55), 0, 0, 0);
	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI with extremely long periods");
}
Commit	Line	Data
0a7de745 A	1	/* Copyright (c) 2018 Apple Inc. All rights reserved. */
	2
	3	#include <CoreFoundation/CoreFoundation.h>
d9a64523 A	4	#include <darwintest.h>
	5	#include <dispatch/dispatch.h>
	6	#include <ktrace/ktrace.h>
	7	#include <kern/debug.h>
0a7de745	8	#include <notify.h>
d9a64523 A	9	#include <sys/kdebug.h>
	10	#include <TargetConditionals.h>
	11
	12	enum telemetry_pmi {
	13	TELEMETRY_PMI_NONE,
	14	TELEMETRY_PMI_INSTRS,
	15	TELEMETRY_PMI_CYCLES,
	16	};
	17	#define TELEMETRY_CMD_PMI_SETUP 3
	18
	19	T_GLOBAL_META(T_META_NAMESPACE("xnu.debugging.telemetry"),
0a7de745 A	20	T_META_CHECK_LEAKS(false),
0a7de745 A	21	T_META_ASROOT(true));
d9a64523 A	22
d9a64523 A	23	extern int __telemetry(uint64_t cmd, uint64_t deadline, uint64_t interval,
0a7de745 A	24	uint64_t leeway, uint64_t arg4, uint64_t arg5);
	25
	26	/*
	27	* Data Analytics (da) also has a microstackshot configuration -- set a PMI
	28	* cycle interval of 0 to force it to disable microstackshot on PMI.
	29	*/
	30
	31	static void
	32	set_da_microstackshot_period(CFNumberRef num)
	33	{
	34	CFPreferencesSetValue(CFSTR("microstackshotPMICycleInterval"), num,
	35	CFSTR("com.apple.da"),
	36	#if TARGET_OS_IPHONE
	37	CFSTR("mobile"),
	38	#else // TARGET_OS_IPHONE
	39	CFSTR("root"),
	40	#endif // !TARGET_OS_IPHONE
	41	kCFPreferencesCurrentHost);
	42
	43	notify_post("com.apple.da.tasking_changed");
	44	}
	45
	46	static void
	47	disable_da_microstackshots(void)
	48	{
	49	int64_t zero = 0;
	50	CFNumberRef num = CFNumberCreate(NULL, kCFNumberSInt64Type, &zero);
	51	set_da_microstackshot_period(num);
	52	T_LOG("notified da of tasking change, sleeping");
	53	sleep(3);
	54	}
	55
	56	/*
	57	* Unset the preference to allow da to reset its configuration.
	58	*/
	59	static void
	60	reenable_da_microstackshots(void)
	61	{
	62	set_da_microstackshot_period(NULL);
	63	}
d9a64523	64
0a7de745 A	65	/*
	66	* Clean up the test's configuration and allow da to activate again.
	67	*/
d9a64523 A	68	static void
	69	telemetry_cleanup(void)
	70	{
	71	int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_NONE, 0, 0, 0, 0);
	72	T_EXPECT_POSIX_SUCCESS(ret, "telemetry(... NONE ...)");
0a7de745 A	73	reenable_da_microstackshots();
	74	}
	75
	76	/*
	77	* Make sure da hasn't configured the microstackshots -- otherwise the PMI
	78	* setup command will return EBUSY.
	79	*/
	80	static void
	81	telemetry_init(void)
	82	{
	83	disable_da_microstackshots();
	84	T_LOG("installing cleanup handler");
	85	T_ATEND(telemetry_cleanup);
d9a64523 A	86	}
	87
	88	volatile static bool spinning = true;
0a7de745	89
d9a64523 A	90	static void *
	91	thread_spin(__unused void *arg)
	92	{
	93	while (spinning) {
	94	}
	95	return NULL;
	96	}
	97
	98	#define MT_MICROSTACKSHOT KDBG_EVENTID(DBG_MONOTONIC, 2, 1)
	99	#define MS_RECORD MACHDBG_CODE(DBG_MACH_STACKSHOT, \
0a7de745	100	MICROSTACKSHOT_RECORD)
d9a64523 A	101	#if defined(__arm64__) \|\| defined(__arm__)
	102	#define INSTRS_PERIOD (100ULL * 1000 * 1000)
	103	#else /* defined(__arm64__) \|\| defined(__arm__) */
	104	#define INSTRS_PERIOD (1ULL * 1000 * 1000 * 1000)
	105	#endif /* !defined(__arm64__) && !defined(__arm__) */
	106	#define SLEEP_SECS 10
	107
	108	T_DECL(microstackshot_pmi, "attempt to configure microstackshots on PMI")
	109	{
	110	#if TARGET_OS_WATCH
	111	T_SKIP("unsupported platform");
	112	#endif /* TARGET_OS_WATCH */
	113
	114	T_SETUPBEGIN;
	115	ktrace_session_t s = ktrace_session_create();
	116	T_QUIET; T_WITH_ERRNO; T_ASSERT_NOTNULL(s, "session create");
	117
	118	__block int pmi_events = 0;
	119	__block int microstackshot_record_events = 0;
	120	__block int pmi_records = 0;
	121	__block int io_records = 0;
	122	__block int interrupt_records = 0;
	123	__block int timer_arm_records = 0;
	124	__block int unknown_records = 0;
d9a64523 A	125
	126	ktrace_events_single(s, MT_MICROSTACKSHOT, ^(__unused struct trace_point *tp) {
	127	pmi_events++;
	128	});
	129	ktrace_events_single_paired(s, MS_RECORD,
0a7de745	130	^(struct trace_point start, __unused struct trace_point end) {
d9a64523	131	if (start->arg1 & kPMIRecord) {
0a7de745	132	pmi_records++;
d9a64523 A	133	}
d9a64523 A	134	if (start->arg1 & kIORecord) {
0a7de745	135	io_records++;
d9a64523 A	136	}
d9a64523 A	137	if (start->arg1 & kInterruptRecord) {
0a7de745	138	interrupt_records++;
d9a64523 A	139	}
d9a64523 A	140	if (start->arg1 & kTimerArmingRecord) {
0a7de745	141	timer_arm_records++;
d9a64523 A	142	}
	143
	144	const uint8_t any_record = kPMIRecord \| kIORecord \| kInterruptRecord \|
0a7de745	145	kTimerArmingRecord;
d9a64523	146	if ((start->arg1 & any_record) == 0) {
0a7de745	147	unknown_records++;
d9a64523 A	148	}
	149
	150	microstackshot_record_events++;
	151	});
	152
	153	ktrace_set_completion_handler(s, ^{
	154	ktrace_session_destroy(s);
	155	T_EXPECT_GT(pmi_events, 0,
0a7de745	156	"saw non-zero PMIs (%g/sec)", pmi_events / (double)SLEEP_SECS);
d9a64523	157	T_EXPECT_GT(pmi_records, 0, "saw non-zero PMI record events (%g/sec)",
0a7de745	158	pmi_records / (double)SLEEP_SECS);
d9a64523	159	T_EXPECT_EQ(unknown_records, 0, "saw zero unknown record events");
d9a64523	160	T_EXPECT_GT(microstackshot_record_events, 0,
0a7de745 A	161	"saw non-zero microstackshot record events (%g/sec)",
0a7de745 A	162	microstackshot_record_events / (double)SLEEP_SECS);
d9a64523 A	163
d9a64523 A	164	if (interrupt_records > 0) {
0a7de745 A	165	T_LOG("saw %g interrupt records per second",
0a7de745 A	166	interrupt_records / (double)SLEEP_SECS);
d9a64523	167	} else {
0a7de745	168	T_LOG("saw no interrupt records");
d9a64523 A	169	}
d9a64523 A	170	if (io_records > 0) {
0a7de745 A	171	T_LOG("saw %g I/O records per second",
0a7de745 A	172	io_records / (double)SLEEP_SECS);
d9a64523	173	} else {
0a7de745	174	T_LOG("saw no I/O records");
d9a64523 A	175	}
d9a64523 A	176	if (timer_arm_records > 0) {
0a7de745 A	177	T_LOG("saw %g timer arming records per second",
0a7de745 A	178	timer_arm_records / (double)SLEEP_SECS);
d9a64523	179	} else {
0a7de745	180	T_LOG("saw no timer arming records");
d9a64523 A	181	}
	182
	183	T_END;
	184	});
	185
	186	T_SETUPEND;
	187
0a7de745 A	188	telemetry_init();
0a7de745 A	189
d9a64523 A	190	/*
	191	* Start sampling via telemetry on the instructions PMI.
	192	*/
	193	int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
0a7de745 A	194	INSTRS_PERIOD, 0, 0, 0);
	195	T_ASSERT_POSIX_SUCCESS(ret,
	196	"telemetry syscall succeeded, started microstackshots");
d9a64523 A	197
	198	pthread_t thread;
	199	int error = pthread_create(&thread, NULL, thread_spin, NULL);
	200	T_ASSERT_POSIX_ZERO(error, "started thread to spin");
	201
	202	error = ktrace_start(s, dispatch_get_main_queue());
	203	T_ASSERT_POSIX_ZERO(error, "started tracing");
	204
	205	dispatch_after(dispatch_time(DISPATCH_TIME_NOW, SLEEP_SECS * NSEC_PER_SEC),
0a7de745	206	dispatch_get_main_queue(), ^{
d9a64523 A	207	spinning = false;
	208	ktrace_end(s, 0);
	209	(void)pthread_join(thread, NULL);
	210	T_LOG("ending trace session after %d seconds", SLEEP_SECS);
	211	});
	212
	213	dispatch_main();
	214	}
	215
	216	T_DECL(error_handling,
0a7de745	217	"ensure that error conditions for the telemetry syscall are observed")
d9a64523	218	{
0a7de745 A	219	telemetry_init();
0a7de745 A	220
d9a64523	221	int ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
0a7de745	222	1, 0, 0, 0);
d9a64523 A	223	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every instruction");
	224
	225	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_INSTRS,
0a7de745	226	1000 * 1000, 0, 0, 0);
d9a64523	227	T_EXPECT_EQ(ret, -1,
0a7de745	228	"telemetry shouldn't allow PMI every million instructions");
d9a64523 A	229
d9a64523 A	230	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
0a7de745	231	1, 0, 0, 0);
d9a64523 A	232	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every cycle");
	233
	234	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
0a7de745	235	1000 * 1000, 0, 0, 0);
d9a64523	236	T_EXPECT_EQ(ret, -1,
0a7de745 A	237	"telemetry shouldn't allow PMI every million cycles");
	238
	239	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
	240	UINT64_MAX, 0, 0, 0);
	241	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI every UINT64_MAX cycles");
	242
	243	ret = __telemetry(TELEMETRY_CMD_PMI_SETUP, TELEMETRY_PMI_CYCLES,
	244	(1ULL << 55), 0, 0, 0);
	245	T_EXPECT_EQ(ret, -1, "telemetry shouldn't allow PMI with extremely long periods");
d9a64523	246	}