Compare commits

..
Author SHA1 Message Date
enricobuehler 4cd35e15ca fix(host): one info! line in a TLS destructor aborted the host on every session teardown
ci / bun-nix (pull_request) Successful in 20s
ci / web (pull_request) Successful in 1m2s
ci / rust (pull_request) Successful in 5m58s
ci / rust-arm64 (pull_request) Successful in 7m18s
ci / docs-site (pull_request) Successful in 8m26s
android / android (pull_request) Successful in 14m11s
A GameStream session ending killed the whole `punktfunk-host` process on Windows.
The SCM restarted it ~6 s later, so in the field it read as a mystery reconnect
rather than a crash. Four occurrences on .173, every one of them a session
teardown, on the canary and on a branch build alike.

`HotThreadGuard` is parked in a `thread_local!` so the last hot thread out
reverts the process-wide session tuning. Its `Drop` is therefore a **TLS
destructor**, and it called `tracing::info!`. By then this thread's other
thread-locals may already be gone — `tracing_subscriber`'s registry is
`sharded-slab`-backed and reads a `thread_local!` through `LocalKey::with` — so
the event panicked with "cannot access a Thread Local Storage value during or
after destruction". A panic that escapes a TLS destructor is fatal in Rust:
`fatal runtime error: thread local panicked on drop, aborting`.

The panic hook then hid the evidence. It teed through `tracing` too, so it
panicked the same way — and a panic raised while the hook runs is
`MustAbort::PanicInHook`, where std deliberately does not format the message
("perhaps that is causing the panic"). The log got `panicked at <loc>:`, a BLANK
line, and `thread panicked while processing panic. aborting.` The one string
naming the cause was erased at exactly the moment it mattered.

* `untune_process` no longer logs. The revert is only FFI and stays inside the
  refcount lock, so it is still atomic against a session starting concurrently.
  Its counterpart "applied" line runs on a live thread and is kept.
* The panic hook writes straight to the `LogRing` instead of through `tracing`.
  The ring is a `OnceLock` + `Mutex`, so it is TLS-free; `thread::current()` and
  `Backtrace::force_capture()` were both verified safe during TLS destruction.
  This does not make a TLS-destructor panic survivable — Rust aborts on those
  regardless — but the message that names the cause now always lands.

Reproduced standalone before fixing, against the same 1.96.0 toolchain, and the
output is byte-identical to the field log down to the blank line. That harness
also settles which half is load-bearing: destructor-logging alone aborts, hook
hardening alone still aborts (with a readable message), and removing the
destructor's log exits cleanly.
2026-08-18 10:30:35 +02:00
enricobuehler 700275fa0d Merge pull request 'A Windows launch is a hand-off, and 0.30 read its exit as the game's' (#288) from worktree-win-game-launch-untracked into main
ci / web (push) Successful in 1m9s
ci / docs-site (push) Successful in 1m24s
ci / rust-arm64 (push) Successful in 1m31s
deb / build-publish-gamescope (push) Successful in 21s
deb / build-publish-client-arm64 (push) Successful in 1m15s
docker / builders (--build-arg FEDORA_VERSION=44, ci/fedora-rpm.Dockerfile, punktfunk-fedora44-rpm, -f44) (push) Successful in 11s
docker / builders (ci/android-ci.Dockerfile, punktfunk-android-ci) (push) Successful in 8s
docker / builders (ci/arch-ci.Dockerfile, punktfunk-arch-ci) (push) Successful in 6s
docker / builders (ci/fedora-rpm.Dockerfile, punktfunk-fedora-rpm) (push) Successful in 7s
docker / builders (ci/flatpak-ci.Dockerfile, punktfunk-flatpak-ci) (push) Successful in 7s
deb / build-publish (push) Successful in 2m49s
docker / builders (ci/gamescope-trixie.Dockerfile, punktfunk-gamescope-trixie) (push) Successful in 11s
docker / builders (ci/rust-ci-noble.Dockerfile, punktfunk-rust-ci-noble) (push) Successful in 10s
docker / builders (ci/rust-ci.Dockerfile, punktfunk-rust-ci) (push) Successful in 12s
ci / bun-nix (push) Successful in 4m35s
docker / apps (., web/Dockerfile, punktfunk-web) (push) Successful in 53s
deb / build-publish-host (push) Successful in 3m57s
docker / apps (docs-site, docs-site/Dockerfile, punktfunk-docs) (push) Successful in 1m13s
docker / builders-arm64cross (push) Successful in 7s
deb / smoke-install (push) Successful in 2m36s
docker / deploy-docs (push) Successful in 30s
windows-host / package (push) Successful in 14m7s
windows-host / winget-source (push) Skipped
windows-host / canary-manifest (push) Successful in 17s
arch / build-publish (push) Successful in 16m14s
android / android (push) Successful in 19m8s
ci / rust (push) Successful in 19m40s
rpm / build-publish (43, bazzite, punktfunk-fedora-rpm) (push) Successful in 16m18s
rpm / build-publish (44, fedora-44, punktfunk-fedora44-rpm) (push) Successful in 16m28s
Reviewed-on: #288
2026-08-18 08:19:50 +00:00
enricobuehler 6352ff629d fix(host/library): a Windows launch is a hand-off, and 0.30 read its exit as the game's
ci / web (pull_request) Successful in 1m8s
ci / docs-site (pull_request) Successful in 1m17s
ci / rust-arm64 (pull_request) Successful in 1m27s
ci / bun-nix (pull_request) Successful in 1m41s
android / android (pull_request) Successful in 12m3s
ci / rust (pull_request) Successful in 16m5s
A user launched a title on a 0.30 Windows host and watched the game come up while
the stream dropped, with the console reporting nothing running. Two changes from
0.30 meet here, and the second turns the first into a disconnect.

`LeaseRequest::spawned` (0.30) started carrying the pid `CreateProcessAsUserW`
hands back, so a Windows launch could finally be a `LeaseKind::Child` instead of
degrading to `Untracked`. But `windows_launch_for` builds a protocol hand-off for
almost every kind — `explorer.exe "playnite://…"`, `Steam.exe "steam://…"`,
`explorer.exe "shell:AppsFolder\…"` — so that pid is a forwarder's, not the
game's, and it says nothing about the game in either direction: it quits a second
after launch when the launcher was already running, and it *becomes* the launcher
when it was not.

The watcher's shim window exists for exactly this, and both callers of the pid
path documented it as their protection — but it was skipped whenever the title
had no detect signals, which is the one shape that needs it. So a hint-less title
(a Playnite entry whose install dir Playnite does not know, a custom entry with no
hint) reported `running` on its first poll because the forwarder was alive, and
`exited` a second later when the forwarder quit: `finish` fired `on_exit`, which
closes the connection with `APP_EXITED`. In 0.29 the same title was `Untracked`,
nothing watched it, and the session stayed up — which is the "it used to just show
as running" the report describes.

The forwarder pid is not only a false liveness signal, it is a termination target:
`windows_term_ladder` adds `shared.spawned` to the pids it `WM_CLOSE`s and then
terminates. A Steam title launched while Steam was closed makes that pid the Steam
*client*, so `POST /game/end`, a grace expiry or `game_on_session_end` would ask
the player's whole Steam client to close rather than the game.

* The Windows recipe table now says which lines start the game and which only
  forward it (`WinRecipe::owns_game`); a forwarder's pid is dropped rather than
  carried, so the lease falls back to detect signals exactly as it did before.
  Only `gog` (the resolved exe), `command` and a plugin's own recipe (`cmd.exe /c`
  blocks on them) own their game.
* The shim window now applies to a bare child or pid whatever the spec holds. An
  empty spec is fewer reasons to trust the child, not more.
* Giving up on tracking lands the lease on `GameState::Untracked` instead of
  leaving the console on `launching` forever — the same honest answer `open`
  reaches when it starts no watcher at all.

`a_pid_only_launch_reports_its_exit` used a 4-second fixture, inside the shim
window; it passed only because of the bug above. It is 8 seconds now, and a new
ignored test drives the field report itself: a pid that hands off inside the
window with no signals must not end the session, and must leave the row
`untracked`. Backing the phase-1 change out fails that test with `on_exit` fired
once — the disconnect, reproduced.

