core: set log config at plugin level

dispatcher/coremain/config.go

@@ -20,18 +20,13 @@ package coremain
 import (
 	"bytes"
 	"github.com/IrineSistiana/mosdns/v3/dispatcher/handler"
+	"github.com/IrineSistiana/mosdns/v3/dispatcher/mlog"
 	"gopkg.in/yaml.v3"
 	"os"
 )
 
-// Config is config
 type Config struct {
-	Log struct {
-		Level    string `yaml:"level"`
-		File     string `yaml:"file"`
-		ErrFile  string `yaml:"err_file"`
-		InfoFile string `yaml:"info_file"`
-	} `yaml:"log"`
+	Log     mlog.LogConfig    `yaml:"log"`
 	Library []string          `yaml:"library"`
 	Plugin  []*handler.Config `yaml:"plugin"`
 	Include []string          `yaml:"include"`

dispatcher/coremain/run.go

@@ -25,7 +25,6 @@ import (
 	"github.com/IrineSistiana/mosdns/v3/dispatcher/pkg/load_cache"
 	_ "github.com/IrineSistiana/mosdns/v3/dispatcher/plugin"
 	"go.uber.org/zap"
-	"go.uber.org/zap/zapcore"
 	"os"
 	"os/signal"
 	"runtime/debug"
@@ -70,49 +69,8 @@ func loadConfig(f string, depth int) error {
 	}
 
 	if depth == 1 {
-		// init logger
-		level, ok := parseLogLevel(c.Log.Level)
-		if !ok {
-			return fmt.Errorf("invalid log level [%s]", c.Log.Level)
-		}
-		mlog.Level().SetLevel(level)
-
-		if len(c.Log.InfoFile) == 0 {
-			c.Log.InfoFile = c.Log.File
-		}
-		if len(c.Log.ErrFile) == 0 {
-			c.Log.ErrFile = c.Log.File
-		}
-
-		if lf := c.Log.File; len(lf) > 0 {
-			mlog.L().Info("opening log file", zap.String("file", lf))
-			f, err := os.OpenFile(lf, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0644)
-			if err != nil {
-				return fmt.Errorf("open log file: %w", err)
-			}
-			mlog.L().Info("redirecting log to file, end of console log", zap.String("file", c.Log.File))
-			fLocked := zapcore.Lock(f)
-			mlog.InfoWriter().Replace(fLocked)
-			mlog.ErrWriter().Replace(fLocked)
-		} else {
-			if lf := c.Log.InfoFile; len(lf) > 0 {
-				mlog.L().Info("opening info log file", zap.String("file", lf))
-				f, err := os.OpenFile(lf, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0644)
-				if err != nil {
-					return fmt.Errorf("open info log file: %w", err)
-				}
-				mlog.L().Info("redirecting info log to file, end of console log", zap.String("file", c.Log.File))
-				mlog.InfoWriter().Replace(zapcore.Lock(f))
-			}
-			if lf := c.Log.ErrFile; len(lf) > 0 {
-				mlog.L().Info("opening err log file", zap.String("file", lf))
-				f, err := os.OpenFile(lf, os.O_APPEND|os.O_WRONLY|os.O_CREATE, 0644)
-				if err != nil {
-					return fmt.Errorf("open err log file: %w", err)
-				}
-				mlog.L().Info("redirecting err log to file, end of console log", zap.String("file", c.Log.File))
-				mlog.ErrWriter().Replace(zapcore.Lock(f))
-			}
+		if err := mlog.ApplyGlobalConfig(&c.Log); err != nil {
+			return fmt.Errorf("failed to init logger: %w", err)
 		}
 
 		for _, lib := range c.Library {
@@ -145,18 +103,3 @@ func loadConfig(f string, depth int) error {
 	}
 	return nil
 }
-
-func parseLogLevel(s string) (zapcore.Level, bool) {
-	switch s {
-	case "debug":
-		return zap.DebugLevel, true
-	case "", "info":
-		return zap.InfoLevel, true
-	case "warn":
-		return zap.WarnLevel, true
-	case "error":
-		return zap.ErrorLevel, true
-	default:
-		return 0, false
-	}
-}

dispatcher/handler/config.go

@@ -18,6 +18,7 @@
 package handler
 
 import (
+	"github.com/IrineSistiana/mosdns/v3/dispatcher/mlog"
 	"github.com/mitchellh/mapstructure"
 )
 
@@ -29,6 +30,8 @@ type Config struct {
 	// Type, required
 	Type string `yaml:"type"`
 
+	LogConfig mlog.LogConfig `yaml:"log"`
+
 	// Args, might be required by some plugins
 	Args map[string]interface{} `yaml:"args"`
 }

dispatcher/handler/plugin_wrapper.go

@@ -33,6 +33,7 @@ var (
 // interface conversion.
 type PluginWrapper struct {
 	Plugin
+	l *zap.Logger
 	e Executable
 	m Matcher
 }
@@ -47,6 +48,9 @@ func NewPluginWrapper(gp Plugin) *PluginWrapper {
 	if m, ok := gp.(Matcher); ok {
 		w.m = m
 	}
+	if v, ok := gp.(interface{ L() *zap.Logger }); ok {
+		w.l = v.L()
+	}
 
 	return w
 }
@@ -56,7 +60,7 @@ func (w *PluginWrapper) Match(ctx context.Context, qCtx *Context) (matched bool,
 	if err != nil {
 		return false, NewPluginError(w.Tag(), err)
 	}
-	mlog.L().Debug("matching query context", qCtx.InfoField(), zap.String("tag", w.Tag()), zap.Bool("result", matched))
+	w.getLogger().Debug("matching query context", qCtx.InfoField(), zap.String("tag", w.Tag()), zap.Bool("result", matched))
 	return matched, nil
 }
 
@@ -73,7 +77,7 @@ func (w *PluginWrapper) match(ctx context.Context, qCtx *Context) (matched bool,
 }
 
 func (w *PluginWrapper) Exec(ctx context.Context, qCtx *Context, next ExecutableChainNode) error {
-	mlog.L().Debug("executing plugin", qCtx.InfoField(), zap.String("tag", w.Tag()))
+	w.getLogger().Debug("executing plugin", qCtx.InfoField(), zap.String("tag", w.Tag()))
 	err := w.exec(ctx, qCtx, next)
 	if err != nil {
 		return NewPluginError(w.Tag(), err)
@@ -93,6 +97,13 @@ func (w *PluginWrapper) exec(ctx context.Context, qCtx *Context, next Executable
 	return w.e.Exec(ctx, qCtx, next)
 }
 
+func (w *PluginWrapper) getLogger() *zap.Logger {
+	if w.l != nil {
+		return w.l
+	}
+	return mlog.L()
+}
+
 type PluginInterfaceType uint8
 
 const (

dispatcher/handler/register.go

@@ -93,7 +93,10 @@ func NewPlugin(c *Config) (p Plugin, err error) {
 		return nil, fmt.Errorf("plugin type %s not defined", c.Type)
 	}
 
-	bp := NewBP(c.Tag, c.Type)
+	bp, err := NewBPWithLog(c.Tag, c.Type, &c.LogConfig)
+	if err != nil {
+		return nil, err
+	}
 
 	// parse args
 	if typeInfo.NewArgs != nil {
@@ -198,6 +201,16 @@ func NewBP(tag string, typ string) *BP {
 	return &BP{tag: tag, typ: typ, l: l, s: l.Sugar()}
 }
 
+// NewBPWithLog creates a new BP and initials its logger with a static level.
+func NewBPWithLog(tag string, typ string, lc *mlog.LogConfig) (*BP, error) {
+	l, err := mlog.NewLogger(lc)
+	if err != nil {
+		return nil, fmt.Errorf("failed to init logger: %w", err)
+	}
+	l = l.Named(tag)
+	return &BP{tag: tag, typ: typ, l: l, s: l.Sugar()}, nil
+}
+
 func (p *BP) Tag() string {
 	return p.tag
 }

dispatcher/mlog/logger.go

@@ -18,18 +18,26 @@
 package mlog
 
 import (
+	"fmt"
 	"go.uber.org/zap"
 	"go.uber.org/zap/zapcore"
 	"os"
 	"sync/atomic"
 	"unsafe"
 )
 
+type LogConfig struct {
+	Level    string `yaml:"level"`
+	File     string `yaml:"file"`
+	ErrFile  string `yaml:"err_file"`
+	InfoFile string `yaml:"info_file"`
+}
+
 var (
 	atomicLevel      = zap.NewAtomicLevelAt(zap.InfoLevel)
 	atomicInfoWriter = NewAtomicWriteSyncer(zapcore.Lock(os.Stdout))
 	atomicErrWriter  = NewAtomicWriteSyncer(zapcore.Lock(os.Stderr))
-	l                = initLogger()
+	l                = newLogger(atomicLevel, atomicInfoWriter, atomicErrWriter)
 	s                = l.Sugar()
 )
 
@@ -45,29 +53,117 @@ func ErrWriter() *AtomicWriteSyncer {
 	return atomicErrWriter
 }
 
-func initLogger() *zap.Logger {
-	errLvl := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
-		return atomicLevel.Enabled(lvl) && lvl >= zapcore.ErrorLevel
+func ApplyGlobalConfig(lc *LogConfig) error {
+	_, err := handleLogConfig(lc, true)
+	return err
+}
+
+func NewLogger(lc *LogConfig) (*zap.Logger, error) {
+	return handleLogConfig(lc, false)
+}
+
+func handleLogConfig(lc *LogConfig, applyGlobally bool) (*zap.Logger, error) {
+	var lvl zapcore.Level
+	if len(lc.Level) > 0 {
+		var ok bool
+		lvl, ok = parseLogLevel(lc.Level)
+		if !ok {
+			return nil, fmt.Errorf("invalid log level [%s]", lc.Level)
+		}
+	}
+
+	if len(lc.InfoFile) == 0 {
+		lc.InfoFile = lc.File
+	}
+	if len(lc.ErrFile) == 0 {
+		lc.ErrFile = lc.File
+	}
+
+	var infoWriter zapcore.WriteSyncer
+	var errWriter zapcore.WriteSyncer
+
+	if lf := lc.File; len(lf) > 0 {
+		f, _, err := zap.Open(lf)
+		if err != nil {
+			return nil, fmt.Errorf("open log file: %w", err)
+		}
+		fLocked := zapcore.Lock(f)
+		infoWriter = fLocked
+		errWriter = fLocked
+	} else {
+		if lf := lc.InfoFile; len(lf) > 0 {
+			f, _, err := zap.Open(lf)
+			if err != nil {
+				return nil, fmt.Errorf("open info log file: %w", err)
+			}
+			infoWriter = zapcore.Lock(f)
+		}
+		if lf := lc.ErrFile; len(lf) > 0 {
+			f, _, err := zap.Open(lf)
+			if err != nil {
+				return nil, fmt.Errorf("open err log file: %w", err)
+			}
+			errWriter = zapcore.Lock(f)
+		}
+	}
+
+	if applyGlobally {
+		if len(lc.Level) > 0 {
+			atomicLevel.SetLevel(lvl)
+		}
+		if infoWriter != nil {
+			atomicInfoWriter.Replace(infoWriter)
+		}
+		if errWriter != nil {
+			atomicErrWriter.Replace(errWriter)
+		}
+		return nil, nil
+	}
+
+	var levelEnabler zapcore.LevelEnabler
+	if len(lc.Level) == 0 {
+		levelEnabler = atomicLevel
+	} else {
+		levelEnabler = lvl
+	}
+	if infoWriter == nil {
+		infoWriter = atomicInfoWriter
+	}
+	if errWriter == nil {
+		errWriter = atomicErrWriter
+	}
+	return newLogger(levelEnabler, infoWriter, errWriter), nil
+}
+
+func newLogger(lvl zapcore.LevelEnabler, infoWriter, errWriter zapcore.WriteSyncer) *zap.Logger {
+	errLvl := zap.LevelEnablerFunc(func(l2 zapcore.Level) bool {
+		return lvl.Enabled(l2) && l2 >= zapcore.ErrorLevel
 	})
-	infoLvl := zap.LevelEnablerFunc(func(lvl zapcore.Level) bool {
-		return atomicLevel.Enabled(lvl) && lvl < zapcore.ErrorLevel
+	infoLvl := zap.LevelEnablerFunc(func(l2 zapcore.Level) bool {
+		return lvl.Enabled(l2) && l2 < zapcore.ErrorLevel
 	})
 
 	core := zapcore.NewTee(
-		zapcore.NewCore(zapcore.NewConsoleEncoder(defaultEncoderConfig()), atomicInfoWriter, infoLvl),
-		zapcore.NewCore(zapcore.NewConsoleEncoder(defaultEncoderConfig()), atomicErrWriter, errLvl),
+		zapcore.NewCore(zapcore.NewConsoleEncoder(defaultEncoderConfig()), infoWriter, infoLvl),
+		zapcore.NewCore(zapcore.NewConsoleEncoder(defaultEncoderConfig()), errWriter, errLvl),
 	)
 	return zap.New(core, zap.AddCaller())
 }
 
+// L returns a logger that has a lvl Level(), and will write
+// logs to InfoWriter() and ErrWriter().
+// The returned logger is shared by all L() call.
 func L() *zap.Logger {
 	return l
 }
 
+// S returns a sugared L.
+// The returned logger is shared by all S() call.
 func S() *zap.SugaredLogger {
 	return s
 }
 
+// NewPluginLogger returns a named logger from L.
 func NewPluginLogger(tag string) *zap.Logger {
 	return l.Named(tag)
 }
@@ -107,3 +203,18 @@ func (a *AtomicWriteSyncer) Sync() error {
 	ws := *(*zapcore.WriteSyncer)(atomic.LoadPointer(&a.ws))
 	return ws.Sync()
 }
+
+func parseLogLevel(s string) (zapcore.Level, bool) {
+	switch s {
+	case "debug":
+		return zap.DebugLevel, true
+	case "", "info":
+		return zap.InfoLevel, true
+	case "warn":
+		return zap.WarnLevel, true
+	case "error":
+		return zap.ErrorLevel, true
+	default:
+		return 0, false
+	}
+}