Backend fetch failed
+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]