Conversation
Chasing a report of large PutFile transfers failing part way through --
with SNI appearing to freeze afterwards -- turned up several distinct
problems, all confirmed against real hardware.
Error paths abandoned a data phase the firmware had already committed to.
usbint_handler_cmd picks its next state before it knows whether the
command succeeded, so:
* LS of a missing directory still emits a block holding the 0xFF
terminator. Returning on the error code left it in the pipe, so the
next command read it as its response header and everything after was
out of step. Drain it before returning.
* PUT sets cmdDat=1 in usbint_recv_block before f_open is even
attempted, so a failed PUT parks the device in HANDLE_LOCK awaiting
the payload. Returning without sending it meant the next command's
bytes were consumed as file data, after which f_write on the failed
handle returns zero bytes written forever inside the USB interrupt
handler -- a wedge needing a physical power cycle. Report it as fatal
so autoCloseableDevice reconnects within the one command of slack the
firmware allows; usbint_check_connect() resets its state on the
disconnect.
* GET has the same shape but cannot be recovered from the host: the
firmware spins in usbint_handler_dat on a size taken from a FILINFO
that a failed f_stat never wrote. Report it as fatal with an
explanatory message so the failure is attributed here rather than to
whatever request came next.
Writes were unbounded. go.bug.st/serial sets WriteTotalTimeoutConstant to
0 on Windows, which Win32 defines as "wait forever", and its Port
interface exposes no SetWriteTimeout. A device that stopped draining its
USB endpoint therefore hung the caller indefinitely while it held d.lock,
blocking every other request for that device -- caught in a goroutine dump
sitting 29 minutes inside WriteFile. Writes now run on their own goroutine
under a timeout, and abandoning one closes the port so the orphan cannot
interleave with whatever the caller does next.
sendSerialProgress also assigned writeExact's error and carried on, so the
next iteration overwrote it and a chunk that failed to send was reported
as a successful transfer.
The timeouts are configurable: fxpakpro_read_timeout,
fxpakpro_write_timeout, and fxpakpro_honor_caller_deadline, the last
controlling whether a caller's deadline aborts I/O already in flight.
Also in here: openPort walked all 14 baud rates on errors that had nothing
to do with speed, taking ~8 minutes to fail against a wedged device; the
caller's context now reaches the write path through sendSerialProgress;
stale buffers are flushed on open so a leftover block cannot desync the
first command after a reconnect; and Init's hardcoded 2s budget now
follows the configured read timeout, since it bounds writes as well now
and too tight a value would close healthy devices.
None of this stops the device wedging. A PUT onto a card that runs out of
space mid-transfer spins the firmware in its interrupt handler with no
error code the host can observe; these changes turn that from a silent
indefinite freeze into a prompt error naming the byte offset it stopped at.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
Unit tests, which need no hardware:
* sendserial_test.go covers the swallowed write error and the write
timeout. The write-error case needs a transient failure to be
meaningful: a permanently broken port leaves err set on the final
loop iteration, so it gets returned by accident and the bug hides.
Against the unfixed code this returns a nil error with sent=7680 of
8192 -- one chunk silently dropped.
* driver_config_test.go covers the timeout settings, including that a
non-positive value is rejected rather than applied, which would
otherwise reintroduce the unbounded wait.
* openport_test.go asserts one baud rate is tried, not fourteen.
Hardware tests, which skip when no fxpakpro is attached:
* stress_test.go interleaves PUT/GET/LS/MKDIR/RM and memory reads in a
seeded random order at sizes deliberately off the 512 byte block
boundary. Every operation is logged so a failure can be replayed with
SNI_TEST_SEED, and on failure it probes whether the device was merely
slow, lost the command, or is wedged. Mixing VGET in matters: it uses
a 64 byte command block where the filesystem commands use 512, and the
firmware only re-evaluates cmd_size when recv_buffer_offset crosses 64
from below.
* errorpath_test.go issues a failing ls/get/put and checks whether the
stream is still aligned afterwards, one path per run since a failure
can wedge the device. putErrorRecovers covers the fix through
AutoCloseableDevice, the layer grpcimpl uses.
* diskfull_test.go fills the card to find the boundary, and reports
which of the two disk-full cases occurred: a clean rejection before
the data phase, or the unrecoverable mid-transfer stall.
* putfile_test.go adds large-transfer, write-size and overwrite cases.
The write-size sweep is what ruled out the original theory that the
host was outrunning the device: throughput is identical whether SNI
writes 512 bytes or 64 KiB per call, because the host is already
blocked on USB NAKs, so inter-chunk sleeps would change nothing.
* deadline_test.go, largexfer_test.go, bootpath_test.go and
cleanup_test.go cover the deadline policy, repeated large transfers,
menu versus in-game state, and clearing leftovers off the card.
device_test.go wires the SNI_FXPAKPRO_* environment variables into the
test binary. Test binaries never call config.Load(), so the settings were
silently inert under test and any config-dependent result would have been
meaningless.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
Audited every command for whether a device error code leaves the protocol
stream clean. What decides it is the firmware's own next-state choice,
which is made by opcode before it knows whether the command succeeded:
GET, VGET, LS -> HANDLE_DAT device is about to send a data phase
PUT, VPUT -> HANDLE_LOCK device is waiting for a payload
everything else -> IDLE nothing pending
So fatality should follow whether there is a pending data phase, not how
severe the error sounds. mkdir, rm, mv, boot, reset, menu_reset and info
all land in IDLE and stay non-fatal, which is right: error code 1 is the
device's generic "something went wrong" and for mkdir usually just means
the directory already exists. Nothing is pending, the stream stays
aligned, and tearing the connection down would be both wrong and risky
given how poorly the firmware handles reconnects.
get and put were the two that did not match. Both are only reachable from
tests today -- d.get appears solely in get_test.go and d.put has no
callers -- and for SpaceSNES the firmware cannot set an error code at all.
SpaceCFG can, though, via cfg_get_stringvalue returning not-found, so get
is genuinely reachable if it is ever wired up.
get cannot drain its way out the way ls does: the data phase length comes
from server_info.size, which on the error path holds whatever a previous
command left in the FILINFO rather than a real length. Closing and
reopening is the only reliable recovery.
vget and vput are unaffected; they set FlagNORESP and never read a
response block, so there is no error code to mishandle.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
abandonPort closed the port synchronously. A Write that is stuck because
the device stopped draining its USB endpoint keeps the handle busy, and on
macOS close() then blocks until that I/O completes -- so the caller hung
inside Close instead of inside Write. The same deadlock the write timeout
exists to prevent, one frame further down, and it triggered exactly when
the timeout was supposed to rescue the caller:
goroutine 23 [syscall]:
fxpakpro.(*devicePort).Close
fxpakpro.abandonPort
fxpakpro.writeWithTimeout
fxpakpro.writeExact
fxpakpro.(*Device).putFile
devicePort.abandon() now marks the port unusable and closes it on its own
goroutine. Write refuses once the port is marked, so nothing can race the
abandoned write, and Close is idempotent so autoCloseableDevice's later
close cannot block behind the same stuck write either.
This was missed on Windows, where the close did not block. It took a soak
on macOS, sitting for minutes with no CPU time, to surface it.
Test_writeWithTimeout_closeDoesNotBlock covers it with a port whose Close
blocks until the write is released.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
SNI_TEST_WEIGHTS sets the operation mix, so a run can be shaped to match real usage. Trackers poll memory with VGET far more than they touch files, which is worth testing directly: VGET sends a 64 byte command block where every filesystem command sends 512, and the firmware only re-evaluates server_info.cmd_size when recv_buffer_offset crosses 64 from below, so mixing the two is where a framing desync would show up. Added a memory write op that VPUTs and then reads the value back. A write-only check would pass on a stream that had desynced into returning plausible but wrong data. Writes target cartridge SRAM rather than WRAM. Writes to 0xF50000-0xF70000 are not a plain VPUT: memory.go turns them into a 65816 copy routine driven through the USB EXE mechanism, which needs the SNES to be running code that services the hook. Sitting in the system menu nothing does, so they time out waiting on $2C00. SRAM is also mirrored to a per-game file on the SD card every 250ms, so these writes generate SD activity too -- useful, since that is where the firmware does FAT work inside its USB interrupt handler. Soaked at 62% VGET, 8% VPUT-with-readback and 30% filesystem operations: 8000 operations in 5m24s with no failures. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
SNI_TEST_MEM_SPACE selects what memory writes go to. SRAM stays the default so the test is usable while the device sits in the system menu. WRAM only works with a ROM running: writes to 0xF50000-0xF70000 are not a plain VPUT, memory.go turns them into a 65816 copy routine driven through the USB EXE mechanism, which polls $2C00 waiting for the SNES to service the hook. That is what a tracker does when it injects state, so it is worth covering, but it needs a game booted. The read-back comparison is skipped for WRAM. A running game writes WRAM constantly, so a value read back can differ from what was written for entirely legitimate reasons and comparing would produce false failures. The byte count is still checked, which catches a desync even when the contents cannot be predicted. SRAM keeps the full comparison, since nothing else writes it. Soaked in-game with Super Mario World running, at 62% VGET, 8% WRAM VPUT and 30% filesystem operations: 12000 operations in 4m8s with no failures. Also worth recording: the same mix runs at roughly 100 ops/sec in-game against 25 ops/sec in the system menu. menu_main_loop sleeps 20ms per usbint_handler() call while the in-game loop in main.c has no sleep at all, so a device sitting in the menu services USB only about 50 times a second. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
Pairs with TestDevice_bootPath for putting the device into a known state between hardware runs. The firmware polls USB very differently in the two states -- menu_main_loop sleeps 20ms per usbint_handler() call while the in-game loop does not -- so which state a soak ran in matters when reading its results. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
fxpakpro_chunk_delay pauses after each 512-byte chunk written during a transfer. It defaults to zero, which writes as fast as the device accepts data, and exists to separate host write pacing from the logging that happens to accompany it. A user reported transfers succeeding with SNI_DEBUG=1 and failing without it, and the obvious theory was that debug logging slowed the host enough to matter. Measured on Windows, it does not: a 4 MiB upload takes 9.40s with debug against 9.51s without, because writes are paced by USB NAKs rather than by the host. This knob makes that testable directly rather than inferred from a logging side effect. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
Abandoning a stuck write closes the port on another goroutine, because a
synchronous close blocks behind the very write being abandoned. The
orphaned write still holds the handle until it unwinds, and
autoCloseableDevice reopens as soon as the fatal error propagates --
microseconds later -- so the reopen lands while the handle is still held.
Seen in the field on Windows: one stalled transfer poisoned every command
that followed.
fxpakpro: open(name="/COM3"): Serial port busy
/DeviceFilesystem/ReadDirectory: err=`... Serial port busy`
openPort now retries for up to 3 seconds at 50ms intervals, but only for
serial.PortBusy. Every other failure still returns immediately, so a
wedged or absent device is not retried for baud rates that were never
going to work.
This does not help if the device has genuinely stopped draining, since the
orphaned write never unwinds and the handle is never released. It fixes
the common case where the close simply had not completed yet, which is
what turned a single failed upload into a stream of unrelated errors.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
cmd/snitest drives SNI over gRPC the way a file transfer client does: ListDevices, MakeDirectory for each path component, PutFile, ReadDirectory, GetFile with verification. Every other hardware test in this repo calls the driver in-process, which skips the gRPC server, autoCloseableDevice and the daemon's goroutine scheduling -- and the failure being investigated was reported through that stack. Flags allow isolating the upload path, and pointing it at a missing directory to exercise the LS error path deliberately. Note it raises the gRPC receive limit: a 4 MiB file plus framing exceeds the client default of 4MB, so GetFile fails with ResourceExhausted otherwise. That is a client-side default, not something SNI imposes -- SNI already allows 100MB inbound. freeze_test.go hunts for a stalled transfer using the production write path, timing the gap between chunks rather than comparing bytes, and reports the worst gap even on success so a near miss is visible. usbstat_test.go and usbstat_probe_test.go read counters written by an instrumented firmware build, and attribute dropped packets to commands rather than to bulk data. putfile_test.go now distinguishes a write that stored the wrong bytes from a read that returned them wrongly, by reading the file back twice: a single comparison cannot tell those apart, and they have different causes. device_test.go wires the SNI_* environment variables into the test binary. Test binaries never call config.Load(), so those settings were silently inert and any config-dependent result would have been meaningless. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01ARLkt3NCnrwBMvpP8eAfDR
SNI presents only a status-bar (tray) icon with no window, so macOS is free to place it under App Nap while a game is in the foreground. App Nap throttles and coalesces a background app's timers and threads; a napped SNI stops servicing the FX Pak Pro's USB serial stream promptly, so the device appears to stop responding (reads return zero bytes, writes stall) until SNI is restarted. This matches field reports of the connection dying after some minutes of play on macOS while the identical setup is stable on Windows, which has no equivalent throttling. Take a process-level NSProcessInfo activity assertion (NSActivityUserInitiatedAllowingIdleSystemSleep) for the lifetime of the process. That keeps SNI out of App Nap while still letting the machine sleep normally when the user walks away. The assertion is held in a new cmd/sni/power package behind a build tag; it is a no-op on non-darwin platforms. This complements the fxpakpro desync/timeout fixes on this branch: those let SNI survive and reconnect after the device wedges, while this keeps the background process from being throttled into that state in the first place. Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01RVRWxcANar3DxSRTsvPPMu
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
2 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
What this does
Fixes SNI losing communication with an FX Pak Pro on macOS after some minutes of play (killing MSU audio and auto-tracking), where a restart only helps temporarily and the identical setup is stable on Windows.
It combines two independent pieces:
1. Upstream
fxpakpro-desync-and-timeout-fixes(the maintainer's hardware-tested work)These commits target the device wedging itself and one stalled transfer poisoning every request that follows:
WriteFilewhile holdingd.lock.close()blocks until stuck I/O completes, so the abandon-close now runs on its own goroutine and is idempotent.snitestgRPC repro harness.fxpakpro_read_timeout,fxpakpro_write_timeout,fxpakpro_honor_caller_deadline,fxpakpro_chunk_delay.This branch also brings
maincurrent: the SNI proxy driver (alttpo#55) and XDG config-dir support (alttpo#54). An existing~/.snidirectory is still used if present, so the config location does not change for current users.2. New: disable macOS App Nap (
cmd/sni/power)SNI presents only a status-bar icon with no window, so macOS is free to place it under App Nap while a game is in the foreground. App Nap throttles and coalesces a background app's timers and threads; a napped SNI stops servicing the FX Pak's USB stream promptly, so the device appears to stop responding until SNI is restarted. This is the most likely reason it is macOS-specific — Windows has no equivalent throttling, and the upstream fix branch itself notes the write stall surfaced "on macOS, sitting for minutes with no CPU time."
power.DisableAppNaptakes a process-levelNSProcessInfoactivity assertion (NSActivityUserInitiatedAllowingIdleSystemSleep) for the process lifetime. That keeps SNI out of App Nap while still letting the machine sleep normally. It is behind a build tag and is a no-op on non-darwin platforms.The two pieces are complementary: the upstream fixes let SNI survive and reconnect after a wedge; the App Nap change keeps the background process from being throttled into that state in the first place.
Testing
go build ./cmd/sniandgo vet ./...clean on darwin/arm64 (macOS 15.7, Go 1.24).go test -short ./...passes, including the new fxpakpro suite.v0.0.99+macos-fxpak-fixes, and logs the new fxpak timeouts. Hardware soak on the FX Pak still to be confirmed in real play.🤖 Generated with Claude Code
https://claude.ai/code/session_01RVRWxcANar3DxSRTsvPPMu