diff --git a/pkg/sessionctx/variable/session_test.go b/pkg/sessionctx/variable/session_test.go index dcb732076e09b..6525af2f15462 100644 --- a/pkg/sessionctx/variable/session_test.go +++ b/pkg/sessionctx/variable/session_test.go @@ -289,6 +289,10 @@ func TestSlowLogFormat(t *testing.T) { sql := "select * from t;" _, digest := parser.NormalizeDigest(sql) ruDetails := util.NewRUDetailsWith(50.0, 100.56, 134*time.Millisecond) + seVar.DurationParse = 10 + seVar.DurationCompile = 10 + seVar.DurationOptimization = 10 + seVar.DurationWaitTS = 3 logItems := &variable.SlowQueryLogItems{ TxnTS: txnTS, KeyspaceName: "keyspace_a", @@ -296,10 +300,6 @@ func TestSlowLogFormat(t *testing.T) { SQL: sql, Digest: digest.String(), TimeTotal: costTime, - TimeParse: time.Duration(10), - TimeCompile: time.Duration(10), - TimeOptimize: time.Duration(10), - TimeWaitTS: time.Duration(3), IndexNames: "[t1:a,t2:b]", CopTasks: copTasks, ExecDetail: execDetail, @@ -324,9 +324,7 @@ func TestSlowLogFormat(t *testing.T) { IsWriteCacheTable: true, UsedStats: &stmtctx.UsedStatsInfo{}, ResourceGroupName: "rg1", - RRU: ruDetails.RRU(), - WRU: ruDetails.WRU(), - WaitRUDuration: ruDetails.RUWaitDuration(), + RUDetails: ruDetails, StorageKV: true, StorageMPP: false, } @@ -335,7 +333,6 @@ func TestSlowLogFormat(t *testing.T) { seVar.CurrentDBChanged = false logString := seVar.SlowLogFormat(logItems) require.Equal(t, resultFields+"\n"+sql, logString) - seVar.CurrentDBChanged = true logString = seVar.SlowLogFormat(logItems) require.Equal(t, resultFields+"\n"+"use test;\n"+sql, logString) @@ -392,8 +389,6 @@ func compareSlowLogItems(t *testing.T, expected, actual *variable.SlowQueryLogIt // Some fields are hard to mock, so we skip them. skipFields := []string{"KeyspaceID", "KeyspaceName", "TimeTotal", "Prepared", "ResultRows", "ResultRows", "Plan", "BinaryPlan", - "TimeParse", "TimeCompile", "TimeOptimize", "TimeWaitTS", - "RRU", "WRU", "WaitRUDuration", "UsedStats", "CopTasks", "RewriteInfo", "ExecRetryTime", "Warnings", "RUDetails", "MemMax", "DiskMax", "StorageKV"} skipFieldsFunc := func(res string, fields []string) bool { for _, f := range fields { diff --git a/pkg/sessionctx/variable/slow_log.go b/pkg/sessionctx/variable/slow_log.go index 0c3a857ba7dbb..98ed77aacb64d 100644 --- a/pkg/sessionctx/variable/slow_log.go +++ b/pkg/sessionctx/variable/slow_log.go @@ -239,10 +239,6 @@ type SlowQueryLogItems struct { SQL string Digest string TimeTotal time.Duration - TimeParse time.Duration - TimeCompile time.Duration - TimeOptimize time.Duration - TimeWaitTS time.Duration IndexNames string CopTasks *execdetails.CopTasksDetails ExecDetail *execdetails.ExecDetails @@ -270,9 +266,6 @@ type SlowQueryLogItems struct { Warnings []JSONSQLWarnForSlowLog ResourceGroupName string RUDetails *util.RUDetails - RRU float64 - WRU float64 - WaitRUDuration time.Duration CPUUsages ppcpuusage.CPUUsages StorageKV bool // query read from TiKV StorageMPP bool // query read from TiFlash @@ -349,8 +342,8 @@ func (s *SessionVars) SlowLogFormat(logItems *SlowQueryLogItems) string { buf.WriteString("\n") } writeSlowLogItem(&buf, SlowLogQueryTimeStr, strconv.FormatFloat(logItems.TimeTotal.Seconds(), 'f', -1, 64)) - writeSlowLogItem(&buf, SlowLogParseTimeStr, strconv.FormatFloat(logItems.TimeParse.Seconds(), 'f', -1, 64)) - writeSlowLogItem(&buf, SlowLogCompileTimeStr, strconv.FormatFloat(logItems.TimeCompile.Seconds(), 'f', -1, 64)) + writeSlowLogItem(&buf, SlowLogParseTimeStr, strconv.FormatFloat(s.DurationParse.Seconds(), 'f', -1, 64)) + writeSlowLogItem(&buf, SlowLogCompileTimeStr, strconv.FormatFloat(s.DurationCompile.Seconds(), 'f', -1, 64)) buf.WriteString(SlowLogRowPrefixStr + fmt.Sprintf("%v%v%v", SlowLogRewriteTimeStr, SlowLogSpaceMarkStr, strconv.FormatFloat(logItems.RewriteInfo.DurationRewrite.Seconds(), 'f', -1, 64))) @@ -360,8 +353,8 @@ func (s *SessionVars) SlowLogFormat(logItems *SlowQueryLogItems) string { } buf.WriteString("\n") - writeSlowLogItem(&buf, SlowLogOptimizeTimeStr, strconv.FormatFloat(logItems.TimeOptimize.Seconds(), 'f', -1, 64)) - writeSlowLogItem(&buf, SlowLogWaitTSTimeStr, strconv.FormatFloat(logItems.TimeWaitTS.Seconds(), 'f', -1, 64)) + writeSlowLogItem(&buf, SlowLogOptimizeTimeStr, strconv.FormatFloat(s.DurationOptimization.Seconds(), 'f', -1, 64)) + writeSlowLogItem(&buf, SlowLogWaitTSTimeStr, strconv.FormatFloat(s.DurationWaitTS.Seconds(), 'f', -1, 64)) if logItems.ExecDetail != nil { if execDetailStr := logItems.ExecDetail.String(); len(execDetailStr) > 0 { @@ -491,29 +484,17 @@ func (s *SessionVars) SlowLogFormat(logItems *SlowQueryLogItems) string { if logItems.ResourceGroupName != "" { writeSlowLogItem(&buf, SlowLogResourceGroup, logItems.ResourceGroupName) } - rru := logItems.RRU - wru := logItems.WRU - waitRUDuration := logItems.WaitRUDuration if logItems.RUDetails != nil { - if rru == 0.0 { - rru = logItems.RUDetails.RRU() + if rru := logItems.RUDetails.RRU(); rru > 0.0 { + writeSlowLogItem(&buf, SlowLogRRU, strconv.FormatFloat(rru, 'f', -1, 64)) } - if wru == 0.0 { - wru = logItems.RUDetails.WRU() + if wru := logItems.RUDetails.WRU(); wru > 0.0 { + writeSlowLogItem(&buf, SlowLogWRU, strconv.FormatFloat(wru, 'f', -1, 64)) } - if waitRUDuration == 0 { - waitRUDuration = logItems.RUDetails.RUWaitDuration() + if waitRUDuration := logItems.RUDetails.RUWaitDuration(); waitRUDuration > 0 { + writeSlowLogItem(&buf, SlowLogWaitRUDuration, strconv.FormatFloat(waitRUDuration.Seconds(), 'f', -1, 64)) } } - if rru > 0.0 { - writeSlowLogItem(&buf, SlowLogRRU, strconv.FormatFloat(rru, 'f', -1, 64)) - } - if wru > 0.0 { - writeSlowLogItem(&buf, SlowLogWRU, strconv.FormatFloat(wru, 'f', -1, 64)) - } - if waitRUDuration > 0 { - writeSlowLogItem(&buf, SlowLogWaitRUDuration, strconv.FormatFloat(waitRUDuration.Seconds(), 'f', -1, 64)) - } if logItems.CPUUsages.TidbCPUTime > time.Duration(0) { writeSlowLogItem(&buf, SlowLogTidbCPUUsageDuration, strconv.FormatFloat(logItems.CPUUsages.TidbCPUTime.Seconds(), 'f', -1, 64)) }