Bug: Getting EOF on connections #21

Closed
opened 2026-07-05 16:13:24 +01:00 by danny · 5 comments
danny commented 2026-07-05 16:13:24 +01:00 (Migrated from gitlab.keyop.co.uk)

We are sometimes seeing connections logging an 'EOF' and failing to connect, as in the logs below:

Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul  5 16:12:34.162 DBG sshtunnel/sshtunnel.go:356 sshConn.startTunnel(0/10.194.100.188/443): Accepted connection - opening '127.0.0.1:40213->10.194.100.188:443'
Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul  5 16:12:34.162 ERR sshtunnel/sshtunnel.go:365 sshConn.startTunnel: Failed to dial destination '10.194.100.188:443': EOF
Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul  5 16:12:34.162 DBG sshtunnel/sshtunnel.go:356 sshConn.startTunnel(0/10.194.100.188/443): Accepted connection - opening '127.0.0.1:40213->10.194.100.188:443'
Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul  5 16:12:34.162 ERR sshtunnel/sshtunnel.go:365 sshConn.startTunnel: Failed to dial destination '10.194.100.188:443': EOF

Determine the cause and fix.

We are sometimes seeing connections logging an 'EOF' and failing to connect, as in the logs below: ``` Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul 5 16:12:34.162 DBG sshtunnel/sshtunnel.go:356 sshConn.startTunnel(0/10.194.100.188/443): Accepted connection - opening '127.0.0.1:40213->10.194.100.188:443' Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul 5 16:12:34.162 ERR sshtunnel/sshtunnel.go:365 sshConn.startTunnel: Failed to dial destination '10.194.100.188:443': EOF Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul 5 16:12:34.162 DBG sshtunnel/sshtunnel.go:356 sshConn.startTunnel(0/10.194.100.188/443): Accepted connection - opening '127.0.0.1:40213->10.194.100.188:443' Jul 05 16:12:34 marvin.keyop.co.uk nfq_forwarder[1419894]: Jul 5 16:12:34.162 ERR sshtunnel/sshtunnel.go:365 sshConn.startTunnel: Failed to dial destination '10.194.100.188:443': EOF ``` Determine the cause and fix.
danny commented 2026-07-05 16:15:01 +01:00 (Migrated from gitlab.keyop.co.uk)

changed the description

changed the description
danny commented 2026-07-05 17:46:44 +01:00 (Migrated from gitlab.keyop.co.uk)

mentioned in commit 60fbf474ea

mentioned in commit 60fbf474ea178666f2df44c1df764be40f1de903
danny commented 2026-07-05 17:47:12 +01:00 (Migrated from gitlab.keyop.co.uk)

mentioned in merge request !63

mentioned in merge request !63
danny commented 2026-07-05 17:47:37 +01:00 (Migrated from gitlab.keyop.co.uk)

Root cause

sshConnections.connection() (internal/nfq_forwarder/nfq_forwarder.go) dials the SSH connection to the jump host once on first use, then caches that single *sshtunnel.Conn forever - every subsequent packet on that queue reuses the same cached client, with no liveness check.

sshtunnel.Dial also set no SSH keepalive at all - nothing periodically pings the jump host, so golang.org/x/crypto/ssh's connection has no way to notice a transport that has died silently (e.g. a NAT/firewall idle timeout dropping the TCP connection without either end sending a FIN/RST).

Once that underlying connection dies, the next attempt to open a channel to the real destination (sshClient.Dial inside startTunnel) fails immediately with EOF - exactly the error in this ticket's log excerpt. Since nothing ever evicted the dead connection from the pool, every subsequent packet kept hitting the same broken client and logging the same EOF, forever, until the whole process was restarted.

