diff --git a/br/pkg/lightning/log/BUILD.bazel b/br/pkg/lightning/log/BUILD.bazel index 07592d6a682f2..1544e7e13dea8 100644 --- a/br/pkg/lightning/log/BUILD.bazel +++ b/br/pkg/lightning/log/BUILD.bazel @@ -33,6 +33,8 @@ go_test( shard_count = 4, deps = [ ":log", + "//util/logutil", + "@com_github_pingcap_log//:log", "@com_github_stretchr_testify//require", "@org_uber_go_zap//:zap", "@org_uber_go_zap//zapcore", diff --git a/br/pkg/lightning/log/log.go b/br/pkg/lightning/log/log.go index f9fb213d3d430..ba9d822296dfb 100644 --- a/br/pkg/lightning/log/log.go +++ b/br/pkg/lightning/log/log.go @@ -16,6 +16,8 @@ package log import ( "context" + "fmt" + "os" "time" "github.com/pingcap/errors" @@ -45,6 +47,8 @@ type Config struct { FileMaxDays int `toml:"max-days" json:"max-days"` // Maximum number of old log files to retain. FileMaxBackups int `toml:"max-backups" json:"max-backups"` + // EnableDiagnoseLogs, when enabled, we will output logs from all packages and enable GRPC debug log. + EnableDiagnoseLogs bool `toml:"enable-diagnose-logs" json:"enable-diagnose-logs"` } // Adjust adjusts some fields in the config to a proper value. @@ -77,10 +81,24 @@ var ( // InitLogger initializes Lightning's and also the TiDB library's loggers. func InitLogger(cfg *Config, _ string) error { + loggerOptions := []zap.Option{} + if cfg.EnableDiagnoseLogs { + // the value doesn't matter, logutil.InitLogger only checks whether it's empty. + if err := os.Setenv(logutil.GRPCDebugEnvName, "true"); err != nil { + fmt.Println("Failed to set environment variable to enable GRPC debug log", err) + } + } else { + // Only output logs of br package and main package. + loggerOptions = append(loggerOptions, zap.WrapCore(func(core zapcore.Core) zapcore.Core { + return NewFilterCore(core, "github.com/pingcap/tidb/br/", "main.main") + })) + } tidbLogCfg := logutil.LogConfig{} // Disable annoying TiDB Log. // TODO: some error logs outputs randomly, we need to fix them in TiDB. + // this LEVEL only affects SlowQueryLogger, later ReplaceGlobals will overwrite it. tidbLogCfg.Level = "fatal" + // this also init GRPCLogger, controlled by GRPC_DEBUG env. err := logutil.InitLogger(&tidbLogCfg) if err != nil { return errors.Trace(err) @@ -90,10 +108,6 @@ func InitLogger(cfg *Config, _ string) error { Level: cfg.Level, DisableCaller: false, // FilterCore requires zap.AddCaller. } - filterTiDBLog := zap.WrapCore(func(core zapcore.Core) zapcore.Core { - // Filter logs from TiDB and PD. - return NewFilterCore(core, "github.com/pingcap/tidb/br/", "main.main") - }) // "-" is a special config for log to stdout. if len(cfg.File) > 0 && cfg.File != "-" { logCfg.File = pclog.FileLogConfig{ @@ -103,7 +117,7 @@ func InitLogger(cfg *Config, _ string) error { MaxBackups: cfg.FileMaxBackups, } } - logger, props, err := pclog.InitLogger(logCfg, filterTiDBLog) + logger, props, err := pclog.InitLogger(logCfg, loggerOptions...) if err != nil { return err } diff --git a/br/pkg/lightning/log/log_test.go b/br/pkg/lightning/log/log_test.go index 42d4c0b0aaf21..a75f438eb9265 100644 --- a/br/pkg/lightning/log/log_test.go +++ b/br/pkg/lightning/log/log_test.go @@ -19,7 +19,9 @@ import ( "os" "testing" + zaplog "github.com/pingcap/log" "github.com/pingcap/tidb/br/pkg/lightning/log" + "github.com/pingcap/tidb/util/logutil" "github.com/stretchr/testify/require" "go.uber.org/zap" ) @@ -72,4 +74,15 @@ func TestInitStdoutLogger(t *testing.T) { output := <-outputC require.NoError(t, r.Close()) require.Contains(t, output, msg) + + // filter packages on default + require.Equal(t, "", os.Getenv(logutil.GRPCDebugEnvName)) + require.IsType(t, &log.FilterCore{}, log.L().Logger.Core()) + // output all packages when EnableDiagnoseLogs=true + logCfg.EnableDiagnoseLogs = true + require.NoError(t, log.InitLogger(logCfg, "info")) + require.IsType(t, &zaplog.TextIOCore{}, log.L().Logger.Core()) + require.Equal(t, "true", os.Getenv(logutil.GRPCDebugEnvName)) + // reset GRPCDebugEnvName + require.NoError(t, os.Unsetenv(logutil.GRPCDebugEnvName)) } diff --git a/util/logutil/log.go b/util/logutil/log.go index 34ea488954273..faf0ddfe03ae9 100644 --- a/util/logutil/log.go +++ b/util/logutil/log.go @@ -94,6 +94,9 @@ const ( SlowLogTimeFormat = time.RFC3339Nano // OldSlowLogTimeFormat is the first version of the the time format for slow log, This is use for compatibility. OldSlowLogTimeFormat = "2006-01-02-15:04:05.999999999 -0700" + + // GRPCDebugEnvName is the environment variable name for GRPC_DEBUG. + GRPCDebugEnvName = "GRPC_DEBUG" ) // SlowQueryLogger is used to log slow query, InitLogger will modify it according to config file. @@ -121,7 +124,7 @@ func InitLogger(cfg *LogConfig, opts ...zap.Option) error { func initGRPCLogger(gl *zap.Logger) { level := zapcore.ErrorLevel verbosity := 0 - if len(os.Getenv("GRPC_DEBUG")) > 0 { + if len(os.Getenv(GRPCDebugEnvName)) > 0 { verbosity = 999 level = zapcore.DebugLevel }