util: Fixed the issues when using the same log files for different log types (#61012)

close pingcap/tidb#61007

pkg/util/logutil/log.go

@@ -148,16 +148,26 @@ func InitLogger(cfg *LogConfig, opts ...zap.Option) error {
 		errVerboseLogger = logger
 	}
 
-	// init dedicated logger for slow query log
-	SlowQueryLogger, _, err = newSlowQueryLogger(cfg)
-	if err != nil {
-		return errors.Trace(err)
+	// init dedicated logger for slow query log,
+	// we should use same writeSyncer when filenames are equal.
+	if cfg.SlowQueryFile != "" && cfg.SlowQueryFile != cfg.File.Filename {
+		SlowQueryLogger, _, err = newSlowQueryLogger(cfg)
+		if err != nil {
+			return errors.Trace(err)
+		}
+	} else {
+		SlowQueryLogger = newSlowQueryLoggerFromZapLogger(gl, props)
 	}
 
-	// init dedicated logger for general log
-	GeneralLogger, _, err = newGeneralLogger(cfg)
-	if err != nil {
-		return errors.Trace(err)
+	// init dedicated logger for general log,
+	// we should use same writeSyncer when filenames are equal.
+	if cfg.GeneralLogFile != "" && cfg.GeneralLogFile != cfg.File.Filename {
+		GeneralLogger, _, err = newGeneralLogger(cfg)
+		if err != nil {
+			return errors.Trace(err)
+		}
+	} else {
+		GeneralLogger = gl
 	}
 
 	initGRPCLogger(gl)

pkg/util/logutil/log_test.go

@@ -21,10 +21,12 @@ import (
 	"io"
 	"os"
 	"path"
+	"reflect"
 	"runtime"
 	"strings"
 	"testing"
 	"time"
+	"unsafe"
 
 	"github.com/google/uuid"
 	"github.com/pingcap/log"
@@ -185,23 +187,23 @@ func TestSetLevel(t *testing.T) {
 }
 
 func TestSlowQueryLoggerAndGeneralLoggerCreation(t *testing.T) {
-	var prop *log.ZapProperties
 	var err error
+	var l *zap.Logger
 	for i := range 2 {
 		level := "Error"
 		conf := NewLogConfig(level, DefaultLogFormat, "", "", EmptyFileLogConfig, false)
 		if i == 0 {
-			_, prop, err = newSlowQueryLogger(conf)
+			l, _, err = newSlowQueryLogger(conf)
 		} else {
-			_, prop, err = newGeneralLogger(conf)
+			l, _, err = newGeneralLogger(conf)
 		}
 		// assert after init logger, the original conf is not changed
 		require.Equal(t, conf.Level, level)
 		require.NoError(t, err)
 		// logger doesn't use the level of the global log config, and the
 		// level should be equals to InfoLevel.
-		require.NotEqual(t, conf.Level, prop.Level.String())
-		require.True(t, prop.Level.Level() == zapcore.InfoLevel)
+		require.NotEqual(t, conf.Level, l.Level().String())
+		require.True(t, l.Level() == zapcore.InfoLevel)
 
 		level = "warn"
 		name := "test.log"
@@ -226,6 +228,62 @@ func TestSlowQueryLoggerAndGeneralLoggerCreation(t *testing.T) {
 	}
 }
 
+func getWriteSyncerViaReflection(core *log.TextIOCore) (*zapcore.WriteSyncer, error) {
+	val := reflect.ValueOf(core).Elem()
+
+	outField := val.FieldByName("out")
+	if !outField.IsValid() {
+		return nil, fmt.Errorf("field 'out' not found in TextIOCore")
+	}
+
+	var out *zapcore.WriteSyncer
+	if outField.Type().AssignableTo(reflect.TypeOf((*zapcore.WriteSyncer)(nil)).Elem()) {
+		out = (*zapcore.WriteSyncer)(unsafe.Pointer(outField.UnsafeAddr()))
+	}
+
+	return out, nil
+}
+
+func TestSlowQueryLoggerAndGeneralUseSameLogFileName(t *testing.T) {
+	fileName := t.TempDir() + "a.log"
+	fileConf := FileLogConfig{
+		log.FileLogConfig{
+			Filename:   fileName,
+			MaxSize:    10,
+			MaxDays:    10,
+			MaxBackups: 10,
+		},
+	}
+	level := "info"
+	// Use same log file for all logs
+	conf := NewLogConfig(level, DefaultLogFormat, "", "", fileConf, false)
+	require.NoError(t, InitLogger(conf))
+
+	SlowQueryLogger.Info("123")
+	GeneralLogger.Info("GENERAL LOG", zap.Int("test", 123))
+
+	slowLogSyncer, err := getWriteSyncerViaReflection(SlowQueryLogger.Core().(*log.TextIOCore))
+	require.NoError(t, err)
+	require.NotNil(t, slowLogSyncer)
+
+	generalLogSyncer, err := getWriteSyncerViaReflection(GeneralLogger.Core().(*log.TextIOCore))
+	require.NoError(t, err)
+	require.NotNil(t, generalLogSyncer)
+
+	// use the same `WriteSyncer`
+	require.Equal(t, generalLogSyncer, slowLogSyncer)
+
+	f, err := os.Open(fileName)
+	require.NoError(t, err)
+
+	b := make([]byte, 1024)
+	n, err := f.Read(b)
+	require.NoError(t, err)
+	// contains slow log and general log.
+	require.True(t, strings.Contains(string(b[:n]), "# Time"))
+	require.True(t, strings.Contains(string(b[:n]), "GENERAL LOG"))
+}
+
 func TestCompressedLog(t *testing.T) {
 	level := "warn"
 	fileConf := FileLogConfig{

pkg/util/logutil/slow_query_logger.go

@@ -44,6 +44,14 @@ func newSlowQueryLogger(cfg *LogConfig) (*zap.Logger, *log.ZapProperties, error)
 	return sqLogger, prop, nil
 }
 
+func newSlowQueryLoggerFromZapLogger(l *zap.Logger, p *log.ZapProperties) *zap.Logger {
+	newCore := log.NewTextCore(&slowLogEncoder{}, p.Syncer, p.Level)
+	sqLogger := l.WithOptions(zap.WrapCore(func(zapcore.Core) zapcore.Core {
+		return newCore
+	}))
+	return sqLogger
+}
+
 func newSlowQueryLogConfig(cfg *LogConfig) *log.Config {
 	// copy the global log config to slow log config
 	// if the filename of slow log config is empty, slow log will behave the same as global log.