^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 1) // SPDX-License-Identifier: (LGPL-2.1 OR BSD-2-Clause)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 2) // Copyright (c) 2019 Facebook
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 3) #include <argp.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 4) #include <stdio.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 5) #include <stdlib.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 6) #include <string.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 7) #include <sys/resource.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 8) #include <time.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 9) #include <bpf/libbpf.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 10) #include <bpf/bpf.h>
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 11) #include "runqslower.h"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 12) #include "runqslower.skel.h"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 13)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 14) struct env {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 15) pid_t pid;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 16) __u64 min_us;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 17) bool verbose;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 18) } env = {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 19) .min_us = 10000,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 20) };
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 21)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 22) const char *argp_program_version = "runqslower 0.1";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 23) const char *argp_program_bug_address = "<bpf@vger.kernel.org>";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 24) const char argp_program_doc[] =
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 25) "runqslower Trace long process scheduling delays.\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 26) " For Linux, uses eBPF, BPF CO-RE, libbpf, BTF.\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 27) "\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 28) "This script traces high scheduling delays between tasks being\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 29) "ready to run and them running on CPU after that.\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 30) "\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 31) "USAGE: runqslower [-p PID] [min_us]\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 32) "\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 33) "EXAMPLES:\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 34) " runqslower # trace run queue latency higher than 10000 us (default)\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 35) " runqslower 1000 # trace run queue latency higher than 1000 us\n"
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 36) " runqslower -p 123 # trace pid 123 only\n";
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 37)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 38) static const struct argp_option opts[] = {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 39) { "pid", 'p', "PID", 0, "Process PID to trace"},
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 40) { "verbose", 'v', NULL, 0, "Verbose debug output" },
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 41) {},
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 42) };
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 43)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 44) static error_t parse_arg(int key, char *arg, struct argp_state *state)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 45) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 46) static int pos_args;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 47) int pid;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 48) long long min_us;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 49)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 50) switch (key) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 51) case 'v':
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 52) env.verbose = true;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 53) break;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 54) case 'p':
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 55) errno = 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 56) pid = strtol(arg, NULL, 10);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 57) if (errno || pid <= 0) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 58) fprintf(stderr, "Invalid PID: %s\n", arg);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 59) argp_usage(state);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 60) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 61) env.pid = pid;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 62) break;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 63) case ARGP_KEY_ARG:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 64) if (pos_args++) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 65) fprintf(stderr,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 66) "Unrecognized positional argument: %s\n", arg);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 67) argp_usage(state);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 68) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 69) errno = 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 70) min_us = strtoll(arg, NULL, 10);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 71) if (errno || min_us <= 0) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 72) fprintf(stderr, "Invalid delay (in us): %s\n", arg);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 73) argp_usage(state);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 74) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 75) env.min_us = min_us;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 76) break;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 77) default:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 78) return ARGP_ERR_UNKNOWN;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 79) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 80) return 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 81) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 82)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 83) int libbpf_print_fn(enum libbpf_print_level level,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 84) const char *format, va_list args)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 85) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 86) if (level == LIBBPF_DEBUG && !env.verbose)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 87) return 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 88) return vfprintf(stderr, format, args);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 89) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 90)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 91) static int bump_memlock_rlimit(void)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 92) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 93) struct rlimit rlim_new = {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 94) .rlim_cur = RLIM_INFINITY,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 95) .rlim_max = RLIM_INFINITY,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 96) };
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 97)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 98) return setrlimit(RLIMIT_MEMLOCK, &rlim_new);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 99) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 100)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 101) void handle_event(void *ctx, int cpu, void *data, __u32 data_sz)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 102) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 103) const struct event *e = data;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 104) struct tm *tm;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 105) char ts[32];
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 106) time_t t;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 107)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 108) time(&t);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 109) tm = localtime(&t);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 110) strftime(ts, sizeof(ts), "%H:%M:%S", tm);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 111) printf("%-8s %-16s %-6d %14llu\n", ts, e->task, e->pid, e->delta_us);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 112) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 113)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 114) void handle_lost_events(void *ctx, int cpu, __u64 lost_cnt)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 115) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 116) printf("Lost %llu events on CPU #%d!\n", lost_cnt, cpu);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 117) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 118)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 119) int main(int argc, char **argv)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 120) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 121) static const struct argp argp = {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 122) .options = opts,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 123) .parser = parse_arg,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 124) .doc = argp_program_doc,
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 125) };
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 126) struct perf_buffer_opts pb_opts;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 127) struct perf_buffer *pb = NULL;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 128) struct runqslower_bpf *obj;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 129) int err;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 130)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 131) err = argp_parse(&argp, argc, argv, 0, NULL, NULL);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 132) if (err)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 133) return err;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 134)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 135) libbpf_set_print(libbpf_print_fn);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 136)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 137) err = bump_memlock_rlimit();
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 138) if (err) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 139) fprintf(stderr, "failed to increase rlimit: %d", err);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 140) return 1;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 141) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 142)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 143) obj = runqslower_bpf__open();
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 144) if (!obj) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 145) fprintf(stderr, "failed to open and/or load BPF object\n");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 146) return 1;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 147) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 148)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 149) /* initialize global data (filtering options) */
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 150) obj->rodata->targ_pid = env.pid;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 151) obj->rodata->min_us = env.min_us;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 152)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 153) err = runqslower_bpf__load(obj);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 154) if (err) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 155) fprintf(stderr, "failed to load BPF object: %d\n", err);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 156) goto cleanup;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 157) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 158)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 159) err = runqslower_bpf__attach(obj);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 160) if (err) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 161) fprintf(stderr, "failed to attach BPF programs\n");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 162) goto cleanup;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 163) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 164)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 165) printf("Tracing run queue latency higher than %llu us\n", env.min_us);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 166) printf("%-8s %-16s %-6s %14s\n", "TIME", "COMM", "PID", "LAT(us)");
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 167)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 168) pb_opts.sample_cb = handle_event;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 169) pb_opts.lost_cb = handle_lost_events;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 170) pb = perf_buffer__new(bpf_map__fd(obj->maps.events), 64, &pb_opts);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 171) err = libbpf_get_error(pb);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 172) if (err) {
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 173) pb = NULL;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 174) fprintf(stderr, "failed to open perf buffer: %d\n", err);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 175) goto cleanup;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 176) }
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 177)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 178) while ((err = perf_buffer__poll(pb, 100)) >= 0)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 179) ;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 180) printf("Error polling perf buffer: %d\n", err);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 181)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 182) cleanup:
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 183) perf_buffer__free(pb);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 184) runqslower_bpf__destroy(obj);
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 185)
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 186) return err != 0;
^8f3ce5b39 (kx 2023-10-28 12:00:06 +0300 187) }