fix(windows): opt-in pad-driver file logs + size-capped service log rotation
Two disk-write fixes: - pf-xusb/pf-dualsense no longer write C:\Users\Public\pf*-driver.log unconditionally — the file log is now opt-in (debug builds, or the PFXUSB_DEBUG_LOG / PFDS_DEBUG_LOG system env var), mirroring the audit-§4.4 fix pf-vdisplay already got: a release driver never writes the world-writable Public file (info-leak/DoS surface), and the per-report OUTPUT/SET_STATE hex dumps stop being a sustained per-rumble disk-write path during gameplay. OutputDebugStringA stays unconditional; the host's driver-silence WARN and the gamepad-driver-health failure-mode table now say the log is opt-in. - service.log/host.log get one-generation rotation: at each (re)open a file over 10 MB is renamed to .old, so a crash-restart loop or a RUST_LOG=debug left in host.env can't grow the append-forever logs without bound. Rotation runs only before an open (never under a live appender — host.log's handle lacks FILE_SHARE_DELETE, so a racing rename harmlessly fails). Windows CI compile/clippy pending (drivers workspace + host are not Linux-cross-checkable); rides along with the next pad-driver redeploy. Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
@@ -534,7 +534,9 @@ impl DriverAttach {
|
|||||||
driver_log = self.driver_log,
|
driver_log = self.driver_log,
|
||||||
"gamepad driver has not attached to the shared section — the virtual pad exists but no \
|
"gamepad driver has not attached to the shared section — the virtual pad exists but no \
|
||||||
driver is serving it (games will not see it); an old (pre-sealed-channel) driver also \
|
driver is serving it (games will not see it); an old (pre-sealed-channel) driver also \
|
||||||
reads as not-attached: update with punktfunk-host.exe driver install --gamepad"
|
reads as not-attached: update with punktfunk-host.exe driver install --gamepad \
|
||||||
|
(driver_log is only written by debug driver builds, or with the PFXUSB_DEBUG_LOG / \
|
||||||
|
PFDS_DEBUG_LOG system env var set + the device restarted)"
|
||||||
);
|
);
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -130,6 +130,23 @@ fn host_log_path() -> PathBuf {
|
|||||||
dir.join("host.log")
|
dir.join("host.log")
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// One-generation size cap for the append-forever logs: at each (re)open, a file over this size is
|
||||||
|
/// renamed to `<name>.old` (replacing the previous generation) — so a crash-restart loop or a
|
||||||
|
/// `RUST_LOG=debug` left in host.env can't grow them without bound.
|
||||||
|
const LOG_ROTATE_BYTES: u64 = 10 * 1024 * 1024;
|
||||||
|
|
||||||
|
/// Rotate `path` to `path.old` when it has outgrown [`LOG_ROTATE_BYTES`]. Only called right before
|
||||||
|
/// an open (service start for service.log, each host (re)launch for host.log) — never while a live
|
||||||
|
/// handle appends: renaming under an appender would silently redirect its writes into the `.old`
|
||||||
|
/// file. Best-effort; a failed rename just means one more un-rotated run.
|
||||||
|
fn rotate_if_large(path: &std::path::Path) {
|
||||||
|
if std::fs::metadata(path).is_ok_and(|m| m.len() >= LOG_ROTATE_BYTES) {
|
||||||
|
let mut old = path.as_os_str().to_owned();
|
||||||
|
old.push(".old");
|
||||||
|
let _ = std::fs::rename(path, std::path::Path::new(&old));
|
||||||
|
}
|
||||||
|
}
|
||||||
|
|
||||||
/// Initialise tracing to the service log file (the SCM gives the service no console/stderr). Falls
|
/// Initialise tracing to the service log file (the SCM gives the service no console/stderr). Falls
|
||||||
/// back to stderr if the file can't be opened. Called from `main()` only for `service run`.
|
/// back to stderr if the file can't be opened. Called from `main()` only for `service run`.
|
||||||
/// Also tees into the in-memory log ring (`log_capture`), like the stderr path in `main()` — the
|
/// Also tees into the in-memory log ring (`log_capture`), like the stderr path in `main()` — the
|
||||||
@@ -140,10 +157,12 @@ pub fn init_file_logging(filter: tracing_subscriber::EnvFilter) {
|
|||||||
use tracing_subscriber::Layer;
|
use tracing_subscriber::Layer;
|
||||||
let ring =
|
let ring =
|
||||||
crate::log_capture::RingLayer.with_filter(tracing_subscriber::filter::LevelFilter::DEBUG);
|
crate::log_capture::RingLayer.with_filter(tracing_subscriber::filter::LevelFilter::DEBUG);
|
||||||
|
let log_path = service_log_path();
|
||||||
|
rotate_if_large(&log_path);
|
||||||
match std::fs::OpenOptions::new()
|
match std::fs::OpenOptions::new()
|
||||||
.create(true)
|
.create(true)
|
||||||
.append(true)
|
.append(true)
|
||||||
.open(service_log_path())
|
.open(log_path)
|
||||||
{
|
{
|
||||||
Ok(file) => {
|
Ok(file) => {
|
||||||
tracing_subscriber::registry()
|
tracing_subscriber::registry()
|
||||||
@@ -549,8 +568,12 @@ unsafe fn spawn_host(
|
|||||||
let _ = DestroyEnvironmentBlock(env_block);
|
let _ = DestroyEnvironmentBlock(env_block);
|
||||||
}
|
}
|
||||||
|
|
||||||
// 3) Redirect the host's stdout+stderr to host.log (inheritable handle).
|
// 3) Redirect the host's stdout+stderr to host.log (inheritable handle). The previous child has
|
||||||
let log = open_log_handle(&host_log_path())?;
|
// exited by the time the supervise loop relaunches, so its handle can't be live here — safe
|
||||||
|
// to rotate. (A leaked orphan's handle lacks FILE_SHARE_DELETE, so the rename just fails.)
|
||||||
|
let host_log = host_log_path();
|
||||||
|
rotate_if_large(&host_log);
|
||||||
|
let log = open_log_handle(&host_log)?;
|
||||||
|
|
||||||
let mut si = STARTUPINFOW {
|
let mut si = STARTUPINFOW {
|
||||||
cb: std::mem::size_of::<STARTUPINFOW>() as u32,
|
cb: std::mem::size_of::<STARTUPINFOW>() as u32,
|
||||||
|
|||||||
@@ -36,7 +36,7 @@ existing `service()` poll. State machine, each transition logs exactly once:
|
|||||||
|---|---|---|---|---|
|
|---|---|---|---|---|
|
||||||
| 1 | Driver package not installed | fresh box, installer's `driver install --gamepad` skipped/failed, package pruned | attach timeout → `pnputil /enum-drivers` misses `pf_xusb.inf`/`pf_dualsense.inf` | WARN `driver package NOT in the driver store — run: punktfunk-host.exe driver install --gamepad` |
|
| 1 | Driver package not installed | fresh box, installer's `driver install --gamepad` skipped/failed, package pruned | attach timeout → `pnputil /enum-drivers` misses `pf_xusb.inf`/`pf_dualsense.inf` | WARN `driver package NOT in the driver store — run: punktfunk-host.exe driver install --gamepad` |
|
||||||
| 2 | Package present but binding failed | certificate not in Root/TrustedPublisher, Memory Integrity (HVCI) rejects it, stale DriverVer kept the old binary | attach timeout → devnode problem code (28 = drivers not installed, 52 = signature rejected, 31/39 = load failure) | WARN with the CM problem code + hint |
|
| 2 | Package present but binding failed | certificate not in Root/TrustedPublisher, Memory Integrity (HVCI) rejects it, stale DriverVer kept the old binary | attach timeout → devnode problem code (28 = drivers not installed, 52 = signature rejected, 31/39 = load failure) | WARN with the CM problem code + hint |
|
||||||
| 3 | Driver bound but crashed / never started | WUDFHost crash, `WdfDeviceCreate`/queue failure inside the driver | attach timeout → devnode status shows `driver_loaded`/`started` flags; the driver's own log (`C:\Users\Public\pf*-driver.log`) has the failing WDF call | WARN referencing both |
|
| 3 | Driver bound but crashed / never started | WUDFHost crash, `WdfDeviceCreate`/queue failure inside the driver | attach timeout → devnode status shows `driver_loaded`/`started` flags; the driver's own log (`C:\Users\Public\pf*-driver.log`) has the failing WDF call — opt-in like pf-vdisplay's (debug builds, or `PFXUSB_DEBUG_LOG`/`PFDS_DEBUG_LOG` set system-wide + device restart) | WARN referencing both |
|
||||||
| 4 | `SwDeviceCreate` fails outright | not Administrator/SYSTEM, PnP wedged, `_` in enumerator (E_INVALIDARG) | existing error path (unchanged) | WARN `SwDeviceCreate failed; … devnode unavailable`, pad continues on the out-of-band fallback |
|
| 4 | `SwDeviceCreate` fails outright | not Administrator/SYSTEM, PnP wedged, `_` in enumerator (E_INVALIDARG) | existing error path (unchanged) | WARN `SwDeviceCreate failed; … devnode unavailable`, pad continues on the out-of-band fallback |
|
||||||
| 5 | `SwDeviceCreate` callback never fires | PnP service hung | **was silently mis-read as success** (zero-init `HRESULT(0)` + ignored `WaitForSingleObject` return). Fixed: `result` inits to `E_FAIL`, the wait result is checked | ERROR `enumeration callback never fired (10s) — PnP may be wedged` |
|
| 5 | `SwDeviceCreate` callback never fires | PnP service hung | **was silently mis-read as success** (zero-init `HRESULT(0)` + ignored `WaitForSingleObject` return). Fixed: `result` inits to `E_FAIL`, the wait result is checked | ERROR `enumeration callback never fired (10s) — PnP may be wedged` |
|
||||||
| 6 | Driver attached, then WUDFHost died mid-session | crash, killed | `driver_heartbeat` freezes (DS/DS4: timer-driven, so a freeze is conclusive; XUSB: only advances while a game polls, so absence is *not* an error) | field exists for a future stall check; not auto-warned yet (XUSB semantics make a generic rule false-positive-prone) |
|
| 6 | Driver attached, then WUDFHost died mid-session | crash, killed | `driver_heartbeat` freezes (DS/DS4: timer-driven, so a freeze is conclusive; XUSB: only advances while a game polls, so absence is *not* an error) | field exists for a future stall check; not auto-warned yet (XUSB semantics make a generic rule false-positive-prone) |
|
||||||
|
|||||||
@@ -129,7 +129,7 @@ notes for context.
|
|||||||
| Setting | Values | Meaning |
|
| Setting | Values | Meaning |
|
||||||
|---|---|---|
|
|---|---|---|
|
||||||
| `PUNKTFUNK_PERF` | `1` | Log per-stage timing (capture, encode, send) — handy when tuning latency. |
|
| `PUNKTFUNK_PERF` | `1` | Log per-stage timing (capture, encode, send) — handy when tuning latency. |
|
||||||
| `RUST_LOG` | `info` · `debug` · `trace` | Log verbosity. On Windows, logs land in `%ProgramData%\punktfunk\logs\`. |
|
| `RUST_LOG` | `info` · `debug` · `trace` | Log verbosity. On Windows, logs land in `%ProgramData%\punktfunk\logs\` (size-capped: a file over 10 MB is rotated to `.old` at the next service/host start, one generation kept). |
|
||||||
| `PUNKTFUNK_FFMPEG_DEBUG` | set | Verbose libavcodec/FFmpeg logging from the encoder. |
|
| `PUNKTFUNK_FFMPEG_DEBUG` | set | Verbose libavcodec/FFmpeg logging from the encoder. |
|
||||||
| `PUNKTFUNK_VIDEO_DROP` | `N` (percent) | Deliberately drop N% of video packets to exercise FEC recovery. **Testing only.** |
|
| `PUNKTFUNK_VIDEO_DROP` | `N` (percent) | Deliberately drop N% of video packets to exercise FEC recovery. **Testing only.** |
|
||||||
|
|
||||||
|
|||||||
@@ -269,18 +269,45 @@ fn channel_cfg() -> ChannelConfig {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Whether the world-writable bring-up file log is enabled (resolved once). OPT-IN — debug builds,
|
||||||
|
/// or the `PFDS_DEBUG_LOG` (system-wide) env var — the same treatment pf-vdisplay got in audit
|
||||||
|
/// §4.4: a RELEASE driver never writes the Public file (info-leak/DoS surface), and the per-report
|
||||||
|
/// OUTPUT hex dumps stop being a sustained disk-write path during gameplay. DebugView can't see the
|
||||||
|
/// UMDF host across session 0, so the file stays the bring-up diagnostic when enabled.
|
||||||
|
fn file_log_enabled() -> bool {
|
||||||
|
use std::sync::OnceLock;
|
||||||
|
static ON: OnceLock<bool> = OnceLock::new();
|
||||||
|
*ON.get_or_init(|| cfg!(debug_assertions) || std::env::var_os("PFDS_DEBUG_LOG").is_some())
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Process-lifetime append handle to the bring-up log, opened ONCE and shared via a `Mutex`
|
||||||
|
/// (pf-vdisplay's pattern) — no per-line open/close.
|
||||||
|
fn file_appender() -> Option<&'static std::sync::Mutex<std::fs::File>> {
|
||||||
|
use std::sync::OnceLock;
|
||||||
|
static APPENDER: OnceLock<Option<std::sync::Mutex<std::fs::File>>> = OnceLock::new();
|
||||||
|
APPENDER
|
||||||
|
.get_or_init(|| {
|
||||||
|
if !file_log_enabled() {
|
||||||
|
return None;
|
||||||
|
}
|
||||||
|
std::fs::OpenOptions::new()
|
||||||
|
.create(true)
|
||||||
|
.append(true)
|
||||||
|
.open("C:\\Users\\Public\\pfds-driver.log")
|
||||||
|
.ok()
|
||||||
|
.map(std::sync::Mutex::new)
|
||||||
|
})
|
||||||
|
.as_ref()
|
||||||
|
}
|
||||||
|
|
||||||
fn log(s: &str) {
|
fn log(s: &str) {
|
||||||
if let Ok(c) = std::ffi::CString::new(s) {
|
if let Ok(c) = std::ffi::CString::new(s) {
|
||||||
// SAFETY: c is a valid null-terminated string for the duration of the call.
|
// SAFETY: c is a valid null-terminated string for the duration of the call.
|
||||||
unsafe { OutputDebugStringA(c.as_ptr().cast()) };
|
unsafe { OutputDebugStringA(c.as_ptr().cast()) };
|
||||||
}
|
}
|
||||||
// Also append to a world-writable file — DebugView can't capture the UMDF host's output
|
|
||||||
// across session 0, so this is how we read driver-start diagnostics.
|
|
||||||
use std::io::Write;
|
use std::io::Write;
|
||||||
if let Ok(mut f) = std::fs::OpenOptions::new()
|
if let Some(m) = file_appender()
|
||||||
.create(true)
|
&& let Ok(mut f) = m.lock()
|
||||||
.append(true)
|
|
||||||
.open("C:\\Users\\Public\\pfds-driver.log")
|
|
||||||
{
|
{
|
||||||
let _ = writeln!(f, "{s}");
|
let _ = writeln!(f, "{s}");
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -104,16 +104,45 @@ fn channel_cfg() -> ChannelConfig {
|
|||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
|
/// Whether the world-writable bring-up file log is enabled (resolved once). OPT-IN — debug builds,
|
||||||
|
/// or the `PFXUSB_DEBUG_LOG` (system-wide) env var — the same treatment pf-vdisplay got in audit
|
||||||
|
/// §4.4: a RELEASE driver never writes the Public file (info-leak/DoS surface), and the per-rumble
|
||||||
|
/// SET_STATE hex dumps stop being a sustained disk-write path during gameplay. DebugView can't see
|
||||||
|
/// the UMDF host across session 0, so the file stays the bring-up diagnostic when enabled.
|
||||||
|
fn file_log_enabled() -> bool {
|
||||||
|
use std::sync::OnceLock;
|
||||||
|
static ON: OnceLock<bool> = OnceLock::new();
|
||||||
|
*ON.get_or_init(|| cfg!(debug_assertions) || std::env::var_os("PFXUSB_DEBUG_LOG").is_some())
|
||||||
|
}
|
||||||
|
|
||||||
|
/// Process-lifetime append handle to the bring-up log, opened ONCE and shared via a `Mutex`
|
||||||
|
/// (pf-vdisplay's pattern) — no per-line open/close.
|
||||||
|
fn file_appender() -> Option<&'static std::sync::Mutex<std::fs::File>> {
|
||||||
|
use std::sync::OnceLock;
|
||||||
|
static APPENDER: OnceLock<Option<std::sync::Mutex<std::fs::File>>> = OnceLock::new();
|
||||||
|
APPENDER
|
||||||
|
.get_or_init(|| {
|
||||||
|
if !file_log_enabled() {
|
||||||
|
return None;
|
||||||
|
}
|
||||||
|
std::fs::OpenOptions::new()
|
||||||
|
.create(true)
|
||||||
|
.append(true)
|
||||||
|
.open("C:\\Users\\Public\\pfxusb-driver.log")
|
||||||
|
.ok()
|
||||||
|
.map(std::sync::Mutex::new)
|
||||||
|
})
|
||||||
|
.as_ref()
|
||||||
|
}
|
||||||
|
|
||||||
fn log(s: &str) {
|
fn log(s: &str) {
|
||||||
if let Ok(c) = std::ffi::CString::new(s) {
|
if let Ok(c) = std::ffi::CString::new(s) {
|
||||||
// SAFETY: `c` is a valid NUL-terminated string for the duration of the call.
|
// SAFETY: `c` is a valid NUL-terminated string for the duration of the call.
|
||||||
unsafe { OutputDebugStringA(c.as_ptr().cast()) };
|
unsafe { OutputDebugStringA(c.as_ptr().cast()) };
|
||||||
}
|
}
|
||||||
use std::io::Write;
|
use std::io::Write;
|
||||||
if let Ok(mut f) = std::fs::OpenOptions::new()
|
if let Some(m) = file_appender()
|
||||||
.create(true)
|
&& let Ok(mut f) = m.lock()
|
||||||
.append(true)
|
|
||||||
.open("C:\\Users\\Public\\pfxusb-driver.log")
|
|
||||||
{
|
{
|
||||||
let _ = writeln!(f, "{s}");
|
let _ = writeln!(f, "{s}");
|
||||||
}
|
}
|
||||||
|
|||||||
Reference in New Issue
Block a user