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

#ifdef T_NAMESPACE
#undef T_NAMESPACE
#endif

#include <darwintest.h>
#include <darwintest_multiprocess.h>
#include <darwintest_utils.h>
#include <pthread.h>
#include <launch.h>
#include <servers/bootstrap.h>
#include <stdlib.h>
#include <sys/event.h>
#include <unistd.h>
#include <crt_externs.h>
#include <sys/sysctl.h>
#include <sys/types.h>
#include <unistd.h>
#include <spawn.h>

T_GLOBAL_META(T_META_NAMESPACE("xnu.kernel_mtx_perf_test"));

#define ITER 100000
#define TEST_MTX_MAX_STATS 		8

#define TEST_MTX_LOCK_STATS 		0
#define TEST_MTX_UNLOCK_MTX_STATS 	6

static void
test_from_kernel_lock_unlock_contended(void)
{
	int i, ret, name_size;
	uint64_t avg, run, tot;
	size_t size;
	char iter[35];
	char *buff, *buff_p, *avg_p, *name, *end_name;

	T_LOG("Testing locking/unlocking mutex from kernel with contention.\n");
	T_LOG("Requesting test with %d iterations\n", ITER);

	size = 1000;
	buff = calloc(size, sizeof(char));
	T_QUIET;T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");

	snprintf(iter, sizeof(iter), "%d", ITER);
	ret = sysctlbyname("kern.test_mtx_contended", buff, &size, iter, sizeof(iter));
	T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_contended");

	T_LOG("%s stats:\n%s\n", __func__, buff);

	/* first line is "STATS INNER LOOP" */
	buff_p = buff;
	while( *buff_p != '\n' ) buff_p++;
	buff_p++;

	/*
	 * Sequence of statistic lines like
	 * { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
	 * for all TEST_MTX_MAX_STATS statistics
	 */
	for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
		avg_p = strstr(buff_p, "avg ");

		/* contended test records statistics only for lock/unlock for now */
		if (i == TEST_MTX_LOCK_STATS || i == TEST_MTX_UNLOCK_MTX_STATS ) {
			T_QUIET;T_ASSERT_NOTNULL(avg_p, "contended %i average not found", i);
			sscanf(avg_p, "avg %llu", &avg);

			name = strstr(buff_p, "TEST_MTX_");
			end_name = strstr(buff_p, "_STATS");
			name_size = end_name - name - strlen("TEST_MTX_") + 1;

			char name_string[40];
			char avg_name_string[50];
			char *pre_string = "contended ";
			snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
			pre_string = "avg contended ";
			snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
			T_PERF(name_string, avg, "ns", avg_name_string);
		}

		buff_p = avg_p;
		while( *buff_p != '\n' ) buff_p++;
		buff_p++;

	}

	while( *buff_p != '\n' ) buff_p++;
	buff_p++;

	/* next line is "STATS OUTER LOOP" */
	while( *buff_p != '\n' ) buff_p++;
	buff_p++;

	/* contended test records statistics only for lock/unlock for now */
	avg_p = strstr(buff_p, "run time ");
	T_QUIET;T_ASSERT_NOTNULL(avg_p, "contended %d loop run time not found", 0);
	sscanf(avg_p, "run time %llu", &run);

	avg_p = strstr(buff_p, "total time ");
	T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", 0);
	sscanf(avg_p, "total time %llu", &tot);

	if (run < tot)
		avg = run;
	else
		avg = tot;

	name = strstr(buff_p, "TEST_MTX_");
	end_name = strstr(buff_p, "_STATS");
	name_size = end_name - name - strlen("TEST_MTX_") + 1;

	char name_string[50];
	char avg_name_string[60];
	char *pre_string = "contended loop ";
	snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
	pre_string = "avg time contended loop ";
	snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
	T_PERF(name_string, avg/ITER, "ns", avg_name_string);

	free(buff);
}

