sql: add MVCC steps and seeks to EXPLAIN ANALYZE

pkg/roachpb/api.go

@@ -1628,3 +1628,14 @@ func (c *TenantConsumption) Sub(other *TenantConsumption) {
 		c.SQLPodsCPUSeconds -= other.SQLPodsCPUSeconds
 	}
 }
+
+// SafeFormat implements redact.SafeFormatter.
+func (s *ScanStats) SafeFormat(w redact.SafePrinter, _ rune) {
+	w.Printf("scan stats: stepped %d times (%d internal); seeked %d times (%d internal)",
+		s.NumInterfaceSteps, s.NumInternalSteps, s.NumInterfaceSeeks, s.NumInternalSeeks)
+}
+
+// String implements fmt.Stringer.
+func (s *ScanStats) String() string {
+	return redact.StringWithoutMarkers(s)
+}

pkg/roachpb/api.proto

@@ -2577,3 +2577,14 @@ message ContentionEvent {
   google.protobuf.Duration duration = 3 [(gogoproto.nullable) = false,
                                          (gogoproto.stdduration) = true];
 }
+
+// ScanStats is a message that will be attached to BatchResponses containing
+// information about what happened during each scan and get in the request.
+message ScanStats {
+  option (gogoproto.goproto_stringer) = false;
+
+  uint64 num_interface_seeks = 1;
+  uint64 num_internal_seeks = 2;
+  uint64 num_interface_steps = 3;
+  uint64 num_internal_steps = 4;
+}

pkg/sql/colexecop/operator.go

@@ -72,6 +72,9 @@ type KVReader interface {
 	// GetCumulativeContentionTime returns the amount of time KV reads spent
 	// contending. It must be safe for concurrent use.
 	GetCumulativeContentionTime() time.Duration
+	// GetScanStats returns statistics about the scan that happened during the
+	// KV reads. It must be safe for concurrent use.
+	GetScanStats() execinfra.ScanStats
 }
 
 // ZeroInputNode is an execinfra.OpNode with no inputs.

pkg/sql/colfetcher/colbatch_scan.go

@@ -169,6 +169,11 @@ func (s *ColBatchScan) GetCumulativeContentionTime() time.Duration {
 	return execinfra.GetCumulativeContentionTime(s.Ctx)
 }
 
