[Bug][Backend][DockerMonitor] All swarm node events published as 'docker.node.unknown' with empty hostname — ~21 junk RabbitMQ msgs/min for healthy nodes #541
Assignees
spikerj (Joseph Spiker)
Clear assignees
spikerj (Joseph Spiker)
No Assignees
Notifications
Due Date
No due date set.
Dependencies
No dependencies set.
Reference: spikerj/spikersoft-issues#541
Reference in New Issue
Block a user
QA log watch, 2026-07-13 ~19:10Z. Found while confirming healthy nodes: docker-monitor (the correct-spelled stack, running fine since the #513 exit-0 fix) is misclassifying EVERY swarm node event.
Observed:
Cluster event: docker.node.unknown for <nodeId> ()logged + published in pairs, ~21 msgs/min to RabbitMQ. Last 30 min: 646 published events, 100% action='unknown', hostname always empty '()', spanning all 8 reachable non-SERVER nodes (all Ready — 0 of these are real incidents). dreamstream7/5/1 etc. are healthy and pingable while being reported as 'unknown'.Root cause (spikersoft-backend, SpikerSoft.EventHandlers.DockerMonitor/Services/DockerClusterEventSource.cs):
var action = message.Status ?? "unknown"— Docker.DotNet'sMessage.Statusis the LEGACY container-event field. Node/swarm-scope events carry the verb inMessage.Action(= 'update'), so Status is null and every node event becomes 'unknown'. Fix:message.Action ?? message.Status ?? "unknown".com.docker.swarm.node.hostname/node.hostnameattribute keys — node events put the hostname inActor.Attributes["name"]→ NodeHostname is always null → the '()' in logs and events with no node identity.The repo's own test asserts the intended contract: SpikerSoft.Data.Tests/Services/ClusterRoutingKeyTests.cs:27 expects routing key
cluster.docker.node.update— live traffic emitscluster.docker.node.unknown, so the mapping test passes while the SOURCE mapping is wrong (test feeds ('docker','node','update') directly and never exercises MapMessage against a real node Message).Impact: (a) RabbitMQ + ClusterEventsConsumerService chew ~30k junk messages/day; (b) any consumer keying on node state/hostname gets garbage — a REAL node-down event is indistinguishable from heartbeat noise (relevant right now: dreamstream6 IS down, #539, and these events can't tell you); (c) DockerPhaseMapper.FromAction('node','unknown') can't map a phase.
Suggested fix: use Message.Action (fallback Status); read hostname from Actor.Attributes['name']; consider debouncing/filtering periodic node 'update' heartbeats to state TRANSITIONS only (ready<->down/unknown) so the bus only sees signal. Add a MapMessage unit test using a realistic node-event Message fixture.
Related: #513 (this service's deploy saga), #510-B (auto-reconciler lives in the same service — unaffected, it reads tasks directly).
Backend PR #265: Action-first verb mapping, node-only name-attr hostname fallback (container names can't masquerade as hostnames), and heartbeat debounce — node updates without a state transition drop before the bus, transitions always pass. MapMessage now tested against realistic node Message payloads (the gap ClusterRoutingKeyTests couldn't see). Verification steps in the PR; note #539's dreamstream6-down should become clearly visible on the bus once deployed.
QA watch 2026-07-13 ~20:44Z — fix VERIFIED in master, not yet live. f0b846a0 lands all three recommendations: Message.Action-first verb resolution, hostname from Actor.Attributes['name'], and heartbeat debounce (state-transition-only publishing). Test gap closed properly: new DockerClusterEventSourceMappingTests exercises MapMessage against realistic payloads — NodeUpdate_MapsActionAndHostname_FromRealisticPayload, ContainerEvent_StillUsesLegacyStatus_AndNeverStealsNameAsHostname, NodeUpdate_WithoutStateChange_IsHeartbeat, NodeStateTransition_IsSignal, NonUpdateNodeActions_AndOtherTypes_AreNeverHeartbeats. 32/32 green per commit.
Live state: docker-monitor service spec still 17:01Z (pre-fix image) — junk events still flowing (~28/min over the last 5 min). Close condition: after the docker-monitor image rebuilds + the stack redeploys, confirm (a) 'docker.node.unknown' disappears from its logs, (b) hostnames populate, and (c) event volume drops to state transitions only. I'll verify on a later pass once it rolls.
QA watch 2026-07-13 ~21:04Z — heads-up: the fix's image build NEVER FIRED. f0b846a0 merged ~20:39Z touching SpikerSoft.EventHandlers.DockerMonitor/** (squarely inside spikersoft-docker-monitor.yml's push path filter), but no Docker Monitor workflow task appears in the last 50 CI tasks, and the registry image is still yesterday's (spikersoft-docker-monitor :latest 07-12 23:22). So the junk-event spam (~28/min) will continue even after the next fleet redeploy — the fixed image doesn't exist yet.
Actionable: the workflow has workflow_dispatch — a manual dispatch of 'Docker Monitor' builds + pushes the fixed image (then the stack redeploy activates it). Separately worth a glance WHY the path-triggered run didn't fire (other workflows from the same merge wave did) — if Gitea silently skipped it, other path-filtered workflows could be affected the same way; compare with the #513 smoke-test commit 8a83a2ab/217da6ee which also touched CI around the same time.
QA Team — watch 2026-07-14 ~02:35Z: the junk
docker.node.unknownstream now has a measurable downstream cost beyond RabbitMQ spam. The API is throwing on it:6 such errors in the last hour, arriving in bursts (5 within ~10s at 02:27–02:28Z) — i.e., the API spends retry cycles and SignalR timeouts on events that carry no information. Raises the value of getting the fixed image actually built (per the earlier note, the workflow never fired — manual dispatch of 'Docker Monitor' still pending). Also note new #554: the jetson-influxdb fleet is churning containers every ~10s on six nodes, feeding docker-monitor a steady event stream on top of this.
QA Team — refinement/correction 2026-07-14 ~03:10Z on the SignalR errors noted earlier: Jaeger traces show the 02:27:48–49Z
ForwardClusterEventToSignalRfailures were Redis PUBLISH timeouts on the SignalR backplane (Timeout awaiting response... command=PUBLISH, 5000ms), and redis-cluster logs show why: a shard failover at 02:28:27Z in shard 7f3f2473 (master handoff, FAIL state cleared 02:31:23Z — self-healed, no slots lost; second failover of the night after the 20:48Z one verified in #539).So, correcting my earlier framing: the junk
docker.node.unknownevents didn't cause those timeouts — a ~40s redis write-stall did, and the junk events were simply the traffic in flight. Two takeaways stand though: (1) the junk stream is what the API was burning those retry cycles on, and (2) any real SignalR notifications in the 02:27:48–02:28:27 window likely timed out too — silently, from the user's perspective. The fix-image dispatch ask is unchanged.QA verification — closing. Fix confirmed present in current master (HEAD bc55a9ff).
DockerClusterEventSourcenow classifies the verb Action-first (message.Action ?? message.Status ?? "unknown", DockerClusterEventSource.cs:187) and derives the node hostname with a node-scoped fallback to the actornameattribute (lines 193-197), and a heartbeat debounce drops no-op nodeupdateevents. Landed in PR #265 (commit f0b846a0, verified ancestor of master). Regression testDockerClusterEventSourceMappingTestsasserts a realistic node payload maps to Action=update / hostname=dreamstream7 and that a container name never becomes a hostname. The 'docker.node.unknown / empty hostname' symptom is resolved in code.