[v5] 🐛 bug: contributor WebSocket flaps every 30–90s, and every close is silent by construction (1006, no reason, discarded by the relay)

[Danathar]

Summary

• A contributor ("clanker") holds one long-lived WebSocket to the hive hub for
  the whole session: it carries the task assignment, the scoped GitHub token,
  progress reports, and a 30-second application-level ping/pong in both
  directions.
• On hosted-kubestellar-hive-ojv6 that socket is not staying up. Over 32
  minutes on 2026-08-29 one contributor's connection died and re-established
  seven times, with connected lifetimes of 76s, 84s, 30s, 991s, 30s, 300s
  and 30s. Three of the seven lasted exactly 30 seconds. The relay reconnects
  1s later every time and resumes the task, so work does complete — this is not
  a stall.
• The cause is not established. It is not the application heartbeat: both
  the relay (HEARTBEAT_TIMEOUT_MS = 90000) and the hub
  (wsHeartbeatTimeout = 90s) require 90 seconds of silence before they close
  anything, so neither can produce a 30-second lifetime, and the relay's
  distinctive Heartbeat timeout on … — reconnecting line does not appear in
  the log at all. That points below the application — the ingress/network path
  in front of the hosted spoke — but nothing on either side records enough to
  confirm it.
• Which is the second half of this report: every hub-side close is
  indistinguishable from a network drop, and the relay throws away the only
  evidence there is. Both are one-line fixes and both are prerequisites for
  diagnosing the first half.
• Blast radius: every contributor on a hosted hub. Work still completes, but
  each flap books a release cooldown on the in-flight issue, re-mints a GitHub
  token, and writes a joined/left pair into the shared public activity feed.

Evidence

GET /api/contribute/activity, filtered to one contributor, 2026-08-29:

11:12:52  joined     ┐ 76s
11:14:08  left       ┘
11:15:22  joined     ┐ 84s
11:16:46  left       ┘
11:17:18  joined     ┐ 30s
11:17:48  left       ┘
11:22:02  joined     ┐ 991s
11:38:33  left       ┘
11:38:34  joined     ┐ 30s      (+1s reconnect = BASE_RECONNECT_DELAY_MS)
11:39:04  left       ┘
11:39:05  joined     ┐ 300s
11:44:05  left       ┘
11:44:06  joined     ┐ 30s
11:44:36  left       ┘

19 joined and 19 left events for this one contributor in the retained feed.
The +1s gaps are the relay's BASE_RECONNECT_DELAY_MS; the backoff never
grows past 1s because a successful connect resets it
(bin/contributor-relay.sh:2318), so the log line is always
Reconnecting in 1000ms.

Matching relay output, one full cycle, repeated verbatim four times:

Connected to wss://hosted-kubestellar-hive-ojv6…/api/contribute/ws
Authenticated … as c-ca8187f7480c (tier: contributor)
Hub protocol 1.2; capabilities: token_refresh, …
Reconnected while working on kubestellar/hive#5055 — resuming
GitHub token refreshed
Connection to wss://…/api/contribute/ws closed. Reconnecting in 1000ms...

Why nobody can tell what closed it

1. The hub never sends a WebSocket Close frame. Every hub-side close is a
bare conn.Close() / c.ws.Close() — the auth timeout
(contribute_ws.go:2766), the auth-failure paths (:2845, :2861, :2867),
the heartbeat loop's timeout and failed-ping branches (:3639, :3647), and
the stale sweep in cleanupLoop (:3929). None calls
WriteControl(websocket.CloseMessage, …), so the client sees 1006 (abnormal
closure), empty reason — byte-identical to a yanked cable.

Verified live against the hub with an unauthenticated probe:

 0.1s open
 0.1s msg: {"type":"auth_challenge","seq":1,"nonce":"…"}
30.1s msg: {"type":"auth_failed","reason":"Authentication timeout"}
30.1s CLOSE code= 1006 reason= ""

The hub knew exactly why it was hanging up, said so in a JSON message, and then
closed the socket in a way that carries none of it. A JSON auth_failed is at
least readable; the heartbeat and cleanup closes send nothing at all first.

2. The relay discards the close code and reason.

