solana/rpc: wait as long as a rate-limited endpoint asks

CHANGELOG.md

@@ -14,6 +14,7 @@ All notable changes to this project will be documented in this file.
   - The Go telemetry SDK no longer reports a transaction the program rejected as a success. Finalization only means the cluster agreed on the transaction: a rejected instruction finalizes too, carrying the rejection in `err`, which the executor never read. It now returns a `*telemetry.ProgramError` holding the ledger's error and the program's log output, and leads the message with the program's own explanation so a caller that just prints the error still gets the reason. This is the check the serviceability executor already made. (malbeclabs/infra#1703, #4152)
   - A samples-account-full or missing-account rejection that reaches execution now returns the same `ErrSamplesAccountFull` / `ErrAccountNotFound` the equivalent preflight rejection does, via the new `ProgramError.CustomErrorCode()`. Preflight catches nearly all of these, but a write that simulated cleanly and then failed against the bank it landed on reported its code only through the finalized transaction, so a caller's account-full handling worked on one side of preflight and not the other. (malbeclabs/infra#1703, #4152)
   - Rate-limit headroom reported by a ledger RPC endpoint is now recorded per JSON-RPC method: new `doublezero_solana_rpc_ratelimit_method_limit` and `doublezero_solana_rpc_ratelimit_method_remaining` gauges, fed by a passive transport wrapper on every retrying client `tools/solana/pkg/rpc` builds. A 429 was previously opaque: solana-go keeps only a code on its error types (`*HTTPError` is `{Code int, err error}`, `*RPCError` is `{Code, Message, Data}`) and discards the `http.Response` inside `CallForInto`, so the `X-Ratelimit-*` headers naming the cap were gone before any caller saw the error — a lake indexer activity was rate-limited on `getTransaction` for 4.5 hours with no way to learn the number it was exceeding, and the endpoint returns no such headers on a 200 either. Limits are enforced per method, per source IP, over a rolling window, so the numbers are attributed to the method they apply to; a global request-rate graph does not show this. Costs nothing where unused: the request body is inspected only once a response header proves there is something to record, it is read through `GetBody` so the body the transport sends is untouched, and an endpoint reporting no headers produces no series. Two further signals make a refusal attributable to a hop: `doublezero_solana_rpc_ratelimited_total` labels each rate-limited response by the shape that carried it, since an HTTP 429 status is what an edge limiter returns while a limiter at or behind the origin commonly answers 200 with the refusal inside the JSON-RPC envelope — only the latter reaches a caller as an `*RPCError`, and no HTTP-level metric shows it; and `doublezero_solana_rpc_responses_total` counts responses by the serving node the endpoint names, which answers whether load is concentrated on one node given limits are enforced per source IP. Neither is recoverable after the fact, which is why the 4.5h rate limit could not be attributed to the edge or the ledger node. (malbeclabs/lake#753, #4161)
+  - A retrying ledger RPC client now waits as long as a rate-limited endpoint asks it to, instead of retrying inside the window that just refused it. The retry budget totals about 3 seconds of jittered backoff across four attempts, while the provider fronting mainnet-beta enforces its limits over a rolling 10-second window, so every attempt of a rate-limited call landed inside the window the first one was refused in — four requests spent to be told the same thing, aimed at an endpoint already shedding load. The number that fixes this is on the response, in `Retry-After`, and it could not be reached: solana-go discards the `http.Response` inside `CallForInto` and its error types carry only a code. The transport now records the header against the in-flight call and the retry loop takes it before waiting, so the endpoint's own number wins over our guess in both directions. Waits are spread upward only, because arriving before the window rolls is arriving refused. One call will hold for at most 15 seconds of endpoint-requested waiting, which clears the 10-second window and keeps the worst case at about 55 seconds against state-ingest's 60-second tick; a call asked for longer than that stops rather than waiting a shorter time, since a partial wait spends the wait and is refused anyway, and it returns the rate limit itself so the caller sees the cause. New counter `doublezero_solana_rpc_retry_after_exceeded_total` is the series that says the allowance is sized wrong. Endpoints that send no `Retry-After` keep the existing backoff untouched. Callers can tune or disable this with `jsonrpc.RetryOptions.MaxRetryAfter`. (malbeclabs/lake#753, #4161)
 - Collector
   - A failed internet-latency submission now retries from the first unwritten sample rather than restarting at the beginning of the flushed partition, and only the unwritten remainder is requeued — the same fix the device telemetry submitter got in #4145. A partition larger than one transaction is written in batches, so any failure part-way through left the earlier batches onchain while the retry and the next tick re-sent them, appending those samples a second time and skewing the latency they feed. Reachable today from an RPC timeout mid-partition; surfacing program rejections adds another way in. (malbeclabs/infra#1703, #4152)
 - Device Telemetry

tools/solana/pkg/jsonrpc/metrics.go

@@ -34,4 +34,16 @@ var (
 		Name: "doublezero_solana_rpc_ratelimited_total",
 		Help: "Rate-limited JSON-RPC responses, by method and the error shape that carried the limit (http_status or jsonrpc_error).",
 	}, []string{"method", "carrier"})
+
+	// retryAfterExceededTotal counts calls that stopped retrying because the endpoint
+	// asked for a longer wait than one call is allowed to hold (MaxRetryAfter).
+	//
+	// This is the series that says the cap is set wrong. A rate limit that clears
+	// inside the cap never appears here; one that shows up steadily means the
+	// endpoint's window is longer than we sized for, and the fix is the cap or the
+	// caller's request rate, not another attempt.
+	retryAfterExceededTotal = promauto.NewCounterVec(prometheus.CounterOpts{
+		Name: "doublezero_solana_rpc_retry_after_exceeded_total",
+		Help: "JSON-RPC calls that gave up because the endpoint's Retry-After exceeded the per-call allowance, by method.",
+	}, []string{"method"})
 )

