trace_selftest.c 13 KB

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