Gates. Windows .173: `clippy --all-targets -D warnings` clean (non-vacuous), and
`library::launch` 11 + `gamelease` 12 tests pass. Linux (punktfunk-rust-ci): fmt
clean, `clippy --all-targets -D warnings` clean, `gamelease` 14 pass, and all
three `--ignored` live-process tests pass.
2026-08-18 09:30:57 +02:00
enricobuehler 33538582e2 Merge pull request 'The usbip DualSense died because its calibration report was one byte too long' (#287) from worktree-usbip-dualsense-fix into main
ci / web (push) Successful in 1m37s
android / android (push) Canceled after 8m17s
ci / bun-nix (push) Successful in 1m59s
arch / build-publish (push) Canceled after 8m19s
ci / docs-site (push) Successful in 2m24s
deb / build-publish-gamescope (push) Successful in 40s
deb / build-publish-client-arm64 (push) Successful in 1m18s
docker / builders (ci/arch-ci.Dockerfile, punktfunk-arch-ci) (push) Successful in 14s
docker / builders (ci/fedora-rpm.Dockerfile, punktfunk-fedora-rpm) (push) Successful in 19s
docker / builders (ci/flatpak-ci.Dockerfile, punktfunk-flatpak-ci) (push) Successful in 17s
docker / builders (ci/gamescope-trixie.Dockerfile, punktfunk-gamescope-trixie) (push) Successful in 17s
docker / builders (ci/rust-ci-noble.Dockerfile, punktfunk-rust-ci-noble) (push) Successful in 18s
docker / builders (ci/rust-ci.Dockerfile, punktfunk-rust-ci) (push) Successful in 12s
docker / builders (ci/android-ci.Dockerfile, punktfunk-android-ci) (push) Successful in 2m50s
deb / build-publish-host (push) Successful in 4m42s
ci / rust-arm64 (push) Successful in 9m6s
windows-host / package (push) Successful in 12m53s
windows-host / winget-source (push) Skipped
docker / apps (., web/Dockerfile, punktfunk-web) (push) Successful in 1m8s
docker / apps (docs-site, docs-site/Dockerfile, punktfunk-docs) (push) Successful in 3m37s
docker / builders (--build-arg FEDORA_VERSION=44, ci/fedora-rpm.Dockerfile, punktfunk-fedora44-rpm, -f44) (push) Successful in 2m53s
ci / rust (push) Successful in 15m38s
docker / builders-arm64cross (push) Successful in 14s
windows-host / canary-manifest (push) Successful in 37s
docker / deploy-docs (push) Successful in 40s
deb / build-publish (push) Successful in 13m14s
deb / smoke-install (push) Successful in 6m35s
rpm / build-publish (44, fedora-44, punktfunk-fedora44-rpm) (push) Successful in 18m49s
rpm / build-publish (43, bazzite, punktfunk-fedora-rpm) (push) Successful in 18m42s
Reviewed-on: #287
2026-08-17 15:01:52 +00:00
enricobuehler 8e8cc84d1a fix(pad): the usbip DualSense died because its calibration report was one byte too long
ci / bun-nix (pull_request) Successful in 30s
ci / docs-site (pull_request) Successful in 1m22s
ci / web (pull_request) Successful in 4m52s
android / android (pull_request) Successful in 4m57s
ci / rust-arm64 (pull_request) Successful in 6m55s
ci / rust (pull_request) Successful in 27m20s
`PUNKTFUNK_DUALSENSE_USBIP=1` enumerated the pad and then lost it ~400 ms later,
taking the controller with it (the usbip transport replaces uhid, so there was
nothing to fall back to). Three sessions blamed the ISO stream, the link speed and
`actual_length` in turn. It was none of them.

`DS_FEATURE_CALIBRATION` is 42 bytes. `hid-playstation` asks for 41
(`DS_FEATURE_REPORT_CALIBRATION_SIZE`), and on a USB backend an over-long reply is
not truncated, it is fatal to the transport:

    size = urb->actual_length;                 /* 42, what we declared */
    if (size > urb->transfer_buffer_length)    /* 42 > 41 */
            goto error;                        /* "probably malicious packet" */
    error:
            dev_err(&urb->dev->dev, "recv xbuf, %d\n", ret);   /* ret still 0 */
            usbip_event_add(ud, VDEV_EVENT_ERROR_TCP);

`VDEV_EVENT_ERROR_TCP` tears down the whole connection, not the one URB — hence
`recv xbuf, 0` (that 0 is the untouched initialiser, not a byte count), then
-EPROTO on the calibration read, `Failed to create dualsense`, and the disconnect.
The dmesg order made the teardown look like the cause; it was the consequence.

The blob had been wrong since it was written, and a FIXME said so. It stayed
invisible because every other backend truncates: hidraw for the uhid pad, hidclass
on Windows. USB/IP is the first transport that checks.

Three changes, because one of them alone would leave the same trap set:

- Trim the constant to 41 and pin all three feature-report sizes in a test.
- Clamp every reply to the requested length in the transport (`clamp_reply`), and
  drop any payload a handler returns on an OUT transfer — the kernel never reads
  one, so those bytes would misframe every PDU after them. A handler bug now costs
  one wrong reply instead of the device.
- `DualSenseUsbip::open` waits for the kernel to actually bind a HID driver before
  reporting success. A `vhci_hcd` attach succeeds immediately and enumerates
  asynchronously, so bringup faults were being reported as working pads; now they
  return Err and the caller's existing uhid fallback catches them.

Also adds `PUNKTFUNK_USBIP_TRACE` (both socket directions to disk) and
`scripts/usbip-trace-analyse.py`, which walks a capture and names the first frame
whose declared length disagrees with what the kernel will consume. The handler's
Err arm is no longer discarded either — it was the only signal distinguishing "we
dropped the connection" from "the kernel did", and both read identically in dmesg.

Verified on .21 (CachyOS, kernel 7.1.8): `Registered DualSense controller
hw_version=0x01000208 fw_version=0x01000036`, the device stays enumerated, and
snd-usb-audio mints a real ALSA card. Audio over the isochronous endpoint now runs
for the first time — a 300 Hz tone on the coil pair reads back channel-exact
(peak_coils=0.5000, peak_speaker=0.0000) for the whole run. A 4957-frame capture
analyses clean.
2026-08-17 16:54:37 +02:00
13 changed files with 889 additions and 90 deletions
+19 -4
View File
@@ -148,14 +148,28 @@ mod imp {
/// place used to be the design ("reverts at process exit") — but the host is a 24/7 service,
/// so after one stream it competed at HIGH class with a 1 ms global timer against whatever
/// the user played locally, forever.
///
/// 🛑 **Nothing in here may log, or touch anything that logs.** This runs from
/// [`HotThreadGuard`]'s `Drop`, which is a **TLS destructor** — and by then this thread's
/// *other* thread-locals may already be gone, including the ones `tracing_subscriber`'s
/// registry keeps (it is `sharded-slab`-backed, and the slab's per-thread registration is a
/// `thread_local!` read with `LocalKey::with`). Emitting an event here panicked with "cannot
/// access a Thread Local Storage value during or after destruction", and **a panic that
/// escapes a TLS destructor is fatal in Rust** — `fatal runtime error: thread local panicked
/// on drop, aborting`. So one `info!` line killed the whole host on session teardown and the
/// SCM restarted it ~6 s later, which read in the field as a mystery reconnect (on glass,
/// .173: four aborts, every one of them a session teardown).
///
/// The revert itself is only FFI and stays here, inside the refcount lock, so it remains
/// atomic against a session starting concurrently. The counterpart "applied" line in
/// [`tune_process`] runs on a live thread and is kept — that one is safe.
fn untune_process() {
// SAFETY: same FFI surface as `tune_process` — plain-integer arguments, constant
// pseudo-handle, no pointers or buffers.
// pseudo-handle, no pointers or buffers. Sound in a TLS destructor: no Rust TLS is read.
unsafe {
timeEndPeriod(1); // pairs the timeBeginPeriod(1)
DwmEnableMMCSS(0);
SetPriorityClass(GetCurrentProcess(), NORMAL_PRIORITY_CLASS);
tracing::info!("windows session tuning reverted (timer, DWM MMCSS, NORMAL priority)");
}
}
@@ -165,8 +179,9 @@ mod imp {
impl Drop for HotThreadGuard {
fn drop(&mut self) {
// A poisoned lock skips the revert (best-effort, like every call here) instead of
// panicking inside a TLS destructor.
// ⚠ TLS DESTRUCTOR. Everything reached from here must be panic-free and must not log —
// see [`untune_process`] for what a single `info!` here cost. A poisoned lock skips the
// revert (best-effort, like every call here) rather than panicking.
if let Ok(mut n) = HOT_THREADS.lock() {
*n -= 1;
if *n == 0 {
@@ -624,7 +624,20 @@ impl DualSenseUsbip {
&format!("virtual DualSense {index}"),
)?;
// Publish only once the device is actually attached, so a failed attach leaves no stale
// **A successful attach is not a working pad.** `vhci_hcd` accepts the socket immediately
// and enumerates asynchronously, so any protocol fault downstream of the attach — a reply
// the kernel rejects, a descriptor it will not parse — surfaces a few hundred milliseconds
// later as a device that appears and then vanishes. Returning `Ok` on the attach alone
// reported those as success, and because this transport *replaces* uhid the user was left
// with no pad at all rather than a degraded one. That has now happened twice, so the
// contract is: `open` returns `Ok` only once the kernel has actually bound a driver, and
// the caller's existing uhid fallback covers everything else.
if let Err(e) = wait_until_bound(index) {
drop(attach); // detach the port before the caller retries or degrades
return Err(e);
}
// Publish only once the device is attached *and* bound, so a failed bringup leaves no stale
// receiver for the streamer to drain forever.
publish_audio_rx(index, rx);
tracing::info!(
@@ -668,6 +681,94 @@ impl Drop for DualSenseUsbip {
}
}
/// How long to give the kernel to enumerate the pad and bind a HID driver to it.
///
/// Enumeration + `hid-playstation` bind measured ~330 ms on an idle box; the failure this guards
/// against tore the device down ~400 ms after attach. Three seconds is comfortably clear of both,
/// and the cost of waiting is paid once per pad arrival. `PUNKTFUNK_DUALSENSE_USBIP_GRACE_MS`
/// overrides it; `0` skips the check entirely (useful when bisecting the transport itself).
const BIND_GRACE: std::time::Duration = std::time::Duration::from_millis(3000);
/// Block until the kernel has enumerated the virtual pad *and* bound a HID driver to its HID
/// interface, or the grace period expires.
///
/// Checking for the `usb_device` node alone is not enough: in the 2026-08-17 failure the node was
/// created and then removed ~400 ms later when the calibration reply tore the connection down, so a
/// single early poll saw a healthy device. Requiring a bound HID driver with an `input` child means
/// the thing the pad exists to provide actually came up.
fn wait_until_bound(index: u8) -> Result<()> {
let grace = std::env::var("PUNKTFUNK_DUALSENSE_USBIP_GRACE_MS")
.ok()
.and_then(|s| s.parse::<u64>().ok())
.map(std::time::Duration::from_millis)
.unwrap_or(BIND_GRACE);
if grace.is_zero() {
return Ok(());
}
let deadline = Instant::now() + grace;
let mut saw_device = false;
loop {
if let Some(t) = find_usb_topology() {
saw_device = true;
if hid_input_bound(&t.sysfs_path) {
tracing::debug!(
index,
sysfs = %t.sysfs_path.display(),
"usbip DualSense bound a HID driver"
);
return Ok(());
}
}
if Instant::now() >= deadline {
break;
}
std::thread::sleep(std::time::Duration::from_millis(50));
}
// Which of the two it is tells the operator where to look, so say it rather than "failed".
if saw_device {
anyhow::bail!(
"the virtual DualSense enumerated but no HID driver bound within {:?} — it is present \
in sysfs without an input device. Check `dmesg` for a `playstation`/`hid-generic` \
probe failure",
grace
)
}
anyhow::bail!(
"the virtual DualSense never enumerated within {grace:?} — `vhci_hcd` accepted the attach \
but no 054c:0ce6 device appeared (or it appeared and was torn down again). Check `dmesg`; \
a transport fault here reads as `recv xbuf` / `sendmsg failed` from vhci_hcd"
)
}
/// Whether the pad's HID interface under `sysfs` has a bound HID driver that produced an input
/// device. Either `hid-playstation` or `hid-generic` counts — both give a usable pad.
fn hid_input_bound(sysfs: &std::path::Path) -> bool {
let Ok(entries) = std::fs::read_dir(sysfs) else {
return false;
};
for e in entries.flatten() {
// The HID function is interface 3; its sysfs node is `<busid>:1.3`.
if !e.file_name().to_string_lossy().ends_with(":1.3") {
continue;
}
let Ok(children) = std::fs::read_dir(e.path()) else {
continue;
};
for c in children.flatten() {
// `0003:054C:0CE6.000N` — the bound HID device. `input/` appears only once a driver
// has claimed it and registered; a probe that fails leaves the directory absent.
if c.file_name().to_string_lossy().starts_with("0003:")
&& c.path().join("input").is_dir()
{
return true;
}
}
}
false
}
/// The sysfs path of an attached virtual DualSense's `usb_device` node, plus the udev properties
/// wine turns into a Windows ContainerId.
#[derive(Debug, Clone, PartialEq, Eq)]
@@ -225,10 +225,12 @@ struct ServerThread {
}
impl ServerThread {
/// Spawn the server on `listener`, serving exactly the one simulated `dev`.
fn spawn(listener: std::net::TcpListener, dev: UsbDevice) -> Result<ServerThread> {
/// Spawn the server on `listener`, serving exactly the one simulated `dev`. `label` names the
/// device in log lines and in the `PUNKTFUNK_USBIP_TRACE` file names.
fn spawn(listener: std::net::TcpListener, dev: UsbDevice, label: &str) -> Result<ServerThread> {
let stop = Arc::new(tokio::sync::Notify::new());
let stop_t = stop.clone();
let label = label.to_string();
let join = std::thread::Builder::new()
.name("pf-deck-usbip".into())
.spawn(move || {
@@ -246,6 +248,7 @@ impl ServerThread {
listener,
Arc::new(UsbIpServer::new_simulated(vec![dev])),
stop_t,
label,
));
})
.context("spawn usbip server thread")?;
@@ -270,6 +273,7 @@ async fn run_server(
listener: std::net::TcpListener,
server: Arc<UsbIpServer>,
stop: Arc<tokio::sync::Notify>,
label: String,
) {
let listener = match tokio::net::TcpListener::from_std(listener) {
Ok(l) => l,
@@ -289,8 +293,41 @@ async fn run_server(
// active hidraw against a 266 Hz source).
sock.set_nodelay(true).ok();
let server = server.clone();
let trace = super::usbip_trace::trace_prefix(&label);
let label = label.clone();
tokio::spawn(async move {
let _ = usbip_sim::handler(&mut sock, server).await;
// The handler's Err arm used to be discarded. It is the *only* signal that
// we tore the connection down rather than the kernel — and the kernel's
// side of that (`recv xbuf`, `sendmsg failed`) reads identically either
// way, so throwing it away cost days of mis-attributed diagnosis.
let sink = trace.and_then(|prefix| {
match super::usbip_trace::open_trace(&prefix) {
Ok(s) => {
tracing::info!(prefix, "usbip byte trace armed");
Some(s)
}
Err(e) => {
tracing::warn!(error = %e, "usbip trace files unopenable — running untraced");
None
}
}
});
let res = match sink {
Some(s) => {
let mut traced = super::usbip_trace::TracedIo::wrap(sock, s);
usbip_sim::handler(&mut traced, server).await
}
None => usbip_sim::handler(&mut sock, server).await,
};
match res {
Ok(()) => tracing::debug!(label, "usbip connection closed by the kernel"),
Err(e) => tracing::warn!(
label,
error = %e,
"usbip server dropped the connection — the kernel will report this as a \
transfer error on whatever URB was in flight"
),
}
});
}
Err(e) => {
@@ -361,7 +398,7 @@ fn attach_in_process(dev: UsbDevice, label: &str) -> Result<UsbipAttachment> {
listener
.set_nonblocking(true)
.context("usbip listener set_nonblocking")?;
let server = ServerThread::spawn(listener, dev)?;
let server = ServerThread::spawn(listener, dev, label)?;
// Connect to our own server and run the OP_REQ_IMPORT handshake.
let mut sock = connect_loopback(port).context("connect to usbip server")?;
@@ -395,7 +432,7 @@ fn attach_via_cli(dev: UsbDevice, label: &str) -> Result<UsbipAttachment> {
listener
.set_nonblocking(true)
.context("usbip listener set_nonblocking")?;
let server = ServerThread::spawn(listener, dev)?;
let server = ServerThread::spawn(listener, dev, label)?;
let before = vhci_used_ports();
usbip_attach_cli().context("usbip CLI attach")?;
@@ -0,0 +1,167 @@
//! Byte-level tracing for the USB/IP transport (`PUNKTFUNK_USBIP_TRACE`).
//!
//! # Why this exists
//!
//! A USB/IP connection is a *framed byte stream over one TCP socket*, and every frame's length is
//! declared inside the frame. So any reply that writes a different number of bytes than its header
//! declares does not corrupt that one URB — it shifts every byte after it, and the peer's next read
//! lands mid-frame. `vhci_hcd` reports the wreckage from wherever it happens to notice
//! (`recv xbuf`, `unknown pdu`, `cannot find a urb of seqnum`), which is never where the extra or
//! missing bytes were written. Reading the code cannot settle it, because the bug *is* a
//! disagreement between the code's arithmetic and the wire.
//!
//! This wraps the socket and writes both directions to disk verbatim, plus a record of where each
//! read/write call began and ended, so [`crate::usbip_trace`]'s companion analyser can walk the
//! streams as PDUs and name the first frame whose declared length and written length disagree.
//!
//! It is off unless `PUNKTFUNK_USBIP_TRACE` is set, and it is deliberately dumb: no parsing, no
//! filtering, no allocation beyond the write buffer. A tracer that interprets can be wrong in the
//! same way the code under test is wrong.
//!
//! # Using it
//!
//! ```text
//! PUNKTFUNK_USBIP_TRACE=/tmp/pad punktfunk-host pad-usbip-test --seconds 5
//! ```
//!
//! yields `/tmp/pad.<label>.rx` (kernel → us), `.tx` (us → kernel) and `.idx` (one
//! `us,dir,offset,len` record per call). Feed them to `scripts/usbip-trace-analyse.py`.
use std::fs::File;
use std::io::{BufWriter, Write};
use std::pin::Pin;
use std::sync::{Arc, Mutex};
use std::task::{Context, Poll};
use std::time::Instant;
use tokio::io::{AsyncRead, AsyncWrite, ReadBuf};
/// Where the trace goes, if tracing is on. One prefix per attached device.
pub fn trace_prefix(label: &str) -> Option<String> {
let base = std::env::var("PUNKTFUNK_USBIP_TRACE").ok()?;
if base.is_empty() || base == "0" {
return None;
}
// `label` is a human string ("virtual DualSense 0"); keep it filesystem-safe.
let safe: String = label
.chars()
.map(|c| if c.is_ascii_alphanumeric() { c } else { '-' })
.collect();
Some(format!("{base}.{safe}"))
}
/// The three files a trace is made of, shared by the read and write halves.
struct Sink {
rx: BufWriter<File>,
tx: BufWriter<File>,
idx: BufWriter<File>,
rx_off: u64,
tx_off: u64,
start: Instant,
}
impl Sink {
fn create(prefix: &str) -> std::io::Result<Self> {
// Append rather than `with_extension`, which would treat the label's own dots/dashes as an
// extension and collapse every pad's trace onto the same three files.
let f = |ext: &str| File::create(format!("{prefix}.{ext}"));
Ok(Sink {
rx: BufWriter::new(f("rx")?),
tx: BufWriter::new(f("tx")?),
idx: BufWriter::new(f("idx")?),
rx_off: 0,
tx_off: 0,
start: Instant::now(),
})
}
/// Record one completed call. `dir` is `r` (kernel → us) or `w` (us → kernel).
fn record(&mut self, dir: char, bytes: &[u8]) {
let (stream, off) = match dir {
'r' => (&mut self.rx, &mut self.rx_off),
_ => (&mut self.tx, &mut self.tx_off),
};
let at = *off;
let _ = stream.write_all(bytes);
*off += bytes.len() as u64;
let us = self.start.elapsed().as_micros();
let _ = writeln!(self.idx, "{us},{dir},{at},{}", bytes.len());
// Flushed per call on purpose: the failure under investigation ends with the process's
// socket dying, and a buffered tail is exactly the part that would be lost.
let _ = stream.flush();
let _ = self.idx.flush();
}
}
/// An opened set of trace files, ready to wrap a stream.
///
/// Opening is separate from wrapping so the caller can fall back to the untraced path without
/// having already surrendered its socket to a constructor that then failed.
pub struct TraceSink(Arc<Mutex<Sink>>);
/// Open `<prefix>.rx` / `.tx` / `.idx`, truncating any previous trace.
pub fn open_trace(prefix: &str) -> std::io::Result<TraceSink> {
Ok(TraceSink(Arc::new(Mutex::new(Sink::create(prefix)?))))
}
/// A socket wrapper that copies both directions to disk.
///
/// Wraps at the *call site* rather than inside the vendored server, so the vendored crate carries
/// no debug scaffolding and the traced and untraced paths run the identical handler.
pub struct TracedIo<T> {
inner: T,
sink: Arc<Mutex<Sink>>,
}
impl<T> TracedIo<T> {
/// Begin copying `inner`'s traffic into an already-opened [`TraceSink`].
pub fn wrap(inner: T, sink: TraceSink) -> Self {
TracedIo {
inner,
sink: sink.0,
}
}
}
impl<T: AsyncRead + Unpin> AsyncRead for TracedIo<T> {
fn poll_read(
mut self: Pin<&mut Self>,
cx: &mut Context<'_>,
buf: &mut ReadBuf<'_>,
) -> Poll<std::io::Result<()>> {
let before = buf.filled().len();
let r = Pin::new(&mut self.inner).poll_read(cx, buf);
if let Poll::Ready(Ok(())) = &r {
let got = buf.filled()[before..].to_vec();
// A zero-length ready read is EOF, and it is worth a record of its own: it is the
// moment the peer went away, and which side went first is the whole question.
if let Ok(mut s) = self.sink.lock() {
s.record('r', &got);
}
}
r
}
}
impl<T: AsyncWrite + Unpin> AsyncWrite for TracedIo<T> {
fn poll_write(
mut self: Pin<&mut Self>,
cx: &mut Context<'_>,
buf: &[u8],
) -> Poll<std::io::Result<usize>> {
let r = Pin::new(&mut self.inner).poll_write(cx, buf);
if let Poll::Ready(Ok(n)) = &r {
if let Ok(mut s) = self.sink.lock() {
s.record('w', &buf[..*n]);
}
}
r
}
fn poll_flush(mut self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<std::io::Result<()>> {
Pin::new(&mut self.inner).poll_flush(cx)
}
fn poll_shutdown(mut self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll<std::io::Result<()>> {
Pin::new(&mut self.inner).poll_shutdown(cx)
}
}
@@ -20,15 +20,19 @@ use punktfunk_core::quic::{HidOutput, RichInput};
// inputtino (each array's first byte is the report id). The pairing report carries a fixed
// virtual MAC.
#[rustfmt::skip]
// FIXME(cal-len): the descriptor declares report 0x05 as a 40-byte feature (id + 40 = 41 total),
// but this blob is 42 bytes (one trailing pad byte too many). Linux `hid-playstation` tolerates it
// (the backend is live-validated), and `hidclass` truncates to the declared length, so it is not
// currently blocking; trim the trailing 0x00 to 41 once a physical DualSense is available to
// re-verify motion calibration on both backends.
// **41 bytes, and that is load-bearing** — the descriptor declares report 0x05 as a 40-byte feature
// and `hid-playstation` asks for id + 40 = 41 (`DS_FEATURE_REPORT_CALIBRATION_SIZE`). This blob
// carried one trailing pad byte too many until 2026-08-17. On uhid and on Windows that was
// invisible, because hidraw and `hidclass` both truncate a feature reply to the declared length —
// but a *USB* backend does not: `usbip_recv_xbuff()` compares the reply's `actual_length` against
// the URB's `transfer_buffer_length` and, on 42 > 41, treats it as a malicious packet, logs
// `recv xbuf, 0` and raises `VDEV_EVENT_ERROR_TCP` — which tears down the whole connection, not the
// one URB. That killed the usbip pad's `hid-playstation` probe with -EPROTO and took the controller
// with it. Keep this exactly 41 bytes. See [`crate::dualsense_usbip`].
pub const DS_FEATURE_CALIBRATION: &[u8] = &[ // report 0x05 (motion calibration)
0x05, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00, 0x10, 0x27, 0xF0, 0xD8, 0x10, 0x27, 0xF0, 0xD8, 0x10,
0x27, 0xF0, 0xD8, 0xF4, 0x01, 0xF4, 0x01, 0x10, 0x27, 0xF0, 0xD8, 0x10, 0x27, 0xF0, 0xD8, 0x10,
0x27, 0xF0, 0xD8, 0x0B, 0x00, 0x00, 0x00, 0x00, 0x00, 0x00,
0x27, 0xF0, 0xD8, 0x0B, 0x00, 0x00, 0x00, 0x00, 0x00,
];
#[rustfmt::skip]
pub const DS_FEATURE_PAIRING: &[u8] = &[ // report 0x09 (pairing info: MAC at bytes 1..7)
@@ -643,6 +647,33 @@ pub fn parse_ds_output(pad: u8, data: &[u8], fb: &mut DsFeedback) {
mod tests {
use super::*;
/// **Every feature report must be exactly the size the driver asks for.**
///
/// `hid-playstation` requests these by fixed size (`DS_FEATURE_REPORT_*_SIZE`), and on a *USB*
/// backend a reply longer than the request is fatal to the whole transport, not to the URB:
/// `usbip_recv_xbuff()` sees `actual_length > transfer_buffer_length`, calls it a malicious
/// packet, and raises `VDEV_EVENT_ERROR_TCP`, which disconnects the device. Calibration was
/// 42 bytes against a 41-byte request until 2026-08-17 and killed the usbip pad outright —
/// invisibly on uhid and on Windows, because hidraw and `hidclass` both truncate.
///
/// Sizes are `hid-playstation`'s own constants: calibration 41, pairing 20, firmware 64.
#[test]
fn feature_reports_are_exactly_the_size_the_driver_requests() {
assert_eq!(
DS_FEATURE_CALIBRATION.len(),
41,
"calibration (report 0x05)"
);
assert_eq!(DS_FEATURE_PAIRING.len(), 20, "pairing (report 0x09)");
assert_eq!(DS_FEATURE_FIRMWARE.len(), 64, "firmware (report 0x20)");
assert_eq!(ds_pairing_reply(0).len(), 20, "pairing reply");
// The first byte of a feature report is its id; a wrong one is answered to the wrong query.
assert_eq!(DS_FEATURE_CALIBRATION[0], 0x05);
assert_eq!(DS_FEATURE_PAIRING[0], 0x09);
assert_eq!(DS_FEATURE_FIRMWARE[0], 0x20);
}
/// The Steam dual-pad → DualSense touchpad SPLIT: left pad (surface 1) lands contact 0
/// on the left half, right pad (surface 2) contact 1 on the right half; y follows the
/// shared screen convention (top → 0) with no flip; pad clicks set the touchpad-click
+6
View File
@@ -623,6 +623,12 @@ pub mod uhid_abi;
#[cfg(any(target_os = "linux", target_os = "windows"))]
#[path = "inject/uhid_manager.rs"]
pub mod uhid_manager;
/// Linux: byte-level tracing of the USB/IP socket (`PUNKTFUNK_USBIP_TRACE`). A framing bug in that
/// stream is only ever visible as damage the kernel notices somewhere later, so the wire itself has
/// to be recoverable.
#[cfg(target_os = "linux")]
#[path = "inject/linux/usbip_trace.rs"]
pub mod usbip_trace;
/// Transport-independent Xbox HID codec — the report the `pf-gamepad` UMDF driver serves under
/// device-types 4, 5 and 6 (Xbox Wireless / One S / Elite Series 2, which share one descriptor and
/// differ only in VID/PID), giving an Xbox pad the HID footing `pf-xusb` never had
+97 -12
View File
@@ -574,6 +574,10 @@ fn watch(
"the launch command exited immediately (a launcher handing off) and this \
title has no detect signals stopping game tracking for it"
);
// Nothing will ever observe this game again, so say that rather than leave the
// console on "launching" forever — the same honest answer `open` reaches when it
// starts no watcher at all.
shared.set_state(GameState::Untracked);
return;
}
tracing::debug!(
@@ -618,6 +622,7 @@ fn watch(
LeaseKind::Matched
};
if matches!(kind, LeaseKind::Untracked) {
shared.set_state(GameState::Untracked);
return;
}
} else {
@@ -643,6 +648,7 @@ fn watch(
LeaseKind::Matched
};
if matches!(kind, LeaseKind::Untracked) {
shared.set_state(GameState::Untracked);
return;
}
}
@@ -654,17 +660,25 @@ fn watch(
// detect signals is still fully tracked.
//
// But a launcher that is about to hand off and exit looks *exactly* like the game for its
// first few seconds. When the store gave us signals to recognize the real game by, wait out
// the shim window before believing this child is it — otherwise the lease leaves this phase
// on its very first poll, the reclassification above never gets to run, and the hand-off
// that follows is read as the game exiting. On Linux that ended a session ~7 s after
// launching any Steam title, before the game had even started (on glass, .41).
// first few seconds, so wait out the shim window before believing this child is it —
// otherwise the lease leaves this phase on its very first poll, the reclassification above
// never gets to run, and the hand-off that follows is read as the game exiting. On Linux
// that ended a session ~7 s after launching any Steam title, before the game had even
// started (on glass, .41).
//
// With no signals the child is all we have, so it still counts immediately: a custom command
// is tracked exactly as before.
// ⚠ This used to be skipped whenever the title had **no** detect signals, on the reasoning
// that the child was then all we had — which quietly made the no-signals case the one shape
// the shim window could not protect. It is the shape that needs it most: a hint-less title
// is exactly the one whose launch is a bare protocol hand-off, and `spec.is_empty()` is
// *fewer* reasons to trust the child, not more. On Windows every launch recipe is a
// hand-off by construction (`explorer.exe "playnite://…"`, `Steam.exe "steam://…"`), so
// carrying its pid (0.30) made a hint-less title report `running` on its first poll and
// `exited` a second later, when the forwarder quit — ending the session and dropping the
// stream while the game was still starting. Both callers of the pid path already documented
// this window as their protection; now they have it.
let child_alive = matches!(kind, LeaseKind::Child)
&& (child.is_some() || spawned.is_some())
&& (shared.spec.is_empty() || spawned_at.elapsed() >= SHIM_WINDOW);
&& spawned_at.elapsed() >= SHIM_WINDOW;
let live = scanner.find(&shared.spec, shared.launch_stamp);
if !live.is_empty() || child_alive {
known = live.clone();
@@ -1744,10 +1758,16 @@ mod tests {
/// The same launch, driven to its exit: the pid dying is the game exiting, and that fires the
/// action that ends the session — which is precisely what never happened in the field report.
///
/// Ignored by default: it waits out [`EXIT_CONFIRM`] after a real process ends, ~10 s.
/// ⚠ The process must outlive [`SHIM_WINDOW`] for that reading to be the right one. It used to
/// be a 4-second `sleep`, which is *inside* the window — the test passed only because a lease
/// with no detect signals skipped the window entirely, which is the bug the sibling test below
/// pins. Keep this fixture longer than the window: a launch that quits sooner is a hand-off, and
/// treating it as a game exit is what dropped the stream a second after every Windows launch.
///
/// Ignored by default: it outlives the shim window and then waits out [`EXIT_CONFIRM`], ~12 s.
#[cfg(target_os = "linux")]
#[test]
#[ignore = "drives a real process for ~10s (exit confirmation)"]
#[ignore = "drives a real process for ~12s (shim window + exit confirmation)"]
fn a_pid_only_launch_reports_its_exit() {
use std::sync::atomic::AtomicUsize;
@@ -1755,7 +1775,7 @@ mod tests {
// `/proc/<pid>` entry with an unchanged start time — so the scan would call it alive
// forever and the exit under test could never be observed.
let mut child = std::process::Command::new("sleep")
.arg("4")
.arg("8")
.spawn()
.expect("spawn the fake game");
let pid = child.id();
@@ -1778,7 +1798,7 @@ mod tests {
);
let shared = lease.shared();
let deadline = Instant::now() + Duration::from_secs(20);
let deadline = Instant::now() + Duration::from_secs(30);
while Instant::now() < deadline && shared.state() != GameState::Exited {
std::thread::sleep(Duration::from_millis(250));
}
@@ -1790,6 +1810,71 @@ mod tests {
);
}
/// 🛑 The 2026-08-18 field report, in one test: a Windows launch is a **protocol hand-off**, and
/// a hand-off must never be mistaken for the game exiting.
///
/// The shape is `explorer.exe "playnite://playnite/start/<id>"` — the host spawns a forwarder,
/// gets its pid, and the forwarder quits about a second later having handed the launch to
/// Playnite. The title carries no detect hint (the Playnite plugin only sends `install_dir` when
/// Playnite knows one), so the lease has the pid and nothing else.
///
/// What shipped in 0.30 did this: the empty spec skipped [`SHIM_WINDOW`], so the lease called
/// the forwarder "the game running" on its first poll, and a second later called the
/// forwarder's exit "the game exited" — closing the connection with `APP_EXITED`. The player
/// saw the game start on the host and the stream drop, with the console reporting no running
/// game. Two things have to hold for that not to happen, and both are asserted here.
///
/// Ignored by default: it must outlive [`SHIM_WINDOW`] and [`EXIT_CONFIRM`] to prove the
/// session is not ended *later* either.
#[cfg(target_os = "linux")]
#[test]
#[ignore = "drives a real process for ~10s (shim window + exit confirmation)"]
fn a_pid_only_handoff_with_no_signals_never_ends_the_session() {
use std::sync::atomic::AtomicUsize;
// Reaped on its own thread — see the sibling test: a zombie keeps its `/proc` entry and
// would read as alive forever.
let mut child = std::process::Command::new("sleep")
.arg("1")
.spawn()
.expect("spawn the fake forwarder");
let pid = child.id();
std::thread::spawn(move || {
let _ = child.wait();
});
static HANDOFF_EXITS: AtomicUsize = AtomicUsize::new(0);
HANDOFF_EXITS.store(0, Ordering::SeqCst);
let lease = open(
LeaseRequest {
spawned: Some(pid),
spec: DetectSpec::default(),
launch_stamp: launch_clock(),
..req("playnite:handoff", DetectSpec::default(), false)
},
Box::new(|| {
HANDOFF_EXITS.fetch_add(1, Ordering::SeqCst);
}),
);
let shared = lease.shared();
std::thread::sleep(SHIM_WINDOW + EXIT_CONFIRM + Duration::from_secs(2));
assert_eq!(
HANDOFF_EXITS.load(Ordering::SeqCst),
0,
"a launch command handing off must not end the session — this is the field report"
);
// ...and the console must not be told the game is up either. `Untracked` is the honest
// answer: nothing is watching this title, so nothing will ever report it starting or
// stopping. Sitting at `Launching` (or claiming `Running`) are the two lies 0.30 set out
// to remove, and giving up on tracking must not quietly reinstate one of them.
assert_eq!(
shared.state(),
GameState::Untracked,
"nothing is watching this title any more, and the row has to say so"
);
}
/// The whole point of the module, against a real process: a `Child` lease sees its game running,
/// notices when it exits, and reports that exit exactly once.
///
@@ -332,7 +332,8 @@ fn run(
#[allow(unused_mut)]
let mut spawned_now = false;
// Windows hands back a pid rather than a child; kept for the lease (see the native plane
// and `gamelease::LeaseRequest::spawned`). `None` elsewhere and when nothing was spawned.
// and `gamelease::LeaseRequest::spawned`). `None` elsewhere, when nothing was spawned, and
// when what was spawned only forwards the launch (`library::WinRecipe::owns_game`).
#[allow(unused_mut)]
let mut spawned_pid: Option<u32> = None;
// Close this client's previous game first, when the operator asked for that — the compat
@@ -365,8 +366,8 @@ fn run(
(None, None) => Ok(None),
};
match launched {
Ok(pid) => {
spawned_pid = pid;
Ok(l) => {
spawned_pid = l.and_then(|l| l.tracked_pid());
spawned_now = true;
}
Err(e) => {
+144 -46
View File
@@ -176,6 +176,70 @@ fn command_for(spec: &LaunchSpec) -> Option<String> {
}
}
/// A resolved Windows launch: the command line to spawn, the directory to spawn it in, and whether
/// the process that line starts **is** the game.
///
/// [`Self::owns_game`] is the whole reason this is a struct and not a pair. Almost every Windows
/// recipe is a protocol hand-off — `explorer.exe "playnite://…"`, `Steam.exe "steam://…"` — that
/// forwards the request to whichever launcher owns the title and then exits. Its pid is a
/// forwarder's, so that pid's lifetime says nothing about the game's, in either direction:
///
/// * the launcher was already running, so the forwarder quits a second later — read as a `Child`
/// lease, that is the game "exiting" while it is still loading;
/// * the launcher was *not* running, so the process the host started becomes the launcher itself
/// and outlives every game the player then quits — a lease that can never report an exit.
///
/// Only a line that starts the game (or the operator's own command) directly earns its pid a place
/// in [`crate::gamelease::LeaseRequest::spawned`]; a hand-off pid is dropped, and the lease falls
/// back to the title's detect signals, exactly as it did before the pid was carried at all.
#[cfg(windows)]
pub struct WinRecipe {
/// The full command line to hand to `CreateProcessAsUserW`.
pub cmdline: String,
/// The working directory to start it in, when the recipe needs a specific one.
pub workdir: Option<std::path::PathBuf>,
/// See the type docs: `false` for a protocol/launcher hand-off.
pub owns_game: bool,
}
#[cfg(windows)]
impl WinRecipe {
/// A line that forwards the launch to whoever owns the title and then exits.
fn handoff(cmdline: String) -> Self {
Self {
cmdline,
workdir: None,
owns_game: false,
}
}
/// A line that starts the game — or the operator's own command — as its own process.
fn game(cmdline: String, workdir: Option<std::path::PathBuf>) -> Self {
Self {
cmdline,
workdir,
owns_game: true,
}
}
}
/// What a Windows launch started, as the lease needs to hear it — see [`WinRecipe::owns_game`].
#[cfg(windows)]
pub struct WindowsLaunch {
/// The pid `CreateProcessAsUserW` handed back.
pub pid: u32,
/// Whether that pid is the game's rather than a forwarder's.
pub owns_game: bool,
}
#[cfg(windows)]
impl WindowsLaunch {
/// The pid to carry on the lease: `None` when all the host started was a hand-off.
pub fn tracked_pid(&self) -> Option<u32> {
self.owns_game.then_some(self.pid)
}
}
/// Windows: launch a store-qualified library id into the **interactive user session** — the Windows
/// analogue of the Linux gamescope-nested [`resolve_launch`]. The id is resolved against the host's
/// OWN library (the client never sends a command), mapped to a concrete process by
@@ -184,12 +248,13 @@ fn command_for(spec: &LaunchSpec) -> Option<String> {
/// Wired into the data plane *after* capture is live, so the title renders onto the already-captured
/// desktop and grabs foreground.
///
/// Returns the **pid of the process it started**, which is what the caller hands to
/// [`crate::gamelease::LeaseRequest::spawned`]. It used to be logged and discarded, and that was the
/// whole of Windows' disadvantage against Linux here: with no `Child` to hold and no pid kept, a
/// title whose provider supplied no detect hint left the lease nothing to watch or signal.
/// Returns the process it started and whether that process is the game ([`WindowsLaunch`]) — the
/// pid is what the caller hands to [`crate::gamelease::LeaseRequest::spawned`], but only when it
/// belongs to the game. It used to be logged and discarded, and that was the whole of Windows'
/// disadvantage against Linux here: with no `Child` to hold and no pid kept, a title whose provider
/// supplied no detect hint left the lease nothing to watch or signal.
#[cfg(windows)]
pub fn launch_title(id: &str) -> Result<u32> {
pub fn launch_title(id: &str) -> Result<WindowsLaunch> {
let entry = all_games()
.into_iter()
.find(|g| g.id == id)
@@ -199,8 +264,10 @@ pub fn launch_title(id: &str) -> Result<u32> {
// A `plugin` entry's recipe comes from the plugin that owns it, and arrives in the same
// (command line, working dir) shape this path already spawns. `windows_launch_for` has no arm
// for the kind, so a failed ask falls through to the "no recipe" error below.
let (cmdline, workdir) = plugin_recipe(&entry)
.map(|l| (l.command, l.cwd))
// A plugin publishes a concrete `(command line, working dir)` for its own title, the same shape
// the operator-typed `command` kind produces — so it is spawned, and tracked, on the same terms.
let recipe = plugin_recipe(&entry)
.map(|l| WinRecipe::game(l.command, l.cwd))
.or_else(|| windows_launch_for(&spec))
.ok_or_else(|| {
anyhow::anyhow!(
@@ -208,10 +275,21 @@ pub fn launch_title(id: &str) -> Result<u32> {
spec.kind
)
})?;
let WinRecipe {
cmdline,
workdir,
owns_game,
} = recipe;
let pid = crate::interactive::spawn_in_active_session(&cmdline, workdir.as_deref())
.with_context(|| format!("launch '{id}' in the interactive session"))?;
tracing::info!(launch_id = id, %cmdline, pid, "launched library title in the interactive session");
Ok(pid)
tracing::info!(
launch_id = id,
%cmdline,
pid,
owns_game,
"launched library title in the interactive session"
);
Ok(WindowsLaunch { pid, owns_game })
}
/// Windows: map a resolved [`LaunchSpec`] to a `(command line, working dir)` to spawn into the
@@ -223,7 +301,7 @@ pub fn launch_title(id: &str) -> Result<u32> {
/// The `plugin` kind is deliberately absent: its answer comes from another process, so it is
/// resolved by [`plugin_recipe`] before this is reached.
#[cfg(windows)]
fn windows_launch_for(spec: &LaunchSpec) -> Option<(String, Option<std::path::PathBuf>)> {
fn windows_launch_for(spec: &LaunchSpec) -> Option<WinRecipe> {
match spec.kind.as_str() {
"steam_appid" => {
if !valid_steam_appid(&spec.value) {
@@ -237,7 +315,9 @@ fn windows_launch_for(spec: &LaunchSpec) -> Option<(String, Option<std::path::Pa
Some(exe) => format!("\"{}\" \"{uri}\"", exe.display()),
None => format!("explorer.exe \"{uri}\""),
};
Some((cmdline, None))
// Either line is a forwarder: `Steam.exe <uri>` against a running client posts the URI
// and exits, and against a cold one it *becomes* the client. Neither is the game.
Some(WinRecipe::handoff(cmdline))
}
// A launcher entry (D4): open the Steam client's own UI. Same Steam.exe-then-explorer ladder
// as `steam_appid`, and the URI is one of exactly two host-owned literals — nothing from the
@@ -252,23 +332,22 @@ fn windows_launch_for(spec: &LaunchSpec) -> Option<(String, Option<std::path::Pa
Some(exe) => format!("\"{}\" \"{uri}\"", exe.display()),
None => format!("explorer.exe \"{uri}\""),
};
Some((cmdline, None))
Some(WinRecipe::handoff(cmdline))
}
// Epic: open the (host-built, validated) com.epicgames.launcher:// URI via explorer.exe — a
// concrete EXE that resolves the registered protocol handler as the user; the URI is a single
// argv element (no shell, no cmd /c). Same pattern as the steam explorer fallback.
"epic" => epic_launch_uri(&spec.value).map(|uri| (format!("explorer.exe \"{uri}\""), None)),
"epic" => epic_launch_uri(&spec.value)
.map(|uri| WinRecipe::handoff(format!("explorer.exe \"{uri}\""))),
// GOG: spawn the resolved game exe directly (host-derived from goggame-<id>.info), no Galaxy.
"gog" => gog_spawn(&spec.value),
// ...and the one store recipe that is NOT a hand-off: the resolved exe is the game itself.
"gog" => gog_spawn(&spec.value).map(|(cmdline, workdir)| WinRecipe::game(cmdline, workdir)),
// Xbox/Game Pass: activate the UWP/GDK package by its AUMID (<PFN>!<AppId>) via explorer's
// shell:AppsFolder — which runs in the interactive user session (UWP activation fails as
// SYSTEM/session-0; spawn_in_active_session uses the user token). Guard the charset (the value
// is host-derived from MicrosoftGame.config + AppRepository, but belt-and-suspenders).
"aumid" => valid_aumid(&spec.value).then(|| {
(
format!("explorer.exe \"shell:AppsFolder\\{}\"", spec.value),
None,
)
WinRecipe::handoff(format!("explorer.exe \"shell:AppsFolder\\{}\"", spec.value))
}),
// Xbox / Game Pass from a library PLUGIN: `<Identity>!<AppId>`, both read straight out of
// `MicrosoftGame.config`. The host completes it into the AUMID.
@@ -287,10 +366,9 @@ fn windows_launch_for(spec: &LaunchSpec) -> Option<(String, Option<std::path::Pa
return None;
}
let pfn = xbox_pfn(identity)?;
Some((
format!("explorer.exe \"shell:AppsFolder\\{pfn}!{app_id}\""),
None,
))
Some(WinRecipe::handoff(format!(
"explorer.exe \"shell:AppsFolder\\{pfn}!{app_id}\""
)))
}
// Playnite: open the game through Playnite's own URI handler, which is what actually knows
// how to start it (Playnite maps the id to whichever store owns the title). explorer.exe
@@ -301,10 +379,10 @@ fn windows_launch_for(spec: &LaunchSpec) -> Option<(String, Option<std::path::Pa
// line). The 2026-08-05 review made `command` operator-only, which refuses a plugin's whole
// reconcile — so without a typed kind the Playnite plugin cannot publish anything at all.
"playnite" => valid_playnite_id(&spec.value).then(|| {
(
format!("explorer.exe \"playnite://playnite/start/{}\"", spec.value),
None,
)
WinRecipe::handoff(format!(
"explorer.exe \"playnite://playnite/start/{}\"",
spec.value
))
}),
// A launcher entry (D4) on Windows: today that is Playnite's Fullscreen app, spawned
// directly (its `playnite://` handler opens the DESKTOP app, so no URI can do this). The
@@ -313,16 +391,18 @@ fn windows_launch_for(spec: &LaunchSpec) -> Option<(String, Option<std::path::Pa
"launcher_ui" => match spec.value.as_str() {
"playnite" => playnite_fullscreen_exe().map(|exe| {
let dir = exe.parent().map(std::path::Path::to_path_buf);
(format!("\"{}\"", exe.display()), dir)
WinRecipe::game(format!("\"{}\"", exe.display()), dir)
}),
_ => None,
},
// Operator-typed custom command (host-owned, never client-set): run it through the shell in the
// interactive session. `cmd.exe /c` is acceptable here precisely because the value is operator
// input — the same trust as the operator typing it — not a client-influenced string.
// `cmd.exe /c <v>` blocks until the operator's command returns, so its pid tracks that
// command's life — the Windows twin of the Linux child the host holds.
"command" => {
let v = spec.value.trim();
(!v.is_empty()).then(|| (format!("cmd.exe /c {v}"), None))
(!v.is_empty()).then(|| WinRecipe::game(format!("cmd.exe /c {v}"), None))
}
_ => None,
}
@@ -744,7 +824,7 @@ pub(crate) fn gog_spawn(value: &str) -> Option<(String, Option<PathBuf>)> {
/// interactive Windows user session, AFTER capture is up (the host is SYSTEM). The Linux paths go
/// through the compositor-aware [`launch_session_command`] instead.
#[cfg(windows)]
pub fn launch_gamestream_command(cmd: &str) -> Result<u32> {
pub fn launch_gamestream_command(cmd: &str) -> Result<WindowsLaunch> {
let cmd = cmd.trim();
anyhow::ensure!(!cmd.is_empty(), "empty command");
// cmd.exe /c is fine here: the value is the host operator's own apps.json command, not a
@@ -752,9 +832,13 @@ pub fn launch_gamestream_command(cmd: &str) -> Result<u32> {
let pid = crate::interactive::spawn_in_active_session(&format!("cmd.exe /c {cmd}"), None)
.context("spawn gamestream command in the interactive session")?;
tracing::info!(command = %cmd, pid, "gamestream: launched app in the interactive session");
// The `cmd.exe` shim's own pid: it exits the moment it has started the real program, which the
// lease reads as a hand-off (inside its shim window) rather than as the game exiting.
Ok(pid)
// `cmd.exe /c` waits for the operator's command, so this pid is the command's own life. Should
// the command itself be a forwarder that returns at once, the lease's shim window is what reads
// that as a hand-off rather than as the game exiting.
Ok(WindowsLaunch {
pid,
owns_game: true,
})
}
/// Launch a library title chosen from the **GameStream `/applist`** (the store-qualified id is carried
@@ -763,7 +847,7 @@ pub fn launch_gamestream_command(cmd: &str) -> Result<u32> {
/// only ever pick an existing title — never inject a command. Linux resolves the id via
/// [`resolve_launch`] and goes through [`launch_session_command`] instead.
#[cfg(windows)]
pub fn launch_gamestream_library(id: &str) -> Result<u32> {
pub fn launch_gamestream_library(id: &str) -> Result<WindowsLaunch> {
launch_title(id)
}
@@ -1023,11 +1107,13 @@ mod tests {
let Some(exe) = playnite_fullscreen_exe() else {
return;
};
let (cmd, dir) = ui("playnite").expect("resolvable when the exe was found");
let r = ui("playnite").expect("resolvable when the exe was found");
let cmd = &r.cmdline;
assert!(cmd.contains("Playnite.FullscreenApp.exe"), "{cmd}");
assert!(!cmd.contains("DesktopApp"), "{cmd}");
assert!(!cmd.contains("playnite://"), "{cmd}");
assert_eq!(dir.as_deref(), exe.parent());
assert_eq!(r.workdir.as_deref(), exe.parent());
assert!(r.owns_game, "the exe is spawned directly, not forwarded");
}
#[cfg(target_os = "linux")]
@@ -1078,11 +1164,20 @@ mod tests {
value: v.into(),
})
};
let (bp, wd) = ui("bigpicture").expect("bigpicture recipe");
assert!(bp.contains("steam://open/bigpicture"), "line was {bp:?}");
assert!(wd.is_none());
let (desk, _) = ui("desktop").expect("desktop recipe");
assert!(desk.contains("steam://open/main"), "line was {desk:?}");
let bp = ui("bigpicture").expect("bigpicture recipe");
assert!(
bp.cmdline.contains("steam://open/bigpicture"),
"line was {:?}",
bp.cmdline
);
assert!(bp.workdir.is_none());
assert!(!bp.owns_game, "a steam:// URI is forwarded to the client");
let desk = ui("desktop").expect("desktop recipe");
assert!(
desk.cmdline.contains("steam://open/main"),
"line was {:?}",
desk.cmdline
);
assert!(ui("nonsense").is_none());
assert!(ui("").is_none());
}
@@ -1162,9 +1257,10 @@ mod tests {
kind: "steam_appid".into(),
value: "570".into(),
};
let (line, wd) = windows_launch_for(&steam).expect("steam recipe");
let steam_r = windows_launch_for(&steam).expect("steam recipe");
let line = &steam_r.cmdline;
assert!(line.contains("steam://rungameid/570"), "line was {line:?}");
assert!(wd.is_none());
assert!(steam_r.workdir.is_none());
// A non-numeric "appid" (a client trying to inject) is rejected, never interpolated.
let evil = LaunchSpec {
kind: "steam_appid".into(),
@@ -1176,9 +1272,11 @@ mod tests {
kind: "command".into(),
value: "notepad.exe".into(),
};
assert_eq!(
windows_launch_for(&cmd).unwrap().0,
"cmd.exe /c notepad.exe"
let cmd_r = windows_launch_for(&cmd).unwrap();
assert_eq!(cmd_r.cmdline, "cmd.exe /c notepad.exe");
assert!(
cmd_r.owns_game,
"`cmd /c` blocks on the operator's command, so its pid is that command's"
);
// Xbox AUMID → explorer shell:AppsFolder activation; a value without '!' is rejected.
let aumid = LaunchSpec {
@@ -1186,7 +1284,7 @@ mod tests {
value: "Microsoft.X_8wekyb3d8bbwe!Game".into(),
};
assert_eq!(
windows_launch_for(&aumid).unwrap().0,
windows_launch_for(&aumid).unwrap().cmdline,
"explorer.exe \"shell:AppsFolder\\Microsoft.X_8wekyb3d8bbwe!Game\""
);
assert!(windows_launch_for(&LaunchSpec {
+34 -9
View File
@@ -190,10 +190,25 @@ fn main() {
);
}
// Tee every panic through `tracing` BEFORE the default hook: a panicking thread otherwise
// Tee every panic into the log ring BEFORE the default hook: a panicking thread otherwise
// prints only to stderr — absent from the web console's Logs tab (the ring) and gone entirely
// when stderr is detached — so a field report reads "host died, zero errors in the logs".
// The default hook still runs afterwards for the usual stderr message/abort behavior.
//
// 🛑 **The tee goes straight to the ring, NOT through `tracing`.** A panic hook that emits a
// tracing event is a trap: `tracing_subscriber`'s registry is `sharded-slab`-backed and reads a
// `thread_local!` with `LocalKey::with`, so emitting from a thread whose TLS is being torn down
// panics — *inside the hook*. Rust treats a panic raised while the hook is running as
// `MustAbort::PanicInHook` and then deliberately does not format the message ("perhaps that is
// causing the panic"), so the log gets `panicked at <loc>:` followed by a BLANK line and
// `thread panicked while processing panic. aborting.` — the cause erased at exactly the moment
// it mattered. That is precisely what hid the 2026-08-18 teardown abort on .173 (four aborts,
// zero diagnosis) until it was reproduced standalone.
//
// Everything below is TLS-free and cannot panic: `LogRing` is a `OnceLock` + `Mutex`, and
// `thread::current().name()` / `Backtrace::force_capture()` were both verified safe during TLS
// destruction. This does not make a TLS-destructor panic survivable — Rust aborts on those
// regardless — but it does mean the message that names the cause always lands.
let default_panic = std::panic::take_hook();
std::panic::set_hook(Box::new(move |info| {
// Manual payload downcast (`payload_as_str` needs Rust 1.91; workspace MSRV is 1.82).
@@ -203,14 +218,24 @@ fn main() {
.copied()
.or_else(|| info.payload().downcast_ref::<String>().map(String::as_str))
.unwrap_or("<non-string panic payload>");
tracing::error!(
thread = std::thread::current().name().unwrap_or("<unnamed>"),
location = %info
.location()
.map(ToString::to_string)
.unwrap_or_else(|| "<unknown>".into()),
backtrace = %std::backtrace::Backtrace::force_capture(),
"PANIC: {payload}"
let location = info
.location()
.map(ToString::to_string)
.unwrap_or_else(|| "<unknown>".into());
let thread = std::thread::current()
.name()
.unwrap_or("<unnamed>")
.to_string();
let backtrace = std::backtrace::Backtrace::force_capture();
let ts_ms = std::time::SystemTime::now()
.duration_since(std::time::UNIX_EPOCH)
.map(|d| d.as_millis() as u64)
.unwrap_or(0);
log_capture::ring().push_remote(
"ERROR",
"punktfunk_host::panic",
&format!("PANIC: {payload} (thread={thread}, at {location})\n{backtrace}"),
ts_ms,
);
default_panic(info);
}));
+5 -4
View File
@@ -1913,8 +1913,9 @@ pub(super) fn virtual_stream(ctx: SessionContext, prepared: Option<PreparedDispl
let mut spawned_now = false;
// The pid Windows hands back for the process it started, kept so the lease has something of its
// own to watch and to signal even when the title carries no detect signals at all (see
// `gamelease::LeaseRequest::spawned`). `None` on every other platform and whenever nothing was
// spawned.
// `gamelease::LeaseRequest::spawned`). `None` on every other platform, whenever nothing was
// spawned, and — crucially — whenever what was spawned is a protocol hand-off rather than the
// game (`library::WinRecipe::owns_game`): a forwarder's pid is not a lifetime signal.
#[allow(unused_mut)]
let mut spawned_pid: Option<u32> = None;
// Close whatever this client had running before, if the operator asked for that
@@ -1941,8 +1942,8 @@ pub(super) fn virtual_stream(ctx: SessionContext, prepared: Option<PreparedDispl
);
} else {
match crate::library::launch_title(id) {
Ok(pid) => {
spawned_pid = Some(pid);
Ok(launched) => {
spawned_pid = launched.tracked_pid();
spawned_now = true;
}
Err(e) => {
+68
View File
@@ -134,6 +134,34 @@ async fn handle_iso_submit(
}
}
/// Force a non-isochronous reply into the shape `vhci_hcd` will accept (punktfunk addition).
///
/// **A reply may be shorter than the host asked for, never longer.** A short IN transfer is
/// ordinary USB — the device had less to say — but an over-long one is a babble condition and the
/// kernel does not forgive it: `usbip_recv_xbuff()` compares the reply's `actual_length` against
/// the URB's `transfer_buffer_length` and, on `>`, treats it as a malicious packet, logs
/// `recv xbuf, 0` (that `0` is the untouched initialiser, not a byte count) and raises
/// `VDEV_EVENT_ERROR_TCP` — which tears down the **whole connection**, so the device disappears
/// rather than one URB failing. Real hardware truncates here, so we do too: a handler bug then
/// costs one wrong reply instead of the pad.
///
/// An OUT transfer returns nothing at all. `usbip_recv_xbuff()` returns early for `usb_pipeout`,
/// so any payload appended to an OUT reply is bytes the kernel never reads — and every byte after
/// it in the stream is then misframed.
///
/// Field-diagnosed 2026-08-17: a 42-byte DualSense calibration report answering a 41-byte request
/// killed `hid-playstation`'s probe with `-EPROTO` and took the controller with it. Every backend
/// that is not USB (uhid, Windows `hidclass`) truncates silently, which is why the same constant
/// had looked correct for months.
pub(crate) fn clamp_reply(mut resp: Vec<u8>, requested: u32, out: bool) -> Vec<u8> {
if out {
resp.clear();
} else if resp.len() > requested as usize {
resp.truncate(requested as usize);
}
resp
}
pub async fn handler<T: AsyncReadExt + AsyncWriteExt + Unpin>(
mut socket: &mut T,
server: Arc<UsbIpServer>,
@@ -264,6 +292,15 @@ pub async fn handler<T: AsyncReadExt + AsyncWriteExt + Unpin>(
match resp {
Ok(resp) => {
let over = resp.len() > transfer_buffer_length as usize;
let resp = clamp_reply(resp, transfer_buffer_length, out);
if over {
warn!(
"handler returned more than the {transfer_buffer_length}-byte \
request on ep {real_ep:02x?} truncated; an over-long reply \
tears down the whole usbip connection"
);
}
if out {
trace!("<-Wrote {}", data.len());
} else {
@@ -323,3 +360,34 @@ pub async fn server(addr: SocketAddr, server: Arc<UsbIpServer>) {
}
// (Host-mode constructors and in-crate tests removed in the vendored copy — see NOTICE.)
/// Covers only the punktfunk reply-shaping addition; see [`clamp_reply`] for why the kernel treats
/// an over-long reply as fatal to the connection rather than to the URB.
#[cfg(test)]
mod clamp_tests {
use super::clamp_reply;
/// The exact 2026-08-17 field failure: a 42-byte calibration blob against `wLength` 41.
/// Un-truncated this is `actual_length = 42 > transfer_buffer_length = 41`, which makes
/// `usbip_recv_xbuff()` raise `VDEV_EVENT_ERROR_TCP` and disconnect the pad entirely.
#[test]
fn an_over_long_in_reply_is_truncated_to_the_request() {
let reply = vec![0xAB; 42];
assert_eq!(clamp_reply(reply, 41, false).len(), 41);
}
/// A device returning less than asked is a short packet — ordinary USB, and the host is told
/// the true count. Padding it out would fabricate data the device never sent.
#[test]
fn a_short_in_reply_is_left_alone() {
assert_eq!(clamp_reply(vec![1, 2, 3], 64, false), vec![1, 2, 3]);
}
/// An OUT reply carries no payload back whatever the handler returns: the kernel does not read
/// one, so those bytes would stay in the stream and misframe every PDU after them.
#[test]
fn an_out_reply_never_carries_a_payload() {
assert!(clamp_reply(vec![1, 2, 3, 4], 4, true).is_empty());
assert!(clamp_reply(vec![], 0, true).is_empty());
}
}
+164
View File
@@ -0,0 +1,164 @@
#!/usr/bin/env python3
"""Walk a `PUNKTFUNK_USBIP_TRACE` capture and find where the two sides stop agreeing.
A USB/IP connection is a framed byte stream whose frame lengths are declared inside the frames, so
one reply that writes a different number of bytes than its header promises shifts everything after
it. The peer then fails at whatever frame happens to land badly, which is never the frame that was
wrong. This walks both directions as PDUs and reports the first frame that does not decode, plus a
per-URB ledger of declared vs. written bytes.
Usage: usbip-trace-analyse.py /tmp/pad.virtual-DualSense-0
(reads <prefix>.rx, <prefix>.tx, <prefix>.idx)
"""
import struct
import sys
CMD_SUBMIT, CMD_UNLINK, RET_SUBMIT, RET_UNLINK = 1, 2, 3, 4
NAMES = {1: "CMD_SUBMIT", 2: "CMD_UNLINK", 3: "RET_SUBMIT", 4: "RET_UNLINK"}
def be32(b, o):
return struct.unpack_from(">I", b, o)[0]
USBIP_VERSION = 0x0111
def skip_handshake(buf, side):
"""Return the offset where URB framing begins.
A capture starts at `accept()`, so the first bytes are the op-level import handshake, which is
framed differently (a 2-byte version, not a 4-byte command). Walking it as a PDU decodes as
garbage and reports a desync at offset 0 a false positive that would send the reader hunting
for a framing bug in the one place there is none.
"""
off = 0
while off + 4 <= len(buf) and struct.unpack_from(">H", buf, off)[0] == USBIP_VERSION:
code = struct.unpack_from(">H", buf, off + 2)[0]
if side == "rx":
# OP_REQ_IMPORT: status(4) + busid(32); OP_REQ_DEVLIST: status(4).
off += 40 if code == 0x8003 else 8
else:
# OP_REP_IMPORT: status(4) + a 312-byte device record when status == 0.
status = be32(buf, off + 4)
off += 8 + (312 if code == 0x0003 and status == 0 else 0)
return off
def walk(buf, side):
"""Yield decoded PDUs. `side` is 'rx' (kernel -> us) or 'tx' (us -> kernel)."""
off = skip_handshake(buf, side)
while off < len(buf):
if len(buf) - off < 48:
yield {"off": off, "error": f"truncated header: {len(buf) - off} bytes left"}
return
cmd = be32(buf, off)
pdu = {
"off": off,
"cmd": cmd,
"name": NAMES.get(cmd, f"?{cmd:#x}"),
"seq": be32(buf, off + 4),
"dir": be32(buf, off + 12), # 0 = OUT, 1 = IN
"ep": be32(buf, off + 16),
}
if cmd not in NAMES:
pdu["error"] = "unknown command — the stream is already desynced at or before here"
yield pdu
return
body = off + 48
if cmd == CMD_SUBMIT:
pdu["xfer_len"] = be32(buf, off + 24)
npkts = be32(buf, off + 32)
pdu["npkts"] = npkts
# OUT carries its payload; IN does not.
payload = pdu["xfer_len"] if pdu["dir"] == 0 else 0
table = 16 * npkts if npkts not in (0, 0xFFFFFFFF) else 0
pdu["payload"], pdu["table"] = payload, table
pdu["setup"] = buf[off + 40 : off + 48].hex()
off = body + payload + table
elif cmd == RET_SUBMIT:
pdu["status"] = be32(buf, off + 20)
pdu["actual"] = be32(buf, off + 24)
npkts = be32(buf, off + 32)
pdu["npkts"] = npkts
# This is the crux: the kernel reads a payload back only for an IN transfer
# (`usbip_recv_xbuff` returns early for `usb_pipeout`). Bytes written after an OUT
# reply's header are never consumed and desync the stream. That holds for isochronous
# OUT too, where `actual_length` counts bytes *accepted* and no buffer follows — so it
# must not be read as a payload length here.
payload = pdu["actual"] if pdu["dir"] == 1 else 0
table = 16 * npkts if npkts not in (0, 0xFFFFFFFF) else 0
pdu["payload"], pdu["table"] = payload, table
off = body + payload + table
else: # UNLINK either way: 48 bytes flat
pdu["payload"], pdu["table"] = 0, 0
off = body
pdu["end"] = off
yield pdu
def main(prefix):
rx = open(prefix + ".rx", "rb").read()
tx = open(prefix + ".tx", "rb").read()
print(f"rx (kernel -> us): {len(rx)} bytes")
print(f"tx (us -> kernel): {len(tx)} bytes\n")
submits = {}
for p in walk(rx, "rx"):
if "error" in p:
print(f"!! RX desync at offset {p['off']}: {p['error']}")
break
if p["cmd"] == CMD_SUBMIT:
submits[p["seq"]] = p
print(f"parsed {len(submits)} CMD_SUBMITs from the kernel")
bad, replies = [], 0
for p in walk(tx, "tx"):
if "error" in p:
bad.append((p, f"TX desync at offset {p['off']}: {p['error']}"))
break
replies += 1
if p["cmd"] != RET_SUBMIT:
continue
req = submits.get(p["seq"])
# The two rules vhci_hcd kills the whole connection over, checked against its own logic.
if p["dir"] == 0 and not p["npkts"] and p["actual"]:
bad.append((p, f"OUT reply declares actual_length={p['actual']}, but the kernel reads "
f"NO payload back on OUT — those bytes desync every frame after it"))
elif req and p["dir"] == 1 and p["actual"] > req["xfer_len"]:
bad.append((p, f"actual_length {p['actual']} > the {req['xfer_len']} requested "
f"(setup {req['setup']}) — usbip_recv_xbuff() calls this a malicious "
f"packet: 'recv xbuf, 0' then VDEV_EVENT_ERROR_TCP, which disconnects "
f"the device"))
elif req and req["dir"] != p["dir"]:
bad.append((p, "direction does not match its CMD_SUBMIT"))
print(f"parsed {replies} replies from us\n")
if bad:
print(f"{len(bad)} BAD frame(s). The first is the bug; the rest is fallout.\n")
for p, why in bad[:10]:
d = "IN" if p["dir"] == 1 else "OUT"
print(f" offset {p['off']} seq {p['seq']} {d} ep{p['ep']}: {why}")
else:
print("Every reply's declared length matches what the kernel will consume.")
print("If the connection still died, framing is not the cause — look below for a")
print("CMD_SUBMIT that never got a reply (a missing reply, not a mis-sized one).")
# An unanswered request is the other way this dies, and it looks identical from dmesg.
answered = {p["seq"] for p in walk(tx, "tx") if p.get("cmd") in (RET_SUBMIT, RET_UNLINK)}
missing = [s for s in submits if s not in answered]
if missing:
print(f"\n{len(missing)} CMD_SUBMIT(s) never answered: {sorted(missing)[:20]}")
for s in sorted(missing)[:5]:
p = submits[s]
d = "IN" if p["dir"] == 1 else "OUT"
print(f" seq {s}: {d} ep{p['ep']} len={p['xfer_len']} setup={p['setup']}")
if __name__ == "__main__":
if len(sys.argv) != 2:
sys.exit(__doc__)
main(sys.argv[1])