ftrace: sysprof-plugin, add self-tests
[safe/jmp/linux-2.6] / kernel / trace / trace_selftest.c
1 /* Include in trace.c */
2
3 #include <linux/kthread.h>
4 #include <linux/delay.h>
5
6 static inline int trace_valid_entry(struct trace_entry *entry)
7 {
8         switch (entry->type) {
9         case TRACE_FN:
10         case TRACE_CTX:
11         case TRACE_WAKE:
12         case TRACE_STACK:
13         case TRACE_SPECIAL:
14                 return 1;
15         }
16         return 0;
17 }
18
19 static int
20 trace_test_buffer_cpu(struct trace_array *tr, struct trace_array_cpu *data)
21 {
22         struct trace_entry *entries;
23         struct page *page;
24         int idx = 0;
25         int i;
26
27         BUG_ON(list_empty(&data->trace_pages));
28         page = list_entry(data->trace_pages.next, struct page, lru);
29         entries = page_address(page);
30
31         if (head_page(data) != entries)
32                 goto failed;
33
34         /*
35          * The starting trace buffer always has valid elements,
36          * if any element exists.
37          */
38         entries = head_page(data);
39
40         for (i = 0; i < tr->entries; i++) {
41
42                 if (i < data->trace_idx && !trace_valid_entry(&entries[idx])) {
43                         printk(KERN_CONT ".. invalid entry %d ",
44                                 entries[idx].type);
45                         goto failed;
46                 }
47
48                 idx++;
49                 if (idx >= ENTRIES_PER_PAGE) {
50                         page = virt_to_page(entries);
51                         if (page->lru.next == &data->trace_pages) {
52                                 if (i != tr->entries - 1) {
53                                         printk(KERN_CONT ".. entries buffer mismatch");
54                                         goto failed;
55                                 }
56                         } else {
57                                 page = list_entry(page->lru.next, struct page, lru);
58                                 entries = page_address(page);
59                         }
60                         idx = 0;
61                 }
62         }
63
64         page = virt_to_page(entries);
65         if (page->lru.next != &data->trace_pages) {
66                 printk(KERN_CONT ".. too many entries");
67                 goto failed;
68         }
69
70         return 0;
71
72  failed:
73         /* disable tracing */
74         tracing_disabled = 1;
75         printk(KERN_CONT ".. corrupted trace buffer .. ");
76         return -1;
77 }
78
79 /*
80  * Test the trace buffer to see if all the elements
81  * are still sane.
82  */
83 static int trace_test_buffer(struct trace_array *tr, unsigned long *count)
84 {
85         unsigned long flags, cnt = 0;
86         int cpu, ret = 0;
87
88         /* Don't allow flipping of max traces now */
89         raw_local_irq_save(flags);
90         __raw_spin_lock(&ftrace_max_lock);
91         for_each_possible_cpu(cpu) {
92                 if (!head_page(tr->data[cpu]))
93                         continue;
94
95                 cnt += tr->data[cpu]->trace_idx;
96
97                 ret = trace_test_buffer_cpu(tr, tr->data[cpu]);
98                 if (ret)
99                         break;
100         }
101         __raw_spin_unlock(&ftrace_max_lock);
102         raw_local_irq_restore(flags);
103
104         if (count)
105                 *count = cnt;
106
107         return ret;
108 }
109
110 #ifdef CONFIG_FTRACE
111
112 #ifdef CONFIG_DYNAMIC_FTRACE
113
114 #define __STR(x) #x
115 #define STR(x) __STR(x)
116
117 /* Test dynamic code modification and ftrace filters */
118 int trace_selftest_startup_dynamic_tracing(struct tracer *trace,
119                                            struct trace_array *tr,
120                                            int (*func)(void))
121 {
122         unsigned long count;
123         int ret;
124         int save_ftrace_enabled = ftrace_enabled;
125         int save_tracer_enabled = tracer_enabled;
126         char *func_name;
127
128         /* The ftrace test PASSED */
129         printk(KERN_CONT "PASSED\n");
130         pr_info("Testing dynamic ftrace: ");
131
132         /* enable tracing, and record the filter function */
133         ftrace_enabled = 1;
134         tracer_enabled = 1;
135
136         /* passed in by parameter to fool gcc from optimizing */
137         func();
138
139         /* update the records */
140         ret = ftrace_force_update();
141         if (ret) {
142                 printk(KERN_CONT ".. ftraced failed .. ");
143                 return ret;
144         }
145
146         /*
147          * Some archs *cough*PowerPC*cough* add charachters to the
148          * start of the function names. We simply put a '*' to
149          * accomodate them.
150          */
151         func_name = "*" STR(DYN_FTRACE_TEST_NAME);
152
153         /* filter only on our function */
154         ftrace_set_filter(func_name, strlen(func_name), 1);
155
156         /* enable tracing */
157         tr->ctrl = 1;
158         trace->init(tr);
159         /* Sleep for a 1/10 of a second */
160         msleep(100);
161
162         /* we should have nothing in the buffer */
163         ret = trace_test_buffer(tr, &count);
164         if (ret)
165                 goto out;
166
167         if (count) {
168                 ret = -1;
169                 printk(KERN_CONT ".. filter did not filter .. ");
170                 goto out;
171         }
172
173         /* call our function again */
174         func();
175
176         /* sleep again */
177         msleep(100);
178
179         /* stop the tracing. */
180         tr->ctrl = 0;
181         trace->ctrl_update(tr);
182         ftrace_enabled = 0;
183
184         /* check the trace buffer */
185         ret = trace_test_buffer(tr, &count);
186         trace->reset(tr);
187
188         /* we should only have one item */
189         if (!ret && count != 1) {
190                 printk(KERN_CONT ".. filter failed count=%ld ..", count);
191                 ret = -1;
192                 goto out;
193         }
194  out:
195         ftrace_enabled = save_ftrace_enabled;
196         tracer_enabled = save_tracer_enabled;
197
198         /* Enable tracing on all functions again */
199         ftrace_set_filter(NULL, 0, 1);
200
201         return ret;
202 }
203 #else
204 # define trace_selftest_startup_dynamic_tracing(trace, tr, func) ({ 0; })
205 #endif /* CONFIG_DYNAMIC_FTRACE */
206 /*
207  * Simple verification test of ftrace function tracer.
208  * Enable ftrace, sleep 1/10 second, and then read the trace
209  * buffer to see if all is in order.
210  */
211 int
212 trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
213 {
214         unsigned long count;
215         int ret;
216         int save_ftrace_enabled = ftrace_enabled;
217         int save_tracer_enabled = tracer_enabled;
218
219         /* make sure msleep has been recorded */
220         msleep(1);
221
222         /* force the recorded functions to be traced */
223         ret = ftrace_force_update();
224         if (ret) {
225                 printk(KERN_CONT ".. ftraced failed .. ");
226                 return ret;
227         }
228
229         /* start the tracing */
230         ftrace_enabled = 1;
231         tracer_enabled = 1;
232
233         tr->ctrl = 1;
234         trace->init(tr);
235         /* Sleep for a 1/10 of a second */
236         msleep(100);
237         /* stop the tracing. */
238         tr->ctrl = 0;
239         trace->ctrl_update(tr);
240         ftrace_enabled = 0;
241
242         /* check the trace buffer */
243         ret = trace_test_buffer(tr, &count);
244         trace->reset(tr);
245
246         if (!ret && !count) {
247                 printk(KERN_CONT ".. no entries found ..");
248                 ret = -1;
249                 goto out;
250         }
251
252         ret = trace_selftest_startup_dynamic_tracing(trace, tr,
253                                                      DYN_FTRACE_TEST_NAME);
254
255  out:
256         ftrace_enabled = save_ftrace_enabled;
257         tracer_enabled = save_tracer_enabled;
258
259         /* kill ftrace totally if we failed */
260         if (ret)
261                 ftrace_kill();
262
263         return ret;
264 }
265 #endif /* CONFIG_FTRACE */
266
267 #ifdef CONFIG_IRQSOFF_TRACER
268 int
269 trace_selftest_startup_irqsoff(struct tracer *trace, struct trace_array *tr)
270 {
271         unsigned long save_max = tracing_max_latency;
272         unsigned long count;
273         int ret;
274
275         /* start the tracing */
276         tr->ctrl = 1;
277         trace->init(tr);
278         /* reset the max latency */
279         tracing_max_latency = 0;
280         /* disable interrupts for a bit */
281         local_irq_disable();
282         udelay(100);
283         local_irq_enable();
284         /* stop the tracing. */
285         tr->ctrl = 0;
286         trace->ctrl_update(tr);
287         /* check both trace buffers */
288         ret = trace_test_buffer(tr, NULL);
289         if (!ret)
290                 ret = trace_test_buffer(&max_tr, &count);
291         trace->reset(tr);
292
293         if (!ret && !count) {
294                 printk(KERN_CONT ".. no entries found ..");
295                 ret = -1;
296         }
297
298         tracing_max_latency = save_max;
299
300         return ret;
301 }
302 #endif /* CONFIG_IRQSOFF_TRACER */
303
304 #ifdef CONFIG_PREEMPT_TRACER
305 int
306 trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr)
307 {
308         unsigned long save_max = tracing_max_latency;
309         unsigned long count;
310         int ret;
311
312         /* start the tracing */
313         tr->ctrl = 1;
314         trace->init(tr);
315         /* reset the max latency */
316         tracing_max_latency = 0;
317         /* disable preemption for a bit */
318         preempt_disable();
319         udelay(100);
320         preempt_enable();
321         /* stop the tracing. */
322         tr->ctrl = 0;
323         trace->ctrl_update(tr);
324         /* check both trace buffers */
325         ret = trace_test_buffer(tr, NULL);
326         if (!ret)
327                 ret = trace_test_buffer(&max_tr, &count);
328         trace->reset(tr);
329
330         if (!ret && !count) {
331                 printk(KERN_CONT ".. no entries found ..");
332                 ret = -1;
333         }
334
335         tracing_max_latency = save_max;
336
337         return ret;
338 }
339 #endif /* CONFIG_PREEMPT_TRACER */
340
341 #if defined(CONFIG_IRQSOFF_TRACER) && defined(CONFIG_PREEMPT_TRACER)
342 int
343 trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *tr)
344 {
345         unsigned long save_max = tracing_max_latency;
346         unsigned long count;
347         int ret;
348
349         /* start the tracing */
350         tr->ctrl = 1;
351         trace->init(tr);
352
353         /* reset the max latency */
354         tracing_max_latency = 0;
355
356         /* disable preemption and interrupts for a bit */
357         preempt_disable();
358         local_irq_disable();
359         udelay(100);
360         preempt_enable();
361         /* reverse the order of preempt vs irqs */
362         local_irq_enable();
363
364         /* stop the tracing. */
365         tr->ctrl = 0;
366         trace->ctrl_update(tr);
367         /* check both trace buffers */
368         ret = trace_test_buffer(tr, NULL);
369         if (ret)
370                 goto out;
371
372         ret = trace_test_buffer(&max_tr, &count);
373         if (ret)
374                 goto out;
375
376         if (!ret && !count) {
377                 printk(KERN_CONT ".. no entries found ..");
378                 ret = -1;
379                 goto out;
380         }
381
382         /* do the test by disabling interrupts first this time */
383         tracing_max_latency = 0;
384         tr->ctrl = 1;
385         trace->ctrl_update(tr);
386         preempt_disable();
387         local_irq_disable();
388         udelay(100);
389         preempt_enable();
390         /* reverse the order of preempt vs irqs */
391         local_irq_enable();
392
393         /* stop the tracing. */
394         tr->ctrl = 0;
395         trace->ctrl_update(tr);
396         /* check both trace buffers */
397         ret = trace_test_buffer(tr, NULL);
398         if (ret)
399                 goto out;
400
401         ret = trace_test_buffer(&max_tr, &count);
402
403         if (!ret && !count) {
404                 printk(KERN_CONT ".. no entries found ..");
405                 ret = -1;
406                 goto out;
407         }
408
409  out:
410         trace->reset(tr);
411         tracing_max_latency = save_max;
412
413         return ret;
414 }
415 #endif /* CONFIG_IRQSOFF_TRACER && CONFIG_PREEMPT_TRACER */
416
417 #ifdef CONFIG_SCHED_TRACER
418 static int trace_wakeup_test_thread(void *data)
419 {
420         /* Make this a RT thread, doesn't need to be too high */
421         struct sched_param param = { .sched_priority = 5 };
422         struct completion *x = data;
423
424         sched_setscheduler(current, SCHED_FIFO, &param);
425
426         /* Make it know we have a new prio */
427         complete(x);
428
429         /* now go to sleep and let the test wake us up */
430         set_current_state(TASK_INTERRUPTIBLE);
431         schedule();
432
433         /* we are awake, now wait to disappear */
434         while (!kthread_should_stop()) {
435                 /*
436                  * This is an RT task, do short sleeps to let
437                  * others run.
438                  */
439                 msleep(100);
440         }
441
442         return 0;
443 }
444
445 int
446 trace_selftest_startup_wakeup(struct tracer *trace, struct trace_array *tr)
447 {
448         unsigned long save_max = tracing_max_latency;
449         struct task_struct *p;
450         struct completion isrt;
451         unsigned long count;
452         int ret;
453
454         init_completion(&isrt);
455
456         /* create a high prio thread */
457         p = kthread_run(trace_wakeup_test_thread, &isrt, "ftrace-test");
458         if (IS_ERR(p)) {
459                 printk(KERN_CONT "Failed to create ftrace wakeup test thread ");
460                 return -1;
461         }
462
463         /* make sure the thread is running at an RT prio */
464         wait_for_completion(&isrt);
465
466         /* start the tracing */
467         tr->ctrl = 1;
468         trace->init(tr);
469         /* reset the max latency */
470         tracing_max_latency = 0;
471
472         /* sleep to let the RT thread sleep too */
473         msleep(100);
474
475         /*
476          * Yes this is slightly racy. It is possible that for some
477          * strange reason that the RT thread we created, did not
478          * call schedule for 100ms after doing the completion,
479          * and we do a wakeup on a task that already is awake.
480          * But that is extremely unlikely, and the worst thing that
481          * happens in such a case, is that we disable tracing.
482          * Honestly, if this race does happen something is horrible
483          * wrong with the system.
484          */
485
486         wake_up_process(p);
487
488         /* stop the tracing. */
489         tr->ctrl = 0;
490         trace->ctrl_update(tr);
491         /* check both trace buffers */
492         ret = trace_test_buffer(tr, NULL);
493         if (!ret)
494                 ret = trace_test_buffer(&max_tr, &count);
495
496
497         trace->reset(tr);
498
499         tracing_max_latency = save_max;
500
501         /* kill the thread */
502         kthread_stop(p);
503
504         if (!ret && !count) {
505                 printk(KERN_CONT ".. no entries found ..");
506                 ret = -1;
507         }
508
509         return ret;
510 }
511 #endif /* CONFIG_SCHED_TRACER */
512
513 #ifdef CONFIG_CONTEXT_SWITCH_TRACER
514 int
515 trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr)
516 {
517         unsigned long count;
518         int ret;
519
520         /* start the tracing */
521         tr->ctrl = 1;
522         trace->init(tr);
523         /* Sleep for a 1/10 of a second */
524         msleep(100);
525         /* stop the tracing. */
526         tr->ctrl = 0;
527         trace->ctrl_update(tr);
528         /* check the trace buffer */
529         ret = trace_test_buffer(tr, &count);
530         trace->reset(tr);
531
532         if (!ret && !count) {
533                 printk(KERN_CONT ".. no entries found ..");
534                 ret = -1;
535         }
536
537         return ret;
538 }
539 #endif /* CONFIG_CONTEXT_SWITCH_TRACER */
540
541 #ifdef CONFIG_SYSPROF_TRACER
542 int
543 trace_selftest_startup_sysprof(struct tracer *trace, struct trace_array *tr)
544 {
545         unsigned long count;
546         int ret;
547
548         /* start the tracing */
549         tr->ctrl = 1;
550         trace->init(tr);
551         /* Sleep for a 1/10 of a second */
552         msleep(100);
553         /* stop the tracing. */
554         tr->ctrl = 0;
555         trace->ctrl_update(tr);
556         /* check the trace buffer */
557         ret = trace_test_buffer(tr, &count);
558         trace->reset(tr);
559
560         if (!ret && !count) {
561                 printk(KERN_CONT ".. no entries found ..");
562                 ret = -1;
563         }
564
565         return ret;
566 }
567 #endif /* CONFIG_SYSPROF_TRACER */