diff --git a/pkg/chainaccessor/config_processors.go b/pkg/chainaccessor/config_processors.go index f8368bbfe..1ddad42fe 100644 --- a/pkg/chainaccessor/config_processors.go +++ b/pkg/chainaccessor/config_processors.go @@ -54,8 +54,7 @@ func processConfigResults( } // processSourceChainConfigResults extracts and processes source chain config results from the batch -func processSourceChainConfigResults( - lggr logger.Logger, +func (l *DefaultAccessor) processSourceChainConfigResults( batchResult types.BatchGetLatestValuesResult, standardOffRampRequestCount int, filteredSourceChains []cciptypes.ChainSelector, @@ -69,7 +68,8 @@ func processSourceChainConfigResults( sourceChainResults := results[standardOffRampRequestCount:] if len(sourceChainResults) != len(filteredSourceChains) { - lggr.Warnw("Source chain result count mismatch", + l.lggr.Warnw("Source chain result count mismatch", + "accessorSelector", l.chainSelector, "expected", len(filteredSourceChains), "got", len(sourceChainResults)) } else { @@ -81,16 +81,17 @@ func processSourceChainConfigResults( v, err := sourceChainResults[i].GetResult() if err != nil { - lggr.Errorw("Failed to get source chain config from result", - "chain", chain, + l.lggr.Errorw("Failed to get source chain config from result", + "accessorSelector", l.chainSelector, + "sourceChain", chain, "error", err) continue } cfg, ok := v.(*cciptypes.SourceChainConfig) if !ok { - lggr.Errorw("Invalid result type from GetSourceChainConfig", - "chain", chain, + l.lggr.Errorw("Invalid result type from GetSourceChainConfig", + "sourceChain", chain, "type", fmt.Sprintf("%T", v)) continue } diff --git a/pkg/chainaccessor/default_accessor.go b/pkg/chainaccessor/default_accessor.go index f453c49f7..3f2dc69ca 100644 --- a/pkg/chainaccessor/default_accessor.go +++ b/pkg/chainaccessor/default_accessor.go @@ -58,7 +58,7 @@ func NewDefaultAccessor( func (l *DefaultAccessor) GetContractAddress(contractName string) ([]byte, error) { bindings := l.contractReader.GetBindings(contractName) if len(bindings) != 1 { - return nil, fmt.Errorf("expected one binding for the %s contract, got %d", contractName, len(bindings)) + return nil, fmt.Errorf("expected one binding for the %s contract, got %d, for accessor on chain %d", contractName, len(bindings), l.chainSelector) } addressBytes, err := l.addrCodec.AddressStringToBytes(bindings[0].Binding.Address, l.chainSelector) @@ -83,12 +83,12 @@ func (l *DefaultAccessor) GetAllConfigsLegacy( var configRequests contractreader.ExtendedBatchGetLatestValuesRequest var standardOffRampRequestCount int if l.chainSelector == destChainSelector { - lggr.Debugw("getting ChainConfigSnapshot and and OffRamp SourceChainConfigs for destination chain", - "chainSelector", l.chainSelector) + lggr.Debugw("getting ChainConfigSnapshot and OffRamp SourceChainConfigs for destination chain", + "accessorSelector", l.chainSelector) configRequests, standardOffRampRequestCount = prepareDestChainRequest(sourceChainSelectors) } else { lggr.Debugw("getting ChainConfigSnapshot for a source chain", - "chainSelector", l.chainSelector) + "accessorSelector", l.chainSelector) configRequests = prepareSourceChainRequest(destChainSelector) } @@ -99,7 +99,9 @@ func (l *DefaultAccessor) GetAllConfigsLegacy( } if len(skipped) > 0 { - lggr.Warnw("chain reader skipped some config requests", "skipped", skipped) + lggr.Warnw("chain reader skipped some config requests", + "skipped", skipped, "accessorSelector", l.chainSelector, "destChainSelector", destChainSelector, + "sourceChainSelectors", sourceChainSelectors) } // Process standard results (ChainConfigSnapshot) @@ -107,17 +109,25 @@ func (l *DefaultAccessor) GetAllConfigsLegacy( standardConfigs, err := processConfigResults(lggr, l.chainSelector, destChainSelector, standardResultsCopy) if err != nil { // Log error but don't return yet and attempt to process source chain configs - lggr.Errorw("failed to process standard chain config results", "err", err) + lggr.Errorw("failed to process standard chain config results", "accessorSelector", l.chainSelector, + "destChainSelector", destChainSelector, "sourceChainSelectors", sourceChainSelectors, "err", err) standardConfigs = cciptypes.ChainConfigSnapshot{} } // Process source chain config results - sourceChainConfigs := processSourceChainConfigResults( - lggr, + sourceChainConfigs := l.processSourceChainConfigResults( batchResult, standardOffRampRequestCount, sourceChainSelectors, ) + l.lggr.Debugw("processed all chain config results", + "accessorSelector", l.chainSelector, + "destChainSelector", destChainSelector, + "sourceChainSelectors", sourceChainSelectors, + "numSourceChainConfigs", len(sourceChainConfigs), + "standardConfigs", standardConfigs, + "sourceChainConfigs", sourceChainConfigs, + ) return standardConfigs, sourceChainConfigs, nil } @@ -823,7 +833,7 @@ func (l *DefaultAccessor) GetChainFeePriceUpdate( ) if err != nil { - lggr.Errorw("failed to batch get chain fee price updates", "err", err) + lggr.Errorw("failed to batch get chain fee price updates", "accessorSelector", l.chainSelector, "err", err) return make(map[cciptypes.ChainSelector]cciptypes.TimestampedUnixBig), nil // Return a new empty map } @@ -834,12 +844,13 @@ func (l *DefaultAccessor) GetChainFeePriceUpdate( if contract.Name == consts.ContractNameFeeQuoter { feeQuoterResults = results found = true + lggr.Debugw("found fee quoter results") break // Found the results, exit loop } } if !found { - lggr.Errorw("FeeQuoter results missing from batch response") + lggr.Errorw("FeeQuoter results missing from batch response", "accessorSelector", l.chainSelector) return make(map[cciptypes.ChainSelector]cciptypes.TimestampedUnixBig), nil // Return a new empty map } @@ -867,6 +878,7 @@ func (l *DefaultAccessor) processFeePriceUpdateResults( if i >= len(results) { // Log error if we have fewer results than requested selectors lggr.Errorw("Skipping selector due to missing result", + "accessorSelector", l.chainSelector, "selectorIndex", i, "chain", chain, "lenFeeQuoterResults", len(results)) @@ -877,6 +889,7 @@ func (l *DefaultAccessor) processFeePriceUpdateResults( val, err := readResult.GetResult() if err != nil { lggr.Warnw("failed to get chain fee price update from batch result", + "accessorSelector", l.chainSelector, "chain", chain, "err", err) continue @@ -886,6 +899,7 @@ func (l *DefaultAccessor) processFeePriceUpdateResults( update, ok := val.(*cciptypes.TimestampedUnixBig) if !ok || update == nil { lggr.Warnw("Invalid type or nil value received for chain fee price update", + "accessorSelector", l.chainSelector, "chain", chain, "type", fmt.Sprintf("%T", val), "ok", ok) @@ -895,6 +909,7 @@ func (l *DefaultAccessor) processFeePriceUpdateResults( // Check if the update is empty if update.Timestamp == 0 || update.Value == nil { lggr.Debugw("chain fee price update is empty", + "accessorSelector", l.chainSelector, "chain", chain, "update", update) continue @@ -918,7 +933,7 @@ func (l *DefaultAccessor) GetLatestPriceSeqNr(ctx context.Context) (cciptypes.Se &latestSeqNr, ) if err != nil { - return 0, fmt.Errorf("get latest price sequence number: %w", err) + return 0, fmt.Errorf("get latest price sequence number for accessor %d: %w", l.chainSelector, err) } return cciptypes.SeqNum(latestSeqNr), nil } diff --git a/pkg/reader/ccip.go b/pkg/reader/ccip.go index 5cbad9a12..85a55f634 100644 --- a/pkg/reader/ccip.go +++ b/pkg/reader/ccip.go @@ -450,6 +450,7 @@ func (r *ccipChainReader) GetWrappedNativeTokenPriceUSD( // 2. Call chain's FeeQuoter to get native tokens price https://github.com/smartcontractkit/chainlink/blob/60e8b1181dd74b66903cf5b9a8427557b85357ec/contracts/src/v0.8/ccip/FeeQuoter.sol#L229-L229 // //nolint:lll + lggr = logger.With(r.lggr, "method", "GetWrappedNativeTokenPriceUSD", "destChain", r.destChain, "selectors", selectors) prices := make(map[cciptypes.ChainSelector]cciptypes.BigInt) var wg sync.WaitGroup @@ -474,15 +475,19 @@ func (r *ccipChainReader) GetWrappedNativeTokenPriceUSD( lggr.Warnw("failed to get chain config for native token address", "chain", chain, "err", err) return } + + lggr.Debugw("fetched chain config for native token address", "chain", chain, "config", config) nativeTokenAddress := config.Router.WrappedNativeAddress + lggr.Debugw("casted native token address", "chain", chain, "address", nativeTokenAddress.String(), "hex", hex.EncodeToString(nativeTokenAddress)) if cciptypes.UnknownAddress(nativeTokenAddress).IsZeroOrEmpty() { lggr.Warnw("Native token address is zero or empty. Ignore for disabled chains otherwise "+ - "check for router misconfiguration", "chain", chain, "address", nativeTokenAddress.String()) + "check for router misconfiguration", "chain", chain, "address", cciptypes.UnknownAddress(nativeTokenAddress), "hexCast", hex.EncodeToString(cciptypes.UnknownAddress(nativeTokenAddress))) return } price, err := chainAccessor.GetTokenPriceUSD(ctx, cciptypes.UnknownAddress(nativeTokenAddress)) + lggr.Debugw("fetched native token price", "chain", chain, "address", nativeTokenAddress.String(), "price", price) if err != nil { lggr.Errorw("failed to get native token price", "chain", chain, "address", nativeTokenAddress.String(), "err", err) return @@ -498,6 +503,7 @@ func (r *ccipChainReader) GetWrappedNativeTokenPriceUSD( } mu.Lock() + lggr.Debugw("setting native token price", "chain", chain, "price", price.Value, "timestamp", price.Timestamp) prices[chain] = cciptypes.NewBigInt(price.Value) mu.Unlock() }() @@ -635,19 +641,26 @@ func (r *ccipChainReader) discoverOffRampContracts( lggr logger.Logger, chains []cciptypes.ChainSelector, ) (ContractAddresses, error) { + lggr = logger.With(lggr, "function", "discoverOffRampContracts", + "destChain", r.destChain, "offRamp", r.offrampAddress, "chains", chains) + // Get from cache + lggr.Debugw("fetching offramp dest chain config") config, err := r.configPoller.GetChainConfig(ctx, r.destChain) if err != nil { return nil, fmt.Errorf("unable to lookup RMN remote address (RMN proxy): %w", err) } + lggr.Debugw("fetched offramp dest chain config from cache", "config", config) + resp := make(ContractAddresses) // OnRamps are in the offRamp SourceChainConfig. { + lggr.Debugw("fetching offramp source chain configs") sourceConfigs, err := r.getOffRampSourceChainsConfig(ctx, lggr, chains, false) - if err != nil { + lggr.Debugw("unable to get SourceChainsConfig", "err", err) return nil, fmt.Errorf("unable to get SourceChainsConfig: %w", err) } @@ -660,12 +673,13 @@ func (r *ccipChainReader) discoverOffRampContracts( // The local router is located in each source sourceChain config. Add it once. if len(resp[consts.ContractNameRouter][r.destChain]) == 0 { resp = resp.Append(consts.ContractNameRouter, r.destChain, cfg.Router) - lggr.Infow("appending router contract address", "address", cfg.Router) + lggr.Infow("appending router contract address", "address", cfg.Router, "sourceChain", sourceChain) } } } // Add static config contracts + lggr.Debugw("checking offramp static config contracts") if len(config.Offramp.StaticConfig.RmnRemote) > 0 { lggr.Infow("appending RMN remote contract address", "address", hex.EncodeToString(config.Offramp.StaticConfig.RmnRemote), @@ -674,6 +688,9 @@ func (r *ccipChainReader) discoverOffRampContracts( } if len(config.Offramp.StaticConfig.NonceManager) > 0 { + lggr.Infow("appending nonce manager contract address", + "address", hex.EncodeToString(config.Offramp.StaticConfig.NonceManager), + "chain", r.destChain) resp = resp.Append(consts.ContractNameNonceManager, r.destChain, config.Offramp.StaticConfig.NonceManager) } @@ -685,6 +702,7 @@ func (r *ccipChainReader) discoverOffRampContracts( resp = resp.Append(consts.ContractNameFeeQuoter, r.destChain, config.Offramp.DynamicConfig.FeeQuoter) } + lggr.Debugw("returning discovered contracts", "contracts", resp) return resp, nil } @@ -694,14 +712,21 @@ func (r *ccipChainReader) DiscoverContracts(ctx context.Context, var resp ContractAddresses var err error lggr := logutil.WithContextValues(ctx, r.lggr) + lggr = logger.With(lggr, "function", "DiscoverContracts", + "destChain", r.destChain, "offRamp", r.offrampAddress, + "supportedChains", supportedChains, "allChains", allChains) if slices.Contains(supportedChains, r.destChain) { + lggr.Debugw("dest chain is supported, calling discoverOffRampContracts") resp, err = r.discoverOffRampContracts(ctx, lggr, allChains) // Can't continue with discovery if the destination chain is not available. // We read source chains OnRamps from there, and onRamps are essential for feeQuoter and Router discovery. if err != nil { + lggr.Debugw("failed to discover destination contracts", "err", err) return nil, fmt.Errorf("discover destination contracts: %w", err) } + } else { + lggr.Debugw("dest chain is not supported, skipping discoverOffRampContracts") } // The following calls are on dynamically configured chains which may not @@ -739,6 +764,7 @@ func (r *ccipChainReader) DiscoverContracts(ctx context.Context, "err", err) return } + lggr.Debugw("got chain config for chainSel", "chainSel", chainSel, "config", config) // Use mutex to safely update the shared resp mu.Lock() @@ -746,18 +772,30 @@ func (r *ccipChainReader) DiscoverContracts(ctx context.Context, // Add FeeQuoter from dynamic config if !cciptypes.UnknownAddress(config.OnRamp.DynamicConfig.DynamicConfig.FeeQuoter).IsZeroOrEmpty() { + lggr.Debugw("appending fee quoter contract address", + "address", hex.EncodeToString(config.OnRamp.DynamicConfig.DynamicConfig.FeeQuoter)) resp = resp.Append( consts.ContractNameFeeQuoter, chainSel, config.OnRamp.DynamicConfig.DynamicConfig.FeeQuoter) + } else { + lggr.Warnw("FeeQuoter address is zero or empty. Ignore for disabled chains otherwise "+ + "check for onRamp misconfiguration", "chain", chainSel, + "address", hex.EncodeToString(config.OnRamp.DynamicConfig.DynamicConfig.FeeQuoter)) } // Add Router from dest chain config if !cciptypes.UnknownAddress(config.OnRamp.DestChainConfig.Router).IsZeroOrEmpty() { + lggr.Debugw("appending router contract address", + "address", hex.EncodeToString(config.OnRamp.DestChainConfig.Router)) resp = resp.Append( consts.ContractNameRouter, chainSel, config.OnRamp.DestChainConfig.Router) + } else { + lggr.Warnw("Router address is zero or empty. Ignore for disabled chains otherwise "+ + "check for onRamp misconfiguration", "chain", chainSel, + "address", hex.EncodeToString(config.OnRamp.DestChainConfig.Router)) } }(chainCopy) } @@ -765,6 +803,7 @@ func (r *ccipChainReader) DiscoverContracts(ctx context.Context, // Wait for all goroutines to complete wg.Wait() + lggr.Debugw("returning discovered contracts", "contracts", resp) return resp, nil } @@ -932,6 +971,8 @@ func (r *ccipChainReader) getOffRampSourceChainsConfig( return nil, fmt.Errorf("get source chain configs: %w", err) } + lggr.Debugw("fetched offramp source chain configs from config poller", "count", len(configs), "configs", configs) + // Filter out disabled chains if needed if !includeDisabled { for chain, cfg := range configs { @@ -949,6 +990,7 @@ func (r *ccipChainReader) getOffRampSourceChainsConfig( } } + lggr.Debugw("returning offramp source chain configs", "count", len(configs)) return configs, nil } @@ -1091,21 +1133,32 @@ func (r *ccipChainReader) getRMNRemoteAddress( ctx context.Context, chain cciptypes.ChainSelector, rmnRemoteProxyAddress []byte) ([]byte, error) { + lggr := logger.With(r.lggr, + "function", "getRMNRemoteAddress", + "chain", chain, + "rmnRemoteProxyAddress", hex.EncodeToString(rmnRemoteProxyAddress), + "destChain", r.destChain) + chainAccessor, err := getChainAccessor(r.accessors, chain) if err != nil { + lggr.Debugw("failed to get chain accessor", "err", err) return nil, fmt.Errorf("unable to getChainAccessor: %w", err) } err = chainAccessor.Sync(ctx, consts.ContractNameRMNProxy, rmnRemoteProxyAddress) if err != nil { + lggr.Debugw("failed to sync RMN proxy contract", "err", err) return nil, fmt.Errorf("sync RMN proxy contract: %w", err) } // Get the address from cache instead of making a contract call config, err := r.configPoller.GetChainConfig(ctx, chain) if err != nil { + lggr.Debugw("failed to get chain config from cache", "err", err) return nil, fmt.Errorf("get chain config: %w", err) } + lggr.Debugw("got chain config snapshot from cache", "config", config) + return config.RMNProxy.RemoteAddress, nil } diff --git a/pkg/reader/config_poller_v2.go b/pkg/reader/config_poller_v2.go index 37135c12c..6f5d9a9b5 100644 --- a/pkg/reader/config_poller_v2.go +++ b/pkg/reader/config_poller_v2.go @@ -165,15 +165,18 @@ func (c *configPollerV2) GetChainConfig( ctx context.Context, chainSel cciptypes.ChainSelector, ) (cciptypes.ChainConfigSnapshot, error) { + lggr := logger.With(c.lggr, "function", "config_poller_v2 GetChainConfig", "chain", chainSel, "destChain", c.destChainSelector) + // Confirm we have an accessor for this chain _, err := getChainAccessor(c.chainAccessors, chainSel) if err != nil { - c.lggr.Errorw("No chain accessor for chain", "chain", chainSel, "error", err) + lggr.Errorw("No chain accessor for chain", "chain", chainSel, "error", err) return cciptypes.ChainConfigSnapshot{}, fmt.Errorf("no chain accessor for %s: %w", chainSel, err) } cache := c.getOrCreateChainCache(chainSel) if cache == nil { + lggr.Debugw("failed to get or create chain cache for chain") return cciptypes.ChainConfigSnapshot{}, fmt.Errorf("failed to get or create chain cache for chain %s", chainSel) } @@ -182,9 +185,11 @@ func (c *configPollerV2) GetChainConfig( cache.chainConfigMu.RLock() if !cache.chainConfigRefresh.IsZero() { defer cache.chainConfigMu.RUnlock() - c.lggr.Debugw("Returning cached chain config", + lggr.Debugw("Returning cached chain config", "chain", chainSel, - "cacheAge", time.Since(cache.chainConfigRefresh)) + "cacheAge", time.Since(cache.chainConfigRefresh), + "cachedChainConfigSnapshot", cache.chainConfigData, + "chainConfigData", cache.chainConfigData) return cache.chainConfigData, nil } cache.chainConfigMu.RUnlock() @@ -192,6 +197,7 @@ func (c *configPollerV2) GetChainConfig( // Cache miss: batch fetch all configs for this chain. Don't hold the lock while fetching. // TODO: alternatively, if we want to prevent multiple goroutines from fetching the same chain config (especially // during node startup), we could block on this fetch if the cache is empty. + lggr.Debugw("Cache miss - fetching chain config via batch refresh") if err := c.batchRefreshChainAndSourceConfigs(ctx, chainSel); err != nil { return cciptypes.ChainConfigSnapshot{}, err } @@ -199,6 +205,7 @@ func (c *configPollerV2) GetChainConfig( // Re-acquire read lock to return the data cache.chainConfigMu.RLock() defer cache.chainConfigMu.RUnlock() + lggr.Debugw("Returning freshly fetched chain config after cache miss", "freshlyFetchedChainConfigSnapshot", cache.chainConfigData) return cache.chainConfigData, nil } @@ -233,14 +240,20 @@ func (c *configPollerV2) GetOfframpSourceChainConfigs( destChain, c.destChainSelector) } + lggr := logger.With(c.lggr, "function", "config_poller_v2 GetOfframpSourceChainConfigs", "destChain", destChain, "sourceChains", sourceChains) + // Ensure we're not trying to fetch source chain configs for the destination chain itself + lggr.Debugw("filtering out destination chain from source chains") filteredSourceChains := filterOutChainSelector(sourceChains, c.destChainSelector) + lggr.Debugw("filtered source chains", "filteredSourceChains", filteredSourceChains) if len(filteredSourceChains) == 0 { + lggr.Debugw("No source chains to fetch after filtering out destination chain, returning empty map") return make(map[cciptypes.ChainSelector]StaticSourceChainConfig), nil } // Add any new source chains to list of tracked source chains for background refreshing for _, chain := range filteredSourceChains { + lggr.Debugw("adding source chain to tracking list for dest chain") if !c.trackSourceChainForDest(chain) { c.lggr.Warnw("Could not track source chain for background refreshing", "destChain", c.destChainSelector, @@ -250,9 +263,13 @@ func (c *configPollerV2) GetOfframpSourceChainConfigs( destChainCache := c.getOrCreateChainCache(c.destChainSelector) if destChainCache == nil { + lggr.Debugw("failed to get or create chain cache for destination chain") return nil, fmt.Errorf("failed to get chain cache for destination chain %s", c.destChainSelector) } + lggr.Debugw("got cache for destination chain, checking for cached source chain configs", + "cacheAge", time.Since(destChainCache.sourceChainRefresh)) + destChainCache.sourceChainMu.RLock() // Initialize results map @@ -263,9 +280,11 @@ func (c *configPollerV2) GetOfframpSourceChainConfigs( for _, chain := range filteredSourceChains { staticSourceChainConfig, exists := destChainCache.staticSourceChainConfigs[chain] if exists { + lggr.Debugw("found source chain config in cache", "sourceChain", chain, "staticSourceChainConfig", staticSourceChainConfig) cachedSourceConfigs[chain] = staticSourceChainConfig } else { // This chain isn't in cache yet + lggr.Debugw("source chain config not found in cache", "sourceChain", chain) missingChains = append(missingChains, chain) } } @@ -275,26 +294,36 @@ func (c *configPollerV2) GetOfframpSourceChainConfigs( destChainCache.sourceChainMu.RUnlock() c.lggr.Debugw("All source chain configs found in cache", "destChain", c.destChainSelector, - "sourceChains", filteredSourceChains) + "sourceChains", filteredSourceChains, + "cachedSourceConfigs", cachedSourceConfigs) return cachedSourceConfigs, nil } // Release lock before issuing batch refresh destChainCache.sourceChainMu.RUnlock() + lggr.Debugw("issuing batch refresh since we had some missing chains in the cache", "missingChains", missingChains) if err := c.batchRefreshChainAndSourceConfigs(ctx, c.destChainSelector); err != nil { return nil, err } + lggr.Debugw("looping through requested source chains to build result set after batch refresh") + // Re-acquire the lock to return only the cached configs that were requested destChainCache.sourceChainMu.RLock() defer destChainCache.sourceChainMu.RUnlock() + result := make(map[cciptypes.ChainSelector]StaticSourceChainConfig) for _, chain := range filteredSourceChains { + lggr.Debugw("attempting to add source chain config to result set", "sourceChain", chain) if cfg, exists := destChainCache.staticSourceChainConfigs[chain]; exists { result[chain] = cfg + } else { + lggr.Warnw("Source chain config still not found in cache after batch refresh", "sourceChain", chain) } } + + lggr.Debugw("returning source chain configs after batch refresh", "result", result) return result, nil } @@ -344,7 +373,7 @@ func (c *configPollerV2) refreshAllKnownChains() { for _, chain := range chainsToRefresh { ctx, cancel := context.WithTimeout(context.Background(), bgRefreshTimeout) c.lggr.Debugw("Issuing background refresh for known chain", - "chain", chain, "destChain", c.destChainSelector) + "chain", chain, "destChain", c.destChainSelector, "trackedSourceChains", c.knownSourceChains) if err := c.batchRefreshChainAndSourceConfigs(ctx, chain); err != nil { refreshFailed = true c.lggr.Warnw("Failed to batch refresh configs", "chain", chain, "error", err) @@ -374,6 +403,8 @@ func (c *configPollerV2) batchRefreshChainAndSourceConfigs( ctx context.Context, chainSel cciptypes.ChainSelector, ) error { + lggr := logger.With(c.lggr, "function", "config_poller_v2 batchRefreshChainAndSourceConfigs", + "chain", chainSel, "destChain", c.destChainSelector) start := time.Now() fetchingForDestChain := chainSel == c.destChainSelector @@ -381,15 +412,19 @@ func (c *configPollerV2) batchRefreshChainAndSourceConfigs( if fetchingForDestChain { // Acquires read lock on 'c' sourceChainSelectors = c.getKnownSourceChainsForDestChain() + lggr.Debugw("Issuing batch refresh for dest chain", + "destChainSelector", c.destChainSelector, "sourceChains", sourceChainSelectors) } // Use chainAccessor to fetch ChainConfigSnapshot (and SourceChainConfigs if destChain) accessor, err := getChainAccessor(c.chainAccessors, chainSel) if err != nil { - c.lggr.Errorw("Failed to get chain accessor", "chain", chainSel, "error", err) + lggr.Errorw("Failed to get chain accessor", "chain", chainSel, "error", err) return fmt.Errorf("failed to get chain accessor for %s: %w", chainSel, err) } + lggr.Debugw("calling accessor.GetAllConfigsLegacy", "sourceChainSelectors", sourceChainSelectors) + // NO LOCKING DURING IO chainConfigSnapshot, sourceChainConfigs, err := accessor.GetAllConfigsLegacy( ctx, @@ -397,7 +432,8 @@ func (c *configPollerV2) batchRefreshChainAndSourceConfigs( sourceChainSelectors, ) if err != nil { - c.lggr.Errorw("Failed batch fetch via chainAccessor", "chain", chainSel, "error", err) + lggr.Errorw("Failed batch fetch via chainAccessor", + "chain", chainSel, "destChainSelector", c.destChainSelector, "error", err) return err } @@ -410,6 +446,7 @@ func (c *configPollerV2) batchRefreshChainAndSourceConfigs( cache.chainConfigMu.Lock() cache.chainConfigData = chainConfigSnapshot cache.chainConfigRefresh = time.Now() + lggr.Debugw("fetched chainConfigSnapshot via chainAccessor", "chainConfigSnapshot", chainConfigSnapshot) cache.chainConfigMu.Unlock() // Acquire StaticSourceChainConfigs lock and update @@ -420,6 +457,13 @@ func (c *configPollerV2) batchRefreshChainAndSourceConfigs( } cache.sourceChainRefresh = time.Now() cache.sourceChainMu.Unlock() + c.lggr.Debugw("Batch refreshed for dest chain", + "destChainSelector", c.destChainSelector, + "sourceChainsFetched", len(sourceChainConfigs), + "chainSel", chainSel, + "latency", time.Since(start), + "cache.staticSourceChainConfigs", cache.staticSourceChainConfigs) + } else if !fetchingForDestChain && len(sourceChainConfigs) > 0 { c.lggr.Errorw("OffRamp SourceChainConfigs were returned when fetching configs from a source chain, "+ "this is not expected", @@ -428,7 +472,9 @@ func (c *configPollerV2) batchRefreshChainAndSourceConfigs( "sourceChainSelectors", sourceChainSelectors, ) } - c.lggr.Debugw("Batch refreshed configs via chainAccessor", "chain", chainSel, "latency", time.Since(start)) + c.lggr.Debugw("Batch refreshed configs via chainAccessor", "chain", chainSel, "latency", time.Since(start), + "chainConfigSnapshot", chainConfigSnapshot, + "sourceChainConfigs", sourceChainConfigs) return nil } @@ -489,6 +535,7 @@ func (c *configPollerV2) trackSourceChainForDest(sourceChain cciptypes.ChainSele defer c.Unlock() // Add the source chain to the knownSourceChains map for the destination chain + c.lggr.Debugw("Tracking source chain", "destChain", c.destChainSelector, "sourceChain", sourceChain) c.knownSourceChains[sourceChain] = struct{}{} return true }