trace_selftest.c 11 KB

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