diff --git a/TOOLS.md b/TOOLS.md index d026189..76c481e 100644 --- a/TOOLS.md +++ b/TOOLS.md @@ -15,3 +15,4 @@ Show entries about TCP&UDP in nf_conntrack. Trace scheduling of system processes between NUMA nodes. - [sigsnoop](https://github.com/bpftrace/user-tools/tree/master/sigsnoop): Trace standard and real-time signals. +- [wakesnoop](wakesnoop): Task wakeup latency tracing. diff --git a/wakesnoop/README.md b/wakesnoop/README.md new file mode 100644 index 0000000..ea66ccf --- /dev/null +++ b/wakesnoop/README.md @@ -0,0 +1,23 @@ +# wakesnoop + +`wakesnoop` attaches to scheduler tracepoints `sched_waking` and `sched_wakeup`, and +measures delay of wakeup. Measurements exceeding threshold, matching cpu mask +and pid are printed. If no optional arguments are provided, the tool prints all +measurements. + +USAGE: wakesnoop.bt \[wakeup delay threshold, us\] \[cpu mask\] \[pid\] + +## Output + +``` +# ./sched/wakesnoop.bt 100 +Attaching 4 probes... +Tracing scheduler delay and in microseconds. Ctrl-C to end. +TIME DELAY(us) CPU PID COMM +21:49:23.425949 123 7 6124 pulseaudio +21:49:23.534792 116 8 32155 VizCompositorTh +21:49:24.213697 145 5 6124 pulseaudio +21:49:24.315695 113 5 6124 pulseaudio +21:49:24.603702 107 5 6124 pulseaudio +21:49:24.652704 107 5 444683 kworker/u25:3 +``` diff --git a/wakesnoop/wakesnoop.bt b/wakesnoop/wakesnoop.bt new file mode 100755 index 0000000..9d626bb --- /dev/null +++ b/wakesnoop/wakesnoop.bt @@ -0,0 +1,44 @@ +#!/usr/bin/env bpftrace + +// SPDX-License-Identifier: GPL-2.0-or-later + +/* + * wakesnoop.bt Scheduler latency tracing tool. + * + * USAGE: + * ./wakesnoop.bt [wakeup delay threshold, us] [cpu mask] [pid] + * + * Copyright 2024 Red Hat, Inc., Costa Shulyupin + * + */ + +BEGIN +{ + printf("Tracing scheduler delay and in microseconds. Ctrl-C to end.\n"); + printf("%-15s %9s %3s %7s %s\n", "TIME", "DELAY(us)", "CPU", "PID", "COMM"); +} + + +tracepoint:sched:sched_waking, +/!$3 || args.pid == $3/ +{ + @waking[args.pid] = nsecs; +} + +tracepoint:sched:sched_wakeup +/(!$3 || args.pid == $3) && @waking[args.pid] / +{ + $delay = (nsecs - @waking[args.pid]) / 1000; + @sched_wakeup_delay_max = max($delay); + if ($delay > $1 && (!$2 || 1 << args.target_cpu & $2)) { + printf("%s %9u %3u %7d %s\n", + strftime("%H:%M:%S.%f", @waking[args.pid]), $delay, args.target_cpu, + args.pid, args.comm); + } + delete(@waking[args.pid]); +} + +END +{ + clear(@waking); +}