Add bpftrace scripts tracing the our timings

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"] }

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
+    );
+}
+*/

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