examples/vsock-latency: reproducer for first-connection vsock delay

examples/vsock-latency/.gitignore

@@ -0,0 +1,2 @@
+host
+rootfs/

examples/vsock-latency/Makefile

@@ -0,0 +1,55 @@
+ARCH = $(shell uname -m)
+OS   = $(shell uname -s)
+
+LDFLAGS_x86_64_Linux  = -lkrun -lpthread
+LDFLAGS_aarch64_Linux = -lkrun -lpthread
+LDFLAGS_riscv64_Linux = -lkrun -lpthread
+
+CFLAGS_HOST  = -O2 -g -I../../include
+CFLAGS_GUEST = -O2 -static
+
+ROOTFS_DIR = rootfs
+
+.PHONY: all demo clean
+
+all: host $(ROOTFS_DIR)/guest
+
+host: host.c
+	gcc -o $@ $< $(CFLAGS_HOST) $(LDFLAGS_$(ARCH)_$(OS))
+
+# Minimal rootfs: just the statically linked guest binary. No userland
+# needed — the guest binary doesn't fork/exec or open anything outside
+# vsock, and libkrunfw's init doesn't require /proc, /sys, or /dev to
+# exist as mountpoints in the rootfs.
+$(ROOTFS_DIR)/guest: guest.c
+	mkdir -p $(ROOTFS_DIR)
+	gcc -o $@ $< $(CFLAGS_GUEST)
+
+# Run the host a few times at different per-probe timeouts and print
+# just the per-attempt / first-roundtrip lines from each run. Shows
+# the trade-off: shorter caller-side probe timeout → shorter observed
+# cold start, because attempt[1] never completes regardless.
+#
+# Each iteration is one cold VM boot — they can't share a VM, since
+# the whole point of the measurement is cold start. Override
+# DEMO_TIMEOUTS to add/remove cases, e.g. `make demo DEMO_TIMEOUTS="'' 2000"`
+# to see the 5 s reaper-TTL floor explicitly.
+DEMO_TIMEOUTS = '' 2000 100 10
+demo: host $(ROOTFS_DIR)/guest
+	@exec </dev/null && \
+	for t in $(DEMO_TIMEOUTS); do \
+	  rm -f /tmp/vsock-latency-*.sock; \
+	  label=$${t:-unset}; \
+	  printf '\n=== PROBE_TIMEOUT_MS=%s  (cold-boot, ~%s)... ===\n' \
+	    "$$label" \
+	    "$$( case $$t in ''|0) echo 5s ;; 2000) echo 2.5s ;; *) echo 0.5s ;; esac )"; \
+	  PROBE_TIMEOUT_MS=$$t timeout 25 ./host $(ROOTFS_DIR) >/dev/null 2>/tmp/vsock-demo.err; \
+	  grep -E 'attempt\[|first-roundtrip-ok' /tmp/vsock-demo.err \
+	    | grep -v 'deferring proxy'; \
+	done
+	@rm -f /tmp/vsock-demo.err
+	@printf '\n'
+
+clean:
+	rm -rf host $(ROOTFS_DIR)
+	rm -f /tmp/vsock-latency-*.sock

examples/vsock-latency/README.md

