builtin-trace.c 31 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524525526527528529530531532533534535536537538539540541542543544545546547548549550551552553554555556557558559560561562563564565566567568569570571572573574575576577578579580581582583584585586587588589590591592593594595596597598599600601602603604605606607608609610611612613614615616617618619620621622623624625626627628629630631632633634635636637638639640641642643644645646647648649650651652653654655656657658659660661662663664665666667668669670671672673674675676677678679680681682683684685686687688689690691692693694695696697698699700701702703704705706707708709710711712713714715716717718719720721722723724725726727728729730731732733734735736737738739740741742743744745746747748749750751752753754755756757758759760761762763764765766767768769770771772773774775776777778779780781782783784785786787788789790791792793794795796797798799800801802803804805806807808809810811812813814815816817818819820821822823824825826827828829830831832833834835836837838839840841842843844845846847848849850851852853854855856857858859860861862863864865866867868869870871872873874875876877878879880881882883884885886887888889890891892893894895896897898899900901902903904905906907908909910911912913914915916917918919920921922923924925926927928929930931932933934935936937938939940941942943944945946947948949950951952953954955956957958959960961962963964965966967968969970971972973974975976977978979980981982983984985986987988989990991992993994995996997998999100010011002100310041005100610071008100910101011101210131014101510161017101810191020102110221023102410251026102710281029103010311032103310341035103610371038103910401041104210431044104510461047104810491050105110521053105410551056105710581059106010611062106310641065106610671068106910701071107210731074107510761077107810791080108110821083108410851086108710881089109010911092109310941095109610971098109911001101110211031104110511061107110811091110111111121113111411151116111711181119112011211122112311241125112611271128112911301131113211331134113511361137113811391140114111421143114411451146114711481149115011511152115311541155115611571158115911601161116211631164116511661167116811691170
  1. #include <traceevent/event-parse.h>
  2. #include "builtin.h"
  3. #include "util/color.h"
  4. #include "util/debug.h"
  5. #include "util/evlist.h"
  6. #include "util/machine.h"
  7. #include "util/session.h"
  8. #include "util/thread.h"
  9. #include "util/parse-options.h"
  10. #include "util/strlist.h"
  11. #include "util/intlist.h"
  12. #include "util/thread_map.h"
  13. #include <libaudit.h>
  14. #include <stdlib.h>
  15. #include <sys/mman.h>
  16. #include <linux/futex.h>
  17. static size_t syscall_arg__scnprintf_hex(char *bf, size_t size,
  18. unsigned long arg, u8 *arg_mask __maybe_unused)
  19. {
  20. return scnprintf(bf, size, "%#lx", arg);
  21. }
  22. #define SCA_HEX syscall_arg__scnprintf_hex
  23. static size_t syscall_arg__scnprintf_mmap_prot(char *bf, size_t size,
  24. unsigned long arg, u8 *arg_mask __maybe_unused)
  25. {
  26. int printed = 0, prot = arg;
  27. if (prot == PROT_NONE)
  28. return scnprintf(bf, size, "NONE");
  29. #define P_MMAP_PROT(n) \
  30. if (prot & PROT_##n) { \
  31. printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \
  32. prot &= ~PROT_##n; \
  33. }
  34. P_MMAP_PROT(EXEC);
  35. P_MMAP_PROT(READ);
  36. P_MMAP_PROT(WRITE);
  37. #ifdef PROT_SEM
  38. P_MMAP_PROT(SEM);
  39. #endif
  40. P_MMAP_PROT(GROWSDOWN);
  41. P_MMAP_PROT(GROWSUP);
  42. #undef P_MMAP_PROT
  43. if (prot)
  44. printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", prot);
  45. return printed;
  46. }
  47. #define SCA_MMAP_PROT syscall_arg__scnprintf_mmap_prot
  48. static size_t syscall_arg__scnprintf_mmap_flags(char *bf, size_t size,
  49. unsigned long arg, u8 *arg_mask __maybe_unused)
  50. {
  51. int printed = 0, flags = arg;
  52. #define P_MMAP_FLAG(n) \
  53. if (flags & MAP_##n) { \
  54. printed += scnprintf(bf + printed, size - printed, "%s%s", printed ? "|" : "", #n); \
  55. flags &= ~MAP_##n; \
  56. }
  57. P_MMAP_FLAG(SHARED);
  58. P_MMAP_FLAG(PRIVATE);
  59. P_MMAP_FLAG(32BIT);
  60. P_MMAP_FLAG(ANONYMOUS);
  61. P_MMAP_FLAG(DENYWRITE);
  62. P_MMAP_FLAG(EXECUTABLE);
  63. P_MMAP_FLAG(FILE);
  64. P_MMAP_FLAG(FIXED);
  65. P_MMAP_FLAG(GROWSDOWN);
  66. #ifdef MAP_HUGETLB
  67. P_MMAP_FLAG(HUGETLB);
  68. #endif
  69. P_MMAP_FLAG(LOCKED);
  70. P_MMAP_FLAG(NONBLOCK);
  71. P_MMAP_FLAG(NORESERVE);
  72. P_MMAP_FLAG(POPULATE);
  73. P_MMAP_FLAG(STACK);
  74. #ifdef MAP_UNINITIALIZED
  75. P_MMAP_FLAG(UNINITIALIZED);
  76. #endif
  77. #undef P_MMAP_FLAG
  78. if (flags)
  79. printed += scnprintf(bf + printed, size - printed, "%s%#x", printed ? "|" : "", flags);
  80. return printed;
  81. }
  82. #define SCA_MMAP_FLAGS syscall_arg__scnprintf_mmap_flags
  83. static size_t syscall_arg__scnprintf_madvise_behavior(char *bf, size_t size,
  84. unsigned long arg, u8 *arg_mask __maybe_unused)
  85. {
  86. int behavior = arg;
  87. switch (behavior) {
  88. #define P_MADV_BHV(n) case MADV_##n: return scnprintf(bf, size, #n)
  89. P_MADV_BHV(NORMAL);
  90. P_MADV_BHV(RANDOM);
  91. P_MADV_BHV(SEQUENTIAL);
  92. P_MADV_BHV(WILLNEED);
  93. P_MADV_BHV(DONTNEED);
  94. P_MADV_BHV(REMOVE);
  95. P_MADV_BHV(DONTFORK);
  96. P_MADV_BHV(DOFORK);
  97. P_MADV_BHV(HWPOISON);
  98. #ifdef MADV_SOFT_OFFLINE
  99. P_MADV_BHV(SOFT_OFFLINE);
  100. #endif
  101. P_MADV_BHV(MERGEABLE);
  102. P_MADV_BHV(UNMERGEABLE);
  103. #ifdef MADV_HUGEPAGE
  104. P_MADV_BHV(HUGEPAGE);
  105. #endif
  106. #ifdef MADV_NOHUGEPAGE
  107. P_MADV_BHV(NOHUGEPAGE);
  108. #endif
  109. #ifdef MADV_DONTDUMP
  110. P_MADV_BHV(DONTDUMP);
  111. #endif
  112. #ifdef MADV_DODUMP
  113. P_MADV_BHV(DODUMP);
  114. #endif
  115. #undef P_MADV_PHV
  116. default: break;
  117. }
  118. return scnprintf(bf, size, "%#x", behavior);
  119. }
  120. #define SCA_MADV_BHV syscall_arg__scnprintf_madvise_behavior
  121. static size_t syscall_arg__scnprintf_futex_op(char *bf, size_t size, unsigned long arg, u8 *arg_mask)
  122. {
  123. enum syscall_futex_args {
  124. SCF_UADDR = (1 << 0),
  125. SCF_OP = (1 << 1),
  126. SCF_VAL = (1 << 2),
  127. SCF_TIMEOUT = (1 << 3),
  128. SCF_UADDR2 = (1 << 4),
  129. SCF_VAL3 = (1 << 5),
  130. };
  131. int op = arg;
  132. int cmd = op & FUTEX_CMD_MASK;
  133. size_t printed = 0;
  134. switch (cmd) {
  135. #define P_FUTEX_OP(n) case FUTEX_##n: printed = scnprintf(bf, size, #n);
  136. P_FUTEX_OP(WAIT); *arg_mask |= SCF_VAL3|SCF_UADDR2; break;
  137. P_FUTEX_OP(WAKE); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break;
  138. P_FUTEX_OP(FD); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break;
  139. P_FUTEX_OP(REQUEUE); *arg_mask |= SCF_VAL3|SCF_TIMEOUT; break;
  140. P_FUTEX_OP(CMP_REQUEUE); *arg_mask |= SCF_TIMEOUT; break;
  141. P_FUTEX_OP(CMP_REQUEUE_PI); *arg_mask |= SCF_TIMEOUT; break;
  142. P_FUTEX_OP(WAKE_OP); break;
  143. P_FUTEX_OP(LOCK_PI); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break;
  144. P_FUTEX_OP(UNLOCK_PI); *arg_mask |= SCF_VAL3|SCF_UADDR2|SCF_TIMEOUT; break;
  145. P_FUTEX_OP(TRYLOCK_PI); *arg_mask |= SCF_VAL3|SCF_UADDR2; break;
  146. P_FUTEX_OP(WAIT_BITSET); *arg_mask |= SCF_UADDR2; break;
  147. P_FUTEX_OP(WAKE_BITSET); *arg_mask |= SCF_UADDR2; break;
  148. P_FUTEX_OP(WAIT_REQUEUE_PI); break;
  149. default: printed = scnprintf(bf, size, "%#x", cmd); break;
  150. }
  151. if (op & FUTEX_PRIVATE_FLAG)
  152. printed += scnprintf(bf + printed, size - printed, "|PRIV");
  153. if (op & FUTEX_CLOCK_REALTIME)
  154. printed += scnprintf(bf + printed, size - printed, "|CLKRT");
  155. return printed;
  156. }
  157. #define SCA_FUTEX_OP syscall_arg__scnprintf_futex_op
  158. static struct syscall_fmt {
  159. const char *name;
  160. const char *alias;
  161. size_t (*arg_scnprintf[6])(char *bf, size_t size, unsigned long arg, u8 *arg_mask);
  162. bool errmsg;
  163. bool timeout;
  164. bool hexret;
  165. } syscall_fmts[] = {
  166. { .name = "access", .errmsg = true, },
  167. { .name = "arch_prctl", .errmsg = true, .alias = "prctl", },
  168. { .name = "brk", .hexret = true,
  169. .arg_scnprintf = { [0] = SCA_HEX, /* brk */ }, },
  170. { .name = "mmap", .hexret = true, },
  171. { .name = "connect", .errmsg = true, },
  172. { .name = "fstat", .errmsg = true, .alias = "newfstat", },
  173. { .name = "fstatat", .errmsg = true, .alias = "newfstatat", },
  174. { .name = "futex", .errmsg = true,
  175. .arg_scnprintf = { [1] = SCA_FUTEX_OP, /* op */ }, },
  176. { .name = "ioctl", .errmsg = true,
  177. .arg_scnprintf = { [2] = SCA_HEX, /* arg */ }, },
  178. { .name = "lstat", .errmsg = true, .alias = "newlstat", },
  179. { .name = "madvise", .errmsg = true,
  180. .arg_scnprintf = { [0] = SCA_HEX, /* start */
  181. [2] = SCA_MADV_BHV, /* behavior */ }, },
  182. { .name = "mmap", .hexret = true,
  183. .arg_scnprintf = { [0] = SCA_HEX, /* addr */
  184. [2] = SCA_MMAP_PROT, /* prot */
  185. [3] = SCA_MMAP_FLAGS, /* flags */ }, },
  186. { .name = "mprotect", .errmsg = true,
  187. .arg_scnprintf = { [0] = SCA_HEX, /* start */
  188. [2] = SCA_MMAP_PROT, /* prot */ }, },
  189. { .name = "mremap", .hexret = true,
  190. .arg_scnprintf = { [0] = SCA_HEX, /* addr */
  191. [4] = SCA_HEX, /* new_addr */ }, },
  192. { .name = "munmap", .errmsg = true,
  193. .arg_scnprintf = { [0] = SCA_HEX, /* addr */ }, },
  194. { .name = "open", .errmsg = true, },
  195. { .name = "poll", .errmsg = true, .timeout = true, },
  196. { .name = "ppoll", .errmsg = true, .timeout = true, },
  197. { .name = "pread", .errmsg = true, .alias = "pread64", },
  198. { .name = "pwrite", .errmsg = true, .alias = "pwrite64", },
  199. { .name = "read", .errmsg = true, },
  200. { .name = "recvfrom", .errmsg = true, },
  201. { .name = "select", .errmsg = true, .timeout = true, },
  202. { .name = "socket", .errmsg = true, },
  203. { .name = "stat", .errmsg = true, .alias = "newstat", },
  204. { .name = "uname", .errmsg = true, .alias = "newuname", },
  205. };
  206. static int syscall_fmt__cmp(const void *name, const void *fmtp)
  207. {
  208. const struct syscall_fmt *fmt = fmtp;
  209. return strcmp(name, fmt->name);
  210. }
  211. static struct syscall_fmt *syscall_fmt__find(const char *name)
  212. {
  213. const int nmemb = ARRAY_SIZE(syscall_fmts);
  214. return bsearch(name, syscall_fmts, nmemb, sizeof(struct syscall_fmt), syscall_fmt__cmp);
  215. }
  216. struct syscall {
  217. struct event_format *tp_format;
  218. const char *name;
  219. bool filtered;
  220. struct syscall_fmt *fmt;
  221. size_t (**arg_scnprintf)(char *bf, size_t size,
  222. unsigned long arg, u8 *args_mask);
  223. };
  224. static size_t fprintf_duration(unsigned long t, FILE *fp)
  225. {
  226. double duration = (double)t / NSEC_PER_MSEC;
  227. size_t printed = fprintf(fp, "(");
  228. if (duration >= 1.0)
  229. printed += color_fprintf(fp, PERF_COLOR_RED, "%6.3f ms", duration);
  230. else if (duration >= 0.01)
  231. printed += color_fprintf(fp, PERF_COLOR_YELLOW, "%6.3f ms", duration);
  232. else
  233. printed += color_fprintf(fp, PERF_COLOR_NORMAL, "%6.3f ms", duration);
  234. return printed + fprintf(fp, "): ");
  235. }
  236. struct thread_trace {
  237. u64 entry_time;
  238. u64 exit_time;
  239. bool entry_pending;
  240. unsigned long nr_events;
  241. char *entry_str;
  242. double runtime_ms;
  243. };
  244. static struct thread_trace *thread_trace__new(void)
  245. {
  246. return zalloc(sizeof(struct thread_trace));
  247. }
  248. static struct thread_trace *thread__trace(struct thread *thread, FILE *fp)
  249. {
  250. struct thread_trace *ttrace;
  251. if (thread == NULL)
  252. goto fail;
  253. if (thread->priv == NULL)
  254. thread->priv = thread_trace__new();
  255. if (thread->priv == NULL)
  256. goto fail;
  257. ttrace = thread->priv;
  258. ++ttrace->nr_events;
  259. return ttrace;
  260. fail:
  261. color_fprintf(fp, PERF_COLOR_RED,
  262. "WARNING: not enough memory, dropping samples!\n");
  263. return NULL;
  264. }
  265. struct trace {
  266. struct perf_tool tool;
  267. int audit_machine;
  268. struct {
  269. int max;
  270. struct syscall *table;
  271. } syscalls;
  272. struct perf_record_opts opts;
  273. struct machine host;
  274. u64 base_time;
  275. FILE *output;
  276. unsigned long nr_events;
  277. struct strlist *ev_qualifier;
  278. bool not_ev_qualifier;
  279. struct intlist *tid_list;
  280. struct intlist *pid_list;
  281. bool sched;
  282. bool multiple_threads;
  283. double duration_filter;
  284. double runtime_ms;
  285. };
  286. static bool trace__filter_duration(struct trace *trace, double t)
  287. {
  288. return t < (trace->duration_filter * NSEC_PER_MSEC);
  289. }
  290. static size_t trace__fprintf_tstamp(struct trace *trace, u64 tstamp, FILE *fp)
  291. {
  292. double ts = (double)(tstamp - trace->base_time) / NSEC_PER_MSEC;
  293. return fprintf(fp, "%10.3f ", ts);
  294. }
  295. static bool done = false;
  296. static void sig_handler(int sig __maybe_unused)
  297. {
  298. done = true;
  299. }
  300. static size_t trace__fprintf_entry_head(struct trace *trace, struct thread *thread,
  301. u64 duration, u64 tstamp, FILE *fp)
  302. {
  303. size_t printed = trace__fprintf_tstamp(trace, tstamp, fp);
  304. printed += fprintf_duration(duration, fp);
  305. if (trace->multiple_threads)
  306. printed += fprintf(fp, "%d ", thread->tid);
  307. return printed;
  308. }
  309. static int trace__process_event(struct trace *trace, struct machine *machine,
  310. union perf_event *event)
  311. {
  312. int ret = 0;
  313. switch (event->header.type) {
  314. case PERF_RECORD_LOST:
  315. color_fprintf(trace->output, PERF_COLOR_RED,
  316. "LOST %" PRIu64 " events!\n", event->lost.lost);
  317. ret = machine__process_lost_event(machine, event);
  318. default:
  319. ret = machine__process_event(machine, event);
  320. break;
  321. }
  322. return ret;
  323. }
  324. static int trace__tool_process(struct perf_tool *tool,
  325. union perf_event *event,
  326. struct perf_sample *sample __maybe_unused,
  327. struct machine *machine)
  328. {
  329. struct trace *trace = container_of(tool, struct trace, tool);
  330. return trace__process_event(trace, machine, event);
  331. }
  332. static int trace__symbols_init(struct trace *trace, struct perf_evlist *evlist)
  333. {
  334. int err = symbol__init();
  335. if (err)
  336. return err;
  337. machine__init(&trace->host, "", HOST_KERNEL_ID);
  338. machine__create_kernel_maps(&trace->host);
  339. if (perf_target__has_task(&trace->opts.target)) {
  340. err = perf_event__synthesize_thread_map(&trace->tool, evlist->threads,
  341. trace__tool_process,
  342. &trace->host);
  343. } else {
  344. err = perf_event__synthesize_threads(&trace->tool, trace__tool_process,
  345. &trace->host);
  346. }
  347. if (err)
  348. symbol__exit();
  349. return err;
  350. }
  351. static int syscall__set_arg_fmts(struct syscall *sc)
  352. {
  353. struct format_field *field;
  354. int idx = 0;
  355. sc->arg_scnprintf = calloc(sc->tp_format->format.nr_fields - 1, sizeof(void *));
  356. if (sc->arg_scnprintf == NULL)
  357. return -1;
  358. for (field = sc->tp_format->format.fields->next; field; field = field->next) {
  359. if (sc->fmt && sc->fmt->arg_scnprintf[idx])
  360. sc->arg_scnprintf[idx] = sc->fmt->arg_scnprintf[idx];
  361. else if (field->flags & FIELD_IS_POINTER)
  362. sc->arg_scnprintf[idx] = syscall_arg__scnprintf_hex;
  363. ++idx;
  364. }
  365. return 0;
  366. }
  367. static int trace__read_syscall_info(struct trace *trace, int id)
  368. {
  369. char tp_name[128];
  370. struct syscall *sc;
  371. const char *name = audit_syscall_to_name(id, trace->audit_machine);
  372. if (name == NULL)
  373. return -1;
  374. if (id > trace->syscalls.max) {
  375. struct syscall *nsyscalls = realloc(trace->syscalls.table, (id + 1) * sizeof(*sc));
  376. if (nsyscalls == NULL)
  377. return -1;
  378. if (trace->syscalls.max != -1) {
  379. memset(nsyscalls + trace->syscalls.max + 1, 0,
  380. (id - trace->syscalls.max) * sizeof(*sc));
  381. } else {
  382. memset(nsyscalls, 0, (id + 1) * sizeof(*sc));
  383. }
  384. trace->syscalls.table = nsyscalls;
  385. trace->syscalls.max = id;
  386. }
  387. sc = trace->syscalls.table + id;
  388. sc->name = name;
  389. if (trace->ev_qualifier) {
  390. bool in = strlist__find(trace->ev_qualifier, name) != NULL;
  391. if (!(in ^ trace->not_ev_qualifier)) {
  392. sc->filtered = true;
  393. /*
  394. * No need to do read tracepoint information since this will be
  395. * filtered out.
  396. */
  397. return 0;
  398. }
  399. }
  400. sc->fmt = syscall_fmt__find(sc->name);
  401. snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->name);
  402. sc->tp_format = event_format__new("syscalls", tp_name);
  403. if (sc->tp_format == NULL && sc->fmt && sc->fmt->alias) {
  404. snprintf(tp_name, sizeof(tp_name), "sys_enter_%s", sc->fmt->alias);
  405. sc->tp_format = event_format__new("syscalls", tp_name);
  406. }
  407. if (sc->tp_format == NULL)
  408. return -1;
  409. return syscall__set_arg_fmts(sc);
  410. }
  411. static size_t syscall__scnprintf_args(struct syscall *sc, char *bf, size_t size,
  412. unsigned long *args)
  413. {
  414. int i = 0;
  415. size_t printed = 0;
  416. if (sc->tp_format != NULL) {
  417. struct format_field *field;
  418. u8 mask = 0, bit = 1;
  419. for (field = sc->tp_format->format.fields->next; field;
  420. field = field->next, ++i, bit <<= 1) {
  421. if (mask & bit)
  422. continue;
  423. printed += scnprintf(bf + printed, size - printed,
  424. "%s%s: ", printed ? ", " : "", field->name);
  425. if (sc->arg_scnprintf && sc->arg_scnprintf[i]) {
  426. printed += sc->arg_scnprintf[i](bf + printed, size - printed,
  427. args[i], &mask);
  428. } else {
  429. printed += scnprintf(bf + printed, size - printed,
  430. "%ld", args[i]);
  431. }
  432. }
  433. } else {
  434. while (i < 6) {
  435. printed += scnprintf(bf + printed, size - printed,
  436. "%sarg%d: %ld",
  437. printed ? ", " : "", i, args[i]);
  438. ++i;
  439. }
  440. }
  441. return printed;
  442. }
  443. typedef int (*tracepoint_handler)(struct trace *trace, struct perf_evsel *evsel,
  444. struct perf_sample *sample);
  445. static struct syscall *trace__syscall_info(struct trace *trace,
  446. struct perf_evsel *evsel,
  447. struct perf_sample *sample)
  448. {
  449. int id = perf_evsel__intval(evsel, sample, "id");
  450. if (id < 0) {
  451. /*
  452. * XXX: Noticed on x86_64, reproduced as far back as 3.0.36, haven't tried
  453. * before that, leaving at a higher verbosity level till that is
  454. * explained. Reproduced with plain ftrace with:
  455. *
  456. * echo 1 > /t/events/raw_syscalls/sys_exit/enable
  457. * grep "NR -1 " /t/trace_pipe
  458. *
  459. * After generating some load on the machine.
  460. */
  461. if (verbose > 1) {
  462. static u64 n;
  463. fprintf(trace->output, "Invalid syscall %d id, skipping (%s, %" PRIu64 ") ...\n",
  464. id, perf_evsel__name(evsel), ++n);
  465. }
  466. return NULL;
  467. }
  468. if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL) &&
  469. trace__read_syscall_info(trace, id))
  470. goto out_cant_read;
  471. if ((id > trace->syscalls.max || trace->syscalls.table[id].name == NULL))
  472. goto out_cant_read;
  473. return &trace->syscalls.table[id];
  474. out_cant_read:
  475. if (verbose) {
  476. fprintf(trace->output, "Problems reading syscall %d", id);
  477. if (id <= trace->syscalls.max && trace->syscalls.table[id].name != NULL)
  478. fprintf(trace->output, "(%s)", trace->syscalls.table[id].name);
  479. fputs(" information\n", trace->output);
  480. }
  481. return NULL;
  482. }
  483. static int trace__sys_enter(struct trace *trace, struct perf_evsel *evsel,
  484. struct perf_sample *sample)
  485. {
  486. char *msg;
  487. void *args;
  488. size_t printed = 0;
  489. struct thread *thread;
  490. struct syscall *sc = trace__syscall_info(trace, evsel, sample);
  491. struct thread_trace *ttrace;
  492. if (sc == NULL)
  493. return -1;
  494. if (sc->filtered)
  495. return 0;
  496. thread = machine__findnew_thread(&trace->host, sample->pid,
  497. sample->tid);
  498. ttrace = thread__trace(thread, trace->output);
  499. if (ttrace == NULL)
  500. return -1;
  501. args = perf_evsel__rawptr(evsel, sample, "args");
  502. if (args == NULL) {
  503. fprintf(trace->output, "Problems reading syscall arguments\n");
  504. return -1;
  505. }
  506. ttrace = thread->priv;
  507. if (ttrace->entry_str == NULL) {
  508. ttrace->entry_str = malloc(1024);
  509. if (!ttrace->entry_str)
  510. return -1;
  511. }
  512. ttrace->entry_time = sample->time;
  513. msg = ttrace->entry_str;
  514. printed += scnprintf(msg + printed, 1024 - printed, "%s(", sc->name);
  515. printed += syscall__scnprintf_args(sc, msg + printed, 1024 - printed, args);
  516. if (!strcmp(sc->name, "exit_group") || !strcmp(sc->name, "exit")) {
  517. if (!trace->duration_filter) {
  518. trace__fprintf_entry_head(trace, thread, 1, sample->time, trace->output);
  519. fprintf(trace->output, "%-70s\n", ttrace->entry_str);
  520. }
  521. } else
  522. ttrace->entry_pending = true;
  523. return 0;
  524. }
  525. static int trace__sys_exit(struct trace *trace, struct perf_evsel *evsel,
  526. struct perf_sample *sample)
  527. {
  528. int ret;
  529. u64 duration = 0;
  530. struct thread *thread;
  531. struct syscall *sc = trace__syscall_info(trace, evsel, sample);
  532. struct thread_trace *ttrace;
  533. if (sc == NULL)
  534. return -1;
  535. if (sc->filtered)
  536. return 0;
  537. thread = machine__findnew_thread(&trace->host, sample->pid,
  538. sample->tid);
  539. ttrace = thread__trace(thread, trace->output);
  540. if (ttrace == NULL)
  541. return -1;
  542. ret = perf_evsel__intval(evsel, sample, "ret");
  543. ttrace = thread->priv;
  544. ttrace->exit_time = sample->time;
  545. if (ttrace->entry_time) {
  546. duration = sample->time - ttrace->entry_time;
  547. if (trace__filter_duration(trace, duration))
  548. goto out;
  549. } else if (trace->duration_filter)
  550. goto out;
  551. trace__fprintf_entry_head(trace, thread, duration, sample->time, trace->output);
  552. if (ttrace->entry_pending) {
  553. fprintf(trace->output, "%-70s", ttrace->entry_str);
  554. } else {
  555. fprintf(trace->output, " ... [");
  556. color_fprintf(trace->output, PERF_COLOR_YELLOW, "continued");
  557. fprintf(trace->output, "]: %s()", sc->name);
  558. }
  559. if (sc->fmt == NULL) {
  560. signed_print:
  561. fprintf(trace->output, ") = %d", ret);
  562. } else if (ret < 0 && sc->fmt->errmsg) {
  563. char bf[256];
  564. const char *emsg = strerror_r(-ret, bf, sizeof(bf)),
  565. *e = audit_errno_to_name(-ret);
  566. fprintf(trace->output, ") = -1 %s %s", e, emsg);
  567. } else if (ret == 0 && sc->fmt->timeout)
  568. fprintf(trace->output, ") = 0 Timeout");
  569. else if (sc->fmt->hexret)
  570. fprintf(trace->output, ") = %#x", ret);
  571. else
  572. goto signed_print;
  573. fputc('\n', trace->output);
  574. out:
  575. ttrace->entry_pending = false;
  576. return 0;
  577. }
  578. static int trace__sched_stat_runtime(struct trace *trace, struct perf_evsel *evsel,
  579. struct perf_sample *sample)
  580. {
  581. u64 runtime = perf_evsel__intval(evsel, sample, "runtime");
  582. double runtime_ms = (double)runtime / NSEC_PER_MSEC;
  583. struct thread *thread = machine__findnew_thread(&trace->host,
  584. sample->pid,
  585. sample->tid);
  586. struct thread_trace *ttrace = thread__trace(thread, trace->output);
  587. if (ttrace == NULL)
  588. goto out_dump;
  589. ttrace->runtime_ms += runtime_ms;
  590. trace->runtime_ms += runtime_ms;
  591. return 0;
  592. out_dump:
  593. fprintf(trace->output, "%s: comm=%s,pid=%u,runtime=%" PRIu64 ",vruntime=%" PRIu64 ")\n",
  594. evsel->name,
  595. perf_evsel__strval(evsel, sample, "comm"),
  596. (pid_t)perf_evsel__intval(evsel, sample, "pid"),
  597. runtime,
  598. perf_evsel__intval(evsel, sample, "vruntime"));
  599. return 0;
  600. }
  601. static bool skip_sample(struct trace *trace, struct perf_sample *sample)
  602. {
  603. if ((trace->pid_list && intlist__find(trace->pid_list, sample->pid)) ||
  604. (trace->tid_list && intlist__find(trace->tid_list, sample->tid)))
  605. return false;
  606. if (trace->pid_list || trace->tid_list)
  607. return true;
  608. return false;
  609. }
  610. static int trace__process_sample(struct perf_tool *tool,
  611. union perf_event *event __maybe_unused,
  612. struct perf_sample *sample,
  613. struct perf_evsel *evsel,
  614. struct machine *machine __maybe_unused)
  615. {
  616. struct trace *trace = container_of(tool, struct trace, tool);
  617. int err = 0;
  618. tracepoint_handler handler = evsel->handler.func;
  619. if (skip_sample(trace, sample))
  620. return 0;
  621. if (trace->base_time == 0)
  622. trace->base_time = sample->time;
  623. if (handler)
  624. handler(trace, evsel, sample);
  625. return err;
  626. }
  627. static bool
  628. perf_session__has_tp(struct perf_session *session, const char *name)
  629. {
  630. struct perf_evsel *evsel;
  631. evsel = perf_evlist__find_tracepoint_by_name(session->evlist, name);
  632. return evsel != NULL;
  633. }
  634. static int parse_target_str(struct trace *trace)
  635. {
  636. if (trace->opts.target.pid) {
  637. trace->pid_list = intlist__new(trace->opts.target.pid);
  638. if (trace->pid_list == NULL) {
  639. pr_err("Error parsing process id string\n");
  640. return -EINVAL;
  641. }
  642. }
  643. if (trace->opts.target.tid) {
  644. trace->tid_list = intlist__new(trace->opts.target.tid);
  645. if (trace->tid_list == NULL) {
  646. pr_err("Error parsing thread id string\n");
  647. return -EINVAL;
  648. }
  649. }
  650. return 0;
  651. }
  652. static int trace__run(struct trace *trace, int argc, const char **argv)
  653. {
  654. struct perf_evlist *evlist = perf_evlist__new();
  655. struct perf_evsel *evsel;
  656. int err = -1, i;
  657. unsigned long before;
  658. const bool forks = argc > 0;
  659. if (evlist == NULL) {
  660. fprintf(trace->output, "Not enough memory to run!\n");
  661. goto out;
  662. }
  663. if (perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_enter", trace__sys_enter) ||
  664. perf_evlist__add_newtp(evlist, "raw_syscalls", "sys_exit", trace__sys_exit)) {
  665. fprintf(trace->output, "Couldn't read the raw_syscalls tracepoints information!\n");
  666. goto out_delete_evlist;
  667. }
  668. if (trace->sched &&
  669. perf_evlist__add_newtp(evlist, "sched", "sched_stat_runtime",
  670. trace__sched_stat_runtime)) {
  671. fprintf(trace->output, "Couldn't read the sched_stat_runtime tracepoint information!\n");
  672. goto out_delete_evlist;
  673. }
  674. err = perf_evlist__create_maps(evlist, &trace->opts.target);
  675. if (err < 0) {
  676. fprintf(trace->output, "Problems parsing the target to trace, check your options!\n");
  677. goto out_delete_evlist;
  678. }
  679. err = trace__symbols_init(trace, evlist);
  680. if (err < 0) {
  681. fprintf(trace->output, "Problems initializing symbol libraries!\n");
  682. goto out_delete_maps;
  683. }
  684. perf_evlist__config(evlist, &trace->opts);
  685. signal(SIGCHLD, sig_handler);
  686. signal(SIGINT, sig_handler);
  687. if (forks) {
  688. err = perf_evlist__prepare_workload(evlist, &trace->opts.target,
  689. argv, false, false);
  690. if (err < 0) {
  691. fprintf(trace->output, "Couldn't run the workload!\n");
  692. goto out_delete_maps;
  693. }
  694. }
  695. err = perf_evlist__open(evlist);
  696. if (err < 0) {
  697. fprintf(trace->output, "Couldn't create the events: %s\n", strerror(errno));
  698. goto out_delete_maps;
  699. }
  700. err = perf_evlist__mmap(evlist, UINT_MAX, false);
  701. if (err < 0) {
  702. fprintf(trace->output, "Couldn't mmap the events: %s\n", strerror(errno));
  703. goto out_close_evlist;
  704. }
  705. perf_evlist__enable(evlist);
  706. if (forks)
  707. perf_evlist__start_workload(evlist);
  708. trace->multiple_threads = evlist->threads->map[0] == -1 || evlist->threads->nr > 1;
  709. again:
  710. before = trace->nr_events;
  711. for (i = 0; i < evlist->nr_mmaps; i++) {
  712. union perf_event *event;
  713. while ((event = perf_evlist__mmap_read(evlist, i)) != NULL) {
  714. const u32 type = event->header.type;
  715. tracepoint_handler handler;
  716. struct perf_sample sample;
  717. ++trace->nr_events;
  718. err = perf_evlist__parse_sample(evlist, event, &sample);
  719. if (err) {
  720. fprintf(trace->output, "Can't parse sample, err = %d, skipping...\n", err);
  721. continue;
  722. }
  723. if (trace->base_time == 0)
  724. trace->base_time = sample.time;
  725. if (type != PERF_RECORD_SAMPLE) {
  726. trace__process_event(trace, &trace->host, event);
  727. continue;
  728. }
  729. evsel = perf_evlist__id2evsel(evlist, sample.id);
  730. if (evsel == NULL) {
  731. fprintf(trace->output, "Unknown tp ID %" PRIu64 ", skipping...\n", sample.id);
  732. continue;
  733. }
  734. if (sample.raw_data == NULL) {
  735. fprintf(trace->output, "%s sample with no payload for tid: %d, cpu %d, raw_size=%d, skipping...\n",
  736. perf_evsel__name(evsel), sample.tid,
  737. sample.cpu, sample.raw_size);
  738. continue;
  739. }
  740. handler = evsel->handler.func;
  741. handler(trace, evsel, &sample);
  742. }
  743. }
  744. if (trace->nr_events == before) {
  745. if (done)
  746. goto out_unmap_evlist;
  747. poll(evlist->pollfd, evlist->nr_fds, -1);
  748. }
  749. if (done)
  750. perf_evlist__disable(evlist);
  751. goto again;
  752. out_unmap_evlist:
  753. perf_evlist__munmap(evlist);
  754. out_close_evlist:
  755. perf_evlist__close(evlist);
  756. out_delete_maps:
  757. perf_evlist__delete_maps(evlist);
  758. out_delete_evlist:
  759. perf_evlist__delete(evlist);
  760. out:
  761. return err;
  762. }
  763. static int trace__replay(struct trace *trace)
  764. {
  765. const struct perf_evsel_str_handler handlers[] = {
  766. { "raw_syscalls:sys_enter", trace__sys_enter, },
  767. { "raw_syscalls:sys_exit", trace__sys_exit, },
  768. };
  769. struct perf_session *session;
  770. int err = -1;
  771. trace->tool.sample = trace__process_sample;
  772. trace->tool.mmap = perf_event__process_mmap;
  773. trace->tool.comm = perf_event__process_comm;
  774. trace->tool.exit = perf_event__process_exit;
  775. trace->tool.fork = perf_event__process_fork;
  776. trace->tool.attr = perf_event__process_attr;
  777. trace->tool.tracing_data = perf_event__process_tracing_data;
  778. trace->tool.build_id = perf_event__process_build_id;
  779. trace->tool.ordered_samples = true;
  780. trace->tool.ordering_requires_timestamps = true;
  781. /* add tid to output */
  782. trace->multiple_threads = true;
  783. if (symbol__init() < 0)
  784. return -1;
  785. session = perf_session__new(input_name, O_RDONLY, 0, false,
  786. &trace->tool);
  787. if (session == NULL)
  788. return -ENOMEM;
  789. err = perf_session__set_tracepoints_handlers(session, handlers);
  790. if (err)
  791. goto out;
  792. if (!perf_session__has_tp(session, "raw_syscalls:sys_enter")) {
  793. pr_err("Data file does not have raw_syscalls:sys_enter events\n");
  794. goto out;
  795. }
  796. if (!perf_session__has_tp(session, "raw_syscalls:sys_exit")) {
  797. pr_err("Data file does not have raw_syscalls:sys_exit events\n");
  798. goto out;
  799. }
  800. err = parse_target_str(trace);
  801. if (err != 0)
  802. goto out;
  803. setup_pager();
  804. err = perf_session__process_events(session, &trace->tool);
  805. if (err)
  806. pr_err("Failed to process events, error %d", err);
  807. out:
  808. perf_session__delete(session);
  809. return err;
  810. }
  811. static size_t trace__fprintf_threads_header(FILE *fp)
  812. {
  813. size_t printed;
  814. printed = fprintf(fp, "\n _____________________________________________________________________\n");
  815. printed += fprintf(fp," __) Summary of events (__\n\n");
  816. printed += fprintf(fp," [ task - pid ] [ events ] [ ratio ] [ runtime ]\n");
  817. printed += fprintf(fp," _____________________________________________________________________\n\n");
  818. return printed;
  819. }
  820. static size_t trace__fprintf_thread_summary(struct trace *trace, FILE *fp)
  821. {
  822. size_t printed = trace__fprintf_threads_header(fp);
  823. struct rb_node *nd;
  824. for (nd = rb_first(&trace->host.threads); nd; nd = rb_next(nd)) {
  825. struct thread *thread = rb_entry(nd, struct thread, rb_node);
  826. struct thread_trace *ttrace = thread->priv;
  827. const char *color;
  828. double ratio;
  829. if (ttrace == NULL)
  830. continue;
  831. ratio = (double)ttrace->nr_events / trace->nr_events * 100.0;
  832. color = PERF_COLOR_NORMAL;
  833. if (ratio > 50.0)
  834. color = PERF_COLOR_RED;
  835. else if (ratio > 25.0)
  836. color = PERF_COLOR_GREEN;
  837. else if (ratio > 5.0)
  838. color = PERF_COLOR_YELLOW;
  839. printed += color_fprintf(fp, color, "%20s", thread->comm);
  840. printed += fprintf(fp, " - %-5d :%11lu [", thread->tid, ttrace->nr_events);
  841. printed += color_fprintf(fp, color, "%5.1f%%", ratio);
  842. printed += fprintf(fp, " ] %10.3f ms\n", ttrace->runtime_ms);
  843. }
  844. return printed;
  845. }
  846. static int trace__set_duration(const struct option *opt, const char *str,
  847. int unset __maybe_unused)
  848. {
  849. struct trace *trace = opt->value;
  850. trace->duration_filter = atof(str);
  851. return 0;
  852. }
  853. static int trace__open_output(struct trace *trace, const char *filename)
  854. {
  855. struct stat st;
  856. if (!stat(filename, &st) && st.st_size) {
  857. char oldname[PATH_MAX];
  858. scnprintf(oldname, sizeof(oldname), "%s.old", filename);
  859. unlink(oldname);
  860. rename(filename, oldname);
  861. }
  862. trace->output = fopen(filename, "w");
  863. return trace->output == NULL ? -errno : 0;
  864. }
  865. int cmd_trace(int argc, const char **argv, const char *prefix __maybe_unused)
  866. {
  867. const char * const trace_usage[] = {
  868. "perf trace [<options>] [<command>]",
  869. "perf trace [<options>] -- <command> [<options>]",
  870. NULL
  871. };
  872. struct trace trace = {
  873. .audit_machine = audit_detect_machine(),
  874. .syscalls = {
  875. . max = -1,
  876. },
  877. .opts = {
  878. .target = {
  879. .uid = UINT_MAX,
  880. .uses_mmap = true,
  881. },
  882. .user_freq = UINT_MAX,
  883. .user_interval = ULLONG_MAX,
  884. .no_delay = true,
  885. .mmap_pages = 1024,
  886. },
  887. .output = stdout,
  888. };
  889. const char *output_name = NULL;
  890. const char *ev_qualifier_str = NULL;
  891. const struct option trace_options[] = {
  892. OPT_STRING('e', "expr", &ev_qualifier_str, "expr",
  893. "list of events to trace"),
  894. OPT_STRING('o', "output", &output_name, "file", "output file name"),
  895. OPT_STRING('i', "input", &input_name, "file", "Analyze events in file"),
  896. OPT_STRING('p', "pid", &trace.opts.target.pid, "pid",
  897. "trace events on existing process id"),
  898. OPT_STRING('t', "tid", &trace.opts.target.tid, "tid",
  899. "trace events on existing thread id"),
  900. OPT_BOOLEAN('a', "all-cpus", &trace.opts.target.system_wide,
  901. "system-wide collection from all CPUs"),
  902. OPT_STRING('C', "cpu", &trace.opts.target.cpu_list, "cpu",
  903. "list of cpus to monitor"),
  904. OPT_BOOLEAN(0, "no-inherit", &trace.opts.no_inherit,
  905. "child tasks do not inherit counters"),
  906. OPT_UINTEGER('m', "mmap-pages", &trace.opts.mmap_pages,
  907. "number of mmap data pages"),
  908. OPT_STRING('u', "uid", &trace.opts.target.uid_str, "user",
  909. "user to profile"),
  910. OPT_CALLBACK(0, "duration", &trace, "float",
  911. "show only events with duration > N.M ms",
  912. trace__set_duration),
  913. OPT_BOOLEAN(0, "sched", &trace.sched, "show blocking scheduler events"),
  914. OPT_INCR('v', "verbose", &verbose, "be more verbose"),
  915. OPT_END()
  916. };
  917. int err;
  918. char bf[BUFSIZ];
  919. argc = parse_options(argc, argv, trace_options, trace_usage, 0);
  920. if (output_name != NULL) {
  921. err = trace__open_output(&trace, output_name);
  922. if (err < 0) {
  923. perror("failed to create output file");
  924. goto out;
  925. }
  926. }
  927. if (ev_qualifier_str != NULL) {
  928. const char *s = ev_qualifier_str;
  929. trace.not_ev_qualifier = *s == '!';
  930. if (trace.not_ev_qualifier)
  931. ++s;
  932. trace.ev_qualifier = strlist__new(true, s);
  933. if (trace.ev_qualifier == NULL) {
  934. fputs("Not enough memory to parse event qualifier",
  935. trace.output);
  936. err = -ENOMEM;
  937. goto out_close;
  938. }
  939. }
  940. err = perf_target__validate(&trace.opts.target);
  941. if (err) {
  942. perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
  943. fprintf(trace.output, "%s", bf);
  944. goto out_close;
  945. }
  946. err = perf_target__parse_uid(&trace.opts.target);
  947. if (err) {
  948. perf_target__strerror(&trace.opts.target, err, bf, sizeof(bf));
  949. fprintf(trace.output, "%s", bf);
  950. goto out_close;
  951. }
  952. if (!argc && perf_target__none(&trace.opts.target))
  953. trace.opts.target.system_wide = true;
  954. if (input_name)
  955. err = trace__replay(&trace);
  956. else
  957. err = trace__run(&trace, argc, argv);
  958. if (trace.sched && !err)
  959. trace__fprintf_thread_summary(&trace, trace.output);
  960. out_close:
  961. if (output_name != NULL)
  962. fclose(trace.output);
  963. out:
  964. return err;
  965. }