Adding symbolizer instrumentation

marcsanmi · marcsanmi · commit bde1501105d5 · 2025-02-19T18:22:34.000+01:00
diff --git a/cmd/symbolization/main.go b/cmd/symbolization/main.go
@@ -16,12 +16,12 @@ const (
 )
 
 func main() {
-	client := symbolizer.NewDebuginfodClient(debuginfodBaseURL)
+	client := symbolizer.NewDebuginfodClient(debuginfodBaseURL, nil)
 
 	// Alternatively, use a local debug info file:
 	//client := &localDebuginfodClient{debugFilePath: "/path/to/your/debug/file"}
 
-	s := symbolizer.NewSymbolizer(client, nil)
+	s := symbolizer.NewSymbolizer(client, nil, nil)
 	ctx := context.Background()
 
 	_, err := client.FetchDebuginfo(buildID)
diff --git a/pkg/experiment/query_backend/backend.go b/pkg/experiment/query_backend/backend.go
@@ -66,7 +66,7 @@ func New(
 	var sym *symbolizer.Symbolizer
 	if config.Symbolizer.DebuginfodURL != "" {
 		var err error
-		sym, err = symbolizer.NewFromConfig(context.Background(), config.Symbolizer)
+		sym, err = symbolizer.NewFromConfig(context.Background(), config.Symbolizer, reg)
 		if err != nil {
 			return nil, fmt.Errorf("create symbolizer: %w", err)
 		}
diff --git a/pkg/experiment/symbolizer/cache.go b/pkg/experiment/symbolizer/cache.go
@@ -15,10 +15,11 @@ type CacheConfig struct {
 	MaxAge  time.Duration `yaml:"max_age"`
 }
 
-func NewObjstoreCache(bucket objstore.Bucket, maxAge time.Duration) *ObjstoreCache {
+func NewObjstoreCache(bucket objstore.Bucket, maxAge time.Duration, metrics *Metrics) *ObjstoreCache {
 	return &ObjstoreCache{
-		bucket: bucket,
-		maxAge: maxAge,
+		bucket:  bucket,
+		maxAge:  maxAge,
+		metrics: metrics,
 	}
 }
 
@@ -30,46 +31,69 @@ type DebugInfoCache interface {
 
 // ObjstoreCache implements DebugInfoCache using S3 storage
 type ObjstoreCache struct {
-	bucket objstore.Bucket
-	maxAge time.Duration
+	bucket  objstore.Bucket
+	maxAge  time.Duration
+	metrics *Metrics
 }
 
 func (c *ObjstoreCache) Get(ctx context.Context, buildID string) (io.ReadCloser, error) {
+	c.metrics.cacheRequestsTotal.WithLabelValues("get").Inc()
+	start := time.Now()
+	defer func() {
+		c.metrics.cacheOperationDuration.WithLabelValues("get").Observe(time.Since(start).Seconds())
+	}()
+
 	// First check if object exists to avoid unnecessary operations
 	reader, err := c.bucket.Get(ctx, buildID)
 	if err != nil {
 		if c.bucket.IsObjNotFoundErr(err) {
+			c.metrics.cacheMissesTotal.Inc()
 			return nil, err
 		}
+		c.metrics.cacheRequestErrorsTotal.WithLabelValues("get", "read_error").Inc()
 		return nil, fmt.Errorf("get from cache: %w", err)
 	}
 
 	// Get attributes - this should use the same HEAD request that Get used
 	attrs, err := c.bucket.Attributes(ctx, buildID)
 	if err != nil {
 		reader.Close()
+		c.metrics.cacheRequestErrorsTotal.WithLabelValues("get", "attribute_error").Inc()
 		return nil, fmt.Errorf("get cache attributes: %w", err)
 	}
 
 	// Check if expired
 	if time.Since(attrs.LastModified) > c.maxAge {
 		reader.Close()
+		c.metrics.cacheExpiredTotal.Inc()
+
 		// Async deletion to not block the request
 		go func() {
 			delCtx, cancel := context.WithTimeout(context.Background(), 10*time.Second)
 			defer cancel()
-			_ = c.bucket.Delete(delCtx, buildID)
+			if err = c.bucket.Delete(delCtx, buildID); err != nil {
+				c.metrics.cacheRequestErrorsTotal.WithLabelValues("delete", "delete_error").Inc()
+			}
 		}()
 		return nil, fmt.Errorf("cached object expired")
 	}
 
+	c.metrics.cacheHitsTotal.Inc()
 	return reader, nil
 }
 
 func (c *ObjstoreCache) Put(ctx context.Context, buildID string, reader io.Reader) error {
+	c.metrics.cacheRequestsTotal.WithLabelValues("put").Inc()
+	start := time.Now()
+	defer func() {
+		c.metrics.cacheOperationDuration.WithLabelValues("put").Observe(time.Since(start).Seconds())
+	}()
+
 	if err := c.bucket.Upload(ctx, buildID, reader); err != nil {
+		c.metrics.cacheRequestErrorsTotal.WithLabelValues("put", "upload_error").Inc()
 		return fmt.Errorf("upload to cache: %w", err)
 	}
+
 	return nil
 }
 
diff --git a/pkg/experiment/symbolizer/debuginfod_client.go b/pkg/experiment/symbolizer/debuginfod_client.go
@@ -7,6 +7,7 @@ import (
 	"os"
 	"path/filepath"
 	"regexp"
+	"time"
 )
 
 type DebuginfodClient interface {
@@ -15,48 +16,69 @@ type DebuginfodClient interface {
 
 type debuginfodClient struct {
 	baseURL string
+	metrics *Metrics
 }
 
-func NewDebuginfodClient(baseURL string) DebuginfodClient {
+func NewDebuginfodClient(baseURL string, metrics *Metrics) DebuginfodClient {
 	return &debuginfodClient{
 		baseURL: baseURL,
+		metrics: metrics,
 	}
 }
 
 // FetchDebuginfo fetches the debuginfo file for a specific build ID.
 func (c *debuginfodClient) FetchDebuginfo(buildID string) (string, error) {
+	c.metrics.debuginfodRequestsTotal.Inc()
+	start := time.Now()
+
 	sanitizedBuildID, err := sanitizeBuildID(buildID)
 	if err != nil {
+		c.metrics.debuginfodRequestErrorsTotal.WithLabelValues("invalid_id").Inc()
 		return "", err
 	}
 
 	url := fmt.Sprintf("%s/buildid/%s/debuginfo", c.baseURL, sanitizedBuildID)
 
 	resp, err := http.Get(url)
 	if err != nil {
+		c.metrics.debuginfodRequestErrorsTotal.WithLabelValues("http").Inc()
+		c.metrics.debuginfodRequestDuration.WithLabelValues("error").Observe(time.Since(start).Seconds())
 		return "", fmt.Errorf("failed to fetch debuginfod: %w", err)
 	}
 	defer resp.Body.Close()
 
 	if resp.StatusCode != http.StatusOK {
+		c.metrics.debuginfodRequestErrorsTotal.WithLabelValues("http").Inc()
+		c.metrics.debuginfodRequestDuration.WithLabelValues("error").Observe(time.Since(start).Seconds())
 		return "", fmt.Errorf("unexpected HTTP status: %s", resp.Status)
 	}
 
+	// Record file size from Content-Length if available
+	if contentLength := resp.ContentLength; contentLength > 0 {
+		c.metrics.debuginfodFileSize.Observe(float64(contentLength))
+	}
+
 	// TODO: Avoid file operations and handle debuginfo in memory.
 	// Save the debuginfo to a temporary file
 	tempDir := os.TempDir()
 	filePath := filepath.Join(tempDir, fmt.Sprintf("%s.elf", sanitizedBuildID))
 	outFile, err := os.Create(filePath)
 	if err != nil {
+		c.metrics.debuginfodRequestErrorsTotal.WithLabelValues("file_create").Inc()
+		c.metrics.debuginfodRequestDuration.WithLabelValues("error").Observe(time.Since(start).Seconds())
 		return "", fmt.Errorf("failed to create temp file: %w", err)
 	}
 	defer outFile.Close()
 
 	_, err = io.Copy(outFile, resp.Body)
 	if err != nil {
+		c.metrics.debuginfodRequestErrorsTotal.WithLabelValues("write").Inc()
+		c.metrics.debuginfodRequestDuration.WithLabelValues("error").Observe(time.Since(start).Seconds())
 		return "", fmt.Errorf("failed to write debuginfod to file: %w", err)
 	}
 
+	c.metrics.debuginfodRequestDuration.WithLabelValues("success").Observe(time.Since(start).Seconds())
+
 	return filePath, nil
 }
 
diff --git a/pkg/experiment/symbolizer/metrics.go b/pkg/experiment/symbolizer/metrics.go
@@ -0,0 +1,160 @@
+package symbolizer
+
+import "github.com/prometheus/client_golang/prometheus"
+
+type Metrics struct {
+	registerer prometheus.Registerer
+
+	// Debuginfod metrics
+	debuginfodRequestDuration    *prometheus.HistogramVec
+	debuginfodFileSize           prometheus.Histogram
+	debuginfodRequestsTotal      prometheus.Counter
+	debuginfodRequestErrorsTotal *prometheus.CounterVec
+
+	// Cache metrics
+	cacheRequestsTotal      *prometheus.CounterVec
+	cacheRequestErrorsTotal *prometheus.CounterVec
+	cacheHitsTotal          prometheus.Counter
+	cacheMissesTotal        prometheus.Counter
+	cacheOperationDuration  *prometheus.HistogramVec
+	cacheExpiredTotal       prometheus.Counter
+
+	// Symbolization metrics
+	//symbolizationDuration  prometheus.Histogram
+	//symbolizationLocations *prometheus.CounterVec
+	symbolizationRequestsTotal      prometheus.Counter
+	symbolizationRequestErrorsTotal *prometheus.CounterVec
+	symbolizationDuration           prometheus.Histogram
+	symbolizationLocationTotal      *prometheus.CounterVec
+}
+
+func NewMetrics(reg prometheus.Registerer) *Metrics {
+	m := &Metrics{
+		registerer: reg,
+		debuginfodRequestDuration: prometheus.NewHistogramVec(prometheus.HistogramOpts{
+			Name:    "pyroscope_symbolizer_debuginfod_request_duration_seconds",
+			Help:    "Time spent performing debuginfod requests",
+			Buckets: []float64{0.1, 0.5, 1, 5, 10, 30, 60, 120, 300},
+		}, []string{"status"},
+		),
+		debuginfodFileSize: prometheus.NewHistogram(
+			prometheus.HistogramOpts{
+				Name: "pyroscope_symbolizer_debuginfo_file_size_bytes",
+				Help: "Size of debug info files fetched from debuginfod",
+				// 1MB to 4GB
+				Buckets: prometheus.ExponentialBuckets(1024*1024, 2, 12),
+			},
+		),
+		debuginfodRequestsTotal: prometheus.NewCounter(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_debuginfod_requests_total",
+			Help: "Total number of debuginfod requests attempted",
+		}),
+		debuginfodRequestErrorsTotal: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_debuginfod_request_errors_total",
+			Help: "Total number of debuginfod request errors",
+		}, []string{"reason"}),
+		cacheRequestsTotal: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_cache_requests_total",
+			Help: "Total number of cache requests",
+		}, []string{"operation"}),
+		cacheRequestErrorsTotal: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_cache_request_errors_total",
+			Help: "Total number of cache request errors",
+		}, []string{"operation", "reason"}), // get/put, and specific error reasons
+		cacheHitsTotal: prometheus.NewCounter(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_cache_hits_total",
+			Help: "Total number of cache hits",
+		}),
+		cacheMissesTotal: prometheus.NewCounter(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_cache_misses_total",
+			Help: "Total number of cache misses",
+		}),
+		cacheOperationDuration: prometheus.NewHistogramVec(
+			prometheus.HistogramOpts{
+				Name:    "pyroscope_symbolizer_cache_operation_duration_seconds",
+				Help:    "Time spent performing cache operations",
+				Buckets: []float64{.01, .05, .1, .5, 1, 5, 10, 30, 60},
+			},
+			[]string{"operation"},
+		),
+		cacheExpiredTotal: prometheus.NewCounter(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_cache_expired_total",
+			Help: "Total number of expired items removed from cache",
+		}),
+		symbolizationRequestsTotal: prometheus.NewCounter(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_requests_total",
+			Help: "Total number of symbolization requests",
+		}),
+		symbolizationRequestErrorsTotal: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_request_errors_total",
+			Help: "Total number of symbolization errors",
+		}, []string{"reason"}),
+		symbolizationDuration: prometheus.NewHistogram(
+			prometheus.HistogramOpts{
+				Name:    "pyroscope_symbolizer_duration_seconds",
+				Help:    "Time spent performing symbolization",
+				Buckets: []float64{.01, .05, .1, .5, 1, 5, 10, 30},
+			},
+		),
+		symbolizationLocationTotal: prometheus.NewCounterVec(prometheus.CounterOpts{
+			Name: "pyroscope_symbolizer_locations_total",
+			Help: "Total number of locations processed",
+		}, []string{"status"}),
+	}
+	m.register()
+	return m
+}
+
+func (m *Metrics) register() {
+	if m.registerer == nil {
+		return
+	}
+
+	collectors := []prometheus.Collector{
+		m.debuginfodRequestDuration,
+		m.debuginfodFileSize,
+		m.debuginfodRequestErrorsTotal,
+		m.debuginfodRequestsTotal,
+		m.cacheRequestsTotal,
+		m.cacheRequestErrorsTotal,
+		m.cacheHitsTotal,
+		m.cacheMissesTotal,
+		m.cacheOperationDuration,
+		m.cacheExpiredTotal,
+		m.symbolizationRequestsTotal,
+		m.symbolizationRequestErrorsTotal,
+		m.symbolizationDuration,
+		m.symbolizationLocationTotal,
+	}
+
+	for _, collector := range collectors {
+		m.registerer.MustRegister(collector)
+	}
+}
+
+func (m *Metrics) Unregister() {
+	if m.registerer == nil {
+		return
+	}
+
+	collectors := []prometheus.Collector{
+		m.debuginfodRequestDuration,
+		m.debuginfodFileSize,
+		m.debuginfodRequestErrorsTotal,
+		m.debuginfodRequestsTotal,
+		m.cacheRequestsTotal,
+		m.cacheRequestErrorsTotal,
+		m.cacheHitsTotal,
+		m.cacheMissesTotal,
+		m.cacheOperationDuration,
+		m.cacheExpiredTotal,
+		m.symbolizationRequestsTotal,
+		m.symbolizationRequestErrorsTotal,
+		m.symbolizationDuration,
+		m.symbolizationLocationTotal,
+	}
+
+	for _, collector := range collectors {
+		m.registerer.Unregister(collector)
+	}
+}
diff --git a/pkg/experiment/symbolizer/symbolizer.go b/pkg/experiment/symbolizer/symbolizer.go
diff --git a/pkg/phlaredb/symdb/resolver_tree_test.go b/pkg/phlaredb/symdb/resolver_tree_test.go

Original file line number	Diff line number	Diff line change
`@@ -66,7 +66,7 @@ func New(`
`66`	`66`	`var sym *symbolizer.Symbolizer`
`67`	`67`	`if config.Symbolizer.DebuginfodURL != "" {`
`68`	`68`	`var err error`
`69`		`- sym, err = symbolizer.NewFromConfig(context.Background(), config.Symbolizer)`
	`69`	`+ sym, err = symbolizer.NewFromConfig(context.Background(), config.Symbolizer, reg)`
`70`	`70`	`if err != nil {`
`71`	`71`	`return nil, fmt.Errorf("create symbolizer: %w", err)`
`72`	`72`	`}`