tracing/ftrace: fix double calls to tracing_start()
[safe/jmp/linux-2.6] / kernel / trace / trace_selftest.c
1 /* Include in trace.c */
2
3 #include <linux/stringify.h>
4 #include <linux/kthread.h>
5 #include <linux/delay.h>
6
7 static inline int trace_valid_entry(struct trace_entry *entry)
8 {
9         switch (entry->type) {
10         case TRACE_FN:
11         case TRACE_CTX:
12         case TRACE_WAKE:
13         case TRACE_STACK:
14         case TRACE_PRINT:
15         case TRACE_SPECIAL:
16         case TRACE_BRANCH:
17         case TRACE_GRAPH_ENT:
18         case TRACE_GRAPH_RET:
19                 return 1;
20         }
21         return 0;
22 }
23
24 static int trace_test_buffer_cpu(struct trace_array *tr, int cpu)
25 {
26         struct ring_buffer_event *event;
27         struct trace_entry *entry;
28         unsigned int loops = 0;
29
30         while ((event = ring_buffer_consume(tr->buffer, cpu, NULL))) {
31                 entry = ring_buffer_event_data(event);
32
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                 }
42                 if (!trace_valid_entry(entry)) {
43                         printk(KERN_CONT ".. invalid entry %d ",
44                                 entry->type);
45                         goto failed;
46                 }
47         }
48         return 0;
49
50  failed:
51         /* disable tracing */
52         tracing_disabled = 1;
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  */
61 static int trace_test_buffer(struct trace_array *tr, unsigned long *count)
62 {
63         unsigned long flags, cnt = 0;
64         int cpu, ret = 0;
65
66         /* Don't allow flipping of max traces now */
67         local_irq_save(flags);
68         __raw_spin_lock(&ftrace_max_lock);
69
70         cnt = ring_buffer_entries(tr->buffer);
71
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();
80         for_each_possible_cpu(cpu) {
81                 ret = trace_test_buffer_cpu(tr, cpu);
82                 if (ret)
83                         break;
84         }
85         tracing_on();
86         __raw_spin_unlock(&ftrace_max_lock);
87         local_irq_restore(flags);
88
89         if (count)
90                 *count = cnt;
91
92         return ret;
93 }
94
95 static 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 }
100 #ifdef CONFIG_FUNCTION_TRACER
101
102 #ifdef CONFIG_DYNAMIC_FTRACE
103
104 /* Test dynamic code modification and ftrace filters */
105 int trace_selftest_startup_dynamic_tracing(struct tracer *trace,
106                                            struct trace_array *tr,
107                                            int (*func)(void))
108 {
109         int save_ftrace_enabled = ftrace_enabled;
110         int save_tracer_enabled = tracer_enabled;
111         unsigned long count;
112         char *func_name;
113         int ret;
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
126         /*
127          * Some archs *cough*PowerPC*cough* add characters to the
128          * start of the function names. We simply put a '*' to
129          * accommodate them.
130          */
131         func_name = "*" __stringify(DYN_FTRACE_TEST_NAME);
132
133         /* filter only on our function */
134         ftrace_set_filter(func_name, strlen(func_name), 1);
135
136         /* enable tracing */
137         ret = tracer_init(trace, tr);
138         if (ret) {
139                 warn_failed_init_tracer(trace, ret);
140                 goto out;
141         }
142
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. */
164         tracing_stop();
165         ftrace_enabled = 0;
166
167         /* check the trace buffer */
168         ret = trace_test_buffer(tr, &count);
169         trace->reset(tr);
170         tracing_start();
171
172         /* we should only have one item */
173         if (!ret && count != 1) {
174                 printk(KERN_CONT ".. filter failed count=%ld ..", count);
175                 ret = -1;
176                 goto out;
177         }
178
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 */
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  */
196 int
197 trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
198 {
199         int save_ftrace_enabled = ftrace_enabled;
200         int save_tracer_enabled = tracer_enabled;
201         unsigned long count;
202         int ret;
203
204         /* make sure msleep has been recorded */
205         msleep(1);
206
207         /* start the tracing */
208         ftrace_enabled = 1;
209         tracer_enabled = 1;
210
211         ret = tracer_init(trace, tr);
212         if (ret) {
213                 warn_failed_init_tracer(trace, ret);
214                 goto out;
215         }
216
217         /* Sleep for a 1/10 of a second */
218         msleep(100);
219         /* stop the tracing. */
220         tracing_stop();
221         ftrace_enabled = 0;
222
223         /* check the trace buffer */
224         ret = trace_test_buffer(tr, &count);
225         trace->reset(tr);
226         tracing_start();
227
228         if (!ret && !count) {
229                 printk(KERN_CONT ".. no entries found ..");
230                 ret = -1;
231                 goto out;
232         }
233
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
241         /* kill ftrace totally if we failed */
242         if (ret)
243                 ftrace_kill();
244
245         return ret;
246 }
247 #endif /* CONFIG_FUNCTION_TRACER */
248
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  */
255 int
256 trace_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
287 out:
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
297 #ifdef CONFIG_IRQSOFF_TRACER
298 int
299 trace_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 */
306         ret = tracer_init(trace, tr);
307         if (ret) {
308                 warn_failed_init_tracer(trace, ret);
309                 return ret;
310         }
311
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. */
319         tracing_stop();
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);
325         tracing_start();
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
339 int
340 trace_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
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
359         /* start the tracing */
360         ret = tracer_init(trace, tr);
361         if (ret) {
362                 warn_failed_init_tracer(trace, ret);
363                 return ret;
364         }
365
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. */
373         tracing_stop();
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);
379         tracing_start();
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)
393 int
394 trace_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
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
413         /* start the tracing */
414         ret = tracer_init(trace, tr);
415         if (ret) {
416                 warn_failed_init_tracer(trace, ret);
417                 goto out_no_start;
418         }
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. */
432         tracing_stop();
433         /* check both trace buffers */
434         ret = trace_test_buffer(tr, NULL);
435         if (ret)
436                 goto out;
437
438         ret = trace_test_buffer(&max_tr, &count);
439         if (ret)
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;
450         tracing_start();
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. */
459         tracing_stop();
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
473 out:
474         tracing_start();
475 out_no_start:
476         trace->reset(tr);
477         tracing_max_latency = save_max;
478
479         return ret;
480 }
481 #endif /* CONFIG_IRQSOFF_TRACER && CONFIG_PREEMPT_TRACER */
482
483 #ifdef CONFIG_NOP_TRACER
484 int
485 trace_selftest_startup_nop(struct tracer *trace, struct trace_array *tr)
486 {
487         /* What could possibly go wrong? */
488         return 0;
489 }
490 #endif
491
492 #ifdef CONFIG_SCHED_TRACER
493 static int trace_wakeup_test_thread(void *data)
494 {
495         /* Make this a RT thread, doesn't need to be too high */
496         struct sched_param param = { .sched_priority = 5 };
497         struct completion *x = data;
498
499         sched_setscheduler(current, SCHED_FIFO, &param);
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
520 int
521 trace_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");
533         if (IS_ERR(p)) {
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 */
542         ret = tracer_init(trace, tr);
543         if (ret) {
544                 warn_failed_init_tracer(trace, ret);
545                 return ret;
546         }
547
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
567         /* give a little time to let the thread wake up */
568         msleep(100);
569
570         /* stop the tracing. */
571         tracing_stop();
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);
579         tracing_start();
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
596 int
597 trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr)
598 {
599         unsigned long count;
600         int ret;
601
602         /* start the tracing */
603         ret = tracer_init(trace, tr);
604         if (ret) {
605                 warn_failed_init_tracer(trace, ret);
606                 return ret;
607         }
608
609         /* Sleep for a 1/10 of a second */
610         msleep(100);
611         /* stop the tracing. */
612         tracing_stop();
613         /* check the trace buffer */
614         ret = trace_test_buffer(tr, &count);
615         trace->reset(tr);
616         tracing_start();
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 */
626
627 #ifdef CONFIG_SYSPROF_TRACER
628 int
629 trace_selftest_startup_sysprof(struct tracer *trace, struct trace_array *tr)
630 {
631         unsigned long count;
632         int ret;
633
634         /* start the tracing */
635         ret = tracer_init(trace, tr);
636         if (ret) {
637                 warn_failed_init_tracer(trace, ret);
638                 return ret;
639         }
640
641         /* Sleep for a 1/10 of a second */
642         msleep(100);
643         /* stop the tracing. */
644         tracing_stop();
645         /* check the trace buffer */
646         ret = trace_test_buffer(tr, &count);
647         trace->reset(tr);
648         tracing_start();
649
650         if (!ret && !count) {
651                 printk(KERN_CONT ".. no entries found ..");
652                 ret = -1;
653         }
654
655         return ret;
656 }
657 #endif /* CONFIG_SYSPROF_TRACER */
658
659 #ifdef CONFIG_BRANCH_TRACER
660 int
661 trace_selftest_startup_branch(struct tracer *trace, struct trace_array *tr)
662 {
663         unsigned long count;
664         int ret;
665
666         /* start the tracing */
667         ret = tracer_init(trace, tr);
668         if (ret) {
669                 warn_failed_init_tracer(trace, ret);
670                 return ret;
671         }
672
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
682         if (!ret && !count) {
683                 printk(KERN_CONT ".. no entries found ..");
684                 ret = -1;
685         }
686
687         return ret;
688 }
689 #endif /* CONFIG_BRANCH_TRACER */