ftrace_test.c

  1// SPDX-License-Identifier: GPL-2.0
  2/*
  3 * User Events FTrace Test Program
  4 *
  5 * Copyright (c) 2021 Beau Belgrave <beaub@linux.microsoft.com>
  6 */
  7
  8#include <errno.h>
  9#include <linux/user_events.h>
 10#include <stdio.h>
 11#include <stdlib.h>
 12#include <fcntl.h>
 13#include <sys/ioctl.h>
 14#include <sys/stat.h>
 15#include <sys/uio.h>
 16#include <unistd.h>
 17
 18#include "kselftest_harness.h"
 19#include "user_events_selftests.h"
 20
 21const char *data_file = "/sys/kernel/tracing/user_events_data";
 22const char *status_file = "/sys/kernel/tracing/user_events_status";
 23const char *enable_file = "/sys/kernel/tracing/events/user_events/__test_event/enable";
 24const char *trace_file = "/sys/kernel/tracing/trace";
 25const char *fmt_file = "/sys/kernel/tracing/events/user_events/__test_event/format";
 26
 27static int trace_bytes(void)
 28{
 29	int fd = open(trace_file, O_RDONLY);
 30	char buf[256];
 31	int bytes = 0, got;
 32
 33	if (fd == -1)
 34		return -1;
 35
 36	while (true) {
 37		got = read(fd, buf, sizeof(buf));
 38
 39		if (got == -1)
 40			return -1;
 41
 42		if (got == 0)
 43			break;
 44
 45		bytes += got;
 46	}
 47
 48	close(fd);
 49
 50	return bytes;
 51}
 52
 53static int skip_until_empty_line(FILE *fp)
 54{
 55	int c, last = 0;
 56
 57	while (true) {
 58		c = getc(fp);
 59
 60		if (c == EOF)
 61			break;
 62
 63		if (last == '\n' && c == '\n')
 64			return 0;
 65
 66		last = c;
 67	}
 68
 69	return -1;
 70}
 71
 72static int get_print_fmt(char *buffer, int len)
 73{
 74	FILE *fp = fopen(fmt_file, "r");
 75	char *newline;
 76
 77	if (!fp)
 78		return -1;
 79
 80	/* Read until empty line (Skip Common) */
 81	if (skip_until_empty_line(fp) < 0)
 82		goto err;
 83
 84	/* Read until empty line (Skip Properties) */
 85	if (skip_until_empty_line(fp) < 0)
 86		goto err;
 87
 88	/* Read in print_fmt: */
 89	if (fgets(buffer, len, fp) == NULL)
 90		goto err;
 91
 92	newline = strchr(buffer, '\n');
 93
 94	if (newline)
 95		*newline = '\0';
 96
 97	fclose(fp);
 98
 99	return 0;
100err:
101	fclose(fp);
102
103	return -1;
104}
105
106static bool wait_for_delete(void)
107{
108	int i;
109
110	for (i = 0; i < 1000; ++i) {
111		int fd = open(enable_file, O_RDONLY);
112
113		if (fd == -1)
114			return true;
115
116		close(fd);
117		usleep(1000);
118	}
119
120	return false;
121}
122
123static int clear(int *check)
124{
125	struct user_unreg unreg = {0};
126	int fd;
127
128	unreg.size = sizeof(unreg);
129	unreg.disable_bit = 31;
130	unreg.disable_addr = (__u64)check;
131
132	fd = open(data_file, O_RDWR);
133
134	if (fd == -1)
135		return -1;
136
137	if (ioctl(fd, DIAG_IOCSUNREG, &unreg) == -1)
138		if (errno != ENOENT)
139			goto fail;
140
141	if (ioctl(fd, DIAG_IOCSDEL, "__test_event") == -1) {
142		if (errno == EBUSY) {
143			if (!wait_for_delete())
144				goto fail;
145		} else if (errno != ENOENT)
146			goto fail;
147	}
148
149	close(fd);
150
151	return 0;
152fail:
153	close(fd);
154
155	return -1;
156}
157
158static int check_print_fmt(const char *event, const char *expected, int *check)
159{
160	struct user_reg reg = {0};
161	char print_fmt[256];
162	int ret;
163	int fd;
164
165	/* Ensure cleared */
166	ret = clear(check);
167
168	if (ret != 0)
169		return ret;
170
171	fd = open(data_file, O_RDWR);
172
173	if (fd == -1)
174		return fd;
175
176	reg.size = sizeof(reg);
177	reg.name_args = (__u64)event;
178	reg.enable_bit = 31;
179	reg.enable_addr = (__u64)check;
180	reg.enable_size = sizeof(*check);
181
182	/* Register should work */
183	ret = ioctl(fd, DIAG_IOCSREG, &reg);
184
185	if (ret != 0) {
186		close(fd);
187		printf("Reg failed in fmt\n");
188		return ret;
189	}
190
191	/* Ensure correct print_fmt */
192	ret = get_print_fmt(print_fmt, sizeof(print_fmt));
193
194	close(fd);
195
196	if (ret != 0)
197		return ret;
198
199	return strcmp(print_fmt, expected);
200}
201
202FIXTURE(user) {
203	int status_fd;
204	int data_fd;
205	int enable_fd;
206	int check;
207	bool umount;
208};
209
210FIXTURE_SETUP(user) {
211	USER_EVENT_FIXTURE_SETUP(return, self->umount);
212
213	self->status_fd = open(status_file, O_RDONLY);
214	ASSERT_NE(-1, self->status_fd);
215
216	self->data_fd = open(data_file, O_RDWR);
217	ASSERT_NE(-1, self->data_fd);
218
219	self->enable_fd = -1;
220}
221
222FIXTURE_TEARDOWN(user) {
223	USER_EVENT_FIXTURE_TEARDOWN(self->umount);
224
225	close(self->status_fd);
226	close(self->data_fd);
227
228	if (self->enable_fd != -1) {
229		write(self->enable_fd, "0", sizeof("0"));
230		close(self->enable_fd);
231	}
232
233	if (clear(&self->check) != 0)
234		printf("WARNING: Clear didn't work!\n");
235}
236
237TEST_F(user, register_events) {
238	struct user_reg reg = {0};
239	struct user_unreg unreg = {0};
240
241	reg.size = sizeof(reg);
242	reg.name_args = (__u64)"__test_event u32 field1; u32 field2";
243	reg.enable_bit = 31;
244	reg.enable_addr = (__u64)&self->check;
245	reg.enable_size = sizeof(self->check);
246
247	unreg.size = sizeof(unreg);
248	unreg.disable_bit = 31;
249	unreg.disable_addr = (__u64)&self->check;
250
251	/* Register should work */
252	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
253	ASSERT_EQ(0, reg.write_index);
254
255	/* Multiple registers to the same addr + bit should fail */
256	ASSERT_EQ(-1, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
257	ASSERT_EQ(EADDRINUSE, errno);
258
259	/* Multiple registers to same name should result in same index */
260	reg.enable_bit = 30;
261	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
262	ASSERT_EQ(0, reg.write_index);
263
264	/* Register without separator spacing should still match */
265	reg.enable_bit = 29;
266	reg.name_args = (__u64)"__test_event u32 field1;u32 field2";
267	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
268	ASSERT_EQ(0, reg.write_index);
269
270	/* Multiple registers to same name but different args should fail */
271	reg.enable_bit = 29;
272	reg.name_args = (__u64)"__test_event u32 field1;";
273	ASSERT_EQ(-1, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
274	ASSERT_EQ(EADDRINUSE, errno);
275
276	/* Ensure disabled */
277	self->enable_fd = open(enable_file, O_RDWR);
278	ASSERT_NE(-1, self->enable_fd);
279	ASSERT_NE(-1, write(self->enable_fd, "0", sizeof("0")))
280
281	/* Enable event and ensure bits updated in status */
282	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
283	ASSERT_EQ(1 << reg.enable_bit, self->check);
284
285	/* Disable event and ensure bits updated in status */
286	ASSERT_NE(-1, write(self->enable_fd, "0", sizeof("0")))
287	ASSERT_EQ(0, self->check);
288
289	/* File still open should return -EBUSY for delete */
290	ASSERT_EQ(-1, ioctl(self->data_fd, DIAG_IOCSDEL, "__test_event"));
291	ASSERT_EQ(EBUSY, errno);
292
293	/* Unregister */
294	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSUNREG, &unreg));
295	unreg.disable_bit = 30;
296	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSUNREG, &unreg));
297	unreg.disable_bit = 29;
298	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSUNREG, &unreg));
299
300	/* Delete should have been auto-done after close and unregister */
301	close(self->data_fd);
302
303	ASSERT_EQ(true, wait_for_delete());
304}
305
306TEST_F(user, write_events) {
307	struct user_reg reg = {0};
308	struct iovec io[3];
309	__u32 field1, field2;
310	int before = 0, after = 0;
311
312	reg.size = sizeof(reg);
313	reg.name_args = (__u64)"__test_event u32 field1; u32 field2";
314	reg.enable_bit = 31;
315	reg.enable_addr = (__u64)&self->check;
316	reg.enable_size = sizeof(self->check);
317
318	field1 = 1;
319	field2 = 2;
320
321	io[0].iov_base = &reg.write_index;
322	io[0].iov_len = sizeof(reg.write_index);
323	io[1].iov_base = &field1;
324	io[1].iov_len = sizeof(field1);
325	io[2].iov_base = &field2;
326	io[2].iov_len = sizeof(field2);
327
328	/* Register should work */
329	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
330	ASSERT_EQ(0, reg.write_index);
331	ASSERT_EQ(0, self->check);
332
333	/* Write should fail on invalid slot with ENOENT */
334	io[0].iov_base = &field2;
335	io[0].iov_len = sizeof(field2);
336	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
337	ASSERT_EQ(ENOENT, errno);
338	io[0].iov_base = &reg.write_index;
339	io[0].iov_len = sizeof(reg.write_index);
340
341	/* Write should return -EBADF when event is not enabled */
342	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
343	ASSERT_EQ(EBADF, errno);
344
345	/* Enable event */
346	self->enable_fd = open(enable_file, O_RDWR);
347	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
348
349	/* Event should now be enabled */
350	ASSERT_NE(1 << reg.enable_bit, self->check);
351
352	/* Write should make it out to ftrace buffers */
353	before = trace_bytes();
354	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 3));
355	after = trace_bytes();
356	ASSERT_GT(after, before);
357
358	/* Negative index should fail with EINVAL */
359	reg.write_index = -1;
360	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
361	ASSERT_EQ(EINVAL, errno);
362}
363
364TEST_F(user, write_empty_events) {
365	struct user_reg reg = {0};
366	struct iovec io[1];
367	int before = 0, after = 0;
368
369	reg.size = sizeof(reg);
370	reg.name_args = (__u64)"__test_event";
371	reg.enable_bit = 31;
372	reg.enable_addr = (__u64)&self->check;
373	reg.enable_size = sizeof(self->check);
374
375	io[0].iov_base = &reg.write_index;
376	io[0].iov_len = sizeof(reg.write_index);
377
378	/* Register should work */
379	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
380	ASSERT_EQ(0, reg.write_index);
381	ASSERT_EQ(0, self->check);
382
383	/* Enable event */
384	self->enable_fd = open(enable_file, O_RDWR);
385	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
386
387	/* Event should now be enabled */
388	ASSERT_EQ(1 << reg.enable_bit, self->check);
389
390	/* Write should make it out to ftrace buffers */
391	before = trace_bytes();
392	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 1));
393	after = trace_bytes();
394	ASSERT_GT(after, before);
395}
396
397TEST_F(user, write_fault) {
398	struct user_reg reg = {0};
399	struct iovec io[2];
400	int l = sizeof(__u64);
401	void *anon;
402
403	reg.size = sizeof(reg);
404	reg.name_args = (__u64)"__test_event u64 anon";
405	reg.enable_bit = 31;
406	reg.enable_addr = (__u64)&self->check;
407	reg.enable_size = sizeof(self->check);
408
409	anon = mmap(NULL, l, PROT_READ, MAP_PRIVATE | MAP_ANONYMOUS, -1, 0);
410	ASSERT_NE(MAP_FAILED, anon);
411
412	io[0].iov_base = &reg.write_index;
413	io[0].iov_len = sizeof(reg.write_index);
414	io[1].iov_base = anon;
415	io[1].iov_len = l;
416
417	/* Register should work */
418	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
419	ASSERT_EQ(0, reg.write_index);
420
421	/* Enable event */
422	self->enable_fd = open(enable_file, O_RDWR);
423	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
424
425	/* Write should work normally */
426	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 2));
427
428	/* Faulted data should zero fill and work */
429	ASSERT_EQ(0, madvise(anon, l, MADV_DONTNEED));
430	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 2));
431	ASSERT_EQ(0, munmap(anon, l));
432}
433
434TEST_F(user, write_validator) {
435	struct user_reg reg = {0};
436	struct iovec io[3];
437	int loc, bytes;
438	char data[8];
439	int before = 0, after = 0;
440
441	reg.size = sizeof(reg);
442	reg.name_args = (__u64)"__test_event __rel_loc char[] data";
443	reg.enable_bit = 31;
444	reg.enable_addr = (__u64)&self->check;
445	reg.enable_size = sizeof(self->check);
446
447	/* Register should work */
448	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
449	ASSERT_EQ(0, reg.write_index);
450	ASSERT_EQ(0, self->check);
451
452	io[0].iov_base = &reg.write_index;
453	io[0].iov_len = sizeof(reg.write_index);
454	io[1].iov_base = &loc;
455	io[1].iov_len = sizeof(loc);
456	io[2].iov_base = data;
457	bytes = snprintf(data, sizeof(data), "Test") + 1;
458	io[2].iov_len = bytes;
459
460	/* Undersized write should fail */
461	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 1));
462	ASSERT_EQ(EINVAL, errno);
463
464	/* Enable event */
465	self->enable_fd = open(enable_file, O_RDWR);
466	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
467
468	/* Event should now be enabled */
469	ASSERT_EQ(1 << reg.enable_bit, self->check);
470
471	/* Full in-bounds write should work */
472	before = trace_bytes();
473	loc = DYN_LOC(0, bytes);
474	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 3));
475	after = trace_bytes();
476	ASSERT_GT(after, before);
477
478	/* Out of bounds write should fault (offset way out) */
479	loc = DYN_LOC(1024, bytes);
480	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
481	ASSERT_EQ(EFAULT, errno);
482
483	/* Out of bounds write should fault (offset 1 byte out) */
484	loc = DYN_LOC(1, bytes);
485	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
486	ASSERT_EQ(EFAULT, errno);
487
488	/* Out of bounds write should fault (size way out) */
489	loc = DYN_LOC(0, bytes + 1024);
490	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
491	ASSERT_EQ(EFAULT, errno);
492
493	/* Out of bounds write should fault (size 1 byte out) */
494	loc = DYN_LOC(0, bytes + 1);
495	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
496	ASSERT_EQ(EFAULT, errno);
497
498	/* Non-Null should fault */
499	memset(data, 'A', sizeof(data));
500	loc = DYN_LOC(0, bytes);
501	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
502	ASSERT_EQ(EFAULT, errno);
503}
504
505TEST_F(user, print_fmt) {
506	int ret;
507
508	ret = check_print_fmt("__test_event __rel_loc char[] data",
509			      "print fmt: \"data=%s\", __get_rel_str(data)",
510			      &self->check);
511	ASSERT_EQ(0, ret);
512
513	ret = check_print_fmt("__test_event __data_loc char[] data",
514			      "print fmt: \"data=%s\", __get_str(data)",
515			      &self->check);
516	ASSERT_EQ(0, ret);
517
518	ret = check_print_fmt("__test_event s64 data",
519			      "print fmt: \"data=%lld\", REC->data",
520			      &self->check);
521	ASSERT_EQ(0, ret);
522
523	ret = check_print_fmt("__test_event u64 data",
524			      "print fmt: \"data=%llu\", REC->data",
525			      &self->check);
526	ASSERT_EQ(0, ret);
527
528	ret = check_print_fmt("__test_event s32 data",
529			      "print fmt: \"data=%d\", REC->data",
530			      &self->check);
531	ASSERT_EQ(0, ret);
532
533	ret = check_print_fmt("__test_event u32 data",
534			      "print fmt: \"data=%u\", REC->data",
535			      &self->check);
536	ASSERT_EQ(0, ret);
537
538	ret = check_print_fmt("__test_event int data",
539			      "print fmt: \"data=%d\", REC->data",
540			      &self->check);
541	ASSERT_EQ(0, ret);
542
543	ret = check_print_fmt("__test_event unsigned int data",
544			      "print fmt: \"data=%u\", REC->data",
545			      &self->check);
546	ASSERT_EQ(0, ret);
547
548	ret = check_print_fmt("__test_event s16 data",
549			      "print fmt: \"data=%d\", REC->data",
550			      &self->check);
551	ASSERT_EQ(0, ret);
552
553	ret = check_print_fmt("__test_event u16 data",
554			      "print fmt: \"data=%u\", REC->data",
555			      &self->check);
556	ASSERT_EQ(0, ret);
557
558	ret = check_print_fmt("__test_event short data",
559			      "print fmt: \"data=%d\", REC->data",
560			      &self->check);
561	ASSERT_EQ(0, ret);
562
563	ret = check_print_fmt("__test_event unsigned short data",
564			      "print fmt: \"data=%u\", REC->data",
565			      &self->check);
566	ASSERT_EQ(0, ret);
567
568	ret = check_print_fmt("__test_event s8 data",
569			      "print fmt: \"data=%d\", REC->data",
570			      &self->check);
571	ASSERT_EQ(0, ret);
572
573	ret = check_print_fmt("__test_event u8 data",
574			      "print fmt: \"data=%u\", REC->data",
575			      &self->check);
576	ASSERT_EQ(0, ret);
577
578	ret = check_print_fmt("__test_event char data",
579			      "print fmt: \"data=%d\", REC->data",
580			      &self->check);
581	ASSERT_EQ(0, ret);
582
583	ret = check_print_fmt("__test_event unsigned char data",
584			      "print fmt: \"data=%u\", REC->data",
585			      &self->check);
586	ASSERT_EQ(0, ret);
587
588	ret = check_print_fmt("__test_event char[4] data",
589			      "print fmt: \"data=%s\", REC->data",
590			      &self->check);
591	ASSERT_EQ(0, ret);
592}
593
594int main(int argc, char **argv)
595{
596	return test_harness_run(argc, argv);
597}