tools/solana/pkg/jsonrpc/retry.go

@@ -20,6 +20,22 @@ const (
 	defaultBaseBackoff = 500 * time.Millisecond
 	defaultMaxBackoff  = 5 * time.Second
 
+	// defaultMaxRetryAfter caps the total time one call will spend waiting on
+	// endpoint-supplied Retry-After headers, summed across its attempts.
+	//
+	// It has to clear the window it is meant to outlast, or honoring the header
+	// changes nothing: our mainnet provider enforces limits over a rolling 10s
+	// window. It also has to keep the worst case inside what callers were sized
+	// for. defaultRequestTimeout in the rpc package documents ~43s worst case and
+	// names state-ingest's 60s tick as the constraint, because state-ingest passes
+	// its root context straight down with no call-site bound. 15s puts the worst
+	// case at 4 attempts of 10s plus 15s of waiting, so 55s, still inside that tick.
+	//
+	// A call whose remaining allowance cannot cover what the endpoint asked for
+	// stops retrying rather than waiting a shorter time. Sleeping less than the
+	// endpoint asked buys a refusal at the cost of the wait.
+	defaultMaxRetryAfter = 15 * time.Second
+
 	// batchLabel is the metric label for CallBatch, which carries a mix of methods.
 	batchLabel = "batch"
 )
@@ -29,6 +45,11 @@ type RetryOptions struct {
 	BaseBackoff     time.Duration
 	MaxBackoff      time.Duration
 	IsRetryableFunc func(error) bool
+
+	// MaxRetryAfter caps the total wait one call will honor from endpoint-supplied
+	// Retry-After headers. Defaults to defaultMaxRetryAfter. A negative value turns
+	// the header off and leaves every wait to BaseBackoff.
+	MaxRetryAfter time.Duration
 }
 
 func WithRetry(inner solanarpc.JSONRPCClient, opt *RetryOptions) solanarpc.JSONRPCClient {
@@ -47,6 +68,9 @@ func WithRetry(inner solanarpc.JSONRPCClient, opt *RetryOptions) solanarpc.JSONR
 	if opt.IsRetryableFunc == nil {
 		opt.IsRetryableFunc = isRetryableJSONRPC
 	}
+	if opt.MaxRetryAfter == 0 {
+		opt.MaxRetryAfter = defaultMaxRetryAfter
+	}
 	return &retryingJSONRPCClient{inner: inner, opt: *opt}
 }
 
@@ -112,10 +136,26 @@ func doRetry(ctx context.Context, opt RetryOptions, label string, idempotent boo
 		maxAttempts = 1
 	}
 
+	// The transport writes any Retry-After it sees into this slot, keyed on the
+	// context it hands down (see retryafter.go). The sink is per call, not per
+	// attempt, because take() clears it.
+	ctx, sink := withRetryAfterSink(ctx)
+
 	var lastErr error
