From 6562b584a316f1537fdead59e4bfe11e285fd1e1 Mon Sep 17 00:00:00 2001 From: Jack Yu Date: Mon, 5 Nov 2018 14:54:07 +0800 Subject: [PATCH] *: add a variable tidb_slow_log_threshold to set the slow log threshold dynamically (#8094) --- config/config.go | 4 ++-- executor/adapter.go | 3 ++- executor/set_test.go | 7 +++++++ sessionctx/variable/session.go | 3 +++ sessionctx/variable/sysvar.go | 2 ++ sessionctx/variable/tidb_vars.go | 5 ++++- sessionctx/variable/varsutil.go | 4 +++- util/logutil/log.go | 2 ++ 8 files changed, 25 insertions(+), 5 deletions(-) diff --git a/config/config.go b/config/config.go index d4b4b0a003ed9..5b849a5fef110 100644 --- a/config/config.go +++ b/config/config.go @@ -87,7 +87,7 @@ type Log struct { File logutil.FileLogConfig `toml:"file" json:"file"` SlowQueryFile string `toml:"slow-query-file" json:"slow-query-file"` - SlowThreshold uint `toml:"slow-threshold" json:"slow-threshold"` + SlowThreshold uint64 `toml:"slow-threshold" json:"slow-threshold"` ExpensiveThreshold uint `toml:"expensive-threshold" json:"expensive-threshold"` QueryLogMaxLen uint `toml:"query-log-max-len" json:"query-log-max-len"` } @@ -273,7 +273,7 @@ var defaultConf = Config{ LogRotate: true, MaxSize: logutil.DefaultLogMaxSize, }, - SlowThreshold: 300, + SlowThreshold: logutil.DefaultSlowThreshold, ExpensiveThreshold: 10000, QueryLogMaxLen: 2048, }, diff --git a/executor/adapter.go b/executor/adapter.go index 0f7c73d9a83ee..95e76acdaadb1 100644 --- a/executor/adapter.go +++ b/executor/adapter.go @@ -17,6 +17,7 @@ import ( "fmt" "math" "strings" + "sync/atomic" "time" "github.com/pingcap/tidb/ast" @@ -341,7 +342,7 @@ func (a *ExecStmt) LogSlowQuery(txnTS uint64, succ bool) { } cfg := config.GetGlobalConfig() costTime := time.Since(a.StartTime) - threshold := time.Duration(cfg.Log.SlowThreshold) * time.Millisecond + threshold := time.Duration(atomic.LoadUint64(&cfg.Log.SlowThreshold)) * time.Millisecond if costTime < threshold && level < log.DebugLevel { return } diff --git a/executor/set_test.go b/executor/set_test.go index 3ef60edfb8ce6..bd6d0f9dc64cb 100644 --- a/executor/set_test.go +++ b/executor/set_test.go @@ -234,6 +234,13 @@ func (s *testSuite) TestSetVar(c *C) { tk.MustQuery(`select @@tidb_force_priority;`).Check(testkit.Rows("NO_PRIORITY")) _, err = tk.Exec(`set global tidb_force_priority = ""`) c.Assert(err, NotNil) + + tk.MustExec("set tidb_slow_log_threshold = 0") + tk.MustQuery("select @@session.tidb_slow_log_threshold;").Check(testkit.Rows("0")) + tk.MustExec("set tidb_slow_log_threshold = 1") + tk.MustQuery("select @@session.tidb_slow_log_threshold;").Check(testkit.Rows("1")) + _, err = tk.Exec("set global tidb_slow_log_threshold = 0") + c.Assert(err, NotNil) } func (s *testSuite) TestSetCharset(c *C) { diff --git a/sessionctx/variable/session.go b/sessionctx/variable/session.go index 94037bbef8242..89b1224109469 100644 --- a/sessionctx/variable/session.go +++ b/sessionctx/variable/session.go @@ -32,6 +32,7 @@ import ( "github.com/pingcap/tidb/types" "github.com/pingcap/tidb/util/auth" "github.com/pingcap/tidb/util/chunk" + "github.com/pingcap/tidb/util/logutil" "github.com/pingcap/tidb/util/timeutil" "github.com/pkg/errors" ) @@ -585,6 +586,8 @@ func (s *SessionVars) SetSystemVar(name string, val string) error { s.MemQuotaNestedLoopApply = tidbOptInt64(val, DefTiDBMemQuotaNestedLoopApply) case TiDBGeneralLog: atomic.StoreUint32(&ProcessGeneralLog, uint32(tidbOptPositiveInt32(val, DefTiDBGeneralLog))) + case TiDBSlowLogThreshold: + atomic.StoreUint64(&config.GetGlobalConfig().Log.SlowThreshold, uint64(tidbOptInt64(val, logutil.DefaultSlowThreshold))) case TiDBRetryLimit: s.RetryLimit = tidbOptInt64(val, DefTiDBRetryLimit) case TiDBDisableTxnAutoRetry: diff --git a/sessionctx/variable/sysvar.go b/sessionctx/variable/sysvar.go index f3a25e17db457..2ab0c4d9fed9d 100644 --- a/sessionctx/variable/sysvar.go +++ b/sessionctx/variable/sysvar.go @@ -22,6 +22,7 @@ import ( "github.com/pingcap/tidb/mysql" "github.com/pingcap/tidb/terror" "github.com/pingcap/tidb/util/charset" + "github.com/pingcap/tidb/util/logutil" ) // ScopeFlag is for system variable whether can be changed in global/session dynamically or not. @@ -660,6 +661,7 @@ var defaultSysVars = []*SysVar{ {ScopeSession, TiDBOptimizerSelectivityLevel, strconv.Itoa(DefTiDBOptimizerSelectivityLevel)}, /* The following variable is defined as session scope but is actually server scope. */ {ScopeSession, TiDBGeneralLog, strconv.Itoa(DefTiDBGeneralLog)}, + {ScopeSession, TiDBSlowLogThreshold, strconv.Itoa(logutil.DefaultSlowThreshold)}, {ScopeSession, TiDBConfig, ""}, {ScopeGlobal | ScopeSession, TiDBDDLReorgWorkerCount, strconv.Itoa(DefTiDBDDLReorgWorkerCount)}, {ScopeSession, TiDBDDLReorgPriority, "PRIORITY_LOW"}, diff --git a/sessionctx/variable/tidb_vars.go b/sessionctx/variable/tidb_vars.go index 3cb5314d07273..8b1ea4371c3d6 100644 --- a/sessionctx/variable/tidb_vars.go +++ b/sessionctx/variable/tidb_vars.go @@ -95,7 +95,10 @@ const ( // tidb_general_log is used to log every query in the server in info level. TiDBGeneralLog = "tidb_general_log" - // tidb_retry_limit is the maximun number of retries when committing a transaction. + // tidb_slow_log_threshold is used to set the slow log threshold in the server. + TiDBSlowLogThreshold = "tidb_slow_log_threshold" + + // tidb_retry_limit is the maximum number of retries when committing a transaction. TiDBRetryLimit = "tidb_retry_limit" // tidb_disable_txn_auto_retry disables transaction auto retry. diff --git a/sessionctx/variable/varsutil.go b/sessionctx/variable/varsutil.go index d956701cb358d..e8766de4fccc4 100644 --- a/sessionctx/variable/varsutil.go +++ b/sessionctx/variable/varsutil.go @@ -85,6 +85,8 @@ func GetSessionOnlySysVars(s *SessionVars, key string) (string, bool, error) { return string(j), true, nil case TiDBForcePriority: return mysql.Priority2Str[mysql.PriorityEnum(atomic.LoadInt32(&ForcePriority))], true, nil + case TiDBSlowLogThreshold: + return strconv.FormatUint(atomic.LoadUint64(&config.GetGlobalConfig().Log.SlowThreshold), 10), true, nil } sVal, ok := s.systems[key] if ok { @@ -325,7 +327,7 @@ func ValidateSetSystemVar(vars *SessionVars, name string, value string) (string, TIDBMemQuotaIndexLookupReader, TIDBMemQuotaIndexLookupJoin, TIDBMemQuotaNestedLoopApply, - TiDBRetryLimit: + TiDBRetryLimit, TiDBSlowLogThreshold: _, err := strconv.ParseInt(value, 10, 64) if err != nil { return value, ErrWrongValueForVar.GenWithStackByArgs(name) diff --git a/util/logutil/log.go b/util/logutil/log.go index d9681cd56009b..610c43b91bcc1 100644 --- a/util/logutil/log.go +++ b/util/logutil/log.go @@ -33,6 +33,8 @@ const ( DefaultLogMaxSize = 300 // MB defaultLogFormat = "text" defaultLogLevel = log.InfoLevel + // DefaultSlowThreshold is the default slow log threshold in millisecond. + DefaultSlowThreshold = 300 ) // FileLogConfig serializes file log related config in toml/json.