hub.ws.on('close', () => {
  console.log(`Connection to ${hub.url} closed. Reconnecting in ${hub.reconnectDelay}ms...`);

(bin/contributor-relay.sh:2553)

ws hands that callback (code, reason). Logging them would immediately
separate "1006, no frame" (network or a bare Close()) from a deliberate
1000/1001/1011 with text — which is the single fact needed to decide whether
this is the ingress or the hub, and it is currently thrown away on every flap.

What each flap costs

• The in-flight issue is briefly withdrawn. The disconnect path calls
  bookReleaseCooldown (contribute_ws.go:2814) so the issue is not instantly
  re-admissible — correct as designed (it closes the /contribute sending "dupe" PRs #2356 duplicate-PR race),
  but it means a flapping session repeatedly pulls its own issue out of the
  ready-work queue.
• A GitHub token is re-minted every cycle — GitHub token refreshed appears
  in all four logged reconnects, against a wsTokenRefreshPeriod of 50 minutes.
• The shared activity feed fills with churn. joined/left are ordinary
  activity entries, so one flapping contributor crowds real picked up /
  completed rows out of the operator's view and out of /api/contribute/activity.
• fleet_size samples become a coin flip — the hourly metric reads 1 or 0
  depending on which side of a flap the sample lands.
• Each dial re-occupies a slot against the hub-wide maxWSConnections = 50.

Suggested order of work

1. Log (code, reason) in the relay's close handler. One line, no behavior change.
2. Have hub-side closes send a real Close frame with a code and a reason before
   closing — at minimum the heartbeat/cleanup paths, which today say nothing at all.
3. With 1 and 2 in place, one flap tells you whether the hub closed it (and why)
   or something in the ingress path did. Fix that.

Reported from a just contribute-hive claude local session on Linux against
hosted-kubestellar-hive-ojv6, 2026-08-29, working #5055.

[kubestellar-hive]

Scanner verification @ fad4ccc — both observability gaps confirmed; one diagnostic lead

Hub side: every close is bare. heartbeatLoop (src/pkg/dashboard/contribute_ws.go:3628-3650) calls c.ws.Close() directly on both heartbeat timeout and ping-write failure — no close frame, so the peer always sees 1006 with empty reason. Same for other hub-side closes.

Relay side: the only evidence is discarded. hub.ws.on('close', () => {...}) (bin/contributor-relay.sh:2553) ignores the (code, reason) arguments the ws library delivers and logs only Connection to ... closed.

Diagnostic lead for the exactly-30s deaths: both sides tick at 30s (wsHeartbeatInterval = 30 * time.Second, contribute_ws.go:34; HEARTBEAT_INTERVAL_MS = 30000, relay:142), so a 30s lifetime is death at the first heartbeat tick. lastPong is initialized to time.Now() at registration (contribute_ws.go:2974), so it is not a zero-time false timeout — but the hub's first-tick c.send(ping) failing takes the heartbeat ping failed, closing branch, which would produce exactly-30s lifetimes and IS hub-logged. Grepping hub logs for [contribute-ws] heartbeat ping failed / heartbeat timeout against the flap timestamps would confirm or eliminate the hub before blaming ingress.

Implementation plan (the two one-liners, as scoped by the report)

1. Hub: before each c.ws.Close(), send a close frame with a reason, e.g.
   c.ws.WriteControl(websocket.CloseMessage, websocket.FormatCloseMessage(websocket.ClosePolicyViolation, "heartbeat timeout"), time.Now().Add(time.Second)) (reason ping write failed on the other branch). Factor a tiny closeWithReason(c, code, reason) helper since there are several bare-Close sites.
2. Relay: hub.ws.on('close', (code, reason) => { console.log(\Connection to ${hub.url} closed (code=${code} reason=${reason || 'none'}). Reconnecting in ...`); ... })`.
3. Optional third line: include the close code in the left activity-feed event so flap forensics don't require relay logs at all.

---

Analysis by scanner agent (ACMM L4 — issues-only mode)

🐝 Hive Agent: scanner | Instance: hosted-available-oke-11-placeholder-r05x | SHA: fad4ccc

— hive: agent=scanner backend=copilot model=claude-fable-5

[Danathar]

Diagnostic results — the hub is exonerated; the cut is below the application

Both halves of #5107 are now live, and together they answer the question this
issue left open.

The hub side is deployed and working. The same unauthenticated probe that
opened this issue — which received the auth-timeout as 1006 with an empty
reason — now receives a real Close frame:

30.1s msg:   {"type":"auth_failed","reason":"Authentication timeout"}
30.1s CLOSE  code=1008 reason="authentication timeout"

So as of today, every deliberate hub-side close announces itself with a code
and a reason.

The flapping continues, and every close is still 1006 with no frame. From
a live container-mode relay (image with the merged relay, against
hosted-kubestellar-hive-ojv6), every single disconnect logs:

closed (code=1006 abnormal closure — no close frame; the socket was cut
(network, proxy, or an abrupt peer close)). Reconnecting in 1000ms...

With the hub provably sending frames on its own closes, uniform 1006 means the
socket is being cut below the hub's application layer — the ingress/proxy
path in front of the hosted spoke. The hub process is ruled out.

Cadence (close-to-close gaps from one observation window, timestamps UTC):

15:48:53  +421s
15:49:54  +61s
15:54:55  +301s
15:55:57  +61s
15:59:19  +202s

Note the repeating shape: a long-lived connection dies, its replacement dies
~61s later, then a longer-lived one again. The ~60s second-connection lifetime
is suggestive of a proxy idle/read timeout — but both sides heartbeat every
30s, which should reset any ordinary idle timer, and the 300–420s survivors
rule out a hard connection-duration cap. So the precise ingress mechanism is
still open; what is no longer open is where to look.

Next step is infrastructure, not code: the WebSocket/idle-timeout
configuration of whatever fronts hosted-kubestellar-hive-ojv6.hive.kubestellar.io
(ingress controller / LB). That is outside this repo's tree, so leaving this
issue open as the tracking point for it.

[Danathar]

Narrowing the ingress suspect — what is and isn't in this repo

Checked how far this repo's own config reaches:

• The spoke's Ingress annotations are already correct. saas_provision.go
  emits the /api/contribute Ingress with
  nginx.ingress.kubernetes.io/proxy-read-timeout: "3600" and
  proxy-send-timeout: "3600", so nginx itself should hold a heartbeating
  WebSocket for an hour. Nothing to fix at that layer.
• The layer this repo does NOT control: the hosted spokes run on OKE (per
  the hive/hosted-available-oke-* labels and the OCI provisioning in
  saas_provision.go), so an OCI load balancer sits in front of the
  ingress-nginx controller. Its install — the controller's
  Service type=LoadBalancer and its annotations — is not in this tree (only
  the error-pages addon in the ingress-nginx namespace is).

For whoever operates the cluster, the specific things to look at on the
ingress-nginx controller Service / its OCI LB:

1. service.beta.kubernetes.io/oci-load-balancer-connection-idle-timeout —
   OCI LBs default to 300 seconds. Several observed connection lifetimes
   cluster near 300–420s, which fits. The caveat that keeps this from being a
   clean diagnosis: both sides heartbeat every 30s, which should reset an
   ordinary idle timer — unless the LB counts idleness per-direction or the
   heartbeats coalesce oddly. Raising it costs nothing and is the first knob
   to turn.
2. The repeating ~61s second-connection lifetime (a long-lived connection
   dies, its replacement dies at ~61s, then long-lived again) doesn't fit an
   idle timeout at all — it looks more like backend-set churn / connection
   draining: if the LB's backends or the controller's endpoints are being
   re-synced periodically, established connections get cut regardless of
   traffic. Worth checking the LB's backend-set update events and whether
   anything (node autoscaling, health-check flaps, cert renewals reloading
   nginx) coincides with the drop times. An nginx reload is a particularly
   good fit: reloads kill WebSocket connections held by old workers after
   worker-shutdown-timeout, and a controller reloading on a config/endpoint
   sync would produce exactly this all-1006, traffic-independent pattern.
3. If the controller logs are reachable: kubectl -n ingress-nginx logs around
   the timestamps above (15:48:53Z, 15:49:54Z, 15:54:55Z, 15:55:57Z,
   15:59:19Z today) — a reloading line at those moments would settle it.

Summary of where this stands: hub application layer ruled out (it now sends
close frames; the flaps carry none), repo-side ingress annotations verified
correct, and the remaining suspects — OCI LB idle timeout and nginx controller
reload/drain behavior — live in the cluster install. Evidence and timestamps
above; this issue stays open as the tracking point.

[Danathar]

/assign @clubanderson

Andy — this one has reached the point where it needs someone with cluster
access, and you're the only one of us with kubectl on the hosted spokes. The
client side and the repo side are both done: the hub now sends close frames on
its deliberate closes (#5107, confirmed live), every flap is still a
frameless 1006, and the repo's own Ingress annotations check out — full
evidence in the two comments above.

The specific asks, both quick:

1. kubectl -n ingress-nginx logs on the oke-11 cluster around today's drop
   timestamps (15:48:53Z, 15:49:54Z, 15:54:55Z, 15:55:57Z, 15:59:19Z) — a
   reloading line at those moments would settle it as nginx reload/drain
   killing held WebSockets.
2. The ingress-nginx controller Service's OCI LB annotation
   service.beta.kubernetes.io/oci-load-balancer-connection-idle-timeout —
   OKE defaults to 300s, and several observed lifetimes cluster at 300–420s.
   Raising it costs nothing even if it turns out not to be the whole story.

Not urgent — the relay reconnects in 1s and work completes — but each flap
books a release cooldown on the in-flight issue and churns the activity feed,
and with the contributor fleet grinding the TUI queue all day it adds up.

[Danathar]

Reopening — this was auto-closed by #5107's Fixes #5090 line when that PR merged, which was a mis-tag on my part: #5107 is the instrumentation (and its own body says so), not the fix. The flapping itself is still live — the diagnostic evidence above was collected after the auto-close — and the remaining action is the cluster-side check assigned above. Should stay open until the ingress/LB cause is found and fixed.

[Danathar]

Still flapping as of 17:41Z (2026-08-29) — now visible in the dashboard feed

Live Activity on the hosted spoke's dashboard, from the operator's screen:

Three things this adds to the record:

1. The cadence is unchanged — entered the hive / left the hive pairs at
   ~60–90s intervals (1:40 PM and 1:41 PM EDT = 17:40–17:41Z), matching the
   frameless-1006 signature measured this morning. Hours later, same pattern.
2. The drops now churn visible release entries on live work. Each flap
   produces released: connection lost — issue kubestellar/hive#5130 …. Those
   rows are 🐛 fix: record released contributor tasks in the activity feed #5108 (merged today) doing its job — before it, these were the
   invisible pickups-with-no-terminal-event this issue's history describes. The
   task itself survives (the relay reconnects in ~1s and re-adopts before the
   release cooldown lapses), so this is churn, not lost work — but it's now
   three feed rows per flap, every minute or two, all day.
3. Measurement is trivial now: when the ingress knobs are turned
   (oci-load-balancer-connection-idle-timeout / nginx reload behavior per the
   comments above), success looks like this exact three-row pattern collapsing
   into one long-lived connection — checkable from the dashboard alone, no logs
   needed.

[Danathar]

Filed the reconnect-churn half separately as #5151, so it is not lost once the ingress cause lands.

Deliberately not to be fixed before this issue is: #5151 carries an explicit sequencing warning, because the three-row-per-flap pattern is currently the measuring instrument for verifying the ingress fix from the dashboard. Suppressing it early would blind the diagnosis and leave the flapping untouched.

What #5151 records, with line references against v4 @ 884733c0: the disconnect defer treats a ~1s reconnect as a terminal departure, so each flap books a 10-minute failedTaskCooldownMinutes exclusion on the issue the contributor is still working, writes three activity rows, and clears tokenMintedAt so the 50-minute refresh cycle restarts. With maxActivityEntries = 50, one flapping contributor churns the entire retained feed in under 20 minutes — which is exactly the 19 joined / 19 left (38 of 50 slots) this issue measured.

This issue stays the tracking point for the ingress/LB cause.

[kubestellar-hive]

Scanner verification @ main 7c55f9f

The diagnosability half of this report has landed via #5107 (2e8f0da):

• Hub now sends a Close frame on every hub-initiated close — sendWsClose (src/pkg/dashboard/contribute_ws.go:5262-5273) uses WriteControl(CloseMessage, FormatCloseMessage(code, reason)).
• Relay now records the evidence — describeWsClose (bin/contributor-relay.sh:2889) renders code+reason on the close handler (line 2943) instead of discarding them.

What remains open here is the underlying flap itself. Current state of the signal:

• App-level heartbeats are 30s interval / 90s timeout on both sides (wsHeartbeatInterval/wsHeartbeatTimeout, contribute_ws.go:34-35), so neither side can produce the observed exact-30s lifetimes — consistent with the original analysis that the killer sits in the ingress/network path in front of the hosted spoke.
• With 🐛 fix: make contributor WebSocket closes diagnosable #5107 in place, the next flap cycle should now show either a real close code from the hub (rules the hub in) or a frameless 1006 at the relay (rules it out and points squarely at ingress idle/read timeout, e.g. an nginx proxy_read_timeout-class setting on the hosted spoke's ingress).

Suggested next step: capture one post-#5107 flap log from the hosted spoke and attach the describeWsClose line — that single line should settle which side of the ingress the close originates from. #5151's churn suppression correctly stays sequenced after that confirmation.

---

Filed by scanner agent (ACMM L4 — issues-only mode)

🐝 Hive Agent: scanner | Instance: hosted-available-oke-11-placeholder-r05x | SHA: unknown

— hive: agent=scanner backend=copilot model=claude-fable-5

[clubanderson]

Found an application-layer cause after all: the keepalive was never a WebSocket keepalive

PR #5310 (merged) — the flap had a cause inside this repo, upstream of the ingress question.

The keepalive was implemented entirely in application JSON. The hub sent {"type":"ping"} as an ordinary text frame and the relay answered {"type":"pong"}. websocket.PingMessage appeared nowhere in pkg/dashboard, and the relay never called ws.ping(). No WebSocket protocol-level control frame was ever exchanged, in either direction.

That distinction is invisible to the two endpoints and decisive to everything between them. An L7 proxy may score tunnel idleness on control-frame traffic alone, precisely because application payload can be a long unidirectional stream that proves nothing about liveness. Under such an intermediary a socket carrying a text frame every 30s is still "idle", and gets reaped without a Close frame.

This reconciles the two facts that looked contradictory above:

1. The hub provably sends Close frames on its own hangups after 🐛 fix: make contributor WebSocket closes diagnosable #5107, yet every flap was frameless. Correct — the close wasn't the hub's.
2. "Both sides heartbeat every 30s, which should reset any ordinary idle timer." It doesn't, if the timer only counts control frames. The heartbeat was real traffic the intermediary was entitled to ignore.

It also fits the shapes the thread couldn't explain: traffic-independence, and lifetimes scattered across 30s/61s/300s/420s rather than one clean constant — what you get when independent idle timers at different layers each expire against a tunnel that never proves itself alive.

The fix (additive; JSON ping/pong untouched, so old relays and old hubs both keep working): the hub sends a real Ping control frame alongside the JSON one each tick and credits inbound protocol Pongs as liveness; the relay does the same. Both halves were needed together — the hub now pings with a control frame, and any conforming client answers that with a control-frame Pong automatically with no relay code at all, so crediting only the JSON pong would have false-timed-out those clients and manufactured a new flap. Also converted the heartbeat's ping-write-failure branch from a bare Close() to closeWithReason, a site #5107 missed.

This does not make the cluster-side asks moot, and I'd leave this issue open. I have no kubectl on the hosted spokes, so this is unverified against a live flap. Two things still stand:

• Raising oci-load-balancer-connection-idle-timeout is still worth doing.
• If the real killer is nginx reload/drain rather than an idle timer, no keepalive can help — reloads cut held sockets regardless of traffic.

What changed is the diagnosis: the application-layer cause is now removed from the list, so a flap that survives #5310 is unambiguously reload/drain, and the cluster-side investigation narrows to a single suspect. Per the earlier comment, success is measurable from the dashboard alone — the three-row-per-flap pattern collapsing into one long-lived connection.

Sequencing note for #5151 is unchanged and worth restating: that pattern is currently the measuring instrument for this verification. Keep it until the cadence is confirmed collapsed, then suppress it. #5310 touches none of the accounting path — no disconnect defer, no bookReleaseCooldown, no activity writes, no tokenMintedAt — so the two are independent.