+	var retryAfterSpent time.Duration
 	for attempt := 1; attempt <= maxAttempts; attempt++ {
 		if attempt > 1 {
-			if err := sleepBackoff(ctx, opt, attempt); err != nil {
+			wait, honored, ok := nextWait(opt, attempt, sink.take(), retryAfterSpent)
+			if !ok {
+				// The endpoint asked for longer than this call is allowed to wait.
+				// Retrying sooner than it asked is a refusal we have already paid
+				// for, so return the rate limit and let the caller's next poll
+				// arrive after the window instead.
+				retryAfterExceededTotal.WithLabelValues(label).Inc()
+				return lastErr
+			}
+			retryAfterSpent += honored
+			if err := sleepFor(ctx, wait); err != nil {
 				// Keep the error that caused the retry. A caller whose deadline is
 				// shorter than the retry budget would otherwise log only "context
 				// deadline exceeded" and lose the 503 behind it — the one thing
@@ -142,21 +182,51 @@ func doRetry(ctx context.Context, opt RetryOptions, label string, idempotent boo
 	return lastErr
 }
 
-// sleepBackoff waits before the given attempt, honoring ctx cancellation and
-// deadlines. The wait is jittered over [d/2, d] so that the ~60 doublezerod hosts
-// and dozen services reading the same ledger endpoint do not retry in lockstep and
-// re-spike an endpoint that is already shedding load. Jitter keeps a floor at half
-// the interval rather than reaching down to zero, so the total budget stays
-// predictable against the caller's poll interval.
-func sleepBackoff(ctx context.Context, opt RetryOptions, attempt int) error {
+// nextWait decides how long to wait before the given attempt.
+//
+// retryAfter is what the endpoint asked for on the attempt that just failed, 0 if it
+// asked for nothing. spent is what earlier attempts of this call already waited on
+// its say-so. It returns the wait, how much of that wait counts against the
+// Retry-After allowance, and whether to retry at all.
+//
+// An endpoint's own number always wins over our backoff, in both directions: it knows
+// its window and we are guessing. The one thing we do not do is wait a shorter time
+// than it asked — that spends the wait and still gets refused — so a request that
+// does not fit the remaining allowance ends the call instead.
+func nextWait(opt RetryOptions, attempt int, retryAfter, spent time.Duration) (wait, honored time.Duration, ok bool) {
+	if retryAfter > 0 && opt.MaxRetryAfter > 0 {
+		// Spread the resumption. Every client refused in the same window otherwise
+		// waits the same number of seconds and fires together, re-spiking an endpoint
+		// at the moment its window rolls. The spread is upward only, for the reason
+		// above: arriving early is arriving refused.
+		wait = retryAfter + rand.N(retryAfter/4+1)
+		if spent+wait > opt.MaxRetryAfter {
+			return 0, 0, false
+		}
+		return wait, wait, true
+	}
+	return jitteredBackoff(opt, attempt), 0, true
+}
+
+// jitteredBackoff is the wait for an endpoint that named no number of its own. It
+// grows linearly with the attempt and is jittered over [d/2, d] so that the ~60
+// doublezerod hosts and dozen services reading the same ledger endpoint do not retry
+// in lockstep and re-spike an endpoint that is already shedding load. Jitter keeps a
+// floor at half the interval rather than reaching down to zero, so the total budget
+// stays predictable against the caller's poll interval.
+func jitteredBackoff(opt RetryOptions, attempt int) time.Duration {
 	d := opt.BaseBackoff * time.Duration(attempt-1)
 	if d > opt.MaxBackoff {
 		d = opt.MaxBackoff
 	}
 	if d > 0 {
 		d = d/2 + rand.N(d/2+1)
 	}
+	return d
+}
 
+// sleepFor waits, honoring ctx cancellation and deadlines.
+func sleepFor(ctx context.Context, d time.Duration) error {
 	t := time.NewTimer(d)
 	defer t.Stop()
 	select {

tools/solana/pkg/jsonrpc/retry_test.go

@@ -328,7 +328,8 @@ func TestTools_Solana_JSONRPC_SleepBackoff_JitteredWithinBounds(t *testing.T) {
 	var sawBelowCeiling bool
 	for i := 0; i < 20; i++ {
 		start := time.Now()
-		require.NoError(t, sleepBackoff(context.Background(), opt, 3)) // nominal 40ms, capped at 40ms
+		// nominal 40ms, capped at 40ms
+		require.NoError(t, sleepFor(context.Background(), jitteredBackoff(opt, 3)))
 		elapsed := time.Since(start)
 		require.GreaterOrEqual(t, elapsed, 20*time.Millisecond, "jitter must not drop below half the interval")
 		if elapsed < 40*time.Millisecond {

tools/solana/pkg/jsonrpc/retryafter.go

@@ -0,0 +1,90 @@
+package jsonrpc
+
+import (
+	"context"
+	"net/http"
+	"strconv"
+	"sync/atomic"
+	"time"
+)
+
+// A rate-limited endpoint tells us how long to wait, and until now nothing in this
+// stack could hear it. The retry budget is ~3s of jittered backoff across 4 attempts
+// (see sleepBackoff), while the provider fronting our mainnet ledger enforces its
+// limits over a rolling 10s window. Every attempt therefore lands inside the same
+// window the first one was refused in, so a rate-limited call cannot be rescued by
+// retrying — it burns four requests to be told the same thing, which is exactly the
+// load the endpoint is trying to shed.
+//
+// The number that fixes this is on the response, in Retry-After. It cannot be read
+// from the error: solana-go discards the http.Response inside CallForInto, and its
+// error types carry a code and nothing else. So the transport records it against the
+// in-flight call (see NoteRetryAfter) and the retry loop takes it before sleeping.
+//
+// Guessing instead of reading was the alternative, and it is worse in both
+// directions: a fixed 10s wait stalls a call the endpoint would have served again in
+// 1s, and it is still too short for a provider whose window is longer.
+
+// retryAfterKey addresses the per-call slot in a context. An unexported key type
+// means no other package can collide with it or read the slot by accident.
+type retryAfterKey struct{}
+
+// retryAfterSink holds the most recent Retry-After the transport saw for one call.
+// Attempts run one at a time, but a single attempt can produce more than one round
+// trip (a redirect, a retried h2 stream), so writes are atomic and the last one wins.
+type retryAfterSink struct{ nanos atomic.Int64 }
+
+// take returns the recorded wait and clears the slot. Clearing matters: without it a
+// Retry-After from attempt 2 would still be sitting there before attempt 3, and a
+// refusal that carried no header would be paced by a stale number.
+func (s *retryAfterSink) take() time.Duration {
+	return time.Duration(s.nanos.Swap(0))
+}
+
+// withRetryAfterSink returns a context carrying a fresh slot for the transport to
+// write into, and the slot itself.
+func withRetryAfterSink(ctx context.Context) (context.Context, *retryAfterSink) {
+	sink := &retryAfterSink{}
+	return context.WithValue(ctx, retryAfterKey{}, sink), sink
+}
+
+// NoteRetryAfter records how long an endpoint asked the caller to wait before
+// repeating the in-flight request. It is for HTTP transports wrapping a client built
+// by this repo's rpc package; a context from anywhere else is ignored, so calling it
+// is always safe.
+//
+// Only the retry loop reads this, and only after an attempt has failed with a
+// retryable error. So a header on a successful response costs nothing, and there is
+// no need to filter by status code here — which matters, because the refusals that
+// caused this work arrived as HTTP 200 with the rate limit inside the JSON-RPC
+// envelope, a shape no status-code check would have matched.
+func NoteRetryAfter(ctx context.Context, d time.Duration) {
+	if d <= 0 {
+		return
+	}
+	if sink, ok := ctx.Value(retryAfterKey{}).(*retryAfterSink); ok {
+		sink.nanos.Store(int64(d))
+	}
+}
+
+// ParseRetryAfter reads a Retry-After header value as a duration, relative to now.
+// RFC 9110 allows either delta-seconds or an HTTP-date, and providers send both. A
+// value that is missing, unparseable, or already in the past yields 0, meaning "the
+// endpoint said nothing" — the caller then keeps its own backoff.
+func ParseRetryAfter(value string, now time.Time) time.Duration {
+	if value == "" {
+		return 0
+	}
+	if secs, err := strconv.Atoi(value); err == nil {
+		if secs <= 0 {
+			return 0
+		}
+		return time.Duration(secs) * time.Second
+	}
+	if when, err := http.ParseTime(value); err == nil {
+		if d := when.Sub(now); d > 0 {
+			return d
+		}
+	}
+	return 0
+}