diff --git a/pkg/util/execdetails/execdetails_test.go b/pkg/util/execdetails/execdetails_test.go index 75bc2546e9..12c53e4525 100644 --- a/pkg/util/execdetails/execdetails_test.go +++ b/pkg/util/execdetails/execdetails_test.go @@ -390,7 +390,9 @@ func TestRuntimeStatsWithCommit(t *testing.T) { StoreAddr: "tikv-1:20160", ExecDetails: util.TiKVExecDetails{ TimeDetail: &util.TimeDetail{ - TotalRPCWallTime: 500 * time.Millisecond, + TotalRPCWallTime: 500 * time.Millisecond, + KvGrpcWaitTime: 100 * time.Millisecond, + KvGrpcProcessTime: 200 * time.Millisecond, }, ScanDetail: &util.ScanDetail{ ProcessedKeys: 10, @@ -403,19 +405,23 @@ func TestRuntimeStatsWithCommit(t *testing.T) { RocksdbBlockReadDuration: 20 * time.Millisecond, }, WriteDetail: &util.WriteDetail{ - StoreBatchWaitDuration: 10 * time.Microsecond, - ProposeSendWaitDuration: 20 * time.Microsecond, - PersistLogDuration: 30 * time.Microsecond, - RaftDbWriteLeaderWaitDuration: 40 * time.Microsecond, - RaftDbSyncLogDuration: 45 * time.Microsecond, - RaftDbWriteMemtableDuration: 50 * time.Microsecond, - CommitLogDuration: 60 * time.Microsecond, - ApplyBatchWaitDuration: 70 * time.Microsecond, - ApplyLogDuration: 80 * time.Microsecond, - ApplyMutexLockDuration: 90 * time.Microsecond, - ApplyWriteLeaderWaitDuration: 100 * time.Microsecond, - ApplyWriteWalDuration: 101 * time.Microsecond, - ApplyWriteMemtableDuration: 102 * time.Microsecond, + StoreBatchWaitDuration: 10 * time.Microsecond, + ProposeSendWaitDuration: 20 * time.Microsecond, + PersistLogDuration: 30 * time.Microsecond, + RaftDbWriteLeaderWaitDuration: 40 * time.Microsecond, + RaftDbSyncLogDuration: 45 * time.Microsecond, + RaftDbWriteMemtableDuration: 50 * time.Microsecond, + CommitLogDuration: 60 * time.Microsecond, + ApplyBatchWaitDuration: 70 * time.Microsecond, + ApplyLogDuration: 80 * time.Microsecond, + ApplyMutexLockDuration: 90 * time.Microsecond, + ApplyWriteLeaderWaitDuration: 100 * time.Microsecond, + ApplyWriteWalDuration: 101 * time.Microsecond, + ApplyWriteMemtableDuration: 102 * time.Microsecond, + SchedulerLatchWaitDuration: 103 * time.Microsecond, + SchedulerProcessDuration: 104 * time.Microsecond, + SchedulerThrottleDuration: 105 * time.Microsecond, + SchedulerPessimisticLockWaitDuration: 106 * time.Microsecond, }, }, }, @@ -433,12 +439,14 @@ func TestRuntimeStatsWithCommit(t *testing.T) { Commit: commitDetail, } expect := "commit_txn: {prewrite:1s, get_commit_ts:1s, commit:1s, backoff: {time: 1s, prewrite type: [backoff1 backoff2]}, " + - "slowest_prewrite_rpc: {total: 1.000s, region_id: 1000, store: tikv-1:20160, time_detail: {tikv_wall_time: 500ms}, " + + "slowest_prewrite_rpc: {total: 1.000s, region_id: 1000, store: tikv-1:20160, " + + "time_detail: {tikv_grpc_process_time: 200ms, tikv_grpc_wait_time: 100ms, tikv_wall_time: 500ms}, " + "scan_detail: {total_process_keys: 10, total_keys: 100, rocksdb: {delete_skipped_count: 1, key_skipped_count: 1, " + "block: {cache_hit_count: 1, read_count: 1, read_byte: 100 Bytes, read_time: 20ms}}}, " + "write_detail: {store_batch_wait: 10µs, propose_send_wait: 20µs, persist_log: {total: 30µs, write_leader_wait: 40µs, " + "sync_log: 45µs, write_memtable: 50µs}, commit_log: 60µs, apply_batch_wait: 70µs, apply: {total:80µs, mutex_lock: 90µs, " + - "write_leader_wait: 100µs, write_wal: 101µs, write_memtable: 102µs}, scheduler: {process: 0s}}}, resolve_lock: 1s, region_num:5, write_keys:3" + + "write_leader_wait: 100µs, write_wal: 101µs, write_memtable: 102µs}, scheduler: {process: 104µs, latch_wait: 103µs, " + + "pessimistic_lock_wait: 106µs, throttle: 105µs}}}, resolve_lock: 1s, region_num:5, write_keys:3" + ", write_byte:66, txn_retry:2}" require.Equal(t, expect, stats.String()) @@ -508,8 +516,8 @@ func TestRuntimeStatsWithCommit(t *testing.T) { "{total_process_keys: 10, total_keys: 100, rocksdb: {delete_skipped_count: 1, key_skipped_count: 1, block: " + "{cache_hit_count: 1, read_count: 1, read_byte: 100 Bytes, read_time: 20ms}}}, write_detail: " + "{store_batch_wait: 10µs, propose_send_wait: 20µs, persist_log: {total: 30µs, write_leader_wait: 40µs, sync_log: 45µs, write_memtable: 50µs}, " + - "commit_log: 60µs, apply_batch_wait: 70µs, apply: {total:80µs, mutex_lock: 90µs, write_leader_wait: 100µs, write_wal: 101µs, write_memtable: 102µs}, scheduler: {process: 0s}}}, " + - "lock_rpc:5s, rpc_count:50, retry_count:2}" + "commit_log: 60µs, apply_batch_wait: 70µs, apply: {total:80µs, mutex_lock: 90µs, write_leader_wait: 100µs, write_wal: 101µs, write_memtable: 102µs}, " + + "scheduler: {process: 0s}}}, lock_rpc:5s, rpc_count:50, retry_count:2}" require.Equal(t, expect, stats.String()) }