trace_selftest.c 11 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538
  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_FTRACE
  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. /* update the records */
  83. ret = ftrace_force_update();
  84. if (ret) {
  85. printk(KERN_CONT ".. ftraced failed .. ");
  86. return ret;
  87. }
  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. tr->ctrl = 1;
  98. trace->init(tr);
  99. /* Sleep for a 1/10 of a second */
  100. msleep(100);
  101. /* we should have nothing in the buffer */
  102. ret = trace_test_buffer(tr, &count);
  103. if (ret)
  104. goto out;
  105. if (count) {
  106. ret = -1;
  107. printk(KERN_CONT ".. filter did not filter .. ");
  108. goto out;
  109. }
  110. /* call our function again */
  111. func();
  112. /* sleep again */
  113. msleep(100);
  114. /* stop the tracing. */
  115. tr->ctrl = 0;
  116. trace->ctrl_update(tr);
  117. ftrace_enabled = 0;
  118. /* check the trace buffer */
  119. ret = trace_test_buffer(tr, &count);
  120. trace->reset(tr);
  121. /* we should only have one item */
  122. if (!ret && count != 1) {
  123. printk(KERN_CONT ".. filter failed count=%ld ..", count);
  124. ret = -1;
  125. goto out;
  126. }
  127. out:
  128. ftrace_enabled = save_ftrace_enabled;
  129. tracer_enabled = save_tracer_enabled;
  130. /* Enable tracing on all functions again */
  131. ftrace_set_filter(NULL, 0, 1);
  132. return ret;
  133. }
  134. #else
  135. # define trace_selftest_startup_dynamic_tracing(trace, tr, func) ({ 0; })
  136. #endif /* CONFIG_DYNAMIC_FTRACE */
  137. /*
  138. * Simple verification test of ftrace function tracer.
  139. * Enable ftrace, sleep 1/10 second, and then read the trace
  140. * buffer to see if all is in order.
  141. */
  142. int
  143. trace_selftest_startup_function(struct tracer *trace, struct trace_array *tr)
  144. {
  145. int save_ftrace_enabled = ftrace_enabled;
  146. int save_tracer_enabled = tracer_enabled;
  147. unsigned long count;
  148. int ret;
  149. /* make sure msleep has been recorded */
  150. msleep(1);
  151. /* force the recorded functions to be traced */
  152. ret = ftrace_force_update();
  153. if (ret) {
  154. printk(KERN_CONT ".. ftraced failed .. ");
  155. return ret;
  156. }
  157. /* start the tracing */
  158. ftrace_enabled = 1;
  159. tracer_enabled = 1;
  160. tr->ctrl = 1;
  161. trace->init(tr);
  162. /* Sleep for a 1/10 of a second */
  163. msleep(100);
  164. /* stop the tracing. */
  165. tr->ctrl = 0;
  166. trace->ctrl_update(tr);
  167. ftrace_enabled = 0;
  168. /* check the trace buffer */
  169. ret = trace_test_buffer(tr, &count);
  170. trace->reset(tr);
  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_FTRACE */
  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. tr->ctrl = 1;
  196. trace->init(tr);
  197. /* reset the max latency */
  198. tracing_max_latency = 0;
  199. /* disable interrupts for a bit */
  200. local_irq_disable();
  201. udelay(100);
  202. local_irq_enable();
  203. /* stop the tracing. */
  204. tr->ctrl = 0;
  205. trace->ctrl_update(tr);
  206. /* check both trace buffers */
  207. ret = trace_test_buffer(tr, NULL);
  208. if (!ret)
  209. ret = trace_test_buffer(&max_tr, &count);
  210. trace->reset(tr);
  211. if (!ret && !count) {
  212. printk(KERN_CONT ".. no entries found ..");
  213. ret = -1;
  214. }
  215. tracing_max_latency = save_max;
  216. return ret;
  217. }
  218. #endif /* CONFIG_IRQSOFF_TRACER */
  219. #ifdef CONFIG_PREEMPT_TRACER
  220. int
  221. trace_selftest_startup_preemptoff(struct tracer *trace, struct trace_array *tr)
  222. {
  223. unsigned long save_max = tracing_max_latency;
  224. unsigned long count;
  225. int ret;
  226. /* start the tracing */
  227. tr->ctrl = 1;
  228. trace->init(tr);
  229. /* reset the max latency */
  230. tracing_max_latency = 0;
  231. /* disable preemption for a bit */
  232. preempt_disable();
  233. udelay(100);
  234. preempt_enable();
  235. /* stop the tracing. */
  236. tr->ctrl = 0;
  237. trace->ctrl_update(tr);
  238. /* check both trace buffers */
  239. ret = trace_test_buffer(tr, NULL);
  240. if (!ret)
  241. ret = trace_test_buffer(&max_tr, &count);
  242. trace->reset(tr);
  243. if (!ret && !count) {
  244. printk(KERN_CONT ".. no entries found ..");
  245. ret = -1;
  246. }
  247. tracing_max_latency = save_max;
  248. return ret;
  249. }
  250. #endif /* CONFIG_PREEMPT_TRACER */
  251. #if defined(CONFIG_IRQSOFF_TRACER) && defined(CONFIG_PREEMPT_TRACER)
  252. int
  253. trace_selftest_startup_preemptirqsoff(struct tracer *trace, struct trace_array *tr)
  254. {
  255. unsigned long save_max = tracing_max_latency;
  256. unsigned long count;
  257. int ret;
  258. /* start the tracing */
  259. tr->ctrl = 1;
  260. trace->init(tr);
  261. /* reset the max latency */
  262. tracing_max_latency = 0;
  263. /* disable preemption and interrupts for a bit */
  264. preempt_disable();
  265. local_irq_disable();
  266. udelay(100);
  267. preempt_enable();
  268. /* reverse the order of preempt vs irqs */
  269. local_irq_enable();
  270. /* stop the tracing. */
  271. tr->ctrl = 0;
  272. trace->ctrl_update(tr);
  273. /* check both trace buffers */
  274. ret = trace_test_buffer(tr, NULL);
  275. if (ret)
  276. goto out;
  277. ret = trace_test_buffer(&max_tr, &count);
  278. if (ret)
  279. goto out;
  280. if (!ret && !count) {
  281. printk(KERN_CONT ".. no entries found ..");
  282. ret = -1;
  283. goto out;
  284. }
  285. /* do the test by disabling interrupts first this time */
  286. tracing_max_latency = 0;
  287. tr->ctrl = 1;
  288. trace->ctrl_update(tr);
  289. preempt_disable();
  290. local_irq_disable();
  291. udelay(100);
  292. preempt_enable();
  293. /* reverse the order of preempt vs irqs */
  294. local_irq_enable();
  295. /* stop the tracing. */
  296. tr->ctrl = 0;
  297. trace->ctrl_update(tr);
  298. /* check both trace buffers */
  299. ret = trace_test_buffer(tr, NULL);
  300. if (ret)
  301. goto out;
  302. ret = trace_test_buffer(&max_tr, &count);
  303. if (!ret && !count) {
  304. printk(KERN_CONT ".. no entries found ..");
  305. ret = -1;
  306. goto out;
  307. }
  308. out:
  309. trace->reset(tr);
  310. tracing_max_latency = save_max;
  311. return ret;
  312. }
  313. #endif /* CONFIG_IRQSOFF_TRACER && CONFIG_PREEMPT_TRACER */
  314. #ifdef CONFIG_NOP_TRACER
  315. int
  316. trace_selftest_startup_nop(struct tracer *trace, struct trace_array *tr)
  317. {
  318. /* What could possibly go wrong? */
  319. return 0;
  320. }
  321. #endif
  322. #ifdef CONFIG_SCHED_TRACER
  323. static int trace_wakeup_test_thread(void *data)
  324. {
  325. /* Make this a RT thread, doesn't need to be too high */
  326. struct sched_param param = { .sched_priority = 5 };
  327. struct completion *x = data;
  328. sched_setscheduler(current, SCHED_FIFO, &param);
  329. /* Make it know we have a new prio */
  330. complete(x);
  331. /* now go to sleep and let the test wake us up */
  332. set_current_state(TASK_INTERRUPTIBLE);
  333. schedule();
  334. /* we are awake, now wait to disappear */
  335. while (!kthread_should_stop()) {
  336. /*
  337. * This is an RT task, do short sleeps to let
  338. * others run.
  339. */
  340. msleep(100);
  341. }
  342. return 0;
  343. }
  344. int
  345. trace_selftest_startup_wakeup(struct tracer *trace, struct trace_array *tr)
  346. {
  347. unsigned long save_max = tracing_max_latency;
  348. struct task_struct *p;
  349. struct completion isrt;
  350. unsigned long count;
  351. int ret;
  352. init_completion(&isrt);
  353. /* create a high prio thread */
  354. p = kthread_run(trace_wakeup_test_thread, &isrt, "ftrace-test");
  355. if (IS_ERR(p)) {
  356. printk(KERN_CONT "Failed to create ftrace wakeup test thread ");
  357. return -1;
  358. }
  359. /* make sure the thread is running at an RT prio */
  360. wait_for_completion(&isrt);
  361. /* start the tracing */
  362. tr->ctrl = 1;
  363. trace->init(tr);
  364. /* reset the max latency */
  365. tracing_max_latency = 0;
  366. /* sleep to let the RT thread sleep too */
  367. msleep(100);
  368. /*
  369. * Yes this is slightly racy. It is possible that for some
  370. * strange reason that the RT thread we created, did not
  371. * call schedule for 100ms after doing the completion,
  372. * and we do a wakeup on a task that already is awake.
  373. * But that is extremely unlikely, and the worst thing that
  374. * happens in such a case, is that we disable tracing.
  375. * Honestly, if this race does happen something is horrible
  376. * wrong with the system.
  377. */
  378. wake_up_process(p);
  379. /* give a little time to let the thread wake up */
  380. msleep(100);
  381. /* stop the tracing. */
  382. tr->ctrl = 0;
  383. trace->ctrl_update(tr);
  384. /* check both trace buffers */
  385. ret = trace_test_buffer(tr, NULL);
  386. if (!ret)
  387. ret = trace_test_buffer(&max_tr, &count);
  388. trace->reset(tr);
  389. tracing_max_latency = save_max;
  390. /* kill the thread */
  391. kthread_stop(p);
  392. if (!ret && !count) {
  393. printk(KERN_CONT ".. no entries found ..");
  394. ret = -1;
  395. }
  396. return ret;
  397. }
  398. #endif /* CONFIG_SCHED_TRACER */
  399. #ifdef CONFIG_CONTEXT_SWITCH_TRACER
  400. int
  401. trace_selftest_startup_sched_switch(struct tracer *trace, struct trace_array *tr)
  402. {
  403. unsigned long count;
  404. int ret;
  405. /* start the tracing */
  406. tr->ctrl = 1;
  407. trace->init(tr);
  408. /* Sleep for a 1/10 of a second */
  409. msleep(100);
  410. /* stop the tracing. */
  411. tr->ctrl = 0;
  412. trace->ctrl_update(tr);
  413. /* check the trace buffer */
  414. ret = trace_test_buffer(tr, &count);
  415. trace->reset(tr);
  416. if (!ret && !count) {
  417. printk(KERN_CONT ".. no entries found ..");
  418. ret = -1;
  419. }
  420. return ret;
  421. }
  422. #endif /* CONFIG_CONTEXT_SWITCH_TRACER */
  423. #ifdef CONFIG_SYSPROF_TRACER
  424. int
  425. trace_selftest_startup_sysprof(struct tracer *trace, struct trace_array *tr)
  426. {
  427. unsigned long count;
  428. int ret;
  429. /* start the tracing */
  430. tr->ctrl = 1;
  431. trace->init(tr);
  432. /* Sleep for a 1/10 of a second */
  433. msleep(100);
  434. /* stop the tracing. */
  435. tr->ctrl = 0;
  436. trace->ctrl_update(tr);
  437. /* check the trace buffer */
  438. ret = trace_test_buffer(tr, &count);
  439. trace->reset(tr);
  440. return ret;
  441. }
  442. #endif /* CONFIG_SYSPROF_TRACER */