From c2927c0ec6ed3b3149b4d008f590ca6567c973b7 Mon Sep 17 00:00:00 2001 From: cfzjywxk Date: Wed, 3 Apr 2024 12:05:38 +0800 Subject: [PATCH] cop: fix time detail merge (#1258) * time detail merge Signed-off-by: cfzjywxk * fix test Signed-off-by: cfzjywxk --------- Signed-off-by: cfzjywxk --- integration_tests/snapshot_test.go | 22 ++++++---------------- util/execdetails.go | 13 ++++++++----- 2 files changed, 14 insertions(+), 21 deletions(-) diff --git a/integration_tests/snapshot_test.go b/integration_tests/snapshot_test.go index 3cf28105a..bba5cac34 100644 --- a/integration_tests/snapshot_test.go +++ b/integration_tests/snapshot_test.go @@ -321,25 +321,15 @@ func (s *testSnapshotSuite) TestSnapshotRuntimeStats() { } snapshot.MergeExecDetail(detail) expect = "Get:{num_rpc:4, total_time:2s},txnLockFast_backoff:{num:2, total_time:10ms}, " + - "total_process_time: 100ms, total_wait_time: 100ms, " + - "scan_detail: {total_process_keys: 10, " + - "total_process_keys_size: 10, " + - "total_keys: 15, " + - "get_snapshot_time: 500ns, " + - "rocksdb: {delete_skipped_count: 5, " + - "key_skipped_count: 1, " + - "block: {cache_hit_count: 10, read_count: 20, read_byte: 15 Bytes}}}" + "time_detail: {total_process_time: 100ms, total_wait_time: 100ms}, " + + "scan_detail: {total_process_keys: 10, total_process_keys_size: 10, total_keys: 15, get_snapshot_time: 500ns, " + + "rocksdb: {delete_skipped_count: 5, key_skipped_count: 1, block: {cache_hit_count: 10, read_count: 20, read_byte: 15 Bytes}}}" s.Equal(expect, snapshot.FormatStats()) snapshot.MergeExecDetail(detail) expect = "Get:{num_rpc:4, total_time:2s},txnLockFast_backoff:{num:2, total_time:10ms}, " + - "total_process_time: 200ms, total_wait_time: 200ms, " + - "scan_detail: {total_process_keys: 20, " + - "total_process_keys_size: 20, " + - "total_keys: 30, " + - "get_snapshot_time: 1µs, " + - "rocksdb: {delete_skipped_count: 10, " + - "key_skipped_count: 2, " + - "block: {cache_hit_count: 20, read_count: 40, read_byte: 30 Bytes}}}" + "time_detail: {total_process_time: 200ms, total_wait_time: 200ms}, " + + "scan_detail: {total_process_keys: 20, total_process_keys_size: 20, total_keys: 30, get_snapshot_time: 1µs, " + + "rocksdb: {delete_skipped_count: 10, key_skipped_count: 2, block: {cache_hit_count: 20, read_count: 40, read_byte: 30 Bytes}}}" s.Equal(expect, snapshot.FormatStats()) } diff --git a/util/execdetails.go b/util/execdetails.go index a9db7a7ce..2fd058436 100644 --- a/util/execdetails.go +++ b/util/execdetails.go @@ -635,6 +635,7 @@ func (td *TimeDetail) String() string { return "" } buf := bytes.NewBuffer(make([]byte, 0, 16)) + buf.WriteString("time_detail: {") if td.ProcessTime > 0 { buf.WriteString("total_process_time: ") buf.WriteString(FormatDuration(td.ProcessTime)) @@ -667,17 +668,19 @@ func (td *TimeDetail) String() string { buf.WriteString("tikv_wall_time: ") buf.WriteString(FormatDuration(td.TotalRPCWallTime)) } + buf.WriteString("}") return buf.String() } // Merge merges the time detail into itself. +// Note this function could be called concurrently. func (td *TimeDetail) Merge(detail *TimeDetail) { if detail != nil { - td.ProcessTime += detail.ProcessTime - td.SuspendTime += detail.SuspendTime - td.WaitTime += detail.WaitTime - td.KvReadWallTime += detail.KvReadWallTime - td.TotalRPCWallTime += detail.TotalRPCWallTime + atomic.AddInt64((*int64)(&td.ProcessTime), int64(detail.ProcessTime)) + atomic.AddInt64((*int64)(&td.SuspendTime), int64(detail.SuspendTime)) + atomic.AddInt64((*int64)(&td.WaitTime), int64(detail.WaitTime)) + atomic.AddInt64((*int64)(&td.KvReadWallTime), int64(detail.KvReadWallTime)) + atomic.AddInt64((*int64)(&td.TotalRPCWallTime), int64(detail.TotalRPCWallTime)) } }