It's actually worse than "logs an error and retries": once a tunnel's DNAT rule exists for a destination, NFQUEUE is never consulted again for it (by design, for normal operation - see deleteDNATRuleForTunnel's doc comment). So a destination whose dial failed even once stayed silently DNAT'd into a dead end forever, with no way to self-heal - not just the specific destination in the log excerpt, but any destination behind that jump host connection from that point on.

Fix (MR !63)

Three pieces, working together:

  1. Keepalive - sshtunnel.Conn now runs a goroutine (started by Dial) that periodically sends an SSH keepalive@openssh.com request and force-closes the connection if no reply arrives within one interval. Configurable via ssh_keepalive_interval_seconds in a --config YAML file, default 30s.
  2. Eviction - sshtunnel.Conn.Wait() blocks until the connection dies for any reason. sshConnections.connection() now spawns a goroutine that calls this right after a successful dial and removes the connection from the pool once it returns, so the next packet triggers a fresh dial instead of reusing a client whose transport has already failed.
  3. Tunnel self-healing - sshtunnel.Conn.SetTunnelFailedHook lets a tunnel whose destination dial fails tear itself down (closing its local listener and removing its DNAT rule), so the next connection attempt to that destination gets a fresh chance through NFQUEUE instead of piling up against a tunnel that can never succeed.

Full details, including new tests (a real in-process SSH client/server test harness was added specifically to exercise all three of these against genuine SSH protocol behavior, not mocks), in MR !63.

## Root cause `sshConnections.connection()` (`internal/nfq_forwarder/nfq_forwarder.go`) dials the SSH connection to the jump host once on first use, then caches that single `*sshtunnel.Conn` forever - every subsequent packet on that queue reuses the same cached client, with no liveness check. `sshtunnel.Dial` also set no SSH keepalive at all - nothing periodically pings the jump host, so `golang.org/x/crypto/ssh`'s connection has no way to notice a transport that has died silently (e.g. a NAT/firewall idle timeout dropping the TCP connection without either end sending a FIN/RST). Once that underlying connection dies, the next attempt to open a channel to the real destination (`sshClient.Dial` inside `startTunnel`) fails immediately with `EOF` - exactly the error in this ticket's log excerpt. Since nothing ever evicted the dead connection from the pool, **every subsequent packet kept hitting the same broken client and logging the same EOF, forever, until the whole process was restarted.** It's actually worse than "logs an error and retries": once a tunnel's DNAT rule exists for a destination, NFQUEUE is never consulted again for it (by design, for normal operation - see `deleteDNATRuleForTunnel`'s doc comment). So a destination whose dial failed even once stayed silently DNAT'd into a dead end forever, with no way to self-heal - not just the specific destination in the log excerpt, but any destination behind that jump host connection from that point on. ## Fix (MR !63) Three pieces, working together: 1. **Keepalive** - `sshtunnel.Conn` now runs a goroutine (started by `Dial`) that periodically sends an SSH `keepalive@openssh.com` request and force-closes the connection if no reply arrives within one interval. Configurable via `ssh_keepalive_interval_seconds` in a `--config` YAML file, default 30s. 2. **Eviction** - `sshtunnel.Conn.Wait()` blocks until the connection dies for any reason. `sshConnections.connection()` now spawns a goroutine that calls this right after a successful dial and removes the connection from the pool once it returns, so the *next* packet triggers a fresh dial instead of reusing a client whose transport has already failed. 3. **Tunnel self-healing** - `sshtunnel.Conn.SetTunnelFailedHook` lets a tunnel whose destination dial fails tear itself down (closing its local listener and removing its DNAT rule), so the next connection attempt to that destination gets a fresh chance through NFQUEUE instead of piling up against a tunnel that can never succeed. Full details, including new tests (a real in-process SSH client/server test harness was added specifically to exercise all three of these against genuine SSH protocol behavior, not mocks), in MR !63.
danny commented 2026-07-05 18:00:34 +01:00 (Migrated from gitlab.keyop.co.uk)

mentioned in commit 6e320bbb1b

mentioned in commit 6e320bbb1b8c58705450031daecf8fd759799a75
danny (Migrated from gitlab.keyop.co.uk) closed this issue 2026-07-05 18:00:34 +01:00
Sign in to join this conversation.
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
keyop-go/nfq_forwarder#21
No description provided.