1 /* Include in trace.c */
3 #include <linux/stringify.h>
4 #include <linux/kthread.h>
5 #include <linux/delay.h>
6 #include <linux/slab.h>
8 static inline int trace_valid_entry(struct trace_entry *entry)
10 switch (entry->type) {
24 static int trace_test_buffer_cpu(struct trace_array *tr, int cpu)
26 struct ring_buffer_event *event;
27 struct trace_entry *entry;
28 unsigned int loops = 0;
30 while ((event = ring_buffer_consume(tr->buffer, cpu, NULL, NULL))) {
31 entry = ring_buffer_event_data(event);
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.
38 if (loops++ > trace_buf_size) {
39 printk(KERN_CONT ".. bad ring buffer ");
42 if (!trace_valid_entry(entry)) {
43 printk(KERN_CONT ".. invalid entry %d ",
53 printk(KERN_CONT ".. corrupted trace buffer .. ");
58 * Test the trace buffer to see if all the elements
61 static int trace_test_buffer(struct trace_array *tr, unsigned long *count)
63 unsigned long flags, cnt = 0;
66 /* Don't allow flipping of max traces now */
67 local_irq_save(flags);
68 arch_spin_lock(&ftrace_max_lock);
70 cnt = ring_buffer_entries(tr->buffer);
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
80 for_each_possible_cpu(cpu) {
81 ret = trace_test_buffer_cpu(tr, cpu);
86 arch_spin_unlock(&ftrace_max_lock);
87 local_irq_restore(flags);
95 static inline void warn_failed_init_tracer(struct tracer *trace, int init_ret)
97 printk(KERN_WARNING "Failed to init %s tracer, init returned %d\n",
98 trace->name, init_ret);
100 #ifdef CONFIG_FUNCTION_TRACER
102 #ifdef CONFIG_DYNAMIC_FTRACE
104 static int trace_selftest_test_probe1_cnt;
105 static void trace_selftest_test_probe1_func(unsigned long ip,
107 struct ftrace_ops *op,
108 struct pt_regs *pt_regs)
110 trace_selftest_test_probe1_cnt++;
113 static int trace_selftest_test_probe2_cnt;
114 static void trace_selftest_test_probe2_func(unsigned long ip,
116 struct ftrace_ops *op,
117 struct pt_regs *pt_regs)
119 trace_selftest_test_probe2_cnt++;
122 static int trace_selftest_test_probe3_cnt;
123 static void trace_selftest_test_probe3_func(unsigned long ip,
125 struct ftrace_ops *op,
126 struct pt_regs *pt_regs)
128 trace_selftest_test_probe3_cnt++;
131 static int trace_selftest_test_global_cnt;
132 static void trace_selftest_test_global_func(unsigned long ip,
134 struct ftrace_ops *op,
135 struct pt_regs *pt_regs)
137 trace_selftest_test_global_cnt++;
140 static int trace_selftest_test_dyn_cnt;
141 static void trace_selftest_test_dyn_func(unsigned long ip,
143 struct ftrace_ops *op,
144 struct pt_regs *pt_regs)
146 trace_selftest_test_dyn_cnt++;
149 static struct ftrace_ops test_probe1 = {
150 .func = trace_selftest_test_probe1_func,
151 .flags = FTRACE_OPS_FL_RECURSION_SAFE,
154 static struct ftrace_ops test_probe2 = {
155 .func = trace_selftest_test_probe2_func,
156 .flags = FTRACE_OPS_FL_RECURSION_SAFE,
159 static struct ftrace_ops test_probe3 = {
160 .func = trace_selftest_test_probe3_func,
161 .flags = FTRACE_OPS_FL_RECURSION_SAFE,
164 static struct ftrace_ops test_global = {
165 .func = trace_selftest_test_global_func,
166 .flags = FTRACE_OPS_FL_GLOBAL | FTRACE_OPS_FL_RECURSION_SAFE,
169 static void print_counts(void)
171 printk("(%d %d %d %d %d) ",
172 trace_selftest_test_probe1_cnt,
173 trace_selftest_test_probe2_cnt,
174 trace_selftest_test_probe3_cnt,
175 trace_selftest_test_global_cnt,
176 trace_selftest_test_dyn_cnt);
179 static void reset_counts(void)
181 trace_selftest_test_probe1_cnt = 0;
182 trace_selftest_test_probe2_cnt = 0;
183 trace_selftest_test_probe3_cnt = 0;
184 trace_selftest_test_global_cnt = 0;
185 trace_selftest_test_dyn_cnt = 0;
188 static int trace_selftest_ops(int cnt)
190 int save_ftrace_enabled = ftrace_enabled;
191 struct ftrace_ops *dyn_ops;
198 printk(KERN_CONT "PASSED\n");
199 pr_info("Testing dynamic ftrace ops #%d: ", cnt);
204 /* Handle PPC64 '.' name */
205 func1_name = "*" __stringify(DYN_FTRACE_TEST_NAME);
206 func2_name = "*" __stringify(DYN_FTRACE_TEST_NAME2);
207 len1 = strlen(func1_name);
208 len2 = strlen(func2_name);
211 * Probe 1 will trace function 1.
212 * Probe 2 will trace function 2.
213 * Probe 3 will trace functions 1 and 2.
215 ftrace_set_filter(&test_probe1, func1_name, len1, 1);
216 ftrace_set_filter(&test_probe2, func2_name, len2, 1);
217 ftrace_set_filter(&test_probe3, func1_name, len1, 1);
218 ftrace_set_filter(&test_probe3, func2_name, len2, 0);
220 register_ftrace_function(&test_probe1);
221 register_ftrace_function(&test_probe2);
222 register_ftrace_function(&test_probe3);
223 register_ftrace_function(&test_global);
225 DYN_FTRACE_TEST_NAME();
229 if (trace_selftest_test_probe1_cnt != 1)
231 if (trace_selftest_test_probe2_cnt != 0)
233 if (trace_selftest_test_probe3_cnt != 1)
235 if (trace_selftest_test_global_cnt == 0)
238 DYN_FTRACE_TEST_NAME2();
242 if (trace_selftest_test_probe1_cnt != 1)
244 if (trace_selftest_test_probe2_cnt != 1)
246 if (trace_selftest_test_probe3_cnt != 2)
249 /* Add a dynamic probe */
250 dyn_ops = kzalloc(sizeof(*dyn_ops), GFP_KERNEL);
252 printk("MEMORY ERROR ");
256 dyn_ops->func = trace_selftest_test_dyn_func;
258 register_ftrace_function(dyn_ops);
260 trace_selftest_test_global_cnt = 0;
262 DYN_FTRACE_TEST_NAME();
266 if (trace_selftest_test_probe1_cnt != 2)
268 if (trace_selftest_test_probe2_cnt != 1)
270 if (trace_selftest_test_probe3_cnt != 3)
272 if (trace_selftest_test_global_cnt == 0)
274 if (trace_selftest_test_dyn_cnt == 0)
277 DYN_FTRACE_TEST_NAME2();
281 if (trace_selftest_test_probe1_cnt != 2)
283 if (trace_selftest_test_probe2_cnt != 2)
285 if (trace_selftest_test_probe3_cnt != 4)
290 unregister_ftrace_function(dyn_ops);
294 /* Purposely unregister in the same order */
295 unregister_ftrace_function(&test_probe1);
296 unregister_ftrace_function(&test_probe2);
297 unregister_ftrace_function(&test_probe3);
298 unregister_ftrace_function(&test_global);
300 /* Make sure everything is off */
302 DYN_FTRACE_TEST_NAME();
303 DYN_FTRACE_TEST_NAME();
305 if (trace_selftest_test_probe1_cnt ||
306 trace_selftest_test_probe2_cnt ||
307 trace_selftest_test_probe3_cnt ||
308 trace_selftest_test_global_cnt ||
309 trace_selftest_test_dyn_cnt)
312 ftrace_enabled = save_ftrace_enabled;
317 /* Test dynamic code modification and ftrace filters */
318 int trace_selftest_startup_dynamic_tracing(struct tracer *trace,
319 struct trace_array *tr,
322 int save_ftrace_enabled = ftrace_enabled;
323 int save_tracer_enabled = tracer_enabled;
328 /* The ftrace test PASSED */
329 printk(KERN_CONT "PASSED\n");
330 pr_info("Testing dynamic ftrace: ");
332 /* enable tracing, and record the filter function */
336 /* passed in by parameter to fool gcc from optimizing */
340 * Some archs *cough*PowerPC*cough* add characters to the
341 * start of the function names. We simply put a '*' to
344 func_name = "*" __stringify(DYN_FTRACE_TEST_NAME);
346 /* filter only on our function */
347 ftrace_set_global_filter(func_name, strlen(func_name), 1);
350 ret = tracer_init(trace, tr);
352 warn_failed_init_tracer(trace, ret);
356 /* Sleep for a 1/10 of a second */
359 /* we should have nothing in the buffer */
360 ret = trace_test_buffer(tr, &count);
366 printk(KERN_CONT ".. filter did not filter .. ");
370 /* call our function again */
376 /* stop the tracing. */
380 /* check the trace buffer */
381 ret = trace_test_buffer(tr, &count);
384 /* we should only have one item */
385 if (!ret && count != 1) {
387 printk(KERN_CONT ".. filter failed count=%ld ..", count);
392 /* Test the ops with global tracing running */
393 ret = trace_selftest_ops(1);
397 ftrace_enabled = save_ftrace_enabled;
398 tracer_enabled = save_tracer_enabled;
400 /* Enable tracing on all functions again */
401 ftrace_set_global_filter(NULL, 0, 1);
403 /* Test the ops with global tracing off */
405 ret = trace_selftest_ops(2);
410 static int trace_selftest_recursion_cnt;
411 static void trace_selftest_test_recursion_func(unsigned long ip,
413 struct ftrace_ops *op,
414 struct pt_regs *pt_regs)
417 * This function is registered without the recursion safe flag.
418 * The ftrace infrastructure should provide the recursion
419 * protection. If not, this will crash the kernel!
421 trace_selftest_recursion_cnt++;
422 DYN_FTRACE_TEST_NAME();
425 static void trace_selftest_test_recursion_safe_func(unsigned long ip,
427 struct ftrace_ops *op,
428 struct pt_regs *pt_regs)
431 * We said we would provide our own recursion. By calling
432 * this function again, we should recurse back into this function
433 * and count again. But this only happens if the arch supports
434 * all of ftrace features and nothing else is using the function
437 if (trace_selftest_recursion_cnt++)
439 DYN_FTRACE_TEST_NAME();
442 static struct ftrace_ops test_rec_probe = {
443 .func = trace_selftest_test_recursion_func,
446 static struct ftrace_ops test_recsafe_probe = {
447 .func = trace_selftest_test_recursion_safe_func,
448 .flags = FTRACE_OPS_FL_RECURSION_SAFE,
452 trace_selftest_function_recursion(void)
454 int save_ftrace_enabled = ftrace_enabled;
455 int save_tracer_enabled = tracer_enabled;
461 /* The previous test PASSED */
463 pr_info("Testing ftrace recursion: ");
466 /* enable tracing, and record the filter function */
470 /* Handle PPC64 '.' name */
471 func_name = "*" __stringify(DYN_FTRACE_TEST_NAME);
472 len = strlen(func_name);
474 ret = ftrace_set_filter(&test_rec_probe, func_name, len, 1);
476 pr_cont("*Could not set filter* ");
480 ret = register_ftrace_function(&test_rec_probe);
482 pr_cont("*could not register callback* ");
486 DYN_FTRACE_TEST_NAME();
488 unregister_ftrace_function(&test_rec_probe);
491 if (trace_selftest_recursion_cnt != 1) {
492 pr_cont("*callback not called once (%d)* ",
493 trace_selftest_recursion_cnt);
497 trace_selftest_recursion_cnt = 1;
500 pr_info("Testing ftrace recursion safe: ");
502 ret = ftrace_set_filter(&test_recsafe_probe, func_name, len, 1);
504 pr_cont("*Could not set filter* ");
508 ret = register_ftrace_function(&test_recsafe_probe);
510 pr_cont("*could not register callback* ");
514 DYN_FTRACE_TEST_NAME();
516 unregister_ftrace_function(&test_recsafe_probe);
519 * If arch supports all ftrace features, and no other task
520 * was on the list, we should be fine.
522 if (!ftrace_nr_registered_ops() && !FTRACE_FORCE_LIST_FUNC)
523 cnt = 2; /* Should have recursed */
528 if (trace_selftest_recursion_cnt != cnt) {
529 pr_cont("*callback not called expected %d times (%d)* ",
530 cnt, trace_selftest_recursion_cnt);
536 ftrace_enabled = save_ftrace_enabled;
537 tracer_enabled = save_tracer_enabled;
542 # define trace_selftest_startup_dynamic_tracing(trace, tr, func) ({ 0; })
543 # define trace_selftest_function_recursion() ({ 0; })
544 #endif /* CONFIG_DYNAMIC_FTRACE */
547 * Simple verification test of ftrace function tracer.
548 * Enable ftrace, sleep 1/10 second, and then read the trace
549 * buffer to see if all is in order.
552 trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
554 int save_ftrace_enabled = ftrace_enabled;
555 int save_tracer_enabled = tracer_enabled;
559 /* make sure msleep has been recorded */
562 /* start the tracing */
566 ret = tracer_init(trace, tr);
568 warn_failed_init_tracer(trace, ret);
572 /* Sleep for a 1/10 of a second */
574 /* stop the tracing. */
578 /* check the trace buffer */
579 ret = trace_test_buffer(tr, &count);
583 if (!ret && !count) {
584 printk(KERN_CONT ".. no entries found ..");
589 ret = trace_selftest_startup_dynamic_tracing(trace, tr,
590 DYN_FTRACE_TEST_NAME);
594 ret = trace_selftest_function_recursion();
596 ftrace_enabled = save_ftrace_enabled;
597 tracer_enabled = save_tracer_enabled;
599 /* kill ftrace totally if we failed */
605 #endif /* CONFIG_FUNCTION_TRACER */
608 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
610 /* Maximum number of functions to trace before diagnosing a hang */
611 #define GRAPH_MAX_FUNC_TEST 100000000
614 __ftrace_dump(bool disable_tracing, enum ftrace_dump_mode oops_dump_mode);
615 static unsigned int graph_hang_thresh;
617 /* Wrap the real function entry probe to avoid possible hanging */
618 static int trace_graph_entry_watchdog(struct ftrace_graph_ent *trace)
620 /* This is harmlessly racy, we want to approximately detect a hang */
621 if (unlikely(++graph_hang_thresh > GRAPH_MAX_FUNC_TEST)) {
623 printk(KERN_WARNING "BUG: Function graph tracer hang!\n");
624 if (ftrace_dump_on_oops)
625 __ftrace_dump(false, DUMP_ALL);
629 return trace_graph_entry(trace);
633 * Pretty much the same than for the function tracer from which the selftest
637 trace_selftest_startup_function_graph(struct tracer *trace,
638 struct trace_array *tr)
644 * Simulate the init() callback but we attach a watchdog callback
645 * to detect and recover from possible hangs
647 tracing_reset_online_cpus(tr);
649 ret = register_ftrace_graph(&trace_graph_return,
650 &trace_graph_entry_watchdog);
652 warn_failed_init_tracer(trace, ret);
655 tracing_start_cmdline_record();
657 /* Sleep for a 1/10 of a second */
660 /* Have we just recovered from a hang? */
661 if (graph_hang_thresh > GRAPH_MAX_FUNC_TEST) {
662 tracing_selftest_disabled = true;
669 /* check the trace buffer */
670 ret = trace_test_buffer(tr, &count);
675 if (!ret && !count) {
676 printk(KERN_CONT ".. no entries found ..");
681 /* Don't test dynamic tracing, the function tracer already did */
684 /* Stop it if we failed */
690 #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
693 #ifdef CONFIG_IRQSOFF_TRACER
695 trace_selftest_startup_irqsoff(struct tracer *trace, struct trace_array *tr)
697 unsigned long save_max = tracing_max_latency;
701 /* start the tracing */
702 ret = tracer_init(trace, tr);
704 warn_failed_init_tracer(trace, ret);
708 /* reset the max latency */
709 tracing_max_latency = 0;
710 /* disable interrupts for a bit */
716 * Stop the tracer to avoid a warning subsequent
717 * to buffer flipping failure because tracing_stop()
718 * disables the tr and max buffers, making flipping impossible
719 * in case of parallels max irqs off latencies.
722 /* stop the tracing. */
724 /* check both trace buffers */
725 ret = trace_test_buffer(tr, NULL);
727 ret = trace_test_buffer(&max_tr, &count);
731 if (!ret && !count) {
732 printk(KERN_CONT ".. no entries found ..");
736 tracing_max_latency = save_max;
740 #endif /* CONFIG_IRQSOFF_TRACER */
742 #ifdef CONFIG_PREEMPT_TRACER
744 trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr)
746 unsigned long save_max = tracing_max_latency;
751 * Now that the big kernel lock is no longer preemptable,
752 * and this is called with the BKL held, it will always
753 * fail. If preemption is already disabled, simply
754 * pass the test. When the BKL is removed, or becomes
755 * preemptible again, we will once again test this,
758 if (preempt_count()) {
759 printk(KERN_CONT "can not test ... force ");
763 /* start the tracing */
764 ret = tracer_init(trace, tr);
766 warn_failed_init_tracer(trace, ret);
770 /* reset the max latency */
771 tracing_max_latency = 0;
772 /* disable preemption for a bit */
778 * Stop the tracer to avoid a warning subsequent
779 * to buffer flipping failure because tracing_stop()
780 * disables the tr and max buffers, making flipping impossible
781 * in case of parallels max preempt off latencies.
784 /* stop the tracing. */
786 /* check both trace buffers */
787 ret = trace_test_buffer(tr, NULL);
789 ret = trace_test_buffer(&max_tr, &count);
793 if (!ret && !count) {
794 printk(KERN_CONT ".. no entries found ..");
798 tracing_max_latency = save_max;
802 #endif /* CONFIG_PREEMPT_TRACER */
804 #if defined(CONFIG_IRQSOFF_TRACER) && defined(CONFIG_PREEMPT_TRACER)
806 trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *tr)
808 unsigned long save_max = tracing_max_latency;
813 * Now that the big kernel lock is no longer preemptable,
814 * and this is called with the BKL held, it will always
815 * fail. If preemption is already disabled, simply
816 * pass the test. When the BKL is removed, or becomes
817 * preemptible again, we will once again test this,
820 if (preempt_count()) {
821 printk(KERN_CONT "can not test ... force ");
825 /* start the tracing */
826 ret = tracer_init(trace, tr);
828 warn_failed_init_tracer(trace, ret);
832 /* reset the max latency */
833 tracing_max_latency = 0;
835 /* disable preemption and interrupts for a bit */
840 /* reverse the order of preempt vs irqs */
844 * Stop the tracer to avoid a warning subsequent
845 * to buffer flipping failure because tracing_stop()
846 * disables the tr and max buffers, making flipping impossible
847 * in case of parallels max irqs/preempt off latencies.
850 /* stop the tracing. */
852 /* check both trace buffers */
853 ret = trace_test_buffer(tr, NULL);
857 ret = trace_test_buffer(&max_tr, &count);
861 if (!ret && !count) {
862 printk(KERN_CONT ".. no entries found ..");
867 /* do the test by disabling interrupts first this time */
868 tracing_max_latency = 0;
876 /* reverse the order of preempt vs irqs */
880 /* stop the tracing. */
882 /* check both trace buffers */
883 ret = trace_test_buffer(tr, NULL);
887 ret = trace_test_buffer(&max_tr, &count);
889 if (!ret && !count) {
890 printk(KERN_CONT ".. no entries found ..");
899 tracing_max_latency = save_max;
903 #endif /* CONFIG_IRQSOFF_TRACER && CONFIG_PREEMPT_TRACER */
905 #ifdef CONFIG_NOP_TRACER
907 trace_selftest_startup_nop(struct tracer *trace, struct trace_array *tr)
909 /* What could possibly go wrong? */
914 #ifdef CONFIG_SCHED_TRACER
915 static int trace_wakeup_test_thread(void *data)
917 /* Make this a RT thread, doesn't need to be too high */
918 static const struct sched_param param = { .sched_priority = 5 };
919 struct completion *x = data;
921 sched_setscheduler(current, SCHED_FIFO, ¶m);
923 /* Make it know we have a new prio */
926 /* now go to sleep and let the test wake us up */
927 set_current_state(TASK_INTERRUPTIBLE);
930 /* we are awake, now wait to disappear */
931 while (!kthread_should_stop()) {
933 * This is an RT task, do short sleeps to let
943 trace_selftest_startup_wakeup(struct tracer *trace, struct trace_array *tr)
945 unsigned long save_max = tracing_max_latency;
946 struct task_struct *p;
947 struct completion isrt;
951 init_completion(&isrt);
953 /* create a high prio thread */
954 p = kthread_run(trace_wakeup_test_thread, &isrt, "ftrace-test");
956 printk(KERN_CONT "Failed to create ftrace wakeup test thread ");
960 /* make sure the thread is running at an RT prio */
961 wait_for_completion(&isrt);
963 /* start the tracing */
964 ret = tracer_init(trace, tr);
966 warn_failed_init_tracer(trace, ret);
970 /* reset the max latency */
971 tracing_max_latency = 0;
973 /* sleep to let the RT thread sleep too */
977 * Yes this is slightly racy. It is possible that for some
978 * strange reason that the RT thread we created, did not
979 * call schedule for 100ms after doing the completion,
980 * and we do a wakeup on a task that already is awake.
981 * But that is extremely unlikely, and the worst thing that
982 * happens in such a case, is that we disable tracing.
983 * Honestly, if this race does happen something is horrible
984 * wrong with the system.
989 /* give a little time to let the thread wake up */
992 /* stop the tracing. */
994 /* check both trace buffers */
995 ret = trace_test_buffer(tr, NULL);
997 ret = trace_test_buffer(&max_tr, &count);
1003 tracing_max_latency = save_max;
1005 /* kill the thread */
1008 if (!ret && !count) {
1009 printk(KERN_CONT ".. no entries found ..");
1015 #endif /* CONFIG_SCHED_TRACER */
1017 #ifdef CONFIG_CONTEXT_SWITCH_TRACER
1019 trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr)
1021 unsigned long count;
1024 /* start the tracing */
1025 ret = tracer_init(trace, tr);
1027 warn_failed_init_tracer(trace, ret);
1031 /* Sleep for a 1/10 of a second */
1033 /* stop the tracing. */
1035 /* check the trace buffer */
1036 ret = trace_test_buffer(tr, &count);
1040 if (!ret && !count) {
1041 printk(KERN_CONT ".. no entries found ..");
1047 #endif /* CONFIG_CONTEXT_SWITCH_TRACER */
1049 #ifdef CONFIG_BRANCH_TRACER
1051 trace_selftest_startup_branch(struct tracer *trace, struct trace_array *tr)
1053 unsigned long count;
1056 /* start the tracing */
1057 ret = tracer_init(trace, tr);
1059 warn_failed_init_tracer(trace, ret);
1063 /* Sleep for a 1/10 of a second */
1065 /* stop the tracing. */
1067 /* check the trace buffer */
1068 ret = trace_test_buffer(tr, &count);
1072 if (!ret && !count) {
1073 printk(KERN_CONT ".. no entries found ..");
1079 #endif /* CONFIG_BRANCH_TRACER */