Fix WSConnection reconnect stall: don't block the event loop during the reconnect delay

[kojira]

Summary

strfry stream and strfry sync — the clients built on WSConnection — cannot reconnect after their first disconnect. The client keeps retrying and failing forever (Attempting to connect → Websocket connection error every 5s) even when the remote is perfectly reachable, and never recovers without a process restart. Since the process never exits, a supervisor (systemd/launchd Restart=) never restarts it — so a brief blip becomes an indefinite stall. (strfry router is not affected: it has its own cron-scheduled reconnect that does not block the loop.)

Root cause

WSConnection::doConnect() implemented the reconnect delay with std::this_thread::sleep_for():

auto doConnect = [&](uint64_t delay = 0){
    if (delay) std::this_thread::sleep_for(std::chrono::milliseconds(delay));
    if (shutdown) return;
    LI << "Attempting to connect to " << url;
    hub.connect(url, nullptr, {}, 5000, hubGroup);
};

That thread also runs the uWS/uv event loop, so the sleep blocks the loop and stalls its cached clock by delay ms (default 5000). The following hub.connect(..., 5000, ...) arms a 5000 ms connection-timeout timer whose deadline is computed against the now-stale clock — already expired in real time — so it fires on the very next loop tick and onEnds the freshly-TCP-connected socket before the WebSocket handshake completes.

The first connection uses doConnect(0) (no sleep → fresh clock) so it works; every reconnect (doConnect(reconnectDelayMilliseconds)) wedges.

Fix

Defer the reconnect with a non-blocking uS::Timer on the hub's event loop instead of sleeping the loop thread, so the loop clock stays accurate and the connection-timeout behaves as intended.

The same principle is why cmd_router.cpp doesn't have this bug: it never sleeps the loop thread — its reconnect delay comes from a separate cron timer that just posts an event to the loop (via hubTrigger), and the actual hub.connect() runs on the loop thread. This patch doesn't copy the router's cron/inbox machinery; a one-shot uS::Timer on the loop is enough for WSConnection.

Reproduce (deterministic)

1. Start a throwaway relay and a stream client pointed at it:

   ./strfry --config relay.conf relay                       # e.g. bind 127.0.0.1:7777
   ./strfry --config client.conf stream ws://127.0.0.1:7777 --dir down
   

   → the client logs Connected.
2. Stop the relay (the client enters the reconnect loop), wait a few seconds, then start the relay again.
3. Before this patch: the client loops Attempting to connect / Websocket connection error every 5s forever and never reconnects, even though the relay is back and a freshly-started client connects to it instantly.
   After this patch: the client reconnects on its next attempt.

Extra confirmation

Lowering reconnectDelayMilliseconds below the 5000 ms connection-timeout (e.g. 250) also makes reconnect succeed with the old code — confirming the delay-vs-timeout clock interaction is the cause.

[kojira]

Background / how this was hit in production (multi-day silent ingest stall): #253

[Gooh456]

Read through the full WSConnection.h (not just the diff) to check this against the class's shutdown path, and the root-cause writeup checks out: sleep_for on the hub thread stalls the uv loop's cached clock, so the hub.connect(..., 5000, ...) timeout timer is armed against a stale clock and fires immediately. The fix (deferring via a non-blocking uS::Timer on the loop) is the right approach.

One gap I noticed: scheduleReconnect()'s uS::Timer isn't tracked as a member, so terminate() (which runs when shutdown is set via close()) closes hubGroup, hubTrigger, and currWs, but has no handle on any in-flight reconnect timer. connectNow() does check shutdown first, so there's no null-hubGroup misuse — but the timer itself keeps the loop's handle count above zero, so hub.run() (and therefore the calling thread, since e.g. cmd_stream.cpp calls ws.run() synchronously) won't return until the pending delay actually elapses. So a close() that races with a pending reconnect can now add up to reconnectDelayMilliseconds (or a caller-supplied delay) of extra hang before the process exits, instead of returning promptly.

To be clear about severity: I checked cmd_stream.cpp/cmd_sync.cpp/cmd_download.cpp/cmd_upload.cpp and none of them currently call ws.close() (there's no SIGINT/SIGTERM handler wired up anywhere — only SIGPIPE is handled, via misc.cpp's exit(1)), so this doesn't regress any live behavior today. But terminate()'s design and the "Should only be called from..." comments make it clear graceful shutdown was an intended part of the contract, so it seems worth closing while you're in here: keep something like a uS::Timer *reconnectTimer = nullptr; member, set it in scheduleReconnect(), and close+null it in terminate() too (mirroring how hubGroup/hubTrigger/currWs are already handled), plus maybe guard against scheduleReconnect() stacking a second timer if it's somehow called while one is already pending.

Didn't build/run this (no easy way to reproduce the exact reconnect-timing race here), so take the above as code-reading rather than a confirmed repro — but the gap seems real from tracing through the code.

[hoytech]

Thank you for this! It looks correct. I will do a bit more testing and then merge.

[Gooh456]

Sounds good, thanks for taking a look — glad the diagnosis lined up.

[kojira]

Good catch, @Gooh456 — you're right. The pending reconnect uS::Timer wasn't tracked, so terminate() had no handle on it: a close() racing with a pending reconnect would keep the loop's handle count up and delay hub.run()'s return by up to reconnectDelayMilliseconds. Fixed in 5e1376f — reconnectTimer is now a member, closed + nulled in terminate() alongside hubGroup/hubTrigger/currWs, and scheduleReconnect() bails if one is already pending (no stacking; also added it to the destroyed-before-close warning). Thanks for the careful read!

[Gooh456]

That's a clean fix, thanks for turning it around so quickly — makes sense to fold the timer into the same terminate() cleanup as the other handles.