From 114ad7e19533bd4f4055d891acf81490bef17e93 Mon Sep 17 00:00:00 2001 From: pingcap-github-bot Date: Sat, 11 Apr 2020 18:50:39 +0800 Subject: [PATCH] *: improve the format of the error log (#12155) (#16181) --- config/config.go | 7 ++++++- config/config.toml.example | 5 ++++- config/config_test.go | 4 ++-- util/logutil/log.go | 22 ++++++++++++++-------- util/logutil/log_test.go | 6 +++++- 5 files changed, 31 insertions(+), 13 deletions(-) diff --git a/config/config.go b/config/config.go index 39f4385026067..bcd007f1b3fae 100644 --- a/config/config.go +++ b/config/config.go @@ -28,6 +28,7 @@ import ( "github.com/BurntSushi/toml" "github.com/pingcap/errors" + zaplog "github.com/pingcap/log" "github.com/pingcap/parser/mysql" "github.com/pingcap/tidb/util/logutil" tracing "github.com/uber/jaeger-client-go/config" @@ -112,6 +113,9 @@ type Log struct { Format string `toml:"format" json:"format"` // Disable automatic timestamps in output. DisableTimestamp bool `toml:"disable-timestamp" json:"disable-timestamp"` + // DisableErrorStack stops annotating logs with the full stack error + // message. + DisableErrorStack bool `toml:"disable-error-stack" json:"disable-error-stack"` // File log config. File logutil.FileLogConfig `toml:"file" json:"file"` @@ -387,6 +391,7 @@ var defaultConf = Config{ ExpensiveThreshold: 10000, QueryLogMaxLen: logutil.DefaultQueryLogMaxLen, RecordPlanInSlowLog: logutil.DefaultRecordPlanInSlowLog, + DisableErrorStack: true, }, Status: Status{ ReportStatus: true, @@ -649,7 +654,7 @@ func hasRootPrivilege() bool { // ToLogConfig converts *Log to *logutil.LogConfig. func (l *Log) ToLogConfig() *logutil.LogConfig { - return logutil.NewLogConfig(l.Level, l.Format, l.SlowQueryFile, l.File, l.DisableTimestamp) + return logutil.NewLogConfig(l.Level, l.Format, l.SlowQueryFile, l.File, l.DisableTimestamp, func(config *zaplog.Config) { config.DisableErrorVerbose = l.DisableErrorStack }) } // ToTracingConfig converts *OpenTracing to *tracing.Configuration. diff --git a/config/config.toml.example b/config/config.toml.example index ebf60a2c0d6e3..41185ebdf62f3 100644 --- a/config/config.toml.example +++ b/config/config.toml.example @@ -81,9 +81,12 @@ level = "info" # Log format, one of json, text, console. format = "text" -# Disable automatic timestamp in output +# Disable automatic timestamp in output. disable-timestamp = false +# Disable stack information in error message. +disable-error-stack = true + # Stores slow query log into separated files. slow-query-file = "tidb-slow.log" diff --git a/config/config_test.go b/config/config_test.go index aa3423d5716bf..bd35ad13f3de5 100644 --- a/config/config_test.go +++ b/config/config_test.go @@ -20,6 +20,7 @@ import ( "testing" . "github.com/pingcap/check" + zaplog "github.com/pingcap/log" "github.com/pingcap/parser/mysql" "github.com/pingcap/tidb/util/logutil" tracing "github.com/uber/jaeger-client-go/config" @@ -124,8 +125,7 @@ history-size=100 c.Assert(conf, DeepEquals, GetGlobalConfig()) // Test for log config. - c.Assert(conf.Log.ToLogConfig(), DeepEquals, logutil.NewLogConfig("info", "text", "tidb-slow.log", conf.Log.File, false)) - + c.Assert(conf.Log.ToLogConfig(), DeepEquals, logutil.NewLogConfig("info", "text", "tidb-slow.log", conf.Log.File, false, func(config *zaplog.Config) { config.DisableErrorVerbose = conf.Log.DisableErrorStack })) // Test for tracing config. tracingConf := &tracing.Configuration{ Disabled: true, diff --git a/util/logutil/log.go b/util/logutil/log.go index a965df4228c18..d350866a47fe9 100644 --- a/util/logutil/log.go +++ b/util/logutil/log.go @@ -28,6 +28,7 @@ import ( zaplog "github.com/pingcap/log" log "github.com/sirupsen/logrus" "go.uber.org/zap" + "go.uber.org/zap/zapcore" "gopkg.in/natefinch/lumberjack.v2" ) @@ -72,8 +73,8 @@ type LogConfig struct { } // NewLogConfig creates a LogConfig. -func NewLogConfig(level, format, slowQueryFile string, fileCfg FileLogConfig, disableTimestamp bool) *LogConfig { - return &LogConfig{ +func NewLogConfig(level, format, slowQueryFile string, fileCfg FileLogConfig, disableTimestamp bool, opts ...func(*zaplog.Config)) *LogConfig { + c := &LogConfig{ Config: zaplog.Config{ Level: level, Format: format, @@ -82,6 +83,10 @@ func NewLogConfig(level, format, slowQueryFile string, fileCfg FileLogConfig, di }, SlowQueryFile: slowQueryFile, } + for _, opt := range opts { + opt(&c.Config) + } + return c } // isSKippedPackageName tests wether path name is on log library calling stack. @@ -324,7 +329,7 @@ func InitLogger(cfg *LogConfig) error { // InitZapLogger initializes a zap logger with cfg. func InitZapLogger(cfg *LogConfig) error { - gl, props, err := zaplog.InitLogger(&cfg.Config) + gl, props, err := zaplog.InitLogger(&cfg.Config, zap.AddStacktrace(zapcore.FatalLevel)) if err != nil { return errors.Trace(err) } @@ -337,12 +342,13 @@ func InitZapLogger(cfg *LogConfig) error { Filename: cfg.SlowQueryFile, } sqCfg := &zaplog.Config{ - Level: cfg.Level, - Format: cfg.Format, - DisableTimestamp: cfg.DisableTimestamp, - File: sqfCfg, + Level: cfg.Level, + Format: cfg.Format, + DisableTimestamp: cfg.DisableTimestamp, + File: sqfCfg, + DisableErrorVerbose: cfg.DisableErrorVerbose, } - sqLogger, _, err := zaplog.InitLogger(sqCfg) + sqLogger, _, err := zaplog.InitLogger(sqCfg, zap.AddStacktrace(zapcore.FatalLevel)) if err != nil { return errors.Trace(err) } diff --git a/util/logutil/log_test.go b/util/logutil/log_test.go index 624a5d8eede64..8e0cbda5b48db 100644 --- a/util/logutil/log_test.go +++ b/util/logutil/log_test.go @@ -24,6 +24,7 @@ import ( "testing" . "github.com/pingcap/check" + "github.com/pingcap/errors" zaplog "github.com/pingcap/log" log "github.com/sirupsen/logrus" "go.uber.org/zap" @@ -160,7 +161,7 @@ func (s *testLogSuite) TestLoggerKeepOrder(c *C) { func (s *testLogSuite) TestSlowQueryZapLogger(c *C) { fileName := "slow_query" - conf := NewLogConfig("info", DefaultLogFormat, fileName, EmptyFileLogConfig, false) + conf := NewLogConfig("info", DefaultLogFormat, fileName, EmptyFileLogConfig, false, func(config *zaplog.Config) { config.DisableErrorVerbose = true }) err := InitZapLogger(conf) c.Assert(err, IsNil) defer os.Remove(fileName) @@ -169,6 +170,7 @@ func (s *testLogSuite) TestSlowQueryZapLogger(c *C) { SlowQueryZapLogger.Info("info message", zap.String("str key", "val")) SlowQueryZapLogger.Warn("warn", zap.Int("int key", 123)) SlowQueryZapLogger.Error("error message", zap.Bool("bool key", true)) + SlowQueryZapLogger.Error("error message", zap.Error(errors.New("unexpect"))) f, err := os.Open(fileName) c.Assert(err, IsNil) @@ -182,6 +184,8 @@ func (s *testLogSuite) TestSlowQueryZapLogger(c *C) { break } c.Assert(str, Matches, zapLogPattern) + c.Assert(strings.Contains(str, "stack"), IsFalse) + c.Assert(strings.Contains(str, "errorVerbose"), IsFalse) } c.Assert(err, Equals, io.EOF) }