git.oblomov.eu Git - linux-2.6/blob - kernel/trace/trace_selftest.c

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