Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

release-22.1: sql: add sql.txn.contended.count metrics #81070

Merged
merged 2 commits into from
May 6, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
27 changes: 27 additions & 0 deletions pkg/server/status_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -3105,6 +3105,9 @@ func TestStatusAPIContentionEvents(t *testing.T) {
server1Conn := sqlutils.MakeSQLRunner(testCluster.ServerConn(0))
server2Conn := sqlutils.MakeSQLRunner(testCluster.ServerConn(1))

contentionCountBefore := testCluster.Server(1).SQLServer().(*sql.Server).
Metrics.EngineMetrics.SQLContendedTxns.Count()

sqlutils.CreateTable(
t,
testCluster.ServerConn(0),
Expand All @@ -3120,6 +3123,7 @@ func TestStatusAPIContentionEvents(t *testing.T) {

server1Conn.Exec(t, "USE test")
server2Conn.Exec(t, "USE test")
server2Conn.Exec(t, "SET application_name = 'contentionTest'")

server1Conn.Exec(t, `
SET TRACING=on;
Expand Down Expand Up @@ -3164,6 +3168,29 @@ SET TRACING=off;

require.True(t, found,
"expect to find contention event for table %d, but found %+v", testTableID, resp)

server1Conn.CheckQueryResults(t, `
SELECT count(*)
FROM crdb_internal.statement_statistics
WHERE
(statistics -> 'execution_statistics' -> 'contentionTime' ->> 'mean')::FLOAT > 0
AND app_name = 'contentionTest'
`, [][]string{{"1"}})

server1Conn.CheckQueryResults(t, `
SELECT count(*)
FROM crdb_internal.transaction_statistics
WHERE
(statistics -> 'execution_statistics' -> 'contentionTime' ->> 'mean')::FLOAT > 0
AND app_name = 'contentionTest'
`, [][]string{{"1"}})

contentionCountNow := testCluster.Server(1).SQLServer().(*sql.Server).
Metrics.EngineMetrics.SQLContendedTxns.Count()

require.Greaterf(t, contentionCountNow, contentionCountBefore,
"expected txn contention count to be more than %d, but it is %d",
contentionCountBefore, contentionCountNow)
}

func TestStatusCancelSessionGatewayMetadataPropagation(t *testing.T) {
Expand Down
1 change: 1 addition & 0 deletions pkg/sql/conn_executor.go
Original file line number Diff line number Diff line change
Expand Up @@ -425,6 +425,7 @@ func makeMetrics(internal bool) Metrics {
6*metricsSampleInterval),
SQLTxnsOpen: metric.NewGauge(getMetricMeta(MetaSQLTxnsOpen, internal)),
SQLActiveStatements: metric.NewGauge(getMetricMeta(MetaSQLActiveQueries, internal)),
SQLContendedTxns: metric.NewCounter(getMetricMeta(MetaSQLTxnContended, internal)),

TxnAbortCount: metric.NewCounter(getMetricMeta(MetaTxnAbort, internal)),
FailureCount: metric.NewCounter(getMetricMeta(MetaFailure, internal)),
Expand Down
8 changes: 6 additions & 2 deletions pkg/sql/conn_executor_exec.go
Original file line number Diff line number Diff line change
Expand Up @@ -470,7 +470,7 @@ func (ex *connExecutor) execStmtInOpenState(
ex.server.cfg,
ex.statsCollector,
&ex.extraTxnState.accumulatedStats,
ex.extraTxnState.shouldCollectTxnExecutionStats,
ih.collectExecStats,
p,
ast,
sql,
Expand Down Expand Up @@ -2214,6 +2214,10 @@ func (ex *connExecutor) recordTransactionFinish(
}
ex.metrics.EngineMetrics.SQLTxnLatency.RecordValue(txnTime.Nanoseconds())

if contentionDuration := ex.extraTxnState.accumulatedStats.ContentionTime.Nanoseconds(); contentionDuration > 0 {
ex.metrics.EngineMetrics.SQLContendedTxns.Inc(1)
}

ex.txnIDCacheWriter.Record(contentionpb.ResolvedTxnID{
TxnID: ev.txnID,
TxnFingerprintID: transactionFingerprintID,
Expand Down Expand Up @@ -2241,7 +2245,7 @@ func (ex *connExecutor) recordTransactionFinish(
RetryLatency: txnRetryLat,
CommitLatency: commitLat,
RowsAffected: ex.extraTxnState.numRows,
CollectedExecStats: ex.extraTxnState.shouldCollectTxnExecutionStats,
CollectedExecStats: ex.planner.instrumentation.collectExecStats,
ExecStats: ex.extraTxnState.accumulatedStats,
RowsRead: ex.extraTxnState.rowsRead,
RowsWritten: ex.extraTxnState.rowsWritten,
Expand Down
6 changes: 6 additions & 0 deletions pkg/sql/exec_util.go
Original file line number Diff line number Diff line change
Expand Up @@ -845,6 +845,12 @@ var (
Measurement: "SQL Statements",
Unit: metric.Unit_COUNT,
}
MetaSQLTxnContended = metric.Metadata{
Name: "sql.txn.contended.count",
Help: "Number of SQL transactions experienced contention",
Measurement: "Contention",
Unit: metric.Unit_COUNT,
}
MetaSelectStarted = metric.Metadata{
Name: "sql.select.started.count",
Help: "Number of SQL SELECT statements started",
Expand Down
1 change: 1 addition & 0 deletions pkg/sql/executor_statement_metrics.go
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@ type EngineMetrics struct {
SQLTxnLatency *metric.Histogram
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
Expand Down
13 changes: 7 additions & 6 deletions pkg/sql/instrumentation.go
Original file line number Diff line number Diff line change
Expand Up @@ -196,11 +196,12 @@ func (ih *instrumentationHelper) Setup(
// collection is enabled so that stats are shown in the traces, but
// no extra work is needed by the instrumentationHelper.
ih.collectExecStats = true
// We still, however, want to finish the instrumentationHelper in
// case we're collecting a bundle. We also capture the span in order
// to fetch the trace from it, but the span won't be finished.
// We always want to finish the instrumentationHelper in order
// to record the execution statistics. Note that we capture the
// span in order to fetch the trace from it, but the span won't be
// finished.
ih.sp = sp
return ctx, ih.collectBundle
return ctx, true /* needFinish */
}
} else {
if buildutil.CrdbTestBuild {
Expand Down Expand Up @@ -244,7 +245,7 @@ func (ih *instrumentationHelper) Finish(
cfg *ExecutorConfig,
statsCollector sqlstats.StatsCollector,
txnStats *execstats.QueryLevelStats,
collectTxnExecStats bool,
collectExecStats bool,
p *planner,
ast tree.Statement,
stmtRawSQL string,
Expand Down Expand Up @@ -314,7 +315,7 @@ func (ih *instrumentationHelper) Finish(
log.Warningf(ctx, "unable to record statement exec stats: %s", err)
}
}
if collectTxnExecStats || ih.implicitTxn {
if collectExecStats || ih.implicitTxn {
txnStats.Accumulate(queryLevelStats)
}
}
Expand Down
8 changes: 8 additions & 0 deletions pkg/ts/catalog/chart_catalog.go
Original file line number Diff line number Diff line change
Expand Up @@ -2340,6 +2340,14 @@ var charts = []sectionDescription{
},
AxisLabel: "Count",
},
{
Title: "SQL Transaction Contention",
Metrics: []string{
"sql.txn.contended.count",
"sql.txn.contended.count.internal",
},
AxisLabel: "Transactions",
},
},
},
{
Expand Down