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

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