openplotter-pypilot-read drops the Signal K websocket every ~90s, losing ~30s of heading data each time

[tuomassaloniemi]

Summary

openplotter-pypilot-read never reads from its Signal K websocket, so it never answers
the server's keepalive pings. Signal K closes the connection, the bridge's exception
handler tears down both connections and sleeps 5s, and navigation.headingMagnetic /
navigation.attitude stop updating for 20-35 seconds. This repeats on a ~90 second cycle,
indefinitely. The failure is silent by default.

Environment

• openplotter-pypilot 4.0.11
• signalk-server 2.31.1
• pypilot 0.71, pypilot_boatimu (ICM-20948 over I2C)
• Raspberry Pi 5, Debian 12 bookworm, OpenPlotter 4.x

Symptom

navigation.headingMagnetic freezes in Signal K — the timestamp stops advancing, not
just the value, so no delta is arriving at all. Measured by polling the REST API once per
second:

10:55:17.008  342.63 deg   <- same timestamp for 22 consecutive polls
...           (36 s)
10:55:53.879  342.70 deg   <- resumes

Freeze starts were 89 s apart, each lasting 22-36 s.

pypilot itself is not at fault. Watching imu.heading directly on port 23322 while
simultaneously polling Signal K, over a 120 s window:

pypilot samples : 241  (steady 2 Hz)
signalk freezes : 2    (22.7 s and 35.1 s)
pypilot output during those freezes: 45 and 70 samples

pypilot produced continuously through both freezes. The stall is in the bridge.

Root cause

In openplotterPypilot/openplotterPypilotRead.py, the loop only ever sends:

ws = create_connection(uri, header=headers, sslopt={"cert_reqs": ssl.CERT_NONE})
...
ws.send(SignalK+'\r\n')

ws.recv() is never called. websocket-client only processes incoming frames — including
ping frames, which it auto-answers with a pong — during recv(). So the server's pings are
never answered.

Signal K reaps such connections (dist/interfaces/ws.js):

const wsPingInterval = app.config.settings.wsPingInterval ?? 30000;
...
if (spark.wsAlive === false) {
    debug('heartbeat timeout for spark %s, closing', spark.id);
    return spark.end(undefined, { reconnect: true });
}
spark.wsAlive = false;
spark.socket.ping();

Every 30 s it sets wsAlive = false and pings; if the next tick still sees false, it
closes the socket. A client that never pongs is therefore killed after ~60 s. The next
ws.send() on the dead TLS session raises, and the handler runs:

except Exception as e:
    if debug: print('ERROR, pypilot-read: '+str(e))
    if ws: ws.close()
    ws = False
    client = False
    time.sleep(5)

which discards the pypilot client too and sleeps 5 s. ~60 s alive + ~30 s to reconnect and
resettle gives the observed ~90 s period.

With debug enabled, the exception is exactly what that predicts:

ERROR, pypilot-read: EOF occurred in violation of protocol (_ssl.c:2393)
pypilot client connected
(90 s later)
ERROR, pypilot-read: EOF occurred in violation of protocol (_ssl.c:2393)
pypilot client connected

Suggested fixes

1. Answer the pings. The stream is opened ?subscribe=none, so no data frames arrive
and there is nothing to consume but control frames. A short-timeout read each iteration is
enough to let the library auto-pong:

ws.settimeout(0.01)
try:
    ws.recv()
except Exception:
    pass          # timeout is expected; this exists only to service control frames

Note this must not share the outer except, or a routine read timeout will trigger the
full 5 s teardown.

2. Don't publish null values. headingValue/rollValue/pitchValue are reset to
None each iteration, but appended unconditionally:

headingValue = None
...
if 'imu.heading_lowpass' in result: headingValue = result['imu.heading_lowpass']*0.017453293
keys.append({"path":"navigation.headingMagnetic","value":headingValue})

client.receive() returns only the keys that changed, so any iteration delivering just
imu.roll or imu.pitch publishes navigation.headingMagnetic: null into Signal K.
The appends should be guarded by whether the value was actually received.

3. Reconnect faster, and don't drop the pypilot client. A 5 s sleep on any exception is
costly for a nav data path, and rebuilding the pypilot client is unnecessary when it was
the websocket that failed.

4. Make the failure visible. The service has no PYTHONUNBUFFERED=1, so print() is
block-buffered and debug output never reaches the journal. Adding
Environment=PYTHONUNBUFFERED=1 to openplotter-pypilot-read.service would have made this
diagnosable from journalctl alone.

Workaround

Setting "wsPingInterval": 0 in ~/.signalk/settings.json disables Signal K's heartbeat
(0 ?? 30000 is 0, which is falsy, so the interval is never created). Verified: 240 s of
polling with zero freezes, where ~2.7 were expected.

This is a workaround, not a fix — it disables dead-client reaping for every websocket
client on the server, not just this bridge.