-
Notifications
You must be signed in to change notification settings - Fork 150
network: detect a wedged discv5 socket (operator health check + boot-node /healthz) #2982
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
base: stage
Are you sure you want to change the base?
Changes from all commits
File filter
Filter by extension
Conversations
Jump to
Diff view
Diff view
There are no files selected for viewing
| Original file line number | Diff line number | Diff line change |
|---|---|---|
|
|
@@ -78,6 +78,9 @@ type DiscV5Service struct { | |
|
|
||
| conn *net.UDPConn | ||
| sharedConn *SharedUDPConn | ||
| // socketConn wraps conn to time socket reads; the post-fork listener drains | ||
| // through it, so DiscoveryStale can detect a wedged socket. | ||
| socketConn *TimedConn | ||
|
|
||
| ssvConfig *networkconfig.SSV | ||
| subnets commons.Subnets | ||
|
|
@@ -159,6 +162,21 @@ func (dvs *DiscV5Service) close() error { | |
| return nil | ||
| } | ||
|
|
||
| // DiscoveryStale reports whether the discv5 socket has gone unread for longer | ||
| // than grace — the sign discovery has wedged. False before the listener is built | ||
| // (or after a failed init), when there's nothing to judge. | ||
| // | ||
| // The operator health check polls this periodically, so it doubles as the | ||
| // sampling point for the read-staleness gauge. | ||
| func (dvs *DiscV5Service) DiscoveryStale(grace time.Duration) bool { | ||
| if dvs.socketConn == nil { | ||
| return false | ||
| } | ||
| age, ok := dvs.socketConn.ReadStaleness() | ||
| recordDiscoveryReadStaleness(dvs.ctx, int64(age.Seconds())) | ||
| return ok && age > grace | ||
| } | ||
|
|
||
| // Self returns self node | ||
| func (dvs *DiscV5Service) Self() *enode.LocalNode { | ||
| return dvs.dv5Listener.LocalNode() | ||
|
|
@@ -402,13 +420,20 @@ func (dvs *DiscV5Service) initDiscV5Listener(discOpts *Options) (err error) { | |
| } | ||
| dvs.conn = udpConn | ||
|
|
||
| // Wrap the socket for liveness (see DiscoveryStale): only the post-fork | ||
| // listener drains it, so only it gets the wrapped conn — the pre-fork | ||
| // listener reads sharedConn's buffer, not the socket. | ||
| socketConn := NewTimedConn(udpConn) | ||
| dvs.socketConn = socketConn | ||
|
|
||
| // Registered before anything else can fail, so every error path below | ||
| // releases the socket. Runs last of the deferred cleanups, by which point a | ||
| // listener may already have closed it. | ||
| defer func() { | ||
| if err != nil { | ||
| _ = udpConn.Close() | ||
| dvs.conn = nil | ||
| dvs.socketConn = nil | ||
| } | ||
| }() | ||
|
|
||
|
|
@@ -453,7 +478,7 @@ func (dvs *DiscV5Service) initDiscV5Listener(discOpts *Options) (err error) { | |
| return err | ||
| } | ||
|
|
||
| dv5PostForkListener, err := listenV5(udpConn, localNode, *dv5PostForkCfg) | ||
| dv5PostForkListener, err := listenV5(socketConn, localNode, *dv5PostForkCfg) | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Finding 2 · [MINOR] The wiring that makes the whole feature work is untested, and it fails open Every test in this PR exercises If a future refactor of The package already has the machinery to pin this cheaply: Suggested fix: Add a wiring assertion using the existing stub pattern: // TestInitDiscV5Listener_WrapsPostForkConn pins the wiring the wedge detector
// depends on: the post-fork listener (the only one that drains the socket) must
// get the TimedConn, and the pre-fork one must get the SharedUDPConn.
func TestInitDiscV5Listener_WrapsPostForkConn(t *testing.T) {
orig := listenV5
t.Cleanup(func() { listenV5 = orig })
var conns []discover.UDPConn
listenV5 = func(conn discover.UDPConn, ln *enode.LocalNode, cfg discover.Config) (Listener, error) {
conns = append(conns, conn)
return orig(conn, ln, cfg)
}
dvs := testingDiscovery(t)
t.Cleanup(func() { require.NoError(t, dvs.Close()) })
require.Len(t, conns, 2)
require.Same(t, dvs.socketConn, conns[0], "post-fork listener must read through TimedConn")
require.IsType(t, &SharedUDPConn{}, conns[1])
}And a one-line addition to the existing
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Done — added Left the boot-node |
||
| if err != nil { | ||
| return fmt.Errorf("could not create discV5 listener: %w", err) | ||
| } | ||
|
|
||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,35 @@ | ||
| package discovery | ||
|
|
||
| import ( | ||
| "testing" | ||
| "time" | ||
|
|
||
| "github.com/stretchr/testify/require" | ||
| ) | ||
|
|
||
| // TestDiscV5Service_DiscoveryStale covers the operator-side liveness accessor: | ||
| // nil before the listener is built, never stale until the socket has actually | ||
| // been read, and driven by the wrapped socket's last-read time thereafter. | ||
| func TestDiscV5Service_DiscoveryStale(t *testing.T) { | ||
| // No socket wrapped yet (not-yet / failed init) → never stale. | ||
| require.False(t, (&DiscV5Service{}).DiscoveryStale(3*time.Minute)) | ||
|
|
||
| sc := NewTimedConn(nil) | ||
| t0 := sc.LastRead() | ||
| dvs := &DiscV5Service{ctx: t.Context(), socketConn: sc} | ||
|
|
||
| // Never read → never stale, however long it sits idle: an operator that has | ||
| // simply had no inbound discv5 traffic yet must not be flagged as wedged. | ||
| sc.now = func() time.Time { return t0.Add(time.Hour) } | ||
| require.False(t, dvs.DiscoveryStale(3*time.Minute), "never-read socket is not a wedge") | ||
|
|
||
| // A read arms the signal, stamped at t0. | ||
| sc.read.Store(true) | ||
| sc.lastReadUnixNano.Store(t0.UnixNano()) | ||
|
|
||
| sc.now = func() time.Time { return t0.Add(2 * time.Minute) } | ||
| require.False(t, dvs.DiscoveryStale(3*time.Minute), "read within grace → not stale") | ||
|
|
||
| sc.now = func() time.Time { return t0.Add(4 * time.Minute) } | ||
| require.True(t, dvs.DiscoveryStale(3*time.Minute), "read then unread past grace → stale") | ||
| } |
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,84 @@ | ||
| package discovery | ||
|
|
||
| import ( | ||
| "net" | ||
| "net/netip" | ||
| "sync/atomic" | ||
| "time" | ||
|
|
||
| "github.com/ethereum/go-ethereum/p2p/discover" | ||
| ) | ||
|
|
||
| // TimedConn wraps a discv5 UDP socket and records when it was last read from. | ||
| // | ||
| // A discv5 listener drains its socket only through ReadFromUDPAddrPort, so a | ||
| // wedged socket — bound but no longer read, leaving discovery silently dead — | ||
| // shows up as a last-read timestamp that stops advancing. StaleFor turns that | ||
| // into a liveness signal, used by both the operator and boot nodes. | ||
| // | ||
| // Only ReadFromUDPAddrPort is overridden; writes, Close and LocalAddr fall | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Might be worth stating the scope here: only the post-fork listener reads through TimedConn, the pre-fork listener reads SharedUDPConn's buffer, so a pre-fork dispatch stall moves neither health signal. The known blocking cause is gone post-#2980, but as written the doc reads as if the wedge signal covers discovery generally. |
||
| // through to the embedded conn. | ||
| type TimedConn struct { | ||
| discover.UDPConn | ||
|
|
||
| lastReadUnixNano atomic.Int64 | ||
| read atomic.Bool // set once the socket has been read at least once | ||
| now func() time.Time // overridable in tests; nil means time.Now | ||
| } | ||
|
|
||
| var _ discover.UDPConn = (*TimedConn)(nil) | ||
|
|
||
| // NewTimedConn wraps conn, seeding the last-read time so LastRead reports a | ||
| // sensible value before the first read. Staleness only arms once the socket has | ||
| // actually been read (see StaleFor). | ||
| func NewTimedConn(conn *net.UDPConn) *TimedConn { | ||
| c := &TimedConn{UDPConn: conn} | ||
| c.lastReadUnixNano.Store(c.nowFn().UnixNano()) | ||
| return c | ||
| } | ||
|
|
||
| func (c *TimedConn) nowFn() time.Time { | ||
| if c.now != nil { | ||
| return c.now() | ||
| } | ||
| return time.Now() | ||
| } | ||
|
|
||
| // ReadFromUDPAddrPort delegates and, on success, records the read time and marks | ||
| // the socket as having been read. Errors leave both untouched, so a closed or | ||
| // failing socket can't look freshly drained. | ||
| func (c *TimedConn) ReadFromUDPAddrPort(b []byte) (n int, addr netip.AddrPort, err error) { | ||
| n, addr, err = c.UDPConn.ReadFromUDPAddrPort(b) | ||
| if err == nil { | ||
| c.lastReadUnixNano.Store(c.nowFn().UnixNano()) | ||
| c.read.Store(true) | ||
| } | ||
| return n, addr, err | ||
| } | ||
|
|
||
| // LastRead reports when a packet was last read from the socket. | ||
| func (c *TimedConn) LastRead() time.Time { | ||
| return time.Unix(0, c.lastReadUnixNano.Load()) | ||
| } | ||
|
|
||
| // ReadStaleness reports how long the socket has gone unread, and whether it has | ||
| // ever been read. Before the first successful read there is nothing to measure, | ||
| // so ok is false: a socket that has never delivered a packet is not wedged, it | ||
| // has simply had no inbound discv5 traffic yet (unreachable bootnodes, blocked | ||
| // UDP), which a restart cannot fix. | ||
| func (c *TimedConn) ReadStaleness() (age time.Duration, ok bool) { | ||
| if !c.read.Load() { | ||
| return 0, false | ||
| } | ||
| return c.nowFn().Sub(c.LastRead()), true | ||
| } | ||
|
|
||
| // StaleFor reports whether the socket has wedged: it was being drained, then | ||
| // went unread for longer than d. A socket that has never been read is never | ||
| // stale — a wedge can only arise after draining has started, so requiring a | ||
| // prior read rules out the false positive (a healthy node that has simply had | ||
| // no inbound traffic yet) without missing any real wedge. | ||
| func (c *TimedConn) StaleFor(d time.Duration) bool { | ||
|
Contributor
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Finding 3 · [MINOR] No metric or log for read staleness — the only evidence of a wedge is the process exiting The signal is consumed purely as a boolean at the moment of a restart decision. Nothing exports the underlying quantity, so:
The package already has Suggested fix: Export the age as an observable gauge in discoveryReadStalenessGauge = observability.NewMetric(
meter.Float64ObservableGauge(
metricName("discovery.socket.read_staleness"),
metric.WithUnit("s"),
metric.WithDescription("seconds since the discv5 socket was last read"),
),
)Plus a
Contributor
Author
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more. Done, scoped to the operator. Added a synchronous Went with a synchronous gauge rather than an |
||
| age, ok := c.ReadStaleness() | ||
| return ok && age > d | ||
| } | ||
| Original file line number | Diff line number | Diff line change |
|---|---|---|
| @@ -0,0 +1,110 @@ | ||
| package discovery | ||
|
|
||
| import ( | ||
| "errors" | ||
| "net" | ||
| "net/netip" | ||
| "testing" | ||
| "time" | ||
|
|
||
| "github.com/stretchr/testify/require" | ||
| ) | ||
|
|
||
| // fakeUDPConn is a minimal discover.UDPConn so the read path can be exercised | ||
| // without a real socket. | ||
| type fakeUDPConn struct { | ||
| readErr error | ||
| } | ||
|
|
||
| func (f *fakeUDPConn) ReadFromUDPAddrPort(b []byte) (int, netip.AddrPort, error) { | ||
| if f.readErr != nil { | ||
| return 0, netip.AddrPort{}, f.readErr | ||
| } | ||
| n := copy(b, []byte{0x1}) | ||
| return n, netip.MustParseAddrPort("1.2.3.4:30303"), nil | ||
| } | ||
|
|
||
| func (f *fakeUDPConn) WriteToUDPAddrPort(b []byte, _ netip.AddrPort) (int, error) { | ||
| return len(b), nil | ||
| } | ||
|
|
||
| func (f *fakeUDPConn) Close() error { return nil } | ||
| func (f *fakeUDPConn) LocalAddr() net.Addr { return nil } | ||
|
|
||
| // TestTimedConn_SeededNotStale: a freshly constructed conn is not stale — it has | ||
| // not been read yet, so there is nothing to flag at startup. | ||
| func TestTimedConn_SeededNotStale(t *testing.T) { | ||
| c := NewTimedConn(nil) | ||
| require.False(t, c.StaleFor(3*time.Minute)) | ||
| } | ||
|
|
||
| // TestTimedConn_NeverReadNeverStale: a socket that has never delivered a packet | ||
| // is not a wedge — it's a node with no inbound discv5 traffic (unreachable | ||
| // bootnodes, blocked UDP), which a restart cannot fix — so it must never report | ||
| // stale, however much time passes. Once it has been read, staleness arms as | ||
| // usual. | ||
| func TestTimedConn_NeverReadNeverStale(t *testing.T) { | ||
| c := NewTimedConn(nil) | ||
| t0 := c.LastRead() | ||
|
|
||
| c.now = func() time.Time { return t0.Add(time.Hour) } | ||
| require.False(t, c.StaleFor(3*time.Minute), "never-read socket must not be stale") | ||
| _, ok := c.ReadStaleness() | ||
| require.False(t, ok, "never-read socket has no staleness to report") | ||
|
|
||
| // A successful read arms the signal; from the read time on, it goes stale. | ||
| c.UDPConn = &fakeUDPConn{} | ||
| _, _, err := c.ReadFromUDPAddrPort(make([]byte, 16)) | ||
| require.NoError(t, err) | ||
| age, ok := c.ReadStaleness() | ||
| require.True(t, ok, "a read arms the signal") | ||
| require.Zero(t, age, "staleness resets to the read time") | ||
|
|
||
| c.now = func() time.Time { return t0.Add(time.Hour + 4*time.Minute) } | ||
| require.True(t, c.StaleFor(3*time.Minute), "past grace after a read") | ||
| } | ||
|
|
||
| // TestTimedConn_StaleForTransitions pins the staleness boundary using an | ||
| // injected clock, so no real time passes. | ||
| func TestTimedConn_StaleForTransitions(t *testing.T) { | ||
| c := NewTimedConn(nil) | ||
| c.read.Store(true) // staleness only arms once the socket has been read | ||
| t0 := c.LastRead() | ||
|
|
||
| c.now = func() time.Time { return t0.Add(2 * time.Minute) } | ||
| require.False(t, c.StaleFor(3*time.Minute), "within grace") | ||
|
|
||
| c.now = func() time.Time { return t0.Add(3 * time.Minute) } | ||
| require.False(t, c.StaleFor(3*time.Minute), "exactly at grace is not yet stale") | ||
|
|
||
| c.now = func() time.Time { return t0.Add(4 * time.Minute) } | ||
| require.True(t, c.StaleFor(3*time.Minute), "past grace") | ||
| } | ||
|
|
||
| // TestTimedConn_ReadStampsLastRead: a successful read advances the timestamp, | ||
| // so an actively drained socket stays fresh. | ||
| func TestTimedConn_ReadStampsLastRead(t *testing.T) { | ||
| c := &TimedConn{UDPConn: &fakeUDPConn{}} | ||
| t0 := time.Now() | ||
| c.lastReadUnixNano.Store(t0.UnixNano()) | ||
| c.now = func() time.Time { return t0.Add(time.Hour) } | ||
|
|
||
| n, addr, err := c.ReadFromUDPAddrPort(make([]byte, 16)) | ||
| require.NoError(t, err) | ||
| require.Equal(t, 1, n) | ||
| require.Equal(t, netip.MustParseAddrPort("1.2.3.4:30303"), addr) | ||
| require.Equal(t, t0.Add(time.Hour).UnixNano(), c.LastRead().UnixNano()) | ||
| } | ||
|
|
||
| // TestTimedConn_FailedReadDoesNotStamp: a read error must leave the timestamp | ||
| // untouched, so a wedged/closed socket cannot look freshly drained. | ||
| func TestTimedConn_FailedReadDoesNotStamp(t *testing.T) { | ||
| c := &TimedConn{UDPConn: &fakeUDPConn{readErr: errors.New("boom")}} | ||
| t0 := time.Now() | ||
| c.lastReadUnixNano.Store(t0.UnixNano()) | ||
| c.now = func() time.Time { return t0.Add(time.Hour) } | ||
|
|
||
| _, _, err := c.ReadFromUDPAddrPort(make([]byte, 16)) | ||
| require.Error(t, err) | ||
| require.Equal(t, t0.UnixNano(), c.LastRead().UnixNano(), "errored read must not stamp") | ||
| } |
Uh oh!
There was an error while loading. Please reload this page.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Should we distinguish the never-read state in the gauge?
Right now "read 200ms ago" and "never read since boot" both record 0 and never-read is precisely the state the health check deliberately ignores, so it's the one you'd want visible to a human for alerting.
A sentinel (-1) or a companion read-ever metric would keep it distinguishable. Also, since this only records when Healthy() reaches the staleness check, the series goes quiet whenever isReady/discoveryFailed short-circuit earlier: i.e. exactly when discovery is broken.