fxpakpro: fix protocol desyncs and unbounded I/O that wedge the device

.github/workflows/release.yml

@@ -12,14 +12,14 @@ jobs:
     runs-on: ubuntu-latest
     steps:
       - name: Set up Go
-        uses: actions/setup-go@v5
+        uses: actions/setup-go@v7
         with:
           go-version: '^1.23.0'
 
       - name: Set up linux dependencies
         run: sudo apt-get update && sudo apt-get install -y gcc
 
-      - uses: actions/checkout@v4
+      - uses: actions/checkout@v7
         with:
           fetch-depth: 0
 
@@ -48,11 +48,6 @@ jobs:
             goarch: "386"
             suffix: zip
             name: win-x86
-          - os: windows-latest
-            goos: windows
-            goarch: arm
-            suffix: zip
-            name: win-arm
           - os: windows-latest
             goos: windows
             goarch: arm64
@@ -63,11 +58,11 @@ jobs:
 
     steps:
       - name: Inject slug/short variables
-        uses: rlespinasse/github-slug-action@v4
+        uses: rlespinasse/github-slug-action@v5
 
       - name: Set up Go
         if: ${{ matrix.goos != 'windows' || matrix.os-variant != '7' }}
-        uses: actions/setup-go@v5
+        uses: actions/setup-go@v7
         with:
           go-version: '^1.23.0'
 
@@ -80,7 +75,7 @@ jobs:
 
       - run: echo "basename=sni-${{env.GITHUB_REF_SLUG}}-${{matrix.goos}}${{matrix.os-variant}}-${{matrix.goarch}}${{matrix.alt}}" | Out-File -FilePath $env:GITHUB_ENV -Encoding utf8 -Append
 
-      - uses: actions/checkout@v4
+      - uses: actions/checkout@v7
         name: Checkout
         with:
           fetch-depth: 0
@@ -130,7 +125,7 @@ jobs:
         run: 7z x -o"${{env.basename}}" "${{ runner.temp }}/${{ matrix.snfm }}"
 
       - name: Upload artifact
-        uses: actions/upload-artifact@v4
+        uses: actions/upload-artifact@v7
         with:
           name: ${{env.basename}}
           path: ${{env.basename}}/
@@ -163,16 +158,16 @@ jobs:
 
     steps:
       - name: Inject slug/short variables
-        uses: rlespinasse/github-slug-action@v4
+        uses: rlespinasse/github-slug-action@v5
 
       - name: Set up Go
-        uses: actions/setup-go@v5
+        uses: actions/setup-go@v7
         with:
           go-version: '^1.23.0'
 
       - run: echo "basename=sni-${{env.GITHUB_REF_SLUG}}-darwin-universal${{matrix.alt}}" >> $GITHUB_ENV
 
-      - uses: actions/checkout@v4
+      - uses: actions/checkout@v7
         name: Checkout
         with:
           fetch-depth: 0
@@ -218,7 +213,7 @@ jobs:
         run: 7z x -o"${{env.basename}}" "${{ runner.temp }}/${{ matrix.snfm }}"
 
       - name: Upload artifact
-        uses: actions/upload-artifact@v4
+        uses: actions/upload-artifact@v7
         with:
           name: ${{env.basename}}
           path: ${{env.basename}}/
@@ -282,10 +277,10 @@ jobs:
 
     steps:
       - name: Inject slug/short variables
-        uses: rlespinasse/github-slug-action@v4
+        uses: rlespinasse/github-slug-action@v5
 
       - name: Set up Go
-        uses: actions/setup-go@v5
+        uses: actions/setup-go@v7
         with:
           go-version: '^1.23.0'
 
@@ -294,7 +289,7 @@ jobs:
 
       - run: echo "basename=sni-${{env.GITHUB_REF_SLUG}}-${{matrix.goos}}${{matrix.os-variant}}-${{matrix.goarch}}${{matrix.alt}}" >> $GITHUB_ENV
 
