SQL Expressions: Fixes for Prometheus Metric Instrumentation (#106722)

* capture errors on metrics
* rename seconds to sql_command_duration_milliseconds to match unit that has been captured, and update buckets
* rename sql_command_errors_total to sql_command_count

pkg/expr/metrics/metrics.go

@@ -10,7 +10,7 @@ type ExprMetrics struct {
 	DSRequests              *prometheus.CounterVec
 	ExpressionsQuerySummary *prometheus.SummaryVec
 	SqlCommandDuration      *prometheus.HistogramVec
-	SqlCommandErrorCount    *prometheus.CounterVec
+	SqlCommandCount         *prometheus.CounterVec
 	SqlCommandCellCount     *prometheus.HistogramVec
 }
 
@@ -37,17 +37,17 @@ func newExprMetrics(subsystem string) *ExprMetrics {
 		SqlCommandDuration: prometheus.NewHistogramVec(prometheus.HistogramOpts{
 			Namespace: "grafana",
 			Subsystem: subsystem,
-			Name:      "sql_command_duration_seconds",
-			Help:      "Duration of SQL command execution",
-			Buckets:   prometheus.DefBuckets,
+			Name:      "sql_command_duration_milliseconds",
+			Help:      "Duration of SQL command execution in milliseconds",
+			Buckets:   []float64{100, 200, 300, 500, 750, 1000, 2000, 5000, 10000},
 		}, []string{"status"}),
 
-		SqlCommandErrorCount: prometheus.NewCounterVec(prometheus.CounterOpts{
+		SqlCommandCount: prometheus.NewCounterVec(prometheus.CounterOpts{
 			Namespace: "grafana",
 			Subsystem: subsystem,
-			Name:      "sql_command_errors_total",
-			Help:      "Total number of SQL command execution errors",
-		}, []string{}),
+			Name:      "sql_command_count",
+			Help:      "Total number of SQL command executions with a status label",
+		}, []string{"status"}),
 
 		SqlCommandCellCount: prometheus.NewHistogramVec(
 			prometheus.HistogramOpts{
@@ -73,7 +73,7 @@ func NewSSEMetrics(reg prometheus.Registerer) *ExprMetrics {
 
 		SqlCommandDuration: newExprMetrics(metricsSubSystem).SqlCommandDuration,
 
-		SqlCommandErrorCount: newExprMetrics(metricsSubSystem).SqlCommandErrorCount,
+		SqlCommandCount: newExprMetrics(metricsSubSystem).SqlCommandCount,
 
 		SqlCommandCellCount: newExprMetrics(metricsSubSystem).SqlCommandCellCount,
 	}
@@ -83,7 +83,7 @@ func NewSSEMetrics(reg prometheus.Registerer) *ExprMetrics {
 			m.DSRequests,
 			m.ExpressionsQuerySummary,
 			m.SqlCommandDuration,
-			m.SqlCommandErrorCount,
+			m.SqlCommandCount,
 			m.SqlCommandCellCount,
 		)
 	}
@@ -102,7 +102,7 @@ func NewQueryServiceExpressionsMetrics(reg prometheus.Registerer) *ExprMetrics {
 
 		SqlCommandDuration: newExprMetrics(metricsSubSystem).SqlCommandDuration,
 
-		SqlCommandErrorCount: newExprMetrics(metricsSubSystem).SqlCommandErrorCount,
+		SqlCommandCount: newExprMetrics(metricsSubSystem).SqlCommandCount,
 
 		SqlCommandCellCount: newExprMetrics(metricsSubSystem).SqlCommandCellCount,
 	}
@@ -112,7 +112,7 @@ func NewQueryServiceExpressionsMetrics(reg prometheus.Registerer) *ExprMetrics {
 			m.DSRequests,
 			m.ExpressionsQuerySummary,
 			m.SqlCommandDuration,
-			m.SqlCommandErrorCount,
+			m.SqlCommandCount,
 			m.SqlCommandCellCount,
 		)
 	}

pkg/expr/sql_command.go

@@ -105,21 +105,24 @@ func (gr *SQLCommand) NeedsVars() []string {
 	return gr.varsToQuery
 }
 
-// Execute runs the command and returns the results or an error if the command
-// failed to execute.
-func (gr *SQLCommand) Execute(ctx context.Context, now time.Time, vars mathexp.Vars, tracer tracing.Tracer, metrics *metrics.ExprMetrics) (mathExprResult mathexp.Results, resultError error) {
+// Execute runs the command and returns the results if successful.
+// If there is an error, it will set Results.Error and return (the return from the func should never error).
+func (gr *SQLCommand) Execute(ctx context.Context, now time.Time, vars mathexp.Vars, tracer tracing.Tracer, metrics *metrics.ExprMetrics) (mathexp.Results, error) {
 	_, span := tracer.Start(ctx, "SSE.ExecuteSQL")
 	start := time.Now()
 	tc := int64(0)
+	rsp := mathexp.Results{}
 
 	defer func() {
 		span.End()
+		duration := float64(time.Since(start).Milliseconds())
+
 		statusLabel := "ok"
-		duration := float64(time.Since(start).Nanoseconds()) / float64(time.Millisecond)
-		if resultError != nil {
+		if rsp.Error != nil {
 			statusLabel = "error"
-			metrics.SqlCommandErrorCount.WithLabelValues().Inc()
 		}
+
+		metrics.SqlCommandCount.WithLabelValues(statusLabel).Inc()
 		metrics.SqlCommandDuration.WithLabelValues(statusLabel).Observe(duration)
 		metrics.SqlCommandCellCount.WithLabelValues(statusLabel).Observe(float64(tc))
 	}()
@@ -139,12 +142,12 @@ func (gr *SQLCommand) Execute(ctx context.Context, now time.Time, vars mathexp.V
 
 	// limit of 0 or less means no limit (following convention)
 	if gr.inputLimit > 0 && tc > gr.inputLimit {
-		return mathexp.Results{},
-			fmt.Errorf(
-				"SQL expression: total cell count across all input tables exceeds limit of %d. Total cells: %d",
-				gr.inputLimit,
-				tc,
-			)
+		rsp.Error = fmt.Errorf(
+			"SQL expression: total cell count across all input tables exceeds limit of %d. Total cells: %d",
+			gr.inputLimit,
+			tc,
+		)
+		return rsp, nil
 	}
 
 	logger.Debug("Executing query", "query", gr.query, "frames", len(allFrames))
@@ -152,7 +155,6 @@ func (gr *SQLCommand) Execute(ctx context.Context, now time.Time, vars mathexp.V
 	db := sql.DB{}
 	frame, err := db.QueryFrames(ctx, tracer, gr.refID, gr.query, allFrames, sql.WithMaxOutputCells(gr.outputLimit), sql.WithTimeout(gr.timeout))
 
-	rsp := mathexp.Results{}
 	if err != nil {
 		logger.Error("Failed to query frames", "error", err.Error())
 		rsp.Error = err

pkg/expr/sql_command_test.go

@@ -136,11 +136,11 @@ func TestSQLCommandCellLimits(t *testing.T) {
 				}
 			}
 
-			_, err = cmd.Execute(context.Background(), time.Now(), vars, &testTracer{}, metrics.NewTestMetrics())
+			res, _ := cmd.Execute(context.Background(), time.Now(), vars, &testTracer{}, metrics.NewTestMetrics())
 
 			if tt.expectError {
-				require.Error(t, err)
-				require.Contains(t, err.Error(), tt.errorContains)
+				require.Error(t, res.Error)
+				require.ErrorContains(t, res.Error, tt.errorContains)
 			} else {
 				require.NoError(t, err)
 			}
@@ -161,7 +161,7 @@ func TestSQLCommandMetrics(t *testing.T) {
 	require.NoError(t, err)
 
 	// Verify error count was not incremented
-	require.Equal(t, 0, testutil.CollectAndCount(m.SqlCommandErrorCount), "Expected error metric not to be recorded")
+	require.Equal(t, 1, testutil.CollectAndCount(m.SqlCommandCount), "Expected error metric not to be recorded")
 
 	// Verify duration was recorded
 	require.Equal(t, 1, testutil.CollectAndCount(m.SqlCommandDuration), "Expected duration metric to be recorded")