*: improve the format of the error log (#12155)

config/config.go

@@ -28,7 +28,11 @@ import (
 
 	"github.com/BurntSushi/toml"
 	"github.com/pingcap/errors"
+<<<<<<< HEAD
 	"github.com/pingcap/parser/mysql"
+=======
+	zaplog "github.com/pingcap/log"
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 	"github.com/pingcap/tidb/util/logutil"
 	tracing "github.com/uber/jaeger-client-go/config"
 	"go.uber.org/atomic"
@@ -119,6 +123,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"`
 
@@ -392,6 +399,7 @@ var defaultConf = Config{
 	LowerCaseTableNames: 2,
 	ServerVersion:       "",
 	Log: Log{
+<<<<<<< HEAD
 		Level:               "info",
 		Format:              "text",
 		File:                logutil.NewFileLogConfig(logutil.DefaultLogMaxSize),
@@ -400,6 +408,16 @@ var defaultConf = Config{
 		ExpensiveThreshold:  10000,
 		QueryLogMaxLen:      logutil.DefaultQueryLogMaxLen,
 		RecordPlanInSlowLog: logutil.DefaultRecordPlanInSlowLog,
+=======
+		Level:              "info",
+		Format:             "text",
+		File:               logutil.NewFileLogConfig(true, logutil.DefaultLogMaxSize),
+		SlowQueryFile:      "tidb-slow.log",
+		SlowThreshold:      logutil.DefaultSlowThreshold,
+		ExpensiveThreshold: 10000,
+		DisableErrorStack:  true,
+		QueryLogMaxLen:     logutil.DefaultQueryLogMaxLen,
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 	},
 	Status: Status{
 		ReportStatus:    true,
@@ -700,7 +718,7 @@ var TableLockDelayClean = func() uint64 {
 
 // 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.

config/config.toml.example

@@ -87,9 +87,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"
 

config/config_test.go

@@ -20,7 +20,11 @@ import (
 	"testing"
 
 	. "github.com/pingcap/check"
+<<<<<<< HEAD
 	"github.com/pingcap/parser/mysql"
+=======
+	zaplog "github.com/pingcap/log"
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 	"github.com/pingcap/tidb/util/logutil"
 	tracing "github.com/uber/jaeger-client-go/config"
 )
@@ -133,8 +137,13 @@ allow-auto-random = true
 	// Make sure the example config is the same as default config.
 	c.Assert(conf, DeepEquals, GetGlobalConfig())
 
+<<<<<<< HEAD
 	// Test for log config.
 	c.Assert(conf.Log.ToLogConfig(), DeepEquals, logutil.NewLogConfig("info", "text", "tidb-slow.log", conf.Log.File, false))
+=======
+	// Test for lof config.
+	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 }))
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 
 	// Test for tracing config.
 	tracingConf := &tracing.Configuration{

go.mod

@@ -33,6 +33,7 @@ require (
 	github.com/pingcap/errors v0.11.5-0.20190809092503-95897b64e011
 	github.com/pingcap/failpoint v0.0.0-20191029060244-12f4ac2fd11d
 	github.com/pingcap/goleveldb v0.0.0-20171020122428-b9ff6c35079e
+<<<<<<< HEAD
 	github.com/pingcap/kvproto v0.0.0-20200317043902-2838e21ca222
 	github.com/pingcap/log v0.0.0-20200117041106-d28c14d3b1cd
 	github.com/pingcap/parser v3.1.0-beta.1.0.20200318061433-f0b8f6cdca0d+incompatible
@@ -41,6 +42,18 @@ require (
 	github.com/pingcap/tipb v0.0.0-20200401093201-cc8b75c53383
 	github.com/prometheus/client_golang v1.0.0
 	github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4
+=======
+	github.com/pingcap/kvproto v0.0.0-20190904075355-9a1bd6a31da2
+	github.com/pingcap/log v0.0.0-20190715063458-479153f07ebd
+	github.com/pingcap/parser v0.0.0-20190912032624-978b8272c04e
+	github.com/pingcap/pd v0.0.0-20190712044914-75a1f9f3062b
+	github.com/pingcap/tidb-tools v2.1.3-0.20190321065848-1e8b48f5c168+incompatible
+	github.com/pingcap/tipb v0.0.0-20190806070524-16909e03435e
+	github.com/prometheus/client_golang v0.9.0
+	github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910
+	github.com/prometheus/common v0.0.0-20181020173914-7e9e6cabbd39 // indirect
+	github.com/prometheus/procfs v0.0.0-20181005140218-185b4288413d // indirect
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 	github.com/remyoudompheng/bigfft v0.0.0-20190512091148-babf20351dd7 // indirect
 	github.com/shirou/gopsutil v2.19.10+incompatible
 	github.com/shurcooL/httpfs v0.0.0-20171119174359-809beceb2371 // indirect

go.sum

@@ -241,6 +241,7 @@ github.com/pingcap/failpoint v0.0.0-20191029060244-12f4ac2fd11d h1:F8vp38kTAckN+
 github.com/pingcap/failpoint v0.0.0-20191029060244-12f4ac2fd11d/go.mod h1:DNS3Qg7bEDhU6EXNHF+XSv/PGznQaMJ5FWvctpm6pQI=
 github.com/pingcap/goleveldb v0.0.0-20171020122428-b9ff6c35079e h1:P73/4dPCL96rGrobssy1nVy2VaVpNCuLpCbr+FEaTA8=
 github.com/pingcap/goleveldb v0.0.0-20171020122428-b9ff6c35079e/go.mod h1:O17XtbryoCJhkKGbT62+L2OlrniwqiGLSqrmdHCMzZw=
+<<<<<<< HEAD
 github.com/pingcap/kvproto v0.0.0-20200213074014-83e827908584/go.mod h1:IOdRDPLyda8GX2hE/jO7gqaCV/PNFh8BZQCQZXfIOqI=
 github.com/pingcap/kvproto v0.0.0-20200317043902-2838e21ca222 h1:y+qDC9hP5ZMQADkVtbGvZOP68NsoYFlt4I3r8QhIvVk=
 github.com/pingcap/kvproto v0.0.0-20200317043902-2838e21ca222/go.mod h1:IOdRDPLyda8GX2hE/jO7gqaCV/PNFh8BZQCQZXfIOqI=
@@ -256,6 +257,22 @@ github.com/pingcap/tidb-tools v4.0.0-beta.1.0.20200317092225-ed6b2a87af54+incomp
 github.com/pingcap/tidb-tools v4.0.0-beta.1.0.20200317092225-ed6b2a87af54+incompatible/go.mod h1:XGdcy9+yqlDSEMTpOXnwf3hiTeqrV6MN/u1se9N8yIM=
 github.com/pingcap/tipb v0.0.0-20200401093201-cc8b75c53383 h1:y1ayhtouCaO0u74JNMN8s20CGJT0yIuAb8UXOYnCALc=
 github.com/pingcap/tipb v0.0.0-20200401093201-cc8b75c53383/go.mod h1:RtkHW8WbcNxj8lsbzjaILci01CtYnYbIkQhjyZWrWVI=
+=======
+github.com/pingcap/kvproto v0.0.0-20190516013202-4cf58ad90b6c/go.mod h1:QMdbTAXCHzzygQzqcG9uVUgU2fKeSN1GmfMiykdSzzY=
+github.com/pingcap/kvproto v0.0.0-20190904075355-9a1bd6a31da2 h1:wBORZD4gvEKK0tGP4g1Rv0Y7f2cNnObzI/ckPhsU11M=
+github.com/pingcap/kvproto v0.0.0-20190904075355-9a1bd6a31da2/go.mod h1:QMdbTAXCHzzygQzqcG9uVUgU2fKeSN1GmfMiykdSzzY=
+github.com/pingcap/log v0.0.0-20190214045112-b37da76f67a7/go.mod h1:xsfkWVaFVV5B8e1K9seWfyJWFrIhbtUTAD8NV1Pq3+w=
+github.com/pingcap/log v0.0.0-20190715063458-479153f07ebd h1:hWDol43WY5PGhsh3+8794bFHY1bPrmu6bTalpssCrGg=
+github.com/pingcap/log v0.0.0-20190715063458-479153f07ebd/go.mod h1:WpHUKhNZ18v116SvGrmjkA9CBhYmuUTKL+p8JC9ANEw=
+github.com/pingcap/parser v0.0.0-20190912032624-978b8272c04e h1:QeD1wC7bGElAhufSHH4JcIbs1cVdxnGWD3n3gcE5qeY=
+github.com/pingcap/parser v0.0.0-20190912032624-978b8272c04e/go.mod h1:1FNvfp9+J0wvc4kl8eGNh7Rqrxveg15jJoWo/a0uHwA=
+github.com/pingcap/pd v0.0.0-20190712044914-75a1f9f3062b h1:oS9PftxQqgcRouKhhdaB52tXhVLEP7Ng3Qqsd6Z18iY=
+github.com/pingcap/pd v0.0.0-20190712044914-75a1f9f3062b/go.mod h1:3DlDlFT7EF64A1bmb/tulZb6wbPSagm5G4p1AlhaEDs=
+github.com/pingcap/tidb-tools v2.1.3-0.20190321065848-1e8b48f5c168+incompatible h1:MkWCxgZpJBgY2f4HtwWMMFzSBb3+JPzeJgF3VrXE/bU=
+github.com/pingcap/tidb-tools v2.1.3-0.20190321065848-1e8b48f5c168+incompatible/go.mod h1:XGdcy9+yqlDSEMTpOXnwf3hiTeqrV6MN/u1se9N8yIM=
+github.com/pingcap/tipb v0.0.0-20190806070524-16909e03435e h1:H7meq8QPmWGImOkHTQYAWw82zwIqndJaCDPVUknOHbM=
+github.com/pingcap/tipb v0.0.0-20190806070524-16909e03435e/go.mod h1:RtkHW8WbcNxj8lsbzjaILci01CtYnYbIkQhjyZWrWVI=
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 github.com/pkg/errors v0.8.0/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=
 github.com/pkg/errors v0.8.1 h1:iURUrRGxPUNPdy5/HRSm+Yj6okJ6UtLINN0Q9M4+h3I=
 github.com/pkg/errors v0.8.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0=

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"
 )
 
@@ -71,8 +72,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,
@@ -81,6 +82,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.
@@ -323,7 +328,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)
 	}

util/logutil/log_test.go

@@ -184,6 +184,53 @@ func (s *testLogSuite) TestSlowQueryZapLogger(c *C) {
 		c.Assert(str, Matches, zapLogPattern)
 	}
 	c.Assert(err, Equals, io.EOF)
+<<<<<<< HEAD
+=======
+
+}
+
+func (s *testLogSuite) TestZapLoggerWithKeys(c *C) {
+	fileCfg := FileLogConfig{zaplog.FileLogConfig{Filename: "zap_log", MaxSize: 4096}}
+	conf := NewLogConfig("info", DefaultLogFormat, "", fileCfg, false)
+	err := InitZapLogger(conf)
+	c.Assert(err, IsNil)
+	connID := uint32(123)
+	ctx := WithConnID(context.Background(), connID)
+	s.testZapLogger(ctx, c, fileCfg.Filename, zapLogWithConnIDPattern)
+	os.Remove(fileCfg.Filename)
+
+	err = InitZapLogger(conf)
+	c.Assert(err, IsNil)
+	key := "ctxKey"
+	val := "ctxValue"
+	ctx1 := WithKeyValue(context.Background(), key, val)
+	s.testZapLogger(ctx1, c, fileCfg.Filename, zapLogWithKeyValPattern)
+	os.Remove(fileCfg.Filename)
+}
+
+func (s *testLogSuite) testZapLogger(ctx context.Context, c *C, fileName, pattern string) {
+	Logger(ctx).Debug("debug msg", zap.String("test with key", "true"))
+	Logger(ctx).Info("info msg", zap.String("test with key", "true"))
+	Logger(ctx).Warn("warn msg", zap.String("test with key", "true"))
+	Logger(ctx).Error("error msg", zap.String("test with key", "true"))
+
+	f, err := os.Open(fileName)
+	c.Assert(err, IsNil)
+	defer f.Close()
+
+	r := bufio.NewReader(f)
+	for {
+		var str string
+		str, err = r.ReadString('\n')
+		if err != nil {
+			break
+		}
+		c.Assert(str, Matches, pattern)
+		c.Assert(strings.Contains(str, "stack"), IsFalse)
+		c.Assert(strings.Contains(str, "errorVerbose"), IsFalse)
+	}
+	c.Assert(err, Equals, io.EOF)
+>>>>>>> cbf4ddc... *: improve the format of the error log (#12155)
 }
 
 func (s *testLogSuite) TestSetLevel(c *C) {