1 // SPDX-License-Identifier: LGPL-2.1
2 /*
3 * Copyright (C) 2020, VMware, Tzvetomir Stoyanov <tz.stoyanov@gmail.com>
4 *
5 */
6 #include <stdio.h>
7 #include <stdlib.h>
8 #include <fcntl.h>
9 #include <unistd.h>
10 #include <time.h>
11 #include <dirent.h>
12 #include <unistd.h>
13 #include <ctype.h>
14 #include <sys/stat.h>
15 #include <sys/wait.h>
16 #include <sys/types.h>
17
18 #include <CUnit/CUnit.h>
19 #include <CUnit/Basic.h>
20
21 #include <trace-cmd.h>
22
23 #include "trace-utest.h"
24
25 #ifndef PATH_MAX
26 #define PATH_MAX 1024
27 #endif
28
29 static char tracecmd_exec[PATH_MAX];
30
31 #define TRACECMD_SUITE "trace-cmd"
32 #define TRACECMD_FILE "__trace_test__.dat"
33 #define TRACECMD_FILE2 "__trace_test__2.dat"
34 #define TRACECMD_OUT "-o", TRACECMD_FILE
35 #define TRACECMD_OUT2 "-o", TRACECMD_FILE2
36 #define TRACECMD_IN "-i", TRACECMD_FILE
37 #define TRACECMD_IN2 "-i", TRACECMD_FILE2
38
39 #define TRACECMD_SQL_HIST "SELECT irq FROM irq_handler_entry"
40 #define TRACECMD_SQL_READ_HIST "show", "--hist", "irq_handler_entry"
41
42 #define SYNTH_EVENT "wakeup"
43 #define TRACECMD_SQL_SYNTH "-e", "-n", SYNTH_EVENT, "SELECT start.pid AS this_pid, (end.TIMESTAMP_USECS - start.TIMESTAMP_USECS) AS delta FROM sched_waking as start JOIN sched_switch AS end ON start.pid = end.next_pid"
44 #define TRACECMD_SQL_START_SYNTH "start", "-e", SYNTH_EVENT
45
get_args(const char * cmd,va_list ap)46 static char **get_args(const char *cmd, va_list ap)
47 {
48 const char *param;
49 char **argv;
50 char **tmp;
51
52 argv = tracefs_list_add(NULL, tracecmd_exec);
53 if (!argv)
54 return NULL;
55
56 tmp = tracefs_list_add(argv, cmd);
57 if (!tmp)
58 goto fail;
59 argv = tmp;
60
61 for (param = va_arg(ap, const char *);
62 param; param = va_arg(ap, const char *)) {
63 tmp = tracefs_list_add(argv, param);
64 if (!tmp)
65 goto fail;
66 argv = tmp;
67 }
68
69 return argv;
70 fail:
71 tracefs_list_free(argv);
72 return NULL;
73 }
74
silent_output(void)75 static void silent_output(void)
76 {
77 close(STDOUT_FILENO);
78 open("/dev/null", O_WRONLY);
79 close(STDERR_FILENO);
80 open("/dev/null", O_WRONLY);
81 }
82
wait_for_exec(int pid)83 static int wait_for_exec(int pid)
84 {
85 int status;
86 int ret;
87
88 ret = waitpid(pid, &status, 0);
89 if (ret != pid)
90 return -1;
91
92 return WEXITSTATUS(status) ? -1 : 0;
93 }
94
run_trace(const char * cmd,...)95 static int run_trace(const char *cmd, ...)
96 {
97 char **argv;
98 va_list ap;
99 int ret = -1;
100 pid_t pid;
101
102 va_start(ap, cmd);
103 argv = get_args(cmd, ap);
104 va_end(ap);
105
106 if (!argv)
107 return -1;
108
109 pid = fork();
110 if (pid < 0)
111 goto out;
112
113 if (!pid) {
114 if (!show_output)
115 silent_output();
116 ret = execvp(tracecmd_exec, argv);
117 exit (ret);
118 }
119
120 ret = wait_for_exec(pid);
121 out:
122 tracefs_list_free(argv);
123 return ret;
124 }
125
pipe_it(int * ofd,int * efd,int (* func)(void *),void * data)126 static int pipe_it(int *ofd, int *efd, int (*func)(void *),
127 void *data)
128 {
129 int obrass[2];
130 int ebrass[2];
131 pid_t pid;
132 int ret;
133
134 if (pipe(obrass) < 0)
135 return -1;
136
137 if (pipe(ebrass) < 0)
138 goto fail_out;
139
140 pid = fork();
141 if (pid < 0)
142 goto fail;
143
144 if (!pid) {
145 char shret[32];
146
147 close(obrass[0]);
148 close(STDOUT_FILENO);
149 if (dup2(obrass[1], STDOUT_FILENO) < 0)
150 exit(-1);
151
152 close(ebrass[0]);
153 close(STDERR_FILENO);
154 if (dup2(obrass[1], STDERR_FILENO) < 0)
155 exit(-1);
156
157 ret = func(data);
158
159 /*
160 * valgrind triggers its reports when the application
161 * exits. If the application does a fork() and the child
162 * exits, it will still trigger the valgrind report for
163 * all the allocations that were not freed by the parent.
164 *
165 * To prevent valgrind from triggering, do an execl() on
166 * a basic shell that will simply exit with the return value.
167 * This will quiet valgrind from reporting memory that has
168 * been allocated by the parent up to here.
169 */
170 snprintf(shret, 32, "exit %d", ret);
171 execl("/usr/bin/sh", "/usr/bin/sh", "-c", shret, NULL);
172 execl("/bin/sh", "/bin/sh", "-c", shret, NULL);
173
174 /* If the above execl() fails, simply do an exit */
175 exit(ret);
176 }
177
178 close(obrass[1]);
179 close(ebrass[1]);
180
181 *ofd = obrass[0];
182 *efd = ebrass[0];
183
184 return pid;
185
186 fail:
187 close(ebrass[0]);
188 close(ebrass[1]);
189 fail_out:
190 close(obrass[0]);
191 close(obrass[1]);
192 return -1;
193 }
194
195 struct do_grep {
196 const char *cmd;
197 va_list *ap;
198 };
199
do_grep(void * data)200 static int do_grep(void *data)
201 {
202 struct do_grep *gdata = data;
203 char **argv;
204 int ret;
205
206 argv = get_args(gdata->cmd, *gdata->ap);
207 if (!argv)
208 exit(-1);
209
210 ret = execvp(tracecmd_exec, argv);
211 tracefs_list_free(argv);
212 return ret;
213 }
214
215 struct do_grep_it {
216 const char *match;
217 const char *cmd;
218 va_list *ap;
219 };
220
do_grep_it(void * data)221 static int do_grep_it(void *data)
222 {
223 struct do_grep_it *dgdata = data;
224 struct do_grep gdata;
225 FILE *fp;
226 regex_t reg;
227 char *buf = NULL;
228 ssize_t n;
229 size_t l = 0;
230 int ofd;
231 int efd;
232 int pid;
233 int ret;
234
235 if (regcomp(®, dgdata->match, REG_ICASE|REG_NOSUB))
236 return -1;
237
238 gdata.cmd = dgdata->cmd;
239 gdata.ap = dgdata->ap;
240 pid = pipe_it(&ofd, &efd, do_grep, &gdata);
241
242 if (pid < 0) {
243 regfree(®);
244 return -1;
245 }
246
247 fp = fdopen(ofd, "r");
248 if (!fp)
249 goto out;
250
251 do {
252 n = getline(&buf, &l, fp);
253 if (n > 0 && regexec(®, buf, 0, NULL, 0) == 0)
254 printf("%s", buf);
255 } while (n >= 0);
256
257 free(buf);
258 out:
259 ret = wait_for_exec(pid);
260 if (fp)
261 fclose(fp);
262 else
263 perror("fp");
264 close(ofd);
265 close(efd);
266 regfree(®);
267
268 return ret > 0 ? 0 : ret;
269 }
270
271 struct do_grep_match {
272 const char *match;
273 const char *cmd;
274 va_list *ap;
275 };
276
grep_match(const char * match,const char * cmd,...)277 static int grep_match(const char *match, const char *cmd, ...)
278 {
279 struct do_grep_it gdata;
280 FILE *fp;
281 va_list ap;
282 char *buf = NULL;
283 ssize_t n;
284 size_t l = 0;
285 bool found = false;
286 int ofd;
287 int efd;
288 int pid;
289 int ret;
290
291 va_start(ap, cmd);
292 gdata.match = match;
293 gdata.cmd = cmd;
294 gdata.ap = ≈
295 pid = pipe_it(&ofd, &efd, do_grep_it, &gdata);
296 va_end(ap);
297
298 if (pid < 0)
299 return -1;
300
301 fp = fdopen(ofd, "r");
302 if (!fp)
303 goto out;
304
305 do {
306 n = getline(&buf, &l, fp);
307 if (n > 0) {
308 if (show_output)
309 printf("%s", buf);
310 found = true;
311 }
312 } while (n >= 0);
313
314 free(buf);
315 out:
316 ret = wait_for_exec(pid);
317 if (ret)
318 n = 1;
319 if (fp)
320 fclose(fp);
321 else {
322 perror("fp");
323 close(ofd);
324 }
325 close(efd);
326
327 return found ? 0 : 1;
328 }
329
test_trace_record_report(void)330 static void test_trace_record_report(void)
331 {
332 int ret;
333
334 ret = run_trace("record", TRACECMD_OUT, "-e", "sched", "sleep", "1", NULL);
335 CU_TEST(ret == 0);
336 ret = run_trace("convert", "--file-version", "6", TRACECMD_IN, TRACECMD_OUT2, NULL);
337 CU_TEST(ret == 0);
338 }
339
test_trace_sqlhist_hist(void)340 static void test_trace_sqlhist_hist(void)
341 {
342 int ret;
343
344 ret = run_trace("sqlhist", "-e", TRACECMD_SQL_HIST, NULL);
345 CU_TEST(ret == 0);
346 ret = grep_match(" *Hits: [0-9][0-9]*", TRACECMD_SQL_READ_HIST, NULL);
347 CU_TEST(ret == 0);
348 ret = run_trace("sqlhist", TRACECMD_SQL_SYNTH, NULL);
349 CU_TEST(ret == 0);
350 ret = run_trace(TRACECMD_SQL_START_SYNTH, NULL);
351 CU_TEST(ret == 0);
352 sleep(1);
353 ret = grep_match(SYNTH_EVENT ":", "show", NULL);
354 CU_TEST(ret == 0);
355
356 tracefs_instance_reset(NULL);
357 }
358
read_stats(const char * out,const char * match,const char * cmd,...)359 static int read_stats(const char *out, const char *match, const char *cmd, ...)
360 {
361 struct do_grep_it gdata;
362 FILE *fp;
363 va_list ap;
364 bool found = false;
365 char *buf = NULL;
366 char *p;
367 ssize_t n;
368 size_t l = 0;
369 int ofd;
370 int efd;
371 int pid;
372 int ret;
373 int val;
374
375 va_start(ap, cmd);
376 gdata.match = match;
377 gdata.cmd = cmd;
378 gdata.ap = ≈
379 pid = pipe_it(&ofd, &efd, do_grep_it, &gdata);
380 va_end(ap);
381
382 if (pid < 0)
383 return -1;
384
385 fp = fdopen(ofd, "r");
386 if (!fp)
387 goto out;
388
389 do {
390 n = getline(&buf, &l, fp);
391 if (n > 0) {
392 for (p = buf; isspace(*p); p++)
393 ;
394 val = atoi(p);
395 found = true;
396 if (show_output)
397 printf("%s", buf);
398 CU_TEST(val < 10000000);
399 }
400 } while (n >= 0);
401
402 free(buf);
403 out:
404 ret = wait_for_exec(pid);
405 if (fp)
406 fclose(fp);
407 else {
408 perror("fp");
409 }
410 if (!found)
411 ret = -1;
412 close(ofd);
413 close(efd);
414 return ret > 0 ? 0 : ret;
415 }
416
test_trace_record_max(void)417 static void test_trace_record_max(void)
418 {
419 int ret;
420
421 ret = run_trace("record", TRACECMD_OUT, "-p", "function", "-m", "5000",
422 "sleep", "10", NULL);
423 CU_TEST(ret == 0);
424
425 ret = read_stats(TRACECMD_FILE, ".*bytes in size.*", "report", TRACECMD_IN, "--stat", NULL);
426 CU_TEST(ret == 0);
427 }
428
test_trace_convert6(void)429 static void test_trace_convert6(void)
430 {
431 struct stat st;
432 int ret;
433
434 /* If the trace data is already created, just use it, otherwise make it again */
435 if (stat(TRACECMD_FILE, &st) < 0) {
436 ret = run_trace("record", TRACECMD_OUT, "-e", "sched", "sleep", "1", NULL);
437 CU_TEST(ret == 0);
438 }
439 ret = grep_match("[ \t]6[ \t]*\\[Version\\]", "dump", TRACECMD_IN2, NULL);
440 CU_TEST(ret == 0);
441 }
442
443 struct callback_data {
444 long counter;
445 struct trace_seq seq;
446 };
447
read_events(struct tracecmd_input * handle,struct tep_record * record,int cpu,void * data)448 static int read_events(struct tracecmd_input *handle, struct tep_record *record,
449 int cpu, void *data)
450 {
451 struct tep_handle *tep = tracecmd_get_tep(handle);
452 struct callback_data *cd = data;
453 struct trace_seq *seq = &cd->seq;
454
455 cd->counter++;
456
457 trace_seq_reset(seq);
458 tep_print_event(tep, seq, record, "%6.1000d", TEP_PRINT_TIME);
459 trace_seq_printf(seq, " [%03d] ", cpu);
460 tep_print_event(tep, seq, record, "%s-%d %s %s\n",
461 TEP_PRINT_COMM, TEP_PRINT_PID,
462 TEP_PRINT_NAME, TEP_PRINT_INFO);
463 if (show_output)
464 trace_seq_do_printf(seq);
465 return 0;
466 }
467
read_events_10(struct tracecmd_input * handle,struct tep_record * record,int cpu,void * data)468 static int read_events_10(struct tracecmd_input *handle, struct tep_record *record,
469 int cpu, void *data)
470 {
471 struct callback_data *cd = data;
472
473 read_events(handle, record, cpu, data);
474 return cd->counter < 10 ? 0 : 1;
475 }
476
test_trace_library_read(void)477 static void test_trace_library_read(void)
478 {
479 struct tracecmd_input *handle;
480 struct callback_data data;
481 struct stat st;
482 int ret;
483
484 data.counter = 0;
485 trace_seq_init(&data.seq);
486
487 /* If the trace data is already created, just use it, otherwise make it again */
488 if (stat(TRACECMD_FILE, &st) < 0) {
489 ret = run_trace("record", TRACECMD_OUT, "-e", "sched", "sleep", "1", NULL);
490 CU_TEST(ret == 0);
491 }
492
493 handle = tracecmd_open(TRACECMD_FILE, 0);
494 CU_TEST(handle != NULL);
495 ret = tracecmd_iterate_events(handle, NULL, 0, read_events, &data);
496 CU_TEST(ret == 0);
497
498 tracecmd_close(handle);
499
500 CU_TEST(data.counter > 0);
501 trace_seq_destroy(&data.seq);
502 }
503
test_trace_library_read_inc(void)504 static void test_trace_library_read_inc(void)
505 {
506 struct tracecmd_input *handle;
507 struct callback_data data;
508 struct stat st;
509 long save_count;
510 long total = 0;
511 int ret;
512
513 data.counter = 0;
514 trace_seq_init(&data.seq);
515
516 /* If the trace data is already created, just use it, otherwise make it again */
517 if (stat(TRACECMD_FILE, &st) < 0) {
518 ret = run_trace("record", TRACECMD_OUT, "-e", "sched", "sleep", "1", NULL);
519 CU_TEST(ret == 0);
520 }
521
522 /* First read all again */
523 handle = tracecmd_open(TRACECMD_FILE, 0);
524 CU_TEST(handle != NULL);
525 ret = tracecmd_iterate_events(handle, NULL, 0, read_events, &data);
526 CU_TEST(ret == 0);
527 CU_TEST(data.counter > 0);
528
529 /* Save the counter */
530 save_count = data.counter;
531
532 tracecmd_iterate_reset(handle);
533
534 /* Read 10 at a time */
535 do {
536 data.counter = 0;
537 ret = tracecmd_iterate_events(handle, NULL, 0, read_events_10, &data);
538 CU_TEST(ret >= 0);
539 CU_TEST(data.counter <= 10);
540 total += data.counter;
541 } while (data.counter);
542 CU_TEST(ret == 0);
543
544 CU_TEST(total == save_count);
545
546 trace_seq_destroy(&data.seq);
547 tracecmd_close(handle);
548 }
549
test_trace_library_read_back(void)550 static void test_trace_library_read_back(void)
551 {
552 struct tracecmd_input *handle;
553 struct callback_data data;
554 struct stat st;
555 long save_count;
556 int ret;
557
558 data.counter = 0;
559 trace_seq_init(&data.seq);
560
561 /* If the trace data is already created, just use it, otherwise make it again */
562 if (stat(TRACECMD_FILE, &st) < 0) {
563 ret = run_trace("record", TRACECMD_OUT, "-e", "sched", "sleep", "1", NULL);
564 CU_TEST(ret == 0);
565 }
566
567 /* First read all again */
568 handle = tracecmd_open(TRACECMD_FILE, 0);
569 CU_TEST(handle != NULL);
570 ret = tracecmd_iterate_events(handle, NULL, 0, read_events, &data);
571 CU_TEST(ret == 0);
572 CU_TEST(data.counter > 0);
573
574 /* Save the counter */
575 save_count = data.counter;
576
577 tracecmd_iterate_reset(handle);
578
579 /* Read backwards */
580 data.counter = 0;
581 ret = tracecmd_iterate_events_reverse(handle, NULL, 0, read_events, &data, false);
582 CU_TEST(ret == 0);
583 CU_TEST(data.counter == save_count);
584
585 /* Read forward again */
586 data.counter = 0;
587 ret = tracecmd_iterate_events(handle, NULL, 0, read_events, &data);
588 CU_TEST(ret == 0);
589 CU_TEST(data.counter == save_count);
590
591 /* Read backwards from where we left off */
592 data.counter = 0;
593 ret = tracecmd_iterate_events_reverse(handle, NULL, 0, read_events, &data, true);
594 CU_TEST(ret == 0);
595 CU_TEST(data.counter == save_count);
596
597 trace_seq_destroy(&data.seq);
598 tracecmd_close(handle);
599 }
600
test_suite_destroy(void)601 static int test_suite_destroy(void)
602 {
603 unlink(TRACECMD_FILE);
604 unlink(TRACECMD_FILE2);
605 return 0;
606 }
607
test_suite_init(void)608 static int test_suite_init(void)
609 {
610 struct stat st;
611 const char *p;
612
613 /* The test must be in the utest directory */
614 for (p = argv0 + strlen(argv0) - 1; p > argv0 && *p != '/'; p--)
615 ;
616
617 if (*p == '/')
618 snprintf(tracecmd_exec, PATH_MAX, "%.*s/../tracecmd/trace-cmd",
619 (int)(p - argv0), argv0);
620 else
621 strncpy(tracecmd_exec, "../tracecmd/trace-cmd", PATH_MAX);
622
623 if (stat(tracecmd_exec, &st) < 0) {
624 fprintf(stderr, "In tree trace-cmd executable not found\n");
625 return 1;
626 }
627
628 if (!(st.st_mode & (S_IXUSR | S_IXGRP | S_IXOTH))) {
629 fprintf(stderr, "In tree trace-cmd executable not executable\n");
630 return 1;
631 }
632
633 return 0;
634 }
635
test_tracecmd_lib(void)636 void test_tracecmd_lib(void)
637 {
638 CU_pSuite suite = NULL;
639
640 suite = CU_add_suite(TRACECMD_SUITE, test_suite_init, test_suite_destroy);
641 if (suite == NULL) {
642 fprintf(stderr, "Suite \"%s\" cannot be ceated\n", TRACECMD_SUITE);
643 return;
644 }
645 CU_add_test(suite, "Simple record and report",
646 test_trace_record_report);
647 CU_add_test(suite, "Create a histogram",
648 test_trace_sqlhist_hist);
649 CU_add_test(suite, "Test convert from v7 to v6",
650 test_trace_convert6);
651 CU_add_test(suite, "Use libraries to read file",
652 test_trace_library_read);
653 CU_add_test(suite, "Use libraries to read file incremental",
654 test_trace_library_read_inc);
655 CU_add_test(suite, "Use libraries to read file backwards",
656 test_trace_library_read_back);
657 CU_add_test(suite, "Test max length",
658 test_trace_record_max);
659 }
660