metrics: Add metrics and telemetry for aggressive locking (pingcap#41038

)

close pingcap#41037

executor/adapter.go

@@ -87,6 +87,17 @@ var (
 	selectForUpdateRetryDuration        = metrics.PessimisticDMLDurationByAttempt.WithLabelValues("select-for-update", "retry")
 	dmlFirstAttemptDuration             = metrics.PessimisticDMLDurationByAttempt.WithLabelValues("dml", "first-attempt")
 	dmlRetryDuration                    = metrics.PessimisticDMLDurationByAttempt.WithLabelValues("dml", "retry")
+
+	// aggressiveLockingTxnUsedCount counts transactions where at least one statement has aggressive locking enabled.
+	aggressiveLockingTxnUsedCount = metrics.AggressiveLockingUsageCount.WithLabelValues(metrics.LblAggressiveLockingTxnUsed)
+	// aggressiveLockingStmtUsedCount counts statements that have aggressive locking enabled.
+	aggressiveLockingStmtUsedCount = metrics.AggressiveLockingUsageCount.WithLabelValues(metrics.LblAggressiveLockingStmtUsed)
+	// aggressiveLockingTxnUsedCount counts transactions where at least one statement has aggressive locking enabled,
+	// and it takes effect (which is determined according to whether lock-with-conflict has occurred during execution).
+	aggressiveLockingTxnEffectiveCount = metrics.AggressiveLockingUsageCount.WithLabelValues(metrics.LblAggressiveLockingTxnEffective)
+	// aggressiveLockingTxnUsedCount counts statements where at least one statement has aggressive locking enabled,
+	// and it takes effect (which is determined according to whether lock-with-conflict has occurred during execution).
+	aggressiveLockingStmtEffectiveCount = metrics.AggressiveLockingUsageCount.WithLabelValues(metrics.LblAggressiveLockingStmtEffective)
 )
 
 // processinfoSetter is the interface use to set current running process info.
