From c11ab16397eec8e93d25003b325dd28698187d00 Mon Sep 17 00:00:00 2001 From: mengxin9014 Date: Sun, 13 Nov 2022 00:01:03 +0800 Subject: [PATCH 1/7] Revert "util: add lock for MergeBasicStats (#38998)" This reverts commit d970c9bf480823dbff523e368f31dfd93cdb5d27. --- util/execdetails/execdetails.go | 2 -- 1 file changed, 2 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 2c7103a7901fb..4c0670e93eb97 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -396,8 +396,6 @@ 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) { - crs.Lock() - defer crs.Unlock() procTimes = make([]time.Duration, 0, 32) for _, instanceStats := range crs.stats { for _, stat := range instanceStats { From 9eb5f3757acfc2d3627a2fa4c5c70cc26536e61a Mon Sep 17 00:00:00 2001 From: mengxin9014 Date: Sun, 13 Nov 2022 00:01:48 +0800 Subject: [PATCH 2/7] Revert "util: fix panic cause by concurrent map iteration and write in memory usage alarm (#38729)" This reverts commit ba175c47cfd5b2367fcca28613547dcbb340292d. --- planner/core/common_plans.go | 4 +-- util/execdetails/execdetails.go | 44 +++++++++++++++++---------------- util/memory/tracker.go | 14 ----------- 3 files changed, 25 insertions(+), 37 deletions(-) diff --git a/planner/core/common_plans.go b/planner/core/common_plans.go index 38dfcca1e2967..688e9e6531e18 100644 --- a/planner/core/common_plans.go +++ b/planner/core/common_plans.go @@ -883,8 +883,8 @@ func getRuntimeInfo(ctx sessionctx.Context, p Plan, runtimeStatsColl *execdetail if runtimeStatsColl != nil && runtimeStatsColl.ExistsCopStats(explainID) { copStats = runtimeStatsColl.GetCopStats(explainID) } - memTracker = ctx.GetSessionVars().StmtCtx.MemTracker.SearchTrackerWithLock(p.ID()) - diskTracker = ctx.GetSessionVars().StmtCtx.DiskTracker.SearchTrackerWithLock(p.ID()) + memTracker = ctx.GetSessionVars().StmtCtx.MemTracker.SearchTrackerWithoutLock(p.ID()) + diskTracker = ctx.GetSessionVars().StmtCtx.DiskTracker.SearchTrackerWithoutLock(p.ID()) return } diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 4c0670e93eb97..2d483e167df61 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -32,17 +32,17 @@ import ( // ExecDetails contains execution detail information. type ExecDetails struct { - CommitDetail *util.CommitDetails - LockKeysDetail *util.LockKeysDetails - ScanDetail *util.ScanDetail - BackoffSleep map[string]time.Duration - BackoffTimes map[string]int CalleeAddress string - TimeDetail util.TimeDetail - RequestCount int CopTime time.Duration BackoffTime time.Duration LockKeysDuration time.Duration + BackoffSleep map[string]time.Duration + BackoffTimes map[string]int + RequestCount int + CommitDetail *util.CommitDetails + LockKeysDetail *util.LockKeysDetails + ScanDetail *util.ScanDetail + TimeDetail util.TimeDetail } type stmtExecDetailKeyType struct{} @@ -318,9 +318,9 @@ func (d ExecDetails) ToZapFields() (fields []zap.Field) { } type basicCopRuntimeStats struct { - storeType string BasicRuntimeStats - threads int32 + threads int32 + storeType string } // String implements the RuntimeStats interface. @@ -359,6 +359,8 @@ func (*basicCopRuntimeStats) Tp() int { // CopRuntimeStats collects cop tasks' execution info. type CopRuntimeStats struct { + sync.Mutex + // stats stores the runtime statistics of coprocessor tasks. // The key of the map is the tikv-server address. Because a tikv-server can // have many region leaders, several coprocessor tasks can be sent to the @@ -368,30 +370,28 @@ type CopRuntimeStats struct { scanDetail *util.ScanDetail // do not use kv.StoreType because it will meet cycle import error storeType string - // count CopRuntimeStats total rows - totalRows int64 - sync.Mutex } // RecordOneCopTask records a specific cop tasks's execution detail. func (crs *CopRuntimeStats) RecordOneCopTask(address string, summary *tipb.ExecutorExecutionSummary) { crs.Lock() defer crs.Unlock() - currentRows := int64(*summary.NumProducedRows) - crs.totalRows += currentRows crs.stats[address] = append(crs.stats[address], &basicCopRuntimeStats{BasicRuntimeStats: BasicRuntimeStats{loop: int32(*summary.NumIterations), consume: int64(*summary.TimeProcessedNs), - rows: currentRows}, + rows: int64(*summary.NumProducedRows)}, threads: int32(summary.GetConcurrency()), storeType: crs.storeType}) } // GetActRows return total rows of CopRuntimeStats. func (crs *CopRuntimeStats) GetActRows() (totalRows int64) { - crs.Lock() - defer crs.Unlock() - return crs.totalRows + for _, instanceStats := range crs.stats { + for _, stat := range instanceStats { + totalRows += stat.rows + } + } + return totalRows } // MergeBasicStats traverses basicCopRuntimeStats in the CopRuntimeStats and collects some useful information. @@ -635,9 +635,9 @@ func (e *BasicRuntimeStats) GetTime() int64 { // RuntimeStatsColl collects executors's execution info. type RuntimeStatsColl struct { + mu sync.Mutex rootStats map[int]*RootRuntimeStats copStats map[int]*CopRuntimeStats - mu sync.Mutex } // NewRuntimeStatsColl creates new executor collector. @@ -786,8 +786,10 @@ func NewConcurrencyInfo(name string, num int) *ConcurrencyInfo { // RuntimeStatsWithConcurrencyInfo is the BasicRuntimeStats with ConcurrencyInfo. type RuntimeStatsWithConcurrencyInfo struct { - concurrency []*ConcurrencyInfo + // protect concurrency sync.Mutex + // executor concurrency information + concurrency []*ConcurrencyInfo } // Tp implements the RuntimeStats interface. @@ -838,8 +840,8 @@ func (*RuntimeStatsWithConcurrencyInfo) Merge(RuntimeStats) {} // RuntimeStatsWithCommit is the RuntimeStats with commit detail. type RuntimeStatsWithCommit struct { Commit *util.CommitDetails - LockKeys *util.LockKeysDetails TxnCnt int + LockKeys *util.LockKeysDetails } // Tp implements the RuntimeStats interface. diff --git a/util/memory/tracker.go b/util/memory/tracker.go index 6f4bad7713e5f..179aa66087497 100644 --- a/util/memory/tracker.go +++ b/util/memory/tracker.go @@ -573,20 +573,6 @@ func (t *Tracker) SearchTrackerWithoutLock(label int) *Tracker { return nil } -// SearchTrackerWithLock searches the specific tracker under this tracker with lock. -func (t *Tracker) SearchTrackerWithLock(label int) *Tracker { - t.mu.Lock() - defer t.mu.Unlock() - if t.label == label { - return t - } - children := t.mu.children[label] - if len(children) > 0 { - return children[0] - } - return nil -} - // SearchTrackerConsumedMoreThanNBytes searches the specific tracker that consumes more than NBytes. func (t *Tracker) SearchTrackerConsumedMoreThanNBytes(limit int64) (res []*Tracker) { t.mu.Lock() From 62e860a5d032441834b6a0c39340e5677ea78dd5 Mon Sep 17 00:00:00 2001 From: mengxin9014 Date: Sun, 13 Nov 2022 00:02:31 +0800 Subject: [PATCH 3/7] Revert "util: fix panic cause by nil plan in memeory usage alarm (#38727)" This reverts commit a151383acf66cb9eff1d7474140bac9f420d4ced. --- session/session.go | 6 ------ util/memoryusagealarm/memoryusagealarm.go | 2 +- util/processinfo.go | 1 - 3 files changed, 1 insertion(+), 8 deletions(-) diff --git a/session/session.go b/session/session.go index d2f4afd10b679..13110775bce64 100644 --- a/session/session.go +++ b/session/session.go @@ -1573,10 +1573,6 @@ func (s *session) SetProcessInfo(sql string, t time.Time, command byte, maxExecu if explain, ok := p.(*plannercore.Explain); ok && explain.Analyze && explain.TargetPlan != nil { p = explain.TargetPlan } - canExplainAnalyze := false - if _, ok := p.(plannercore.PhysicalPlan); ok { - canExplainAnalyze = true - } pi := util.ProcessInfo{ ID: s.sessionVars.ConnectionID, Port: s.sessionVars.Port, @@ -1597,7 +1593,6 @@ func (s *session) SetProcessInfo(sql string, t time.Time, command byte, maxExecu OOMAlarmVariablesInfo: s.getOomAlarmVariablesInfo(), MaxExecutionTime: maxExecutionTime, RedactSQL: s.sessionVars.EnableRedactLog, - CanExplainAnalyze: canExplainAnalyze, } oldPi := s.ShowProcess() if p == nil { @@ -1607,7 +1602,6 @@ func (s *session) SetProcessInfo(sql string, t time.Time, command byte, maxExecu pi.Plan = oldPi.Plan pi.PlanExplainRows = oldPi.PlanExplainRows pi.RuntimeStatsColl = oldPi.RuntimeStatsColl - _, pi.CanExplainAnalyze = pi.Plan.(plannercore.PhysicalPlan) } } // We set process info before building plan, so we extended execution time. diff --git a/util/memoryusagealarm/memoryusagealarm.go b/util/memoryusagealarm/memoryusagealarm.go index a5fa1be5e0d64..403c140f6915c 100644 --- a/util/memoryusagealarm/memoryusagealarm.go +++ b/util/memoryusagealarm/memoryusagealarm.go @@ -315,7 +315,7 @@ func (record *memoryUsageAlarm) recordSQL(sm util.SessionManager, recordDir stri processInfo := sm.ShowProcessList() pinfo := make([]*util.ProcessInfo, 0, len(processInfo)) for _, info := range processInfo { - if len(info.Info) != 0 && info.CanExplainAnalyze { + if len(info.Info) != 0 { pinfo = append(pinfo, info) } } diff --git a/util/processinfo.go b/util/processinfo.go index 270b4e6588163..a2f9648db488e 100644 --- a/util/processinfo.go +++ b/util/processinfo.go @@ -65,7 +65,6 @@ type ProcessInfo struct { Command byte ExceedExpensiveTimeThresh bool RedactSQL bool - CanExplainAnalyze bool } // ToRowForShow returns []interface{} for the row data of "SHOW [FULL] PROCESSLIST". From 0e48377d04b801521ffd1ff3d23274abec640a96 Mon Sep 17 00:00:00 2001 From: mengxin9014 Date: Sun, 13 Nov 2022 01:46:53 +0800 Subject: [PATCH 4/7] change record analyze to explain in OOM alarm --- planner/core/plan.go | 5 ----- session/session.go | 13 ------------- util/memoryusagealarm/memoryusagealarm.go | 10 +++++----- util/memoryusagealarm/memoryusagealarm_test.go | 12 ++++-------- util/processinfo.go | 1 - 5 files changed, 9 insertions(+), 32 deletions(-) diff --git a/planner/core/plan.go b/planner/core/plan.go index b8963fb281217..78d18c59ff7f0 100644 --- a/planner/core/plan.go +++ b/planner/core/plan.go @@ -881,11 +881,6 @@ func (p *basePlan) SCtx() sessionctx.Context { return p.ctx } -// SetSCtx Context implements Plan Set Context interface. -func (p *basePlan) SetSCtx(ctx sessionctx.Context) { - p.ctx = ctx -} - // buildPlanTrace implements Plan func (p *basePhysicalPlan) buildPlanTrace() *tracing.PlanTrace { planTrace := &tracing.PlanTrace{ID: p.ID(), TP: p.self.TP(), ExplainInfo: p.self.ExplainInfo()} diff --git a/session/session.go b/session/session.go index 13110775bce64..e248dd547c61f 100644 --- a/session/session.go +++ b/session/session.go @@ -85,7 +85,6 @@ import ( "github.com/pingcap/tidb/table/temptable" "github.com/pingcap/tidb/tablecodec" "github.com/pingcap/tidb/telemetry" - "github.com/pingcap/tidb/types" "github.com/pingcap/tidb/util" "github.com/pingcap/tidb/util/chunk" "github.com/pingcap/tidb/util/collate" @@ -1580,7 +1579,6 @@ func (s *session) SetProcessInfo(sql string, t time.Time, command byte, maxExecu Command: command, Plan: p, PlanExplainRows: plannercore.GetExplainRowsForPlan(p), - CurrentAnalyzeRows: s.getCurrentAnalyzePlan, RuntimeStatsColl: s.sessionVars.StmtCtx.RuntimeStatsColl, Time: t, State: s.Status(), @@ -1630,17 +1628,6 @@ func (s *session) getOomAlarmVariablesInfo() util.OOMAlarmVariablesInfo { } } -func (s *session) getCurrentAnalyzePlan(p interface{}, runtimeStatsColl *execdetails.RuntimeStatsColl) [][]string { - explain := &plannercore.Explain{ - TargetPlan: p.(plannercore.Plan), - Format: types.ExplainFormatROW, - Analyze: false, - RuntimeStatsColl: runtimeStatsColl, - } - explain.SetSCtx(s) - return plannercore.GetExplainAnalyzeRowsForPlan(explain) -} - func (s *session) SetDiskFullOpt(level kvrpcpb.DiskFullOpt) { s.diskFullOpt = level } diff --git a/util/memoryusagealarm/memoryusagealarm.go b/util/memoryusagealarm/memoryusagealarm.go index 403c140f6915c..882d8462ef60b 100644 --- a/util/memoryusagealarm/memoryusagealarm.go +++ b/util/memoryusagealarm/memoryusagealarm.go @@ -236,12 +236,12 @@ func (record *memoryUsageAlarm) tryRemoveRedundantRecords() { } } -func getCurrentAnalyzePlan(info *util.ProcessInfo) string { +func getPlanString(info *util.ProcessInfo) string { var buf strings.Builder - rows := info.CurrentAnalyzeRows(info.Plan, info.RuntimeStatsColl) - buf.WriteString(fmt.Sprintf("|%v|%v|%v|%v|%v|%v|%v|%v|%v|", "id", "estRows", "actRows", "task", "access object", "execution info", "operator info", "memory", "disk")) + rows := info.PlanExplainRows + buf.WriteString(fmt.Sprintf("|%v|%v|%v|%v|%v|", "id", "estRows", "task", "access object", "operator info")) for _, row := range rows { - buf.WriteString(fmt.Sprintf("\n|%v|%v|%v|%v|%v|%v|%v|%v|%v|", row[0], row[1], row[2], row[3], row[4], row[5], row[6], row[7], row[8])) + buf.WriteString(fmt.Sprintf("\n|%v|%v|%v|%v|%v|", row[0], row[1], row[2], row[3], row[4])) } return buf.String() } @@ -280,7 +280,7 @@ func (record *memoryUsageAlarm) getTop10SqlInfo(cmp func(i, j *util.ProcessInfo) fields = append(fields, zap.Int64("tidb_mem_quota_query", info.OOMAlarmVariablesInfo.SessionMemQuotaQuery)) fields = append(fields, zap.Int("tidb_analyze_version", info.OOMAlarmVariablesInfo.SessionAnalyzeVersion)) fields = append(fields, zap.Bool("tidb_enable_rate_limit_action", info.OOMAlarmVariablesInfo.SessionEnabledRateLimitAction)) - fields = append(fields, zap.String("current_analyze_plan", getCurrentAnalyzePlan(info))) + fields = append(fields, zap.String("current_analyze_plan", getPlanString(info))) for _, field := range fields { switch field.Type { case zapcore.StringType: diff --git a/util/memoryusagealarm/memoryusagealarm_test.go b/util/memoryusagealarm/memoryusagealarm_test.go index d98d3bb822475..f0b0af6bd99ec 100644 --- a/util/memoryusagealarm/memoryusagealarm_test.go +++ b/util/memoryusagealarm/memoryusagealarm_test.go @@ -21,7 +21,6 @@ import ( "github.com/pingcap/tidb/sessionctx/stmtctx" "github.com/pingcap/tidb/sessionctx/variable" "github.com/pingcap/tidb/util" - "github.com/pingcap/tidb/util/execdetails" "github.com/pingcap/tidb/util/memory" "github.com/stretchr/testify/assert" ) @@ -86,18 +85,18 @@ func TestGetTop10Sql(t *testing.T) { []time.Time{genTime(1234), genTime(123456), genTime(12)}, 3) actual := record.getTop10SqlInfoByMemoryUsage(processInfoList) - assert.Equal(t, "SQL 0: \ncost_time: 0s\ntxn_start_ts: 0\nmem_max: 87263523 Bytes (83.2 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 1: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 2: \ncost_time: 122222s\ntxn_start_ts: 0\nmem_max: 1000 Bytes (1000 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\n\n", + assert.Equal(t, "SQL 0: \ncost_time: 0s\ntxn_start_ts: 0\nmem_max: 87263523 Bytes (83.2 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 1: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 2: \ncost_time: 122222s\ntxn_start_ts: 0\nmem_max: 1000 Bytes (1000 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\n\n", actual.String()) actual = record.getTop10SqlInfoByCostTime(processInfoList) - assert.Equal(t, "SQL 0: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 1: \ncost_time: 122222s\ntxn_start_ts: 0\nmem_max: 1000 Bytes (1000 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 2: \ncost_time: 0s\ntxn_start_ts: 0\nmem_max: 87263523 Bytes (83.2 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\n\n", actual.String()) + assert.Equal(t, "SQL 0: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 1: \ncost_time: 122222s\ntxn_start_ts: 0\nmem_max: 1000 Bytes (1000 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 2: \ncost_time: 0s\ntxn_start_ts: 0\nmem_max: 87263523 Bytes (83.2 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\n\n", actual.String()) processInfoList = genMockProcessInfoList([]int64{1000, 87263523, 34223, 532355, 123225151, 231231515, 12312, 12515134234, 232, 12414, 15263236, 123123123, 15}, []time.Time{genTime(1234), genTime(123456), genTime(12), genTime(3241), genTime(12515), genTime(3215), genTime(61314), genTime(12234), genTime(1123), genTime(512), genTime(11111), genTime(22222), genTime(5512)}, 13) actual = record.getTop10SqlInfoByMemoryUsage(processInfoList) - assert.Equal(t, "SQL 0: \ncost_time: 111222s\ntxn_start_ts: 0\nmem_max: 12515134234 Bytes (11.7 GB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 1: \ncost_time: 120241s\ntxn_start_ts: 0\nmem_max: 231231515 Bytes (220.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 2: \ncost_time: 110941s\ntxn_start_ts: 0\nmem_max: 123225151 Bytes (117.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 3: \ncost_time: 101234s\ntxn_start_ts: 0\nmem_max: 123123123 Bytes (117.4 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 4: \ncost_time: 0s\ntxn_start_ts: 0\nmem_max: 87263523 Bytes (83.2 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 5: \ncost_time: 112345s\ntxn_start_ts: 0\nmem_max: 15263236 Bytes (14.6 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 6: \ncost_time: 120215s\ntxn_start_ts: 0\nmem_max: 532355 Bytes (519.9 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 7: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 8: \ncost_time: 122944s\ntxn_start_ts: 0\nmem_max: 12414 Bytes (12.1 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 9: \ncost_time: 62142s\ntxn_start_ts: 0\nmem_max: 12312 Bytes (12.0 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\n\n", actual.String()) + assert.Equal(t, "SQL 0: \ncost_time: 111222s\ntxn_start_ts: 0\nmem_max: 12515134234 Bytes (11.7 GB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 1: \ncost_time: 120241s\ntxn_start_ts: 0\nmem_max: 231231515 Bytes (220.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 2: \ncost_time: 110941s\ntxn_start_ts: 0\nmem_max: 123225151 Bytes (117.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 3: \ncost_time: 101234s\ntxn_start_ts: 0\nmem_max: 123123123 Bytes (117.4 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 4: \ncost_time: 0s\ntxn_start_ts: 0\nmem_max: 87263523 Bytes (83.2 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 5: \ncost_time: 112345s\ntxn_start_ts: 0\nmem_max: 15263236 Bytes (14.6 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 6: \ncost_time: 120215s\ntxn_start_ts: 0\nmem_max: 532355 Bytes (519.9 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 7: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 8: \ncost_time: 122944s\ntxn_start_ts: 0\nmem_max: 12414 Bytes (12.1 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 9: \ncost_time: 62142s\ntxn_start_ts: 0\nmem_max: 12312 Bytes (12.0 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\n\n", actual.String()) actual = record.getTop10SqlInfoByCostTime(processInfoList) - assert.Equal(t, "SQL 0: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 1: \ncost_time: 122944s\ntxn_start_ts: 0\nmem_max: 12414 Bytes (12.1 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 2: \ncost_time: 122333s\ntxn_start_ts: 0\nmem_max: 232 Bytes (232 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 3: \ncost_time: 122222s\ntxn_start_ts: 0\nmem_max: 1000 Bytes (1000 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 4: \ncost_time: 120241s\ntxn_start_ts: 0\nmem_max: 231231515 Bytes (220.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 5: \ncost_time: 120215s\ntxn_start_ts: 0\nmem_max: 532355 Bytes (519.9 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 6: \ncost_time: 117944s\ntxn_start_ts: 0\nmem_max: 15 Bytes (15 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 7: \ncost_time: 112345s\ntxn_start_ts: 0\nmem_max: 15263236 Bytes (14.6 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 8: \ncost_time: 111222s\ntxn_start_ts: 0\nmem_max: 12515134234 Bytes (11.7 GB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\nSQL 9: \ncost_time: 110941s\ntxn_start_ts: 0\nmem_max: 123225151 Bytes (117.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|actRows|task|access object|execution info|operator info|memory|disk|\n\n", actual.String()) + assert.Equal(t, "SQL 0: \ncost_time: 123444s\ntxn_start_ts: 0\nmem_max: 34223 Bytes (33.4 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 1: \ncost_time: 122944s\ntxn_start_ts: 0\nmem_max: 12414 Bytes (12.1 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 2: \ncost_time: 122333s\ntxn_start_ts: 0\nmem_max: 232 Bytes (232 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 3: \ncost_time: 122222s\ntxn_start_ts: 0\nmem_max: 1000 Bytes (1000 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 4: \ncost_time: 120241s\ntxn_start_ts: 0\nmem_max: 231231515 Bytes (220.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 5: \ncost_time: 120215s\ntxn_start_ts: 0\nmem_max: 532355 Bytes (519.9 KB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 6: \ncost_time: 117944s\ntxn_start_ts: 0\nmem_max: 15 Bytes (15 Bytes)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 7: \ncost_time: 112345s\ntxn_start_ts: 0\nmem_max: 15263236 Bytes (14.6 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 8: \ncost_time: 111222s\ntxn_start_ts: 0\nmem_max: 12515134234 Bytes (11.7 GB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\nSQL 9: \ncost_time: 110941s\ntxn_start_ts: 0\nmem_max: 123225151 Bytes (117.5 MB)\nsql: \ntidb_mem_oom_action: CANCEL\ntidb_server_memory_limit: 0\ntidb_mem_quota_query: 0\ntidb_analyze_version: 0\ntidb_enable_rate_limit_action: false\ncurrent_analyze_plan: |id|estRows|task|access object|operator info|\n\n", actual.String()) } func genMockProcessInfoList(memConsumeList []int64, startTimeList []time.Time, size int) []*util.ProcessInfo { @@ -111,9 +110,6 @@ func genMockProcessInfoList(memConsumeList []int64, startTimeList []time.Time, s StatsInfo: func(interface{}) map[string]uint64 { return map[string]uint64{} }, - CurrentAnalyzeRows: func(interface{}, *execdetails.RuntimeStatsColl) [][]string { - return [][]string{} - }, } processInfoList = append(processInfoList, &processInfo) } diff --git a/util/processinfo.go b/util/processinfo.go index a2f9648db488e..6e379e49a8fe7 100644 --- a/util/processinfo.go +++ b/util/processinfo.go @@ -43,7 +43,6 @@ type ProcessInfo struct { Time time.Time Plan interface{} StmtCtx *stmtctx.StatementContext - CurrentAnalyzeRows func(interface{}, *execdetails.RuntimeStatsColl) [][]string MemTracker *memory.Tracker DiskTracker *disk.Tracker StatsInfo func(interface{}) map[string]uint64 From 2f1d2ec5eba41bb8a37265dc6c121860d523139e Mon Sep 17 00:00:00 2001 From: mengxin9014 Date: Sun, 13 Nov 2022 09:44:21 +0800 Subject: [PATCH 5/7] pass bazel --- util/execdetails/execdetails.go | 33 ++++++++++++--------------------- 1 file changed, 12 insertions(+), 21 deletions(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 2d483e167df61..56aa7b7aef116 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -32,17 +32,17 @@ import ( // ExecDetails contains execution detail information. type ExecDetails struct { - CalleeAddress string - CopTime time.Duration - BackoffTime time.Duration - LockKeysDuration time.Duration BackoffSleep map[string]time.Duration BackoffTimes map[string]int - RequestCount int CommitDetail *util.CommitDetails LockKeysDetail *util.LockKeysDetails ScanDetail *util.ScanDetail + CalleeAddress string TimeDetail util.TimeDetail + CopTime time.Duration + BackoffTime time.Duration + LockKeysDuration time.Duration + RequestCount int } type stmtExecDetailKeyType struct{} @@ -318,9 +318,9 @@ func (d ExecDetails) ToZapFields() (fields []zap.Field) { } type basicCopRuntimeStats struct { - BasicRuntimeStats - threads int32 storeType string + BasicRuntimeStats + threads int32 } // String implements the RuntimeStats interface. @@ -359,17 +359,10 @@ func (*basicCopRuntimeStats) Tp() int { // CopRuntimeStats collects cop tasks' execution info. type CopRuntimeStats struct { - sync.Mutex - - // stats stores the runtime statistics of coprocessor tasks. - // The key of the map is the tikv-server address. Because a tikv-server can - // have many region leaders, several coprocessor tasks can be sent to the - // same tikv-server instance. We have to use a list to maintain all tasks - // executed on each instance. stats map[string][]*basicCopRuntimeStats scanDetail *util.ScanDetail - // do not use kv.StoreType because it will meet cycle import error - storeType string + storeType string + sync.Mutex } // RecordOneCopTask records a specific cop tasks's execution detail. @@ -635,9 +628,9 @@ func (e *BasicRuntimeStats) GetTime() int64 { // RuntimeStatsColl collects executors's execution info. type RuntimeStatsColl struct { - mu sync.Mutex rootStats map[int]*RootRuntimeStats copStats map[int]*CopRuntimeStats + mu sync.Mutex } // NewRuntimeStatsColl creates new executor collector. @@ -786,10 +779,8 @@ func NewConcurrencyInfo(name string, num int) *ConcurrencyInfo { // RuntimeStatsWithConcurrencyInfo is the BasicRuntimeStats with ConcurrencyInfo. type RuntimeStatsWithConcurrencyInfo struct { - // protect concurrency - sync.Mutex - // executor concurrency information concurrency []*ConcurrencyInfo + sync.Mutex } // Tp implements the RuntimeStats interface. @@ -840,8 +831,8 @@ func (*RuntimeStatsWithConcurrencyInfo) Merge(RuntimeStats) {} // RuntimeStatsWithCommit is the RuntimeStats with commit detail. type RuntimeStatsWithCommit struct { Commit *util.CommitDetails - TxnCnt int LockKeys *util.LockKeysDetails + TxnCnt int } // Tp implements the RuntimeStats interface. From 74036558b59f1dd5d2f8a6e4321ab4b55be23157 Mon Sep 17 00:00:00 2001 From: mengxin9014 Date: Sun, 13 Nov 2022 09:51:23 +0800 Subject: [PATCH 6/7] add comment --- util/execdetails/execdetails.go | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/util/execdetails/execdetails.go b/util/execdetails/execdetails.go index 56aa7b7aef116..c1c65499ec288 100644 --- a/util/execdetails/execdetails.go +++ b/util/execdetails/execdetails.go @@ -359,9 +359,15 @@ func (*basicCopRuntimeStats) Tp() int { // CopRuntimeStats collects cop tasks' execution info. type CopRuntimeStats struct { + // stats stores the runtime statistics of coprocessor tasks. + // The key of the map is the tikv-server address. Because a tikv-server can + // have many region leaders, several coprocessor tasks can be sent to the + // same tikv-server instance. We have to use a list to maintain all tasks + // executed on each instance. stats map[string][]*basicCopRuntimeStats scanDetail *util.ScanDetail - storeType string + // do not use kv.StoreType because it will meet cycle import error + storeType string sync.Mutex } @@ -779,7 +785,9 @@ func NewConcurrencyInfo(name string, num int) *ConcurrencyInfo { // RuntimeStatsWithConcurrencyInfo is the BasicRuntimeStats with ConcurrencyInfo. type RuntimeStatsWithConcurrencyInfo struct { + // executor concurrency information concurrency []*ConcurrencyInfo + // protect concurrency sync.Mutex } From f4daba4a7746139e13b37827599e6529becbeca4 Mon Sep 17 00:00:00 2001 From: Weizhen Wang Date: Sun, 13 Nov 2022 10:03:32 +0800 Subject: [PATCH 7/7] update bazel Signed-off-by: Weizhen Wang --- util/memoryusagealarm/BUILD.bazel | 1 - 1 file changed, 1 deletion(-) diff --git a/util/memoryusagealarm/BUILD.bazel b/util/memoryusagealarm/BUILD.bazel index c865183197d59..80d092d6e4723 100644 --- a/util/memoryusagealarm/BUILD.bazel +++ b/util/memoryusagealarm/BUILD.bazel @@ -28,7 +28,6 @@ go_test( "//sessionctx/stmtctx", "//sessionctx/variable", "//util", - "//util/execdetails", "//util/memory", "@com_github_stretchr_testify//assert", ],