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