static void
test_from_kernel_lock_unlock_uncontended(void)
{
	int i, ret, name_size;
	uint64_t avg, run, tot;
	size_t size;
	char iter[35];
	char *buff, *buff_p, *avg_p, *name, *end_name;

	T_LOG("Testing locking/unlocking mutex from kernel without contention.\n");
	T_LOG("Requesting test with %d iterations\n", ITER);

	size = 2000;
	buff = calloc(size, sizeof(char));
	T_QUIET;T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");

	snprintf(iter, sizeof(iter), "%d", ITER);
	ret = sysctlbyname("kern.test_mtx_uncontended", buff, &size, iter, sizeof(iter));
	T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_uncontended");

	T_LOG("%s stats:\n%s\n", __func__, buff);

	/* first line is "STATS INNER LOOP" */
	buff_p = buff;
	while( *buff_p != '\n' ) buff_p++;
	buff_p++;

	/*
	 * Sequence of statistic lines like
	 * { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
	 * for all TEST_MTX_MAX_STATS statistics
	 */
	for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
		avg_p = strstr(buff_p, "avg ");
		T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %i average not found", i);
		sscanf(avg_p, "avg %llu", &avg);

		name = strstr(buff_p, "TEST_MTX_");
		end_name = strstr(buff_p, "_STATS");
		name_size = end_name - name - strlen("TEST_MTX_") + 1;

		char name_string[40];
		char avg_name_string[50];
		char *pre_string = "uncontended ";
		snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
		pre_string = "avg time uncontended ";
		snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
		T_PERF(name_string, avg, "ns", avg_name_string);

		buff_p = avg_p;
		while( *buff_p != '\n' ) buff_p++;
		buff_p++;
	}

	while( *buff_p != '\n' ) buff_p++;
	buff_p++;

	/* next line is "STATS OUTER LOOP" */
	while( *buff_p != '\n' ) buff_p++;
	buff_p++;

	/*
	 * Sequence of statistic lines like
	 * total time 4040673 ns total run time 3981080 ns TEST_MTX_LOCK_STATS
	 * for all TEST_MTX_MAX_STATS statistics exept UNLOCK
	 */
	for (i = 0; i < TEST_MTX_MAX_STATS - 2; i++) {
		avg_p = strstr(buff_p, "run time ");
		T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %d loop run time not found", i);
		sscanf(avg_p, "run time %llu", &run);

		avg_p = strstr(buff_p, "total time ");
		T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", i);
		sscanf(avg_p, "total time %llu", &tot);

		if (run < tot)
			avg = run;
		else
			avg = tot;

		name = strstr(buff_p, "TEST_MTX_");
		end_name = strstr(buff_p, "_STATS");
		name_size = end_name - name - strlen("TEST_MTX_") + 1;

		char name_string[50];
		char avg_name_string[60];
		char *pre_string = "uncontended loop ";
		snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
		pre_string = "avg time uncontended loop ";
		snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
		T_PERF(name_string, avg/ITER, "ns", avg_name_string);

		buff_p = avg_p;
		while( *buff_p != '\n' ) buff_p++;
		buff_p++;

	}
	free(buff);
}

extern char **environ;
static void
fix_cpu_frequency(void)
{
#if CONFIG_EMBEDDED
	int spawn_ret, pid;
	char *const clpcctrl_args[] = {"/usr/local/bin/clpcctrl", "-f", "5000", NULL};

	T_LOG("Setting cpu frequency to %d\n", 5000);

	spawn_ret = posix_spawn(&pid, clpcctrl_args[0], NULL, NULL, clpcctrl_args, environ);
	waitpid(pid, &spawn_ret, 0);

#else /*CONFIG_EMBEDDED*/

	int spawn_ret, pid;
	int ret, nom_freq;
	size_t len;
	float val;
	char scale;
	char *buffer, *cpu_freq;
	char str_val[10];

	ret = sysctlbyname("machdep.cpu.brand_string", NULL, &len, NULL, 0);
	T_QUIET;T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");

	buffer = malloc(len+2);
	ret = sysctlbyname("machdep.cpu.brand_string", buffer, &len, NULL, 0);
	T_QUIET;T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
	buffer[len+1] = '\0';

	cpu_freq = strstr(buffer, "CPU @ ");
	if (cpu_freq == NULL) {
		T_LOG("Could not fix frequency, %s field not present\n", "CPU @ ");
		goto out;
	}

	if (strstr(cpu_freq, "Hz") != NULL) {
		sscanf(cpu_freq, "CPU @ %f%cHz", &val, &scale);
	} else {
		if (strstr(cpu_freq, "hz") != NULL) {
			sscanf(cpu_freq, "CPU @ %f%chz", &val, &scale);
		} else {
			T_LOG("Could not fix frequency, %s field not present\n", "Hz");
			goto out;
		}
	}

	switch(scale){
	case 'M':
	case 'm':
		nom_freq = (int) val;
		break;
	case 'G':
	case 'g':
		nom_freq = (int) (val*1000);
		break;
	default:
		T_LOG("Could not fix frequency, scale field is %c\n", scale);
		goto out;
	}

	snprintf(str_val, 10, "%d", nom_freq);
	T_LOG("Setting min and max cpu frequency to %d (%s)\n", nom_freq, str_val);
	char *xcpm_args[] = {"/usr/local/bin/xcpm", "limits", str_val, str_val, NULL};
	spawn_ret = posix_spawn(&pid, xcpm_args[0], NULL, NULL, xcpm_args, environ);
	waitpid(pid, &spawn_ret, 0);

out:
	free(buffer);
	return;
#endif /*CONFIG_EMBEDDED*/
}

