From d83ee8cfdad434d212d3229c0be24d9d81ef7ab3 Mon Sep 17 00:00:00 2001
From: TonsnakeLin <87681388+TonsnakeLin@users.noreply.github.com>
Date: Tue, 7 Dec 2021 20:49:56 +0800
Subject: [PATCH] executor,util: write slow query to slow log no matter what
 log level (#30461)

---
 executor/adapter.go               | 9 ++++-----
 util/logutil/log_test.go          | 8 ++++++--
 util/logutil/slow_query_logger.go | 3 +++
 3 files changed, 13 insertions(+), 7 deletions(-)

diff --git a/executor/adapter.go b/executor/adapter.go
index b8610ffd10f60..87f87a9712516 100644
--- a/executor/adapter.go
+++ b/executor/adapter.go
@@ -1022,13 +1022,12 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool, hasMoreResults bool) {
 	if _, ok := a.StmtNode.(*ast.CommitStmt); ok {
 		slowItems.PrevStmt = sessVars.PrevStmt.String()
 	}
+	slowLog := sessVars.SlowLogFormat(slowItems)
 	if trace.IsEnabled() {
-		trace.Log(a.GoCtx, "details", sessVars.SlowLogFormat(slowItems))
+		trace.Log(a.GoCtx, "details", slowLog)
 	}
-	if costTime < threshold {
-		logutil.SlowQueryLogger.Debug(sessVars.SlowLogFormat(slowItems))
-	} else {
-		logutil.SlowQueryLogger.Warn(sessVars.SlowLogFormat(slowItems))
+	logutil.SlowQueryLogger.Warn(slowLog)
+	if costTime >= threshold {
 		if sessVars.InRestrictedSQL {
 			totalQueryProcHistogramInternal.Observe(costTime.Seconds())
 			totalCopProcHistogramInternal.Observe(execDetail.TimeDetail.ProcessTime.Seconds())
diff --git a/util/logutil/log_test.go b/util/logutil/log_test.go
index d4f671f05dc92..713c34de77ab5 100644
--- a/util/logutil/log_test.go
+++ b/util/logutil/log_test.go
@@ -25,6 +25,7 @@ import (
 	"github.com/pingcap/log"
 	"github.com/stretchr/testify/require"
 	"go.uber.org/zap"
+	"go.uber.org/zap/zapcore"
 )
 
 func TestZapLoggerWithKeys(t *testing.T) {
@@ -115,13 +116,16 @@ func TestGrpcLoggerCreation(t *testing.T) {
 }
 
 func TestSlowQueryLoggerCreation(t *testing.T) {
-	level := "warn"
+	level := "Error"
 	conf := NewLogConfig(level, DefaultLogFormat, "", EmptyFileLogConfig, false)
 	_, prop, err := newSlowQueryLogger(conf)
 	// assert after init slow query logger, the original conf is not changed
 	require.Equal(t, conf.Level, level)
 	require.Nil(t, err)
-	require.Equal(t, prop.Level.String(), conf.Level)
+	// slow query logger doesn't use the level of the global log config, and the
+	// level should be less than WarnLevel which is used by it to log slow query.
+	require.NotEqual(t, conf.Level, prop.Level.String())
+	require.True(t, prop.Level.Level() <= zapcore.WarnLevel)
 }
 
 func TestGlobalLoggerReplace(t *testing.T) {
diff --git a/util/logutil/slow_query_logger.go b/util/logutil/slow_query_logger.go
index 2588c36131fd9..0c7fd10982314 100644
--- a/util/logutil/slow_query_logger.go
+++ b/util/logutil/slow_query_logger.go
@@ -32,6 +32,9 @@ func newSlowQueryLogger(cfg *LogConfig) (*zap.Logger, *log.ZapProperties, error)
 	// copy the global log config to slow log config
 	// if the filename of slow log config is empty, slow log will behave the same as global log.
 	sqConfig := cfg.Config
+	// level of the global log config doesn't affect the slow query logger which determines whether to
+	// log by execution duration.
+	sqConfig.Level = LogConfig{}.Level
 	if len(cfg.SlowQueryFile) != 0 {
 		sqConfig.File = cfg.File
 		sqConfig.File.Filename = cfg.SlowQueryFile