xref: /linux/tools/testing/selftests/user_events/ftrace_test.c (revision c532de5a67a70f8533d495f8f2aaa9a0491c3ad0)
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 
21 const char *data_file = "/sys/kernel/tracing/user_events_data";
22 const char *status_file = "/sys/kernel/tracing/user_events_status";
23 const char *enable_file = "/sys/kernel/tracing/events/user_events/__test_event/enable";
24 const char *trace_file = "/sys/kernel/tracing/trace";
25 const char *fmt_file = "/sys/kernel/tracing/events/user_events/__test_event/format";
26 
27 static 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 
53 static 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 
72 static 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;
100 err:
101 	fclose(fp);
102 
103 	return -1;
104 }
105 
106 static 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 
123 static 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;
152 fail:
153 	close(fd);
154 
155 	return -1;
156 }
157 
158 static 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 
202 FIXTURE(user) {
203 	int status_fd;
204 	int data_fd;
205 	int enable_fd;
206 	int check;
207 	bool umount;
208 };
209 
210 FIXTURE_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 
222 FIXTURE_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 
237 TEST_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 
306 TEST_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 
364 TEST_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 
397 TEST_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 
434 TEST_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 
505 TEST_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 
594 int main(int argc, char **argv)
595 {
596 	return test_harness_run(argc, argv);
597 }
598