From 7a8010be0c8a762813d3348bb84c588cead6bdb0 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?Peter=20=C5=A0tibran=C3=BD?= <pstibrany@gmail.com>
Date: Thu, 28 Aug 2025 16:02:47 +0200
Subject: [PATCH] search-after-write: improve observability (#110288)

* Improve tracing and observability around updating of index during search.
---
 pkg/storage/unified/resource/search.go | 21 ++++++++++++++++-----
 pkg/storage/unified/search/bleve.go    | 15 ++++++++-------
 2 files changed, 24 insertions(+), 12 deletions(-)

diff --git a/pkg/storage/unified/resource/search.go b/pkg/storage/unified/resource/search.go
index 7a88ccbdf3c..57dc02df02d 100644
--- a/pkg/storage/unified/resource/search.go
+++ b/pkg/storage/unified/resource/search.go
@@ -24,6 +24,7 @@ import (
 
 	dashboardv1 "github.com/grafana/grafana/apps/dashboard/pkg/apis/dashboard/v1beta1"
 	folders "github.com/grafana/grafana/apps/folder/pkg/apis/folder/v1beta1"
+	"github.com/grafana/grafana/pkg/infra/tracing"
 	"github.com/grafana/grafana/pkg/storage/unified/resourcepb"
 )
 
@@ -659,13 +660,20 @@ func (s *searchSupport) getOrCreateIndex(ctx context.Context, key NamespacedReso
 
 	ctx, span := s.tracer.Start(ctx, tracingPrexfixSearch+"GetOrCreateIndex")
 	defer span.End()
+	span.SetAttributes(
+		attribute.String("namespace", key.Namespace),
+		attribute.String("group", key.Group),
+		attribute.String("resource", key.Resource),
+		attribute.String("namespace", key.Namespace),
+	)
 
 	idx, err := s.search.GetIndex(ctx, key)
 	if err != nil {
-		return nil, err
+		return nil, tracing.Error(span, err)
 	}
 
 	if idx == nil {
+		span.AddEvent("Building index")
 		ch := s.buildIndex.DoChan(key.String(), func() (interface{}, error) {
 			// We want to finish building of the index even if original context is canceled.
 			// We reuse original context without cancel to keep the tracing spans correct.
@@ -708,24 +716,27 @@ func (s *searchSupport) getOrCreateIndex(ctx context.Context, key NamespacedReso
 		select {
 		case res := <-ch:
 			if res.Err != nil {
-				return nil, res.Err
+				return nil, tracing.Error(span, res.Err)
 			}
 			idx = res.Val.(ResourceIndex)
 		case <-ctx.Done():
-			return nil, fmt.Errorf("failed to get index: %w", ctx.Err())
+			return nil, tracing.Error(span, fmt.Errorf("failed to get index: %w", ctx.Err()))
 		}
 	}
 
 	if s.searchAfterWrite {
+		span.AddEvent("Updating index")
 		start := time.Now()
-		_, err := idx.UpdateIndex(ctx, reason)
+		rv, err := idx.UpdateIndex(ctx, reason)
 		if err != nil {
-			return nil, fmt.Errorf("failed to update index to guarantee strong consistency: %w", err)
+			return nil, tracing.Error(span, fmt.Errorf("failed to update index to guarantee strong consistency: %w", err))
 		}
 		elapsed := time.Since(start)
 		if s.indexMetrics != nil {
 			s.indexMetrics.SearchUpdateWaitTime.WithLabelValues(reason).Observe(elapsed.Seconds())
 		}
+		s.log.Debug("Index updated before search", "namespace", key.Namespace, "group", key.Group, "resource", key.Resource, "reason", reason, "duration", elapsed, "rv", rv)
+		span.AddEvent("Index updated")
 	}
 
 	return idx, nil
diff --git a/pkg/storage/unified/search/bleve.go b/pkg/storage/unified/search/bleve.go
index 72853abe3eb..b0ab36e36e1 100644
--- a/pkg/storage/unified/search/bleve.go
+++ b/pkg/storage/unified/search/bleve.go
@@ -1268,17 +1268,18 @@ func (b *bleveIndex) updateIndexWithLatestModifications(ctx context.Context, req
 	ctx, span := b.tracing.Start(ctx, tracingPrexfixBleve+"updateIndexWithLatestModifications")
 	defer span.End()
 
-	b.logger.Debug("Updating index", "sinceRV", b.resourceVersion, "requests", requests, "reasons", reasons)
+	sinceRV := b.resourceVersion
+	b.logger.Debug("Updating index", "sinceRV", sinceRV, "requests", requests, "reasons", reasons)
 
 	startTime := time.Now()
-	rv, docs, err := b.updaterFn(ctx, b, b.resourceVersion)
-	if err == nil && rv > 0 {
-		err = b.updateResourceVersion(rv)
+	listRV, docs, err := b.updaterFn(ctx, b, sinceRV)
+	if err == nil && listRV > 0 {
+		err = b.updateResourceVersion(listRV) // updates b.resourceVersion
 	}
 
 	elapsed := time.Since(startTime)
 	if err == nil {
-		b.logger.Debug("Finished updating index", "listRV", b.resourceVersion, "duration", elapsed, "docs", docs)
+		b.logger.Debug("Finished updating index", "sinceRV", sinceRV, "listRV", listRV, "duration", elapsed, "docs", docs, "reasons", reasons)
 
 		if b.updateLatency != nil {
 			b.updateLatency.Observe(elapsed.Seconds())
@@ -1287,9 +1288,9 @@ func (b *bleveIndex) updateIndexWithLatestModifications(ctx context.Context, req
 			b.updatedDocuments.Observe(float64(docs))
 		}
 	} else {
-		b.logger.Debug("Updating of index finished with error", "duration", elapsed, "err", err)
+		b.logger.Error("Updating of index finished with error", "duration", elapsed, "err", err)
 	}
-	return rv, err
+	return listRV, err
 }
 
 func safeInt64ToInt(i64 int64) (int, error) {