@@ -0,0 +1,146 @@
+# vsock-latency
+
+Minimal reproducer for a multi-second one-time delay on the **first
+host-to-guest vsock connection** through libkrun. After the first
+round trip, all subsequent connections on the same VM are sub-millisecond.
+
+## What it measures
+
+`host.c` configures a libkrun microVM whose PID 1 is a tiny static
+binary (`guest.c`). The guest binds an AF_VSOCK listener on port 1234
+and writes one ack byte to each accepted connection. The host maps
+that vsock port to a host UNIX socket via
+`krun_add_vsock_port2(..., listen=true)`, then a timing thread breaks
+startup into phases:
+
+1. **socket-created**: time from `krun_start_enter` until libkrun's
+   `UnixAcceptorProxy` binds the host-side UNIX socket.
+2. **first-roundtrip-ok**: time until the first host `connect()` plus
+   `read(1 byte)` completes end-to-end — i.e. the first byte actually
+   arrives through the kernel's virtio-vsock RX path.
+3. **warm-roundtrip[0..3]**: four more back-to-back round trips for
+   comparison.
+
+## Build
+
+Prereqs: libkrun installed (`pkg-config --modversion libkrun` works),
+`/dev/kvm` writable, gcc with `-static` support (`glibc-static` on
+Fedora, `musl-dev` on Alpine, etc.).
+
+```
+make
+```
+
+Produces `./host` and `./rootfs/guest`. The rootfs is just the
+single static guest binary — no userland, no `/proc` or `/dev`
+mountpoints, no container image needed.
+
+## Run
+
+```
+./host ./rootfs
+```
+
+The argument is the directory libkrun mounts as the VM's `/` (via
+virtio-fs). It must contain a top-level `guest` binary; `make`
+produces that at `./rootfs/guest`.
+
+## Expected output
+
+On an affected libkrunfw/kernel combination (e.g. libkrunfw 5.4.0 on
+host kernel 6.18, libkrunfw-bundled kernel 6.12.87):
+
+```
+vsock-latency: rootfs=./rootfs sock=/tmp/vsock-latency-12345.sock
+guest: listening on vsock:1234
+phase: socket-created     + 343.10 ms
+phase: first-roundtrip-ok +5365.22 ms  (delta-from-socket=5012.58 ms, attempts=2)
+guest: accept[0] ack
+warm-roundtrip[0]:           0.22 ms
+guest: accept[1] ack
+warm-roundtrip[1]:           0.28 ms
+guest: accept[2] ack
+warm-roundtrip[2]:           0.24 ms
+guest: accept[3] ack
+warm-roundtrip[3]:           0.22 ms
+```
+
+The diagnostic is **`delta-from-socket`**: the time between libkrun's
+unix socket being ready and the first successful end-to-end round
+trip. On this kernel it is ~5 seconds; warm round trips on the same
+VM are ~0.3 ms.
+
+With per-attempt timing enabled (uncomment the inner `fprintf` in
+`host.c`) the pattern is:
+
+```
+  attempt[1] +5000.83 ms  connect=ok read=EOF
+  attempt[2]   +0.39 ms   connect=ok read=ack
+```
+
+The first host `connect()` succeeds at the unix layer immediately, but
+the `read()` blocks for **exactly 5 seconds** before libkrun closes
+the unix socket with EOF. The second attempt — on a brand-new unix
+connection — succeeds in under a millisecond.
+
+The 5 s is hardcoded in libkrun: `src/devices/src/virtio/vsock/reaper.rs`
+sets `TIMEOUT = Duration::new(5, 0)` for the vsock reaper thread,
+which holds proxies in `released_map` for 5 s before actually
+removing them. The first vsock leg was refused (guest's AF_VSOCK
+accept() not yet ready when libkrun tried to forward), libkrun queued
+the proxy for `ProxyRemoval::Deferred`, and the unix socket FD stays
+associated with that not-yet-reaped proxy for the full 5 s.
+
+The corresponding `deferring proxy removal: <id>` WARN messages are
+visible at libkrun log level WARN or higher in the muxer thread
+(`muxer_thread.rs:100`).
+
+### Effect of a caller-side per-probe timeout
+
+A caller that probes for agent readiness typically wraps each attempt
+in some kind of deadline — for example `context.WithTimeout(ctx, X)`
+around each round trip in a polling loop. That deadline caps how
+long the caller waits for the doomed first attempt before retrying.
+
+Set `PROBE_TIMEOUT_MS` to apply `SO_RCVTIMEO` to each probe attempt
+(simulates a per-probe `WithTimeout(ctx, X)`). The reproducer prints
+per-attempt outcomes plus the total wall-clock to first success.
+
+| `PROBE_TIMEOUT_MS` | first-roundtrip-ok | attempts | attempt[1] outcome |
+| --- | --- | --- | --- |
+| unset (block to EOF) | ~5340 ms | 2 | EOF at 5007 ms |
+| `2000`               | ~2355 ms | 2 | timeout at 2022 ms |
+| `100`                |  ~425 ms | 2 | timeout at 101 ms |
+| `10`                 |  ~373 ms | 3 | timeout, timeout, ack |
+
+In every case attempt 1 never completes — it either EOFs at libkrun's
+5 s reaper TTL or hits the per-attempt timeout earlier. Attempt 2 is
+a fresh unix connection, fresh libkrun proxy, and succeeds in <1 ms.
+
+A caller polling with a 2 s deadline observes a ~2.4 s cold start
+that is entirely the duration of *its own* probe deadline — nothing
+in the libkrun + guest path benefits from waiting that long. The
+same caller switched to a 100 ms deadline observes ~400 ms total
+cold start (vsock), matching console cold-start.
+
+Run it yourself:
+
+```
+PROBE_TIMEOUT_MS=2000 ./host ./rootfs    # ~2.4s cold start
+PROBE_TIMEOUT_MS=100  ./host ./rootfs    # ~400ms cold start
+```
+
+Or run all four columns of the table in one shot:
+
+```
+make demo
+```
+
+## Cleanup
+
+```
+make clean
+```
+
+Removes `host`, the staged `rootfs/`, and any leftover
+`/tmp/vsock-latency-*.sock` from prior runs.

