Mirror of strace – the linux syscall tracer
You can not select more than 25 topics Topics must start with a letter or number, can include dashes ('-') and can be up to 35 characters long.

count.c 13KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398399400401402403404405406407408409410411412413414415416417418419420421422423424425426427428429430431432433434435436437438439440441442443444445446447448449450451452453454455456457458459460461462463464465466467468469470471472473474475476477478479480481482483484485486487488489490491492493494495496497498499500501502503504505506507508509510511512513514515516517518519520521522523524
  1. /*
  2. * Copyright (c) 1991, 1992 Paul Kranenburg <pk@cs.few.eur.nl>
  3. * Copyright (c) 1993 Branko Lankester <branko@hacktic.nl>
  4. * Copyright (c) 1993, 1994, 1995, 1996 Rick Sladkey <jrs@world.std.com>
  5. * Copyright (c) 1996-1999 Wichert Akkerman <wichert@cistron.nl>
  6. * Copyright (c) 1999 IBM Deutschland Entwicklung GmbH, IBM Corporation
  7. * Linux for s390 port by D.J. Barrow
  8. * <barrow_dj@mail.yahoo.com,djbarrow@de.ibm.com>
  9. * Copyright (c) 2004 Roland McGrath <roland@redhat.com>
  10. * Copyright (c) 2006 Dmitry V. Levin <ldv@altlinux.org>
  11. * Copyright (c) 2006-2020 The strace developers.
  12. * All rights reserved.
  13. *
  14. * SPDX-License-Identifier: LGPL-2.1-or-later
  15. */
  16. #include "defs.h"
  17. #include <stdarg.h>
  18. /* Per-syscall stats structure */
  19. struct call_counts {
  20. /* time may be total latency or system time */
  21. struct timespec time;
  22. struct timespec time_min;
  23. struct timespec time_max;
  24. struct timespec time_avg;
  25. uint64_t calls, errors;
  26. };
  27. static struct call_counts *countv[SUPPORTED_PERSONALITIES];
  28. #define counts (countv[current_personality])
  29. static const struct timespec zero_ts;
  30. static const struct timespec max_ts = {
  31. (time_t) (long long) (zero_extend_signed_to_ull((time_t) -1ULL) >> 1),
  32. 999999999 };
  33. static struct timespec overhead;
  34. enum count_summary_columns {
  35. CSC_NONE,
  36. CSC_TIME_100S,
  37. CSC_TIME_TOTAL,
  38. CSC_TIME_MIN,
  39. CSC_TIME_MAX,
  40. CSC_TIME_AVG,
  41. CSC_CALLS,
  42. CSC_ERRORS,
  43. CSC_SC_NAME,
  44. CSC_MAX,
  45. };
  46. static uint8_t columns[CSC_MAX] = {
  47. CSC_TIME_100S,
  48. CSC_TIME_TOTAL,
  49. CSC_TIME_AVG,
  50. CSC_CALLS,
  51. CSC_ERRORS,
  52. CSC_SC_NAME,
  53. };
  54. static const struct {
  55. const char *name;
  56. uint8_t column;
  57. } column_aliases[] = {
  58. { "time", CSC_TIME_100S },
  59. { "time_percent", CSC_TIME_100S },
  60. { "time-percent", CSC_TIME_100S },
  61. { "time_total", CSC_TIME_TOTAL },
  62. { "time-total", CSC_TIME_TOTAL },
  63. { "total_time", CSC_TIME_TOTAL },
  64. { "total-time", CSC_TIME_TOTAL },
  65. { "min_time", CSC_TIME_MIN },
  66. { "min-time", CSC_TIME_MIN },
  67. { "shortest", CSC_TIME_MIN },
  68. { "time_min", CSC_TIME_MIN },
  69. { "time-min", CSC_TIME_MIN },
  70. { "longest" , CSC_TIME_MAX },
  71. { "max_time", CSC_TIME_MAX },
  72. { "max-time", CSC_TIME_MAX },
  73. { "time_max", CSC_TIME_MAX },
  74. { "time-max", CSC_TIME_MAX },
  75. { "avg_time", CSC_TIME_AVG },
  76. { "avg-time", CSC_TIME_AVG },
  77. { "time_avg", CSC_TIME_AVG },
  78. { "time-avg", CSC_TIME_AVG },
  79. { "calls", CSC_CALLS },
  80. { "count", CSC_CALLS },
  81. { "error", CSC_ERRORS },
  82. { "errors", CSC_ERRORS },
  83. { "name", CSC_SC_NAME },
  84. { "syscall", CSC_SC_NAME },
  85. { "syscall_name", CSC_SC_NAME },
  86. { "syscall-name", CSC_SC_NAME },
  87. { "none", CSC_NONE },
  88. { "nothing", CSC_NONE },
  89. };
  90. void
  91. count_syscall(struct tcb *tcp, const struct timespec *syscall_exiting_ts)
  92. {
  93. if (!scno_in_range(tcp->scno))
  94. return;
  95. if (!counts) {
  96. counts = xcalloc(nsyscalls, sizeof(*counts));
  97. for (size_t i = 0; i < nsyscalls; i++)
  98. counts[i].time_min = max_ts;
  99. }
  100. struct call_counts *cc = &counts[tcp->scno];
  101. cc->calls++;
  102. if (syserror(tcp))
  103. cc->errors++;
  104. struct timespec wts;
  105. if (count_wallclock) {
  106. /* wall clock time spent while in syscall */
  107. ts_sub(&wts, syscall_exiting_ts, &tcp->etime);
  108. } else {
  109. /* system CPU time spent while in syscall */
  110. ts_sub(&wts, &tcp->stime, &tcp->ltime);
  111. }
  112. ts_sub(&wts, &wts, &overhead);
  113. const struct timespec *wts_nonneg = ts_max(&wts, &zero_ts);
  114. ts_add(&cc->time, &cc->time, wts_nonneg);
  115. cc->time_min = *ts_min(&cc->time_min, wts_nonneg);
  116. cc->time_max = *ts_max(&cc->time_max, wts_nonneg);
  117. }
  118. static int
  119. time_cmp(const void *a, const void *b)
  120. {
  121. const unsigned int *a_int = a;
  122. const unsigned int *b_int = b;
  123. return -ts_cmp(&counts[*a_int].time, &counts[*b_int].time);
  124. }
  125. static int
  126. min_time_cmp(const void *a, const void *b)
  127. {
  128. return -ts_cmp(&counts[*((unsigned int *) a)].time_min,
  129. &counts[*((unsigned int *) b)].time_min);
  130. }
  131. static int
  132. max_time_cmp(const void *a, const void *b)
  133. {
  134. return -ts_cmp(&counts[*((unsigned int *) a)].time_max,
  135. &counts[*((unsigned int *) b)].time_max);
  136. }
  137. static int
  138. avg_time_cmp(const void *a, const void *b)
  139. {
  140. return -ts_cmp(&counts[*((unsigned int *) a)].time_avg,
  141. &counts[*((unsigned int *) b)].time_avg);
  142. }
  143. static int
  144. syscall_cmp(const void *a, const void *b)
  145. {
  146. const unsigned int *a_int = a;
  147. const unsigned int *b_int = b;
  148. const char *a_name = sysent[*a_int].sys_name;
  149. const char *b_name = sysent[*b_int].sys_name;
  150. return strcmp(a_name ? a_name : "", b_name ? b_name : "");
  151. }
  152. static int
  153. count_cmp(const void *a, const void *b)
  154. {
  155. const unsigned int *a_int = a;
  156. const unsigned int *b_int = b;
  157. unsigned int m = counts[*a_int].calls;
  158. unsigned int n = counts[*b_int].calls;
  159. return (m < n) ? 1 : (m > n) ? -1 : 0;
  160. }
  161. static int
  162. error_cmp(const void *a, const void *b)
  163. {
  164. const unsigned int *a_int = a;
  165. const unsigned int *b_int = b;
  166. unsigned int m = counts[*a_int].errors;
  167. unsigned int n = counts[*b_int].errors;
  168. return (m < n) ? 1 : (m > n) ? -1 : 0;
  169. }
  170. typedef int (*sort_func)(const void *, const void *);
  171. static sort_func sortfun;
  172. void
  173. set_sortby(const char *sortby)
  174. {
  175. static const sort_func sort_fns[CSC_MAX] = {
  176. [CSC_TIME_100S] = time_cmp,
  177. [CSC_TIME_TOTAL] = time_cmp,
  178. [CSC_TIME_MIN] = min_time_cmp,
  179. [CSC_TIME_MAX] = max_time_cmp,
  180. [CSC_TIME_AVG] = avg_time_cmp,
  181. [CSC_CALLS] = count_cmp,
  182. [CSC_ERRORS] = error_cmp,
  183. [CSC_SC_NAME] = syscall_cmp,
  184. };
  185. for (size_t i = 0; i < ARRAY_SIZE(column_aliases); ++i) {
  186. if (!strcmp(column_aliases[i].name, sortby)) {
  187. sortfun = sort_fns[column_aliases[i].column];
  188. return;
  189. }
  190. }
  191. error_msg_and_help("invalid sortby: '%s'", sortby);
  192. }
  193. void
  194. set_count_summary_columns(const char *s)
  195. {
  196. uint8_t visible[CSC_MAX] = { 0 };
  197. const char *prev = s;
  198. size_t cur = 0;
  199. memset(columns, 0, sizeof(columns));
  200. for (;;) {
  201. bool found = false;
  202. const char *pos = strchr(prev, ',');
  203. size_t len = pos ? (size_t) (pos - prev) : strlen(prev);
  204. for (size_t i = 0; i < ARRAY_SIZE(column_aliases); i++) {
  205. if (strncmp(column_aliases[i].name, prev, len) ||
  206. column_aliases[i].name[len])
  207. continue;
  208. if (column_aliases[i].column == CSC_NONE ||
  209. column_aliases[i].column >= CSC_MAX)
  210. continue;
  211. if (visible[column_aliases[i].column])
  212. error_msg_and_help("call summary column "
  213. "has been provided more "
  214. "than once: '%s' (-U option "
  215. "residual: '%s')",
  216. column_aliases[i].name,
  217. prev);
  218. columns[cur++] = column_aliases[i].column;
  219. visible[column_aliases[i].column] = 1;
  220. found = true;
  221. break;
  222. }
  223. if (!found)
  224. error_msg_and_help("unknown column name: '%.*s'",
  225. (int) MIN(len, INT_MAX), prev);
  226. if (!pos)
  227. break;
  228. prev = pos + 1;
  229. }
  230. /*
  231. * Always enable syscall name column, as without it table is meaningless
  232. */
  233. if (!visible[CSC_SC_NAME])
  234. columns[cur++] = CSC_SC_NAME;
  235. }
  236. int
  237. set_overhead(const char *str)
  238. {
  239. return parse_ts(str, &overhead);
  240. }
  241. static size_t ATTRIBUTE_FORMAT((printf, 1, 2))
  242. num_chars(const char *fmt, ...)
  243. {
  244. va_list ap;
  245. va_start(ap, fmt);
  246. int ret = vsnprintf(NULL, 0, fmt, ap);
  247. va_end(ap);
  248. return (unsigned int) MAX(ret, 0);
  249. }
  250. static void
  251. call_summary_pers(FILE *outf)
  252. {
  253. unsigned int *indices;
  254. size_t last_column = 0;
  255. struct timespec tv_cum = zero_ts;
  256. const struct timespec *tv_min = &max_ts;
  257. const struct timespec *tv_min_max = &zero_ts;
  258. const struct timespec *tv_max = &zero_ts;
  259. const struct timespec *tv_avg_max = &zero_ts;
  260. uint64_t call_cum = 0;
  261. uint64_t error_cum = 0;
  262. double float_tv_cum;
  263. double percent;
  264. size_t sc_name_max = 0;
  265. /* sort, calculate statistics */
  266. indices = xcalloc(sizeof(indices[0]), nsyscalls);
  267. for (size_t i = 0; i < nsyscalls; ++i) {
  268. indices[i] = i;
  269. if (counts[i].calls == 0)
  270. continue;
  271. ts_add(&tv_cum, &tv_cum, &counts[i].time);
  272. tv_min = ts_min(tv_min, &counts[i].time_min);
  273. tv_min_max = ts_max(tv_min_max, &counts[i].time_min);
  274. tv_max = ts_max(tv_max, &counts[i].time_max);
  275. call_cum += counts[i].calls;
  276. error_cum += counts[i].errors;
  277. ts_div(&counts[i].time_avg, &counts[i].time, counts[i].calls);
  278. tv_avg_max = ts_max(tv_avg_max, &counts[i].time_avg);
  279. sc_name_max = MAX(sc_name_max, strlen(sysent[i].sys_name));
  280. }
  281. float_tv_cum = ts_float(&tv_cum);
  282. if (sortfun)
  283. qsort((void *) indices, nsyscalls, sizeof(indices[0]), sortfun);
  284. enum column_flags {
  285. CF_L = 1 << 0, /* Left-aligned column */
  286. };
  287. static const struct {
  288. const char *s;
  289. size_t sz;
  290. const char *fmt;
  291. const char *last_fmt;
  292. uint32_t flags;
  293. } cdesc[] = {
  294. [CSC_TIME_100S] = { ARRSZ_PAIR("% time") - 1, "%1$*2$.2f" },
  295. [CSC_TIME_MIN] = { ARRSZ_PAIR("shortest") - 1, "%1$*2$.6f" },
  296. [CSC_TIME_MAX] = { ARRSZ_PAIR("longest") - 1, "%1$*2$.6f" },
  297. /* Historical field sizes are preserved */
  298. [CSC_TIME_TOTAL] = { "seconds", 11, "%1$*2$.6f" },
  299. [CSC_TIME_AVG] = { "usecs/call", 11, "%1$*2$" PRIu64 },
  300. [CSC_CALLS] = { "calls", 9, "%1$*2$" PRIu64 },
  301. [CSC_ERRORS] = { "errors", 9, "%1$*2$.0" PRIu64 },
  302. [CSC_SC_NAME] = { "syscall", 16, "%1$-*2$s", "%1$s", CF_L },
  303. };
  304. /* calculate column widths */
  305. #define W_(c_, v_) [c_] = MAX(cdesc[c_].sz, (v_))
  306. unsigned int cwidths[CSC_MAX] = {
  307. W_(CSC_TIME_100S, sizeof("100.00") - 1),
  308. W_(CSC_TIME_TOTAL, num_chars("%.6f", float_tv_cum)),
  309. W_(CSC_TIME_MIN, num_chars("%" PRId64 ".000000",
  310. (int64_t) tv_min_max->tv_sec)),
  311. W_(CSC_TIME_MAX, num_chars("%" PRId64 ".000000",
  312. (int64_t) tv_max->tv_sec)),
  313. W_(CSC_TIME_AVG, num_chars("%" PRId64 ,
  314. (uint64_t) (ts_float(tv_avg_max)
  315. * 1e6))),
  316. W_(CSC_CALLS, num_chars("%" PRIu64, call_cum)),
  317. W_(CSC_ERRORS, num_chars("%" PRIu64, error_cum)),
  318. W_(CSC_SC_NAME, sc_name_max + 1),
  319. };
  320. #undef W_
  321. /* find the last column */
  322. for (size_t i = 0; i < ARRAY_SIZE(columns) && columns[i]; ++i)
  323. last_column = i;
  324. /* header */
  325. for (size_t i = 0; i <= last_column; ++i) {
  326. const char *fmt = cdesc[columns[i]].flags & CF_L
  327. ? (i == last_column ? "%1$s" : "%1$-*2$s")
  328. : "%1$*2$s";
  329. if (i)
  330. fputc(' ', outf);
  331. fprintf(outf, fmt, cdesc[columns[i]].s, cwidths[columns[i]]);
  332. }
  333. fputc('\n', outf);
  334. /* divider */
  335. for (size_t i = 0; i <= last_column; ++i) {
  336. if (i)
  337. fputc(' ', outf);
  338. for (size_t j = 0; j < cwidths[columns[i]]; ++j)
  339. fputc('-', outf);
  340. }
  341. fputc('\n', outf);
  342. /* cache column formats */
  343. #define FC_(c_) \
  344. case (c_): \
  345. column_fmts[i] = (i == last_column) && cdesc[c].last_fmt \
  346. ? cdesc[c].last_fmt : cdesc[c].fmt; \
  347. break
  348. #define PC_(c_, val_) \
  349. case (c_): \
  350. fprintf(outf, column_fmts[i], (val_), cwidths[c]); \
  351. break
  352. const char *column_fmts[last_column + 1];
  353. for (size_t i = 0; i <= last_column; ++i) {
  354. const size_t c = columns[i];
  355. switch (c) {
  356. FC_(CSC_TIME_100S);
  357. FC_(CSC_TIME_TOTAL);
  358. FC_(CSC_TIME_MIN);
  359. FC_(CSC_TIME_MAX);
  360. FC_(CSC_TIME_AVG);
  361. FC_(CSC_CALLS);
  362. FC_(CSC_ERRORS);
  363. FC_(CSC_SC_NAME);
  364. }
  365. }
  366. /* data output */
  367. for (size_t j = 0; j < nsyscalls; ++j) {
  368. unsigned int idx = indices[j];
  369. struct call_counts *cc = &counts[idx];
  370. double float_syscall_time;
  371. if (cc->calls == 0)
  372. continue;
  373. float_syscall_time = ts_float(&cc->time);
  374. percent = (100.0 * float_syscall_time);
  375. /* else: float_tv_cum can be 0.0 too and we get 0/0 = NAN */
  376. if (percent != 0.0)
  377. percent /= float_tv_cum;
  378. for (size_t i = 0; i <= last_column; ++i) {
  379. const size_t c = columns[i];
  380. if (i)
  381. fputc(' ', outf);
  382. switch (c) {
  383. PC_(CSC_TIME_100S, percent);
  384. PC_(CSC_TIME_TOTAL, float_syscall_time);
  385. PC_(CSC_TIME_MIN, ts_float(&cc->time_min));
  386. PC_(CSC_TIME_MAX, ts_float(&cc->time_max));
  387. PC_(CSC_TIME_AVG,
  388. (uint64_t) (ts_float(&cc->time_avg) * 1e6));
  389. PC_(CSC_CALLS, cc->calls);
  390. PC_(CSC_ERRORS, cc->errors);
  391. PC_(CSC_SC_NAME, sysent[idx].sys_name);
  392. }
  393. }
  394. fputc('\n', outf);
  395. }
  396. free(indices);
  397. /* footer */
  398. for (size_t i = 0; i <= last_column; ++i) {
  399. if (i)
  400. fputc(' ', outf);
  401. for (size_t j = 0; j < cwidths[columns[i]]; ++j)
  402. fputc('-', outf);
  403. }
  404. fputc('\n', outf);
  405. /* totals */
  406. for (size_t i = 0; i <= last_column; ++i) {
  407. const size_t c = columns[i];
  408. if (i)
  409. fputc(' ', outf);
  410. switch (c) {
  411. PC_(CSC_TIME_100S, 100.0);
  412. PC_(CSC_TIME_TOTAL, float_tv_cum);
  413. PC_(CSC_TIME_MIN, ts_float(tv_min));
  414. PC_(CSC_TIME_MAX, ts_float(tv_max));
  415. PC_(CSC_TIME_AVG, (uint64_t) (float_tv_cum / call_cum * 1e6));
  416. PC_(CSC_CALLS, call_cum);
  417. PC_(CSC_ERRORS, error_cum);
  418. PC_(CSC_SC_NAME, "total");
  419. }
  420. }
  421. fputc('\n', outf);
  422. #undef PC_
  423. #undef FC_
  424. }
  425. void
  426. call_summary(FILE *outf)
  427. {
  428. unsigned int i, old_pers = current_personality;
  429. for (i = 0; i < SUPPORTED_PERSONALITIES; ++i) {
  430. if (!countv[i])
  431. continue;
  432. if (current_personality != i)
  433. set_personality(i);
  434. if (i)
  435. fprintf(outf,
  436. "System call usage summary for %s mode:\n",
  437. personality_names[i]);
  438. call_summary_pers(outf);
  439. }
  440. if (old_pers != current_personality)
  441. set_personality(old_pers);
  442. }