#!/usr/bin/env python # # syscount Summarize syscall counts and latencies. # # USAGE: syscount [-p PID] [-i INTERVAL] [-T TOP] [-x] [-L] [-m] [-P] [-l] # # Copyright 2017, Sasha Goldshtein. # Licensed under the Apache License, Version 2.0 (the "License") # # 15-Feb-2017 Sasha Goldshtein Created this. from bcc import BPF from time import sleep, strftime import argparse import itertools import subprocess import sys import platform if sys.version_info.major < 3: izip_longest = itertools.izip_longest else: izip_longest = itertools.zip_longest # # Syscall table for Linux x86_64, not very recent. # Automatically generated from strace/linux/x86_64/syscallent.h using the # following command: # # cat syscallent.h | awk -F, '{ gsub(/[ \t"}]/, "", $4); # gsub(/[ \t/*]/, "", $5); # print " "$5": \""$4"\","; } # BEGIN { print "syscalls = {" } # END { print "}" }' # syscalls = { 0: "read", 1: "write", 2: "open", 3: "close", 4: "stat", 5: "fstat", 6: "lstat", 7: "poll", 8: "lseek", 9: "mmap", 10: "mprotect", 11: "munmap", 12: "brk", 13: "rt_sigaction", 14: "rt_sigprocmask", 15: "rt_sigreturn", 16: "ioctl", 17: "pread", 18: "pwrite", 19: "readv", 20: "writev", 21: "access", 22: "pipe", 23: "select", 24: "sched_yield", 25: "mremap", 26: "msync", 27: "mincore", 28: "madvise", 29: "shmget", 30: "shmat", 31: "shmctl", 32: "dup", 33: "dup2", 34: "pause", 35: "nanosleep", 36: "getitimer", 37: "alarm", 38: "setitimer", 39: "getpid", 40: "sendfile", 41: "socket", 42: "connect", 43: "accept", 44: "sendto", 45: "recvfrom", 46: "sendmsg", 47: "recvmsg", 48: "shutdown", 49: "bind", 50: "listen", 51: "getsockname", 52: "getpeername", 53: "socketpair", 54: "setsockopt", 55: "getsockopt", 56: "clone", 57: "fork", 58: "vfork", 59: "execve", 60: "_exit", 61: "wait4", 62: "kill", 63: "uname", 64: "semget", 65: "semop", 66: "semctl", 67: "shmdt", 68: "msgget", 69: "msgsnd", 70: "msgrcv", 71: "msgctl", 72: "fcntl", 73: "flock", 74: "fsync", 75: "fdatasync", 76: "truncate", 77: "ftruncate", 78: "getdents", 79: "getcwd", 80: "chdir", 81: "fchdir", 82: "rename", 83: "mkdir", 84: "rmdir", 85: "creat", 86: "link", 87: "unlink", 88: "symlink", 89: "readlink", 90: "chmod", 91: "fchmod", 92: "chown", 93: "fchown", 94: "lchown", 95: "umask", 96: "gettimeofday", 97: "getrlimit", 98: "getrusage", 99: "sysinfo", 100: "times", 101: "ptrace", 102: "getuid", 103: "syslog", 104: "getgid", 105: "setuid", 106: "setgid", 107: "geteuid", 108: "getegid", 109: "setpgid", 110: "getppid", 111: "getpgrp", 112: "setsid", 113: "setreuid", 114: "setregid", 115: "getgroups", 116: "setgroups", 117: "setresuid", 118: "getresuid", 119: "setresgid", 120: "getresgid", 121: "getpgid", 122: "setfsuid", 123: "setfsgid", 124: "getsid", 125: "capget", 126: "capset", 127: "rt_sigpending", 128: "rt_sigtimedwait", 129: "rt_sigqueueinfo", 130: "rt_sigsuspend", 131: "sigaltstack", 132: "utime", 133: "mknod", 134: "uselib", 135: "personality", 136: "ustat", 137: "statfs", 138: "fstatfs", 139: "sysfs", 140: "getpriority", 141: "setpriority", 142: "sched_setparam", 143: "sched_getparam", 144: "sched_setscheduler", 145: "sched_getscheduler", 146: "sched_get_priority_max", 147: "sched_get_priority_min", 148: "sched_rr_get_interval", 149: "mlock", 150: "munlock", 151: "mlockall", 152: "munlockall", 153: "vhangup", 154: "modify_ldt", 155: "pivot_root", 156: "_sysctl", 157: "prctl", 158: "arch_prctl", 159: "adjtimex", 160: "setrlimit", 161: "chroot", 162: "sync", 163: "acct", 164: "settimeofday", 165: "mount", 166: "umount", 167: "swapon", 168: "swapoff", 169: "reboot", 170: "sethostname", 171: "setdomainname", 172: "iopl", 173: "ioperm", 174: "create_module", 175: "init_module", 176: "delete_module", 177: "get_kernel_syms", 178: "query_module", 179: "quotactl", 180: "nfsservctl", 181: "getpmsg", 182: "putpmsg", 183: "afs_syscall", 184: "tuxcall", 185: "security", 186: "gettid", 187: "readahead", 188: "setxattr", 189: "lsetxattr", 190: "fsetxattr", 191: "getxattr", 192: "lgetxattr", 193: "fgetxattr", 194: "listxattr", 195: "llistxattr", 196: "flistxattr", 197: "removexattr", 198: "lremovexattr", 199: "fremovexattr", 200: "tkill", 201: "time", 202: "futex", 203: "sched_setaffinity", 204: "sched_getaffinity", 205: "set_thread_area", 206: "io_setup", 207: "io_destroy", 208: "io_getevents", 209: "io_submit", 210: "io_cancel", 211: "get_thread_area", 212: "lookup_dcookie", 213: "epoll_create", 214: "epoll_ctl_old", 215: "epoll_wait_old", 216: "remap_file_pages", 217: "getdents64", 218: "set_tid_address", 219: "restart_syscall", 220: "semtimedop", 221: "fadvise64", 222: "timer_create", 223: "timer_settime", 224: "timer_gettime", 225: "timer_getoverrun", 226: "timer_delete", 227: "clock_settime", 228: "clock_gettime", 229: "clock_getres", 230: "clock_nanosleep", 231: "exit_group", 232: "epoll_wait", 233: "epoll_ctl", 234: "tgkill", 235: "utimes", 236: "vserver", 237: "mbind", 238: "set_mempolicy", 239: "get_mempolicy", 240: "mq_open", 241: "mq_unlink", 242: "mq_timedsend", 243: "mq_timedreceive", 244: "mq_notify", 245: "mq_getsetattr", 246: "kexec_load", 247: "waitid", 248: "add_key", 249: "request_key", 250: "keyctl", 251: "ioprio_set", 252: "ioprio_get", 253: "inotify_init", 254: "inotify_add_watch", 255: "inotify_rm_watch", 256: "migrate_pages", 257: "openat", 258: "mkdirat", 259: "mknodat", 260: "fchownat", 261: "futimesat", 262: "newfstatat", 263: "unlinkat", 264: "renameat", 265: "linkat", 266: "symlinkat", 267: "readlinkat", 268: "fchmodat", 269: "faccessat", 270: "pselect6", 271: "ppoll", 272: "unshare", 273: "set_robust_list", 274: "get_robust_list", 275: "splice", 276: "tee", 277: "sync_file_range", 278: "vmsplice", 279: "move_pages", 280: "utimensat", 281: "epoll_pwait", 282: "signalfd", 283: "timerfd_create", 284: "eventfd", 285: "fallocate", 286: "timerfd_settime", 287: "timerfd_gettime", 288: "accept4", 289: "signalfd4", 290: "eventfd2", 291: "epoll_create1", 292: "dup3", 293: "pipe2", 294: "inotify_init1", 295: "preadv", 296: "pwritev", 297: "rt_tgsigqueueinfo", 298: "perf_event_open", 299: "recvmmsg", 300: "fanotify_init", 301: "fanotify_mark", 302: "prlimit64", 303: "name_to_handle_at", 304: "open_by_handle_at", 305: "clock_adjtime", 306: "syncfs", 307: "sendmmsg", 308: "setns", 309: "getcpu", 310: "process_vm_readv", 311: "process_vm_writev", 312: "kcmp", 313: "finit_module", } # Try to use ausyscall if it is available, because it can give us an up-to-date # list of syscalls for various architectures, rather than the x86-64 hardcoded # list above. def parse_syscall(line): parts = line.split() return (int(parts[0]), parts[1].strip()) try: # Skip the first line, which is a header. The rest of the lines are simply # SYSCALL_NUM\tSYSCALL_NAME pairs. out = subprocess.check_output('ausyscall --dump | tail -n +2', shell=True) syscalls = dict(map(parse_syscall, out.strip().split('\n'))) except Exception as e: if platform.machine() == "x86_64": pass else: raise Exception("ausyscall: command not found") parser = argparse.ArgumentParser( description="Summarize syscall counts and latencies.") parser.add_argument("-p", "--pid", type=int, help="trace only this pid") parser.add_argument("-i", "--interval", type=int, help="print summary at this interval (seconds)") parser.add_argument("-T", "--top", type=int, default=10, help="print only the top syscalls by count or latency") parser.add_argument("-x", "--failures", action="store_true", help="trace only failed syscalls (return < 0)") parser.add_argument("-L", "--latency", action="store_true", help="collect syscall latency") parser.add_argument("-m", "--milliseconds", action="store_true", help="display latency in milliseconds (default: microseconds)") parser.add_argument("-P", "--process", action="store_true", help="count by process and not by syscall") parser.add_argument("-l", "--list", action="store_true", help="print list of recognized syscalls and exit") args = parser.parse_args() if args.list: for grp in izip_longest(*(iter(sorted(syscalls.values())),) * 4): print(" ".join(["%-20s" % s for s in grp if s is not None])) sys.exit(0) text = """ #ifdef LATENCY struct data_t { u64 count; u64 total_ns; }; BPF_HASH(start, u64, u64); BPF_HASH(data, u32, struct data_t); #else BPF_HASH(data, u32, u64); #endif #ifdef LATENCY TRACEPOINT_PROBE(raw_syscalls, sys_enter) { u64 pid_tgid = bpf_get_current_pid_tgid(); #ifdef FILTER_PID if (pid_tgid >> 32 != FILTER_PID) return 0; #endif u64 t = bpf_ktime_get_ns(); start.update(&pid_tgid, &t); return 0; } #endif TRACEPOINT_PROBE(raw_syscalls, sys_exit) { u64 pid_tgid = bpf_get_current_pid_tgid(); #ifdef FILTER_PID if (pid_tgid >> 32 != FILTER_PID) return 0; #endif #ifdef FILTER_FAILED if (args->ret >= 0) return 0; #endif #ifdef BY_PROCESS u32 key = pid_tgid >> 32; #else u32 key = args->id; #endif #ifdef LATENCY struct data_t *val, zero = {}; u64 *start_ns = start.lookup(&pid_tgid); if (!start_ns) return 0; val = data.lookup_or_init(&key, &zero); val->count++; val->total_ns = bpf_ktime_get_ns() - *start_ns; #else u64 *val, zero = 0; val = data.lookup_or_init(&key, &zero); ++(*val); #endif return 0; } """ if args.pid: text = ("#define FILTER_PID %d\n" % args.pid) + text if args.failures: text = "#define FILTER_FAILED\n" + text if args.latency: text = "#define LATENCY\n" + text if args.process: text = "#define BY_PROCESS\n" + text bpf = BPF(text=text) def print_stats(): if args.latency: print_latency_stats() else: print_count_stats() agg_colname = "PID COMM" if args.process else "SYSCALL" time_colname = "TIME (ms)" if args.milliseconds else "TIME (us)" def comm_for_pid(pid): try: return open("/proc/%d/comm" % pid).read().strip() except Exception: return "[unknown]" def agg_colval(key): if args.process: return "%-6d %-15s" % (key.value, comm_for_pid(key.value)) else: return syscalls.get(key.value, "[unknown: %d]" % key.value) def print_count_stats(): data = bpf["data"] print("[%s]" % strftime("%H:%M:%S")) print("%-22s %8s" % (agg_colname, "COUNT")) for k, v in sorted(data.items(), key=lambda kv: -kv[1].value)[:args.top]: if k.value == 0xFFFFFFFF: continue # happens occasionally, we don't need it print("%-22s %8d" % (agg_colval(k), v.value)) print("") data.clear() def print_latency_stats(): data = bpf["data"] print("[%s]" % strftime("%H:%M:%S")) print("%-22s %8s %16s" % (agg_colname, "COUNT", time_colname)) for k, v in sorted(data.items(), key=lambda kv: -kv[1].total_ns)[:args.top]: if k.value == 0xFFFFFFFF: continue # happens occasionally, we don't need it print(("%-22s %8d " + ("%16.6f" if args.milliseconds else "%16.3f")) % (agg_colval(k), v.count, v.total_ns / (1e6 if args.milliseconds else 1e3))) print("") data.clear() print("Tracing %ssyscalls, printing top %d... Ctrl+C to quit." % ("failed " if args.failures else "", args.top)) while True: try: sleep(args.interval or 999999999) print_stats() except KeyboardInterrupt: if not args.interval: print_stats() break