+// GetScanStats is part of the colexecop.KVReader interface.
+func (s *ColBatchScan) GetScanStats() execinfra.ScanStats {
+	return execinfra.GetScanStats(s.Ctx)
+}
+
 var colBatchScanPool = sync.Pool{
 	New: func() interface{} {
 		return &ColBatchScan{}

pkg/sql/colfetcher/index_join.go

@@ -514,6 +514,11 @@ func adjustMemEstimate(estimate int64) int64 {
 	return estimate*memEstimateMultiplier + memEstimateAdditive
 }
 
+// GetScanStats is part of the colexecop.KVReader interface.
+func (s *ColIndexJoin) GetScanStats() execinfra.ScanStats {
+	return execinfra.GetScanStats(s.Ctx)
+}
+
 // Release implements the execinfra.Releasable interface.
 func (s *ColIndexJoin) Release() {
 	s.rf.Release()

pkg/sql/colflow/stats.go

@@ -19,6 +19,7 @@ import (
 	"github.com/cockroachdb/cockroach/pkg/sql/colexecerror"
 	"github.com/cockroachdb/cockroach/pkg/sql/colexecop"
 	"github.com/cockroachdb/cockroach/pkg/sql/colflow/colrpc"
+	"github.com/cockroachdb/cockroach/pkg/sql/execinfra"
 	"github.com/cockroachdb/cockroach/pkg/sql/execinfrapb"
 	"github.com/cockroachdb/cockroach/pkg/util"
 	"github.com/cockroachdb/cockroach/pkg/util/mon"
@@ -212,6 +213,8 @@ func (vsc *vectorizedStatsCollectorImpl) GetStats() *execinfrapb.ComponentStats
 		s.KV.TuplesRead.Set(uint64(vsc.kvReader.GetRowsRead()))
 		s.KV.BytesRead.Set(uint64(vsc.kvReader.GetBytesRead()))
 		s.KV.ContentionTime.Set(vsc.kvReader.GetCumulativeContentionTime())
+		scanStats := vsc.kvReader.GetScanStats()
+		execinfra.PopulateKVMVCCStats(&s.KV, &scanStats)
 	} else {
 		s.Exec.ExecTime.Set(time)
 	}

pkg/sql/execinfra/stats.go

@@ -15,6 +15,8 @@ import (
 	"time"
 
 	"github.com/cockroachdb/cockroach/pkg/roachpb"
+	"github.com/cockroachdb/cockroach/pkg/sql/execinfrapb"
+	"github.com/cockroachdb/cockroach/pkg/util/optional"
 	"github.com/cockroachdb/cockroach/pkg/util/tracing"
 	pbtypes "github.com/gogo/protobuf/types"
 )
@@ -50,3 +52,55 @@ func GetCumulativeContentionTime(ctx context.Context) time.Duration {
 	}
 	return cumulativeContentionTime
 }
+
+// ScanStats contains statistics on the internal MVCC operators used to satisfy
+// a scan. See storage/engine.go for a more thorough discussion of the meaning
+// of each stat.
+type ScanStats struct {
+	// NumInterfaceSteps is the number of times the MVCC step function was called
+	// to satisfy a scan.
+	NumInterfaceSteps uint64
+	// NumInternalSteps is the number of times that MVCC step was invoked
+	// internally, including to step over internal, uncompacted Pebble versions.
+	NumInternalSteps uint64
+	// NumInterfaceSeeks is the number of times the MVCC seek function was called
+	// to satisfy a scan.
+	NumInterfaceSeeks uint64
+	// NumInternalSeeks is the number of times that MVCC seek was invoked
+	// internally, including to step over internal, uncompacted Pebble versions.
+	NumInternalSeeks uint64
+}
+
+// PopulateKVMVCCStats adds data from the input ScanStats to the input KVStats.
+func PopulateKVMVCCStats(kvStats *execinfrapb.KVStats, ss *ScanStats) {
+	kvStats.NumInterfaceSteps = optional.MakeUint(ss.NumInterfaceSteps)
+	kvStats.NumInternalSteps = optional.MakeUint(ss.NumInternalSteps)
+	kvStats.NumInterfaceSeeks = optional.MakeUint(ss.NumInterfaceSeeks)
+	kvStats.NumInternalSeeks = optional.MakeUint(ss.NumInternalSeeks)
+}
+
+// GetScanStats is a helper function to calculate scan stats from the tracing
+// span from the context.
+func GetScanStats(ctx context.Context) (ss ScanStats) {
+	recording := GetTraceData(ctx)
+	if recording == nil {
+		return ScanStats{}
+	}
+	var ev roachpb.ScanStats
+	for i := range recording {
+		recording[i].Structured(func(any *pbtypes.Any, _ time.Time) {
+			if !pbtypes.Is(any, &ev) {
+				return
+			}
+			if err := pbtypes.UnmarshalAny(any, &ev); err != nil {
+				return
+			}
+
+			ss.NumInterfaceSteps += ev.NumInterfaceSteps
+			ss.NumInternalSteps += ev.NumInternalSteps
+			ss.NumInterfaceSeeks += ev.NumInterfaceSeeks
+			ss.NumInternalSeeks += ev.NumInternalSeeks
+		})
+	}
+	return ss
+}

pkg/sql/execinfrapb/component_stats.go

@@ -151,6 +151,20 @@ func (s *ComponentStats) formatStats(fn func(suffix string, value interface{}))
 	if s.KV.BytesRead.HasValue() {
 		fn("KV bytes read", humanize.IBytes(s.KV.BytesRead.Value()))
 	}
+	if s.KV.NumInterfaceSteps.HasValue() {
+		fn("MVCC step count (ext/int)",
+			fmt.Sprintf("%s/%s",
+				humanizeutil.Count(s.KV.NumInterfaceSteps.Value()),
+				humanizeutil.Count(s.KV.NumInternalSteps.Value())),
+		)
+	}
+	if s.KV.NumInterfaceSeeks.HasValue() {
+		fn("MVCC seek count (ext/int)",
+			fmt.Sprintf("%s/%s",
+				humanizeutil.Count(s.KV.NumInterfaceSeeks.Value()),
+				humanizeutil.Count(s.KV.NumInternalSeeks.Value())),
+		)
+	}
 
 	// Exec stats.
 	if s.Exec.ExecTime.HasValue() {
@@ -217,6 +231,18 @@ func (s *ComponentStats) Union(other *ComponentStats) *ComponentStats {
 	if !result.KV.ContentionTime.HasValue() {
 		result.KV.ContentionTime = other.KV.ContentionTime
 	}
+	if !result.KV.NumInterfaceSteps.HasValue() {
+		result.KV.NumInterfaceSteps = other.KV.NumInterfaceSteps
+	}
+	if !result.KV.NumInternalSteps.HasValue() {
+		result.KV.NumInternalSteps = other.KV.NumInternalSteps
+	}
+	if !result.KV.NumInterfaceSeeks.HasValue() {
+		result.KV.NumInterfaceSeeks = other.KV.NumInterfaceSeeks
+	}
+	if !result.KV.NumInternalSeeks.HasValue() {
+		result.KV.NumInternalSeeks = other.KV.NumInternalSeeks
+	}
 	if !result.KV.TuplesRead.HasValue() {
 		result.KV.TuplesRead = other.KV.TuplesRead
 	}
@@ -306,6 +332,10 @@ func (s *ComponentStats) MakeDeterministic() {
 	// KV.
 	timeVal(&s.KV.KVTime)
 	timeVal(&s.KV.ContentionTime)
+	resetUint(&s.KV.NumInterfaceSteps)
+	resetUint(&s.KV.NumInternalSteps)
+	resetUint(&s.KV.NumInterfaceSeeks)
+	resetUint(&s.KV.NumInternalSeeks)
 	if s.KV.BytesRead.HasValue() {
 		// BytesRead is overridden to a useful value for tests.
 		s.KV.BytesRead.Set(8 * s.KV.TuplesRead.Value())