File bpf_trace_sys_time.py of Package mmdebug-tools

#!/usr/bin/python3

# Script to gather time spent in syscalls via BPF. The script reports for each
# process syscalls it did, total time (in ns) spent in each syscall type and
# number of syscalls of each type. Output looks like:
#
#  PID COMM               SCN   CNT          SUM
# 6681 sshd                16     1         3510
# 6681 sshd                 0     5        20433
# 6681 sshd                 1     5        97640
# 6681 sshd                14    18        10396
# 1908 irqbalance         257    31       169720
# 6760 bpf_trace_sys_t     15     1         2077
# 1908 irqbalance           3    22         9623
# 6681 sshd                23     8   4750585528
#
# Syscall numbers can be decoded to symbolic names e.g. using
# /usr/include/asm/unistd_64.h or corresponding architecture syscall table.
#
# Note that the tool needs python3-bcc package installed.

from __future__ import print_function
from bcc import BPF
from time import sleep
import signal
import ctypes
import sys

# define BPF program
bpf_text = """

/* Hack for LLVM and 5.x kernels */
#undef asm_volatile_goto
#define asm_volatile_goto(x...)

#include <uapi/linux/ptrace.h>
#include <linux/sched.h>
#include <uapi/asm/unistd.h>
#include <linux/mm.h>

struct tracked_task {
    u64 start;
    char comm[TASK_COMM_LEN];
    int scn;
};

BPF_HASH(tasks, pid_t, struct tracked_task);

#define PID_SHIFT 12
#define PID_SCN_TO_KEY(pid, scn) (((pid) << PID_SHIFT) | (scn))

struct sc_stat {
    u64 sum;
    int count;
};

BPF_HASH(duration, unsigned int, struct sc_stat);

static void track_current_task(int scn)
{
    pid_t pid = (u32)bpf_get_current_pid_tgid();
    struct tracked_task *tt;
    struct tracked_task init = {};

    tt = tasks.lookup(&pid);
    if (tt == NULL) {
        init.start = bpf_ktime_get_ns();
        bpf_get_current_comm(init.comm, TASK_COMM_LEN);
        init.scn = scn;
        tasks.insert(&pid, &init);
    } else {
        tt->start = bpf_ktime_get_ns();
        tt->scn = scn;
    }
}

static void add_sys_time(pid_t pid, int scn, u64 len)
{
    unsigned int key = PID_SCN_TO_KEY(pid, scn);
    struct sc_stat *stat;
    struct sc_stat init = { };

    stat = duration.lookup(&key);
    if (!stat) {
        init.sum = len;
        init.count = 1;
        duration.insert(&key, &init);
    } else {
        stat->sum += len;
        stat->count++;
    }
}

static void untrack_current_task(void)
{
    pid_t pid = (u32)bpf_get_current_pid_tgid();
    struct tracked_task *tt;
    u64 end = bpf_ktime_get_ns();

    tt = tasks.lookup(&pid);
    if (tt == NULL)
        return;
    add_sys_time(pid, tt->scn, end - tt->start);
}

TRACEPOINT_PROBE(raw_syscalls, sys_enter)
{
    track_current_task(args->id);
    return 0;
}

TRACEPOINT_PROBE(raw_syscalls, sys_exit)
{
    untrack_current_task();
    return 0;
}
"""

# load BPF program
b = BPF(text=bpf_text)

print("Tracing tasks. Press Ctrl-C to end.", file=sys.stderr);

try:
    sleep(99999)
except KeyboardInterrupt:
    print(file=sys.stderr)

print("%5s %-16s %5s %5s %12s" % ("PID", "COMM", "SCN", "CNT", "SUM"))
tasks = b["tasks"]
calls = b["duration"]
for pidscn, dur in calls.items():
    pid = pidscn.value >> 12
    print("%5d %-16s %5d %5d %12d" % (pid,
            tasks[ctypes.c_int(pid)].comm.decode("utf-8"),
            (pidscn.value & ((1<<12) - 1)), dur.count, dur.sum))