Skip to content

rpc: fix rpc_ep_workers_http being stopped on first request #2364

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.

Sign up for GitHub

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

Open
ChanHongMing wants to merge 1 commit into
base: develop
Choose a base branch
from
Open

rpc: fix rpc_ep_workers_http being stopped on first request #2364

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
3 changes: 3 additions & 0 deletions rpc/client.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -124,6 +124,9 @@ func (c *Client) newClientConn(conn ServerCodec) *clientConn {
}

func (cc *clientConn) close(err error, inflightReq *requestOp) {
// The client-side pool is per-connection (created in newClientConn), so it
// is owned here and must be stopped to release its metric goroutine.
cc.handler.executionPool.Stop()
Comment on lines 126 to +129

@claude claude Bot Aug 17, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟣 Pre-existing (not introduced by this PR): every server-side WS/IPC connection creates its own execution pool via newClientConn → NewExecutionPool(100, 0, "rpcclient", true) (rpc/client.go:122), but newEpMetrics keys its gauges only by the literal service string "rpcclient" (rpc/metrics.go:53-58). With N concurrent WS/IPC connections, their independent 3s reportMetrics tickers all write to the same rpc/ep/workers/rpcclient gauge, so the value flip-flops between unrelated connections, and the Stop() call this PR relocates to clientConn.close leaves a stale last-written value once a connection closes. Not caused by this PR, but it sits directly on the per-connection lifecycle path this PR touches.

Extended reasoning...

What the bug is: newEpMetrics (rpc/metrics.go:53-58) builds its gauge names purely from the pool's service string via metrics.GetOrRegisterGauge, which returns the same singleton gauge object for any two pools sharing that string. newClientConn (rpc/client.go:122) hardcodes NewExecutionPool(100, 0, "rpcclient", true) for every non-HTTP clientConn it creates — and since initialSize=100>0 and report=true, each such pool spawns its own reportMetrics goroutine (execution_pool.go:52-54, 158-176) that ticks every 3 seconds and calls workerCount.Update(s.inFlight.Load()) on the shared rpc/ep/workers/rpcclient gauge (plus its queue/processed siblings).

The code path that triggers it: the key fact to verify was whether this per-connection newClientConn path is actually reachable from the server side for real WS/IPC connections, or only from outbound Dial("ws://...") clients. I traced it directly: rpc/websocket.go:66 and rpc/ipc.go:42 both call Server.ServeCodec, not serveSingleRequest (that function's own doc comment says it is 'used to serve HTTP connections' — confirmed by rpc/http.go:341 being its only caller). ServeCodec (rpc/server.go:142-155) calls initClient(codec, ...), and initClient (rpc/client.go:247-276) spawns go c.dispatch(conn) whenever the codec isn't an *httpConn. dispatch then calls c.newClientConn(codec) to build the per-connection handler. So every inbound WS or IPC connection to a Bor node's RPC server gets its own independent Client/clientConn/SafePool instance, each tagged "rpcclient", each running its own 3s reporter goroutine concurrently with every other open WS/IPC connection.

Why existing code doesn't prevent it: the pool's service label is a static string baked in at the call site, with no per-connection suffix (e.g. remote address or connection ID) to disambiguate. metrics.GetOrRegisterGauge deliberately returns one shared instance per name, so nothing stops two independently-created pools with the same service string from stomping on each other.

Step-by-step proof:

  1. Client A opens a WS connection to the node's RPC endpoint. Server-side: websocket.go → ServeCodec → initClient → dispatch → newClientConn creates poolA = NewExecutionPool(100,0,"rpcclient",true). poolA's reportMetrics goroutine starts, registers/fetches gauge rpc/ep/workers/rpcclient, and every 3s writes poolA.inFlight.
  2. While A is still connected, Client B opens a second WS connection. The same path creates poolB, tagged with the identical service string "rpcclient". newEpMetrics("rpcclient") returns the same gauge object poolA is already updating.
  3. Both reporter goroutines now race independent 3s tickers against the same gauge: whichever fires last wins, so the exported rpc_ep_workers_rpcclient value alternates between A's and B's in-flight counts with no way for an observer to tell which connection it reflects.
  4. Client A disconnects; clientConn.close (the line this PR modifies) calls cc.handler.executionPool.Stop(), which stops poolA's ticker via <-s.close. It never resets/zeroes the shared gauge, so if A's ticker happened to write last, the gauge is now permanently stuck at A's stale last value even though only B (or nobody) is live.

Impact: this is an observability-only defect — no consensus, correctness, or crash impact (Gauge.Update is atomic, so there's no data race, just a semantic collision). It only affects the accuracy of the rpc_ep_workers_rpcclient / rpc_ep_queue_rpcclient / rpc_ep_processed_rpcclient metrics under concurrent WS/IPC server connections.

Why pre-existing: the NewExecutionPool(...,"rpcclient",true) call and newEpMetrics's naming scheme are both untouched by this diff. Before this PR, Stop() was already invoked at the same point in the per-connection lifecycle, just from inside handler.close() (called by clientConn.close) instead of directly in clientConn.close. This PR only relocates where Stop() is called for HTTP's shared server pool bug; it does not change when or how the per-connection client-side pool's Stop() fires relative to the collision. That said, it does now sit on the exact code line (cc.handler.executionPool.Stop()) governing this lifecycle, so it's worth flagging here even though it predates the change.

Suggested fix (non-blocking): include a connection-unique component (e.g. remote address, or an incrementing connection counter) in the service string passed to NewExecutionPool for server-side per-connection pools, or disable report for connections created via ServeCodec/initClient and instead track WS/IPC pool stats in aggregate on the server's own shared pool.

@Sohailghafoor Sohailghafoor Aug 18, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Potential issue: this execution pool uses the static "rpcclient" service label, so multiple concurrent WS/IPC connections share the same rpc_ep_*_rpcclient metric gauges.
Since each connection owns and stops its own pool, closing one connection can also leave the shared gauge with a stale value while other connections are still active.

This appears pre-existing and is not introduced by this PR, so I don't think it should block this change, but it would be worth tracking separately or adding a follow-up issue to make the per-connection metrics distinct or aggregate them correctly.

cc.handler.close(err, inflightReq)
cc.codec.close()
}
Expand Down
7 changes: 6 additions & 1 deletion rpc/handler.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -334,7 +334,12 @@ func (h *handler) close(err error, inflightReq *requestOp) {
h.callWG.Wait()
h.cancelRoot()
h.cancelServerSubscriptions(err)
h.executionPool.Stop()

// The execution pool is deliberately not stopped here. On the server side
// it is shared across all handlers and owned by Server, which stops it in
// Server.Stop(); stopping it per-handler would kill the shared pool's
// metric goroutine on the first request (regression introduced in #1005).
// On the client side the per-connection pool is stopped by clientConn.close.
}

@Sohailghafoor Sohailghafoor Aug 18, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Suggestion: could we add a short comment here explaining that executionPool is the shared server-side HTTP pool and is intentionally stopped by Server.Stop() rather than by each handler?
This ownership distinction is easy to miss and helps prevent reintroducing the first-request metrics regression.

@ChanHongMing ChanHongMing Aug 18, 2026

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Comment added as suggested.


// addRequestOp registers a request operation.
Comment on lines 334 to 345

@claude claude Bot Aug 17, 2026

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 This is a quality/documentation nit: neither handler.close() (rpc/handler.go:334-339) nor clientConn.close() (rpc/client.go:127) documents why the server-side execution pool is stopped centrally while the client-side pool is stopped per-connection. Without a one-line comment explaining this shared-vs-per-connection split, a future refactor could re-add h.executionPool.Stop() to handler.close() (exactly what PR #1005 did) and silently reintroduce the rpc_ep_workers_http regression this PR fixes.

Extended reasoning...

This PR correctly separates ownership of two SafePool instances that look similar but have very different lifecycles. The server-side pool is created once in Server.NewServer (rpc/server.go:74) and shared across every per-request handler instance created in serveSingleRequest (rpc/server.go:189). Because it's shared, it must only be stopped once, centrally, in Server.Stop() (rpc/server.go:234) — which is exactly why this PR removes h.executionPool.Stop() from handler.close(). The client-side pool, by contrast, is created fresh per connection in newClientConn (rpc/client.go:127) via NewExecutionPool(100, 0, "rpcclient", true), so it's correct — and necessary to avoid a goroutine leak — to stop it in clientConn.close().

The problem is that this ownership asymmetry is not written down anywhere. Both call sites now look superficially inconsistent: one path stops its pool on close, the other doesn't. Nothing in the code signals why — a reader has to trace back through Server.NewServer, serveSingleRequest, and newClientConn to reconstruct the shared-vs-per-connection distinction that justifies the difference.

This is not a hypothetical risk: PR #1005 originally added h.executionPool.Stop() to handler.close() believing (reasonably, without this context) that each handler owns its pool and should clean it up on close. That mistake caused the exact bug this PR now fixes — the shared HTTP server pool's metric-reporting goroutine got stopped after the very first request, so rpc_ep_workers_http/rpc_ep_queue_http/rpc_ep_processed_http never got a chance to report. Without a comment recording this history, a future contributor fixing a different client-side pool issue, or generically refactoring handler.close() for symmetry, could easily reintroduce the same regression a second time.

Per this repo's own commenting guidance in AGENTS.md ("gotchas future developers should know", "why simpler alternatives don't work"), this is precisely the kind of non-obvious invariant that warrants a one-line comment — not because the code is wrong, but because its correctness depends on external, easy-to-forget context (which pool is shared vs. per-connection) that isn't visible at either call site.

Concrete walkthrough of the regression this documentation would prevent:

  1. Today: Server.NewServer creates one s.executionPool, passed to every handler via newHandler in serveSingleRequest.
  2. A future PR reviewer sees handler.close() doesn't stop its executionPool field and, wanting to "fix" what looks like a leak, adds h.executionPool.Stop() back into handler.close().
  3. The first HTTP request now finishes, calls handler.close(), and stops the shared pool — exactly PR Stop execution pool in rpc handler #1005's bug reappears, and rpc_ep_workers_http metrics go silent again on any future release.
  4. A one-line comment at handler.close() ("executionPool is shared across all HTTP handlers and is stopped once in Server.Stop(), not here") and at clientConn.close() ("pool is per-connection, must be stopped here to avoid leaking its goroutine") would make the invariant explicit and stop this from recurring.

Fix: add a short comment at both rpc/handler.go:334-339 and rpc/client.go:127 stating the ownership split. This is a documentation nit, not a functional bug — the current code is correct.

Expand Down
Loading