From f07580adcad1fe0a19328c53721387b7f8f9d7cd Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Gerg=C5=91=20S=C3=A1lyi?= Date: Thu, 17 Oct 2024 02:31:48 +0200 Subject: [PATCH] Add bpftrace scripts tracing the our timings --- Cargo.toml | 2 +- scripts/ipc.bt | 99 +++++++++++++++++++++++++++++++++++++++++++++ scripts/ipc.out.txt | 15 +++++++ 3 files changed, 115 insertions(+), 1 deletion(-) create mode 100755 scripts/ipc.bt create mode 100644 scripts/ipc.out.txt diff --git a/Cargo.toml b/Cargo.toml index acf3c6b..44fd3ed 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -11,7 +11,7 @@ repository = "https://github.com/gergo-salyi/multibg-sway" license = "MIT OR Apache-2.0" keywords = ["wallpaper", "background", "desktop", "wayland", "sway"] categories = ["command-line-utilities", "multimedia::images"] -exclude = ["PKGBUILD"] +exclude = ["/PKGBUILD", "/scripts/"] [dependencies] clap = { version = "4.5.3", features = ["derive"] } diff --git a/scripts/ipc.bt b/scripts/ipc.bt new file mode 100755 index 0000000..b21c83a --- /dev/null +++ b/scripts/ipc.bt @@ -0,0 +1,99 @@ +#!/usr/bin/env bpftrace +/* + * Trace the timings of wayland and sway-ipc unix socket + * send and receive syscalls on multibg-sway + * + * On Linux with bpftrace installed one can run this script as root + * to get microsecond resolution timings printed to stdout + * when on our wayland and sway-ipc sockets + * - receive syscalls return + * - send and write syscalls enter + * + * Use the obtained timestamps + * to calculate our latency switching the wallpaper + */ + +tracepoint:syscalls:sys_enter_sendto +{ + if (comm != "multibg-sway") { + return; + } + + printf( + "%s sendto enter fd=%d\n", + strftime("%H:%M:%S.%f", nsecs), + args->fd + ); +} + +tracepoint:syscalls:sys_enter_sendmsg +{ + if (comm != "multibg-sway") { + return; + } + + printf( + "%s sendmsg enter fd=%d\n", + strftime("%H:%M:%S.%f", nsecs), + args->fd + ); +} + +tracepoint:syscalls:sys_enter_write +{ + if (comm != "multibg-sway") { + return; + } + + if (args->fd == 1 && args->fd == 2) { + return; + } + + printf( + "%s write enter fd=%d count=%d %r\n", + strftime("%H:%M:%S.%f", nsecs), + args->fd, + args->count, + buf(args->buf, args->count) + ); +} + +tracepoint:syscalls:sys_exit_recvfrom +{ + if (comm != "multibg-sway") { + return; + } + + printf( + "%s recvfrom exit\n", + strftime("%H:%M:%S.%f", nsecs) + ); +} + +tracepoint:syscalls:sys_exit_recvmsg +{ + if (comm != "multibg-sway") { + return; + } + + printf( + "%s recvmsg exit\n", + strftime("%H:%M:%S.%f", nsecs) + ); +} + +/* Option to trace other syscalls too */ +/* +tracepoint:raw_syscalls:sys_enter +{ + if (comm != "multibg-sway") { + return; + } + + printf( + "%s syscall %d enter\n", + strftime("%H:%M:%S.%f", nsecs), + args->id + ); +} +*/ diff --git a/scripts/ipc.out.txt b/scripts/ipc.out.txt new file mode 100644 index 0000000..26a758d --- /dev/null +++ b/scripts/ipc.out.txt @@ -0,0 +1,15 @@ +Attaching 4 probes... +00:52:29.501701 recvfrom exit +00:52:29.501723 recvfrom exit +00:52:29.501725 recvfrom exit +00:52:29.501740 recvfrom exit +00:52:29.501908 sendto enter fd=3 +00:52:29.512243 recvmsg exit +00:52:29.512257 recvmsg exit +00:52:37.534095 recvfrom exit +00:52:37.534127 recvfrom exit +00:52:37.534129 recvfrom exit +00:52:37.534140 recvfrom exit +00:52:37.534276 sendto enter fd=3 +00:52:37.546900 recvmsg exit +00:52:37.546913 recvmsg exit