add vrf replay logs (#12887)

* add vrf replay logs * address comment * fix replay blocks logic and add logging for jobs * add changeset * fix linter * address comments
smartcontractkit · Apr 19, 2024 · e87b83c · e87b83c
1 parent 4279bec
commit e87b83c
Show file tree

Hide file tree

Showing 5 changed files with 73 additions and 27 deletions.
diff --git a/.changeset/hungry-ways-add.md b/.changeset/hungry-ways-add.md
@@ -0,0 +1,6 @@
+---
+"chainlink": patch
+---
+
+#bugfix
+vrf fix replay number of blocks logic and add logging for job specs
diff --git a/core/services/blockhashstore/delegate.go b/core/services/blockhashstore/delegate.go
@@ -2,6 +2,7 @@ package blockhashstore
 
 import (
 	"context"
+	"encoding/json"
 	"fmt"
 	"sync"
 	"time"
@@ -55,6 +56,11 @@ func (d *Delegate) ServicesForSpec(ctx context.Context, jb job.Job) ([]job.Servi
 		return nil, errors.Errorf(
 			"blockhashstore.Delegate expects a BlockhashStoreSpec to be present, got %+v", jb)
 	}
+	marshalledJob, err := json.MarshalIndent(jb.BlockhashStoreSpec, "", " ")
+	if err != nil {
+		return nil, err
+	}
+	d.logger.Debugw("Creating services for job spec", "job", string(marshalledJob))
 
 	chain, err := d.legacyChains.Get(jb.BlockhashStoreSpec.EVMChainID.String())
 	if err != nil {

diff --git a/core/services/blockheaderfeeder/delegate.go b/core/services/blockheaderfeeder/delegate.go
@@ -2,6 +2,7 @@ package blockheaderfeeder
 
 import (
 	"context"
+	"encoding/json"
 	"fmt"
 	"time"
 
@@ -52,6 +53,11 @@ func (d *Delegate) ServicesForSpec(ctx context.Context, jb job.Job) ([]job.Servi
 	if jb.BlockHeaderFeederSpec == nil {
 		return nil, errors.Errorf("Delegate expects a BlockHeaderFeederSpec to be present, got %+v", jb)
 	}
+	marshalledJob, err := json.MarshalIndent(jb.BlockHeaderFeederSpec, "", " ")
+	if err != nil {
+		return nil, err
+	}
+	d.logger.Debugw("Creating services for job spec", "job", string(marshalledJob))
 
 	chain, err := d.legacyChains.Get(jb.BlockHeaderFeederSpec.EVMChainID.String())
 	if err != nil {

diff --git a/core/services/vrf/delegate.go b/core/services/vrf/delegate.go
@@ -2,6 +2,7 @@ package vrf
 
 import (
 	"context"
+	"encoding/json"
 	"fmt"
 	"time"
 
@@ -74,6 +75,19 @@ func (d *Delegate) ServicesForSpec(ctx context.Context, jb job.Job) ([]job.Servi
 	if jb.VRFSpec == nil || jb.PipelineSpec == nil {
 		return nil, errors.Errorf("vrf.Delegate expects a VRFSpec and PipelineSpec to be present, got %+v", jb)
 	}
+	marshalledVRFSpec, err := json.MarshalIndent(jb.VRFSpec, "", " ")
+	if err != nil {
+		return nil, err
+	}
+	marshalledPipelineSpec, err := json.MarshalIndent(jb.PipelineSpec, "", " ")
+	if err != nil {
+		return nil, err
+	}
+	d.lggr.Debugw("Creating services for job spec",
+		"vrfSpec", string(marshalledVRFSpec),
+		"pipelineSpec", string(marshalledPipelineSpec),
+		"keyHash", jb.VRFSpec.PublicKey.MustHash(),
+	)
 	pl, err := jb.PipelineSpec.ParsePipeline()
 	if err != nil {
 		return nil, err

diff --git a/core/services/vrf/v2/listener_v2_log_listener.go b/core/services/vrf/v2/listener_v2_log_listener.go
@@ -129,8 +129,13 @@ func (lsn *listenerV2) initializeLastProcessedBlock(ctx context.Context) (lastPr
 	}()
 
 	numBlocksToReplay := numReplayBlocks(lsn.job.VRFSpec.RequestTimeout, lsn.chain.ID())
-	ll.Debugw("running replay on log poller")
-	err = lp.Replay(ctx, mathutil.Max(latestBlock.FinalizedBlockNumber-numBlocksToReplay, 1))
+	replayStartBlock := mathutil.Max(latestBlock.FinalizedBlockNumber-numBlocksToReplay, 1)
+	ll.Debugw("running replay on log poller",
+		"numBlocksToReplay", numBlocksToReplay,
+		"replayStartBlock", replayStartBlock,
+		"requestTimeout", lsn.job.VRFSpec.RequestTimeout,
+	)
+	err = lp.Replay(ctx, replayStartBlock)
 	if err != nil {
 		return 0, fmt.Errorf("LogPoller.Replay: %w", err)
 	}
@@ -414,47 +419,56 @@ func (lsn *listenerV2) handleRequested(requested []RandomWordsRequested, request
 func numReplayBlocks(requestTimeout time.Duration, chainID *big.Int) int64 {
 	var timeoutSeconds = int64(requestTimeout.Seconds())
 	switch chainID.String() {
-	case "1": // eth mainnet
-	case "3": // eth ropsten
-	case "4": // eth rinkeby
-	case "5": // eth goerli
-	case "11155111": // eth sepolia
+	case
+		"1",        // eth mainnet
+		"3",        // eth robsten
+		"4",        // eth rinkeby
+		"5",        // eth goerli
+		"11155111": // eth sepolia
 		// block time is 12s
 		return timeoutSeconds / 12
-	case "137": // polygon mainnet
-	case "80001": // polygon mumbai
+	case
+		"137",   // polygon mainnet
+		"80001", // polygon mumbai
+		"80002": // polygon amoy
 		// block time is 2s
 		return timeoutSeconds / 2
-	case "56": // bsc mainnet
-	case "97": // bsc testnet
+	case
+		"56", // bsc mainnet
+		"97": // bsc testnet
 		// block time is 2s
 		return timeoutSeconds / 2
-	case "43114": // avalanche mainnet
-	case "43113": // avalanche fuji
+	case
+		"43114", // avalanche mainnet
+		"43113": // avalanche fuji
 		// block time is 1s
 		return timeoutSeconds
-	case "250": // fantom mainnet
-	case "4002": // fantom testnet
+	case
+		"250",  // fantom mainnet
+		"4002": // fantom testnet
 		// block time is 1s
 		return timeoutSeconds
-	case "42161": // arbitrum mainnet
-	case "421613": // arbitrum goerli
-	case "421614": // arbitrum sepolia
+	case
+		"42161",  // arbitrum mainnet
+		"421613", // arbitrum goerli
+		"421614": // arbitrum sepolia
 		// block time is 0.25s in the worst case
 		return timeoutSeconds * 4
-	case "10": // optimism mainnet
-	case "69": // optimism kovan
-	case "420": // optimism goerli
-	case "11155420": // optimism sepolia
-	case "8453": // base mainnet
-	case "84531": // base goerli
-	case "84532": // base sepolia
+	case
+		"10",       // optimism mainnet
+		"69",       // optimism kovan
+		"420",      // optimism goerli
+		"11155420": // optimism sepolia
+		// block time is 2s
+		return timeoutSeconds / 2
+	case
+		"8453",  // base mainnet
+		"84531", // base goerli
+		"84532": // base sepolia
 		// block time is 2s
 		return timeoutSeconds / 2
 	default:
 		// assume block time of 1s
 		return timeoutSeconds
 	}
-	// assume block time of 1s
-	return timeoutSeconds
 }