*: add HTTP API to generate TiDB metric profile

executor/inspection_summary.go

@@ -71,7 +71,7 @@ var inspectionSummaryRules = map[string][]string{
 		"tidb_kv_backoff_duration",
 		"tidb_kv_request_duration",
 		"pd_client_cmd_duration",
-		"tikv_grpc_messge_duration",
+		"tikv_grpc_message_duration",
 		"tikv_average_grpc_messge_duration",
 		"tikv_channel_full",
 		"tikv_scheduler_is_busy",
@@ -155,7 +155,7 @@ var inspectionSummaryRules = map[string][]string{
 		"tikv_grpc_avg_req_batch_size",
 		"tikv_grpc_avg_resp_batch_size",
 		"tikv_grpc_errors",
-		"tikv_grpc_messge_duration",
+		"tikv_grpc_message_duration",
 		"tikv_grpc_qps",
 		"tikv_grpc_req_batch_size",
 		"tikv_grpc_resp_batch_size",
@@ -219,7 +219,7 @@ var inspectionSummaryRules = map[string][]string{
 		"tikv_grpc_avg_req_batch_size",
 		"tikv_grpc_avg_resp_batch_size",
 		"tikv_grpc_errors",
-		"tikv_grpc_messge_duration",
+		"tikv_grpc_message_duration",
 		"tikv_grpc_qps",
 		"tikv_grpc_req_batch_size",
 		"tikv_grpc_resp_batch_size",

infoschema/metric_table_def.go

@@ -1069,7 +1069,7 @@ var MetricTableMap = map[string]MetricTableDef{
 		Comment:  "The quantile size of requests into request batch per TiKV instance",
 	},
 
-	"tikv_grpc_messge_duration": {
+	"tikv_grpc_message_duration": {
 		PromQL:   `histogram_quantile($QUANTILE, sum(rate(tikv_grpc_msg_duration_seconds_bucket{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (le,type,instance))`,
 		Labels:   []string{"instance", "type"},
 		Quantile: 0.99,
@@ -1354,6 +1354,22 @@ var MetricTableMap = map[string]MetricTableDef{
 		Labels:  []string{"instance", "type"},
 		Comment: "The average time which is caused by latch wait in command",
 	},
+	"tikv_scheduler_processing_read_duration": {
+		PromQL:   `histogram_quantile($QUANTILE, sum(rate(tikv_scheduler_processing_read_duration_seconds_bucket{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (le,instance,type))`,
+		Labels:   []string{"instance", "type"},
+		Quantile: 0.99,
+		Comment:  "The quantile time of scheduler processing read in command",
+	},
+	"tikv_scheduler_processing_read_total_count": {
+		PromQL:  "sum(increase(tikv_scheduler_processing_read_duration_seconds_count{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,type)",
+		Labels:  []string{"instance", "type"},
+		Comment: "The total count of scheduler processing read in command",
+	},
+	"tikv_scheduler_processing_read_total_time": {
+		PromQL:  "sum(increase(tikv_scheduler_processing_read_duration_seconds_sum{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,type)",
+		Labels:  []string{"instance", "type"},
+		Comment: "The total time of scheduler processing read in command",
+	},
 
 	"tikv_scheduler_keys_read": {
 		PromQL:   `histogram_quantile($QUANTILE, sum(rate(tikv_scheduler_kv_command_key_read_bucket{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (le,instance,type))`,
@@ -1573,8 +1589,8 @@ var MetricTableMap = map[string]MetricTableDef{
 		Comment:  "The quantile of time consumed when handling coprocessor requests",
 	},
 	"tikv_cop_wait_duration": {
-		PromQL:   `histogram_quantile($QUANTILE, sum(rate(tikv_coprocessor_request_wait_seconds_bucket{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (le,req,instance))`,
-		Labels:   []string{"instance", "req"},
+		PromQL:   `histogram_quantile($QUANTILE, sum(rate(tikv_coprocessor_request_wait_seconds_bucket{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (le,req,type,instance))`,
+		Labels:   []string{"instance", "req", "type"},
 		Quantile: 1,
 		Comment:  "The quantile of time consumed when coprocessor requests are wait for being handled",
 	},
@@ -2583,6 +2599,22 @@ var MetricTableMap = map[string]MetricTableDef{
 		Labels:  []string{"instance", "sql_type"},
 		Comment: "The total time of TiDB query durations(second)",
 	},
+	"tidb_txn_cmd_duration": {
+		PromQL:   `histogram_quantile($QUANTILE, sum(rate(tidb_tikvclient_txn_cmd_duration_seconds_bucket{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (le,type,instance))`,
+		Labels:   []string{"instance", "type"},
+		Quantile: 0.90,
+		Comment:  "The quantile of TiDB transaction command durations(second)",
+	},
+	"tidb_txn_cmd_total_count": {
+		PromQL:  "sum(increase(tidb_tikvclient_txn_cmd_duration_seconds_count{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,type)",
+		Labels:  []string{"instance", "type"},
+		Comment: "The total count of TiDB transaction command",
+	},
+	"tidb_txn_cmd_total_time": {
+		PromQL:  "sum(increase(tidb_tikvclient_txn_cmd_duration_seconds_sum{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,type)",
+		Labels:  []string{"instance", "type"},
+		Comment: "The total time of TiDB transaction command",
+	},
 	"tidb_slow_query_cop_process_total_count": {
 		PromQL:  "sum(increase(tidb_server_slow_query_cop_duration_seconds_count{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance)",
 		Labels:  []string{"instance"},
@@ -2728,13 +2760,13 @@ var MetricTableMap = map[string]MetricTableDef{
 		Comment: "The total time of time consumed to handle coprocessor read requests",
 	},
 	"tikv_cop_wait_total_count": {
-		PromQL:  "sum(increase(tikv_coprocessor_request_wait_seconds_count{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,req)",
-		Labels:  []string{"instance", "req"},
+		PromQL:  "sum(increase(tikv_coprocessor_request_wait_seconds_count{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,req,type)",
+		Labels:  []string{"instance", "req", "type"},
 		Comment: "The total count of coprocessor requests that wait for being handled",
 	},
 	"tikv_cop_wait_total_time": {
-		PromQL:  "sum(increase(tikv_coprocessor_request_wait_seconds_sum{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,req)",
-		Labels:  []string{"instance", "req"},
+		PromQL:  "sum(increase(tikv_coprocessor_request_wait_seconds_sum{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,req,type)",
+		Labels:  []string{"instance", "req", "type"},
 		Comment: "The total time of time consumed when coprocessor requests are wait for being handled",
 	},
 	"tikv_raft_store_events_total_count": {
@@ -2757,12 +2789,12 @@ var MetricTableMap = map[string]MetricTableDef{
 		Labels:  []string{"instance", "task"},
 		Comment: "The total time of time consumed when executing GC tasks",
 	},
-	"tikv_grpc_messge_total_count": {
+	"tikv_grpc_message_total_count": {
 		PromQL:  "sum(increase(tikv_grpc_msg_duration_seconds_count{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,type)",
 		Labels:  []string{"instance", "type"},
 		Comment: "The total count of tikv execution gRPC message",
 	},
-	"tikv_grpc_messge_total_time": {
+	"tikv_grpc_message_total_time": {
 		PromQL:  "sum(increase(tikv_grpc_msg_duration_seconds_sum{$LABEL_CONDITIONS}[$RANGE_DURATION])) by (instance,type)",
 		Labels:  []string{"instance", "type"},
 		Comment: "The total time of execution time of gRPC message",

metrics/session.go

@@ -140,4 +140,6 @@ const (
 	LblOptimistic  = "optimistic"
 	LblStore       = "store"
 	LblAddress     = "address"
+	LblBatchGet    = "batch_get"
+	LblGet         = "get"
 )

server/http_handler.go

@@ -402,6 +402,10 @@ type allServerInfoHandler struct {
 	*tikvHandlerTool
 }
 
+type profileHandler struct {
+	*tikvHandlerTool
+}
+
 // valueHandler is the handler for get value.
 type valueHandler struct {
 }
@@ -1698,6 +1702,41 @@ func (h dbTableHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {
 	writeData(w, dbTblInfo)
 }
 
+func (h profileHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {
+	sctx, err := session.CreateSession(h.Store)
+	if err != nil {
+		writeError(w, err)
+		return
+	}
+	var start, end time.Time
+	if req.FormValue("end") != "" {
+		end, err = time.ParseInLocation(time.RFC3339, req.FormValue("end"), sctx.GetSessionVars().Location())
+		if err != nil {
+			writeError(w, err)
+			return
+		}
+	} else {
+		end = time.Now()
+	}
+	if req.FormValue("start") != "" {
+		start, err = time.ParseInLocation(time.RFC3339, req.FormValue("start"), sctx.GetSessionVars().Location())
+		if err != nil {
+			writeError(w, err)
+			return
+		}
+	} else {
+		start = end.Add(-time.Minute * 10)
+	}
+	pb := executor.NewProfileBuilder(sctx, start, end)
+	err = pb.Collect()
+	if err != nil {
+		writeError(w, err)
+		return
+	}
+	_, err = w.Write(pb.Build())
+	terror.Log(errors.Trace(err))
+}
+
 // testHandler is the handler for tests. It's convenient to provide some APIs for integration tests.
 type testHandler struct {
 	*tikvHandlerTool

server/http_status.go

@@ -151,6 +151,8 @@ func (s *Server) startHTTPServer() {
 	router.Handle("/mvcc/hex/{hexKey}", mvccTxnHandler{tikvHandlerTool, opMvccGetByHex})
 	router.Handle("/mvcc/index/{db}/{table}/{index}/{handle}", mvccTxnHandler{tikvHandlerTool, opMvccGetByIdx})
 
+	// HTTP path for generate metric profile.
+	router.Handle("/metric/profile", profileHandler{tikvHandlerTool})
 	// HTTP path for web UI.
 	if host, port, err := net.SplitHostPort(s.statusAddr); err == nil {
 		if host == "" {

store/tikv/snapshot.go

@@ -21,6 +21,7 @@ import (
 	"strings"
 	"sync"
 	"sync/atomic"
+	"time"
 	"unsafe"
 
 	"github.com/opentracing/opentracing-go"
@@ -187,6 +188,9 @@ func appendBatchKeysBySize(b []batchKeys, region RegionVerID, keys [][]byte, siz
 }
 
 func (s *tikvSnapshot) batchGetKeysByRegions(bo *Backoffer, keys [][]byte, collectF func(k, v []byte)) error {
+	defer func(start time.Time) {
+		tikvTxnCmdHistogramWithBatchGet.Observe(time.Since(start).Seconds())
+	}(time.Now())
 	groups, _, err := s.store.regionCache.GroupKeysByRegion(bo, keys, nil)
 	if err != nil {
 		return errors.Trace(err)
@@ -308,6 +312,10 @@ func (s *tikvSnapshot) Get(ctx context.Context, k kv.Key) ([]byte, error) {
 		ctx = opentracing.ContextWithSpan(ctx, span1)
 	}
 
+	defer func(start time.Time) {
+		tikvTxnCmdHistogramWithGet.Observe(time.Since(start).Seconds())
+	}(time.Now())
+
 	ctx = context.WithValue(ctx, txnStartKey, s.version.Ver)
 	val, err := s.get(NewBackoffer(ctx, getMaxBackoff), k)
 	if err != nil {

store/tikv/txn.go

@@ -42,6 +42,8 @@ var (
 var (
 	tikvTxnCmdHistogramWithCommit   = metrics.TiKVTxnCmdHistogram.WithLabelValues(metrics.LblCommit)
 	tikvTxnCmdHistogramWithRollback = metrics.TiKVTxnCmdHistogram.WithLabelValues(metrics.LblRollback)
+	tikvTxnCmdHistogramWithBatchGet = metrics.TiKVTxnCmdHistogram.WithLabelValues(metrics.LblBatchGet)
+	tikvTxnCmdHistogramWithGet      = metrics.TiKVTxnCmdHistogram.WithLabelValues(metrics.LblGet)
 )
 
 // tikvTxn implements kv.Transaction.