trace_selftest.c 13 KB

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