sql: add latency metrics for historical queries

This commit adds 4 new latency metrics specifically to separate out
AOST queries:

* sql.exec.latency.consistent -- Latency of SQL statement execution of non-historical queries
* sql.exec.latency.historical -- Latency of SQL statement execution of historical queries
* sql.service.latency.consistent -- Latency of SQL request execution of non-historical queries
* sql.service.latency.historical -- Latency of SQL request execution of historical queries

This will help when trying to optimize workloads that have a
combination of historical and non-historical queries.

Fixes: #121507
Part of: https://cockroachlabs.atlassian.net/browse/CRDB-37293
Part of: https://cockroachlabs.atlassian.net/browse/TREQ-152
Part of: https://cockroachlabs.atlassian.net/browse/FEB-22

Release note (ops change): Added 4 new latency metrics:
sql.service.latency.historical, sql.service.latency.consistent,
sql.exec.latency.historical, sql.exec.latency.consistent for easier query
optimizations.

Author: BramGruneir

docs/generated/metrics/metrics.html

@@ -1695,8 +1695,12 @@
 <tr><td>APPLICATION</td><td>sql.distsql.service.latency.internal</td><td>Latency of DistSQL request execution (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.distsql.vec.openfds</td><td>Current number of open file descriptors used by vectorized external storage</td><td>Files</td><td>GAUGE</td><td>COUNT</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.exec.latency</td><td>Latency of SQL statement execution</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.exec.latency.consistent</td><td>Latency of SQL statement execution of non-historical queries</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.exec.latency.consistent.internal</td><td>Latency of SQL statement execution of non-historical queries (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.exec.latency.detail</td><td>Latency of SQL statement execution, by statement fingerprint</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.exec.latency.detail.internal</td><td>Latency of SQL statement execution, by statement fingerprint (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.exec.latency.historical</td><td>Latency of SQL statement execution of historical queries</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.exec.latency.historical.internal</td><td>Latency of SQL statement execution of historical queries (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.exec.latency.internal</td><td>Latency of SQL statement execution (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.failure.count</td><td>Number of statements resulting in a planning or runtime error</td><td>SQL Statements</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
 <tr><td>APPLICATION</td><td>sql.failure.count.internal</td><td>Number of statements resulting in a planning or runtime error (internal queries)</td><td>SQL Internal Statements</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
@@ -1819,6 +1823,10 @@
 <tr><td>APPLICATION</td><td>sql.select.started.count</td><td>Number of SQL SELECT statements started</td><td>SQL Statements</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
 <tr><td>APPLICATION</td><td>sql.select.started.count.internal</td><td>Number of SQL SELECT statements started (internal queries)</td><td>SQL Internal Statements</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
 <tr><td>APPLICATION</td><td>sql.service.latency</td><td>Latency of SQL request execution</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.service.latency.consistent</td><td>Latency of SQL request execution of non-historical queries</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.service.latency.consistent.internal</td><td>Latency of SQL request execution of non-historical queries (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.service.latency.historical</td><td>Latency of SQL request execution of historical queries</td><td>Latency</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
+<tr><td>APPLICATION</td><td>sql.service.latency.historical.internal</td><td>Latency of SQL request execution of historical queries (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.service.latency.internal</td><td>Latency of SQL request execution (internal queries)</td><td>SQL Internal Statements</td><td>HISTOGRAM</td><td>NANOSECONDS</td><td>AVG</td><td>NONE</td></tr>
 <tr><td>APPLICATION</td><td>sql.statement_timeout.count</td><td>Count of statements that failed because they exceeded the statement timeout</td><td>SQL Statements</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>
 <tr><td>APPLICATION</td><td>sql.statement_timeout.count.internal</td><td>Count of statements that failed because they exceeded the statement timeout (internal queries)</td><td>SQL Internal Statements</td><td>COUNTER</td><td>COUNT</td><td>AVG</td><td>NON_NEGATIVE_DERIVATIVE</td></tr>

pkg/sql/conn_executor.go

@@ -557,6 +557,7 @@ func makeMetrics(internal bool, sv *settings.Values) Metrics {
 			SQLOptPlanCacheMisses:         metric.NewCounter(getMetricMeta(MetaSQLOptPlanCacheMisses, internal)),
 			StatementFingerprintCount:     metric.NewUniqueCounter(getMetricMeta(MetaUniqueStatementCount, internal)),
 			SQLExecLatencyDetail:          sqlExecLatencyDetail,
+
 			// TODO(mrtracy): See HistogramWindowInterval in server/config.go for the 6x factor.
 			DistSQLExecLatency: metric.NewHistogram(metric.HistogramOptions{
 				Mode:         metric.HistogramModePreferHdrLatency,
@@ -570,6 +571,18 @@ func makeMetrics(internal bool, sv *settings.Values) Metrics {
 				Duration:     6 * metricsSampleInterval,
 				BucketConfig: metric.IOLatencyBuckets,
 			}),
+			SQLExecLatencyConsistent: metric.NewHistogram(metric.HistogramOptions{
+				Mode:         metric.HistogramModePreferHdrLatency,
+				Metadata:     getMetricMeta(MetaSQLExecLatencyConsistent, internal),
+				Duration:     6 * metricsSampleInterval,
+				BucketConfig: metric.IOLatencyBuckets,
+			}),
+			SQLExecLatencyHistorical: metric.NewHistogram(metric.HistogramOptions{
+				Mode:         metric.HistogramModePreferHdrLatency,
+				Metadata:     getMetricMeta(MetaSQLExecLatencyHistorical, internal),
+				Duration:     6 * metricsSampleInterval,
+				BucketConfig: metric.IOLatencyBuckets,
+			}),
 			DistSQLServiceLatency: metric.NewHistogram(metric.HistogramOptions{
 				Mode:         metric.HistogramModePreferHdrLatency,
 				Metadata:     getMetricMeta(MetaDistSQLServiceLatency, internal),
@@ -582,6 +595,18 @@ func makeMetrics(internal bool, sv *settings.Values) Metrics {
 				Duration:     6 * metricsSampleInterval,
 				BucketConfig: metric.IOLatencyBuckets,
 			}),
+			SQLServiceLatencyConsistent: metric.NewHistogram(metric.HistogramOptions{
+				Mode:         metric.HistogramModePreferHdrLatency,
+				Metadata:     getMetricMeta(MetaSQLServiceLatencyConsistent, internal),
+				Duration:     6 * metricsSampleInterval,
+				BucketConfig: metric.IOLatencyBuckets,
+			}),
+			SQLServiceLatencyHistorical: metric.NewHistogram(metric.HistogramOptions{
+				Mode:         metric.HistogramModePreferHdrLatency,
+				Metadata:     getMetricMeta(MetaSQLServiceLatencyHistorical, internal),
+				Duration:     6 * metricsSampleInterval,
+				BucketConfig: metric.IOLatencyBuckets,
+			}),
 			SQLTxnLatency: metric.NewHistogram(metric.HistogramOptions{
 				Mode:         metric.HistogramModePreferHdrLatency,
 				Metadata:     getMetricMeta(MetaSQLTxnLatency, internal),

pkg/sql/exec_util.go

@@ -767,6 +767,18 @@ var (
 		Measurement: "Latency",
 		Unit:        metric.Unit_NANOSECONDS,
 	}
+	MetaSQLExecLatencyConsistent = metric.Metadata{
+		Name:        "sql.exec.latency.consistent",
+		Help:        "Latency of SQL statement execution of non-historical queries",
+		Measurement: "Latency",
+		Unit:        metric.Unit_NANOSECONDS,
+	}
+	MetaSQLExecLatencyHistorical = metric.Metadata{
+		Name:        "sql.exec.latency.historical",
+		Help:        "Latency of SQL statement execution of historical queries",
+		Measurement: "Latency",
+		Unit:        metric.Unit_NANOSECONDS,
+	}
 	MetaSQLExecLatencyDetail = metric.Metadata{
 		Name:        "sql.exec.latency.detail",
 		Help:        "Latency of SQL statement execution, by statement fingerprint",
@@ -780,6 +792,18 @@ var (
 		Measurement: "Latency",
 		Unit:        metric.Unit_NANOSECONDS,
 	}
+	MetaSQLServiceLatencyConsistent = metric.Metadata{
+		Name:        "sql.service.latency.consistent",
+		Help:        "Latency of SQL request execution of non-historical queries",
+		Measurement: "Latency",
+		Unit:        metric.Unit_NANOSECONDS,
+	}
+	MetaSQLServiceLatencyHistorical = metric.Metadata{
+		Name:        "sql.service.latency.historical",
+		Help:        "Latency of SQL request execution of historical queries",
+		Measurement: "Latency",
+		Unit:        metric.Unit_NANOSECONDS,
+	}
 	MetaSQLOptPlanCacheHits = metric.Metadata{
 		Name:        "sql.optimizer.plan_cache.hits",
 		Help:        "Number of non-prepared statements for which a cached plan was used",

pkg/sql/executor_statement_metrics.go

@@ -26,19 +26,31 @@ type EngineMetrics struct {
 	// The subset of SELECTs that were executed by DistSQL with full or partial
 	// distribution.
 	DistSQLSelectDistributedCount *metric.Counter
-	SQLOptPlanCacheHits           *metric.Counter
-	SQLOptPlanCacheMisses         *metric.Counter
-	StatementFingerprintCount     *metric.UniqueCounter
-
-	SQLExecLatencyDetail  *metric.HistogramVec
-	DistSQLExecLatency    metric.IHistogram
-	SQLExecLatency        metric.IHistogram
-	DistSQLServiceLatency metric.IHistogram
-	SQLServiceLatency     metric.IHistogram
-	SQLTxnLatency         metric.IHistogram
-	SQLTxnsOpen           *metric.Gauge
-	SQLActiveStatements   *metric.Gauge
-	SQLContendedTxns      *metric.Counter
+	DistSQLExecLatency            metric.IHistogram
+	DistSQLServiceLatency         metric.IHistogram
+
+	SQLOptPlanCacheHits   *metric.Counter
+	SQLOptPlanCacheMisses *metric.Counter
+
+	StatementFingerprintCount *metric.UniqueCounter
+	SQLExecLatencyDetail      *metric.HistogramVec
+
+	SQLExecLatency metric.IHistogram
+	// Exec Latency of only non-AOST queries
+	SQLExecLatencyConsistent metric.IHistogram
+	// Exec Latency of only AOST queries
+	SQLExecLatencyHistorical metric.IHistogram
+
+	SQLServiceLatency metric.IHistogram
+	// Service Latency of only non-AOST queries
+	SQLServiceLatencyConsistent metric.IHistogram
+	// Service Latency of only AOST queries
+	SQLServiceLatencyHistorical metric.IHistogram
+
+	SQLTxnLatency       metric.IHistogram
+	SQLTxnsOpen         *metric.Gauge
+	SQLActiveStatements *metric.Gauge
+	SQLContendedTxns    *metric.Counter
 
 	// TxnAbortCount counts transactions that were aborted, either due
 	// to non-retriable errors, or retriable errors when the client-side
@@ -319,6 +331,13 @@ func (ex *connExecutor) recordStatementLatencyMetrics(
 			}
 			m.SQLExecLatency.RecordValue(runLatRaw.Nanoseconds())
 			m.SQLServiceLatency.RecordValue(svcLatRaw.Nanoseconds())
+			if ex.state.isHistorical.Load() {
+				m.SQLExecLatencyHistorical.RecordValue(runLatRaw.Nanoseconds())
+				m.SQLServiceLatencyHistorical.RecordValue(svcLatRaw.Nanoseconds())
+			} else {
+				m.SQLExecLatencyConsistent.RecordValue(runLatRaw.Nanoseconds())
+				m.SQLServiceLatencyConsistent.RecordValue(svcLatRaw.Nanoseconds())
+			}
 		}
 	}
 }