diff options
Diffstat (limited to 'kernel/trace/trace_selftest.c')
-rw-r--r-- | kernel/trace/trace_selftest.c | 562 |
1 files changed, 562 insertions, 0 deletions
diff --git a/kernel/trace/trace_selftest.c b/kernel/trace/trace_selftest.c new file mode 100644 index 000000000000..5588ecc40985 --- /dev/null +++ b/kernel/trace/trace_selftest.c | |||
@@ -0,0 +1,562 @@ | |||
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, ¶m); | ||
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 | return ret; | ||
561 | } | ||
562 | #endif /* CONFIG_SYSPROF_TRACER */ | ||