fix: warn when feedback arrives with no step state (and a falsified hypothesis)

[tactino]

Read the last section first. This branch started as a keepalive fix. Measurement killed that hypothesis, and the keepalive change is no longer in it. The commit history keeps the wrong version rather than hiding it.

What ships

One warning, in _handler:

step_state = step_state_map.get(eid, None)
if step_state is None:
    logger.warning(f"Feedback for env {eid} arrived with no step state. ...")

Every environment that reaches feedback was handed an action first, on the same connection, and that is what fills the map. So a miss means exactly one thing: the connection was replaced mid-run, and the five per-environment maps — prev_node_map, step_state_map, terminated_map, truncated_map, last_obs_map — went with it. The transition then gets built from an empty observation and stored.

That used to happen in total silence. The real fix is on the client side, PlugRL/plugrl-env-client#5, which now drops a held feedback instead of resending it across a reconnect. This is the server saying so when it happens anyway.

Plus experiments/e8-keepalive-hypothesis/, below.

The hypothesis that did not survive

A clean-machine run of the documented quickstart dropped its connection with sent 1011 (internal error) keepalive ping timeout. websockets pings every 20 s with a 20 s timeout; a learn step is CPU-bound; therefore the server misses its pong and kills a healthy connection. Plausible at every step, and wrong.

E8 measured it. Gradient steps per learn are num_updates_per_batch * ceil(buffer_size / batch_size), so raising the epoch count makes the learn long while keeping the fill short:

run	gradient steps per learn	learns	learn duration	keepalive timeouts
default epochs	256	3	7–11 s	0
400 epochs	1600	5	177–190 s	0

Nine times the ping timeout, five times over, and nothing closed. The reason is one line in server/training_backend.py:

step, log_dict = await asyncio.to_thread(self._algorithm.learn)

Learning already runs off the event loop. The hypothesis was not merely unproven — it was contradicted by code sitting there to be read.

What actually happened

The client's own log, either side of the failure:

12:28:16.237 | INFO    | Intermediate rollout timing summary: env_steps=5353 ...
14:21:53.007 | WARNING | Connection closed during INFER/ACTION exchange ...

Those timing lines are emitted every 30 s without a break from 12:24:14. Then 1 h 53 min of nothing. A slow process still logs; this one was frozen. The machine suspended with the run open.

Two details the first diagnosis had backwards: the traceback is in websockets/sync/connection.py, the client library, so sent 1011 means the client gave up on the server, not the reverse; and the server log for that run contains no keepalive line at all. Turning the server's keepalive off would not have prevented this incident.

Why the rest still stands

The state-loss path was read out of the handler and reproduced in a unit test. It was never inferred from the incident — only the cause was, and the cause is the part that was wrong. Any reconnect costs the same state: a suspend, a flaky link, a server restart.

E6 was checked for contamination and is clean: one connection per seed, zero reconnects across all three.

Verification

• 54 passed. ruff check --exclude third_party . clean, format clean.
• tests/test_serve_options.py keeps only the assertions that are still true — compression and max_size are None — and records the falsified hypothesis in its docstring so nobody re-derives it.

Specification updated in PlugRL/plugrl-protocol#3, which lost its keepalive corollary for the same reason.

🤖 Generated with Claude Code