examples/vsock-latency/guest.c

@@ -0,0 +1,64 @@
+/*
+ * Guest side of the vsock first-connection latency reproducer.
+ *
+ * Runs as PID 1 inside a libkrun microVM. Binds AF_VSOCK on port 1234,
+ * accepts ITERATIONS connections, and exits — which makes libkrun shut
+ * the VM down.
+ *
+ * Each accepted connection gets exactly one ack byte. The host times
+ * connect() + read(1) to measure end-to-end vsock round-trip cost,
+ * since the host-side connect() returns as soon as libkrun's
+ * UnixAcceptorProxy accepts on the host — NOT when the guest accepts.
+ *
+ * Built static so it only depends on one file in the rootfs.
+ */
+
+#include <errno.h>
+#include <linux/vm_sockets.h>
+#include <stdio.h>
+#include <string.h>
+#include <sys/socket.h>
+#include <unistd.h>
+
+#define VSOCK_PORT 1234
+#define ITERATIONS 5
+
+static int die(const char *what)
+{
+    fprintf(stderr, "guest: %s: %s\n", what, strerror(errno));
+    return 1;
+}
+
+int main(void)
+{
+    int s = socket(AF_VSOCK, SOCK_STREAM, 0);
+    if (s < 0)
+        return die("socket(AF_VSOCK)");
+
+    struct sockaddr_vm a;
+    memset(&a, 0, sizeof a);
+    a.svm_family = AF_VSOCK;
+    a.svm_cid    = VMADDR_CID_ANY;
+    a.svm_port   = VSOCK_PORT;
+
+    if (bind(s, (struct sockaddr *)&a, sizeof a) < 0)
+        return die("bind");
+    if (listen(s, 8) < 0)
+        return die("listen");
+
+    fprintf(stderr, "guest: listening on vsock:%u\n", VSOCK_PORT);
+
+    for (int i = 0; i < ITERATIONS; i++) {
+        int c = accept(s, NULL, NULL);
+        if (c < 0)
+            return die("accept");
+        char ack = 'a';
+        if (write(c, &ack, 1) != 1)
+            return die("write ack");
+        fprintf(stderr, "guest: accept[%d] ack\n", i);
+        close(c);
+    }
+
+    close(s);
+    return 0;
+}