Logging improvements - reduce spam of warn logs (#381)

* logging improvements

* logging improvements

commit/chainfee/outcome.go

@@ -50,11 +50,12 @@ func (p *processor) Outcome(
 		// 1 LINK = 5.00 USD per full token, each full token is 1e18 units -> 5 * 1e18 * 1e18 / 1e18 = 5e18
 		usdPerFeeToken, ok := consensusObs.NativeTokenPrices[chain]
 		if !ok {
-			p.lggr.Warnw("missing native token price for chain",
+			p.lggr.Warnw("missing native token price for chain, chain fee will not be updated",
 				"chain", chain,
 			)
 			continue
 		}
+		p.lggr.Debugw("USD per fee token", "chain", chain, "usdPerFeeToken", usdPerFeeToken)
 
 		// Example with Wei as the lowest denominator and Eth as the Fee token
 		// usdPerEthToken = Xe18USD18

commit/report.go

@@ -8,6 +8,7 @@ import (
 	"fmt"
 	"time"
 
+	"github.com/smartcontractkit/chainlink-common/pkg/logger"
 	"golang.org/x/exp/maps"
 
 	"github.com/smartcontractkit/libocr/offchainreporting2plus/ocr3types"
@@ -125,8 +126,10 @@ func (p *Plugin) validateReport(
 	seqNr uint64,
 	r ocr3types.ReportWithInfo[[]byte],
 ) (bool, cciptypes.CommitPluginReport, error) {
+	lggr := logger.With(p.lggr, "seqNr", seqNr)
+
 	if r.Report == nil {
-		p.lggr.Warn("nil report", "seqNr", seqNr)
+		lggr.Warn("nil report")
 		return false, cciptypes.CommitPluginReport{}, nil
 	}
 
@@ -136,7 +139,7 @@ func (p *Plugin) validateReport(
 	}
 
 	if decodedReport.IsEmpty() {
-		p.lggr.Warnw("empty report after decoding", "seqNr", seqNr, "decodedReport", decodedReport)
+		lggr.Warnw("empty report after decoding", "decodedReport", decodedReport)
 		return false, cciptypes.CommitPluginReport{}, nil
 	}
 
@@ -148,7 +151,7 @@ func (p *Plugin) validateReport(
 	if p.offchainCfg.RMNEnabled &&
 		len(decodedReport.MerkleRoots) > 0 &&
 		consensus.LtFPlusOne(int(reportInfo.RemoteF), len(decodedReport.RMNSignatures)) {
-		p.lggr.Infow("report with insufficient RMN signatures %d < %d+1",
+		lggr.Infof("report with insufficient RMN signatures %d < %d+1",
 			len(decodedReport.RMNSignatures), reportInfo.RemoteF)
 		return false, cciptypes.CommitPluginReport{}, nil
 	}
@@ -160,7 +163,7 @@ func (p *Plugin) validateReport(
 	}
 
 	if !supports {
-		p.lggr.Warnw("dest chain not supported, can't run report acceptance procedures")
+		lggr.Warnw("dest chain not supported, can't run report acceptance procedures")
 		return false, cciptypes.CommitPluginReport{}, nil
 	}
 
@@ -170,7 +173,7 @@ func (p *Plugin) validateReport(
 	}
 
 	if !bytes.Equal(offRampConfigDigest[:], p.reportingCfg.ConfigDigest[:]) {
-		p.lggr.Warnw("my config digest doesn't match offramp's config digest, not accepting report",
+		lggr.Warnw("my config digest doesn't match offramp's config digest, not accepting report",
 			"myConfigDigest", p.reportingCfg.ConfigDigest,
 			"offRampConfigDigest", hex.EncodeToString(offRampConfigDigest[:]),
 		)
@@ -188,7 +191,7 @@ func (p *Plugin) validateReport(
 
 	err = merkleroot.ValidateMerkleRootsState(ctx, decodedReport.MerkleRoots, p.ccipReader)
 	if err != nil {
-		p.lggr.Warnw("report reached transmission protocol but not transmitted, invalid merkle roots state",
+		lggr.Infow("report reached transmission protocol but not transmitted, invalid merkle roots state",
 			"err", err, "merkleRoots", decodedReport.MerkleRoots)
 		return false, cciptypes.CommitPluginReport{}, nil
 	}
@@ -205,7 +208,7 @@ func (p *Plugin) ShouldAcceptAttestedReport(
 	}
 
 	if !valid {
-		p.lggr.Warnw("report not valid, not accepting", "seqNr", seqNr)
+		p.lggr.Infow("report is not accepted", "seqNr", seqNr)
 		return false, nil
 	}
 
@@ -266,7 +269,7 @@ func (p *Plugin) ShouldTransmitAcceptedReport(
 	}
 
 	if !valid {
-		p.lggr.Warnw("report not valid, not transmitting", "seqNr", seqNr)
+		p.lggr.Infow("report not valid, not transmitting", "seqNr", seqNr)
 		return false, nil
 	}
 

execute/plugin.go

@@ -341,9 +341,11 @@ func (p *Plugin) validateReport(
 	seqNr uint64,
 	r ocr3types.ReportWithInfo[[]byte],
 ) (valid bool, decodedReport cciptypes.ExecutePluginReport, err error) {
+	lggr := logger.With(p.lggr, "seqNr", seqNr)
+
 	// Just a safety check, should never happen.
 	if r.Report == nil {
-		p.lggr.Warn("skipping nil report", "seqNr", seqNr)
+		lggr.Warn("skipping nil report")
 		return false, cciptypes.ExecutePluginReport{}, nil
 	}
 
@@ -353,7 +355,7 @@ func (p *Plugin) validateReport(
 	}
 
 	if len(decodedReport.ChainReports) == 0 {
-		p.lggr.Info("skipping empty report", "seqNr", seqNr)
+		lggr.Infow("skipping empty report")
 		return false, cciptypes.ExecutePluginReport{}, nil
 	}
 
@@ -364,7 +366,7 @@ func (p *Plugin) validateReport(
 	}
 
 	if !supports {
-		p.lggr.Warnw("dest chain not supported, can't run report acceptance procedures", "seqNr", seqNr)
+		lggr.Warnw("dest chain not supported, can't run report acceptance procedures")
 		return false, cciptypes.ExecutePluginReport{}, nil
 	}
 
@@ -374,10 +376,9 @@ func (p *Plugin) validateReport(
 	}
 
 	if !bytes.Equal(offRampConfigDigest[:], p.reportingCfg.ConfigDigest[:]) {
-		p.lggr.Warnw("my config digest doesn't match offramp's config digest, not accepting/transmitting report",
+		lggr.Warnw("my config digest doesn't match offramp's config digest, not accepting/transmitting report",
 			"myConfigDigest", p.reportingCfg.ConfigDigest,
 			"offRampConfigDigest", hex.EncodeToString(offRampConfigDigest[:]),
-			"seqNr", seqNr,
 		)
 		return false, cciptypes.ExecutePluginReport{}, nil
 	}
@@ -394,7 +395,7 @@ func (p *Plugin) ShouldAcceptAttestedReport(
 	}
 
 	if !valid {
-		p.lggr.Warnw("report not valid, not accepting", "seqNr", seqNr)
+		p.lggr.Infow("report is not accepted", "seqNr", seqNr)
 		return false, nil
 	}
 
@@ -417,7 +418,10 @@ func (p *Plugin) ShouldAcceptAttestedReport(
 		return false, nil
 	}
 
-	p.lggr.Info("ShouldAcceptAttestedReport returns true, report accepted")
+	p.lggr.Infow("ShouldAcceptAttestedReport returns true, report accepted",
+		"seqNr", seqNr,
+		"reports", decodedReport.ChainReports,
+	)
 	return true, nil
 }
 
@@ -430,11 +434,14 @@ func (p *Plugin) ShouldTransmitAcceptedReport(
 	}
 
 	if !valid {
-		p.lggr.Warnw("report not valid, not transmitting", "seqNr", seqNr)
+		p.lggr.Infow("report not accepted for transmit", "seqNr", seqNr)
 		return false, nil
 	}
 
-	p.lggr.Infow("transmitting report", "reports", decodedReport.ChainReports)
+	p.lggr.Infow("ShouldTransmitAttestedReport returns true, report accepted",
+		"seqNr", seqNr,
+		"reports", decodedReport.ChainReports,
+	)
 	return true, nil
 }
 

internal/plugincommon/consensus/consensus.go

@@ -60,7 +60,7 @@ func GetConsensusMapAggregator[K comparable, T any](
 
 	for key, values := range items {
 		if thresh, ok := f.Get(key); ok && len(values) < int(thresh) {
-			lggr.Warnf("could not reach consensus on %s for key %v", objectName, key)
+			lggr.Debugf("could not reach consensus on %s for key %v", objectName, key)
 			continue
 		}
 		consensus[key] = agg(values)

internal/plugincommon/discovery/processor.go

@@ -155,14 +155,14 @@ func aggregateObservations(
 		for chain, addr := range ao.Observation.Addresses[consts.ContractNameOnRamp] {
 			// we don't want invalid observations to "poison" the consensus.
 			if isZero(addr) {
-				lggr.Warnf("skipping empty onramp address in observation from Oracle %d", ao.OracleID)
+				lggr.Debugf("skipping empty onramp address in observation from Oracle %d", ao.OracleID)
 				continue
 			}
 			obs.onrampAddrs[chain] = append(obs.onrampAddrs[chain], addr)
 		}
 
 		if isZero(ao.Observation.Addresses[consts.ContractNameNonceManager][dest]) {
-			lggr.Warnf("skipping empty nonce manager address in observation from Oracle %d", ao.OracleID)
+			lggr.Debugf("skipping empty nonce manager address in observation from Oracle %d", ao.OracleID)
 		} else {
 			obs.nonceManagerAddrs[dest] = append(
 				obs.nonceManagerAddrs[dest],
@@ -171,7 +171,7 @@ func aggregateObservations(
 		}
 
 		if isZero(ao.Observation.Addresses[consts.ContractNameRMNRemote][dest]) {
-			lggr.Warnf("skipping empty RMNRemote address in observation from Oracle %d", ao.OracleID)
+			lggr.Debugf("skipping empty RMNRemote address in observation from Oracle %d", ao.OracleID)
 		} else {
 			obs.rmnRemoteAddrs[dest] = append(
 				obs.rmnRemoteAddrs[dest],
@@ -181,7 +181,7 @@ func aggregateObservations(
 
 		for chain, addr := range ao.Observation.Addresses[consts.ContractNameRouter] {
 			if isZero(addr) {
-				lggr.Warnf("skipping empty Router address in observation from Oracle %d", ao.OracleID)
+				lggr.Debugf("skipping empty Router address in observation from Oracle %d", ao.OracleID)
 				continue
 			}
 			obs.routerAddrs[chain] = append(
@@ -193,7 +193,7 @@ func aggregateObservations(
 		for chain, addr := range ao.Observation.Addresses[consts.ContractNameFeeQuoter] {
 			// we don't want invalid observations to "poison" the consensus.
 			if isZero(addr) {
-				lggr.Warnf("skipping empty fee quoter address in observation from Oracle %d", ao.OracleID)
+				lggr.Debugf("skipping empty fee quoter address in observation from Oracle %d", ao.OracleID)
 				continue
 			}
 			obs.feeQuoterAddrs[chain] = append(obs.feeQuoterAddrs[chain], addr)
@@ -240,7 +240,7 @@ func (cdp *ContractDiscoveryProcessor) Outcome(
 		"fChainThresh", fChainThresh,
 	)
 	if len(onrampConsensus) == 0 {
-		cdp.lggr.Warnw("No consensus on onramps, onrampConsensus map is empty")
+		cdp.lggr.Debugw("No consensus on onramps, onrampConsensus map is empty")
 	}
 	contracts[consts.ContractNameOnRamp] = onrampConsensus
 
@@ -256,7 +256,7 @@ func (cdp *ContractDiscoveryProcessor) Outcome(
 		"fChainThresh", fChainThresh,
 	)
 	if len(nonceManagerConsensus) == 0 {
-		cdp.lggr.Warnw("No consensus on nonce manager, nonceManagerConsensus map is empty")
+		cdp.lggr.Debugw("No consensus on nonce manager, nonceManagerConsensus map is empty")
 	}
 	contracts[consts.ContractNameNonceManager] = nonceManagerConsensus
 
@@ -273,7 +273,7 @@ func (cdp *ContractDiscoveryProcessor) Outcome(
 		"fChainThresh", fChainThresh,
 	)
 	if len(rmnRemoteConsensus) == 0 {
-		cdp.lggr.Warnw("No consensus on RMNRemote, rmnRemoteConsensus map is empty")
+		cdp.lggr.Debugw("No consensus on RMNRemote, rmnRemoteConsensus map is empty")
 	}
 	contracts[consts.ContractNameRMNRemote] = rmnRemoteConsensus
 
@@ -289,7 +289,7 @@ func (cdp *ContractDiscoveryProcessor) Outcome(
 		"fChainThresh", fChainThresh,
 	)
 	if len(feeQuoterConsensus) == 0 {
-		cdp.lggr.Warnw("No consensus on fee quoters, feeQuoterConsensus map is empty")
+		cdp.lggr.Debugw("No consensus on fee quoters, feeQuoterConsensus map is empty")
 	}
 	contracts[consts.ContractNameFeeQuoter] = feeQuoterConsensus
 
@@ -306,7 +306,7 @@ func (cdp *ContractDiscoveryProcessor) Outcome(
 		"fChainThresh", fChainThresh,
 	)
 	if len(routerConsensus) == 0 {
-		cdp.lggr.Warnw("No consensus on router, routerConsensus map is empty")
+		cdp.lggr.Debugw("No consensus on router, routerConsensus map is empty")
 	}
 	contracts[consts.ContractNameRouter] = routerConsensus