cop: fix time detail merge (#1258)

* time detail merge Signed-off-by: cfzjywxk <[email protected]> * fix test Signed-off-by: cfzjywxk <[email protected]> --------- Signed-off-by: cfzjywxk <[email protected]>
tikv · Apr 3, 2024 · c2927c0 · c2927c0
1 parent 146a632
commit c2927c0
Show file tree

Hide file tree

Showing 2 changed files with 14 additions and 21 deletions.
diff --git 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
@@ -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))
 	}
 }