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