-      - uses: actions/checkout@v4
+      - uses: actions/checkout@v7
         name: Checkout
         with:
           fetch-depth: 0
@@ -336,7 +331,7 @@ jobs:
         run: 7z x -o"${{env.basename}}" "${{ runner.temp }}/${{ matrix.snfm }}"
 
       - name: Upload artifact
-        uses: actions/upload-artifact@v4
+        uses: actions/upload-artifact@v7
         with:
           name: ${{env.basename}}
           path: ${{env.basename}}/
@@ -361,10 +356,10 @@ jobs:
     name: manylinux_2_28
     steps:
       - name: Inject slug/short variables
-        uses: rlespinasse/github-slug-action@v4
+        uses: rlespinasse/github-slug-action@v5
 
       - name: Set up Go
-        uses: actions/setup-go@v5
+        uses: actions/setup-go@v7
         with:
           go-version: '^1.23.0'
 
@@ -375,7 +370,7 @@ jobs:
 
       - run: echo "basename=sni-${{env.GITHUB_REF_SLUG}}-manylinux_2_28-amd64" >> $GITHUB_ENV
 
-      - uses: actions/checkout@v4
+      - uses: actions/checkout@v7
         name: Checkout
         with:
           fetch-depth: 0
@@ -414,7 +409,7 @@ jobs:
           tar cJf ${{env.basename}}.tar.xz ${{env.basename}}/
 
       - name: Upload artifact
-        uses: actions/upload-artifact@v4
+        uses: actions/upload-artifact@v7
         with:
           name: ${{env.basename}}.tar.xz
           path: ${{github.workspace}}/${{env.basename}}.tar.xz

cmd/sni/config/config.go

