Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

executor,util: write slow query to slow log no matter what log level (#30461) #30493

Merged
merged 5 commits into from
Feb 22, 2022
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 4 additions & 5 deletions executor/adapter.go
Original file line number Diff line number Diff line change
Expand Up @@ -1010,13 +1010,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())
Expand Down
8 changes: 6 additions & 2 deletions util/logutil/log_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand Down Expand Up @@ -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) {
Expand Down
3 changes: 3 additions & 0 deletions util/logutil/slow_query_logger.go
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,9 @@ func newSlowQueryLogger(cfg *LogConfig) (*zap.Logger, *log.ZapProperties, error)
// copy global config and override slow query log file
// if slow query log filename is empty, slow query 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 = log.FileLogConfig{
MaxSize: cfg.File.MaxSize,
Expand Down