xref: /linux/tools/testing/selftests/user_events/ftrace_test.c (revision 576d7fed09c7edbae7600f29a8a3ed6c1ead904f)
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 	/* Multiple registers to same name but different args should fail */
265 	reg.enable_bit = 29;
266 	reg.name_args = (__u64)"__test_event u32 field1;";
267 	ASSERT_EQ(-1, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
268 	ASSERT_EQ(EADDRINUSE, errno);
269 
270 	/* Ensure disabled */
271 	self->enable_fd = open(enable_file, O_RDWR);
272 	ASSERT_NE(-1, self->enable_fd);
273 	ASSERT_NE(-1, write(self->enable_fd, "0", sizeof("0")))
274 
275 	/* Enable event and ensure bits updated in status */
276 	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
277 	ASSERT_EQ(1 << reg.enable_bit, self->check);
278 
279 	/* Disable event and ensure bits updated in status */
280 	ASSERT_NE(-1, write(self->enable_fd, "0", sizeof("0")))
281 	ASSERT_EQ(0, self->check);
282 
283 	/* File still open should return -EBUSY for delete */
284 	ASSERT_EQ(-1, ioctl(self->data_fd, DIAG_IOCSDEL, "__test_event"));
285 	ASSERT_EQ(EBUSY, errno);
286 
287 	/* Unregister */
288 	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSUNREG, &unreg));
289 	unreg.disable_bit = 30;
290 	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSUNREG, &unreg));
291 
292 	/* Delete should have been auto-done after close and unregister */
293 	close(self->data_fd);
294 
295 	ASSERT_EQ(true, wait_for_delete());
296 }
297 
298 TEST_F(user, write_events) {
299 	struct user_reg reg = {0};
300 	struct iovec io[3];
301 	__u32 field1, field2;
302 	int before = 0, after = 0;
303 
304 	reg.size = sizeof(reg);
305 	reg.name_args = (__u64)"__test_event u32 field1; u32 field2";
306 	reg.enable_bit = 31;
307 	reg.enable_addr = (__u64)&self->check;
308 	reg.enable_size = sizeof(self->check);
309 
310 	field1 = 1;
311 	field2 = 2;
312 
313 	io[0].iov_base = &reg.write_index;
314 	io[0].iov_len = sizeof(reg.write_index);
315 	io[1].iov_base = &field1;
316 	io[1].iov_len = sizeof(field1);
317 	io[2].iov_base = &field2;
318 	io[2].iov_len = sizeof(field2);
319 
320 	/* Register should work */
321 	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
322 	ASSERT_EQ(0, reg.write_index);
323 	ASSERT_EQ(0, self->check);
324 
325 	/* Write should fail on invalid slot with ENOENT */
326 	io[0].iov_base = &field2;
327 	io[0].iov_len = sizeof(field2);
328 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
329 	ASSERT_EQ(ENOENT, errno);
330 	io[0].iov_base = &reg.write_index;
331 	io[0].iov_len = sizeof(reg.write_index);
332 
333 	/* Write should return -EBADF when event is not enabled */
334 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
335 	ASSERT_EQ(EBADF, errno);
336 
337 	/* Enable event */
338 	self->enable_fd = open(enable_file, O_RDWR);
339 	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
340 
341 	/* Event should now be enabled */
342 	ASSERT_NE(1 << reg.enable_bit, self->check);
343 
344 	/* Write should make it out to ftrace buffers */
345 	before = trace_bytes();
346 	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 3));
347 	after = trace_bytes();
348 	ASSERT_GT(after, before);
349 
350 	/* Negative index should fail with EINVAL */
351 	reg.write_index = -1;
352 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
353 	ASSERT_EQ(EINVAL, errno);
354 }
355 
356 TEST_F(user, write_empty_events) {
357 	struct user_reg reg = {0};
358 	struct iovec io[1];
359 	int before = 0, after = 0;
360 
361 	reg.size = sizeof(reg);
362 	reg.name_args = (__u64)"__test_event";
363 	reg.enable_bit = 31;
364 	reg.enable_addr = (__u64)&self->check;
365 	reg.enable_size = sizeof(self->check);
366 
367 	io[0].iov_base = &reg.write_index;
368 	io[0].iov_len = sizeof(reg.write_index);
369 
370 	/* Register should work */
371 	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
372 	ASSERT_EQ(0, reg.write_index);
373 	ASSERT_EQ(0, self->check);
374 
375 	/* Enable event */
376 	self->enable_fd = open(enable_file, O_RDWR);
377 	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
378 
379 	/* Event should now be enabled */
380 	ASSERT_EQ(1 << reg.enable_bit, self->check);
381 
382 	/* Write should make it out to ftrace buffers */
383 	before = trace_bytes();
384 	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 1));
385 	after = trace_bytes();
386 	ASSERT_GT(after, before);
387 }
388 
389 TEST_F(user, write_fault) {
390 	struct user_reg reg = {0};
391 	struct iovec io[2];
392 	int l = sizeof(__u64);
393 	void *anon;
394 
395 	reg.size = sizeof(reg);
396 	reg.name_args = (__u64)"__test_event u64 anon";
397 	reg.enable_bit = 31;
398 	reg.enable_addr = (__u64)&self->check;
399 	reg.enable_size = sizeof(self->check);
400 
401 	anon = mmap(NULL, l, PROT_READ, MAP_PRIVATE | MAP_ANONYMOUS, -1, 0);
402 	ASSERT_NE(MAP_FAILED, anon);
403 
404 	io[0].iov_base = &reg.write_index;
405 	io[0].iov_len = sizeof(reg.write_index);
406 	io[1].iov_base = anon;
407 	io[1].iov_len = l;
408 
409 	/* Register should work */
410 	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
411 	ASSERT_EQ(0, reg.write_index);
412 
413 	/* Enable event */
414 	self->enable_fd = open(enable_file, O_RDWR);
415 	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
416 
417 	/* Write should work normally */
418 	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 2));
419 
420 	/* Faulted data should zero fill and work */
421 	ASSERT_EQ(0, madvise(anon, l, MADV_DONTNEED));
422 	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 2));
423 	ASSERT_EQ(0, munmap(anon, l));
424 }
425 
426 TEST_F(user, write_validator) {
427 	struct user_reg reg = {0};
428 	struct iovec io[3];
429 	int loc, bytes;
430 	char data[8];
431 	int before = 0, after = 0;
432 
433 	reg.size = sizeof(reg);
434 	reg.name_args = (__u64)"__test_event __rel_loc char[] data";
435 	reg.enable_bit = 31;
436 	reg.enable_addr = (__u64)&self->check;
437 	reg.enable_size = sizeof(self->check);
438 
439 	/* Register should work */
440 	ASSERT_EQ(0, ioctl(self->data_fd, DIAG_IOCSREG, &reg));
441 	ASSERT_EQ(0, reg.write_index);
442 	ASSERT_EQ(0, self->check);
443 
444 	io[0].iov_base = &reg.write_index;
445 	io[0].iov_len = sizeof(reg.write_index);
446 	io[1].iov_base = &loc;
447 	io[1].iov_len = sizeof(loc);
448 	io[2].iov_base = data;
449 	bytes = snprintf(data, sizeof(data), "Test") + 1;
450 	io[2].iov_len = bytes;
451 
452 	/* Undersized write should fail */
453 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 1));
454 	ASSERT_EQ(EINVAL, errno);
455 
456 	/* Enable event */
457 	self->enable_fd = open(enable_file, O_RDWR);
458 	ASSERT_NE(-1, write(self->enable_fd, "1", sizeof("1")))
459 
460 	/* Event should now be enabled */
461 	ASSERT_EQ(1 << reg.enable_bit, self->check);
462 
463 	/* Full in-bounds write should work */
464 	before = trace_bytes();
465 	loc = DYN_LOC(0, bytes);
466 	ASSERT_NE(-1, writev(self->data_fd, (const struct iovec *)io, 3));
467 	after = trace_bytes();
468 	ASSERT_GT(after, before);
469 
470 	/* Out of bounds write should fault (offset way out) */
471 	loc = DYN_LOC(1024, bytes);
472 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
473 	ASSERT_EQ(EFAULT, errno);
474 
475 	/* Out of bounds write should fault (offset 1 byte out) */
476 	loc = DYN_LOC(1, bytes);
477 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
478 	ASSERT_EQ(EFAULT, errno);
479 
480 	/* Out of bounds write should fault (size way out) */
481 	loc = DYN_LOC(0, bytes + 1024);
482 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
483 	ASSERT_EQ(EFAULT, errno);
484 
485 	/* Out of bounds write should fault (size 1 byte out) */
486 	loc = DYN_LOC(0, bytes + 1);
487 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
488 	ASSERT_EQ(EFAULT, errno);
489 
490 	/* Non-Null should fault */
491 	memset(data, 'A', sizeof(data));
492 	loc = DYN_LOC(0, bytes);
493 	ASSERT_EQ(-1, writev(self->data_fd, (const struct iovec *)io, 3));
494 	ASSERT_EQ(EFAULT, errno);
495 }
496 
497 TEST_F(user, print_fmt) {
498 	int ret;
499 
500 	ret = check_print_fmt("__test_event __rel_loc char[] data",
501 			      "print fmt: \"data=%s\", __get_rel_str(data)",
502 			      &self->check);
503 	ASSERT_EQ(0, ret);
504 
505 	ret = check_print_fmt("__test_event __data_loc char[] data",
506 			      "print fmt: \"data=%s\", __get_str(data)",
507 			      &self->check);
508 	ASSERT_EQ(0, ret);
509 
510 	ret = check_print_fmt("__test_event s64 data",
511 			      "print fmt: \"data=%lld\", REC->data",
512 			      &self->check);
513 	ASSERT_EQ(0, ret);
514 
515 	ret = check_print_fmt("__test_event u64 data",
516 			      "print fmt: \"data=%llu\", REC->data",
517 			      &self->check);
518 	ASSERT_EQ(0, ret);
519 
520 	ret = check_print_fmt("__test_event s32 data",
521 			      "print fmt: \"data=%d\", REC->data",
522 			      &self->check);
523 	ASSERT_EQ(0, ret);
524 
525 	ret = check_print_fmt("__test_event u32 data",
526 			      "print fmt: \"data=%u\", REC->data",
527 			      &self->check);
528 	ASSERT_EQ(0, ret);
529 
530 	ret = check_print_fmt("__test_event int data",
531 			      "print fmt: \"data=%d\", REC->data",
532 			      &self->check);
533 	ASSERT_EQ(0, ret);
534 
535 	ret = check_print_fmt("__test_event unsigned int data",
536 			      "print fmt: \"data=%u\", REC->data",
537 			      &self->check);
538 	ASSERT_EQ(0, ret);
539 
540 	ret = check_print_fmt("__test_event s16 data",
541 			      "print fmt: \"data=%d\", REC->data",
542 			      &self->check);
543 	ASSERT_EQ(0, ret);
544 
545 	ret = check_print_fmt("__test_event u16 data",
546 			      "print fmt: \"data=%u\", REC->data",
547 			      &self->check);
548 	ASSERT_EQ(0, ret);
549 
550 	ret = check_print_fmt("__test_event short data",
551 			      "print fmt: \"data=%d\", REC->data",
552 			      &self->check);
553 	ASSERT_EQ(0, ret);
554 
555 	ret = check_print_fmt("__test_event unsigned short data",
556 			      "print fmt: \"data=%u\", REC->data",
557 			      &self->check);
558 	ASSERT_EQ(0, ret);
559 
560 	ret = check_print_fmt("__test_event s8 data",
561 			      "print fmt: \"data=%d\", REC->data",
562 			      &self->check);
563 	ASSERT_EQ(0, ret);
564 
565 	ret = check_print_fmt("__test_event u8 data",
566 			      "print fmt: \"data=%u\", REC->data",
567 			      &self->check);
568 	ASSERT_EQ(0, ret);
569 
570 	ret = check_print_fmt("__test_event char data",
571 			      "print fmt: \"data=%d\", REC->data",
572 			      &self->check);
573 	ASSERT_EQ(0, ret);
574 
575 	ret = check_print_fmt("__test_event unsigned char data",
576 			      "print fmt: \"data=%u\", REC->data",
577 			      &self->check);
578 	ASSERT_EQ(0, ret);
579 
580 	ret = check_print_fmt("__test_event char[4] data",
581 			      "print fmt: \"data=%s\", REC->data",
582 			      &self->check);
583 	ASSERT_EQ(0, ret);
584 }
585 
586 int main(int argc, char **argv)
587 {
588 	return test_harness_run(argc, argv);
589 }
590