1/* Include in trace.c */ 2 3#include <linux/stringify.h> 4#include <linux/kthread.h> 5#include <linux/delay.h> 6#include <linux/slab.h> 7 8static inline int trace_valid_entry(struct trace_entry *entry) 9{ 10 switch (entry->type) { 11 case TRACE_FN: 12 case TRACE_CTX: 13 case TRACE_WAKE: 14 case TRACE_STACK: 15 case TRACE_PRINT: 16 case TRACE_BRANCH: 17 case TRACE_GRAPH_ENT: 18 case TRACE_GRAPH_RET: 19 return 1; 20 } 21 return 0; 22} 23 24static 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, 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 */ 61static 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 arch_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 arch_spin_unlock(&ftrace_max_lock); 87 local_irq_restore(flags); 88 89 if (count) 90 *count = cnt; 91 92 return ret; 93} 94 95static 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 */ 105int 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/* 193 * Simple verification test of ftrace function tracer. 194 * Enable ftrace, sleep 1/10 second, and then read the trace 195 * buffer to see if all is in order. 196 */ 197int 198trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr) 199{ 200 int save_ftrace_enabled = ftrace_enabled; 201 int save_tracer_enabled = tracer_enabled; 202 unsigned long count; 203 int ret; 204 205 /* make sure msleep has been recorded */ 206 msleep(1); 207 208 /* start the tracing */ 209 ftrace_enabled = 1; 210 tracer_enabled = 1; 211 212 ret = tracer_init(trace, tr); 213 if (ret) { 214 warn_failed_init_tracer(trace, ret); 215 goto out; 216 } 217 218 /* Sleep for a 1/10 of a second */ 219 msleep(100); 220 /* stop the tracing. */ 221 tracing_stop(); 222 ftrace_enabled = 0; 223 224 /* check the trace buffer */ 225 ret = trace_test_buffer(tr, &count); 226 trace->reset(tr); 227 tracing_start(); 228 229 if (!ret && !count) { 230 printk(KERN_CONT ".. no entries found .."); 231 ret = -1; 232 goto out; 233 } 234 235 ret = trace_selftest_startup_dynamic_tracing(trace, tr, 236 DYN_FTRACE_TEST_NAME); 237 238 out: 239 ftrace_enabled = save_ftrace_enabled; 240 tracer_enabled = save_tracer_enabled; 241 242 /* kill ftrace totally if we failed */ 243 if (ret) 244 ftrace_kill(); 245 246 return ret; 247} 248#endif /* CONFIG_FUNCTION_TRACER */ 249 250 251#ifdef CONFIG_FUNCTION_GRAPH_TRACER 252 253/* Maximum number of functions to trace before diagnosing a hang */ 254#define GRAPH_MAX_FUNC_TEST 100000000 255 256static void 257__ftrace_dump(bool disable_tracing, enum ftrace_dump_mode oops_dump_mode); 258static unsigned int graph_hang_thresh; 259 260/* Wrap the real function entry probe to avoid possible hanging */ 261static int trace_graph_entry_watchdog(struct ftrace_graph_ent *trace) 262{ 263 /* This is harmlessly racy, we want to approximately detect a hang */ 264 if (unlikely(++graph_hang_thresh > GRAPH_MAX_FUNC_TEST)) { 265 ftrace_graph_stop(); 266 printk(KERN_WARNING "BUG: Function graph tracer hang!\n"); 267 if (ftrace_dump_on_oops) 268 __ftrace_dump(false, DUMP_ALL); 269 return 0; 270 } 271 272 return trace_graph_entry(trace); 273} 274 275/* 276 * Pretty much the same than for the function tracer from which the selftest 277 * has been borrowed. 278 */ 279int 280trace_selftest_startup_function_graph(struct tracer *trace, 281 struct trace_array *tr) 282{ 283 int ret; 284 unsigned long count; 285 286 /* 287 * Simulate the init() callback but we attach a watchdog callback 288 * to detect and recover from possible hangs 289 */ 290 tracing_reset_online_cpus(tr); 291 set_graph_array(tr); 292 ret = register_ftrace_graph(&trace_graph_return, 293 &trace_graph_entry_watchdog); 294 if (ret) { 295 warn_failed_init_tracer(trace, ret); 296 goto out; 297 } 298 tracing_start_cmdline_record(); 299 300 /* Sleep for a 1/10 of a second */ 301 msleep(100); 302 303 /* Have we just recovered from a hang? */ 304 if (graph_hang_thresh > GRAPH_MAX_FUNC_TEST) { 305 tracing_selftest_disabled = true; 306 ret = -1; 307 goto out; 308 } 309 310 tracing_stop(); 311 312 /* check the trace buffer */ 313 ret = trace_test_buffer(tr, &count); 314 315 trace->reset(tr); 316 tracing_start(); 317 318 if (!ret && !count) { 319 printk(KERN_CONT ".. no entries found .."); 320 ret = -1; 321 goto out; 322 } 323 324 /* Don't test dynamic tracing, the function tracer already did */ 325 326out: 327 /* Stop it if we failed */ 328 if (ret) 329 ftrace_graph_stop(); 330 331 return ret; 332} 333#endif /* CONFIG_FUNCTION_GRAPH_TRACER */ 334 335 336#ifdef CONFIG_IRQSOFF_TRACER 337int 338trace_selftest_startup_irqsoff(struct tracer *trace, struct trace_array *tr) 339{ 340 unsigned long save_max = tracing_max_latency; 341 unsigned long count; 342 int ret; 343 344 /* start the tracing */ 345 ret = tracer_init(trace, tr); 346 if (ret) { 347 warn_failed_init_tracer(trace, ret); 348 return ret; 349 } 350 351 /* reset the max latency */ 352 tracing_max_latency = 0; 353 /* disable interrupts for a bit */ 354 local_irq_disable(); 355 udelay(100); 356 local_irq_enable(); 357 358 /* 359 * Stop the tracer to avoid a warning subsequent 360 * to buffer flipping failure because tracing_stop() 361 * disables the tr and max buffers, making flipping impossible 362 * in case of parallels max irqs off latencies. 363 */ 364 trace->stop(tr); 365 /* stop the tracing. */ 366 tracing_stop(); 367 /* check both trace buffers */ 368 ret = trace_test_buffer(tr, NULL); 369 if (!ret) 370 ret = trace_test_buffer(&max_tr, &count); 371 trace->reset(tr); 372 tracing_start(); 373 374 if (!ret && !count) { 375 printk(KERN_CONT ".. no entries found .."); 376 ret = -1; 377 } 378 379 tracing_max_latency = save_max; 380 381 return ret; 382} 383#endif /* CONFIG_IRQSOFF_TRACER */ 384 385#ifdef CONFIG_PREEMPT_TRACER 386int 387trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr) 388{ 389 unsigned long save_max = tracing_max_latency; 390 unsigned long count; 391 int ret; 392 393 /* 394 * Now that the big kernel lock is no longer preemptable, 395 * and this is called with the BKL held, it will always 396 * fail. If preemption is already disabled, simply 397 * pass the test. When the BKL is removed, or becomes 398 * preemptible again, we will once again test this, 399 * so keep it in. 400 */ 401 if (preempt_count()) { 402 printk(KERN_CONT "can not test ... force "); 403 return 0; 404 } 405 406 /* start the tracing */ 407 ret = tracer_init(trace, tr); 408 if (ret) { 409 warn_failed_init_tracer(trace, ret); 410 return ret; 411 } 412 413 /* reset the max latency */ 414 tracing_max_latency = 0; 415 /* disable preemption for a bit */ 416 preempt_disable(); 417 udelay(100); 418 preempt_enable(); 419 420 /* 421 * Stop the tracer to avoid a warning subsequent 422 * to buffer flipping failure because tracing_stop() 423 * disables the tr and max buffers, making flipping impossible 424 * in case of parallels max preempt off latencies. 425 */ 426 trace->stop(tr); 427 /* stop the tracing. */ 428 tracing_stop(); 429 /* check both trace buffers */ 430 ret = trace_test_buffer(tr, NULL); 431 if (!ret) 432 ret = trace_test_buffer(&max_tr, &count); 433 trace->reset(tr); 434 tracing_start(); 435 436 if (!ret && !count) { 437 printk(KERN_CONT ".. no entries found .."); 438 ret = -1; 439 } 440 441 tracing_max_latency = save_max; 442 443 return ret; 444} 445#endif /* CONFIG_PREEMPT_TRACER */ 446 447#if defined(CONFIG_IRQSOFF_TRACER) && defined(CONFIG_PREEMPT_TRACER) 448int 449trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *tr) 450{ 451 unsigned long save_max = tracing_max_latency; 452 unsigned long count; 453 int ret; 454 455 /* 456 * Now that the big kernel lock is no longer preemptable, 457 * and this is called with the BKL held, it will always 458 * fail. If preemption is already disabled, simply 459 * pass the test. When the BKL is removed, or becomes 460 * preemptible again, we will once again test this, 461 * so keep it in. 462 */ 463 if (preempt_count()) { 464 printk(KERN_CONT "can not test ... force "); 465 return 0; 466 } 467 468 /* start the tracing */ 469 ret = tracer_init(trace, tr); 470 if (ret) { 471 warn_failed_init_tracer(trace, ret); 472 goto out_no_start; 473 } 474 475 /* reset the max latency */ 476 tracing_max_latency = 0; 477 478 /* disable preemption and interrupts for a bit */ 479 preempt_disable(); 480 local_irq_disable(); 481 udelay(100); 482 preempt_enable(); 483 /* reverse the order of preempt vs irqs */ 484 local_irq_enable(); 485 486 /* 487 * Stop the tracer to avoid a warning subsequent 488 * to buffer flipping failure because tracing_stop() 489 * disables the tr and max buffers, making flipping impossible 490 * in case of parallels max irqs/preempt off latencies. 491 */ 492 trace->stop(tr); 493 /* stop the tracing. */ 494 tracing_stop(); 495 /* check both trace buffers */ 496 ret = trace_test_buffer(tr, NULL); 497 if (ret) 498 goto out; 499 500 ret = trace_test_buffer(&max_tr, &count); 501 if (ret) 502 goto out; 503 504 if (!ret && !count) { 505 printk(KERN_CONT ".. no entries found .."); 506 ret = -1; 507 goto out; 508 } 509 510 /* do the test by disabling interrupts first this time */ 511 tracing_max_latency = 0; 512 tracing_start(); 513 trace->start(tr); 514 515 preempt_disable(); 516 local_irq_disable(); 517 udelay(100); 518 preempt_enable(); 519 /* reverse the order of preempt vs irqs */ 520 local_irq_enable(); 521 522 trace->stop(tr); 523 /* stop the tracing. */ 524 tracing_stop(); 525 /* check both trace buffers */ 526 ret = trace_test_buffer(tr, NULL); 527 if (ret) 528 goto out; 529 530 ret = trace_test_buffer(&max_tr, &count); 531 532 if (!ret && !count) { 533 printk(KERN_CONT ".. no entries found .."); 534 ret = -1; 535 goto out; 536 } 537 538out: 539 tracing_start(); 540out_no_start: 541 trace->reset(tr); 542 tracing_max_latency = save_max; 543 544 return ret; 545} 546#endif /* CONFIG_IRQSOFF_TRACER && CONFIG_PREEMPT_TRACER */ 547 548#ifdef CONFIG_NOP_TRACER 549int 550trace_selftest_startup_nop(struct tracer *trace, struct trace_array *tr) 551{ 552 /* What could possibly go wrong? */ 553 return 0; 554} 555#endif 556 557#ifdef CONFIG_SCHED_TRACER 558static int trace_wakeup_test_thread(void *data) 559{ 560 /* Make this a RT thread, doesn't need to be too high */ 561 struct sched_param param = { .sched_priority = 5 }; 562 struct completion *x = data; 563 564 sched_setscheduler(current, SCHED_FIFO, ¶m); 565 566 /* Make it know we have a new prio */ 567 complete(x); 568 569 /* now go to sleep and let the test wake us up */ 570 set_current_state(TASK_INTERRUPTIBLE); 571 schedule(); 572 573 /* we are awake, now wait to disappear */ 574 while (!kthread_should_stop()) { 575 /* 576 * This is an RT task, do short sleeps to let 577 * others run. 578 */ 579 msleep(100); 580 } 581 582 return 0; 583} 584 585int 586trace_selftest_startup_wakeup(struct tracer *trace, struct trace_array *tr) 587{ 588 unsigned long save_max = tracing_max_latency; 589 struct task_struct *p; 590 struct completion isrt; 591 unsigned long count; 592 int ret; 593 594 init_completion(&isrt); 595 596 /* create a high prio thread */ 597 p = kthread_run(trace_wakeup_test_thread, &isrt, "ftrace-test"); 598 if (IS_ERR(p)) { 599 printk(KERN_CONT "Failed to create ftrace wakeup test thread "); 600 return -1; 601 } 602 603 /* make sure the thread is running at an RT prio */ 604 wait_for_completion(&isrt); 605 606 /* start the tracing */ 607 ret = tracer_init(trace, tr); 608 if (ret) { 609 warn_failed_init_tracer(trace, ret); 610 return ret; 611 } 612 613 /* reset the max latency */ 614 tracing_max_latency = 0; 615 616 /* sleep to let the RT thread sleep too */ 617 msleep(100); 618 619 /* 620 * Yes this is slightly racy. It is possible that for some 621 * strange reason that the RT thread we created, did not 622 * call schedule for 100ms after doing the completion, 623 * and we do a wakeup on a task that already is awake. 624 * But that is extremely unlikely, and the worst thing that 625 * happens in such a case, is that we disable tracing. 626 * Honestly, if this race does happen something is horrible 627 * wrong with the system. 628 */ 629 630 wake_up_process(p); 631 632 /* give a little time to let the thread wake up */ 633 msleep(100); 634 635 /* stop the tracing. */ 636 tracing_stop(); 637 /* check both trace buffers */ 638 ret = trace_test_buffer(tr, NULL); 639 if (!ret) 640 ret = trace_test_buffer(&max_tr, &count); 641 642 643 trace->reset(tr); 644 tracing_start(); 645 646 tracing_max_latency = save_max; 647 648 /* kill the thread */ 649 kthread_stop(p); 650 651 if (!ret && !count) { 652 printk(KERN_CONT ".. no entries found .."); 653 ret = -1; 654 } 655 656 return ret; 657} 658#endif /* CONFIG_SCHED_TRACER */ 659 660#ifdef CONFIG_CONTEXT_SWITCH_TRACER 661int 662trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr) 663{ 664 unsigned long count; 665 int ret; 666 667 /* start the tracing */ 668 ret = tracer_init(trace, tr); 669 if (ret) { 670 warn_failed_init_tracer(trace, ret); 671 return ret; 672 } 673 674 /* Sleep for a 1/10 of a second */ 675 msleep(100); 676 /* stop the tracing. */ 677 tracing_stop(); 678 /* check the trace buffer */ 679 ret = trace_test_buffer(tr, &count); 680 trace->reset(tr); 681 tracing_start(); 682 683 if (!ret && !count) { 684 printk(KERN_CONT ".. no entries found .."); 685 ret = -1; 686 } 687 688 return ret; 689} 690#endif /* CONFIG_CONTEXT_SWITCH_TRACER */ 691 692#ifdef CONFIG_BRANCH_TRACER 693int 694trace_selftest_startup_branch(struct tracer *trace, struct trace_array *tr) 695{ 696 unsigned long count; 697 int ret; 698 699 /* start the tracing */ 700 ret = tracer_init(trace, tr); 701 if (ret) { 702 warn_failed_init_tracer(trace, ret); 703 return ret; 704 } 705 706 /* Sleep for a 1/10 of a second */ 707 msleep(100); 708 /* stop the tracing. */ 709 tracing_stop(); 710 /* check the trace buffer */ 711 ret = trace_test_buffer(tr, &count); 712 trace->reset(tr); 713 tracing_start(); 714 715 if (!ret && !count) { 716 printk(KERN_CONT ".. no entries found .."); 717 ret = -1; 718 } 719 720 return ret; 721} 722#endif /* CONFIG_BRANCH_TRACER */ 723