diff options
Diffstat (limited to 'docs')
| -rw-r--r-- | docs/link-drop-investigation.md | 190 |
1 files changed, 190 insertions, 0 deletions
diff --git a/docs/link-drop-investigation.md b/docs/link-drop-investigation.md new file mode 100644 index 0000000..807145b --- /dev/null +++ b/docs/link-drop-investigation.md @@ -0,0 +1,190 @@ +# Investigation: idle link-socket drops in the multi–Game Boy setup + +Status: **open / not root-caused.** This document records what the bug is, what +has been ruled out, the exact conditions under which it reproduces, and the most +promising next steps, so the next debugging session can start cold. + +## TL;DR + +When a Game Boy's link port is bridged over a unix socket (`sl0pboy +--serial-sock`), the **link connection gets dropped while the Game Boy is idle** +(sitting at the shell prompt after it has a DHCP lease). The emulator *process +stays alive* — it is the socket that dies, and nothing reconnects, so that GB +goes permanently offline until the emulator is relaunched. + +It is **not** a gbos crash, **not** a gbos poweroff, and **not** caused by the +recent KGetc/net_pump change (the pre-change ROM drops too). It only happens +when the link is **idle** (no packets flowing); a busy link stays up. + +## Symptom + +- Hub (`tools/gbhub`) logs `[gbhub] GB0 (10.0.0.2) left`, i.e. its per-GB reader + thread's `conn.recv()` returned empty (or raised and was caught). +- In the user's interactive session the GB then appeared to "rejoin" repeatedly — + that was the user relaunching `gbjoin` after each drop (see "No recovery"). +- `ping <that GB>` from another GB fails because the target is offline. + +## Architecture recap (so the pieces are named) + +- Each Game Boy = one `sl0pboy` emulator. Its **link/serial port** is wired to a + **unix stream socket** via `--serial-sock PATH` (emulator connects as client; + `serial_connect()` in `src/main.c`, retried ~1s at startup **only**). +- `tools/gbhub` is a virtual switch/router/DHCP. It `accept()`s each GB's socket, + runs a per-GB reader thread (`gb_reader`) that SLIP-decodes frames and routes + them, answers DHCP, and NATs external traffic out a TUN. + - **daemon mode** (`gbhub --daemon`): hub is its own process; emulators are + launched separately (`tools/gbjoin`). + - **spawn mode** (`gbhub N`): hub *and* the emulator child processes live in + one process. +- The GB's kernel serial RX (`net_getbyte_nb`, `gb.c` rSC=0x80 path) does a + non-blocking `read()` of 1 byte per poll; TX (`rSC=0x81`) does a non-blocking + `write()` of 1 byte and ignores errors. + +## What it is NOT (ruled out this session) + +- **Not a gbos crash.** Emulator stderr is clean (`Loaded 'GBOS' ... / link port + <-> ...` and nothing else). No fault/opcode message. +- **Not a gbos poweroff via readc EOF.** Instrumented the shell's read loop to + print every byte and to not `poweroff()` on EOF — no `EOF` byte was ever read, + and the GB still left. So the shell is not powering off. +- **Not the emulator process exiting.** Logged `Popen.poll()` — it stays `None` + (process alive) after "left". The *socket* died, not the process. +- **Not the recent KGetc/net_pump change.** Stashing that change and rebuilding + the previous gbos still drops in spawn mode. Pre-existing. +- **Not the TUN, NAT, `--uncapped`, the per-GB ROM copy, or a stale battery + `.sav`.** A standalone harness that adds each of these one at a time keeps the + GB up (see matrix). +- **Not gbhub's `while all(e.poll())` main loop.** Replacing it with a plain + sleep did not stop the drop. +- **Not gbhub's per-line `stderr.flush()` console logging.** Disabling it did not + stop the drop. + +## Where it reproduces (bisection matrix) + +| Setup | Idle GB result | +|---|---| +| Minimal harness: one Python proc spawns the emulator **and** reads its socket; no TUN; capped | **survives** | +| Harness + TUN + a `tun_reader` (nothing gets forwarded to the GB at idle) | **survives** | +| Harness + TUN + NAT (`ip_forward` + masquerade) + `--uncapped` | **survives** | +| Harness + fresh ROM copy (no `.sav`) | **survives** | +| `gbhub --daemon` + **headless** emulators as separate processes (`hubtest.py`) | **survives** ✅ | +| `gbhub N` **spawn mode** (emulators are children of the hub, one process) | **drops when idle** ❌ | +| `gbhub --daemon` + **windowed** `gbjoin` (the user's real setup) | **drops when idle** ❌ | + +Two important facts fall out of this: + +1. **`daemon + headless` is the only combination that is reliably stable.** +2. There appear to be **two independent triggers**, because: + - spawn mode drops with **headless** emulators, and + - daemon mode drops with **windowed** emulators, + but `daemon + headless` does not. + +## The frustrating part + +The standalone harness `edbg2.py` — which, like spawn-mode gbhub, spawns the +emulator **and** reads its socket in the **same process**, with TUN+NAT+uncapped — +**survives**. So the drop is *not* simply "the process that reads the socket is +also the emulator's parent." Yet gbhub spawn mode, which is functionally the +same, **drops**. Every difference I could find between them was eliminated +without changing the outcome: + +- Same emulator argv. +- Same DHCP reply bytes (gbhub `_dreply` == harness `dreply`, byte-for-byte). +- Same TUN/NAT. +- Console-logging removed, poll-loop removed — still drops. + +So the specific difference that flips gbhub-spawn from "survives" to "drops" was +**not isolated**. Likewise the windowed-vs-headless difference in daemon mode was +not isolated (couldn't be driven in the sandbox — no interactive TTY). + +## Key behavioral clue + +Drops happen **only when the link is idle**. When the GB is doing something over +the network (answering pings via `netd` or the prompt-pump, running `ping`/ +`wget`), the link stays up. This strongly implicates the **quiet-socket** path: +the GB spinning `net_getbyte_nb` (many 1-byte non-blocking `read()`s/sec on a +socket with no data) and/or the hub's reader thread blocked in `recv()` with +nothing arriving. + +## No recovery (makes every drop fatal) + +Independent of the cause, there is currently **no self-healing**: + +- The emulator's `serial_connect()` runs **once** at startup; a dead socket is + never reconnected (reads/writes just fail silently; `serial_no_eof` keeps RX + "pending" forever). +- gbos runs `dhcp` **once** at boot; no lease renewal, no "link back" detection. +- So a drop = offline until manual relaunch. This is why the user saw constant + "churn." + +(Adding auto-reconnect in the emulator + a periodic lease renewer in gbos would +make drops a ~1s blip and is worth doing regardless — but it is a *mitigation*, +not the fix.) + +## The hard constraint any theory must satisfy + +**Both processes stay alive, but the socket dies.** The emulator's `poll()` stays +`None` (process alive) and the hub is alive (it logs "left"), yet the hub's +`recv()` returns empty - meaning the emulator's *write half* of the link socket +was closed. Nothing in `gb.c`/`main.c` closes that fd, and the emulator never +exits. So the precise question is: **what closes/resets the emulator-side link fd +without the emulator process exiting?** + +Note this *weakens* a naive `SIGPIPE` theory: an unignored `SIGPIPE` would +*terminate* the emulator, which contradicts "process alive" (unless that +observation is racy). Worth confirming, but not a clean fit. + +## Hypotheses still on the table + +1. **A socket syscall/errno we simply haven't observed.** Given the constraint + above, stop guessing and `strace` it (see next steps). Look for an unexpected + `close(fd)`, an `ECONNRESET`/`EPIPE` on `read`/`write`, or a faulting `write`. + Also check whether the emulator installs `SIG_IGN` for `SIGPIPE` and whether a + signal is actually delivered. +2. **Hub `recv()` raising, not a clean peer-close.** `gb_reader` does + `except Exception: chunk = None`, so an exception (e.g. `ConnectionResetError`) + is reported identically to a clean EOF. The two need to be distinguished. +3. **High-frequency 1-byte reads** on the unix socket interacting badly with the + emulator's serial state machine or the socket under specific scheduling. +4. **Windowed path** (`daemon + gbjoin`): the non-headless main loop + (`render_frame` sixel to stdout + `input_poll` on stdin + paced 59.73fps) may + starve serial servicing or interact with a slow terminal; needs a real TTY to + reproduce. + +## Next diagnostic steps (in priority order) + +1. **Check/ignore SIGPIPE in the emulator.** Add `signal(SIGPIPE, SIG_IGN)` at + startup and re-test spawn mode. If the drop stops, hypothesis (1) is confirmed. + (Cheap, high-value.) +2. **`strace -f -e trace=network,read,write,close` the emulator** during a spawn- + mode idle drop; find the exact syscall + errno at the moment the socket dies + (EPIPE/ECONNRESET/close). This should end the guessing. +3. **Distinguish EOF vs reset in the hub.** In `gb_reader`, log the exception type + separately from a clean empty `recv()`. Tells us who closed and why. +4. **Reproduce the windowed case on a real terminal** (outside the sandbox): + `sudo tools/gbhub --daemon` + `tools/gbjoin` in another terminal; watch + whether the emulator window closes (process exits) or the link goes quiet + (socket drop). Note anything on stderr. +5. If (1)/(2) implicate the write path, consider making the emulator's serial + socket writes tolerate back-pressure explicitly (drop-on-EAGAIN is already the + intent, but make sure a full buffer / peer-gone can't escalate). + +## Repro / harness pointers + +- Fails: `sudo tools/gbhub 1 ""` (single idle GB, spawn mode) — `GB0 ... left`. +- Fails: `sudo tools/gbhub 2 "" "ping 10.0.0.2"` is *racy* now — GB0 sometimes + drops before GB1's ping lands. +- Survives: daemon mode with headless emulators launched separately (the shape of + the throwaway `hubtest.py` used this session: spawn `gbhub --daemon` as one + process, then two `sl0pboy --headless --uncapped --serial-sock /tmp/gbhub.sock` + as separate children; both idle GBs keep their leases). + +## Relevant code + +- Emulator link socket: `~/dev/gbc/src/main.c` (`serial_connect`, `--serial-sock` + wiring) and `~/dev/gbc/src/gb.c` (rSC=0x80 RX / rSC=0x81 TX, `serial_no_eof`). +- Hub reader/router/DHCP: `~/dev/gbos/tools/gbhub` (`gb_reader`, `route`, + `_dreply`, `tun_reader`). +- GB kernel serial/net pump: `~/dev/gbos/src/socket.asm` (`net_getbyte_nb`, + `net_putbyte`, `net_pump`) and console pump in `~/dev/gbos/src/syscall.asm` + (`KGetc`). |