@@ -452,6 +463,18 @@ func (a *ExecStmt) Exec(ctx context.Context) (_ sqlexec.RecordSet, err error) {
 			if lockKeysCnt > 0 {
 				metrics.StatementLockKeysCount.Observe(float64(lockKeysCnt))
 			}
+
+			execDetails := a.Ctx.GetSessionVars().StmtCtx.GetExecDetails()
+			if err == nil && execDetails.LockKeysDetail != nil &&
+				(execDetails.LockKeysDetail.AggressiveLockNewCount > 0 || execDetails.LockKeysDetail.AggressiveLockDerivedCount > 0) {
+				a.Ctx.GetSessionVars().TxnCtx.AggressiveLockingUsed = true
+				// If this statement is finished when some of the keys are locked with conflict in the last retry, or
+				// some of the keys are derived from the previous retry, we consider the optimization of aggressive locking
+				// takes effect on this statement.
+				if execDetails.LockKeysDetail.LockedWithConflictCount > 0 || execDetails.LockKeysDetail.AggressiveLockDerivedCount > 0 {
+					a.Ctx.GetSessionVars().TxnCtx.AggressiveLockingEffective = true
+				}
+			}
 			return
 		}
 		if str, ok := r.(string); !ok || !strings.Contains(str, memory.PanicMemoryExceed) {
@@ -1472,6 +1495,28 @@ func (a *ExecStmt) FinishExecuteStmt(txnTS uint64, err error, hasMoreResults boo
 	if sessVars.StmtCtx.ReadFromTableCache {
 		metrics.ReadFromTableCacheCounter.Inc()
 	}
+
+	// Update aggressive locking related counters by stmt
+	if execDetail.LockKeysDetail != nil {
+		if execDetail.LockKeysDetail.AggressiveLockNewCount > 0 || execDetail.LockKeysDetail.AggressiveLockDerivedCount > 0 {
+			aggressiveLockingStmtUsedCount.Inc()
+			// If this statement is finished when some of the keys are locked with conflict in the last retry, or
+			// some of the keys are derived from the previous retry, we consider the optimization of aggressive locking
+			// takes effect on this statement.
+			if execDetail.LockKeysDetail.LockedWithConflictCount > 0 || execDetail.LockKeysDetail.AggressiveLockDerivedCount > 0 {
+				aggressiveLockingStmtEffectiveCount.Inc()
+			}
+		}
+	}
+	// If the transaction is committed, update aggressive locking related counters by txn
+	if execDetail.CommitDetail != nil {
+		if sessVars.TxnCtx.AggressiveLockingUsed {
+			aggressiveLockingTxnUsedCount.Inc()
+		}
+		if sessVars.TxnCtx.AggressiveLockingEffective {
+			aggressiveLockingTxnEffectiveCount.Inc()
+		}
+	}
 }
 
 func (a *ExecStmt) checkPlanReplayerCapture(txnTS uint64) {

metrics/grafana/tidb.json

@@ -6799,6 +6799,204 @@
             "align": false,
             "alignLevel": null
           }
+        },
+        {
+          "aliasColors": {},
+          "bars": false,
+          "dashLength": 10,
+          "dashes": false,
+          "datasource": "${DS_TEST-CLUSTER}",
+          "description": "Counters of transactions or statements in which aggressive locking is enabled / takes effect.",
+          "fieldConfig": {
+            "defaults": {},
+            "overrides": []
+          },
+          "fill": 1,
+          "fillGradient": 0,
+          "grid": {},
+          "gridPos": {
+            "h": 7,
+            "w": 8,
+            "x": 0,
+            "y": 74
+          },
+          "hiddenSeries": false,
+          "id": 295,
+          "legend": {
+            "alignAsTable": false,
+            "avg": false,
+            "current": false,
+            "hideEmpty": false,
+            "max": false,
+            "min": false,
+            "rightSide": false,
+            "show": true,
+            "total": false,
+            "values": false
+          },
+          "lines": true,
+          "linewidth": 1,
+          "nullPointMode": "null",
+          "options": {
+            "alertThreshold": true
+          },
+          "percentage": false,
+          "pluginVersion": "7.5.11",
+          "pointradius": 2,
+          "points": false,
+          "renderer": "flot",
+          "seriesOverrides": [],
+          "spaceLength": 10,
+          "stack": false,
+          "steppedLine": false,
+          "targets": [
+            {
+              "exemplar": true,
+              "expr": "sum(irate(tidb_session_transaction_aggressive_locking_usage{instance=~\"$instance\"}[30s])) by (type)",
+              "interval": "",
+              "legendFormat": "{{type}}",
+              "refId": "A"
+            }
+          ],
+          "thresholds": [],
+          "timeFrom": null,
+          "timeRegions": [],
+          "timeShift": null,
+          "title": "Aggressive Locking Usage",
+          "tooltip": {
+            "shared": true,
+            "sort": 0,
+            "value_type": "individual"
+          },
+          "type": "graph",
+          "xaxis": {
+            "buckets": null,
+            "mode": "time",
+            "name": null,
+            "show": true,
+            "values": []
+          },
+          "yaxes": [
+            {
+              "format": "short",
+              "label": null,
+              "logBase": 1,
+              "max": null,
+              "min": "0",
+              "show": true
+            },
+            {
+              "format": "short",
+              "label": null,
+              "logBase": 1,
+              "max": null,
+              "min": null,
+              "show": true
+            }
+          ],
+          "yaxis": {
+            "align": false,
+            "alignLevel": null
+          }
+        },
+        {
+          "aliasColors": {},
+          "bars": false,
+          "dashLength": 10,
+          "dashes": false,
+          "datasource": "${DS_TEST-CLUSTER}",
+          "description": "Counters of keys involved in aggressive locking.",
+          "fieldConfig": {
+            "defaults": {},
+            "overrides": []
+          },
+          "fill": 1,
+          "fillGradient": 0,
+          "grid": {},
+          "gridPos": {
+            "h": 7,
+            "w": 8,
+            "x": 8,
+            "y": 74
+          },
+          "hiddenSeries": false,
+          "id": 296,
+          "legend": {
+            "alignAsTable": false,
+            "avg": false,
+            "current": false,
+            "hideEmpty": false,
+            "max": false,
+            "min": false,
+            "rightSide": false,
+            "show": true,
+            "total": false,
+            "values": false
+          },
+          "lines": true,
+          "linewidth": 1,
+          "nullPointMode": "null",
+          "options": {
+            "alertThreshold": true
+          },
+          "percentage": false,
+          "pluginVersion": "7.5.11",
+          "pointradius": 2,
+          "points": false,
+          "renderer": "flot",
+          "seriesOverrides": [],
+          "spaceLength": 10,
+          "stack": false,
+          "steppedLine": false,
+          "targets": [
+            {
+              "exemplar": true,
+              "expr": "sum(irate(tidb_tikvclient_aggressive_locking_count{instance=~\"$instance\"}[30s])) by (type)",
+              "interval": "",
+              "legendFormat": "{{type}}",
+              "refId": "A"
+            }
+          ],
+          "thresholds": [],
+          "timeFrom": null,
+          "timeRegions": [],
+          "timeShift": null,
+          "title": "Aggressive Locking Keys",
+          "tooltip": {
+            "shared": true,
+            "sort": 0,
+            "value_type": "individual"
+          },
+          "type": "graph",
+          "xaxis": {
+            "buckets": null,
+            "mode": "time",
+            "name": null,
+            "show": true,
+            "values": []
+          },
+          "yaxes": [
+            {
+              "format": "short",
+              "label": null,
+              "logBase": 1,
+              "max": null,
+              "min": "0",
+              "show": true
+            },
+            {
+              "format": "short",
+              "label": null,
+              "logBase": 1,
+              "max": null,
+              "min": null,
+              "show": true
+            }
+          ],
+          "yaxis": {
+            "align": false,
+            "alignLevel": null
+          }
         }
       ],
       "repeat": null,
