trace_selftest.c 14 KB

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