Merge branch 'tip/tracing/ftrace' of git://git.kernel.org/pub/scm/linux/kernel/git...
[linux-2.6-block.git] / kernel / trace / trace_selftest.c
CommitLineData
60a11774
SR
1/* Include in trace.c */
2
9cc26a26 3#include <linux/stringify.h>
60a11774 4#include <linux/kthread.h>
c7aafc54 5#include <linux/delay.h>
60a11774 6
e309b41d 7static inline int trace_valid_entry(struct trace_entry *entry)
60a11774
SR
8{
9 switch (entry->type) {
10 case TRACE_FN:
11 case TRACE_CTX:
57422797 12 case TRACE_WAKE:
06fa75ab 13 case TRACE_STACK:
dd0e545f 14 case TRACE_PRINT:
06fa75ab 15 case TRACE_SPECIAL:
80e5ea45 16 case TRACE_BRANCH:
7447dce9
FW
17 case TRACE_GRAPH_ENT:
18 case TRACE_GRAPH_RET:
60a11774
SR
19 return 1;
20 }
21 return 0;
22}
23
3928a8a2 24static int trace_test_buffer_cpu(struct trace_array *tr, int cpu)
60a11774 25{
3928a8a2
SR
26 struct ring_buffer_event *event;
27 struct trace_entry *entry;
4b3e3d22 28 unsigned int loops = 0;
60a11774 29
3928a8a2
SR
30 while ((event = ring_buffer_consume(tr->buffer, cpu, NULL))) {
31 entry = ring_buffer_event_data(event);
60a11774 32
4b3e3d22
SR
33 /*
34 * The ring buffer is a size of trace_buf_size, if
35 * we loop more than the size, there's something wrong
36 * with the ring buffer.
37 */
38 if (loops++ > trace_buf_size) {
39 printk(KERN_CONT ".. bad ring buffer ");
40 goto failed;
41 }
3928a8a2 42 if (!trace_valid_entry(entry)) {
c7aafc54 43 printk(KERN_CONT ".. invalid entry %d ",
3928a8a2 44 entry->type);
60a11774
SR
45 goto failed;
46 }
60a11774 47 }
60a11774
SR
48 return 0;
49
50 failed:
08bafa0e
SR
51 /* disable tracing */
52 tracing_disabled = 1;
60a11774
SR
53 printk(KERN_CONT ".. corrupted trace buffer .. ");
54 return -1;
55}
56
57/*
58 * Test the trace buffer to see if all the elements
59 * are still sane.
60 */
61static int trace_test_buffer(struct trace_array *tr, unsigned long *count)
62{
30afdcb1
SR
63 unsigned long flags, cnt = 0;
64 int cpu, ret = 0;
60a11774 65
30afdcb1 66 /* Don't allow flipping of max traces now */
d51ad7ac 67 local_irq_save(flags);
30afdcb1 68 __raw_spin_lock(&ftrace_max_lock);
60a11774 69
3928a8a2 70 cnt = ring_buffer_entries(tr->buffer);
60a11774 71
0c5119c1
SR
72 /*
73 * The trace_test_buffer_cpu runs a while loop to consume all data.
74 * If the calling tracer is broken, and is constantly filling
75 * the buffer, this will run forever, and hard lock the box.
76 * We disable the ring buffer while we do this test to prevent
77 * a hard lock up.
78 */
79 tracing_off();
3928a8a2
SR
80 for_each_possible_cpu(cpu) {
81 ret = trace_test_buffer_cpu(tr, cpu);
60a11774
SR
82 if (ret)
83 break;
84 }
0c5119c1 85 tracing_on();
30afdcb1 86 __raw_spin_unlock(&ftrace_max_lock);
d51ad7ac 87 local_irq_restore(flags);
60a11774
SR
88
89 if (count)
90 *count = cnt;
91
92 return ret;
93}
94
1c80025a
FW
95static inline void warn_failed_init_tracer(struct tracer *trace, int init_ret)
96{
97 printk(KERN_WARNING "Failed to init %s tracer, init returned %d\n",
98 trace->name, init_ret);
99}
606576ce 100#ifdef CONFIG_FUNCTION_TRACER
77a2b37d
SR
101
102#ifdef CONFIG_DYNAMIC_FTRACE
103
77a2b37d
SR
104/* Test dynamic code modification and ftrace filters */
105int trace_selftest_startup_dynamic_tracing(struct tracer *trace,
106 struct trace_array *tr,
107 int (*func)(void))
108{
77a2b37d
SR
109 int save_ftrace_enabled = ftrace_enabled;
110 int save_tracer_enabled = tracer_enabled;
dd0e545f 111 unsigned long count;
4e491d14 112 char *func_name;
dd0e545f 113 int ret;
77a2b37d
SR
114
115 /* The ftrace test PASSED */
116 printk(KERN_CONT "PASSED\n");
117 pr_info("Testing dynamic ftrace: ");
118
119 /* enable tracing, and record the filter function */
120 ftrace_enabled = 1;
121 tracer_enabled = 1;
122
123 /* passed in by parameter to fool gcc from optimizing */
124 func();
125
4e491d14 126 /*
73d8b8bc 127 * Some archs *cough*PowerPC*cough* add characters to the
4e491d14 128 * start of the function names. We simply put a '*' to
73d8b8bc 129 * accommodate them.
4e491d14 130 */
9cc26a26 131 func_name = "*" __stringify(DYN_FTRACE_TEST_NAME);
4e491d14 132
77a2b37d 133 /* filter only on our function */
4e491d14 134 ftrace_set_filter(func_name, strlen(func_name), 1);
77a2b37d
SR
135
136 /* enable tracing */
b6f11df2 137 ret = tracer_init(trace, tr);
1c80025a
FW
138 if (ret) {
139 warn_failed_init_tracer(trace, ret);
140 goto out;
141 }
dd0e545f 142
77a2b37d
SR
143 /* Sleep for a 1/10 of a second */
144 msleep(100);
145
146 /* we should have nothing in the buffer */
147 ret = trace_test_buffer(tr, &count);
148 if (ret)
149 goto out;
150
151 if (count) {
152 ret = -1;
153 printk(KERN_CONT ".. filter did not filter .. ");
154 goto out;
155 }
156
157 /* call our function again */
158 func();
159
160 /* sleep again */
161 msleep(100);
162
163 /* stop the tracing. */
bbf5b1a0 164 tracing_stop();
77a2b37d
SR
165 ftrace_enabled = 0;
166
167 /* check the trace buffer */
168 ret = trace_test_buffer(tr, &count);
169 trace->reset(tr);
bbf5b1a0 170 tracing_start();
77a2b37d
SR
171
172 /* we should only have one item */
173 if (!ret && count != 1) {
06fa75ab 174 printk(KERN_CONT ".. filter failed count=%ld ..", count);
77a2b37d
SR
175 ret = -1;
176 goto out;
177 }
bbf5b1a0 178
77a2b37d
SR
179 out:
180 ftrace_enabled = save_ftrace_enabled;
181 tracer_enabled = save_tracer_enabled;
182
183 /* Enable tracing on all functions again */
184 ftrace_set_filter(NULL, 0, 1);
185
186 return ret;
187}
188#else
189# define trace_selftest_startup_dynamic_tracing(trace, tr, func) ({ 0; })
190#endif /* CONFIG_DYNAMIC_FTRACE */
60a11774
SR
191/*
192 * Simple verification test of ftrace function tracer.
193 * Enable ftrace, sleep 1/10 second, and then read the trace
194 * buffer to see if all is in order.
195 */
196int
197trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
198{
77a2b37d
SR
199 int save_ftrace_enabled = ftrace_enabled;
200 int save_tracer_enabled = tracer_enabled;
dd0e545f
SR
201 unsigned long count;
202 int ret;
60a11774 203
77a2b37d
SR
204 /* make sure msleep has been recorded */
205 msleep(1);
206
60a11774 207 /* start the tracing */
c7aafc54 208 ftrace_enabled = 1;
77a2b37d 209 tracer_enabled = 1;
c7aafc54 210
b6f11df2 211 ret = tracer_init(trace, tr);
1c80025a
FW
212 if (ret) {
213 warn_failed_init_tracer(trace, ret);
214 goto out;
215 }
216
60a11774
SR
217 /* Sleep for a 1/10 of a second */
218 msleep(100);
219 /* stop the tracing. */
bbf5b1a0 220 tracing_stop();
c7aafc54
IM
221 ftrace_enabled = 0;
222
60a11774
SR
223 /* check the trace buffer */
224 ret = trace_test_buffer(tr, &count);
225 trace->reset(tr);
bbf5b1a0 226 tracing_start();
60a11774
SR
227
228 if (!ret && !count) {
229 printk(KERN_CONT ".. no entries found ..");
230 ret = -1;
77a2b37d 231 goto out;
60a11774
SR
232 }
233
77a2b37d
SR
234 ret = trace_selftest_startup_dynamic_tracing(trace, tr,
235 DYN_FTRACE_TEST_NAME);
236
237 out:
238 ftrace_enabled = save_ftrace_enabled;
239 tracer_enabled = save_tracer_enabled;
240
4eebcc81
SR
241 /* kill ftrace totally if we failed */
242 if (ret)
243 ftrace_kill();
244
60a11774
SR
245 return ret;
246}
606576ce 247#endif /* CONFIG_FUNCTION_TRACER */
60a11774 248
7447dce9
FW
249
250#ifdef CONFIG_FUNCTION_GRAPH_TRACER
251/*
252 * Pretty much the same than for the function tracer from which the selftest
253 * has been borrowed.
254 */
255int
256trace_selftest_startup_function_graph(struct tracer *trace,
257 struct trace_array *tr)
258{
259 int ret;
260 unsigned long count;
261
262 ret = tracer_init(trace, tr);
263 if (ret) {
264 warn_failed_init_tracer(trace, ret);
265 goto out;
266 }
267
268 /* Sleep for a 1/10 of a second */
269 msleep(100);
270
271 tracing_stop();
272
273 /* check the trace buffer */
274 ret = trace_test_buffer(tr, &count);
275
276 trace->reset(tr);
277 tracing_start();
278
279 if (!ret && !count) {
280 printk(KERN_CONT ".. no entries found ..");
281 ret = -1;
282 goto out;
283 }
284
285 /* Don't test dynamic tracing, the function tracer already did */
286
287out:
288 /* Stop it if we failed */
289 if (ret)
290 ftrace_graph_stop();
291
292 return ret;
293}
294#endif /* CONFIG_FUNCTION_GRAPH_TRACER */
295
296
60a11774
SR
297#ifdef CONFIG_IRQSOFF_TRACER
298int
299trace_selftest_startup_irqsoff(struct tracer *trace, struct trace_array *tr)
300{
301 unsigned long save_max = tracing_max_latency;
302 unsigned long count;
303 int ret;
304
305 /* start the tracing */
b6f11df2 306 ret = tracer_init(trace, tr);
1c80025a
FW
307 if (ret) {
308 warn_failed_init_tracer(trace, ret);
309 return ret;
310 }
311
60a11774
SR
312 /* reset the max latency */
313 tracing_max_latency = 0;
314 /* disable interrupts for a bit */
315 local_irq_disable();
316 udelay(100);
317 local_irq_enable();
318 /* stop the tracing. */
bbf5b1a0 319 tracing_stop();
60a11774
SR
320 /* check both trace buffers */
321 ret = trace_test_buffer(tr, NULL);
322 if (!ret)
323 ret = trace_test_buffer(&max_tr, &count);
324 trace->reset(tr);
bbf5b1a0 325 tracing_start();
60a11774
SR
326
327 if (!ret && !count) {
328 printk(KERN_CONT ".. no entries found ..");
329 ret = -1;
330 }
331
332 tracing_max_latency = save_max;
333
334 return ret;
335}
336#endif /* CONFIG_IRQSOFF_TRACER */
337
338#ifdef CONFIG_PREEMPT_TRACER
339int
340trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr)
341{
342 unsigned long save_max = tracing_max_latency;
343 unsigned long count;
344 int ret;
345
769c48eb
SR
346 /*
347 * Now that the big kernel lock is no longer preemptable,
348 * and this is called with the BKL held, it will always
349 * fail. If preemption is already disabled, simply
350 * pass the test. When the BKL is removed, or becomes
351 * preemptible again, we will once again test this,
352 * so keep it in.
353 */
354 if (preempt_count()) {
355 printk(KERN_CONT "can not test ... force ");
356 return 0;
357 }
358
60a11774 359 /* start the tracing */
b6f11df2 360 ret = tracer_init(trace, tr);
1c80025a
FW
361 if (ret) {
362 warn_failed_init_tracer(trace, ret);
363 return ret;
364 }
365
60a11774
SR
366 /* reset the max latency */
367 tracing_max_latency = 0;
368 /* disable preemption for a bit */
369 preempt_disable();
370 udelay(100);
371 preempt_enable();
372 /* stop the tracing. */
bbf5b1a0 373 tracing_stop();
60a11774
SR
374 /* check both trace buffers */
375 ret = trace_test_buffer(tr, NULL);
376 if (!ret)
377 ret = trace_test_buffer(&max_tr, &count);
378 trace->reset(tr);
bbf5b1a0 379 tracing_start();
60a11774
SR
380
381 if (!ret && !count) {
382 printk(KERN_CONT ".. no entries found ..");
383 ret = -1;
384 }
385
386 tracing_max_latency = save_max;
387
388 return ret;
389}
390#endif /* CONFIG_PREEMPT_TRACER */
391
392#if defined(CONFIG_IRQSOFF_TRACER) && defined(CONFIG_PREEMPT_TRACER)
393int
394trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *tr)
395{
396 unsigned long save_max = tracing_max_latency;
397 unsigned long count;
398 int ret;
399
769c48eb
SR
400 /*
401 * Now that the big kernel lock is no longer preemptable,
402 * and this is called with the BKL held, it will always
403 * fail. If preemption is already disabled, simply
404 * pass the test. When the BKL is removed, or becomes
405 * preemptible again, we will once again test this,
406 * so keep it in.
407 */
408 if (preempt_count()) {
409 printk(KERN_CONT "can not test ... force ");
410 return 0;
411 }
412
60a11774 413 /* start the tracing */
b6f11df2 414 ret = tracer_init(trace, tr);
1c80025a
FW
415 if (ret) {
416 warn_failed_init_tracer(trace, ret);
ac1d52d0 417 goto out_no_start;
1c80025a 418 }
60a11774
SR
419
420 /* reset the max latency */
421 tracing_max_latency = 0;
422
423 /* disable preemption and interrupts for a bit */
424 preempt_disable();
425 local_irq_disable();
426 udelay(100);
427 preempt_enable();
428 /* reverse the order of preempt vs irqs */
429 local_irq_enable();
430
431 /* stop the tracing. */
bbf5b1a0 432 tracing_stop();
60a11774
SR
433 /* check both trace buffers */
434 ret = trace_test_buffer(tr, NULL);
ac1d52d0 435 if (ret)
60a11774
SR
436 goto out;
437
438 ret = trace_test_buffer(&max_tr, &count);
ac1d52d0 439 if (ret)
60a11774
SR
440 goto out;
441
442 if (!ret && !count) {
443 printk(KERN_CONT ".. no entries found ..");
444 ret = -1;
445 goto out;
446 }
447
448 /* do the test by disabling interrupts first this time */
449 tracing_max_latency = 0;
bbf5b1a0 450 tracing_start();
60a11774
SR
451 preempt_disable();
452 local_irq_disable();
453 udelay(100);
454 preempt_enable();
455 /* reverse the order of preempt vs irqs */
456 local_irq_enable();
457
458 /* stop the tracing. */
bbf5b1a0 459 tracing_stop();
60a11774
SR
460 /* check both trace buffers */
461 ret = trace_test_buffer(tr, NULL);
462 if (ret)
463 goto out;
464
465 ret = trace_test_buffer(&max_tr, &count);
466
467 if (!ret && !count) {
468 printk(KERN_CONT ".. no entries found ..");
469 ret = -1;
470 goto out;
471 }
472
ac1d52d0 473out:
bbf5b1a0 474 tracing_start();
ac1d52d0
FW
475out_no_start:
476 trace->reset(tr);
60a11774
SR
477 tracing_max_latency = save_max;
478
479 return ret;
480}
481#endif /* CONFIG_IRQSOFF_TRACER && CONFIG_PREEMPT_TRACER */
482
fb1b6d8b
SN
483#ifdef CONFIG_NOP_TRACER
484int
485trace_selftest_startup_nop(struct tracer *trace, struct trace_array *tr)
486{
487 /* What could possibly go wrong? */
488 return 0;
489}
490#endif
491
60a11774
SR
492#ifdef CONFIG_SCHED_TRACER
493static int trace_wakeup_test_thread(void *data)
494{
60a11774 495 /* Make this a RT thread, doesn't need to be too high */
05bd68c5
SR
496 struct sched_param param = { .sched_priority = 5 };
497 struct completion *x = data;
60a11774 498
05bd68c5 499 sched_setscheduler(current, SCHED_FIFO, &param);
60a11774
SR
500
501 /* Make it know we have a new prio */
502 complete(x);
503
504 /* now go to sleep and let the test wake us up */
505 set_current_state(TASK_INTERRUPTIBLE);
506 schedule();
507
508 /* we are awake, now wait to disappear */
509 while (!kthread_should_stop()) {
510 /*
511 * This is an RT task, do short sleeps to let
512 * others run.
513 */
514 msleep(100);
515 }
516
517 return 0;
518}
519
520int
521trace_selftest_startup_wakeup(struct tracer *trace, struct trace_array *tr)
522{
523 unsigned long save_max = tracing_max_latency;
524 struct task_struct *p;
525 struct completion isrt;
526 unsigned long count;
527 int ret;
528
529 init_completion(&isrt);
530
531 /* create a high prio thread */
532 p = kthread_run(trace_wakeup_test_thread, &isrt, "ftrace-test");
c7aafc54 533 if (IS_ERR(p)) {
60a11774
SR
534 printk(KERN_CONT "Failed to create ftrace wakeup test thread ");
535 return -1;
536 }
537
538 /* make sure the thread is running at an RT prio */
539 wait_for_completion(&isrt);
540
541 /* start the tracing */
b6f11df2 542 ret = tracer_init(trace, tr);
1c80025a
FW
543 if (ret) {
544 warn_failed_init_tracer(trace, ret);
545 return ret;
546 }
547
60a11774
SR
548 /* reset the max latency */
549 tracing_max_latency = 0;
550
551 /* sleep to let the RT thread sleep too */
552 msleep(100);
553
554 /*
555 * Yes this is slightly racy. It is possible that for some
556 * strange reason that the RT thread we created, did not
557 * call schedule for 100ms after doing the completion,
558 * and we do a wakeup on a task that already is awake.
559 * But that is extremely unlikely, and the worst thing that
560 * happens in such a case, is that we disable tracing.
561 * Honestly, if this race does happen something is horrible
562 * wrong with the system.
563 */
564
565 wake_up_process(p);
566
5aa60c60
SR
567 /* give a little time to let the thread wake up */
568 msleep(100);
569
60a11774 570 /* stop the tracing. */
bbf5b1a0 571 tracing_stop();
60a11774
SR
572 /* check both trace buffers */
573 ret = trace_test_buffer(tr, NULL);
574 if (!ret)
575 ret = trace_test_buffer(&max_tr, &count);
576
577
578 trace->reset(tr);
bbf5b1a0 579 tracing_start();
60a11774
SR
580
581 tracing_max_latency = save_max;
582
583 /* kill the thread */
584 kthread_stop(p);
585
586 if (!ret && !count) {
587 printk(KERN_CONT ".. no entries found ..");
588 ret = -1;
589 }
590
591 return ret;
592}
593#endif /* CONFIG_SCHED_TRACER */
594
595#ifdef CONFIG_CONTEXT_SWITCH_TRACER
596int
597trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr)
598{
599 unsigned long count;
600 int ret;
601
602 /* start the tracing */
b6f11df2 603 ret = tracer_init(trace, tr);
1c80025a
FW
604 if (ret) {
605 warn_failed_init_tracer(trace, ret);
606 return ret;
607 }
608
60a11774
SR
609 /* Sleep for a 1/10 of a second */
610 msleep(100);
611 /* stop the tracing. */
bbf5b1a0 612 tracing_stop();
60a11774
SR
613 /* check the trace buffer */
614 ret = trace_test_buffer(tr, &count);
615 trace->reset(tr);
bbf5b1a0 616 tracing_start();
60a11774
SR
617
618 if (!ret && !count) {
619 printk(KERN_CONT ".. no entries found ..");
620 ret = -1;
621 }
622
623 return ret;
624}
625#endif /* CONFIG_CONTEXT_SWITCH_TRACER */
a6dd24f8
IM
626
627#ifdef CONFIG_SYSPROF_TRACER
628int
629trace_selftest_startup_sysprof(struct tracer *trace, struct trace_array *tr)
630{
631 unsigned long count;
632 int ret;
633
634 /* start the tracing */
b6f11df2 635 ret = tracer_init(trace, tr);
1c80025a
FW
636 if (ret) {
637 warn_failed_init_tracer(trace, ret);
d2ef7c2f 638 return ret;
1c80025a
FW
639 }
640
a6dd24f8
IM
641 /* Sleep for a 1/10 of a second */
642 msleep(100);
643 /* stop the tracing. */
bbf5b1a0 644 tracing_stop();
a6dd24f8
IM
645 /* check the trace buffer */
646 ret = trace_test_buffer(tr, &count);
647 trace->reset(tr);
bbf5b1a0 648 tracing_start();
a6dd24f8 649
d2ef7c2f
WH
650 if (!ret && !count) {
651 printk(KERN_CONT ".. no entries found ..");
652 ret = -1;
653 }
654
a6dd24f8
IM
655 return ret;
656}
657#endif /* CONFIG_SYSPROF_TRACER */
80e5ea45
SR
658
659#ifdef CONFIG_BRANCH_TRACER
660int
661trace_selftest_startup_branch(struct tracer *trace, struct trace_array *tr)
662{
663 unsigned long count;
664 int ret;
665
666 /* start the tracing */
b6f11df2 667 ret = tracer_init(trace, tr);
1c80025a
FW
668 if (ret) {
669 warn_failed_init_tracer(trace, ret);
670 return ret;
671 }
672
80e5ea45
SR
673 /* Sleep for a 1/10 of a second */
674 msleep(100);
675 /* stop the tracing. */
676 tracing_stop();
677 /* check the trace buffer */
678 ret = trace_test_buffer(tr, &count);
679 trace->reset(tr);
680 tracing_start();
681
d2ef7c2f
WH
682 if (!ret && !count) {
683 printk(KERN_CONT ".. no entries found ..");
684 ret = -1;
685 }
686
80e5ea45
SR
687 return ret;
688}
689#endif /* CONFIG_BRANCH_TRACER */