From bf2b72d164f8cc714cfbf57df59a3f3bf952b153 Mon Sep 17 00:00:00 2001 From: Domino Valdano Date: Tue, 27 Aug 2024 08:06:02 -0700 Subject: [PATCH] [BCF-3250]: Fix FilterLog error handling in LogPoller (#11654) * Fix error handling of results from FilterLogs() This was logging a critical error when any error other than an rpc error happened (eg networking issue, or context timeout) when batch_size was = 1. Should have only been logging at that level for rpc error "Limit Exceeded" More specifically, there are 4 interrelated issues addressed in this PR: 1. The logic for whether to retry or reduce batch size was wrong--so it was retrying with reduced batch size unnecessariy for transient errors 2. The error was being matched against a concrete JsonError type which is very fragile due to the number of types the type gets wrapped and re-formatted while it's propagated up the stack from geth through different layers. (It may have matched only in simulated geth but not with a live rpc server). Now it's matched against rpc.Error interface defined in geth for this purpose, which should work more generally. 3. There was a bug in the test for this feature (related to pointer indirection) which caused a false positive PASS 4. In addition to the rate limiting error returned by infura, alchemy, etc. I've added a similar error code geth can return when the request size is too large Also: A new subtest has been added to make sure that unrelated errors do not log this error message * pnpm changeset * Fix whitespace for lint * Add ErrorData() implementation to satisfy rpc.DataError This will make our JsonError fully parallel with jsonError, so they can both be treated in the same way. * Add more sophisticated classificaiton of FilterLogs error codes There are a lot of different error codes and messages which can be returned depending on what type of rpc server it is. Classification has been expanded to include both the codes and regex matching of the messages, and moved into client/errors.go where a similar process happens to disambiguate SendTx error * Add TooManyResults to docs example & full-config.toml * Add tests for IsTooManyResults() --- .changeset/poor-pumas-occur.md | 5 + core/chains/evm/client/errors.go | 105 ++++++++++- core/chains/evm/client/errors_test.go | 85 +++++++++ core/chains/evm/client/helpers_test.go | 3 + .../evm/client/simulated_backend_client.go | 4 +- .../evm/config/chain_scoped_client_errors.go | 1 + core/chains/evm/config/config.go | 1 + core/chains/evm/config/config_test.go | 2 + core/chains/evm/config/toml/config.go | 4 + core/chains/evm/logpoller/log_poller.go | 16 +- core/chains/evm/logpoller/log_poller_test.go | 165 +++++++++++------- core/chains/legacyevm/chain.go | 1 + core/config/docs/chains-evm.toml | 2 + core/services/chainlink/config_test.go | 2 + .../chainlink/testdata/config-full.toml | 1 + core/web/resolver/testdata/config-full.toml | 1 + docs/CONFIG.md | 7 + 17 files changed, 331 insertions(+), 74 deletions(-) create mode 100644 .changeset/poor-pumas-occur.md diff --git a/.changeset/poor-pumas-occur.md b/.changeset/poor-pumas-occur.md new file mode 100644 index 00000000000..df3e1e2f5f9 --- /dev/null +++ b/.changeset/poor-pumas-occur.md @@ -0,0 +1,5 @@ +--- +"chainlink": minor +--- + +#bugfix More robust error handling in LogPoller, including no more misleading CRITICAL errors emitted under non-critical conditions diff --git a/core/chains/evm/client/errors.go b/core/chains/evm/client/errors.go index 5980b0dd963..76411cb0407 100644 --- a/core/chains/evm/client/errors.go +++ b/core/chains/evm/client/errors.go @@ -10,6 +10,7 @@ import ( "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/core/types" + "github.com/ethereum/go-ethereum/rpc" pkgerrors "github.com/pkg/errors" "github.com/smartcontractkit/chainlink-common/pkg/logger" @@ -62,6 +63,7 @@ const ( Fatal ServiceUnavailable TerminallyStuck + TooManyResults ) type ClientErrors map[int]*regexp.Regexp @@ -298,6 +300,7 @@ func ClientErrorRegexes(errsRegex config.ClientErrors) *ClientErrors { TransactionAlreadyMined: regexp.MustCompile(errsRegex.TransactionAlreadyMined()), Fatal: regexp.MustCompile(errsRegex.Fatal()), ServiceUnavailable: regexp.MustCompile(errsRegex.ServiceUnavailable()), + TooManyResults: regexp.MustCompile(errsRegex.TooManyResults()), } } @@ -457,6 +460,11 @@ func isFatalSendError(err error) bool { return false } +var ( + _ rpc.Error = JsonError{} + _ rpc.DataError = JsonError{} +) + // go-ethereum@v1.10.0/rpc/json.go type JsonError struct { Code int `json:"code"` @@ -471,7 +479,17 @@ func (err JsonError) Error() string { return err.Message } -func (err *JsonError) String() string { +// To satisfy rpc.Error interface +func (err JsonError) ErrorCode() int { + return err.Code +} + +// To satisfy rpc.DataError +func (err JsonError) ErrorData() interface{} { + return err.Data +} + +func (err JsonError) String() string { return fmt.Sprintf("json-rpc error { Code = %d, Message = '%s', Data = '%v' }", err.Code, err.Message, err.Data) } @@ -610,3 +628,88 @@ func ClassifySendError(err error, clientErrors config.ClientErrors, lggr logger. lggr.Criticalw("Unknown error encountered when sending transaction", "err", err, "etx", tx) return commonclient.Unknown } + +var infura = ClientErrors{ + TooManyResults: regexp.MustCompile(`(: |^)query returned more than [0-9]+ results. Try with this block range \[0x[0-9A-F]+, 0x[0-9A-F]+\].$`), +} + +var alchemy = ClientErrors{ + TooManyResults: regexp.MustCompile(`(: |^)Log response size exceeded. You can make eth_getLogs requests with up to a [0-9A-Z]+ block range and no limit on the response size, or you can request any block range with a cap of [0-9A-Z]+ logs in the response. Based on your parameters and the response size limit, this block range should work: \[0x[0-9a-f]+, 0x[0-9a-f]+\]$`), +} + +var quicknode = ClientErrors{ + TooManyResults: regexp.MustCompile(`(: |^)eth_getLogs is limited to a [0-9,]+ range$`), +} + +var simplyvc = ClientErrors{ + TooManyResults: regexp.MustCompile(`too wide blocks range, the limit is [0-9,]+$`), +} + +var drpc = ClientErrors{ + TooManyResults: regexp.MustCompile(`(: |^)requested too many blocks from [0-9]+ to [0-9]+, maximum is set to [0-9,]+$`), +} + +// Linkpool, Blockdaemon, and Chainstack all return "request timed out" if the log results are too large for them to process +var defaultClient = ClientErrors{ + TooManyResults: regexp.MustCompile(`request timed out`), +} + +// JSON-RPC error codes which can indicate a refusal of the server to process an eth_getLogs request because the result set is too large +const ( + jsonRpcServerError = -32000 // Server error. SimplyVC uses this error code when too many results are returned + + // Server timeout. When the rpc server has its own limit on how long it can take to compile the results + // Examples: Linkpool, Chainstack, Block Daemon + jsonRpcTimedOut = -32002 + + // See: https://github.com/ethereum/go-ethereum/blob/master/rpc/errors.go#L63 + // Can occur if the rpc server is configured with a maximum byte limit on the response size of batch requests + jsonRpcResponseTooLarge = -32003 + + // Not implemented in geth by default, but is defined in EIP 1474 and implemented by infura and some other 3rd party rpc servers + // See: https://community.infura.io/t/getlogs-error-query-returned-more-than-1000-results/358/5 + jsonRpcLimitExceeded = -32005 // See also: https://github.com/ethereum/EIPs/blob/master/EIPS/eip-1474.md + + jsonRpcInvalidParams = -32602 // Invalid method params. Returned by alchemy if the block range is too large or there are too many results to return + + jsonRpcQuicknodeTooManyResults = -32614 // Undocumented error code used by Quicknode for too many results error +) + +func IsTooManyResults(err error, clientErrors config.ClientErrors) bool { + var rpcErr rpc.Error + + if !pkgerrors.As(err, &rpcErr) { + return false + } + configErrors := ClientErrorRegexes(clientErrors) + if configErrors.ErrIs(rpcErr, TooManyResults) { + return true + } + + switch rpcErr.ErrorCode() { + case jsonRpcResponseTooLarge: + return true + case jsonRpcLimitExceeded: + if infura.ErrIs(rpcErr, TooManyResults) { + return true + } + case jsonRpcInvalidParams: + if alchemy.ErrIs(rpcErr, TooManyResults) { + return true + } + case jsonRpcQuicknodeTooManyResults: + if quicknode.ErrIs(rpcErr, TooManyResults) { + return true + } + case jsonRpcTimedOut: + if defaultClient.ErrIs(rpcErr, TooManyResults) { + return true + } + case jsonRpcServerError: + if simplyvc.ErrIs(rpcErr, TooManyResults) || + drpc.ErrIs(rpcErr, TooManyResults) { + return true + } + } + return false +} diff --git a/core/chains/evm/client/errors_test.go b/core/chains/evm/client/errors_test.go index 095e291f5e9..7d11279d32f 100644 --- a/core/chains/evm/client/errors_test.go +++ b/core/chains/evm/client/errors_test.go @@ -1,7 +1,9 @@ package client_test import ( + "encoding/json" "errors" + "fmt" "testing" pkgerrors "github.com/pkg/errors" @@ -439,3 +441,86 @@ func Test_Config_Errors(t *testing.T) { assert.False(t, clientErrors.ErrIs(errors.New("some old bollocks"), evmclient.NonceTooLow)) }) } + +func Test_IsTooManyResultsError(t *testing.T) { + customErrors := evmclient.NewTestClientErrors() + + tests := []errorCase{ + {`{ + "code":-32602, + "message":"Log response size exceeded. You can make eth_getLogs requests with up to a 2K block range and no limit on the response size, or you can request any block range with a cap of 10K logs in the response. Based on your parameters and the response size limit, this block range should work: [0x0, 0x133e71]"}`, + true, + "alchemy", + }, {`{ + "code":-32005, + "data":{"from":"0xCB3D","limit":10000,"to":"0x7B737"}, + "message":"query returned more than 10000 results. Try with this block range [0xCB3D, 0x7B737]."}`, + true, + "infura", + }, {`{ + "code":-32002, + "message":"request timed out"}`, + true, + "LinkPool-Blockdaemon-Chainstack", + }, {`{ + "code":-32614, + "message":"eth_getLogs is limited to a 10,000 range"}`, + true, + "Quicknode", + }, {`{ + "code":-32000, + "message":"too wide blocks range, the limit is 100"}`, + true, + "SimplyVC", + }, {`{ + "message":"requested too many blocks from 0 to 16777216, maximum is set to 2048", + "code":-32000}`, + true, + "Drpc", + }, {` + + + + 503 Backend fetch failed + + +

Error 503 Backend fetch failed

+

Backend fetch failed

+

Guru Meditation:

+

XID: 343710611

+
+

Varnish cache server

+ +`, + false, + "Nirvana Labs"}, // This isn't an error response we can handle, but including for completeness. }, + + {`{ + "code":-32000", + "message":"unrelated server error"}`, + false, + "any", + }, {`{ + "code":-32500, + "message":"unrelated error code"}`, + false, + "any2", + }, {fmt.Sprintf(`{ + "code" : -43106, + "message" : "%s"}`, customErrors.TooManyResults()), + true, + "custom chain with error specified in toml config", + }, + } + + for _, test := range tests { + t.Run(test.network, func(t *testing.T) { + jsonRpcErr := evmclient.JsonError{} + err := json.Unmarshal([]byte(test.message), &jsonRpcErr) + if err == nil { + err = jsonRpcErr + } + assert.Equal(t, test.expect, evmclient.IsTooManyResults(err, &customErrors)) + }) + } +} diff --git a/core/chains/evm/client/helpers_test.go b/core/chains/evm/client/helpers_test.go index e996ccc5e4f..67977b180ed 100644 --- a/core/chains/evm/client/helpers_test.go +++ b/core/chains/evm/client/helpers_test.go @@ -34,6 +34,7 @@ type TestClientErrors struct { transactionAlreadyMined string fatal string serviceUnavailable string + tooManyResults string } func NewTestClientErrors() TestClientErrors { @@ -52,6 +53,7 @@ func NewTestClientErrors() TestClientErrors { transactionAlreadyMined: "client error transaction already mined", fatal: "client error fatal", serviceUnavailable: "client error service unavailable", + tooManyResults: "client error too many results", } } @@ -77,6 +79,7 @@ func (c *TestClientErrors) L2Full() string { return c.l2Full } func (c *TestClientErrors) TransactionAlreadyMined() string { return c.transactionAlreadyMined } func (c *TestClientErrors) Fatal() string { return c.fatal } func (c *TestClientErrors) ServiceUnavailable() string { return c.serviceUnavailable } +func (c *TestClientErrors) TooManyResults() string { return c.serviceUnavailable } type TestNodePoolConfig struct { NodePollFailureThreshold uint32 diff --git a/core/chains/evm/client/simulated_backend_client.go b/core/chains/evm/client/simulated_backend_client.go index 7dfd39f444c..9f8da08e806 100644 --- a/core/chains/evm/client/simulated_backend_client.go +++ b/core/chains/evm/client/simulated_backend_client.go @@ -415,7 +415,7 @@ func (c *SimulatedBackendClient) CallContract(ctx context.Context, msg ethereum. res, err := c.b.CallContract(ctx, msg, blockNumber) if err != nil { dataErr := revertError{} - if errors.Is(err, &dataErr) { + if errors.As(err, &dataErr) { return nil, &JsonError{Data: dataErr.ErrorData(), Message: dataErr.Error(), Code: 3} } // Generic revert, no data @@ -434,7 +434,7 @@ func (c *SimulatedBackendClient) PendingCallContract(ctx context.Context, msg et res, err := c.b.PendingCallContract(ctx, msg) if err != nil { dataErr := revertError{} - if errors.Is(err, &dataErr) { + if errors.As(err, &dataErr) { return nil, &JsonError{Data: dataErr.ErrorData(), Message: dataErr.Error(), Code: 3} } // Generic revert, no data diff --git a/core/chains/evm/config/chain_scoped_client_errors.go b/core/chains/evm/config/chain_scoped_client_errors.go index 53bb04846d2..f9d2096e903 100644 --- a/core/chains/evm/config/chain_scoped_client_errors.go +++ b/core/chains/evm/config/chain_scoped_client_errors.go @@ -48,3 +48,4 @@ func (c *clientErrorsConfig) Fatal() string { return derefOrDefault(c.c.Fatal) } func (c *clientErrorsConfig) ServiceUnavailable() string { return derefOrDefault(c.c.ServiceUnavailable) } +func (c *clientErrorsConfig) TooManyResults() string { return derefOrDefault(c.c.TooManyResults) } diff --git a/core/chains/evm/config/config.go b/core/chains/evm/config/config.go index aeb39cbf8d3..e3134380381 100644 --- a/core/chains/evm/config/config.go +++ b/core/chains/evm/config/config.go @@ -96,6 +96,7 @@ type ClientErrors interface { TransactionAlreadyMined() string Fatal() string ServiceUnavailable() string + TooManyResults() string } type Transactions interface { diff --git a/core/chains/evm/config/config_test.go b/core/chains/evm/config/config_test.go index ba362bda981..678d04425b0 100644 --- a/core/chains/evm/config/config_test.go +++ b/core/chains/evm/config/config_test.go @@ -353,6 +353,7 @@ func TestClientErrorsConfig(t *testing.T) { TransactionAlreadyMined: ptr("client error transaction already mined"), Fatal: ptr("client error fatal"), ServiceUnavailable: ptr("client error service unavailable"), + TooManyResults: ptr("client error too many results"), }, } }) @@ -372,6 +373,7 @@ func TestClientErrorsConfig(t *testing.T) { assert.Equal(t, "client error transaction already mined", errors.TransactionAlreadyMined()) assert.Equal(t, "client error fatal", errors.Fatal()) assert.Equal(t, "client error service unavailable", errors.ServiceUnavailable()) + assert.Equal(t, "client error too many results", errors.TooManyResults()) }) } diff --git a/core/chains/evm/config/toml/config.go b/core/chains/evm/config/toml/config.go index 8b926bf0875..a22fa31ddf9 100644 --- a/core/chains/evm/config/toml/config.go +++ b/core/chains/evm/config/toml/config.go @@ -807,6 +807,7 @@ type ClientErrors struct { TransactionAlreadyMined *string `toml:",omitempty"` Fatal *string `toml:",omitempty"` ServiceUnavailable *string `toml:",omitempty"` + TooManyResults *string `toml:",omitempty"` } func (r *ClientErrors) setFrom(f *ClientErrors) bool { @@ -852,6 +853,9 @@ func (r *ClientErrors) setFrom(f *ClientErrors) bool { if v := f.ServiceUnavailable; v != nil { r.ServiceUnavailable = v } + if v := f.TooManyResults; v != nil { + r.TooManyResults = v + } return true } diff --git a/core/chains/evm/logpoller/log_poller.go b/core/chains/evm/logpoller/log_poller.go index dee5d1d1a5d..a4560c967c4 100644 --- a/core/chains/evm/logpoller/log_poller.go +++ b/core/chains/evm/logpoller/log_poller.go @@ -29,6 +29,7 @@ import ( "github.com/smartcontractkit/chainlink-common/pkg/utils/mathutil" "github.com/smartcontractkit/chainlink/v2/core/chains/evm/client" + "github.com/smartcontractkit/chainlink/v2/core/chains/evm/config" evmtypes "github.com/smartcontractkit/chainlink/v2/core/chains/evm/types" ubig "github.com/smartcontractkit/chainlink/v2/core/chains/evm/utils/big" ) @@ -113,6 +114,7 @@ type logPoller struct { backfillBatchSize int64 // batch size to use when backfilling finalized logs rpcBatchSize int64 // batch size to use for fallback RPC calls made in GetBlocks logPrunePageSize int64 + clientErrors config.ClientErrors backupPollerNextBlock int64 // next block to be processed by Backup LogPoller backupPollerBlockDelay int64 // how far behind regular LogPoller should BackupLogPoller run. 0 = disabled @@ -143,6 +145,7 @@ type Opts struct { KeepFinalizedBlocksDepth int64 BackupPollerBlockDelay int64 LogPrunePageSize int64 + ClientErrors config.ClientErrors } // NewLogPoller creates a log poller. Note there is an assumption @@ -172,6 +175,7 @@ func NewLogPoller(orm ORM, ec Client, lggr logger.Logger, headTracker HeadTracke rpcBatchSize: opts.RpcBatchSize, keepFinalizedBlocksDepth: opts.KeepFinalizedBlocksDepth, logPrunePageSize: opts.LogPrunePageSize, + clientErrors: opts.ClientErrors, filters: make(map[string]Filter), filterDirty: true, // Always build Filter on first call to cache an empty filter if nothing registered yet. finalityViolated: new(atomic.Bool), @@ -794,8 +798,6 @@ func (lp *logPoller) blocksFromLogs(ctx context.Context, logs []types.Log, endBl return lp.GetBlocksRange(ctx, numbers) } -const jsonRpcLimitExceeded = -32005 // See https://github.com/ethereum/EIPs/blob/master/EIPS/eip-1474.md - // backfill will query FilterLogs in batches for logs in the // block range [start, end] and save them to the db. // Retries until ctx cancelled. Will return an error if cancelled @@ -807,13 +809,11 @@ func (lp *logPoller) backfill(ctx context.Context, start, end int64) error { gethLogs, err := lp.ec.FilterLogs(ctx, lp.Filter(big.NewInt(from), big.NewInt(to), nil)) if err != nil { - var rpcErr client.JsonError - if pkgerrors.As(err, &rpcErr) { - if rpcErr.Code != jsonRpcLimitExceeded { - lp.lggr.Errorw("Unable to query for logs", "err", err, "from", from, "to", to) - return err - } + if !client.IsTooManyResults(err, lp.clientErrors) { + lp.lggr.Errorw("Unable to query for logs", "err", err, "from", from, "to", to) + return err } + if batchSize == 1 { lp.lggr.Criticalw("Too many log results in a single block, failed to retrieve logs! Node may be running in a degraded state.", "err", err, "from", from, "to", to, "LogBackfillBatchSize", lp.backfillBatchSize) return err diff --git a/core/chains/evm/logpoller/log_poller_test.go b/core/chains/evm/logpoller/log_poller_test.go index 548711c19bb..73302877f95 100644 --- a/core/chains/evm/logpoller/log_poller_test.go +++ b/core/chains/evm/logpoller/log_poller_test.go @@ -1542,6 +1542,8 @@ type getLogErrData struct { } func TestTooManyLogResults(t *testing.T) { + t.Parallel() + ctx := testutils.Context(t) ec := evmtest.NewEthClientMockWithDefaultChain(t) lggr, obs := logger.TestObserved(t, zapcore.DebugLevel) @@ -1561,89 +1563,126 @@ func TestTooManyLogResults(t *testing.T) { lp := logpoller.NewLogPoller(o, ec, lggr, headTracker, lpOpts) expected := []int64{10, 5, 2, 1} - clientErr := client.JsonError{ + tooLargeErr := client.JsonError{ Code: -32005, Data: getLogErrData{"0x100E698", "0x100E6D4", 10000}, Message: "query returned more than 10000 results. Try with this block range [0x100E698, 0x100E6D4].", } - // Simulate currentBlock = 300 - head := &evmtypes.Head{Number: 300} - finalized := &evmtypes.Head{Number: head.Number - lpOpts.FinalityDepth} - headTracker.On("LatestAndFinalizedBlock", mock.Anything).Return(head, finalized, nil).Once() - call1 := ec.On("HeadByNumber", mock.Anything, mock.Anything).Return(func(ctx context.Context, blockNumber *big.Int) (*evmtypes.Head, error) { + var filterLogsCall *mock.Call + head := &evmtypes.Head{} + finalized := &evmtypes.Head{} + + ec.On("HeadByNumber", mock.Anything, mock.Anything).Return(func(ctx context.Context, blockNumber *big.Int) (*evmtypes.Head, error) { if blockNumber == nil { require.FailNow(t, "unexpected call to get current head") } return &evmtypes.Head{Number: blockNumber.Int64()}, nil }) - call2 := ec.On("FilterLogs", mock.Anything, mock.Anything).Return(func(ctx context.Context, fq ethereum.FilterQuery) (logs []types.Log, err error) { - if fq.BlockHash != nil { - return []types.Log{}, nil // succeed when single block requested - } - from := fq.FromBlock.Uint64() - to := fq.ToBlock.Uint64() - if to-from >= 4 { - return []types.Log{}, &clientErr // return "too many results" error if block range spans 4 or more blocks - } - return logs, err - }) + t.Run("halves size until small enough, then succeeds", func(t *testing.T) { + // Simulate currentBlock = 300 + head.Number = 300 + finalized.Number = head.Number - lpOpts.FinalityDepth + headTracker.On("LatestAndFinalizedBlock", mock.Anything).Return(head, finalized, nil).Once() - addr := testutils.NewAddress() - err := lp.RegisterFilter(ctx, logpoller.Filter{ - Name: "Integration test", - EventSigs: []common.Hash{EmitterABI.Events["Log1"].ID}, - Addresses: []common.Address{addr}, - }) - require.NoError(t, err) - lp.PollAndSaveLogs(ctx, 5) - block, err2 := o.SelectLatestBlock(ctx) - require.NoError(t, err2) - assert.Equal(t, int64(298), block.BlockNumber) - - logs := obs.FilterLevelExact(zapcore.WarnLevel).FilterMessageSnippet("halving block range batch size").FilterFieldKey("newBatchSize").All() - // Should have tried again 3 times--first reducing batch size to 10, then 5, then 2 - require.Len(t, logs, 3) - for i, s := range expected[:3] { - assert.Equal(t, s, logs[i].ContextMap()["newBatchSize"]) - } + filterLogsCall = ec.On("FilterLogs", mock.Anything, mock.Anything).Return(func(ctx context.Context, fq ethereum.FilterQuery) (logs []types.Log, err error) { + if fq.BlockHash != nil { + return []types.Log{}, nil // succeed when single block requested + } + from := fq.FromBlock.Uint64() + to := fq.ToBlock.Uint64() + if to-from >= 4 { + return []types.Log{}, tooLargeErr // return "too many results" error if block range spans 4 or more blocks + } + return logs, err + }) - obs.TakeAll() - call1.Unset() - call2.Unset() + addr := testutils.NewAddress() + err := lp.RegisterFilter(ctx, logpoller.Filter{ + Name: "Integration test", + EventSigs: []common.Hash{EmitterABI.Events["Log1"].ID}, + Addresses: []common.Address{addr}, + }) + require.NoError(t, err) + lp.PollAndSaveLogs(ctx, 5) + block, err2 := o.SelectLatestBlock(ctx) + require.NoError(t, err2) + assert.Equal(t, int64(298), block.BlockNumber) - // Now jump to block 500, but return error no matter how small the block range gets. - // Should exit the loop with a critical error instead of hanging. - head = &evmtypes.Head{Number: 500} - finalized = &evmtypes.Head{Number: head.Number - lpOpts.FinalityDepth} - headTracker.On("LatestAndFinalizedBlock", mock.Anything).Return(head, finalized, nil).Once() - call1.On("HeadByNumber", mock.Anything, mock.Anything).Return(func(ctx context.Context, blockNumber *big.Int) (*evmtypes.Head, error) { - if blockNumber == nil { - require.FailNow(t, "unexpected call to get current head") + logs := obs.FilterLevelExact(zapcore.WarnLevel).FilterMessageSnippet("halving block range batch size").FilterFieldKey("newBatchSize").All() + // Should have tried again 3 times--first reducing batch size to 10, then 5, then 2 + require.Len(t, logs, 3) + for i, s := range expected[:3] { + assert.Equal(t, s, logs[i].ContextMap()["newBatchSize"]) } - return &evmtypes.Head{Number: blockNumber.Int64()}, nil + filterLogsCall.Unset() }) - call2.On("FilterLogs", mock.Anything, mock.Anything).Return(func(ctx context.Context, fq ethereum.FilterQuery) (logs []types.Log, err error) { - if fq.BlockHash != nil { - return []types.Log{}, nil // succeed when single block requested + + t.Run("Halves size until single block, then reports critical error", func(t *testing.T) { + obs.TakeAll() + + // Now jump to block 500, but return error no matter how small the block range gets. + // Should exit the loop with a critical error instead of hanging. + head.Number = 500 + finalized.Number = head.Number - lpOpts.FinalityDepth + headTracker.On("LatestAndFinalizedBlock", mock.Anything).Return(head, finalized, nil).Once() + filterLogsCall = ec.On("FilterLogs", mock.Anything, mock.Anything).Return(func(ctx context.Context, fq ethereum.FilterQuery) (logs []types.Log, err error) { + if fq.BlockHash != nil { + return []types.Log{}, nil // succeed when single block requested + } + return []types.Log{}, tooLargeErr // return "too many results" error if block range spans 4 or more blocks + }) + + lp.PollAndSaveLogs(ctx, 298) + block, err := o.SelectLatestBlock(ctx) + if err != nil { + assert.ErrorContains(t, err, "no rows") // In case this subtest is run by itself + } else { + assert.Equal(t, int64(298), block.BlockNumber) + } + warns := obs.FilterMessageSnippet("halving block range").FilterLevelExact(zapcore.WarnLevel).All() + crit := obs.FilterMessageSnippet("failed to retrieve logs").FilterLevelExact(zapcore.DPanicLevel).All() + require.Len(t, warns, 4) + for i, s := range expected { + assert.Equal(t, s, warns[i].ContextMap()["newBatchSize"]) } - return []types.Log{}, &clientErr // return "too many results" error if block range spans 4 or more blocks + + require.Len(t, crit, 1) + assert.Contains(t, crit[0].Message, "Too many log results in a single block") + filterLogsCall.Unset() }) - lp.PollAndSaveLogs(ctx, 298) - block, err2 = o.SelectLatestBlock(ctx) - require.NoError(t, err2) - assert.Equal(t, int64(298), block.BlockNumber) - warns := obs.FilterMessageSnippet("halving block range").FilterLevelExact(zapcore.WarnLevel).All() - crit := obs.FilterMessageSnippet("failed to retrieve logs").FilterLevelExact(zapcore.DPanicLevel).All() - require.Len(t, warns, 4) - for i, s := range expected { - assert.Equal(t, s, warns[i].ContextMap()["newBatchSize"]) - } + t.Run("Unrelated error are retried without adjusting size", func(t *testing.T) { + unrelatedError := fmt.Errorf("Unrelated to the size of the request") + head.Number = 500 + finalized.Number = head.Number - lpOpts.FinalityDepth + + obs.TakeAll() + filterLogsCall = ec.On("FilterLogs", mock.Anything, mock.Anything).Return(func(ctx context.Context, fq ethereum.FilterQuery) (logs []types.Log, err error) { + if fq.BlockHash != nil { + return []types.Log{}, nil // succeed when single block requested + } + return []types.Log{}, unrelatedError // return an unrelated error that should just be retried with same size + }) + headTracker.On("LatestAndFinalizedBlock", mock.Anything).Return(head, finalized, nil).Once() - require.Len(t, crit, 1) - assert.Contains(t, crit[0].Message, "Too many log results in a single block") + lp.PollAndSaveLogs(ctx, 298) + block, err := o.SelectLatestBlock(ctx) + if err != nil { + assert.ErrorContains(t, err, "no rows") // In case this subtest is run by itself + } else { + assert.Equal(t, int64(298), block.BlockNumber) + } + crit := obs.FilterLevelExact(zapcore.DPanicLevel).All() + errors := obs.FilterLevelExact(zapcore.ErrorLevel).All() + warns := obs.FilterLevelExact(zapcore.WarnLevel).All() + assert.Len(t, crit, 0) + require.Len(t, errors, 1) + assert.Equal(t, errors[0].Message, "Unable to query for logs") + require.Len(t, warns, 1) + assert.Contains(t, warns[0].Message, "retrying later") + }) } func Test_PollAndQueryFinalizedBlocks(t *testing.T) { diff --git a/core/chains/legacyevm/chain.go b/core/chains/legacyevm/chain.go index 68ff8d4e111..022f4cc5315 100644 --- a/core/chains/legacyevm/chain.go +++ b/core/chains/legacyevm/chain.go @@ -241,6 +241,7 @@ func newChain(ctx context.Context, cfg *evmconfig.ChainScoped, nodes []*toml.Nod KeepFinalizedBlocksDepth: int64(cfg.EVM().LogKeepBlocksDepth()), LogPrunePageSize: int64(cfg.EVM().LogPrunePageSize()), BackupPollerBlockDelay: int64(cfg.EVM().BackupLogPollerBlockDelay()), + ClientErrors: cfg.EVM().NodePool().Errors(), } logPoller = logpoller.NewLogPoller(logpoller.NewObservedORM(chainID, opts.DS, l), client, l, headTracker, lpOpts) } diff --git a/core/config/docs/chains-evm.toml b/core/config/docs/chains-evm.toml index 2186f502f49..aef9be09669 100644 --- a/core/config/docs/chains-evm.toml +++ b/core/config/docs/chains-evm.toml @@ -429,6 +429,8 @@ TransactionAlreadyMined = '(: |^)transaction already mined' # Example Fatal = '(: |^)fatal' # Example # ServiceUnavailable is a regex pattern to match against service unavailable errors. ServiceUnavailable = '(: |^)service unavailable' # Example +# TooManyResults is a regex pattern to match an eth_getLogs error indicating the result set is too large to return +TooManyResults = '(: |^)too many results' # Example [EVM.OCR] # ContractConfirmations sets `OCR.ContractConfirmations` for this EVM chain. diff --git a/core/services/chainlink/config_test.go b/core/services/chainlink/config_test.go index 253e4aa067f..56b0661854e 100644 --- a/core/services/chainlink/config_test.go +++ b/core/services/chainlink/config_test.go @@ -615,6 +615,7 @@ func TestConfig_Marshal(t *testing.T) { TransactionAlreadyMined: ptr[string]("(: |^)transaction already mined"), Fatal: ptr[string]("(: |^)fatal"), ServiceUnavailable: ptr[string]("(: |^)service unavailable"), + TooManyResults: ptr[string]("(: |^)too many results"), }, }, OCR: evmcfg.OCR{ @@ -1090,6 +1091,7 @@ L2Full = '(: |^)l2 full' TransactionAlreadyMined = '(: |^)transaction already mined' Fatal = '(: |^)fatal' ServiceUnavailable = '(: |^)service unavailable' +TooManyResults = '(: |^)too many results' [EVM.OCR] ContractConfirmations = 11 diff --git a/core/services/chainlink/testdata/config-full.toml b/core/services/chainlink/testdata/config-full.toml index a7fc9dcb94c..ff044fff586 100644 --- a/core/services/chainlink/testdata/config-full.toml +++ b/core/services/chainlink/testdata/config-full.toml @@ -381,6 +381,7 @@ L2Full = '(: |^)l2 full' TransactionAlreadyMined = '(: |^)transaction already mined' Fatal = '(: |^)fatal' ServiceUnavailable = '(: |^)service unavailable' +TooManyResults = '(: |^)too many results' [EVM.OCR] ContractConfirmations = 11 diff --git a/core/web/resolver/testdata/config-full.toml b/core/web/resolver/testdata/config-full.toml index f67d4737b57..37644c1d221 100644 --- a/core/web/resolver/testdata/config-full.toml +++ b/core/web/resolver/testdata/config-full.toml @@ -380,6 +380,7 @@ L2Full = '(: |^)l2 full' TransactionAlreadyMined = '(: |^)transaction already mined' Fatal = '(: |^)fatal' ServiceUnavailable = '(: |^)service unavailable' +TooManyResults = '(: |^)too many results' [EVM.OCR] ContractConfirmations = 11 diff --git a/docs/CONFIG.md b/docs/CONFIG.md index 7c54682367d..264f73d0033 100644 --- a/docs/CONFIG.md +++ b/docs/CONFIG.md @@ -8390,6 +8390,7 @@ L2Full = '(: |^)l2 full' # Example TransactionAlreadyMined = '(: |^)transaction already mined' # Example Fatal = '(: |^)fatal' # Example ServiceUnavailable = '(: |^)service unavailable' # Example +TooManyResults = '(: |^)too many results' # Example ``` Errors enable the node to provide custom regex patterns to match against error messages from RPCs. @@ -8477,6 +8478,12 @@ ServiceUnavailable = '(: |^)service unavailable' # Example ``` ServiceUnavailable is a regex pattern to match against service unavailable errors. +### TooManyResults +```toml +TooManyResults = '(: |^)too many results' # Example +``` +TooManyResults is a regex pattern to match an eth_getLogs error indicating the result set is too large to return + ## EVM.OCR ```toml [EVM.OCR]