lightning: add parameter to output logs of all packages and enable gr…

…pc log (#45498)

close #45497

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",

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
 	}

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))
 }

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
 	}