Skip to content

Commit

Permalink
server, sql: collect additional session details
Browse files Browse the repository at this point in the history
Partially addresses cockroachdb#74257.

Previously, the sql server did not provide additional session details
such as total number of transactions executed, transaction fingerprint
IDs, and total active time. This change adds the aforementioned session
details to the `serverpb.Session` struct.

The transaction fingerprint IDs are collected from the
`ApplicationStats` for each connExecutor. The total number of
transactions executed is the length of the list of transaction
fingerprint IDs. The total active time is calculated by a
`timeutil.StopWatch` which is started and stopped when a transaction is
started, restarted, and finished.

Release note: none
  • Loading branch information
Gerardo Torres committed Apr 28, 2022
1 parent 3831e27 commit 79d16c0
Show file tree
Hide file tree
Showing 11 changed files with 95 additions and 10 deletions.
6 changes: 6 additions & 0 deletions docs/generated/http/full.md
Original file line number Diff line number Diff line change
Expand Up @@ -2108,9 +2108,12 @@ Session represents one SQL session.
| alloc_bytes | [int64](#cockroach.server.serverpb.ListSessionsResponse-int64) | | Number of currently allocated bytes in the session memory monitor. | [reserved](#support-status) |
| max_alloc_bytes | [int64](#cockroach.server.serverpb.ListSessionsResponse-int64) | | High water mark of allocated bytes in the session memory monitor. | [reserved](#support-status) |
| active_txn | [TxnInfo](#cockroach.server.serverpb.ListSessionsResponse-cockroach.server.serverpb.TxnInfo) | | Information about the txn in progress on this session. Nil if the session doesn't currently have a transaction. | [reserved](#support-status) |
| num_txns_executed | [int32](#cockroach.server.serverpb.ListSessionsResponse-int32) | | num_txns_executed is the number of transactions that were executed so far on this session. | [reserved](#support-status) |
| txnFingerprintIDs | [uint64](#cockroach.server.serverpb.ListSessionsResponse-uint64) | repeated | List of transaction fingerprint IDs in this session. | [reserved](#support-status) |
| last_active_query_no_constants | [string](#cockroach.server.serverpb.ListSessionsResponse-string) | | The SQL statement fingerprint of the last query executed on this session, compatible with StatementStatisticsKey. | [reserved](#support-status) |
| status | [Session.Status](#cockroach.server.serverpb.ListSessionsResponse-cockroach.server.serverpb.Session.Status) | | The session's status. | [reserved](#support-status) |
| end | [google.protobuf.Timestamp](#cockroach.server.serverpb.ListSessionsResponse-google.protobuf.Timestamp) | | Timestamp of session's end. | [reserved](#support-status) |
| totalActiveTime | [google.protobuf.Duration](#cockroach.server.serverpb.ListSessionsResponse-google.protobuf.Duration) | | The session's total active time. | [reserved](#support-status) |



Expand Down Expand Up @@ -2242,9 +2245,12 @@ Session represents one SQL session.
| alloc_bytes | [int64](#cockroach.server.serverpb.ListSessionsResponse-int64) | | Number of currently allocated bytes in the session memory monitor. | [reserved](#support-status) |
| max_alloc_bytes | [int64](#cockroach.server.serverpb.ListSessionsResponse-int64) | | High water mark of allocated bytes in the session memory monitor. | [reserved](#support-status) |
| active_txn | [TxnInfo](#cockroach.server.serverpb.ListSessionsResponse-cockroach.server.serverpb.TxnInfo) | | Information about the txn in progress on this session. Nil if the session doesn't currently have a transaction. | [reserved](#support-status) |
| num_txns_executed | [int32](#cockroach.server.serverpb.ListSessionsResponse-int32) | | num_txns_executed is the number of transactions that were executed so far on this session. | [reserved](#support-status) |
| txnFingerprintIDs | [uint64](#cockroach.server.serverpb.ListSessionsResponse-uint64) | repeated | List of transaction fingerprint IDs in this session. | [reserved](#support-status) |
| last_active_query_no_constants | [string](#cockroach.server.serverpb.ListSessionsResponse-string) | | The SQL statement fingerprint of the last query executed on this session, compatible with StatementStatisticsKey. | [reserved](#support-status) |
| status | [Session.Status](#cockroach.server.serverpb.ListSessionsResponse-cockroach.server.serverpb.Session.Status) | | The session's status. | [reserved](#support-status) |
| end | [google.protobuf.Timestamp](#cockroach.server.serverpb.ListSessionsResponse-google.protobuf.Timestamp) | | Timestamp of session's end. | [reserved](#support-status) |
| totalActiveTime | [google.protobuf.Duration](#cockroach.server.serverpb.ListSessionsResponse-google.protobuf.Duration) | | The session's total active time. | [reserved](#support-status) |



Expand Down
29 changes: 29 additions & 0 deletions docs/generated/swagger/spec.json
Original file line number Diff line number Diff line change
Expand Up @@ -768,6 +768,12 @@
},
"x-go-package": "github.com/cockroachdb/cockroach/pkg/server/serverpb"
},
"Duration": {
"description": "A Duration represents the elapsed time between two instants\nas an int64 nanosecond count. The representation limits the\nlargest representable duration to approximately 290 years.",
"type": "integer",
"format": "int64",
"x-go-package": "time"
},
"EventsResponse": {
"description": "EventsResponse contains a set of event log entries. This is always limited\nto the latest N entries (N is enforced in the associated endpoint).",
"type": "object",
Expand Down Expand Up @@ -1220,6 +1226,12 @@
"node_id": {
"$ref": "#/definitions/NodeID"
},
"num_txns_executed": {
"description": "num_txns_executed is the number of transactions that were executed so\nfar on this session.",
"type": "integer",
"format": "int32",
"x-go-name": "NumTxnsExecuted"
},
"start": {
"description": "Timestamp of session's start.",
"type": "string",
Expand All @@ -1229,6 +1241,17 @@
"status": {
"$ref": "#/definitions/Session_Status"
},
"totalActiveTime": {
"$ref": "#/definitions/Duration"
},
"txnFingerprintIDs": {
"description": "List of transaction fingerprint IDs in this session.",
"type": "array",
"items": {
"$ref": "#/definitions/TransactionFingerprintID"
},
"x-go-name": "TxnFingerprintIDs"
},
"username": {
"description": "Username of the user for this session.",
"type": "string",
Expand Down Expand Up @@ -1493,6 +1516,12 @@
},
"x-go-package": "github.com/cockroachdb/cockroach/pkg/util/hlc"
},
"TransactionFingerprintID": {
"description": "TransactionFingerprintID is the hashed string constructed using the\nindividual statement fingerprint IDs that comprise the transaction.",
"type": "integer",
"format": "uint64",
"x-go-package": "github.com/cockroachdb/cockroach/pkg/roachpb"
},
"TxnInfo": {
"type": "object",
"title": "TxnInfo represents an in flight user transaction on some Session.",
Expand Down
8 changes: 4 additions & 4 deletions pkg/ccl/logictestccl/testdata/logic_test/crdb_internal_tenant
Original file line number Diff line number Diff line change
Expand Up @@ -243,15 +243,15 @@ SELECT * FROM crdb_internal.cluster_transactions WHERE node_id < 0
----
id node_id session_id start txn_string application_name num_stmts num_retries num_auto_retries

query ITTTTTTTTTTTTT colnames
query ITTTTTTTTTTTTTT colnames
SELECT * FROM crdb_internal.node_sessions WHERE node_id < 0
----
node_id session_id user_name client_address application_name active_queries last_active_query session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end
node_id session_id user_name client_address application_name active_queries last_active_query num_txns_executed session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end

query ITTTTTTTTTTTTT colnames
query ITTTTTTTTTTTTTT colnames
SELECT * FROM crdb_internal.cluster_sessions WHERE node_id < 0
----
node_id session_id user_name client_address application_name active_queries last_active_query session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end
node_id session_id user_name client_address application_name active_queries last_active_query num_txns_executed session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end

query IIITTTI colnames
SELECT * FROM crdb_internal.node_contention_events WHERE table_id < 0
Expand Down
10 changes: 10 additions & 0 deletions pkg/server/serverpb/status.proto
Original file line number Diff line number Diff line change
Expand Up @@ -944,6 +944,13 @@ message Session {
// Information about the txn in progress on this session. Nil if the
// session doesn't currently have a transaction.
TxnInfo active_txn = 12;
// num_txns_executed is the number of transactions that were executed so
// far on this session.
int32 num_txns_executed = 16;
// List of transaction fingerprint IDs in this session.
repeated uint64 txnFingerprintIDs = 17 [(gogoproto.customname) = "TxnFingerprintIDs",
(gogoproto.customtype) = "github.com/cockroachdb/cockroach/pkg/roachpb.TransactionFingerprintID",
(gogoproto.nullable) = false];
// The SQL statement fingerprint of the last query executed on this session,
// compatible with StatementStatisticsKey.
string last_active_query_no_constants = 13;
Expand All @@ -958,6 +965,9 @@ message Session {
// Timestamp of session's end.
google.protobuf.Timestamp end = 15
[ (gogoproto.nullable) = true, (gogoproto.stdtime) = true ];
// The session's total active time.
google.protobuf.Duration totalActiveTime = 18 [(gogoproto.nullable) = false,
(gogoproto.stdduration) = true];
}

// An error wrapper object for ListSessionsResponse.
Expand Down
18 changes: 18 additions & 0 deletions pkg/sql/conn_executor.go
Original file line number Diff line number Diff line change
Expand Up @@ -883,6 +883,7 @@ func (s *Server) newConnExecutor(
stmtDiagnosticsRecorder: s.cfg.StmtDiagnosticsRecorder,
indexUsageStats: s.indexUsageStats,
txnIDCacheWriter: s.txnIDCache,
totalActiveTimeStopWatch: timeutil.NewStopWatch(),
}

ex.state.txnAbortCount = ex.metrics.EngineMetrics.TxnAbortCount
Expand Down Expand Up @@ -1497,6 +1498,9 @@ type connExecutor struct {
// txnIDCacheWriter is used to write txnidcache.ResolvedTxnID to the
// Transaction ID Cache.
txnIDCacheWriter txnidcache.Writer

// totalActiveTimeStopWatch represents the total time the session has been active for.
totalActiveTimeStopWatch *timeutil.StopWatch
}

// ctxHolder contains a connection's context and, while session tracing is
Expand Down Expand Up @@ -3115,19 +3119,33 @@ func (ex *connExecutor) serialize() serverpb.Session {
remoteStr = sd.RemoteAddr.String()
}

var txnFingerprintIDs []roachpb.TransactionFingerprintID
options := &sqlstats.IteratorOptions{}
txnStatsVisitor := func(_ context.Context, stat *roachpb.CollectedTransactionStatistics) error {
txnFingerprintIDs = append(txnFingerprintIDs, stat.TransactionFingerprintID)
return nil
}
err := ex.applicationStats.IterateTransactionStats(context.Background(), options, txnStatsVisitor)
if err != nil {
log.Fatal(context.Background(), err.Error())
}

return serverpb.Session{
Username: sd.SessionUser().Normalized(),
ClientAddress: remoteStr,
ApplicationName: ex.applicationName.Load().(string),
Start: ex.phaseTimes.GetSessionPhaseTime(sessionphase.SessionInit).UTC(),
ActiveQueries: activeQueries,
ActiveTxn: activeTxnInfo,
NumTxnsExecuted: int32(len(txnFingerprintIDs)),
TxnFingerprintIDs: txnFingerprintIDs,
LastActiveQuery: lastActiveQuery,
ID: ex.sessionID.GetBytes(),
AllocBytes: ex.mon.AllocBytes(),
MaxAllocBytes: ex.mon.MaximumBytes(),
LastActiveQueryNoConstants: lastActiveQueryNoConstants,
Status: status,
TotalActiveTime: ex.totalActiveTimeStopWatch.Elapsed(),
}
}

Expand Down
5 changes: 5 additions & 0 deletions pkg/sql/conn_executor_exec.go
Original file line number Diff line number Diff line change
Expand Up @@ -2126,6 +2126,8 @@ func (ex *connExecutor) onTxnFinish(ctx context.Context, ev txnEvent) {

func (ex *connExecutor) onTxnRestart(ctx context.Context) {
if ex.extraTxnState.shouldExecuteOnTxnRestart {
ex.totalActiveTimeStopWatch.Stop()
defer ex.totalActiveTimeStopWatch.Start()
ex.phaseTimes.SetSessionPhaseTime(sessionphase.SessionMostRecentStartExecTransaction, timeutil.Now())
ex.extraTxnState.transactionStatementFingerprintIDs = nil
ex.extraTxnState.transactionStatementsHash = util.MakeFNV64()
Expand Down Expand Up @@ -2157,6 +2159,8 @@ func (ex *connExecutor) recordTransactionStart(txnID uuid.UUID) {
ex.state.mu.RUnlock()
implicit := ex.implicitTxn()

ex.totalActiveTimeStopWatch.Start()

// Transaction received time is the time at which the statement that prompted
// the creation of this transaction was received.
ex.phaseTimes.SetSessionPhaseTime(sessionphase.SessionTransactionReceived,
Expand Down Expand Up @@ -2210,6 +2214,7 @@ func (ex *connExecutor) recordTransactionFinish(

txnEnd := timeutil.Now()
txnTime := txnEnd.Sub(txnStart)
ex.totalActiveTimeStopWatch.Stop()
if ex.executorType != executorTypeInternal {
ex.metrics.EngineMetrics.SQLTxnsOpen.Dec(1)
}
Expand Down
7 changes: 6 additions & 1 deletion pkg/sql/crdb_internal.go
Original file line number Diff line number Diff line change
Expand Up @@ -1615,7 +1615,7 @@ CREATE TABLE crdb_internal.%s (
node_id INT, -- the ID of the node running the transaction
session_id STRING, -- the ID of the session
start TIMESTAMP, -- the start time of the transaction
txn_string STRING, -- the string representation of the transcation
txn_string STRING, -- the string representation of the transaction
application_name STRING, -- the name of the application as per SET application_name
num_stmts INT, -- the number of statements executed so far
num_retries INT, -- the number of times the transaction was restarted
Expand Down Expand Up @@ -1894,6 +1894,7 @@ CREATE TABLE crdb_internal.%s (
application_name STRING, -- the name of the application as per SET application_name
active_queries STRING, -- the currently running queries as SQL
last_active_query STRING, -- the query that finished last on this session as SQL
num_txns_executed INT, -- the number of transactions that were executed so far on this session
session_start TIMESTAMP, -- the time when the session was opened
oldest_query_start TIMESTAMP, -- the time when the oldest query in the session was started
kv_txn STRING, -- the ID of the current KV transaction
Expand Down Expand Up @@ -1975,6 +1976,8 @@ func populateSessionsTable(
kvTxnIDDatum = tree.NewDString(session.ActiveTxn.ID.String())
}

numTxnsExecuted := session.NumTxnsExecuted

sessionID := getSessionID(session)
startTSDatum, err := tree.MakeDTimestamp(session.Start, time.Microsecond)
if err != nil {
Expand All @@ -1995,6 +1998,7 @@ func populateSessionsTable(
tree.NewDString(session.ApplicationName),
tree.NewDString(activeQueries.String()),
tree.NewDString(session.LastActiveQuery),
tree.NewDInt(tree.DInt(numTxnsExecuted)),
startTSDatum,
oldestStartDatum,
kvTxnIDDatum,
Expand All @@ -2020,6 +2024,7 @@ func populateSessionsTable(
tree.DNull, // application name
tree.NewDString("-- "+rpcErr.Message), // active queries
tree.DNull, // last active query
tree.DNull, // num txns executed
tree.DNull, // session start
tree.DNull, // oldest_query_start
tree.DNull, // kv_txn
Expand Down
2 changes: 1 addition & 1 deletion pkg/sql/delegate/show_sessions.go
Original file line number Diff line number Diff line change
Expand Up @@ -16,7 +16,7 @@ import (
)

func (d *delegator) delegateShowSessions(n *tree.ShowSessions) (tree.Statement, error) {
const query = `SELECT node_id, session_id, status, user_name, client_address, application_name, active_queries, last_active_query, session_start, oldest_query_start FROM crdb_internal.`
const query = `SELECT node_id, session_id, status, user_name, client_address, application_name, active_queries, last_active_query, num_txns_executed, session_start, oldest_query_start FROM crdb_internal.`
table := `node_sessions`
if n.Cluster {
table = `cluster_sessions`
Expand Down
8 changes: 4 additions & 4 deletions pkg/sql/logictest/testdata/logic_test/crdb_internal
Original file line number Diff line number Diff line change
Expand Up @@ -364,15 +364,15 @@ SELECT * FROM crdb_internal.cluster_transactions WHERE node_id < 0
----
id node_id session_id start txn_string application_name num_stmts num_retries num_auto_retries

query ITTTTTTTTTTTTT colnames
query ITTTTTTTTTTTTTT colnames
SELECT * FROM crdb_internal.node_sessions WHERE node_id < 0
----
node_id session_id user_name client_address application_name active_queries last_active_query session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end
node_id session_id user_name client_address application_name active_queries last_active_query num_txns_executed session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end

query ITTTTTTTTTTTTT colnames
query ITTTTTTTTTTTTTT colnames
SELECT * FROM crdb_internal.cluster_sessions WHERE node_id < 0
----
node_id session_id user_name client_address application_name active_queries last_active_query session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end
node_id session_id user_name client_address application_name active_queries last_active_query num_txns_executed session_start oldest_query_start kv_txn alloc_bytes max_alloc_bytes status session_end

query IIITTTI colnames
SELECT * FROM crdb_internal.node_contention_events WHERE table_id < 0
Expand Down
4 changes: 4 additions & 0 deletions pkg/sql/logictest/testdata/logic_test/create_statements
Original file line number Diff line number Diff line change
Expand Up @@ -316,6 +316,7 @@ CREATE TABLE crdb_internal.cluster_sessions (
application_name STRING NULL,
active_queries STRING NULL,
last_active_query STRING NULL,
num_txns_executed INT8 NULL,
session_start TIMESTAMP NULL,
oldest_query_start TIMESTAMP NULL,
kv_txn STRING NULL,
Expand All @@ -331,6 +332,7 @@ CREATE TABLE crdb_internal.cluster_sessions (
application_name STRING NULL,
active_queries STRING NULL,
last_active_query STRING NULL,
num_txns_executed INT8 NULL,
session_start TIMESTAMP NULL,
oldest_query_start TIMESTAMP NULL,
kv_txn STRING NULL,
Expand Down Expand Up @@ -939,6 +941,7 @@ CREATE TABLE crdb_internal.node_sessions (
application_name STRING NULL,
active_queries STRING NULL,
last_active_query STRING NULL,
num_txns_executed INT8 NULL,
session_start TIMESTAMP NULL,
oldest_query_start TIMESTAMP NULL,
kv_txn STRING NULL,
Expand All @@ -954,6 +957,7 @@ CREATE TABLE crdb_internal.node_sessions (
application_name STRING NULL,
active_queries STRING NULL,
last_active_query STRING NULL,
num_txns_executed INT8 NULL,
session_start TIMESTAMP NULL,
oldest_query_start TIMESTAMP NULL,
kv_txn STRING NULL,
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -47,6 +47,8 @@ export const idleSession: SessionInfo = {
alloc_bytes: Long.fromNumber(0),
max_alloc_bytes: Long.fromNumber(10240),
active_queries: [],
num_txns_executed: 1,
txnFingerprintIDs: [],
status: Status.IDLE,
toJSON: () => ({}),
},
Expand Down Expand Up @@ -85,6 +87,8 @@ export const idleTransactionSession: SessionInfo = {
},
last_active_query_no_constants: "SHOW database",
active_queries: [],
num_txns_executed: 1,
txnFingerprintIDs: [],
status: Status.IDLE,
toJSON: () => ({}),
},
Expand Down Expand Up @@ -138,6 +142,8 @@ export const activeSession: SessionInfo = {
},
last_active_query_no_constants: "SHOW database",
status: Status.ACTIVE,
num_txns_executed: 1,
txnFingerprintIDs: [],
toJSON: () => ({}),
},
};
Expand All @@ -163,6 +169,8 @@ export const closedSession: SessionInfo = {
nanos: 369989000,
},
status: Status.CLOSED,
num_txns_executed: 1,
txnFingerprintIDs: [],
toJSON: () => ({}),
},
};
Expand Down

0 comments on commit 79d16c0

Please sign in to comment.