@@ -12883,7 +13081,7 @@
           "bars": false,
           "dashLength": 10,
           "dashes": false,
-          "datasource": "tidb-cluster",
+          "datasource": "${DS_TEST-CLUSTER}",
           "description": "Speed of add index",
           "editable": true,
           "error": false,

metrics/metrics.go

@@ -212,6 +212,7 @@ func RegisterMetrics() {
 	prometheus.MustRegister(AutoIDReqDuration)
 	prometheus.MustRegister(RegionCheckpointSubscriptionEvent)
 	prometheus.MustRegister(RCCheckTSWriteConfilictCounter)
+	prometheus.MustRegister(AggressiveLockingUsageCount)
 
 	prometheus.MustRegister(TTLQueryDuration)
 	prometheus.MustRegister(TTLProcessedExpiredRowsCounter)

metrics/session.go

@@ -186,6 +186,14 @@ var (
 			Name:      "resource_group_query_total",
 			Help:      "Counter of the total number of queries for the resource group",
 		}, []string{LblName})
+
+	AggressiveLockingUsageCount = prometheus.NewCounterVec(
+		prometheus.CounterOpts{
+			Namespace: "tidb",
+			Subsystem: "server",
+			Name:      "transaction_aggressive_locking_usage",
+			Help:      "The counter of statements and transactions in which aggressive locking is used or takes effect",
+		}, []string{LblType})
 )
 
 // Label constants.
@@ -227,5 +235,11 @@ const (
 	LblModule         = "module"
 	LblRCReadCheckTS  = "read_check"
 	LblRCWriteCheckTS = "write_check"
-	LblName           = "name"
+
+	LblName = "name"
+
+	LblAggressiveLockingTxnUsed       = "txn-used"
+	LblAggressiveLockingTxnEffective  = "txn-effective"
+	LblAggressiveLockingStmtUsed      = "stmt-used"
+	LblAggressiveLockingStmtEffective = "stmt-effective"
 )

metrics/telemetry.go

@@ -484,3 +484,25 @@ func GetStoreBatchCoprCounter() StoreBatchCoprCounter {
 		BatchedFallbackCount: readCounter(TelemetryStoreBatchedFallbackCnt),
 	}
 }
+
+// AggressiveLockingUsageCounter records the usage of Aggressive Locking feature of pessimistic transaction.
+type AggressiveLockingUsageCounter struct {
+	TxnAggressiveLockingUsed      int64 `json:"txn_aggressive_locking_used"`
+	TxnAggressiveLockingEffective int64 `json:"txn_aggressive_locking_effective"`
+}
+
+// Sub returns the difference of two counters.
+func (i AggressiveLockingUsageCounter) Sub(rhs AggressiveLockingUsageCounter) AggressiveLockingUsageCounter {
+	return AggressiveLockingUsageCounter{
+		TxnAggressiveLockingUsed:      i.TxnAggressiveLockingUsed - rhs.TxnAggressiveLockingUsed,
+		TxnAggressiveLockingEffective: i.TxnAggressiveLockingEffective - rhs.TxnAggressiveLockingEffective,
+	}
+}
+
+// GetAggressiveLockingUsageCounter returns the Aggressive Locking usage counter.
+func GetAggressiveLockingUsageCounter() AggressiveLockingUsageCounter {
+	return AggressiveLockingUsageCounter{
+		TxnAggressiveLockingUsed:      readCounter(AggressiveLockingUsageCount.WithLabelValues(LblAggressiveLockingTxnUsed)),
+		TxnAggressiveLockingEffective: readCounter(AggressiveLockingUsageCount.WithLabelValues(LblAggressiveLockingTxnEffective)),
+	}
+}

sessionctx/variable/session.go

@@ -240,6 +240,14 @@ type TxnCtxNoNeedToRestore struct {
 	EnableMDL bool
 	// relatedTableForMDL records the `lock` table for metadata lock. It maps from int64 to int64(version).
 	relatedTableForMDL *sync.Map
+
+	// AggressiveLockingUsed marking whether at least one of the statements in the transaction was executed in
+	// aggressive locking mode.
+	AggressiveLockingUsed bool
+	// AggressiveLockingEffective marking whether at least one of the statements in the transaction was executed in
+	// aggressive locking mode, and it takes effect (which is determined according to whether lock-with-conflict
+	// has occurred during execution of any statement).
+	AggressiveLockingEffective bool
 }
 
 // SavepointRecord indicates a transaction's savepoint record.

telemetry/data.go

@@ -71,6 +71,7 @@ func postReportTelemetryData() {
 	postReportDDLUsage()
 	postReportIndexMergeUsage()
 	postStoreBatchUsage()
+	postReportAggressiveLockingUsageCounter()
 }
 
 // PostReportTelemetryDataForTest is for test.