From 721ccb4ed8649263d7a218a95ad4a2280e4e72ee Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 17 Nov 2022 17:18:33 +0800 Subject: [PATCH 01/19] support more info in explain analyze --- util/execdetails/execdetails.go | 55 +++++++++++++++++++++++++--- util/execdetails/execdetails_test.go | 10 ++++- 2 files changed, 57 insertions(+), 8 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index c1c65499ec288..5876c288f5805 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -375,10 +375,17 @@ type CopRuntimeStats struct { func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.ExecutorExecutionSummary) { crs.Lock() defer crs.Unlock() + fmt.Printf("hyy RecordOneCopTask summary GetFullTableScanContext GetScanPacksCount is %v", summary.GetFullTableScanContext().GetScanPacksCount()) + fmt.Println("") crs.stats[address] = append(crs.stats[address], &basicCopRuntimeStats{BasicRuntimeStats: BasicRuntimeStats{loop: int32(*summary.NumIterations), consume: int64(*summary.TimeProcessedNs), - rows: int64(*summary.NumProducedRows)}, + rows: int64(*summary.NumProducedRows), + fullTableScanContext: &FullTableScanContext{ + scanPacksCount: summary.GetFullTableScanContext().GetScanPacksCount(), + skipPacksCount: summary.GetFullTableScanContext().GetSkipPacksCount(), + scanRowsCount: summary.GetFullTableScanContext().GetScanRowsCount(), + skipRowsCount: summary.GetFullTableScanContext().GetSkipRowsCount()}}, threads: int32(summary.GetConcurrency()), storeType: crs.storeType}) } @@ -394,14 +401,16 @@ func (crs *CopRuntimeStats) GetActRows() (totalRows int64) { } // MergeBasicStats traverses basicCopRuntimeStats in the CopRuntimeStats and collects some useful information. -func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32) { +func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalFullTableScanContext *FullTableScanContext) { procTimes = make([]time.Duration, 0, 32) + totalFullTableScanContext = &FullTableScanContext{} for _, instanceStats := range crs.stats { for _, stat := range instanceStats { procTimes = append(procTimes, time.Duration(stat.consume)*time.Nanosecond) totalTime += time.Duration(stat.consume) totalLoops += stat.loop totalThreads += stat.threads + totalFullTableScanContext.Merge(stat.fullTableScanContext) totalTasks++ } } @@ -413,7 +422,7 @@ func (crs *CopRuntimeStats) String() string { return "" } - procTimes, totalTime, totalTasks, totalLoops, totalThreads := crs.MergeBasicStats() + procTimes, totalTime, totalTasks, totalLoops, totalThreads, totalFullTableScanContext := crs.MergeBasicStats() avgTime := time.Duration(totalTime.Nanoseconds() / int64(totalTasks)) isTiFlashCop := crs.storeType == "tiflash" @@ -422,6 +431,9 @@ func (crs *CopRuntimeStats) String() string { buf.WriteString(fmt.Sprintf("%v_task:{time:%v, loops:%d", crs.storeType, FormatDuration(procTimes[0]), totalLoops)) if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) + if !totalFullTableScanContext.Empty() { + buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", totalFullTableScanContext.scanPacksCount, totalFullTableScanContext.skipPacksCount, totalFullTableScanContext.scanRowsCount, totalFullTableScanContext.skipRowsCount)) + } } else { buf.WriteString("}") } @@ -433,6 +445,9 @@ func (crs *CopRuntimeStats) String() string { FormatDuration(procTimes[n*4/5]), FormatDuration(procTimes[n*19/20]), totalLoops, totalTasks)) if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) + if !totalFullTableScanContext.Empty() { + buf.WriteString(fmt.Sprintf("table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", totalFullTableScanContext.scanPacksCount, totalFullTableScanContext.skipPacksCount, totalFullTableScanContext.scanRowsCount, totalFullTableScanContext.skipRowsCount)) + } } else { buf.WriteString("}") } @@ -490,6 +505,30 @@ type RuntimeStats interface { Tp() int } +type FullTableScanContext struct { + scanPacksCount uint64 + scanRowsCount uint64 + skipPacksCount uint64 + skipRowsCount uint64 +} + +func (context *FullTableScanContext) Merge(other *FullTableScanContext) { + context.scanPacksCount += other.scanPacksCount + context.scanRowsCount += other.scanRowsCount + context.skipPacksCount += other.skipPacksCount + context.skipRowsCount += other.skipRowsCount + + fmt.Printf("hyy FullTableScanContext Merge context.scanPacksCount is %v", context.scanPacksCount) + fmt.Println("") +} + +func (context *FullTableScanContext) Empty() bool { + res := (context.scanPacksCount == 0 && context.skipPacksCount == 0) + fmt.Printf("hyy FullTableScanContext empty is %v", res) + fmt.Println(" ") + return res +} + // BasicRuntimeStats is the basic runtime stats. type BasicRuntimeStats struct { // executor's Next() called times. @@ -498,6 +537,8 @@ type BasicRuntimeStats struct { consume int64 // executor return row count. rows int64 + // executor extra infos + fullTableScanContext *FullTableScanContext } // GetActRows return total rows of BasicRuntimeStats. @@ -508,9 +549,10 @@ func (e *BasicRuntimeStats) GetActRows() int64 { // Clone implements the RuntimeStats interface. func (e *BasicRuntimeStats) Clone() RuntimeStats { return &BasicRuntimeStats{ - loop: e.loop, - consume: e.consume, - rows: e.rows, + loop: e.loop, + consume: e.consume, + rows: e.rows, + fullTableScanContext: e.fullTableScanContext, } } @@ -523,6 +565,7 @@ func (e *BasicRuntimeStats) Merge(rs RuntimeStats) { e.loop += tmp.loop e.consume += tmp.consume e.rows += tmp.rows + e.fullTableScanContext.Merge(tmp.fullTableScanContext) } // Tp implements the RuntimeStats interface. diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index 1f14f9f933509..fa6586bd1520a 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -135,9 +135,15 @@ func mockExecutorExecutionSummary(TimeProcessedNs, NumProducedRows, NumIteration NumIterations: &NumIterations, XXX_unrecognized: nil} } -func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { +func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, ScanPacksCount, ScanRowsCount, SkipPacksCount, SkipRowsCount uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { + fullTableScanContext := tipb.FullTableScanContext{ + ScanPacksCount: &ScanPacksCount, + ScanRowsCount: &ScanRowsCount, + SkipPacksCount: &SkipPacksCount, + SkipRowsCount: &SkipRowsCount, + } return &tipb.ExecutorExecutionSummary{TimeProcessedNs: &TimeProcessedNs, NumProducedRows: &NumProducedRows, - NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, XXX_unrecognized: nil} + NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_FullTableScanContext{FullTableScanContext: &fullTableScanContext}, XXX_unrecognized: nil} } func TestCopRuntimeStats(t *testing.T) { From 86b93911ea374cc11577341e3d2daf36e1c4db29 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 18 Nov 2022 14:55:27 +0800 Subject: [PATCH 02/19] fix test --- util/execdetails/execdetails.go | 6 +++--- util/execdetails/execdetails_test.go | 18 +++++++++--------- 2 files changed, 12 insertions(+), 12 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 5876c288f5805..675ec59e21d75 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -326,7 +326,7 @@ type basicCopRuntimeStats struct { // String implements the RuntimeStats interface. func (e *basicCopRuntimeStats) String() string { if e.storeType == "tiflash" { - return fmt.Sprintf("time:%v, loops:%d, threads:%d", FormatDuration(time.Duration(e.consume)), e.loop, e.threads) + return fmt.Sprintf("time:%v, loops:%d, threads:%d, table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.fullTableScanContext.scanPacksCount, e.fullTableScanContext.skipPacksCount, e.fullTableScanContext.scanRowsCount, e.fullTableScanContext.skipRowsCount) } return fmt.Sprintf("time:%v, loops:%d", FormatDuration(time.Duration(e.consume)), e.loop) } @@ -334,7 +334,7 @@ func (e *basicCopRuntimeStats) String() string { // Clone implements the RuntimeStats interface. func (e *basicCopRuntimeStats) Clone() RuntimeStats { return &basicCopRuntimeStats{ - BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows}, + BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, fullTableScanContext: e.fullTableScanContext}, threads: e.threads, storeType: e.storeType, } @@ -446,7 +446,7 @@ func (crs *CopRuntimeStats) String() string { if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) if !totalFullTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf("table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", totalFullTableScanContext.scanPacksCount, totalFullTableScanContext.skipPacksCount, totalFullTableScanContext.scanRowsCount, totalFullTableScanContext.skipRowsCount)) + buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", totalFullTableScanContext.scanPacksCount, totalFullTableScanContext.skipPacksCount, totalFullTableScanContext.scanRowsCount, totalFullTableScanContext.skipRowsCount)) } } else { buf.WriteString("}") diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index fa6586bd1520a..c9dfc6493e8ce 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -203,10 +203,10 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { tableScanID := 1 aggID := 2 tableReaderID := 3 - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, "aggregation_"+strconv.Itoa(aggID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, "aggregation_"+strconv.Itoa(aggID))) scanDetail := &util.ScanDetail{ TotalKeys: 10, ProcessedKeys: 10, @@ -220,15 +220,15 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { require.True(t, stats.ExistsCopStats(tableScanID)) cop := stats.GetOrCreateCopStats(tableScanID, "tiflash") - require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}", cop.String()) + require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0}", cop.String()) copStats := cop.stats["8.8.8.8"] require.NotNil(t, copStats) copStats[0].SetRowNum(10) copStats[0].Record(time.Second, 10) - require.Equal(t, "time:1s, loops:2, threads:1", copStats[0].String()) - expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}" + require.Equal(t, "time:1s, loops:2, threads:1, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0}", copStats[0].String()) + expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:3, skip_pack_counts:11, scan_rows_counts:20192, skip_rows_count:86000}" require.Equal(t, expected, stats.GetOrCreateCopStats(aggID, "tiflash").String()) rootStats := stats.GetRootStats(tableReaderID) @@ -382,8 +382,8 @@ func TestRuntimeStatsWithCommit(t *testing.T) { } func TestRootRuntimeStats(t *testing.T) { - basic1 := &BasicRuntimeStats{} - basic2 := &BasicRuntimeStats{} + basic1 := &BasicRuntimeStats{fullTableScanContext: &FullTableScanContext{}} + basic2 := &BasicRuntimeStats{fullTableScanContext: &FullTableScanContext{}} basic1.Record(time.Second, 20) basic2.Record(time.Second*2, 30) pid := 1 From 0a72bba0d0c6add0a78fc412dfd2957040d19510 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 18 Nov 2022 17:49:10 +0800 Subject: [PATCH 03/19] update code --- go.mod | 2 + util/execdetails/execdetails.go | 73 +++++++++++++++------------- util/execdetails/execdetails_test.go | 35 +++++++------ 3 files changed, 59 insertions(+), 51 deletions(-) diff --git a/go.mod b/go.mod index 01400b701b85b..e7a30f8ad0882 100644 --- a/go.mod +++ b/go.mod @@ -254,3 +254,5 @@ replace ( github.com/pingcap/tidb/parser => ./parser go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) + +replace github.com/pingcap/tipb => github.com/hongyunyan/tipb hongyunyan_add_statistic diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 675ec59e21d75..39908ff1e3a59 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -326,7 +326,7 @@ type basicCopRuntimeStats struct { // String implements the RuntimeStats interface. func (e *basicCopRuntimeStats) String() string { if e.storeType == "tiflash" { - return fmt.Sprintf("time:%v, loops:%d, threads:%d, table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.fullTableScanContext.scanPacksCount, e.fullTableScanContext.skipPacksCount, e.fullTableScanContext.scanRowsCount, e.fullTableScanContext.skipRowsCount) + return fmt.Sprintf("time:%v, loops:%d, threads:%d, table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time_in_milliseconds: %d, dmfile_read_time_in_milliseconds: %d, create_snapshot_time_in_milliseconds: %d}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.tableScanContext.scanPacksCount, e.tableScanContext.skipPacksCount, e.tableScanContext.scanRowsCount, e.tableScanContext.skipRowsCount, e.tableScanContext.roughSetIndexLoadTimeInMilliseconds, e.tableScanContext.dmfileReadTimeInMilliseconds, e.tableScanContext.createSnapshotTimeInMilliseconds) } return fmt.Sprintf("time:%v, loops:%d", FormatDuration(time.Duration(e.consume)), e.loop) } @@ -334,7 +334,7 @@ func (e *basicCopRuntimeStats) String() string { // Clone implements the RuntimeStats interface. func (e *basicCopRuntimeStats) Clone() RuntimeStats { return &basicCopRuntimeStats{ - BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, fullTableScanContext: e.fullTableScanContext}, + BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tableScanContext: e.tableScanContext}, threads: e.threads, storeType: e.storeType, } @@ -375,17 +375,19 @@ type CopRuntimeStats struct { func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.ExecutorExecutionSummary) { crs.Lock() defer crs.Unlock() - fmt.Printf("hyy RecordOneCopTask summary GetFullTableScanContext GetScanPacksCount is %v", summary.GetFullTableScanContext().GetScanPacksCount()) - fmt.Println("") + crs.stats[address] = append(crs.stats[address], &basicCopRuntimeStats{BasicRuntimeStats: BasicRuntimeStats{loop: int32(*summary.NumIterations), consume: int64(*summary.TimeProcessedNs), rows: int64(*summary.NumProducedRows), - fullTableScanContext: &FullTableScanContext{ - scanPacksCount: summary.GetFullTableScanContext().GetScanPacksCount(), - skipPacksCount: summary.GetFullTableScanContext().GetSkipPacksCount(), - scanRowsCount: summary.GetFullTableScanContext().GetScanRowsCount(), - skipRowsCount: summary.GetFullTableScanContext().GetSkipRowsCount()}}, + tableScanContext: &TableScanContext{ + scanPacksCount: summary.GetTableScanContext().GetScanPacksCount(), + skipPacksCount: summary.GetTableScanContext().GetSkipPacksCount(), + scanRowsCount: summary.GetTableScanContext().GetScanRowsCount(), + skipRowsCount: summary.GetTableScanContext().GetSkipRowsCount(), + roughSetIndexLoadTimeInMilliseconds: summary.GetTableScanContext().GetRoughSetIndexLoadTimeInMilliseconds(), + dmfileReadTimeInMilliseconds: summary.GetTableScanContext().GetDmfileReadTimeInMilliseconds(), + createSnapshotTimeInMilliseconds: summary.GetTableScanContext().GetCreateSnapshotTimeInMilliseconds()}}, threads: int32(summary.GetConcurrency()), storeType: crs.storeType}) } @@ -401,16 +403,16 @@ func (crs *CopRuntimeStats) GetActRows() (totalRows int64) { } // MergeBasicStats traverses basicCopRuntimeStats in the CopRuntimeStats and collects some useful information. -func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalFullTableScanContext *FullTableScanContext) { +func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalTableScanContext *TableScanContext) { procTimes = make([]time.Duration, 0, 32) - totalFullTableScanContext = &FullTableScanContext{} + totalTableScanContext = &TableScanContext{} for _, instanceStats := range crs.stats { for _, stat := range instanceStats { procTimes = append(procTimes, time.Duration(stat.consume)*time.Nanosecond) totalTime += time.Duration(stat.consume) totalLoops += stat.loop totalThreads += stat.threads - totalFullTableScanContext.Merge(stat.fullTableScanContext) + totalTableScanContext.Merge(stat.tableScanContext) totalTasks++ } } @@ -422,7 +424,7 @@ func (crs *CopRuntimeStats) String() string { return "" } - procTimes, totalTime, totalTasks, totalLoops, totalThreads, totalFullTableScanContext := crs.MergeBasicStats() + procTimes, totalTime, totalTasks, totalLoops, totalThreads, totalTableScanContext := crs.MergeBasicStats() avgTime := time.Duration(totalTime.Nanoseconds() / int64(totalTasks)) isTiFlashCop := crs.storeType == "tiflash" @@ -431,8 +433,8 @@ func (crs *CopRuntimeStats) String() string { buf.WriteString(fmt.Sprintf("%v_task:{time:%v, loops:%d", crs.storeType, FormatDuration(procTimes[0]), totalLoops)) if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) - if !totalFullTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", totalFullTableScanContext.scanPacksCount, totalFullTableScanContext.skipPacksCount, totalFullTableScanContext.scanRowsCount, totalFullTableScanContext.skipRowsCount)) + if !totalTableScanContext.Empty() { + buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time_in_milliseconds: %d, dmfile_read_time_in_milliseconds: %d, create_snapshot_time_in_milliseconds: %d}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInMilliseconds, totalTableScanContext.dmfileReadTimeInMilliseconds, totalTableScanContext.createSnapshotTimeInMilliseconds)) } } else { buf.WriteString("}") @@ -445,8 +447,8 @@ func (crs *CopRuntimeStats) String() string { FormatDuration(procTimes[n*4/5]), FormatDuration(procTimes[n*19/20]), totalLoops, totalTasks)) if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) - if !totalFullTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d}", totalFullTableScanContext.scanPacksCount, totalFullTableScanContext.skipPacksCount, totalFullTableScanContext.scanRowsCount, totalFullTableScanContext.skipRowsCount)) + if !totalTableScanContext.Empty() { + buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time_in_milliseconds: %d, dmfile_read_time_in_milliseconds: %d, create_snapshot_time_in_milliseconds: %d}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInMilliseconds, totalTableScanContext.dmfileReadTimeInMilliseconds, totalTableScanContext.createSnapshotTimeInMilliseconds)) } } else { buf.WriteString("}") @@ -505,27 +507,28 @@ type RuntimeStats interface { Tp() int } -type FullTableScanContext struct { - scanPacksCount uint64 - scanRowsCount uint64 - skipPacksCount uint64 - skipRowsCount uint64 +type TableScanContext struct { + scanPacksCount uint64 + scanRowsCount uint64 + skipPacksCount uint64 + skipRowsCount uint64 + roughSetIndexLoadTimeInMilliseconds uint64 + dmfileReadTimeInMilliseconds uint64 + createSnapshotTimeInMilliseconds uint64 } -func (context *FullTableScanContext) Merge(other *FullTableScanContext) { +func (context *TableScanContext) Merge(other *TableScanContext) { context.scanPacksCount += other.scanPacksCount context.scanRowsCount += other.scanRowsCount context.skipPacksCount += other.skipPacksCount context.skipRowsCount += other.skipRowsCount - - fmt.Printf("hyy FullTableScanContext Merge context.scanPacksCount is %v", context.scanPacksCount) - fmt.Println("") + context.roughSetIndexLoadTimeInMilliseconds += other.roughSetIndexLoadTimeInMilliseconds + context.dmfileReadTimeInMilliseconds += other.dmfileReadTimeInMilliseconds + context.createSnapshotTimeInMilliseconds += other.createSnapshotTimeInMilliseconds } -func (context *FullTableScanContext) Empty() bool { +func (context *TableScanContext) Empty() bool { res := (context.scanPacksCount == 0 && context.skipPacksCount == 0) - fmt.Printf("hyy FullTableScanContext empty is %v", res) - fmt.Println(" ") return res } @@ -538,7 +541,7 @@ type BasicRuntimeStats struct { // executor return row count. rows int64 // executor extra infos - fullTableScanContext *FullTableScanContext + tableScanContext *TableScanContext } // GetActRows return total rows of BasicRuntimeStats. @@ -549,10 +552,10 @@ func (e *BasicRuntimeStats) GetActRows() int64 { // Clone implements the RuntimeStats interface. func (e *BasicRuntimeStats) Clone() RuntimeStats { return &BasicRuntimeStats{ - loop: e.loop, - consume: e.consume, - rows: e.rows, - fullTableScanContext: e.fullTableScanContext, + loop: e.loop, + consume: e.consume, + rows: e.rows, + tableScanContext: e.tableScanContext, } } @@ -565,7 +568,7 @@ func (e *BasicRuntimeStats) Merge(rs RuntimeStats) { e.loop += tmp.loop e.consume += tmp.consume e.rows += tmp.rows - e.fullTableScanContext.Merge(tmp.fullTableScanContext) + e.tableScanContext.Merge(tmp.tableScanContext) } // Tp implements the RuntimeStats interface. diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index c9dfc6493e8ce..00fbc4b5738cb 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -135,15 +135,18 @@ func mockExecutorExecutionSummary(TimeProcessedNs, NumProducedRows, NumIteration NumIterations: &NumIterations, XXX_unrecognized: nil} } -func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, ScanPacksCount, ScanRowsCount, SkipPacksCount, SkipRowsCount uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { - fullTableScanContext := tipb.FullTableScanContext{ - ScanPacksCount: &ScanPacksCount, - ScanRowsCount: &ScanRowsCount, - SkipPacksCount: &SkipPacksCount, - SkipRowsCount: &SkipRowsCount, +func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, ScanPacksCount, ScanRowsCount, SkipPacksCount, SkipRowsCount, roughSetIndexLoadTimeInMilliseconds, dmfileReadTimeInMilliseconds, createSnapshotTimeInMilliseconds uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { + tableScanContext := tipb.TableScanContext{ + ScanPacksCount: &ScanPacksCount, + ScanRowsCount: &ScanRowsCount, + SkipPacksCount: &SkipPacksCount, + SkipRowsCount: &SkipRowsCount, + RoughSetIndexLoadTimeInMilliseconds: &roughSetIndexLoadTimeInMilliseconds, + DmfileReadTimeInMilliseconds: &dmfileReadTimeInMilliseconds, + CreateSnapshotTimeInMilliseconds: &createSnapshotTimeInMilliseconds, } return &tipb.ExecutorExecutionSummary{TimeProcessedNs: &TimeProcessedNs, NumProducedRows: &NumProducedRows, - NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_FullTableScanContext{FullTableScanContext: &fullTableScanContext}, XXX_unrecognized: nil} + NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_TableScanContext{TableScanContext: &tableScanContext}, XXX_unrecognized: nil} } func TestCopRuntimeStats(t *testing.T) { @@ -203,10 +206,10 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { tableScanID := 1 aggID := 2 tableReaderID := 3 - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, "aggregation_"+strconv.Itoa(aggID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, 15, 200, 40, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, 0, 2, 0, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, 60, 1000, 20, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, 40, 2000, 30, "aggregation_"+strconv.Itoa(aggID))) scanDetail := &util.ScanDetail{ TotalKeys: 10, ProcessedKeys: 10, @@ -220,15 +223,15 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { require.True(t, stats.ExistsCopStats(tableScanID)) cop := stats.GetOrCreateCopStats(tableScanID, "tiflash") - require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0}", cop.String()) + require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time_in_milliseconds: 15, dmfile_read_time_in_milliseconds: 202, create_snapshot_time_in_milliseconds: 40}", cop.String()) copStats := cop.stats["8.8.8.8"] require.NotNil(t, copStats) copStats[0].SetRowNum(10) copStats[0].Record(time.Second, 10) - require.Equal(t, "time:1s, loops:2, threads:1, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0}", copStats[0].String()) - expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:3, skip_pack_counts:11, scan_rows_counts:20192, skip_rows_count:86000}" + require.Equal(t, "time:1s, loops:2, threads:1, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time_in_milliseconds: 15, dmfile_read_time_in_milliseconds: 200, create_snapshot_time_in_milliseconds: 40}", copStats[0].String()) + expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:3, skip_pack_counts:11, scan_rows_counts:20192, skip_rows_count:86000, rough_set_index_load_time_in_milliseconds: 100, dmfile_read_time_in_milliseconds: 3000, create_snapshot_time_in_milliseconds: 50}" require.Equal(t, expected, stats.GetOrCreateCopStats(aggID, "tiflash").String()) rootStats := stats.GetRootStats(tableReaderID) @@ -382,8 +385,8 @@ func TestRuntimeStatsWithCommit(t *testing.T) { } func TestRootRuntimeStats(t *testing.T) { - basic1 := &BasicRuntimeStats{fullTableScanContext: &FullTableScanContext{}} - basic2 := &BasicRuntimeStats{fullTableScanContext: &FullTableScanContext{}} + basic1 := &BasicRuntimeStats{tableScanContext: &TableScanContext{}} + basic2 := &BasicRuntimeStats{tableScanContext: &TableScanContext{}} basic1.Record(time.Second, 20) basic2.Record(time.Second*2, 30) pid := 1 From 894520d2b6d4ed3f1f7989e3ae0168bc2e2ff493 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 18 Nov 2022 18:05:07 +0800 Subject: [PATCH 04/19] update code --- go.mod | 2 +- util/execdetails/execdetails.go | 3 +++ 2 files changed, 4 insertions(+), 1 deletion(-) diff --git a/go.mod b/go.mod index e7a30f8ad0882..d6833053195fb 100644 --- a/go.mod +++ b/go.mod @@ -255,4 +255,4 @@ replace ( go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) -replace github.com/pingcap/tipb => github.com/hongyunyan/tipb hongyunyan_add_statistic +replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221118093936-06ca0ac7901d diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 39908ff1e3a59..bbc8dc004b366 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -507,6 +507,7 @@ type RuntimeStats interface { Tp() int } +// TableScanContext is used to express the table scan information in tiflash type TableScanContext struct { scanPacksCount uint64 scanRowsCount uint64 @@ -517,6 +518,7 @@ type TableScanContext struct { createSnapshotTimeInMilliseconds uint64 } +// Merge make sum to merge the information in TableScanContext func (context *TableScanContext) Merge(other *TableScanContext) { context.scanPacksCount += other.scanPacksCount context.scanRowsCount += other.scanRowsCount @@ -527,6 +529,7 @@ func (context *TableScanContext) Merge(other *TableScanContext) { context.createSnapshotTimeInMilliseconds += other.createSnapshotTimeInMilliseconds } +// Empty check whether TableScanContext is Empty, if scan no pack and skip no pack, we regard it as empty func (context *TableScanContext) Empty() bool { res := (context.scanPacksCount == 0 && context.skipPacksCount == 0) return res From 959949613a5035957d4fa1eabf5531758034504c Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 18 Nov 2022 18:10:29 +0800 Subject: [PATCH 05/19] update --- go.sum | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/go.sum b/go.sum index 0730b5193bd55..498837aa922bc 100644 --- a/go.sum +++ b/go.sum @@ -526,6 +526,8 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM= github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg= +github.com/hongyunyan/tipb v0.0.0-20221118093936-06ca0ac7901d h1:ppM0DGGu19/NS1Yez2EA0uhpwJh3/Hh9Ly9OSqhPeHg= +github.com/hongyunyan/tipb v0.0.0-20221118093936-06ca0ac7901d/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/hydrogen18/memlistener v0.0.0-20141126152155-54553eb933fb/go.mod h1:qEIFzExnS6016fRpRfxrExeVn2gbClQA99gQhnIcdhE= github.com/iancoleman/strcase v0.2.0 h1:05I4QRnGpI0m37iZQRuskXh+w77mr6Z41lwQzuHLwW0= @@ -787,8 +789,6 @@ github.com/pingcap/log v1.1.1-0.20221110065318-21a4942860b3 h1:T7e5Low0BU2ZazI2d github.com/pingcap/log v1.1.1-0.20221110065318-21a4942860b3/go.mod h1:DWQW5jICDR7UJh4HtxXSM20Churx4CQL0fwL/SoOSA4= github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4 h1:HYbcxtnkN3s5tqrZ/z3eJS4j3Db8wMphEm1q10lY/TM= github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4/go.mod h1:sDCsM39cGiv2vwunZkaFA917vVkqDTGSPbbV7z4Oops= -github.com/pingcap/tipb v0.0.0-20221020071514-cd933387bcb5 h1:Yoo8j5xQGxjlsC3yt0ndsiAz0WZXED9rzsKmEN0U0DY= -github.com/pingcap/tipb v0.0.0-20221020071514-cd933387bcb5/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4 h1:49lOXmGaUpV9Fz3gd7TFZY106KVlPVa5jcYD1gaQf98= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4/go.mod h1:4OwLy04Bl9Ef3GJJCoec+30X3LQs/0/m4HFRt/2LUSA= github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= From e84faca302ae02513bd02a10a70974896b490832 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Fri, 18 Nov 2022 18:25:50 +0800 Subject: [PATCH 06/19] update code --- go.mod | 2 +- go.sum | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index d6833053195fb..b730388e7494c 100644 --- a/go.mod +++ b/go.mod @@ -255,4 +255,4 @@ replace ( go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) -replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221118093936-06ca0ac7901d +replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221118102111-bce44035c5bc diff --git a/go.sum b/go.sum index 498837aa922bc..27c5130c6fc7e 100644 --- a/go.sum +++ b/go.sum @@ -526,8 +526,8 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM= github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg= -github.com/hongyunyan/tipb v0.0.0-20221118093936-06ca0ac7901d h1:ppM0DGGu19/NS1Yez2EA0uhpwJh3/Hh9Ly9OSqhPeHg= -github.com/hongyunyan/tipb v0.0.0-20221118093936-06ca0ac7901d/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= +github.com/hongyunyan/tipb v0.0.0-20221118102111-bce44035c5bc h1:wDkEC1UvCTdd5bUNbbdePKV+ttq3/r3etTfF3fykjkM= +github.com/hongyunyan/tipb v0.0.0-20221118102111-bce44035c5bc/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/hydrogen18/memlistener v0.0.0-20141126152155-54553eb933fb/go.mod h1:qEIFzExnS6016fRpRfxrExeVn2gbClQA99gQhnIcdhE= github.com/iancoleman/strcase v0.2.0 h1:05I4QRnGpI0m37iZQRuskXh+w77mr6Z41lwQzuHLwW0= From d71ad6a37cbb57e07715913c02fb60a9e93276d6 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Mon, 21 Nov 2022 11:55:44 +0800 Subject: [PATCH 07/19] update code --- go.mod | 2 +- go.sum | 4 +-- util/execdetails/execdetails.go | 40 ++++++++++++++-------------- util/execdetails/execdetails_test.go | 30 ++++++++++----------- 4 files changed, 38 insertions(+), 38 deletions(-) diff --git a/go.mod b/go.mod index b730388e7494c..3a690b232f91e 100644 --- a/go.mod +++ b/go.mod @@ -255,4 +255,4 @@ replace ( go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) -replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221118102111-bce44035c5bc +replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221121032241-36c9b9bf454c diff --git a/go.sum b/go.sum index 27c5130c6fc7e..dd07450a4141b 100644 --- a/go.sum +++ b/go.sum @@ -526,8 +526,8 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM= github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg= -github.com/hongyunyan/tipb v0.0.0-20221118102111-bce44035c5bc h1:wDkEC1UvCTdd5bUNbbdePKV+ttq3/r3etTfF3fykjkM= -github.com/hongyunyan/tipb v0.0.0-20221118102111-bce44035c5bc/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= +github.com/hongyunyan/tipb v0.0.0-20221121032241-36c9b9bf454c h1:vPyVNIRMayvJEewwWoV1t6lFcC1vLmqS+mRiSbt5rRU= +github.com/hongyunyan/tipb v0.0.0-20221121032241-36c9b9bf454c/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/hydrogen18/memlistener v0.0.0-20141126152155-54553eb933fb/go.mod h1:qEIFzExnS6016fRpRfxrExeVn2gbClQA99gQhnIcdhE= github.com/iancoleman/strcase v0.2.0 h1:05I4QRnGpI0m37iZQRuskXh+w77mr6Z41lwQzuHLwW0= diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index bbc8dc004b366..db9599c9639af 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -326,7 +326,7 @@ type basicCopRuntimeStats struct { // String implements the RuntimeStats interface. func (e *basicCopRuntimeStats) String() string { if e.storeType == "tiflash" { - return fmt.Sprintf("time:%v, loops:%d, threads:%d, table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time_in_milliseconds: %d, dmfile_read_time_in_milliseconds: %d, create_snapshot_time_in_milliseconds: %d}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.tableScanContext.scanPacksCount, e.tableScanContext.skipPacksCount, e.tableScanContext.scanRowsCount, e.tableScanContext.skipRowsCount, e.tableScanContext.roughSetIndexLoadTimeInMilliseconds, e.tableScanContext.dmfileReadTimeInMilliseconds, e.tableScanContext.createSnapshotTimeInMilliseconds) + return fmt.Sprintf("time:%v, loops:%d, threads:%d, table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time: %dms, dmfile_read_time: %dms, create_snapshot_time: %dms}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.tableScanContext.scanPacksCount, e.tableScanContext.skipPacksCount, e.tableScanContext.scanRowsCount, e.tableScanContext.skipRowsCount, e.tableScanContext.roughSetIndexLoadTimeInNs/1000000, e.tableScanContext.dmfileReadTimeInNs/1000000, e.tableScanContext.createSnapshotTimeInNs/1000000) } return fmt.Sprintf("time:%v, loops:%d", FormatDuration(time.Duration(e.consume)), e.loop) } @@ -381,13 +381,13 @@ func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.Execu consume: int64(*summary.TimeProcessedNs), rows: int64(*summary.NumProducedRows), tableScanContext: &TableScanContext{ - scanPacksCount: summary.GetTableScanContext().GetScanPacksCount(), - skipPacksCount: summary.GetTableScanContext().GetSkipPacksCount(), - scanRowsCount: summary.GetTableScanContext().GetScanRowsCount(), - skipRowsCount: summary.GetTableScanContext().GetSkipRowsCount(), - roughSetIndexLoadTimeInMilliseconds: summary.GetTableScanContext().GetRoughSetIndexLoadTimeInMilliseconds(), - dmfileReadTimeInMilliseconds: summary.GetTableScanContext().GetDmfileReadTimeInMilliseconds(), - createSnapshotTimeInMilliseconds: summary.GetTableScanContext().GetCreateSnapshotTimeInMilliseconds()}}, + scanPacksCount: summary.GetTableScanContext().GetScanPacksCount(), + skipPacksCount: summary.GetTableScanContext().GetSkipPacksCount(), + scanRowsCount: summary.GetTableScanContext().GetScanRowsCount(), + skipRowsCount: summary.GetTableScanContext().GetSkipRowsCount(), + roughSetIndexLoadTimeInNs: summary.GetTableScanContext().GetRoughSetIndexLoadTimeInNs(), + dmfileReadTimeInNs: summary.GetTableScanContext().GetDmfileReadTimeInNs(), + createSnapshotTimeInNs: summary.GetTableScanContext().GetCreateSnapshotTimeInNs()}}, threads: int32(summary.GetConcurrency()), storeType: crs.storeType}) } @@ -434,7 +434,7 @@ func (crs *CopRuntimeStats) String() string { if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) if !totalTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time_in_milliseconds: %d, dmfile_read_time_in_milliseconds: %d, create_snapshot_time_in_milliseconds: %d}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInMilliseconds, totalTableScanContext.dmfileReadTimeInMilliseconds, totalTableScanContext.createSnapshotTimeInMilliseconds)) + buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time: %dms, dmfile_read_time: %dms, create_snapshot_time: %dms}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInNs/1000000, totalTableScanContext.dmfileReadTimeInNs/1000000, totalTableScanContext.createSnapshotTimeInNs/1000000)) } } else { buf.WriteString("}") @@ -448,7 +448,7 @@ func (crs *CopRuntimeStats) String() string { if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) if !totalTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time_in_milliseconds: %d, dmfile_read_time_in_milliseconds: %d, create_snapshot_time_in_milliseconds: %d}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInMilliseconds, totalTableScanContext.dmfileReadTimeInMilliseconds, totalTableScanContext.createSnapshotTimeInMilliseconds)) + buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time: %dms, dmfile_read_time: %dms, create_snapshot_time: %dms}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInNs/1000000, totalTableScanContext.dmfileReadTimeInNs/1000000, totalTableScanContext.createSnapshotTimeInNs/1000000)) } } else { buf.WriteString("}") @@ -509,13 +509,13 @@ type RuntimeStats interface { // TableScanContext is used to express the table scan information in tiflash type TableScanContext struct { - scanPacksCount uint64 - scanRowsCount uint64 - skipPacksCount uint64 - skipRowsCount uint64 - roughSetIndexLoadTimeInMilliseconds uint64 - dmfileReadTimeInMilliseconds uint64 - createSnapshotTimeInMilliseconds uint64 + scanPacksCount uint64 + scanRowsCount uint64 + skipPacksCount uint64 + skipRowsCount uint64 + roughSetIndexLoadTimeInNs uint64 + dmfileReadTimeInNs uint64 + createSnapshotTimeInNs uint64 } // Merge make sum to merge the information in TableScanContext @@ -524,9 +524,9 @@ func (context *TableScanContext) Merge(other *TableScanContext) { context.scanRowsCount += other.scanRowsCount context.skipPacksCount += other.skipPacksCount context.skipRowsCount += other.skipRowsCount - context.roughSetIndexLoadTimeInMilliseconds += other.roughSetIndexLoadTimeInMilliseconds - context.dmfileReadTimeInMilliseconds += other.dmfileReadTimeInMilliseconds - context.createSnapshotTimeInMilliseconds += other.createSnapshotTimeInMilliseconds + context.roughSetIndexLoadTimeInNs += other.roughSetIndexLoadTimeInNs + context.dmfileReadTimeInNs += other.dmfileReadTimeInNs + context.createSnapshotTimeInNs += other.createSnapshotTimeInNs } // Empty check whether TableScanContext is Empty, if scan no pack and skip no pack, we regard it as empty diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index 00fbc4b5738cb..666ca83ea0e9f 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -135,15 +135,15 @@ func mockExecutorExecutionSummary(TimeProcessedNs, NumProducedRows, NumIteration NumIterations: &NumIterations, XXX_unrecognized: nil} } -func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, ScanPacksCount, ScanRowsCount, SkipPacksCount, SkipRowsCount, roughSetIndexLoadTimeInMilliseconds, dmfileReadTimeInMilliseconds, createSnapshotTimeInMilliseconds uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { +func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, ScanPacksCount, ScanRowsCount, SkipPacksCount, SkipRowsCount, roughSetIndexLoadTimeInNs, dmfileReadTimeInNs, createSnapshotTimeInNs uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { tableScanContext := tipb.TableScanContext{ - ScanPacksCount: &ScanPacksCount, - ScanRowsCount: &ScanRowsCount, - SkipPacksCount: &SkipPacksCount, - SkipRowsCount: &SkipRowsCount, - RoughSetIndexLoadTimeInMilliseconds: &roughSetIndexLoadTimeInMilliseconds, - DmfileReadTimeInMilliseconds: &dmfileReadTimeInMilliseconds, - CreateSnapshotTimeInMilliseconds: &createSnapshotTimeInMilliseconds, + ScanPacksCount: &ScanPacksCount, + ScanRowsCount: &ScanRowsCount, + SkipPacksCount: &SkipPacksCount, + SkipRowsCount: &SkipRowsCount, + RoughSetIndexLoadTimeInNs: &roughSetIndexLoadTimeInNs, + DmfileReadTimeInNs: &dmfileReadTimeInNs, + CreateSnapshotTimeInNs: &createSnapshotTimeInNs, } return &tipb.ExecutorExecutionSummary{TimeProcessedNs: &TimeProcessedNs, NumProducedRows: &NumProducedRows, NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_TableScanContext{TableScanContext: &tableScanContext}, XXX_unrecognized: nil} @@ -206,10 +206,10 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { tableScanID := 1 aggID := 2 tableReaderID := 3 - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, 15, 200, 40, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, 0, 2, 0, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, 60, 1000, 20, "aggregation_"+strconv.Itoa(aggID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, 40, 2000, 30, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, 15000000, 200000000, 40000000, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, 0, 2000000, 0, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, 60000000, 1000000000, 20000000, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, 40000000, 2000000000, 30000000, "aggregation_"+strconv.Itoa(aggID))) scanDetail := &util.ScanDetail{ TotalKeys: 10, ProcessedKeys: 10, @@ -223,15 +223,15 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { require.True(t, stats.ExistsCopStats(tableScanID)) cop := stats.GetOrCreateCopStats(tableScanID, "tiflash") - require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time_in_milliseconds: 15, dmfile_read_time_in_milliseconds: 202, create_snapshot_time_in_milliseconds: 40}", cop.String()) + require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time: 15ms, dmfile_read_time: 202ms, create_snapshot_time: 40ms}", cop.String()) copStats := cop.stats["8.8.8.8"] require.NotNil(t, copStats) copStats[0].SetRowNum(10) copStats[0].Record(time.Second, 10) - require.Equal(t, "time:1s, loops:2, threads:1, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time_in_milliseconds: 15, dmfile_read_time_in_milliseconds: 200, create_snapshot_time_in_milliseconds: 40}", copStats[0].String()) - expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:3, skip_pack_counts:11, scan_rows_counts:20192, skip_rows_count:86000, rough_set_index_load_time_in_milliseconds: 100, dmfile_read_time_in_milliseconds: 3000, create_snapshot_time_in_milliseconds: 50}" + require.Equal(t, "time:1s, loops:2, threads:1, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time: 15ms, dmfile_read_time: 200ms, create_snapshot_time: 40ms}", copStats[0].String()) + expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:3, skip_pack_counts:11, scan_rows_counts:20192, skip_rows_count:86000, rough_set_index_load_time: 100ms, dmfile_read_time: 3000ms, create_snapshot_time: 50ms}" require.Equal(t, expected, stats.GetOrCreateCopStats(aggID, "tiflash").String()) rootStats := stats.GetRootStats(tableReaderID) From 049d516bcb23c8139f730f97c8d3927ea674c4f7 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Mon, 21 Nov 2022 13:28:46 +0800 Subject: [PATCH 08/19] update branch --- go.mod | 2 +- go.sum | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index 3a690b232f91e..fba0a121d3897 100644 --- a/go.mod +++ b/go.mod @@ -255,4 +255,4 @@ replace ( go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) -replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221121032241-36c9b9bf454c +replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221121051916-a5b808f2438a diff --git a/go.sum b/go.sum index dd07450a4141b..ae8b92b07fd93 100644 --- a/go.sum +++ b/go.sum @@ -526,8 +526,8 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM= github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg= -github.com/hongyunyan/tipb v0.0.0-20221121032241-36c9b9bf454c h1:vPyVNIRMayvJEewwWoV1t6lFcC1vLmqS+mRiSbt5rRU= -github.com/hongyunyan/tipb v0.0.0-20221121032241-36c9b9bf454c/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= +github.com/hongyunyan/tipb v0.0.0-20221121051916-a5b808f2438a h1:NhjftWDihzIE15fABHHJbo/ainsj8ZaZVMq6LyPeDso= +github.com/hongyunyan/tipb v0.0.0-20221121051916-a5b808f2438a/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/hydrogen18/memlistener v0.0.0-20141126152155-54553eb933fb/go.mod h1:qEIFzExnS6016fRpRfxrExeVn2gbClQA99gQhnIcdhE= github.com/iancoleman/strcase v0.2.0 h1:05I4QRnGpI0m37iZQRuskXh+w77mr6Z41lwQzuHLwW0= From 88e0b5a27fdeef5810778902ae875c50e3276e63 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Tue, 22 Nov 2022 18:12:47 +0800 Subject: [PATCH 09/19] update code --- go.mod | 2 +- go.sum | 4 +- util/execdetails/execdetails.go | 90 ++++++++++++++-------------- util/execdetails/execdetails_test.go | 10 ++-- 4 files changed, 53 insertions(+), 53 deletions(-) diff --git a/go.mod b/go.mod index fba0a121d3897..55b7ef4bcd272 100644 --- a/go.mod +++ b/go.mod @@ -255,4 +255,4 @@ replace ( go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) -replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221121051916-a5b808f2438a +replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221122080927-439f8cc5720e diff --git a/go.sum b/go.sum index ae8b92b07fd93..0b72958762e0a 100644 --- a/go.sum +++ b/go.sum @@ -526,8 +526,8 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM= github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg= -github.com/hongyunyan/tipb v0.0.0-20221121051916-a5b808f2438a h1:NhjftWDihzIE15fABHHJbo/ainsj8ZaZVMq6LyPeDso= -github.com/hongyunyan/tipb v0.0.0-20221121051916-a5b808f2438a/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= +github.com/hongyunyan/tipb v0.0.0-20221122080927-439f8cc5720e h1:4Aw7CnbV5fkN/4Ng+guRobTO9Rl4ZdfNN70RxlEerbE= +github.com/hongyunyan/tipb v0.0.0-20221122080927-439f8cc5720e/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/hydrogen18/memlistener v0.0.0-20141126152155-54553eb933fb/go.mod h1:qEIFzExnS6016fRpRfxrExeVn2gbClQA99gQhnIcdhE= github.com/iancoleman/strcase v0.2.0 h1:05I4QRnGpI0m37iZQRuskXh+w77mr6Z41lwQzuHLwW0= diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index db9599c9639af..2cc1b6f494fe1 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -326,7 +326,7 @@ type basicCopRuntimeStats struct { // String implements the RuntimeStats interface. func (e *basicCopRuntimeStats) String() string { if e.storeType == "tiflash" { - return fmt.Sprintf("time:%v, loops:%d, threads:%d, table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time: %dms, dmfile_read_time: %dms, create_snapshot_time: %dms}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.tableScanContext.scanPacksCount, e.tableScanContext.skipPacksCount, e.tableScanContext.scanRowsCount, e.tableScanContext.skipRowsCount, e.tableScanContext.roughSetIndexLoadTimeInNs/1000000, e.tableScanContext.dmfileReadTimeInNs/1000000, e.tableScanContext.createSnapshotTimeInNs/1000000) + return fmt.Sprintf("time:%v, loops:%d, threads:%d, tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_dmfile_read_time: %dms}, total_create_snapshot_time: %dms}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.tiflashScanContext.totalScannedPacksInDmfile, e.tiflashScanContext.totalSkippedPacksInDmfile, e.tiflashScanContext.totalScannedRowsInDmfile, e.tiflashScanContext.totalSkippedRowsInDmfile, e.tiflashScanContext.totalRoughSetIndexLoadTimeInNs/1000000, e.tiflashScanContext.totalDmfileReadTimeInNs/1000000, e.tiflashScanContext.totalCreateSnapshotTimeInNs/1000000) } return fmt.Sprintf("time:%v, loops:%d", FormatDuration(time.Duration(e.consume)), e.loop) } @@ -334,7 +334,7 @@ func (e *basicCopRuntimeStats) String() string { // Clone implements the RuntimeStats interface. func (e *basicCopRuntimeStats) Clone() RuntimeStats { return &basicCopRuntimeStats{ - BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tableScanContext: e.tableScanContext}, + BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tiflashScanContext: e.tiflashScanContext}, threads: e.threads, storeType: e.storeType, } @@ -380,14 +380,14 @@ func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.Execu &basicCopRuntimeStats{BasicRuntimeStats: BasicRuntimeStats{loop: int32(*summary.NumIterations), consume: int64(*summary.TimeProcessedNs), rows: int64(*summary.NumProducedRows), - tableScanContext: &TableScanContext{ - scanPacksCount: summary.GetTableScanContext().GetScanPacksCount(), - skipPacksCount: summary.GetTableScanContext().GetSkipPacksCount(), - scanRowsCount: summary.GetTableScanContext().GetScanRowsCount(), - skipRowsCount: summary.GetTableScanContext().GetSkipRowsCount(), - roughSetIndexLoadTimeInNs: summary.GetTableScanContext().GetRoughSetIndexLoadTimeInNs(), - dmfileReadTimeInNs: summary.GetTableScanContext().GetDmfileReadTimeInNs(), - createSnapshotTimeInNs: summary.GetTableScanContext().GetCreateSnapshotTimeInNs()}}, + tiflashScanContext: &TiFlashScanContext{ + totalScannedPacksInDmfile: summary.GetTiflashScanContext().GetTotalScannedPacksInDmfile(), + totalSkippedPacksInDmfile: summary.GetTiflashScanContext().GetTotalSkippedPacksInDmfile(), + totalScannedRowsInDmfile: summary.GetTiflashScanContext().GetTotalScannedRowsInDmfile(), + totalSkippedRowsInDmfile: summary.GetTiflashScanContext().GetTotalSkippedRowsInDmfile(), + totalRoughSetIndexLoadTimeInNs: summary.GetTiflashScanContext().GetTotalRoughSetIndexLoadTimeInNs(), + totalDmfileReadTimeInNs: summary.GetTiflashScanContext().GetTotalDmfileReadTimeInNs(), + totalCreateSnapshotTimeInNs: summary.GetTiflashScanContext().GetTotalCreateSnapshotTimeInNs()}}, threads: int32(summary.GetConcurrency()), storeType: crs.storeType}) } @@ -403,16 +403,16 @@ func (crs *CopRuntimeStats) GetActRows() (totalRows int64) { } // MergeBasicStats traverses basicCopRuntimeStats in the CopRuntimeStats and collects some useful information. -func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalTableScanContext *TableScanContext) { +func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalTiFlashScanContext *TiFlashScanContext) { procTimes = make([]time.Duration, 0, 32) - totalTableScanContext = &TableScanContext{} + totalTiFlashScanContext = &TiFlashScanContext{} for _, instanceStats := range crs.stats { for _, stat := range instanceStats { procTimes = append(procTimes, time.Duration(stat.consume)*time.Nanosecond) totalTime += time.Duration(stat.consume) totalLoops += stat.loop totalThreads += stat.threads - totalTableScanContext.Merge(stat.tableScanContext) + totalTiFlashScanContext.Merge(stat.tiflashScanContext) totalTasks++ } } @@ -424,7 +424,7 @@ func (crs *CopRuntimeStats) String() string { return "" } - procTimes, totalTime, totalTasks, totalLoops, totalThreads, totalTableScanContext := crs.MergeBasicStats() + procTimes, totalTime, totalTasks, totalLoops, totalThreads, totalTiFlashScanContext := crs.MergeBasicStats() avgTime := time.Duration(totalTime.Nanoseconds() / int64(totalTasks)) isTiFlashCop := crs.storeType == "tiflash" @@ -433,8 +433,8 @@ func (crs *CopRuntimeStats) String() string { buf.WriteString(fmt.Sprintf("%v_task:{time:%v, loops:%d", crs.storeType, FormatDuration(procTimes[0]), totalLoops)) if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) - if !totalTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time: %dms, dmfile_read_time: %dms, create_snapshot_time: %dms}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInNs/1000000, totalTableScanContext.dmfileReadTimeInNs/1000000, totalTableScanContext.createSnapshotTimeInNs/1000000)) + if !totalTiFlashScanContext.Empty() { + buf.WriteString(fmt.Sprintf(", tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_dmfile_read_time: %dms}, total_create_snapshot_time: %dms}", totalTiFlashScanContext.totalScannedPacksInDmfile, totalTiFlashScanContext.totalSkippedPacksInDmfile, totalTiFlashScanContext.totalScannedRowsInDmfile, totalTiFlashScanContext.totalSkippedRowsInDmfile, totalTiFlashScanContext.totalRoughSetIndexLoadTimeInNs/1000000, totalTiFlashScanContext.totalDmfileReadTimeInNs/1000000, totalTiFlashScanContext.totalCreateSnapshotTimeInNs/1000000)) } } else { buf.WriteString("}") @@ -447,8 +447,8 @@ func (crs *CopRuntimeStats) String() string { FormatDuration(procTimes[n*4/5]), FormatDuration(procTimes[n*19/20]), totalLoops, totalTasks)) if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) - if !totalTableScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", table_scan_info:{scan_pack_counts:%d, skip_pack_counts:%d, scan_rows_counts:%d, skip_rows_count:%d, rough_set_index_load_time: %dms, dmfile_read_time: %dms, create_snapshot_time: %dms}", totalTableScanContext.scanPacksCount, totalTableScanContext.skipPacksCount, totalTableScanContext.scanRowsCount, totalTableScanContext.skipRowsCount, totalTableScanContext.roughSetIndexLoadTimeInNs/1000000, totalTableScanContext.dmfileReadTimeInNs/1000000, totalTableScanContext.createSnapshotTimeInNs/1000000)) + if !totalTiFlashScanContext.Empty() { + buf.WriteString(fmt.Sprintf(", tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_dmfile_read_time: %dms}, total_create_snapshot_time: %dms}", totalTiFlashScanContext.totalScannedPacksInDmfile, totalTiFlashScanContext.totalSkippedPacksInDmfile, totalTiFlashScanContext.totalScannedRowsInDmfile, totalTiFlashScanContext.totalSkippedRowsInDmfile, totalTiFlashScanContext.totalRoughSetIndexLoadTimeInNs/1000000, totalTiFlashScanContext.totalDmfileReadTimeInNs/1000000, totalTiFlashScanContext.totalCreateSnapshotTimeInNs/1000000)) } } else { buf.WriteString("}") @@ -507,31 +507,31 @@ type RuntimeStats interface { Tp() int } -// TableScanContext is used to express the table scan information in tiflash -type TableScanContext struct { - scanPacksCount uint64 - scanRowsCount uint64 - skipPacksCount uint64 - skipRowsCount uint64 - roughSetIndexLoadTimeInNs uint64 - dmfileReadTimeInNs uint64 - createSnapshotTimeInNs uint64 +// TiFlashScanContext is used to express the table scan information in tiflash +type TiFlashScanContext struct { + totalScannedPacksInDmfile uint64 + totalScannedRowsInDmfile uint64 + totalSkippedPacksInDmfile uint64 + totalSkippedRowsInDmfile uint64 + totalRoughSetIndexLoadTimeInNs uint64 + totalDmfileReadTimeInNs uint64 + totalCreateSnapshotTimeInNs uint64 } -// Merge make sum to merge the information in TableScanContext -func (context *TableScanContext) Merge(other *TableScanContext) { - context.scanPacksCount += other.scanPacksCount - context.scanRowsCount += other.scanRowsCount - context.skipPacksCount += other.skipPacksCount - context.skipRowsCount += other.skipRowsCount - context.roughSetIndexLoadTimeInNs += other.roughSetIndexLoadTimeInNs - context.dmfileReadTimeInNs += other.dmfileReadTimeInNs - context.createSnapshotTimeInNs += other.createSnapshotTimeInNs +// Merge make sum to merge the information in TiFlashScanContext +func (context *TiFlashScanContext) Merge(other *TiFlashScanContext) { + context.totalScannedPacksInDmfile += other.totalScannedPacksInDmfile + context.totalScannedRowsInDmfile += other.totalScannedRowsInDmfile + context.totalSkippedPacksInDmfile += other.totalSkippedPacksInDmfile + context.totalSkippedRowsInDmfile += other.totalSkippedRowsInDmfile + context.totalRoughSetIndexLoadTimeInNs += other.totalRoughSetIndexLoadTimeInNs + context.totalDmfileReadTimeInNs += other.totalDmfileReadTimeInNs + context.totalCreateSnapshotTimeInNs += other.totalCreateSnapshotTimeInNs } -// Empty check whether TableScanContext is Empty, if scan no pack and skip no pack, we regard it as empty -func (context *TableScanContext) Empty() bool { - res := (context.scanPacksCount == 0 && context.skipPacksCount == 0) +// Empty check whether TiFlashScanContext is Empty, if scan no pack and skip no pack, we regard it as empty +func (context *TiFlashScanContext) Empty() bool { + res := (context.totalScannedPacksInDmfile == 0 && context.totalSkippedPacksInDmfile == 0) return res } @@ -544,7 +544,7 @@ type BasicRuntimeStats struct { // executor return row count. rows int64 // executor extra infos - tableScanContext *TableScanContext + tiflashScanContext *TiFlashScanContext } // GetActRows return total rows of BasicRuntimeStats. @@ -555,10 +555,10 @@ func (e *BasicRuntimeStats) GetActRows() int64 { // Clone implements the RuntimeStats interface. func (e *BasicRuntimeStats) Clone() RuntimeStats { return &BasicRuntimeStats{ - loop: e.loop, - consume: e.consume, - rows: e.rows, - tableScanContext: e.tableScanContext, + loop: e.loop, + consume: e.consume, + rows: e.rows, + tiflashScanContext: e.tiflashScanContext, } } @@ -571,7 +571,7 @@ func (e *BasicRuntimeStats) Merge(rs RuntimeStats) { e.loop += tmp.loop e.consume += tmp.consume e.rows += tmp.rows - e.tableScanContext.Merge(tmp.tableScanContext) + e.tiflashScanContext.Merge(tmp.tiflashScanContext) } // Tp implements the RuntimeStats interface. diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index 666ca83ea0e9f..b819a3f849f1d 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -223,15 +223,15 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { require.True(t, stats.ExistsCopStats(tableScanID)) cop := stats.GetOrCreateCopStats(tableScanID, "tiflash") - require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time: 15ms, dmfile_read_time: 202ms, create_snapshot_time: 40ms}", cop.String()) + require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, tiflash_scan:{dmfile:{total_scanned_packs:1, total_skipped_packs:0, total_scanned_rows:8192, total_skipped_rows:0, total_rough_set_index_load_time: 15ms, total_dmfile_read_time: 202ms}, create_snapshot_time: 40ms}", cop.String()) copStats := cop.stats["8.8.8.8"] require.NotNil(t, copStats) copStats[0].SetRowNum(10) copStats[0].Record(time.Second, 10) - require.Equal(t, "time:1s, loops:2, threads:1, table_scan_info:{scan_pack_counts:1, skip_pack_counts:0, scan_rows_counts:8192, skip_rows_count:0, rough_set_index_load_time: 15ms, dmfile_read_time: 200ms, create_snapshot_time: 40ms}", copStats[0].String()) - expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, table_scan_info:{scan_pack_counts:3, skip_pack_counts:11, scan_rows_counts:20192, skip_rows_count:86000, rough_set_index_load_time: 100ms, dmfile_read_time: 3000ms, create_snapshot_time: 50ms}" + require.Equal(t, "time:1s, loops:2, threads:1, tiflash_scan:{dmfile:{total_scanned_packs:1, total_skipped_packs:0, total_scanned_rows:8192, total_skipped_rows:0, total_rough_set_index_load_time: 15ms, total_dmfile_read_time: 200ms}, create_snapshot_time: 40ms}", copStats[0].String()) + expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, tiflash_scan:{dmfile:{total_scanned_packs:3, total_skipped_packs:11, total_scanned_rows:20192, total_skipped_rows:86000, total_rough_set_index_load_time: 100ms, total_dmfile_read_time: 3000ms}, create_snapshot_time: 50ms}" require.Equal(t, expected, stats.GetOrCreateCopStats(aggID, "tiflash").String()) rootStats := stats.GetRootStats(tableReaderID) @@ -385,8 +385,8 @@ func TestRuntimeStatsWithCommit(t *testing.T) { } func TestRootRuntimeStats(t *testing.T) { - basic1 := &BasicRuntimeStats{tableScanContext: &TableScanContext{}} - basic2 := &BasicRuntimeStats{tableScanContext: &TableScanContext{}} + basic1 := &BasicRuntimeStats{tiflashScanContext: &TiFlashScanContext{}} + basic2 := &BasicRuntimeStats{tiflashScanContext: &TiFlashScanContext{}} basic1.Record(time.Second, 20) basic2.Record(time.Second*2, 30) pid := 1 From c1ce996271a729d3acb7dc92d830325d4b65f7e1 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 23 Nov 2022 11:22:22 +0800 Subject: [PATCH 10/19] update mod --- go.mod | 4 +--- go.sum | 2 ++ 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/go.mod b/go.mod index 55b7ef4bcd272..77b50f77d516c 100644 --- a/go.mod +++ b/go.mod @@ -72,7 +72,7 @@ require ( github.com/pingcap/log v1.1.1-0.20221110065318-21a4942860b3 github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4 github.com/pingcap/tidb/parser v0.0.0-20211011031125-9b13dc409c5e - github.com/pingcap/tipb v0.0.0-20221020071514-cd933387bcb5 + github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48 github.com/pkg/errors v0.9.1 github.com/prometheus/client_golang v1.13.0 github.com/prometheus/client_model v0.2.0 @@ -254,5 +254,3 @@ replace ( github.com/pingcap/tidb/parser => ./parser go.opencensus.io => go.opencensus.io v0.23.1-0.20220331163232-052120675fac ) - -replace github.com/pingcap/tipb => github.com/hongyunyan/tipb v0.0.0-20221122080927-439f8cc5720e diff --git a/go.sum b/go.sum index 0b72958762e0a..2ca8375ec6730 100644 --- a/go.sum +++ b/go.sum @@ -789,6 +789,8 @@ github.com/pingcap/log v1.1.1-0.20221110065318-21a4942860b3 h1:T7e5Low0BU2ZazI2d github.com/pingcap/log v1.1.1-0.20221110065318-21a4942860b3/go.mod h1:DWQW5jICDR7UJh4HtxXSM20Churx4CQL0fwL/SoOSA4= github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4 h1:HYbcxtnkN3s5tqrZ/z3eJS4j3Db8wMphEm1q10lY/TM= github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4/go.mod h1:sDCsM39cGiv2vwunZkaFA917vVkqDTGSPbbV7z4Oops= +github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48 h1:CmDqkuJIil+pAOsY9smc+NO7we88EKumLgD6wHj3Zdg= +github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4 h1:49lOXmGaUpV9Fz3gd7TFZY106KVlPVa5jcYD1gaQf98= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4/go.mod h1:4OwLy04Bl9Ef3GJJCoec+30X3LQs/0/m4HFRt/2LUSA= github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= From ed7de66caf562a300969da2d9b01bf20d47898be Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 23 Nov 2022 11:35:33 +0800 Subject: [PATCH 11/19] update make --- DEPS.bzl | 4 ++-- go.sum | 2 -- 2 files changed, 2 insertions(+), 4 deletions(-) diff --git a/DEPS.bzl b/DEPS.bzl index 4c3e94cca5a14..2c3ee291aa71a 100644 --- a/DEPS.bzl +++ b/DEPS.bzl @@ -2912,8 +2912,8 @@ def go_deps(): name = "com_github_pingcap_tipb", build_file_proto_mode = "disable_global", importpath = "github.com/pingcap/tipb", - sum = "h1:Yoo8j5xQGxjlsC3yt0ndsiAz0WZXED9rzsKmEN0U0DY=", - version = "v0.0.0-20221020071514-cd933387bcb5", + sum = "h1:CmDqkuJIil+pAOsY9smc+NO7we88EKumLgD6wHj3Zdg=", + version = "v0.0.0-20221123024159-8765d4977a48", ) go_repository( name = "com_github_pkg_browser", diff --git a/go.sum b/go.sum index 2ca8375ec6730..37172a5d6a780 100644 --- a/go.sum +++ b/go.sum @@ -526,8 +526,6 @@ github.com/hashicorp/memberlist v0.1.3/go.mod h1:ajVTdAv/9Im8oMAAj5G31PhhMCZJV2p github.com/hashicorp/serf v0.8.2/go.mod h1:6hOLApaqBFA1NXqRQAsxw9QxuDEvNxSQRwA/JwenrHc= github.com/hexops/gotextdiff v1.0.3 h1:gitA9+qJrrTCsiCl7+kh75nPqQt1cx4ZkudSTLoUqJM= github.com/hexops/gotextdiff v1.0.3/go.mod h1:pSWU5MAI3yDq+fZBTazCSJysOMbxWL1BSow5/V2vxeg= -github.com/hongyunyan/tipb v0.0.0-20221122080927-439f8cc5720e h1:4Aw7CnbV5fkN/4Ng+guRobTO9Rl4ZdfNN70RxlEerbE= -github.com/hongyunyan/tipb v0.0.0-20221122080927-439f8cc5720e/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/hpcloud/tail v1.0.0/go.mod h1:ab1qPbhIpdTxEkNHXyeSf5vhxWSCs/tWer42PpOxQnU= github.com/hydrogen18/memlistener v0.0.0-20141126152155-54553eb933fb/go.mod h1:qEIFzExnS6016fRpRfxrExeVn2gbClQA99gQhnIcdhE= github.com/iancoleman/strcase v0.2.0 h1:05I4QRnGpI0m37iZQRuskXh+w77mr6Z41lwQzuHLwW0= From 2eb68e8bbd85277180991f68827a3b98be52ee4f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Wed, 23 Nov 2022 11:48:52 +0800 Subject: [PATCH 12/19] fix code --- util/execdetails/execdetails_test.go | 20 ++++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index b819a3f849f1d..6805f86295023 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -135,18 +135,18 @@ func mockExecutorExecutionSummary(TimeProcessedNs, NumProducedRows, NumIteration NumIterations: &NumIterations, XXX_unrecognized: nil} } -func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, ScanPacksCount, ScanRowsCount, SkipPacksCount, SkipRowsCount, roughSetIndexLoadTimeInNs, dmfileReadTimeInNs, createSnapshotTimeInNs uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { - tableScanContext := tipb.TableScanContext{ - ScanPacksCount: &ScanPacksCount, - ScanRowsCount: &ScanRowsCount, - SkipPacksCount: &SkipPacksCount, - SkipRowsCount: &SkipRowsCount, - RoughSetIndexLoadTimeInNs: &roughSetIndexLoadTimeInNs, - DmfileReadTimeInNs: &dmfileReadTimeInNs, - CreateSnapshotTimeInNs: &createSnapshotTimeInNs, +func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, totalScannedPacksInDmfile, totalSkippedPacksInDmfile, totalScannedRowsInDmfile, totalSkippedRowsInDmfile, totalRoughSetIndexLoadTimeInNs, totalDmfileReadTimeInNs, totalCreateSnapshotTimeInNs uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { + tiflashScanContext := tipb.TiFlashScanContext{ + TotalScannedPacksInDmfile: &totalScannedPacksInDmfile, + TotalSkippedPacksInDmfile: &totalSkippedPacksInDmfile, + TotalScannedRowsInDmfile: &totalSkippedRowsInDmfile, + TotalSkippedRowsInDmfile: &totalSkippedRowsInDmfile, + TotalRoughSetIndexLoadTimeInNs: &totalRoughSetIndexLoadTimeInNs, + TotalDmfileReadTimeInNs: &totalDmfileReadTimeInNs, + TotalCreateSnapshotTimeInNs: &totalCreateSnapshotTimeInNs, } return &tipb.ExecutorExecutionSummary{TimeProcessedNs: &TimeProcessedNs, NumProducedRows: &NumProducedRows, - NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_TableScanContext{TableScanContext: &tableScanContext}, XXX_unrecognized: nil} + NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_TiflashScanContext{TiflashScanContext: &tiflashScanContext}, XXX_unrecognized: nil} } func TestCopRuntimeStats(t *testing.T) { From 6886cd81dcd2311ea983b2e6724f8cbd83ee812e Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 24 Nov 2022 11:01:36 +0800 Subject: [PATCH 13/19] update dependency --- go.mod | 2 +- go.sum | 2 ++ 2 files changed, 3 insertions(+), 1 deletion(-) diff --git a/go.mod b/go.mod index 77b50f77d516c..c62dc388db32c 100644 --- a/go.mod +++ b/go.mod @@ -72,7 +72,7 @@ require ( github.com/pingcap/log v1.1.1-0.20221110065318-21a4942860b3 github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4 github.com/pingcap/tidb/parser v0.0.0-20211011031125-9b13dc409c5e - github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48 + github.com/pingcap/tipb v0.0.0-20221123081521-2fb828910813 github.com/pkg/errors v0.9.1 github.com/prometheus/client_golang v1.13.0 github.com/prometheus/client_model v0.2.0 diff --git a/go.sum b/go.sum index 37172a5d6a780..0ddadaaff12be 100644 --- a/go.sum +++ b/go.sum @@ -789,6 +789,8 @@ github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4 h1:HYbcxtnkN3s5tqr github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4/go.mod h1:sDCsM39cGiv2vwunZkaFA917vVkqDTGSPbbV7z4Oops= github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48 h1:CmDqkuJIil+pAOsY9smc+NO7we88EKumLgD6wHj3Zdg= github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= +github.com/pingcap/tipb v0.0.0-20221123081521-2fb828910813 h1:DbmCfCbcavo0JG+gSp0ySvv1ub/c/j3hsnYzyYPzONo= +github.com/pingcap/tipb v0.0.0-20221123081521-2fb828910813/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4 h1:49lOXmGaUpV9Fz3gd7TFZY106KVlPVa5jcYD1gaQf98= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4/go.mod h1:4OwLy04Bl9Ef3GJJCoec+30X3LQs/0/m4HFRt/2LUSA= github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= From 524b0089ceb136b56554a00b66c59d6a989c7837 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 24 Nov 2022 11:20:05 +0800 Subject: [PATCH 14/19] update format --- util/execdetails/execdetails.go | 54 +++++++++++++++------------- util/execdetails/execdetails_test.go | 30 ++++++++-------- 2 files changed, 44 insertions(+), 40 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 2cc1b6f494fe1..fd79b780dc271 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -326,7 +326,7 @@ type basicCopRuntimeStats struct { // String implements the RuntimeStats interface. func (e *basicCopRuntimeStats) String() string { if e.storeType == "tiflash" { - return fmt.Sprintf("time:%v, loops:%d, threads:%d, tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_dmfile_read_time: %dms}, total_create_snapshot_time: %dms}", FormatDuration(time.Duration(e.consume)), e.loop, e.threads, e.tiflashScanContext.totalScannedPacksInDmfile, e.tiflashScanContext.totalSkippedPacksInDmfile, e.tiflashScanContext.totalScannedRowsInDmfile, e.tiflashScanContext.totalSkippedRowsInDmfile, e.tiflashScanContext.totalRoughSetIndexLoadTimeInNs/1000000, e.tiflashScanContext.totalDmfileReadTimeInNs/1000000, e.tiflashScanContext.totalCreateSnapshotTimeInNs/1000000) + return fmt.Sprintf("time:%v, loops:%d, threads:%d, ", FormatDuration(time.Duration(e.consume)), e.loop, e.threads) + e.BasicRuntimeStats.tiflashScanContext.String() } return fmt.Sprintf("time:%v, loops:%d", FormatDuration(time.Duration(e.consume)), e.loop) } @@ -381,13 +381,13 @@ func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.Execu consume: int64(*summary.TimeProcessedNs), rows: int64(*summary.NumProducedRows), tiflashScanContext: &TiFlashScanContext{ - totalScannedPacksInDmfile: summary.GetTiflashScanContext().GetTotalScannedPacksInDmfile(), - totalSkippedPacksInDmfile: summary.GetTiflashScanContext().GetTotalSkippedPacksInDmfile(), - totalScannedRowsInDmfile: summary.GetTiflashScanContext().GetTotalScannedRowsInDmfile(), - totalSkippedRowsInDmfile: summary.GetTiflashScanContext().GetTotalSkippedRowsInDmfile(), - totalRoughSetIndexLoadTimeInNs: summary.GetTiflashScanContext().GetTotalRoughSetIndexLoadTimeInNs(), - totalDmfileReadTimeInNs: summary.GetTiflashScanContext().GetTotalDmfileReadTimeInNs(), - totalCreateSnapshotTimeInNs: summary.GetTiflashScanContext().GetTotalCreateSnapshotTimeInNs()}}, + totalDmfileScannedPacks: summary.GetTiflashScanContext().GetTotalDmfileScannedPacks(), + totalDmfileSkippedPacks: summary.GetTiflashScanContext().GetTotalDmfileSkippedPacks(), + totalDmfileScannedRows: summary.GetTiflashScanContext().GetTotalDmfileScannedRows(), + totalDmfileSkippedRows: summary.GetTiflashScanContext().GetTotalDmfileSkippedRows(), + totalDmfileRoughSetIndexLoadTimeMs: summary.GetTiflashScanContext().GetTotalDmfileRoughSetIndexLoadTimeMs(), + totalDmfileReadTimeMs: summary.GetTiflashScanContext().GetTotalDmfileReadTimeMs(), + totalCreateSnapshotTimeMs: summary.GetTiflashScanContext().GetTotalCreateSnapshotTimeMs()}}, threads: int32(summary.GetConcurrency()), storeType: crs.storeType}) } @@ -434,7 +434,7 @@ func (crs *CopRuntimeStats) String() string { if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) if !totalTiFlashScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_dmfile_read_time: %dms}, total_create_snapshot_time: %dms}", totalTiFlashScanContext.totalScannedPacksInDmfile, totalTiFlashScanContext.totalSkippedPacksInDmfile, totalTiFlashScanContext.totalScannedRowsInDmfile, totalTiFlashScanContext.totalSkippedRowsInDmfile, totalTiFlashScanContext.totalRoughSetIndexLoadTimeInNs/1000000, totalTiFlashScanContext.totalDmfileReadTimeInNs/1000000, totalTiFlashScanContext.totalCreateSnapshotTimeInNs/1000000)) + buf.WriteString(", " + totalTiFlashScanContext.String()) } } else { buf.WriteString("}") @@ -448,7 +448,7 @@ func (crs *CopRuntimeStats) String() string { if isTiFlashCop { buf.WriteString(fmt.Sprintf(", threads:%d}", totalThreads)) if !totalTiFlashScanContext.Empty() { - buf.WriteString(fmt.Sprintf(", tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_dmfile_read_time: %dms}, total_create_snapshot_time: %dms}", totalTiFlashScanContext.totalScannedPacksInDmfile, totalTiFlashScanContext.totalSkippedPacksInDmfile, totalTiFlashScanContext.totalScannedRowsInDmfile, totalTiFlashScanContext.totalSkippedRowsInDmfile, totalTiFlashScanContext.totalRoughSetIndexLoadTimeInNs/1000000, totalTiFlashScanContext.totalDmfileReadTimeInNs/1000000, totalTiFlashScanContext.totalCreateSnapshotTimeInNs/1000000)) + buf.WriteString(", " + totalTiFlashScanContext.String()) } } else { buf.WriteString("}") @@ -509,29 +509,33 @@ type RuntimeStats interface { // TiFlashScanContext is used to express the table scan information in tiflash type TiFlashScanContext struct { - totalScannedPacksInDmfile uint64 - totalScannedRowsInDmfile uint64 - totalSkippedPacksInDmfile uint64 - totalSkippedRowsInDmfile uint64 - totalRoughSetIndexLoadTimeInNs uint64 - totalDmfileReadTimeInNs uint64 - totalCreateSnapshotTimeInNs uint64 + totalDmfileScannedPacks uint64 + totalDmfileScannedRows uint64 + totalDmfileSkippedPacks uint64 + totalDmfileSkippedRows uint64 + totalDmfileRoughSetIndexLoadTimeMs uint64 + totalDmfileReadTimeMs uint64 + totalCreateSnapshotTimeMs uint64 +} + +func (context *TiFlashScanContext) String() string { + return fmt.Sprintf("tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_read_time: %dms}, total_create_snapshot_time: %dms}", context.totalDmfileScannedPacks, context.totalDmfileSkippedPacks, context.totalDmfileScannedRows, context.totalDmfileSkippedRows, context.totalDmfileRoughSetIndexLoadTimeMs, context.totalDmfileReadTimeMs, context.totalCreateSnapshotTimeMs) } // Merge make sum to merge the information in TiFlashScanContext func (context *TiFlashScanContext) Merge(other *TiFlashScanContext) { - context.totalScannedPacksInDmfile += other.totalScannedPacksInDmfile - context.totalScannedRowsInDmfile += other.totalScannedRowsInDmfile - context.totalSkippedPacksInDmfile += other.totalSkippedPacksInDmfile - context.totalSkippedRowsInDmfile += other.totalSkippedRowsInDmfile - context.totalRoughSetIndexLoadTimeInNs += other.totalRoughSetIndexLoadTimeInNs - context.totalDmfileReadTimeInNs += other.totalDmfileReadTimeInNs - context.totalCreateSnapshotTimeInNs += other.totalCreateSnapshotTimeInNs + context.totalDmfileScannedPacks += other.totalDmfileScannedPacks + context.totalDmfileScannedRows += other.totalDmfileScannedRows + context.totalDmfileSkippedPacks += other.totalDmfileSkippedPacks + context.totalDmfileSkippedRows += other.totalDmfileSkippedRows + context.totalDmfileRoughSetIndexLoadTimeMs += other.totalDmfileRoughSetIndexLoadTimeMs + context.totalDmfileReadTimeMs += other.totalDmfileReadTimeMs + context.totalCreateSnapshotTimeMs += other.totalCreateSnapshotTimeMs } // Empty check whether TiFlashScanContext is Empty, if scan no pack and skip no pack, we regard it as empty func (context *TiFlashScanContext) Empty() bool { - res := (context.totalScannedPacksInDmfile == 0 && context.totalSkippedPacksInDmfile == 0) + res := (context.totalDmfileScannedPacks == 0 && context.totalDmfileSkippedPacks == 0) return res } diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index 6805f86295023..9b6b8bdc3c5ae 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -135,15 +135,15 @@ func mockExecutorExecutionSummary(TimeProcessedNs, NumProducedRows, NumIteration NumIterations: &NumIterations, XXX_unrecognized: nil} } -func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, totalScannedPacksInDmfile, totalSkippedPacksInDmfile, totalScannedRowsInDmfile, totalSkippedRowsInDmfile, totalRoughSetIndexLoadTimeInNs, totalDmfileReadTimeInNs, totalCreateSnapshotTimeInNs uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { +func mockExecutorExecutionSummaryForTiFlash(TimeProcessedNs, NumProducedRows, NumIterations, Concurrency, totalDmfileScannedPacks, totalDmfileScannedRows, totalDmfileSkippedPacks, totalDmfileSkippedRows, totalDmfileRoughSetIndexLoadTimeMs, totalDmfileReadTimeMs, totalCreateSnapshotTimeMs uint64, ExecutorID string) *tipb.ExecutorExecutionSummary { tiflashScanContext := tipb.TiFlashScanContext{ - TotalScannedPacksInDmfile: &totalScannedPacksInDmfile, - TotalSkippedPacksInDmfile: &totalSkippedPacksInDmfile, - TotalScannedRowsInDmfile: &totalSkippedRowsInDmfile, - TotalSkippedRowsInDmfile: &totalSkippedRowsInDmfile, - TotalRoughSetIndexLoadTimeInNs: &totalRoughSetIndexLoadTimeInNs, - TotalDmfileReadTimeInNs: &totalDmfileReadTimeInNs, - TotalCreateSnapshotTimeInNs: &totalCreateSnapshotTimeInNs, + TotalDmfileScannedPacks: &totalDmfileScannedPacks, + TotalDmfileSkippedPacks: &totalDmfileSkippedPacks, + TotalDmfileScannedRows: &totalDmfileScannedRows, + TotalDmfileSkippedRows: &totalDmfileSkippedRows, + TotalDmfileRoughSetIndexLoadTimeMs: &totalDmfileRoughSetIndexLoadTimeMs, + TotalDmfileReadTimeMs: &totalDmfileReadTimeMs, + TotalCreateSnapshotTimeMs: &totalCreateSnapshotTimeMs, } return &tipb.ExecutorExecutionSummary{TimeProcessedNs: &TimeProcessedNs, NumProducedRows: &NumProducedRows, NumIterations: &NumIterations, Concurrency: &Concurrency, ExecutorId: &ExecutorID, DetailInfo: &tipb.ExecutorExecutionSummary_TiflashScanContext{TiflashScanContext: &tiflashScanContext}, XXX_unrecognized: nil} @@ -206,10 +206,10 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { tableScanID := 1 aggID := 2 tableReaderID := 3 - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, 15000000, 200000000, 40000000, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, 0, 2000000, 0, "tablescan_"+strconv.Itoa(tableScanID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, 60000000, 1000000000, 20000000, "aggregation_"+strconv.Itoa(aggID))) - stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, 40000000, 2000000000, 30000000, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(1, 1, 1, 1, 1, 8192, 0, 0, 15, 200, 40, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(aggID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(2, 2, 2, 1, 0, 0, 0, 0, 0, 2, 0, "tablescan_"+strconv.Itoa(tableScanID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.8", mockExecutorExecutionSummaryForTiFlash(3, 3, 3, 1, 2, 12000, 1, 6000, 60, 1000, 20, "aggregation_"+strconv.Itoa(aggID))) + stats.RecordOneCopTask(tableScanID, "tiflash", "8.8.8.9", mockExecutorExecutionSummaryForTiFlash(4, 4, 4, 1, 1, 8192, 10, 80000, 40, 2000, 30, "aggregation_"+strconv.Itoa(aggID))) scanDetail := &util.ScanDetail{ TotalKeys: 10, ProcessedKeys: 10, @@ -223,15 +223,15 @@ func TestCopRuntimeStatsForTiFlash(t *testing.T) { require.True(t, stats.ExistsCopStats(tableScanID)) cop := stats.GetOrCreateCopStats(tableScanID, "tiflash") - require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, tiflash_scan:{dmfile:{total_scanned_packs:1, total_skipped_packs:0, total_scanned_rows:8192, total_skipped_rows:0, total_rough_set_index_load_time: 15ms, total_dmfile_read_time: 202ms}, create_snapshot_time: 40ms}", cop.String()) + require.Equal(t, "tiflash_task:{proc max:2ns, min:1ns, avg: 1ns, p80:2ns, p95:2ns, iters:3, tasks:2, threads:2}, tiflash_scan:{dmfile:{total_scanned_packs:1, total_skipped_packs:0, total_scanned_rows:8192, total_skipped_rows:0, total_rough_set_index_load_time: 15ms, total_read_time: 202ms}, total_create_snapshot_time: 40ms}", cop.String()) copStats := cop.stats["8.8.8.8"] require.NotNil(t, copStats) copStats[0].SetRowNum(10) copStats[0].Record(time.Second, 10) - require.Equal(t, "time:1s, loops:2, threads:1, tiflash_scan:{dmfile:{total_scanned_packs:1, total_skipped_packs:0, total_scanned_rows:8192, total_skipped_rows:0, total_rough_set_index_load_time: 15ms, total_dmfile_read_time: 200ms}, create_snapshot_time: 40ms}", copStats[0].String()) - expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, tiflash_scan:{dmfile:{total_scanned_packs:3, total_skipped_packs:11, total_scanned_rows:20192, total_skipped_rows:86000, total_rough_set_index_load_time: 100ms, total_dmfile_read_time: 3000ms}, create_snapshot_time: 50ms}" + require.Equal(t, "time:1s, loops:2, threads:1, tiflash_scan:{dmfile:{total_scanned_packs:1, total_skipped_packs:0, total_scanned_rows:8192, total_skipped_rows:0, total_rough_set_index_load_time: 15ms, total_read_time: 200ms}, total_create_snapshot_time: 40ms}", copStats[0].String()) + expected := "tiflash_task:{proc max:4ns, min:3ns, avg: 3ns, p80:4ns, p95:4ns, iters:7, tasks:2, threads:2}, tiflash_scan:{dmfile:{total_scanned_packs:3, total_skipped_packs:11, total_scanned_rows:20192, total_skipped_rows:86000, total_rough_set_index_load_time: 100ms, total_read_time: 3000ms}, total_create_snapshot_time: 50ms}" require.Equal(t, expected, stats.GetOrCreateCopStats(aggID, "tiflash").String()) rootStats := stats.GetRootStats(tableReaderID) From 9b0739b8843ec10ee8b1dcaa4a00b938e4d0d98e Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 24 Nov 2022 11:23:33 +0800 Subject: [PATCH 15/19] update bzl --- DEPS.bzl | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/DEPS.bzl b/DEPS.bzl index bcc8b8bebf27d..99e8e7005021d 100644 --- a/DEPS.bzl +++ b/DEPS.bzl @@ -2936,8 +2936,8 @@ def go_deps(): name = "com_github_pingcap_tipb", build_file_proto_mode = "disable_global", importpath = "github.com/pingcap/tipb", - sum = "h1:CmDqkuJIil+pAOsY9smc+NO7we88EKumLgD6wHj3Zdg=", - version = "v0.0.0-20221123024159-8765d4977a48", + sum = "h1:DbmCfCbcavo0JG+gSp0ySvv1ub/c/j3hsnYzyYPzONo=", + version = "v0.0.0-20221123081521-2fb828910813", ) go_repository( name = "com_github_pkg_browser", From db831621a1bd7a4bd5ac61782d1c94cd1930bf4f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 24 Nov 2022 11:30:19 +0800 Subject: [PATCH 16/19] update go.sum --- go.sum | 2 -- 1 file changed, 2 deletions(-) diff --git a/go.sum b/go.sum index 22401d6574dcf..d37768c1493aa 100644 --- a/go.sum +++ b/go.sum @@ -788,8 +788,6 @@ github.com/pingcap/log v1.1.1-0.20221116035753-734d527bc87c h1:crhkw6DD+07Bg1wYh github.com/pingcap/log v1.1.1-0.20221116035753-734d527bc87c/go.mod h1:DWQW5jICDR7UJh4HtxXSM20Churx4CQL0fwL/SoOSA4= github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4 h1:HYbcxtnkN3s5tqrZ/z3eJS4j3Db8wMphEm1q10lY/TM= github.com/pingcap/sysutil v0.0.0-20220114020952-ea68d2dbf5b4/go.mod h1:sDCsM39cGiv2vwunZkaFA917vVkqDTGSPbbV7z4Oops= -github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48 h1:CmDqkuJIil+pAOsY9smc+NO7we88EKumLgD6wHj3Zdg= -github.com/pingcap/tipb v0.0.0-20221123024159-8765d4977a48/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/pingcap/tipb v0.0.0-20221123081521-2fb828910813 h1:DbmCfCbcavo0JG+gSp0ySvv1ub/c/j3hsnYzyYPzONo= github.com/pingcap/tipb v0.0.0-20221123081521-2fb828910813/go.mod h1:A7mrd7WHBl1o63LE2bIBGEJMTNWXqhgmYiOvMLxozfs= github.com/pkg/browser v0.0.0-20180916011732-0a3d74bf9ce4 h1:49lOXmGaUpV9Fz3gd7TFZY106KVlPVa5jcYD1gaQf98= From 140d7290d037983dda708b537164388e2bbd496f Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 24 Nov 2022 12:59:05 +0800 Subject: [PATCH 17/19] update code --- util/execdetails/execdetails.go | 18 ++++++++++++++++-- 1 file changed, 16 insertions(+), 2 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index fd79b780dc271..0264ed3349ec7 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -333,8 +333,9 @@ func (e *basicCopRuntimeStats) String() string { // Clone implements the RuntimeStats interface. func (e *basicCopRuntimeStats) Clone() RuntimeStats { + tiflashScanContextClone := e.tiflashScanContext.Clone() return &basicCopRuntimeStats{ - BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tiflashScanContext: e.tiflashScanContext}, + BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tiflashScanContext: &tiflashScanContextClone}, threads: e.threads, storeType: e.storeType, } @@ -518,6 +519,18 @@ type TiFlashScanContext struct { totalCreateSnapshotTimeMs uint64 } +// Clone implements the deep copy of * TiFlashshScanContext +func (context *TiFlashScanContext) Clone() TiFlashScanContext { + return TiFlashScanContext{ + totalDmfileScannedPacks: context.totalDmfileScannedPacks, + totalDmfileScannedRows: context.totalDmfileScannedRows, + totalDmfileSkippedPacks: context.totalDmfileSkippedPacks, + totalDmfileSkippedRows: context.totalDmfileSkippedRows, + totalDmfileRoughSetIndexLoadTimeMs: context.totalDmfileRoughSetIndexLoadTimeMs, + totalDmfileReadTimeMs: context.totalDmfileReadTimeMs, + totalCreateSnapshotTimeMs: context.totalCreateSnapshotTimeMs, + } +} func (context *TiFlashScanContext) String() string { return fmt.Sprintf("tiflash_scan:{dmfile:{total_scanned_packs:%d, total_skipped_packs:%d, total_scanned_rows:%d, total_skipped_rows:%d, total_rough_set_index_load_time: %dms, total_read_time: %dms}, total_create_snapshot_time: %dms}", context.totalDmfileScannedPacks, context.totalDmfileSkippedPacks, context.totalDmfileScannedRows, context.totalDmfileSkippedRows, context.totalDmfileRoughSetIndexLoadTimeMs, context.totalDmfileReadTimeMs, context.totalCreateSnapshotTimeMs) } @@ -558,11 +571,12 @@ func (e *BasicRuntimeStats) GetActRows() int64 { // Clone implements the RuntimeStats interface. func (e *BasicRuntimeStats) Clone() RuntimeStats { + tiflashScanContextClone := e.tiflashScanContext.Clone() return &BasicRuntimeStats{ loop: e.loop, consume: e.consume, rows: e.rows, - tiflashScanContext: e.tiflashScanContext, + tiflashScanContext: &tiflashScanContextClone, } } From 0a86ff33531f7c4d62badbfd7e62e303899ca7c4 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Thu, 24 Nov 2022 13:23:43 +0800 Subject: [PATCH 18/19] change code --- util/execdetails/execdetails.go | 12 +++++------- util/execdetails/execdetails_test.go | 4 ++-- 2 files changed, 7 insertions(+), 9 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 0264ed3349ec7..61b948bd3b9af 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -333,9 +333,8 @@ func (e *basicCopRuntimeStats) String() string { // Clone implements the RuntimeStats interface. func (e *basicCopRuntimeStats) Clone() RuntimeStats { - tiflashScanContextClone := e.tiflashScanContext.Clone() return &basicCopRuntimeStats{ - BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tiflashScanContext: &tiflashScanContextClone}, + BasicRuntimeStats: BasicRuntimeStats{loop: e.loop, consume: e.consume, rows: e.rows, tiflashScanContext: e.tiflashScanContext.Clone()}, threads: e.threads, storeType: e.storeType, } @@ -381,7 +380,7 @@ func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.Execu &basicCopRuntimeStats{BasicRuntimeStats: BasicRuntimeStats{loop: int32(*summary.NumIterations), consume: int64(*summary.TimeProcessedNs), rows: int64(*summary.NumProducedRows), - tiflashScanContext: &TiFlashScanContext{ + tiflashScanContext: TiFlashScanContext{ totalDmfileScannedPacks: summary.GetTiflashScanContext().GetTotalDmfileScannedPacks(), totalDmfileSkippedPacks: summary.GetTiflashScanContext().GetTotalDmfileSkippedPacks(), totalDmfileScannedRows: summary.GetTiflashScanContext().GetTotalDmfileScannedRows(), @@ -536,7 +535,7 @@ func (context *TiFlashScanContext) String() string { } // Merge make sum to merge the information in TiFlashScanContext -func (context *TiFlashScanContext) Merge(other *TiFlashScanContext) { +func (context *TiFlashScanContext) Merge(other TiFlashScanContext) { context.totalDmfileScannedPacks += other.totalDmfileScannedPacks context.totalDmfileScannedRows += other.totalDmfileScannedRows context.totalDmfileSkippedPacks += other.totalDmfileSkippedPacks @@ -561,7 +560,7 @@ type BasicRuntimeStats struct { // executor return row count. rows int64 // executor extra infos - tiflashScanContext *TiFlashScanContext + tiflashScanContext TiFlashScanContext } // GetActRows return total rows of BasicRuntimeStats. @@ -571,12 +570,11 @@ func (e *BasicRuntimeStats) GetActRows() int64 { // Clone implements the RuntimeStats interface. func (e *BasicRuntimeStats) Clone() RuntimeStats { - tiflashScanContextClone := e.tiflashScanContext.Clone() return &BasicRuntimeStats{ loop: e.loop, consume: e.consume, rows: e.rows, - tiflashScanContext: &tiflashScanContextClone, + tiflashScanContext: e.tiflashScanContext.Clone(), } } diff --git a/util/execdetails/execdetails_test.go b/util/execdetails/execdetails_test.go index 9b6b8bdc3c5ae..2740e10b321cb 100644 --- a/util/execdetails/execdetails_test.go +++ b/util/execdetails/execdetails_test.go @@ -385,8 +385,8 @@ func TestRuntimeStatsWithCommit(t *testing.T) { } func TestRootRuntimeStats(t *testing.T) { - basic1 := &BasicRuntimeStats{tiflashScanContext: &TiFlashScanContext{}} - basic2 := &BasicRuntimeStats{tiflashScanContext: &TiFlashScanContext{}} + basic1 := &BasicRuntimeStats{} + basic2 := &BasicRuntimeStats{} basic1.Record(time.Second, 20) basic2.Record(time.Second*2, 30) pid := 1 From 68372921f827a5f1b6dff3542f531ec281d814d1 Mon Sep 17 00:00:00 2001 From: hongyunyan <649330952@qq.com> Date: Mon, 28 Nov 2022 13:54:46 +0800 Subject: [PATCH 19/19] fix comments --- util/execdetails/execdetails.go | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 61b948bd3b9af..76e468cf38f50 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -403,9 +403,9 @@ func (crs *CopRuntimeStats) GetActRows() (totalRows int64) { } // MergeBasicStats traverses basicCopRuntimeStats in the CopRuntimeStats and collects some useful information. -func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalTiFlashScanContext *TiFlashScanContext) { +func (crs *CopRuntimeStats) MergeBasicStats() (procTimes []time.Duration, totalTime time.Duration, totalTasks, totalLoops, totalThreads int32, totalTiFlashScanContext TiFlashScanContext) { procTimes = make([]time.Duration, 0, 32) - totalTiFlashScanContext = &TiFlashScanContext{} + totalTiFlashScanContext = TiFlashScanContext{} for _, instanceStats := range crs.stats { for _, stat := range instanceStats { procTimes = append(procTimes, time.Duration(stat.consume)*time.Nanosecond)