T_DECL(kernel_mtx_perf_test,
	"Kernel mutex performance test",
	T_META_ASROOT(YES), T_META_CHECK_LEAKS(NO))
{
	fix_cpu_frequency();

	test_from_kernel_lock_unlock_uncontended();
	test_from_kernel_lock_unlock_contended();
}
Commit	Line	Data
d9a64523 A	1	#ifdef T_NAMESPACE
	2	#undef T_NAMESPACE
	3	#endif
	4
	5	#include <darwintest.h>
	6	#include <darwintest_multiprocess.h>
	7	#include <darwintest_utils.h>
	8	#include <pthread.h>
	9	#include <launch.h>
	10	#include <servers/bootstrap.h>
	11	#include <stdlib.h>
	12	#include <sys/event.h>
	13	#include <unistd.h>
	14	#include <crt_externs.h>
	15	#include <sys/sysctl.h>
	16	#include <sys/types.h>
	17	#include <unistd.h>
	18	#include <spawn.h>
	19
	20	T_GLOBAL_META(T_META_NAMESPACE("xnu.kernel_mtx_perf_test"));
	21
	22	#define ITER 100000
	23	#define TEST_MTX_MAX_STATS 8
	24
	25	#define TEST_MTX_LOCK_STATS 0
	26	#define TEST_MTX_UNLOCK_MTX_STATS 6
	27
	28	static void
	29	test_from_kernel_lock_unlock_contended(void)
	30	{
	31	int i, ret, name_size;
	32	uint64_t avg, run, tot;
	33	size_t size;
	34	char iter[35];
	35	char buff, buff_p, avg_p, name, *end_name;
	36
	37	T_LOG("Testing locking/unlocking mutex from kernel with contention.\n");
	38	T_LOG("Requesting test with %d iterations\n", ITER);
	39
	40	size = 1000;
	41	buff = calloc(size, sizeof(char));
	42	T_QUIET;T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");
	43
	44	snprintf(iter, sizeof(iter), "%d", ITER);
	45	ret = sysctlbyname("kern.test_mtx_contended", buff, &size, iter, sizeof(iter));
	46	T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_contended");
	47
	48	T_LOG("%s stats:\n%s\n", __func__, buff);
	49
	50	/* first line is "STATS INNER LOOP" */
	51	buff_p = buff;
	52	while( *buff_p != '\n' ) buff_p++;
	53	buff_p++;
	54
	55	/*
	56	* Sequence of statistic lines like
	57	* { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
	58	* for all TEST_MTX_MAX_STATS statistics
	59	*/
	60	for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
	61	avg_p = strstr(buff_p, "avg ");
	62
	63	/* contended test records statistics only for lock/unlock for now */
	64	if (i == TEST_MTX_LOCK_STATS \|\| i == TEST_MTX_UNLOCK_MTX_STATS ) {
65	T_QUIET;T_ASSERT_NOTNULL(avg_p, "contended %i average not found", i);
66	sscanf(avg_p, "avg %llu", &avg);
67
68	name = strstr(buff_p, "TEST_MTX_");
69	end_name = strstr(buff_p, "_STATS");
70	name_size = end_name - name - strlen("TEST_MTX_") + 1;
71
72	char name_string[40];
73	char avg_name_string[50];
74	char *pre_string = "contended ";
75	snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
76	pre_string = "avg contended ";
77	snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
78	T_PERF(name_string, avg, "ns", avg_name_string);
79	}
80
81	buff_p = avg_p;
82	while( *buff_p != '\n' ) buff_p++;
83	buff_p++;
84
85	}
86
87	while( *buff_p != '\n' ) buff_p++;
88	buff_p++;
89
90	/* next line is "STATS OUTER LOOP" */
91	while( *buff_p != '\n' ) buff_p++;
92	buff_p++;
93
94	/* contended test records statistics only for lock/unlock for now */
95	avg_p = strstr(buff_p, "run time ");
96	T_QUIET;T_ASSERT_NOTNULL(avg_p, "contended %d loop run time not found", 0);
97	sscanf(avg_p, "run time %llu", &run);
98
99	avg_p = strstr(buff_p, "total time ");
100	T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", 0);
101	sscanf(avg_p, "total time %llu", &tot);
102
103	if (run < tot)
104	avg = run;
105	else
106	avg = tot;
107
108	name = strstr(buff_p, "TEST_MTX_");
109	end_name = strstr(buff_p, "_STATS");
110	name_size = end_name - name - strlen("TEST_MTX_") + 1;
111
112	char name_string[50];
113	char avg_name_string[60];
114	char *pre_string = "contended loop ";
115	snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
116	pre_string = "avg time contended loop ";
117	snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
118	T_PERF(name_string, avg/ITER, "ns", avg_name_string);
119
120	free(buff);
121	}
122
123	static void
124	test_from_kernel_lock_unlock_uncontended(void)
125	{
126	int i, ret, name_size;
127	uint64_t avg, run, tot;
128	size_t size;
129	char iter[35];
130	char buff, buff_p, avg_p, name, *end_name;
131
132	T_LOG("Testing locking/unlocking mutex from kernel without contention.\n");
133	T_LOG("Requesting test with %d iterations\n", ITER);
134
135	size = 2000;
136	buff = calloc(size, sizeof(char));
137	T_QUIET;T_ASSERT_NOTNULL(buff, "Allocating buffer fo sysctl");
138
139	snprintf(iter, sizeof(iter), "%d", ITER);
140	ret = sysctlbyname("kern.test_mtx_uncontended", buff, &size, iter, sizeof(iter));
141	T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname kern.test_mtx_uncontended");
142
143	T_LOG("%s stats:\n%s\n", __func__, buff);
144
145	/* first line is "STATS INNER LOOP" */
146	buff_p = buff;
147	while( *buff_p != '\n' ) buff_p++;
148	buff_p++;
149
150	/*
151	* Sequence of statistic lines like
152	* { samples 100000, tot 3586175 ns, avg 35 ns, max 3997 ns, min 33 ns } TEST_MTX_LOCK_STATS
153	* for all TEST_MTX_MAX_STATS statistics
154	*/
155	for (i = 0; i < TEST_MTX_MAX_STATS; i++) {
156	avg_p = strstr(buff_p, "avg ");
157	T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %i average not found", i);
158	sscanf(avg_p, "avg %llu", &avg);
159
160	name = strstr(buff_p, "TEST_MTX_");
161	end_name = strstr(buff_p, "_STATS");
162	name_size = end_name - name - strlen("TEST_MTX_") + 1;
163
164	char name_string[40];
165	char avg_name_string[50];
166	char *pre_string = "uncontended ";
167	snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
168	pre_string = "avg time uncontended ";
169	snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
170	T_PERF(name_string, avg, "ns", avg_name_string);
171
172	buff_p = avg_p;
173	while( *buff_p != '\n' ) buff_p++;
174	buff_p++;
175	}
176
177	while( *buff_p != '\n' ) buff_p++;
178	buff_p++;
179
180	/* next line is "STATS OUTER LOOP" */
181	while( *buff_p != '\n' ) buff_p++;
182	buff_p++;
183
184	/*
185	* Sequence of statistic lines like
186	* total time 4040673 ns total run time 3981080 ns TEST_MTX_LOCK_STATS
187	* for all TEST_MTX_MAX_STATS statistics exept UNLOCK
188	*/
189	for (i = 0; i < TEST_MTX_MAX_STATS - 2; i++) {
190	avg_p = strstr(buff_p, "run time ");
191	T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %d loop run time not found", i);
192	sscanf(avg_p, "run time %llu", &run);
193
194	avg_p = strstr(buff_p, "total time ");
195	T_QUIET;T_ASSERT_NOTNULL(avg_p, "uncontended %d loop total time not found", i);
196	sscanf(avg_p, "total time %llu", &tot);
197
198	if (run < tot)
199	avg = run;
200	else
201	avg = tot;
202
203	name = strstr(buff_p, "TEST_MTX_");
204	end_name = strstr(buff_p, "_STATS");
205	name_size = end_name - name - strlen("TEST_MTX_") + 1;
206
207	char name_string[50];
208	char avg_name_string[60];
209	char *pre_string = "uncontended loop ";
210	snprintf(name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
211	pre_string = "avg time uncontended loop ";
212	snprintf(avg_name_string, name_size + strlen(pre_string), "%s%s", pre_string, &name[strlen("TEST_MTX_")]);
213	T_PERF(name_string, avg/ITER, "ns", avg_name_string);
214
215	buff_p = avg_p;
216	while( *buff_p != '\n' ) buff_p++;
217	buff_p++;
218
219	}
220	free(buff);
221	}
222
223	extern char **environ;
224	static void
225	fix_cpu_frequency(void)
226	{
227	#if CONFIG_EMBEDDED
228	int spawn_ret, pid;
229	char *const clpcctrl_args[] = {"/usr/local/bin/clpcctrl", "-f", "5000", NULL};
230
231	T_LOG("Setting cpu frequency to %d\n", 5000);
232
233	spawn_ret = posix_spawn(&pid, clpcctrl_args[0], NULL, NULL, clpcctrl_args, environ);
234	waitpid(pid, &spawn_ret, 0);
235
236	#else /CONFIG_EMBEDDED/
237
238	int spawn_ret, pid;
239	int ret, nom_freq;
240	size_t len;
241	float val;
242	char scale;
243	char buffer, cpu_freq;
244	char str_val[10];
245
246	ret = sysctlbyname("machdep.cpu.brand_string", NULL, &len, NULL, 0);
247	T_QUIET;T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
248
249	buffer = malloc(len+2);
250	ret = sysctlbyname("machdep.cpu.brand_string", buffer, &len, NULL, 0);
251	T_QUIET;T_ASSERT_POSIX_SUCCESS(ret, "sysctlbyname machdep.cpu.brand_string");
252	buffer[len+1] = '\0';
253
254	cpu_freq = strstr(buffer, "CPU @ ");
255	if (cpu_freq == NULL) {
256	T_LOG("Could not fix frequency, %s field not present\n", "CPU @ ");
257	goto out;
258	}
259
260	if (strstr(cpu_freq, "Hz") != NULL) {
261	sscanf(cpu_freq, "CPU @ %f%cHz", &val, &scale);
262	} else {
263	if (strstr(cpu_freq, "hz") != NULL) {
264	sscanf(cpu_freq, "CPU @ %f%chz", &val, &scale);
265	} else {
266	T_LOG("Could not fix frequency, %s field not present\n", "Hz");
267	goto out;
268	}
269	}
270
271	switch(scale){
272	case 'M':
273	case 'm':
274	nom_freq = (int) val;
275	break;
276	case 'G':
277	case 'g':
278	nom_freq = (int) (val*1000);
279	break;
280	default:
281	T_LOG("Could not fix frequency, scale field is %c\n", scale);
282	goto out;
283	}
284
285	snprintf(str_val, 10, "%d", nom_freq);
286	T_LOG("Setting min and max cpu frequency to %d (%s)\n", nom_freq, str_val);
287	char *xcpm_args[] = {"/usr/local/bin/xcpm", "limits", str_val, str_val, NULL};
288	spawn_ret = posix_spawn(&pid, xcpm_args[0], NULL, NULL, xcpm_args, environ);
289	waitpid(pid, &spawn_ret, 0);
290
291	out:
292	free(buffer);
293	return;
294	#endif /CONFIG_EMBEDDED/
295	}
296
297	T_DECL(kernel_mtx_perf_test,
298	"Kernel mutex performance test",
299	T_META_ASROOT(YES), T_META_CHECK_LEAKS(NO))
300	{
301	fix_cpu_frequency();
302
303	test_from_kernel_lock_unlock_uncontended();
304	test_from_kernel_lock_unlock_contended();
305	}
306