diff --git a/README.md b/README.md index cad13db..3ae909a 100644 --- a/README.md +++ b/README.md @@ -7,6 +7,7 @@ batch-export is a tool to retrieve Ethereum event logs for specific contracts, p - Retrieve event logs for a specified contract address and block range. - Handles large block ranges by querying in smaller chunks. - Supports rate limiting for RPC requests. +- Retries requests that fail with a transient network error (timeouts, dropped connections, rate limiting) using an exponential backoff. - Saves retrieved logs to a specified output file (default: `export.ndjson`) in NDJSON format. - Graceful shutdown on interrupt signals (Ctrl+C). @@ -49,6 +50,8 @@ The primary command is export. -h, --help help for export -m, --max-request int Max RPC requests/sec (default 15) -o, --output string Output file path (NDJSON) (default "export.ndjson") + --retry-delay duration Delay before the first retry, doubling per retry up to 30s (default 1s) + --retry-max int Max retries per RPC request on transient network errors (0 disables retrying) (default 5) --start uint Start block (optional, uses contract start block if 0) (default 31306381) -v, --verbosity string Log verbosity (silent, error, warn, info, debug) (default "info") ``` diff --git a/cmd/export.go b/cmd/export.go index f39bb50..6f39c2e 100644 --- a/cmd/export.go +++ b/cmd/export.go @@ -25,6 +25,8 @@ func (c *command) initExportCmd() (err error) { blockRangeLimit uint32 outputFile string compress bool + retryMax int + retryDelay time.Duration ) cmd := &cobra.Command{ @@ -32,14 +34,26 @@ func (c *command) initExportCmd() (err error) { Short: "Export Swarm Postage Stamp contract event logs within a block range.", Long: `Exports event logs for the Swarm Postage Stamp contract from a specified Ethereum RPC endpoint within a given block range (--start to --end). It handles large ranges by querying in chunks (--block-range-limit) -and respects RPC rate limits (--max-request). +and respects RPC rate limits (--max-request). Requests failing with a transient network error are retried +with an exponential backoff (--retry-max, --retry-delay). The retrieved logs are saved to the specified output file (default: 'export.ndjson') in NDJSON format. The process can be interrupted at any time (Ctrl+C), and it will attempt to save already retrieved logs before exiting.`, RunE: func(cmd *cobra.Command, args []string) (err error) { ctx := cmd.Context() - ec, err := ethclient.NewClient(ctx, rpcEndpoint, ethclient.WithRateLimit(maxRequest), ethclient.WithLogger(c.log)) + if retryMax < 0 { + return fmt.Errorf("invalid --retry-max %d: must not be negative", retryMax) + } + if retryDelay <= 0 { + return fmt.Errorf("invalid --retry-delay %s: must be greater than zero", retryDelay) + } + + ec, err := ethclient.NewClient(ctx, rpcEndpoint, + ethclient.WithRateLimit(maxRequest), + ethclient.WithLogger(c.log), + ethclient.WithRetry(retryMax, retryDelay), + ) if err != nil { return fmt.Errorf("failed to connect to the Ethereum client: %w", err) } @@ -139,6 +153,8 @@ The process can be interrupted at any time (Ctrl+C), and it will attempt to save cmd.Flags().Uint32VarP(&blockRangeLimit, "block-range-limit", "b", 5, "Max blocks per log query") cmd.Flags().StringVarP(&outputFile, "output", "o", "export.ndjson", "Output file path (NDJSON)") cmd.Flags().BoolVarP(&compress, "compress", "c", false, "Compress to GZIP") + cmd.Flags().IntVarP(&retryMax, "retry-max", "", 5, "Max retries per RPC request on transient network errors (0 disables retrying)") + cmd.Flags().DurationVarP(&retryDelay, "retry-delay", "", ethclient.DefaultRetryDelay, "Delay before the first retry, doubling per retry up to 30s") c.root.AddCommand(cmd) diff --git a/pkg/ethclientwrapper/ethclientwrapper.go b/pkg/ethclientwrapper/ethclientwrapper.go index 2e3b6e1..fe0e2b3 100644 --- a/pkg/ethclientwrapper/ethclientwrapper.go +++ b/pkg/ethclientwrapper/ethclientwrapper.go @@ -2,7 +2,9 @@ package ethclientwrapper import ( "context" + "math/big" "sync" + "time" "github.com/ethereum/go-ethereum" "github.com/ethereum/go-ethereum/core/types" @@ -15,6 +17,7 @@ type Client struct { *ethclient.Client limiter *rate.Limiter logger log.Logger + retry retryConfig rawURL string mu sync.Mutex } @@ -35,6 +38,16 @@ func WithLogger(logger log.Logger) ClientOption { } } +// WithRetry retries requests that fail with a transient error, such as a +// timed out TLS handshake. maxRetries is the number of retries attempted after +// the initial request, 0 disables retrying. baseDelay is the delay before the +// first retry, doubling for every further retry. +func WithRetry(maxRetries int, baseDelay time.Duration) ClientOption { + return func(c *Client) { + c.retry = newRetryConfig(maxRetries, baseDelay) + } +} + // NewClient creates a new Ethereum client with possible rate limiting. func NewClient(ctx context.Context, rawURL string, opts ...ClientOption) (*Client, error) { ethclient, err := ethclient.DialContext(ctx, rawURL) @@ -62,14 +75,52 @@ func (c *Client) Close() { } func (c *Client) FilterLogs(ctx context.Context, q ethereum.FilterQuery) ([]types.Log, error) { - c.mu.Lock() - defer c.mu.Unlock() + return retryCall(ctx, c.retryConfigFor("FilterLogs"), func() ([]types.Log, error) { + c.mu.Lock() + defer c.mu.Unlock() - if err := c.applyRateLimit(ctx); err != nil { - return nil, err - } + if err := c.applyRateLimit(ctx); err != nil { + return nil, err + } + + return c.Client.FilterLogs(ctx, q) + }) +} + +func (c *Client) BlockNumber(ctx context.Context) (uint64, error) { + return retryCall(ctx, c.retryConfigFor("BlockNumber"), func() (uint64, error) { + c.mu.Lock() + defer c.mu.Unlock() - return c.Client.FilterLogs(ctx, q) + if err := c.applyRateLimit(ctx); err != nil { + return 0, err + } + + return c.Client.BlockNumber(ctx) + }) +} + +func (c *Client) ChainID(ctx context.Context) (*big.Int, error) { + return retryCall(ctx, c.retryConfigFor("ChainID"), func() (*big.Int, error) { + c.mu.Lock() + defer c.mu.Unlock() + + if err := c.applyRateLimit(ctx); err != nil { + return nil, err + } + + return c.Client.ChainID(ctx) + }) +} + +// retryConfigFor returns the retry config for the named call, reporting every +// retry through the client logger. +func (c *Client) retryConfigFor(call string) retryConfig { + cfg := c.retry + cfg.onRetry = func(attempt int, delay time.Duration, err error) { + c.logger.Warning("retrying rpc call", "call", call, "attempt", attempt, "retry_in", delay, "error", err) + } + return cfg } // applyRateLimit checks if the limiter is set and applies the rate limit. diff --git a/pkg/ethclientwrapper/retry.go b/pkg/ethclientwrapper/retry.go new file mode 100644 index 0000000..fb170fe --- /dev/null +++ b/pkg/ethclientwrapper/retry.go @@ -0,0 +1,180 @@ +package ethclientwrapper + +import ( + "context" + "errors" + "io" + "math/rand/v2" + "net" + "syscall" + "time" + + "github.com/ethereum/go-ethereum/rpc" +) + +const ( + // DefaultRetryDelay is the base delay applied before the first retry. + DefaultRetryDelay = time.Second + + // maxRetryDelay caps the exponential backoff between retries. + maxRetryDelay = 30 * time.Second + + // rpcErrCodeLimitExceeded is the JSON-RPC error code endpoints return when + // the client is being rate limited. Unlike other server-side errors, it is + // worth retrying. + rpcErrCodeLimitExceeded = -32005 +) + +// retryConfig describes how transient RPC failures are retried. Its zero value +// performs no retries. +type retryConfig struct { + // maxRetries is the number of retries attempted after the initial call. + maxRetries int + baseDelay time.Duration + maxDelay time.Duration + + // sleep, jitter and onRetry are injectable to keep the backoff testable. + sleep func(context.Context, time.Duration) error + jitter func(time.Duration) time.Duration + onRetry func(attempt int, delay time.Duration, err error) +} + +// newRetryConfig returns a config retrying up to maxRetries times, starting +// with baseDelay and doubling it up to maxRetryDelay. +func newRetryConfig(maxRetries int, baseDelay time.Duration) retryConfig { + return retryConfig{ + maxRetries: maxRetries, + baseDelay: baseDelay, + maxDelay: maxRetryDelay, + } +} + +// withDefaults fills in the fields left unset by the caller. +func (c retryConfig) withDefaults() retryConfig { + if c.maxRetries < 0 { + c.maxRetries = 0 + } + if c.baseDelay <= 0 { + c.baseDelay = DefaultRetryDelay + } + if c.maxDelay < c.baseDelay { + c.maxDelay = c.baseDelay + } + if c.sleep == nil { + c.sleep = sleepCtx + } + if c.jitter == nil { + c.jitter = jitter + } + if c.onRetry == nil { + c.onRetry = func(int, time.Duration, error) {} + } + return c +} + +// retryCall calls fn, retrying transient failures with an exponential backoff. +// It gives up as soon as the error is not transient, the retries are exhausted +// or ctx is done, and then returns the error of the last attempt, joined with +// the context error when ctx is what stopped it. +func retryCall[T any](ctx context.Context, cfg retryConfig, fn func() (T, error)) (T, error) { + cfg = cfg.withDefaults() + + for attempt := 0; ; attempt++ { + result, err := fn() + if err == nil { + return result, nil + } + + if attempt >= cfg.maxRetries || !isRetryable(err) || ctx.Err() != nil { + return result, errors.Join(err, ctx.Err()) + } + + delay := cfg.jitter(backoffDelay(attempt+1, cfg.baseDelay, cfg.maxDelay)) + cfg.onRetry(attempt+1, delay, err) + + if sleepErr := cfg.sleep(ctx, delay); sleepErr != nil { + return result, errors.Join(err, sleepErr) + } + } +} + +// backoffDelay returns the delay before the given 1-based retry attempt, +// doubling base per attempt without ever exceeding max. +func backoffDelay(attempt int, base, maxDelay time.Duration) time.Duration { + delay := base + for i := 1; i < attempt; i++ { + delay *= 2 + // A delay that is no longer positive means the doubling overflowed. + if delay <= 0 || delay >= maxDelay { + return maxDelay + } + } + return delay +} + +// jitter spreads the delay over the second half of the backoff window so that +// repeated retries do not hit the endpoint in lockstep. +func jitter(d time.Duration) time.Duration { + if d <= 0 { + return 0 + } + return d/2 + time.Duration(rand.Int64N(int64(d/2)+1)) +} + +// sleepCtx waits for d, returning early if ctx is done. +func sleepCtx(ctx context.Context, d time.Duration) error { + if d <= 0 { + return ctx.Err() + } + + timer := time.NewTimer(d) + defer timer.Stop() + + select { + case <-ctx.Done(): + return ctx.Err() + case <-timer.C: + return nil + } +} + +// isRetryable reports whether err is a transient failure that a later attempt +// may recover from, such as a dropped connection or a timed out TLS handshake. +func isRetryable(err error) bool { + if err == nil { + return false + } + + if errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded) { + return false + } + + // The endpoint answered with an HTTP error: retry only if it is temporary. + var httpErr rpc.HTTPError + if errors.As(err, &httpErr) { + return httpErr.StatusCode == 408 || httpErr.StatusCode == 429 || httpErr.StatusCode >= 500 + } + + // The endpoint answered with a JSON-RPC error, so the request reached it and + // replaying it would fail the same way, unless we are being rate limited. + var rpcErr rpc.Error + if errors.As(err, &rpcErr) { + return rpcErr.ErrorCode() == rpcErrCodeLimitExceeded + } + + // Transport level failures: timeouts, TLS handshake failures, DNS errors. + var netErr net.Error + if errors.As(err, &netErr) { + return true + } + + if errors.Is(err, io.EOF) || errors.Is(err, io.ErrUnexpectedEOF) { + return true + } + + return errors.Is(err, syscall.ECONNRESET) || + errors.Is(err, syscall.ECONNREFUSED) || + errors.Is(err, syscall.ECONNABORTED) || + errors.Is(err, syscall.EPIPE) || + errors.Is(err, syscall.ETIMEDOUT) +} diff --git a/pkg/ethclientwrapper/retry_test.go b/pkg/ethclientwrapper/retry_test.go new file mode 100644 index 0000000..b16f6a6 --- /dev/null +++ b/pkg/ethclientwrapper/retry_test.go @@ -0,0 +1,316 @@ +package ethclientwrapper + +import ( + "context" + "errors" + "io" + "net" + "net/url" + "syscall" + "testing" + "time" + + "github.com/ethereum/go-ethereum/rpc" +) + +// errTLSHandshakeTimeout mimics the error surfaced by net/http when the TLS +// handshake with the RPC endpoint times out. +var errTLSHandshakeTimeout = &url.Error{ + Op: "Post", + URL: "https://gno.swarm1.ethswarm.org/", + Err: errors.New("net/http: TLS handshake timeout"), +} + +type fakeRPCError struct{ code int } + +func (e fakeRPCError) Error() string { return "json-rpc error" } +func (e fakeRPCError) ErrorCode() int { return e.code } + +// testConfig returns a config with deterministic backoff that records the +// delays it would have slept for instead of sleeping. +func testConfig(maxRetries int, delays *[]time.Duration) retryConfig { + cfg := newRetryConfig(maxRetries, time.Second) + cfg.jitter = func(d time.Duration) time.Duration { return d } + cfg.sleep = func(_ context.Context, d time.Duration) error { + *delays = append(*delays, d) + return nil + } + return cfg +} + +func TestRetryCallSucceedsOnFirstAttempt(t *testing.T) { + t.Parallel() + + var delays []time.Duration + calls := 0 + + got, err := retryCall(context.Background(), testConfig(5, &delays), func() (int, error) { + calls++ + return 42, nil + }) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if got != 42 { + t.Errorf("got %d, want 42", got) + } + if calls != 1 { + t.Errorf("made %d calls, want 1", calls) + } + if len(delays) != 0 { + t.Errorf("slept %v, want no sleeps", delays) + } +} + +func TestRetryCallSucceedsAfterTransientFailures(t *testing.T) { + t.Parallel() + + var ( + delays []time.Duration + retries []int + calls int + ) + + cfg := testConfig(5, &delays) + cfg.onRetry = func(attempt int, _ time.Duration, _ error) { retries = append(retries, attempt) } + + got, err := retryCall(context.Background(), cfg, func() (string, error) { + calls++ + if calls < 3 { + return "", errTLSHandshakeTimeout + } + return "ok", nil + }) + if err != nil { + t.Fatalf("unexpected error: %v", err) + } + if got != "ok" { + t.Errorf("got %q, want %q", got, "ok") + } + if calls != 3 { + t.Errorf("made %d calls, want 3", calls) + } + if want := []time.Duration{time.Second, 2 * time.Second}; !equalDurations(delays, want) { + t.Errorf("slept %v, want %v", delays, want) + } + if want := []int{1, 2}; !equalInts(retries, want) { + t.Errorf("reported retries %v, want %v", retries, want) + } +} + +func TestRetryCallExhaustsRetries(t *testing.T) { + t.Parallel() + + var delays []time.Duration + calls := 0 + + _, err := retryCall(context.Background(), testConfig(2, &delays), func() (int, error) { + calls++ + return 0, errTLSHandshakeTimeout + }) + if !errors.Is(err, errTLSHandshakeTimeout) { + t.Fatalf("got error %v, want %v", err, errTLSHandshakeTimeout) + } + if calls != 3 { + t.Errorf("made %d calls, want 3 (1 attempt + 2 retries)", calls) + } + if want := []time.Duration{time.Second, 2 * time.Second}; !equalDurations(delays, want) { + t.Errorf("slept %v, want %v", delays, want) + } +} + +func TestRetryCallDisabled(t *testing.T) { + t.Parallel() + + var delays []time.Duration + calls := 0 + + _, err := retryCall(context.Background(), testConfig(0, &delays), func() (int, error) { + calls++ + return 0, errTLSHandshakeTimeout + }) + if !errors.Is(err, errTLSHandshakeTimeout) { + t.Fatalf("got error %v, want %v", err, errTLSHandshakeTimeout) + } + if calls != 1 { + t.Errorf("made %d calls, want 1", calls) + } +} + +func TestRetryCallZeroValueConfigDoesNotRetry(t *testing.T) { + t.Parallel() + + calls := 0 + + _, err := retryCall(context.Background(), retryConfig{}, func() (int, error) { + calls++ + return 0, errTLSHandshakeTimeout + }) + if !errors.Is(err, errTLSHandshakeTimeout) { + t.Fatalf("got error %v, want %v", err, errTLSHandshakeTimeout) + } + if calls != 1 { + t.Errorf("made %d calls, want 1", calls) + } +} + +func TestRetryCallDoesNotRetryPermanentErrors(t *testing.T) { + t.Parallel() + + var delays []time.Duration + permanent := fakeRPCError{code: -32602} // invalid params + calls := 0 + + _, err := retryCall(context.Background(), testConfig(5, &delays), func() (int, error) { + calls++ + return 0, permanent + }) + if !errors.Is(err, permanent) { + t.Fatalf("got error %v, want %v", err, permanent) + } + if calls != 1 { + t.Errorf("made %d calls, want 1", calls) + } + if len(delays) != 0 { + t.Errorf("slept %v, want no sleeps", delays) + } +} + +func TestRetryCallStopsWhenContextIsCanceledDuringBackoff(t *testing.T) { + t.Parallel() + + cfg := newRetryConfig(5, time.Second) + cfg.jitter = func(d time.Duration) time.Duration { return d } + cfg.sleep = func(context.Context, time.Duration) error { return context.Canceled } + + calls := 0 + _, err := retryCall(context.Background(), cfg, func() (int, error) { + calls++ + return 0, errTLSHandshakeTimeout + }) + if !errors.Is(err, errTLSHandshakeTimeout) { + t.Fatalf("got error %v, want the last call error %v", err, errTLSHandshakeTimeout) + } + if !errors.Is(err, context.Canceled) { + t.Errorf("got error %v, want it to report the cancellation too", err) + } + if calls != 1 { + t.Errorf("made %d calls, want 1", calls) + } +} + +func TestRetryCallStopsWhenContextIsAlreadyCanceled(t *testing.T) { + t.Parallel() + + ctx, cancel := context.WithCancel(context.Background()) + cancel() + + var delays []time.Duration + calls := 0 + + _, err := retryCall(ctx, testConfig(5, &delays), func() (int, error) { + calls++ + return 0, errTLSHandshakeTimeout + }) + if !errors.Is(err, errTLSHandshakeTimeout) { + t.Fatalf("got error %v, want %v", err, errTLSHandshakeTimeout) + } + if !errors.Is(err, context.Canceled) { + t.Errorf("got error %v, want it to report the cancellation too", err) + } + if calls != 1 { + t.Errorf("made %d calls, want 1", calls) + } + if len(delays) != 0 { + t.Errorf("slept %v, want no sleeps", delays) + } +} + +func TestBackoffDelay(t *testing.T) { + t.Parallel() + + const ( + base = time.Second + maxDelay = 30 * time.Second + ) + + for _, tc := range []struct { + attempt int + want time.Duration + }{ + {attempt: 1, want: time.Second}, + {attempt: 2, want: 2 * time.Second}, + {attempt: 3, want: 4 * time.Second}, + {attempt: 4, want: 8 * time.Second}, + {attempt: 5, want: 16 * time.Second}, + {attempt: 6, want: maxDelay}, + {attempt: 100, want: maxDelay}, // no overflow + {attempt: 10000, want: maxDelay}, // no overflow + } { + if got := backoffDelay(tc.attempt, base, maxDelay); got != tc.want { + t.Errorf("backoffDelay(%d) = %v, want %v", tc.attempt, got, tc.want) + } + } +} + +func TestIsRetryable(t *testing.T) { + t.Parallel() + + for _, tc := range []struct { + name string + err error + want bool + }{ + {name: "nil", err: nil, want: false}, + {name: "tls handshake timeout", err: errTLSHandshakeTimeout, want: true}, + {name: "wrapped tls handshake timeout", err: errors.Join(errors.New("failed to retrieve logs"), errTLSHandshakeTimeout), want: true}, + {name: "dns failure", err: &net.DNSError{Err: "no such host", IsNotFound: true}, want: true}, + {name: "unexpected eof", err: io.ErrUnexpectedEOF, want: true}, + {name: "eof", err: io.EOF, want: true}, + {name: "connection reset", err: syscall.ECONNRESET, want: true}, + {name: "connection refused", err: syscall.ECONNREFUSED, want: true}, + {name: "broken pipe", err: syscall.EPIPE, want: true}, + {name: "http 408", err: rpc.HTTPError{StatusCode: 408, Status: "408 Request Timeout"}, want: true}, + {name: "http 429", err: rpc.HTTPError{StatusCode: 429, Status: "429 Too Many Requests"}, want: true}, + {name: "http 502", err: rpc.HTTPError{StatusCode: 502, Status: "502 Bad Gateway"}, want: true}, + {name: "http 400", err: rpc.HTTPError{StatusCode: 400, Status: "400 Bad Request"}, want: false}, + {name: "rpc limit exceeded", err: fakeRPCError{code: -32005}, want: true}, + {name: "rpc invalid params", err: fakeRPCError{code: -32602}, want: false}, + {name: "rpc internal error", err: fakeRPCError{code: -32603}, want: false}, + {name: "context canceled", err: context.Canceled, want: false}, + {name: "context deadline exceeded", err: context.DeadlineExceeded, want: false}, + {name: "unknown error", err: errors.New("boom"), want: false}, + } { + t.Run(tc.name, func(t *testing.T) { + t.Parallel() + + if got := isRetryable(tc.err); got != tc.want { + t.Errorf("isRetryable(%v) = %t, want %t", tc.err, got, tc.want) + } + }) + } +} + +func equalDurations(got, want []time.Duration) bool { + if len(got) != len(want) { + return false + } + for i := range got { + if got[i] != want[i] { + return false + } + } + return true +} + +func equalInts(got, want []int) bool { + if len(got) != len(want) { + return false + } + for i := range got { + if got[i] != want[i] { + return false + } + } + return true +}