@@ -50,6 +50,27 @@ var (
 		"usb2snes_listen_addrs": "0.0.0.0:23074",
 		"fxpakpro_disable":      false,
 
+		// How long the fxpakpro driver waits on a device that has gone quiet or
+		// stopped accepting data. The firmware does its FAT work inside the USB
+		// interrupt handler, so a cluster allocation on a large, full, fragmented
+		// card can stall for seconds before it can answer; raise these if you see
+		// spurious timeouts on such a card.
+		"fxpakpro_read_timeout":  "15s",
+		"fxpakpro_write_timeout": "15s",
+		// Whether a caller's context deadline or cancellation aborts I/O already
+		// in flight to the device. With this off, a request that has already
+		// started talking to the fxpakpro runs to completion (bounded by the two
+		// timeouts above) rather than being cut short mid-transfer by an
+		// impatient client.
+		"fxpakpro_honor_caller_deadline": true,
+		// Optional pause after each 512-byte chunk written during a transfer.
+		// Zero, the default, writes as fast as the device accepts data. This
+		// exists to test whether host write pacing affects reliability: setting
+		// SNI_DEBUG=1 slows transfers dramatically (a hex dump per chunk to a
+		// file and the console) and has been reported to make failing transfers
+		// succeed, so this isolates the timing from the logging.
+		"fxpakpro_chunk_delay": "0s",
+
 		"retroarch_disable":    false,
 		"retroarch_hosts":      "localhost:55355",
 		"retroarch_detect_log": false,
@@ -64,8 +85,8 @@ var (
 		"emunw_disable":    false,
 		"emunw_detect_log": false,
 
-		"proxy_disable":       false,
-		"proxy_backend_host":  "",
+		"proxy_disable":      false,
+		"proxy_backend_host": "",
 	}
 	nwaConfigs = map[string]any{
 		"nwa_port_range":        NwaDefaultPort,
@@ -91,7 +112,7 @@ func InitDir() {
 		Dir = filepath.Join(Dir, ".sni")
 
 		// Follow XDG Base Directory Specification
-		if _, err := os.Stat(Dir); err != nil {		
+		if _, err := os.Stat(Dir); err != nil {
 			var xdgConfig = os.Getenv("XDG_CONFIG_HOME")
 			if xdgConfig == "" {
 				homeDir, _ := os.UserHomeDir()

cmd/snitest/main.go

@@ -0,0 +1,173 @@
+// Command snitest drives SNI over gRPC the way a file-transfer client does, to
+// reproduce transfer failures through the whole daemon stack rather than by
+// calling the driver directly.
+//
+// Every hardware test in this repo talks to the fxpakpro driver in-process,
+// which skips the gRPC server, autoCloseableDevice, and the daemon's goroutine
+// scheduling. The reported freeze happened through that stack, so this exists
+// to exercise it: ListDevices, then MakeDirectory for each path component,
+// PutFile, then ReadDirectory -- the sequence SNFM issues.
+//
+// PutFile is unary and blocking with no progress reporting, so a stalled
+// transfer shows up here the same way it does for a user: the call simply does
+// not return. Each call is therefore timed and reported.
+package main
+
+import (
+	"context"
+	"flag"
+	"fmt"
+	"log"
+	"os"
+	"strconv"
+	"strings"
+	"time"
+
+	"google.golang.org/grpc"
+	"google.golang.org/grpc/credentials/insecure"
+
+	"sni/protos/sni"
+)
+
+func main() {
+	addr := flag.String("addr", "localhost:8191", "SNI gRPC address")
+	dir := flag.String("dir", "unittest-grpc/sub", "directory to upload into")
+	size := flag.Int("size", 4*1024*1024, "payload size in bytes")
+	iterations := flag.Int("n", 20, "iterations")
+	timeout := flag.Duration("timeout", 0, "per-call deadline; 0 means none")
+	skipGet := flag.Bool("skipget", false, "skip GetFile verification (isolate the upload path)")
+	skipLs := flag.Bool("skipls", false, "skip ReadDirectory")
+	lsMissing := flag.Bool("lsmissing", false,
+		"ReadDirectory a path that does not exist before each PutFile")
+	flag.Parse()
+
+	// A 4 MiB file plus protobuf framing exceeds gRPC's default 4MB receive
+	// cap, so GetFile fails with ResourceExhausted unless this is raised. Worth
+	// knowing for any client that reads whole ROMs back.
+	const maxMsg = 64 * 1024 * 1024
+	conn, err := grpc.NewClient(*addr,
+		grpc.WithTransportCredentials(insecure.NewCredentials()),
+		grpc.WithDefaultCallOptions(
+			grpc.MaxCallRecvMsgSize(maxMsg),
+			grpc.MaxCallSendMsgSize(maxMsg),
+		))
+	if err != nil {
+		log.Fatalf("dial %s: %v", *addr, err)
+	}
+	defer conn.Close()
+
+	devices := sni.NewDevicesClient(conn)
+	fsys := sni.NewDeviceFilesystemClient(conn)
+
+	// find a device
+	ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
+	list, err := devices.ListDevices(ctx, &sni.DevicesRequest{})
+	cancel()
+	if err != nil {
+		log.Fatalf("ListDevices: %v", err)
+	}
+	if len(list.GetDevices()) == 0 {
+		log.Fatalf("no devices found; is a device connected and SNI running?")
+	}
+	uri := list.GetDevices()[0].GetUri()
+	log.Printf("device: %s (%s)", uri, list.GetDevices()[0].GetDisplayName())
+
+	// deterministic payload: each 4-byte word holds its own offset, so a
+	// mismatch reports how far the data shifted
+	payload := make([]byte, *size)
+	for i := 0; i+4 <= len(payload); i += 4 {
+		payload[i] = byte(i)
+		payload[i+1] = byte(i >> 8)
+		payload[i+2] = byte(i >> 16)
+		payload[i+3] = byte(i >> 24)
+	}
+
+	call := func(name string, fn func(context.Context) error) time.Duration {
+		ctx := context.Background()
+		var cancel context.CancelFunc
+		if *timeout > 0 {
+			ctx, cancel = context.WithTimeout(ctx, *timeout)
+			defer cancel()
+		}
+		start := time.Now()
+		err := fn(ctx)
+		d := time.Since(start)
+		if err != nil {
+			log.Printf("  %-16s FAILED after %v: %v", name, d.Round(time.Millisecond), err)
+			os.Exit(1)
+		}
+		return d
+	}
+
+	// MakeDirectory for each path component, as SNFM does
+	parts := strings.Split(*dir, "/")
+	for i := range parts {
+		p := strings.Join(parts[:i+1], "/")
+		ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
+		_, err := fsys.MakeDirectory(ctx, &sni.MakeDirectoryRequest{Uri: uri, Path: p})
+		cancel()
+		if err != nil {
+			log.Printf("  mkdir %-20s %v (continuing; it may already exist)", p, err)
+		}
+	}
+
+	path := *dir + "/grpc-test.bin"
+	log.Printf("uploading %d bytes to %s, %d iterations", *size, path, *iterations)
+
+	var worst time.Duration
+	for i := 1; i <= *iterations; i++ {
+		// A client that checks whether a folder exists before creating it will
+		// LS a missing path and get an error back. The firmware commits to a
+		// data phase for LS regardless, and still emits the block holding the
+		// 0xFF terminator on the error path, so a client that returns on the
+		// error code leaves it unread and every command afterwards is one block
+		// out of step. This reproduces that sequence deliberately.
+		if *lsMissing {
+			lctx, lcancel := context.WithTimeout(context.Background(), 20*time.Second)
+			_, lerr := fsys.ReadDirectory(lctx, &sni.ReadDirectoryRequest{
+				Uri: uri, Path: "unittest-no-such-dir-" + strconv.Itoa(i)})
+			lcancel()
+			if lerr == nil {
+				log.Printf("[%2d] ReadDirectory of a missing path unexpectedly succeeded", i)
+			}
+		}
+
+		put := call("PutFile", func(ctx context.Context) error {
+			_, err := fsys.PutFile(ctx, &sni.PutFileRequest{Uri: uri, Path: path, Data: payload})
+			return err
+		})
+		var ls time.Duration
+		if !*skipLs {
+			ls = call("ReadDirectory", func(ctx context.Context) error {
+				_, err := fsys.ReadDirectory(ctx, &sni.ReadDirectoryRequest{Uri: uri, Path: *dir})
+				return err
+			})
+		}
+		var get time.Duration
+		if !*skipGet {
+			get = call("GetFile", func(ctx context.Context) error {
+				rsp, err := fsys.GetFile(ctx, &sni.GetFileRequest{Uri: uri, Path: path})
+				if err != nil {
+					return err
+				}
+				data := rsp.GetData()
+				if len(data) != len(payload) {
+					return fmt.Errorf("read back %d bytes, sent %d", len(data), len(payload))
+				}
+				for j := range payload {
+					if data[j] != payload[j] {
+						return fmt.Errorf("contents differ at offset %d: got %02x want %02x",
+							j, data[j], payload[j])
+					}
+				}
+				return nil
+			})
+		}
+		if put > worst {
+			worst = put
+		}
+		log.Printf("[%2d] PutFile %v  ReadDirectory %v  GetFile+verify %v",
+			i, put.Round(time.Millisecond), ls.Round(time.Millisecond), get.Round(time.Millisecond))
+	}
+	log.Printf("completed %d iterations; slowest PutFile %v", *iterations, worst.Round(time.Millisecond))
+}

devices/snes/drivers/fxpakpro/boot.go

@@ -22,7 +22,7 @@ func (d *Device) boot(ctx context.Context, path string) (err error) {
 	}
 
 	// send command:
-	err = sendSerialChunked(d.f, 512, sb)
+	err = sendSerialChunked(ctx, d.f, 512, sb)
 	if err != nil {
 		err = d.FatalError(err)
 		return