Improve logging of data column sidecars (#15728)

* Implement `SortedSliceFromMap`, `PrettySlice`, and `SortedSliceFromMap`.

* Use `SortedPrettySliceFromMap` and `SortedSliceFromMap` when needed.

beacon-chain/blockchain/process_block.go

@@ -3,7 +3,6 @@ package blockchain
 import (
 	"context"
 	"fmt"
-	"slices"
 	"time"
 
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/blocks"
@@ -746,14 +745,14 @@ func (s *Service) areDataColumnsAvailable(
 	}
 
 	// Get a map of data column indices that are not currently available.
-	missingMap, err := missingDataColumnIndices(s.dataColumnStorage, root, peerInfo.CustodyColumns)
+	missing, err := missingDataColumnIndices(s.dataColumnStorage, root, peerInfo.CustodyColumns)
 	if err != nil {
 		return errors.Wrap(err, "missing data columns")
 	}
 
 	// If there are no missing indices, all data column sidecars are available.
 	// This is the happy path.
-	if len(missingMap) == 0 {
+	if len(missing) == 0 {
 		return nil
 	}
 
@@ -770,33 +769,17 @@ func (s *Service) areDataColumnsAvailable(
 	// Avoid logging if DA check is called after next slot start.
 	if nextSlot.After(time.Now()) {
 		timer := time.AfterFunc(time.Until(nextSlot), func() {
-			missingMapCount := uint64(len(missingMap))
+			missingCount := uint64(len(missing))
 
-			if missingMapCount == 0 {
+			if missingCount == 0 {
 				return
 			}
 
-			var (
-				expected interface{} = "all"
-				missing  interface{} = "all"
-			)
-
-			numberOfColumns := params.BeaconConfig().NumberOfColumns
-			colMapCount := uint64(len(peerInfo.CustodyColumns))
-
-			if colMapCount < numberOfColumns {
-				expected = uint64MapToSortedSlice(peerInfo.CustodyColumns)
-			}
-
-			if missingMapCount < numberOfColumns {
-				missing = uint64MapToSortedSlice(missingMap)
-			}
-
 			log.WithFields(logrus.Fields{
 				"slot":            block.Slot(),
 				"root":            fmt.Sprintf("%#x", root),
-				"columnsExpected": expected,
-				"columnsWaiting":  missing,
+				"columnsExpected": helpers.SortedPrettySliceFromMap(peerInfo.CustodyColumns),
+				"columnsWaiting":  helpers.SortedPrettySliceFromMap(missing),
 			}).Warning("Data columns still missing at slot end")
 		})
 		defer timer.Stop()
@@ -812,7 +795,7 @@ func (s *Service) areDataColumnsAvailable(
 
 			for _, index := range idents.Indices {
 				// This is a data column we are expecting.
-				if _, ok := missingMap[index]; ok {
+				if _, ok := missing[index]; ok {
 					storedDataColumnsCount++
 				}
 
@@ -823,10 +806,10 @@ func (s *Service) areDataColumnsAvailable(
 				}
 
 				// Remove the index from the missing map.
-				delete(missingMap, index)
+				delete(missing, index)
 
 				// Return if there is no more missing data columns.
-				if len(missingMap) == 0 {
+				if len(missing) == 0 {
 					return nil
 				}
 			}
@@ -834,10 +817,10 @@ func (s *Service) areDataColumnsAvailable(
 		case <-ctx.Done():
 			var missingIndices interface{} = "all"
 			numberOfColumns := params.BeaconConfig().NumberOfColumns
-			missingIndicesCount := uint64(len(missingMap))
+			missingIndicesCount := uint64(len(missing))
 
 			if missingIndicesCount < numberOfColumns {
-				missingIndices = uint64MapToSortedSlice(missingMap)
+				missingIndices = helpers.SortedPrettySliceFromMap(missing)
 			}
 
 			return errors.Wrapf(ctx.Err(), "data column sidecars slot: %d, BlockRoot: %#x, missing: %v", block.Slot(), root, missingIndices)
@@ -921,16 +904,6 @@ func (s *Service) areBlobsAvailable(ctx context.Context, root [fieldparams.RootL
 	}
 }
 
-// uint64MapToSortedSlice produces a sorted uint64 slice from a map.
-func uint64MapToSortedSlice(input map[uint64]bool) []uint64 {
-	output := make([]uint64, 0, len(input))
-	for idx := range input {
-		output = append(output, idx)
-	}
-	slices.Sort[[]uint64](output)
-	return output
-}
-
 // lateBlockTasks  is called 4 seconds into the slot and performs tasks
 // related to late blocks. It emits a MissedSlot state feed event.
 // It calls FCU and sets the right attributes if we are proposing next slot

beacon-chain/core/helpers/BUILD.bazel

@@ -10,6 +10,7 @@ go_library(
         "legacy.go",
         "metrics.go",
         "randao.go",
+        "ranges.go",
         "rewards_penalties.go",
         "shuffle.go",
         "sync_committee.go",
@@ -56,6 +57,7 @@ go_test(
         "private_access_fuzz_noop_test.go",  # keep
         "private_access_test.go",
         "randao_test.go",
+        "ranges_test.go",
         "rewards_penalties_test.go",
         "shuffle_test.go",
         "sync_committee_test.go",

beacon-chain/core/helpers/ranges.go

@@ -0,0 +1,62 @@
+package helpers
+
+import (
+	"fmt"
+	"slices"
+)
+
+// SortedSliceFromMap takes a map with uint64 keys and returns a sorted slice of the keys.
+func SortedSliceFromMap(toSort map[uint64]bool) []uint64 {
+	slice := make([]uint64, 0, len(toSort))
+	for key := range toSort {
+		slice = append(slice, key)
+	}
+
+	slices.Sort(slice)
+	return slice
+}
+
+// PrettySlice returns a pretty string representation of a sorted slice of uint64.
+// `sortedSlice` must be sorted in ascending order.
+// Example: [1,2,3,5,6,7,8,10] -> "1-3,5-8,10"
+func PrettySlice(sortedSlice []uint64) string {
+	if len(sortedSlice) == 0 {
+		return ""
+	}
+
+	var result string
+	start := sortedSlice[0]
+	end := sortedSlice[0]
+
+	for i := 1; i < len(sortedSlice); i++ {
+		if sortedSlice[i] == end+1 {
+			end = sortedSlice[i]
+			continue
+		}
+
+		if start == end {
+			result += fmt.Sprintf("%d,", start)
+			start = sortedSlice[i]
+			end = sortedSlice[i]
+			continue
+		}
+
+		result += fmt.Sprintf("%d-%d,", start, end)
+		start = sortedSlice[i]
+		end = sortedSlice[i]
+	}
+
+	if start == end {
+		result += fmt.Sprintf("%d", start)
+		return result
+	}
+
+	result += fmt.Sprintf("%d-%d", start, end)
+	return result
+}
+
+// SortedPrettySliceFromMap combines SortedSliceFromMap and PrettySlice to return a pretty string representation of the keys in a map.
+func SortedPrettySliceFromMap(toSort map[uint64]bool) string {
+	sorted := SortedSliceFromMap(toSort)
+	return PrettySlice(sorted)
+}

beacon-chain/core/helpers/ranges_test.go

@@ -0,0 +1,64 @@
+package helpers_test
+
+import (
+	"testing"
+
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
+	"github.com/OffchainLabs/prysm/v6/testing/require"
+)
+
+func TestSortedSliceFromMap(t *testing.T) {
+	input := map[uint64]bool{5: true, 3: true, 8: true, 1: true}
+	expected := []uint64{1, 3, 5, 8}
+
+	actual := helpers.SortedSliceFromMap(input)
+	require.Equal(t, len(expected), len(actual))
+
+	for i := range expected {
+		require.Equal(t, expected[i], actual[i])
+	}
+}
+
+func TestPrettySlice(t *testing.T) {
+	tests := []struct {
+		name     string
+		input    []uint64
+		expected string
+	}{
+		{
+			name:     "empty slice",
+			input:    []uint64{},
+			expected: "",
+		},
+		{
+			name:     "only distinct elements",
+			input:    []uint64{1, 3, 5, 7, 9},
+			expected: "1,3,5,7,9",
+		},
+		{
+			name:     "single range",
+			input:    []uint64{1, 2, 3, 4, 5},
+			expected: "1-5",
+		},
+		{
+			name:     "multiple ranges and distinct elements",
+			input:    []uint64{1, 2, 3, 5, 6, 7, 8, 10, 12, 13, 14},
+			expected: "1-3,5-8,10,12-14",
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			actual := helpers.PrettySlice(tt.input)
+			require.Equal(t, tt.expected, actual)
+		})
+	}
+}
+
+func TestSortedPrettySliceFromMap(t *testing.T) {
+	input := map[uint64]bool{5: true, 7: true, 8: true, 10: true}
+	expected := "5,7-8,10"
+
+	actual := helpers.SortedPrettySliceFromMap(input)
+	require.Equal(t, expected, actual)
+}

beacon-chain/sync/data_column_sidecars.go

@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/blockchain"
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/peerdas"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/db/filesystem"
 	prysmP2P "github.com/OffchainLabs/prysm/v6/beacon-chain/p2p"
@@ -187,7 +188,7 @@ func requestSidecarsFromStorage(
 	requestedIndicesMap map[uint64]bool,
 	roots map[[fieldparams.RootLength]byte]bool,
 ) (map[[fieldparams.RootLength]byte][]blocks.VerifiedRODataColumn, error) {
-	requestedIndices := sortedSliceFromMap(requestedIndicesMap)
+	requestedIndices := helpers.SortedSliceFromMap(requestedIndicesMap)
 
 	result := make(map[[fieldparams.RootLength]byte][]blocks.VerifiedRODataColumn, len(roots))
 
@@ -599,7 +600,7 @@ func assembleAvailableSidecarsForRoot(
 	root [fieldparams.RootLength]byte,
 	indices map[uint64]bool,
 ) ([]blocks.VerifiedRODataColumn, error) {
-	stored, err := storage.Get(root, sortedSliceFromMap(indices))
+	stored, err := storage.Get(root, helpers.SortedSliceFromMap(indices))
 	if err != nil {
 		return nil, errors.Wrapf(err, "storage get for root %#x", root)
 	}
@@ -802,25 +803,27 @@ func sendDataColumnSidecarsRequest(
 			roDataColumns = append(roDataColumns, localRoDataColumns...)
 		}
 
-		prettyByRangeRequests := make([]map[string]any, 0, len(byRangeRequests))
-		for _, request := range byRangeRequests {
-			prettyRequest := map[string]any{
-				"startSlot": request.StartSlot,
-				"count":     request.Count,
-				"columns":   request.Columns,
+		if logrus.GetLevel() >= logrus.DebugLevel {
+			prettyByRangeRequests := make([]map[string]any, 0, len(byRangeRequests))
+			for _, request := range byRangeRequests {
+				prettyRequest := map[string]any{
+					"startSlot": request.StartSlot,
+					"count":     request.Count,
+					"columns":   helpers.PrettySlice(request.Columns),
+				}
+
+				prettyByRangeRequests = append(prettyByRangeRequests, prettyRequest)
 			}
 
-			prettyByRangeRequests = append(prettyByRangeRequests, prettyRequest)
+			log.WithFields(logrus.Fields{
+				"respondedSidecars": len(roDataColumns),
+				"requestCount":      len(byRangeRequests),
+				"type":              "byRange",
+				"duration":          time.Since(start),
+				"requests":          prettyByRangeRequests,
+			}).Debug("Received data column sidecars")
 		}
 
-		log.WithFields(logrus.Fields{
-			"respondedSidecars": len(roDataColumns),
-			"requestCount":      len(byRangeRequests),
-			"type":              "byRange",
-			"duration":          time.Since(start),
-			"requests":          prettyByRangeRequests,
-		}).Debug("Received data column sidecars")
-
 		return roDataColumns, nil
 	}
 
@@ -895,7 +898,7 @@ func buildByRangeRequests(
 		}
 	}
 
-	columns := sortedSliceFromMap(reference)
+	columns := helpers.SortedSliceFromMap(reference)
 	startSlot, endSlot := slots[0], slots[len(slots)-1]
 	totalCount := uint64(endSlot - startSlot + 1)
 
@@ -920,7 +923,7 @@ func buildByRootRequest(indicesByRoot map[[fieldparams.RootLength]byte]map[uint6
 	for root, indices := range indicesByRoot {
 		identifier := &eth.DataColumnsByRootIdentifier{
 			BlockRoot: root[:],
-			Columns:   sortedSliceFromMap(indices),
+			Columns:   helpers.SortedSliceFromMap(indices),
 		}
 		identifiers = append(identifiers, identifier)
 	}
@@ -1173,17 +1176,6 @@ func compareIndices(left, right map[uint64]bool) bool {
 	return true
 }
 
-// sortedSliceFromMap converts a map[uint64]bool to a sorted slice of keys.
-func sortedSliceFromMap(m map[uint64]bool) []uint64 {
-	result := make([]uint64, 0, len(m))
-	for k := range m {
-		result = append(result, k)
-	}
-
-	slices.Sort(result)
-	return result
-}
-
 // computeTotalCount calculates the total count of indices across all roots.
 func computeTotalCount(input map[[fieldparams.RootLength]byte]map[uint64]bool) int {
 	totalCount := 0

beacon-chain/sync/data_column_sidecars_test.go

@@ -1007,13 +1007,6 @@ func TestCompareIndices(t *testing.T) {
 	require.Equal(t, true, compareIndices(left, right))
 }
 
-func TestSlortedSliceFromMap(t *testing.T) {
-	input := map[uint64]bool{54: true, 23: true, 35: true}
-	expected := []uint64{23, 35, 54}
-	actual := sortedSliceFromMap(input)
-	require.DeepEqual(t, expected, actual)
-}
-
 func TestComputeTotalCount(t *testing.T) {
 	input := map[[fieldparams.RootLength]byte]map[uint64]bool{
 		[fieldparams.RootLength]byte{1}: {1: true, 3: true},

beacon-chain/sync/data_columns_reconstruct.go

@@ -6,6 +6,7 @@ import (
 	"sync"
 	"time"
 
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/peerdas"
 	fieldparams "github.com/OffchainLabs/prysm/v6/config/fieldparams"
 	"github.com/OffchainLabs/prysm/v6/config/params"
@@ -95,7 +96,7 @@ func (s *Service) processDataColumnSidecarsFromReconstruction(ctx context.Contex
 					"slot":          slot,
 					"proposerIndex": proposerIndex,
 					"count":         len(unseenIndices),
-					"indices":       sortedSliceFromMap(unseenIndices),
+					"indices":       helpers.SortedPrettySliceFromMap(unseenIndices),
 					"duration":      duration,
 				}).Debug("Reconstructed data column sidecars")
 			}

beacon-chain/sync/initial-sync/BUILD.bazel

@@ -20,6 +20,7 @@ go_library(
         "//beacon-chain/blockchain:go_default_library",
         "//beacon-chain/core/feed/block:go_default_library",
         "//beacon-chain/core/feed/state:go_default_library",
+        "//beacon-chain/core/helpers:go_default_library",
         "//beacon-chain/core/peerdas:go_default_library",
         "//beacon-chain/core/transition:go_default_library",
         "//beacon-chain/das:go_default_library",

beacon-chain/sync/initial-sync/blocks_fetcher.go

@@ -3,12 +3,12 @@ package initialsync
 import (
 	"context"
 	"fmt"
-	"slices"
 	"sort"
 	"strings"
 	"sync"
 	"time"
 
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/peerdas"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/db"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/db/filesystem"
@@ -430,9 +430,9 @@ func (f *blocksFetcher) fetchSidecars(ctx context.Context, pid peer.ID, peers []
 	}
 
 	if len(missingIndicesByRoot) > 0 {
-		prettyMissingIndicesByRoot := make(map[string][]uint64, len(missingIndicesByRoot))
+		prettyMissingIndicesByRoot := make(map[string]string, len(missingIndicesByRoot))
 		for root, indices := range missingIndicesByRoot {
-			prettyMissingIndicesByRoot[fmt.Sprintf("%#x", root)] = sortedSliceFromMap(indices)
+			prettyMissingIndicesByRoot[fmt.Sprintf("%#x", root)] = helpers.SortedPrettySliceFromMap(indices)
 		}
 		return "", errors.Errorf("some sidecars are still missing after fetch: %v", prettyMissingIndicesByRoot)
 	}
@@ -727,17 +727,6 @@ func (f *blocksFetcher) fetchBlobsFromPeer(ctx context.Context, bwb []blocks.Blo
 	return "", errNoPeersAvailable
 }
 
-// sortedSliceFromMap returns a sorted slice of keys from a map.
-func sortedSliceFromMap(m map[uint64]bool) []uint64 {
-	result := make([]uint64, 0, len(m))
-	for k := range m {
-		result = append(result, k)
-	}
-
-	slices.Sort(result)
-	return result
-}
-
 // requestBlocks is a wrapper for handling BeaconBlocksByRangeRequest requests/streams.
 func (f *blocksFetcher) requestBlocks(
 	ctx context.Context,

beacon-chain/sync/initial-sync/blocks_fetcher_test.go

@@ -1349,14 +1349,6 @@ func TestBlockFetcher_HasSufficientBandwidth(t *testing.T) {
 	assert.Equal(t, 2, len(receivedPeers))
 }
 
-func TestSortedSliceFromMap(t *testing.T) {
-	m := map[uint64]bool{1: true, 3: true, 2: true, 4: true}
-	expected := []uint64{1, 2, 3, 4}
-
-	actual := sortedSliceFromMap(m)
-	require.DeepSSZEqual(t, expected, actual)
-}
-
 func TestFetchSidecars(t *testing.T) {
 	ctx := t.Context()
 	t.Run("No blocks", func(t *testing.T) {

beacon-chain/sync/initial-sync/service.go

@@ -12,6 +12,7 @@ import (
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/blockchain"
 	blockfeed "github.com/OffchainLabs/prysm/v6/beacon-chain/core/feed/block"
 	statefeed "github.com/OffchainLabs/prysm/v6/beacon-chain/core/feed/state"
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/peerdas"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/das"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/db"
@@ -479,7 +480,7 @@ func (s *Service) fetchOriginDataColumnSidecars(roBlock blocks.ROBlock, delay ti
 		// Some sidecars are still missing.
 		log := log.WithFields(logrus.Fields{
 			"attempt":        attempt,
-			"missingIndices": sortedSliceFromMap(missingIndicesByRoot[root]),
+			"missingIndices": helpers.SortedPrettySliceFromMap(missingIndicesByRoot[root]),
 			"delay":          delay,
 		})
 

beacon-chain/sync/rpc_beacon_blocks_by_root.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"fmt"
 
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/peerdas"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/db/filesystem"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/execution"
@@ -121,9 +122,9 @@ func (s *Service) requestAndSaveMissingDataColumnSidecars(blks []blocks.ROBlock)
 	}
 
 	if len(missingIndicesByRoot) > 0 {
-		prettyMissingIndicesByRoot := make(map[string][]uint64, len(missingIndicesByRoot))
+		prettyMissingIndicesByRoot := make(map[string]string, len(missingIndicesByRoot))
 		for root, indices := range missingIndicesByRoot {
-			prettyMissingIndicesByRoot[fmt.Sprintf("%#x", root)] = sortedSliceFromMap(indices)
+			prettyMissingIndicesByRoot[fmt.Sprintf("%#x", root)] = helpers.SortedPrettySliceFromMap(indices)
 		}
 		return errors.Errorf("some sidecars are still missing after fetch: %v", prettyMissingIndicesByRoot)
 	}

beacon-chain/sync/rpc_send_request.go

@@ -7,6 +7,7 @@ import (
 	"slices"
 
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/blockchain"
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/p2p"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/p2p/encoder"
 	p2ptypes "github.com/OffchainLabs/prysm/v6/beacon-chain/p2p/types"
@@ -598,7 +599,7 @@ func isSidecarIndexRequested(request *ethpb.DataColumnSidecarsByRangeRequest) Da
 	return func(sidecar blocks.RODataColumn) error {
 		columnIndex := sidecar.Index
 		if !requestedIndices[columnIndex] {
-			requested := sortedSliceFromMap(requestedIndices)
+			requested := helpers.SortedPrettySliceFromMap(requestedIndices)
 			return errors.Errorf("data column sidecar index %d returned by the peer but not found in requested indices %v", columnIndex, requested)
 		}
 

beacon-chain/sync/subscriber_beacon_blocks.go

@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/blockchain"
+	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/helpers"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/peerdas"
 	"github.com/OffchainLabs/prysm/v6/beacon-chain/core/transition/interop"
 	"github.com/OffchainLabs/prysm/v6/config/features"
@@ -227,7 +228,7 @@ func (s *Service) processDataColumnSidecarsFromExecution(ctx context.Context, so
 					"iteration":     iteration,
 					"type":          source.Type(),
 					"count":         len(unseenIndices),
-					"indices":       sortedSliceFromMap(unseenIndices),
+					"indices":       helpers.SortedPrettySliceFromMap(unseenIndices),
 				}).Debug("Constructed data column sidecars from the execution client")
 			}
 

changelog/manu-logs-datacolumns.md

@@ -0,0 +1,2 @@
+## Changed
+- Improve logging of data column sidecars