Move some logs to trace (#15816)

* Prettify logs for byRange/byRoot data column sidecar requests.

* Moving byRoot/byRange data column sidecars requests from peers to TRACE level.

* Move "Peer requested blob sidecar by root not found in db" in TRACE.

* Add changelog.

* Fix Kasey's comment.

* Apply Kasey's suggestion.

beacon-chain/sync/rpc_blob_sidecars_by_root.go

@@ -72,17 +72,21 @@ func (s *Service) blobSidecarByRootRPCHandler(ctx context.Context, msg interface
 		root, idx := bytesutil.ToBytes32(blobIdents[i].BlockRoot), blobIdents[i].Index
 		sc, err := s.cfg.blobStorage.Get(root, idx)
 		if err != nil {
+			log := log.WithFields(logrus.Fields{
+				"root":  fmt.Sprintf("%#x", root),
+				"index": idx,
+				"peer":  remotePeer.String(),
+			})
+
 			if db.IsNotFound(err) {
-				log.WithError(err).WithFields(logrus.Fields{
-					"root":  fmt.Sprintf("%#x", root),
-					"index": idx,
-					"peer":  remotePeer.String(),
-				}).Debugf("Peer requested blob sidecar by root not found in db")
+				log.Trace("Peer requested blob sidecar by root not found in db")
 				continue
 			}
-			log.WithError(err).Errorf("unexpected db error retrieving BlobSidecar, root=%x, index=%d", root, idx)
+
+			log.Error("Unexpected DB error retrieving blob sidecar from storage")
 			s.writeErrorResponseToStream(responseCodeServerError, types.ErrGeneric.Error(), stream)
-			return err
+
+			return errors.Wrap(err, "get blob sidecar by root")
 		}
 
 		// If any root in the request content references a block earlier than minimum_request_epoch,

beacon-chain/sync/rpc_data_column_sidecars_by_range.go

@@ -5,6 +5,7 @@ import (
 	"slices"
 	"time"
 
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	p2ptypes "github.com/OffchainLabs/prysm/v6/beacon-chain/p2p/types"
 	"github.com/OffchainLabs/prysm/v6/config/params"
 	"github.com/OffchainLabs/prysm/v6/consensus-types/primitives"
@@ -41,21 +42,17 @@ func (s *Service) dataColumnSidecarsByRangeRPCHandler(ctx context.Context, msg i
 	maxRequestDataColumnSidecars := beaconConfig.MaxRequestDataColumnSidecars
 	remotePeer := stream.Conn().RemotePeer()
 
-	requestedColumns := request.Columns
-
-	// Format log fields.
-	var requestedColumnsLog interface{} = "all"
-	if uint64(len(requestedColumns)) != beaconConfig.NumberOfColumns {
-		requestedColumnsLog = requestedColumns
-	}
-
 	log := log.WithFields(logrus.Fields{
-		"remotePeer":       remotePeer,
-		"requestedColumns": requestedColumnsLog,
-		"startSlot":        request.StartSlot,
-		"count":            request.Count,
+		"remotePeer": remotePeer,
+		"startSlot":  request.StartSlot,
+		"count":      request.Count,
 	})
 
+	if log.Logger.Level >= logrus.DebugLevel {
+		slices.Sort(request.Columns)
+		log = log.WithField("requestedColumns", helpers.PrettySlice(request.Columns))
+	}
+
 	// Validate the request regarding rate limiting.
 	if err := s.rateLimiter.validateRequest(stream, rateLimitingAmount); err != nil {
 		return errors.Wrap(err, "rate limiter validate request")
@@ -69,13 +66,13 @@ func (s *Service) dataColumnSidecarsByRangeRPCHandler(ctx context.Context, msg i
 		tracing.AnnotateError(span, err)
 		return errors.Wrap(err, "validate data columns by range")
 	}
+
+	log.Trace("Serving data column sidecars by range")
+
 	if rangeParameters == nil {
-		log.Debug("No data columns by range to serve")
 		return nil
 	}
 
-	log.Debug("Serving data columns by range request")
-
 	// Ticker to stagger out large requests.
 	ticker := time.NewTicker(time.Second)
 
@@ -104,13 +101,13 @@ func (s *Service) dataColumnSidecarsByRangeRPCHandler(ctx context.Context, msg i
 
 		// Once the quota is reached, we're done serving the request.
 		if maxRequestDataColumnSidecars == 0 {
-			log.WithField("initialQuota", beaconConfig.MaxRequestDataColumnSidecars).Debug("Reached quota for data column sidecars by range request")
+			log.WithField("initialQuota", beaconConfig.MaxRequestDataColumnSidecars).Trace("Reached quota for data column sidecars by range request")
 			break
 		}
 	}
 
 	if err := batch.error(); err != nil {
-		log.WithError(err).Debug("Error in DataColumnSidecarsByRange batch")
+		log.WithError(err).Error("Cannot get next batch of blocks")
 
 		// If we hit a rate limit, the error response has already been written, and the stream is already closed.
 		if !errors.Is(err, p2ptypes.ErrRateLimited) {

beacon-chain/sync/rpc_data_column_sidecars_by_root.go

@@ -7,6 +7,7 @@ import (
 	"slices"
 	"time"
 
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/p2p/types"
 	"github.com/OffchainLabs/prysm/v6/cmd/beacon-chain/flags"
 	fieldparams "github.com/OffchainLabs/prysm/v6/config/fieldparams"
@@ -33,7 +34,6 @@ func (s *Service) dataColumnSidecarByRootRPCHandler(ctx context.Context, msg int
 	defer span.End()
 
 	batchSize := flags.Get().DataColumnBatchLimit
-	numberOfColumns := params.BeaconConfig().NumberOfColumns
 
 	// Check if the message type is the one expected.
 	ref, ok := msg.(types.DataColumnsByRootIdentifiers)
@@ -68,26 +68,13 @@ func (s *Service) dataColumnSidecarByRootRPCHandler(ctx context.Context, msg int
 		slices.Sort(columns)
 	}
 
-	// Format nice logs.
-	requestedColumnsByRootLog := make(map[string]interface{})
-	for root, columns := range requestedColumnsByRoot {
-		rootStr := fmt.Sprintf("%#x", root)
-		requestedColumnsByRootLog[rootStr] = "all"
-		if uint64(len(columns)) != numberOfColumns {
-			requestedColumnsByRootLog[rootStr] = columns
-		}
-	}
-
 	// Compute the oldest slot we'll allow a peer to request, based on the current slot.
 	minReqSlot, err := dataColumnsRPCMinValidSlot(s.cfg.clock.CurrentSlot())
 	if err != nil {
 		return errors.Wrapf(err, "data columns RPC min valid slot")
 	}
 
-	log := log.WithFields(logrus.Fields{
-		"peer":    remotePeer,
-		"columns": requestedColumnsByRootLog,
-	})
+	log := log.WithField("peer", remotePeer)
 
 	defer closeStream(stream, log)
 
@@ -96,7 +83,18 @@ func (s *Service) dataColumnSidecarByRootRPCHandler(ctx context.Context, msg int
 		ticker = time.NewTicker(tickerDelay)
 	}
 
-	log.Debug("Serving data column sidecar by root request")
+	if log.Logger.Level >= logrus.TraceLevel {
+		// We optimistially assume the peer requests the same set of columns for all roots,
+		// pre-sizing the map accordingly.
+		requestedRootsByColumnSet := make(map[string][]string, 1)
+		for root, columns := range requestedColumnsByRoot {
+			slices.Sort(columns)
+			prettyColumns := helpers.PrettySlice(columns)
+			requestedRootsByColumnSet[prettyColumns] = append(requestedRootsByColumnSet[prettyColumns], fmt.Sprintf("%#x", root))
+		}
+
+		log.WithField("requested", requestedRootsByColumnSet).Trace("Serving data column sidecars by root")
+	}
 
 	count := 0
 	for _, ident := range requestedColumnIdents {

changelog/manu-logs-to-trace.md

@@ -0,0 +1,4 @@
+### Ignored 
+- Prettify logs for byRange/byRoot data column sidecar requests.
+- Moving byRoot/byRange data column sidecars requests from peers to TRACE level.
+- Move "Peer requested blob sidecar by root not found in db" in TRACE.