opt: improve logging logic

eventloop_unix.go

@@ -62,6 +62,10 @@ type internalEventloop struct {
 	eventHandler EventHandler    // user eventHandler
 }
 
+func (el *eventloop) getLogger() logging.Logger {
+	return el.svr.opts.Logger
+}
+
 func (el *eventloop) addConn(delta int32) {
 	atomic.AddInt32(&el.connCount, delta)
 }
@@ -90,7 +94,7 @@ func (el *eventloop) loopRun(lockOSThread bool) {
 	}()
 
 	err := el.poller.Polling(el.handleEvent)
-	logging.Infof("Event-loop(%d) is exiting due to error: %v", el.idx, err)
+	el.getLogger().Infof("Event-loop(%d) is exiting due to error: %v", el.idx, err)
 }
 
 func (el *eventloop) loopAccept(fd int) error {
@@ -277,8 +281,8 @@ func (el *eventloop) loopTicker(ctx context.Context) {
 		switch action {
 		case None:
 		case Shutdown:
-			_ = el.poller.UrgentTrigger(func(_ []byte) error { return gerrors.ErrServerShutdown })
-			// logging.Debugf("stopping ticker in event-loop(%d) from Tick(), UrgentTrigger:%v", el.idx, err)
+			err := el.poller.UrgentTrigger(func(_ []byte) error { return gerrors.ErrServerShutdown })
+			el.getLogger().Debugf("stopping ticker in event-loop(%d) from Tick(), UrgentTrigger:%v", el.idx, err)
 		}
 		if timer == nil {
 			timer = time.NewTimer(delay)
@@ -287,7 +291,7 @@ func (el *eventloop) loopTicker(ctx context.Context) {
 		}
 		select {
 		case <-ctx.Done():
-			// logging.Debugf("stopping ticker in event-loop(%d) from Server, error:%v", el.idx, ctx.Err())
+			el.getLogger().Debugf("stopping ticker in event-loop(%d) from Server, error:%v", el.idx, ctx.Err())
 			return
 		case <-timer.C:
 		}

eventloop_windows.go

@@ -52,6 +52,10 @@ type internalEventloop struct {
 	eventHandler EventHandler          // user eventHandler
 }
 
+func (el *eventloop) getLogger() logging.Logger {
+	return el.svr.opts.Logger
+}
+
 func (el *eventloop) addConn(delta int32) {
 	atomic.AddInt32(&el.connCount, delta)
 }
@@ -96,9 +100,10 @@ func (el *eventloop) loopRun(lockOSThread bool) {
 		}
 
 		if err == errors.ErrServerShutdown {
+			el.getLogger().Infof("Event-loop(%d) is exiting in terms of the demand from user, %v", el.idx, err)
 			break
 		} else if err != nil {
-			logging.Infof("Event-loop(%d) is exiting due to the error: %v", el.idx, err)
+			el.getLogger().Errorf("Event-loop(%d) is exiting due to the error: %v", el.idx, err)
 		}
 	}
 }
@@ -186,7 +191,7 @@ func (el *eventloop) loopTicker(ctx context.Context) {
 		delay, action = el.eventHandler.Tick()
 		if action == Shutdown {
 			el.ch <- errors.ErrServerShutdown
-			// logging.Debugf("stopping ticker in event-loop(%d) from Tick()", el.idx)
+			el.getLogger().Debugf("stopping ticker in event-loop(%d) from Tick()", el.idx)
 		}
 		if timer == nil {
 			timer = time.NewTimer(delay)
@@ -195,7 +200,7 @@ func (el *eventloop) loopTicker(ctx context.Context) {
 		}
 		select {
 		case <-ctx.Done():
-			// logging.Debugf("stopping ticker in event-loop(%d) from Server, error:%v", el.idx, ctx.Err())
+			el.getLogger().Debugf("stopping ticker in event-loop(%d) from Server, error:%v", el.idx, ctx.Err())
 			return
 		case <-timer.C:
 		}
@@ -209,7 +214,7 @@ func (el *eventloop) loopError(c *stdConn, err error) (e error) {
 		}
 
 		if err = c.conn.Close(); err != nil {
-			logging.Warnf("Failed to close connection(%s), error: %v", c.remoteAddr.String(), err)
+			el.getLogger().Warnf("Failed to close connection(%s), error: %v", c.remoteAddr.String(), err)
 			if e == nil {
 				e = err
 			}

gnet.go

@@ -248,18 +248,26 @@ func (es *EventServer) Tick() (delay time.Duration, action Action) {
 func Serve(eventHandler EventHandler, protoAddr string, opts ...Option) (err error) {
 	options := loadOptions(opts...)
 
-	logging.Init(options.LogLevel)
-
+	var (
+		logger logging.Logger
+		flush  func() error
+	)
 	if options.LogPath != "" {
-		err = logging.SetupLoggerWithPath(options.LogPath, options.LogLevel)
-	}
-	if err != nil {
-		return
+		if logger, flush, err = logging.CreateLoggerAsLocalFile(options.LogPath, options.LogLevel); err != nil {
+			return
+		}
+	} else {
+		logger = logging.DefaultLogger
 	}
-	if options.Logger != nil {
-		logging.SetupLogger(options.Logger, options.LogLevel)
+	if options.Logger == nil {
+		options.Logger = logger
 	}
-	defer logging.Cleanup()
+	defer func() {
+		if flush != nil {
+			_ = flush()
+		}
+		logging.Cleanup()
+	}()
 
 	// The maximum number of operating system threads that the Go program can use is initially set to 10000,
 	// which should be the maximum amount of I/O event-loops locked to OS threads users can start up.

internal/logging/logger.go

@@ -43,15 +43,16 @@ import (
 var (
 	// DefaultLogger is the default logger inside the tbuspp client.
 	DefaultLogger Logger
-	zapLogger     *zap.Logger
-	loggingLevel  zapcore.Level
+	// LogLevel is for the default logger.
+	LogLevel  zapcore.Level
+	zapLogger *zap.Logger
 )
 
-// Init initializes the inside default logger of client.
-func Init(logLevel zapcore.Level) {
+func init() {
+	// Initializes the inside default logger of client.
 	cfg := zap.NewDevelopmentConfig()
-	loggingLevel = logLevel
-	cfg.Level = zap.NewAtomicLevelAt(logLevel)
+	LogLevel = zapcore.DebugLevel
+	cfg.Level = zap.NewAtomicLevelAt(LogLevel)
 	zapLogger, _ = cfg.Build()
 	DefaultLogger = zapLogger.Sugar()
 }
@@ -63,40 +64,30 @@ func getEncoder() zapcore.Encoder {
 	return zapcore.NewConsoleEncoder(encoderConfig)
 }
 
-// SetupLoggerWithPath setups the logger by local file path.
-func SetupLoggerWithPath(localPath string, logLevel zapcore.Level) (err error) {
-	if len(localPath) == 0 {
-		return errors.New("invalid local logger path")
+// CreateLoggerAsLocalFile setups the logger by local file path.
+func CreateLoggerAsLocalFile(localFilePath string, logLevel zapcore.Level) (logger Logger, flush func() error, err error) {
+	if len(localFilePath) == 0 {
+		return nil, nil, errors.New("invalid local logger path")
 	}
 
 	// lumberjack.Logger is already safe for concurrent use, so we don't need to lock it.
 	w := &lumberjack.Logger{
-		Filename:   localPath,
+		Filename:   localFilePath,
 		MaxSize:    100, // megabytes
 		MaxBackups: 3,
 		MaxAge:     28, // days
 	}
 
-	loggingLevel = logLevel
 	encoder := getEncoder()
 	syncer := zapcore.AddSync(w)
 	highPriority := zap.LevelEnablerFunc(func(level zapcore.Level) bool {
 		return level >= logLevel
 	})
 	core := zapcore.NewCore(encoder, syncer, highPriority)
 	zapLogger := zap.New(core, zap.AddCaller())
-	DefaultLogger = zapLogger.Sugar()
-	return nil
-}
-
-// SetupLogger setups the logger by the Logger interface.
-func SetupLogger(logger Logger, logLevel zapcore.Level) {
-	if logger == nil {
-		return
-	}
-	loggingLevel = logLevel
-	zapLogger = nil
-	DefaultLogger = logger
+	logger = zapLogger.Sugar()
+	flush = zapLogger.Sync
+	return
 }
 
 // Cleanup does something windup for logger, like closing, flushing, etc.
@@ -113,11 +104,6 @@ func LogErr(err error) {
 	}
 }
 
-// Level returns the logging level.
-func Level() zapcore.Level {
-	return loggingLevel
-}
-
 // Debugf logs messages at DEBUG level.
 func Debugf(format string, args ...interface{}) {
 	DefaultLogger.Debugf(format, args...)

internal/netpoll/queue/queue.go

@@ -31,7 +31,7 @@ type Task struct {
 	Buf []byte
 }
 
-var taskPool = sync.Pool{New: func() interface{} { return &Task{} }}
+var taskPool = sync.Pool{New: func() interface{} { return new(Task) }}
 
 // GetTask gets a cached Task from pool.
 func GetTask() *Task {

reactor_bsd.go

@@ -25,7 +25,7 @@ package gnet
 import (
 	"runtime"
 
-	"github.com/panjf2000/gnet/internal/logging"
+	"github.com/panjf2000/gnet/errors"
 	"github.com/panjf2000/gnet/internal/netpoll"
 )
 
@@ -38,7 +38,11 @@ func (svr *server) activateMainReactor(lockOSThread bool) {
 	defer svr.signalShutdown()
 
 	err := svr.mainLoop.poller.Polling(func(fd int, filter int16) error { return svr.acceptNewConnection(fd) })
-	logging.Infof("Main reactor is exiting due to error: %v", err)
+	if err == errors.ErrServerShutdown {
+		svr.opts.Logger.Debugf("main reactor is exiting in terms of the demand from user, %v", err)
+	} else if err != nil {
+		svr.opts.Logger.Infof("main reactor is exiting due to error: %v", err)
+	}
 }
 
 func (svr *server) activateSubReactor(el *eventloop, lockOSThread bool) {
@@ -65,5 +69,9 @@ func (svr *server) activateSubReactor(el *eventloop, lockOSThread bool) {
 		}
 		return
 	})
-	logging.Infof("Event-loop(%d) is exiting normally on the signal error: %v", el.idx, err)
+	if err == errors.ErrServerShutdown {
+		svr.opts.Logger.Debugf("Event-loop(%d) is exiting in terms of the demand from user, %v", el.idx, err)
+	} else if err != nil {
+		svr.opts.Logger.Errorf("Event-loop(%d) is exiting normally on the signal error: %v", el.idx, err)
+	}
 }

reactor_linux.go

@@ -23,7 +23,7 @@ package gnet
 import (
 	"runtime"
 
-	"github.com/panjf2000/gnet/internal/logging"
+	"github.com/panjf2000/gnet/errors"
 	"github.com/panjf2000/gnet/internal/netpoll"
 )
 
@@ -36,7 +36,11 @@ func (svr *server) activateMainReactor(lockOSThread bool) {
 	defer svr.signalShutdown()
 
 	err := svr.mainLoop.poller.Polling(func(fd int, ev uint32) error { return svr.acceptNewConnection(fd) })
-	logging.Infof("Main reactor is exiting due to error: %v", err)
+	if err == errors.ErrServerShutdown {
+		svr.opts.Logger.Debugf("main reactor is exiting in terms of the demand from user, %v", err)
+	} else if err != nil {
+		svr.opts.Logger.Infof("main reactor is exiting due to error: %v", err)
+	}
 }
 
 func (svr *server) activateSubReactor(el *eventloop, lockOSThread bool) {
@@ -81,5 +85,9 @@ func (svr *server) activateSubReactor(el *eventloop, lockOSThread bool) {
 		}
 		return nil
 	})
-	logging.Infof("Event-loop(%d) is exiting normally on the signal error: %v", el.idx, err)
+	if err == errors.ErrServerShutdown {
+		svr.opts.Logger.Debugf("Event-loop(%d) is exiting in terms of the demand from user, %v", el.idx, err)
+	} else if err != nil {
+		svr.opts.Logger.Errorf("Event-loop(%d) is exiting normally on the signal error: %v", el.idx, err)
+	}
 }

server_unix.go

@@ -30,7 +30,6 @@ import (
 	"sync/atomic"
 
 	"github.com/panjf2000/gnet/errors"
-	"github.com/panjf2000/gnet/internal/logging"
 	"github.com/panjf2000/gnet/internal/netpoll"
 )
 
@@ -201,17 +200,23 @@ func (svr *server) stop(s Server) {
 
 	// Notify all loops to close by closing all listeners
 	svr.lb.iterate(func(i int, el *eventloop) bool {
-		logging.LogErr(el.poller.UrgentTrigger(func(_ []byte) error {
+		err := el.poller.UrgentTrigger(func(_ []byte) error {
 			return errors.ErrServerShutdown
-		}))
+		})
+		if err != nil {
+			svr.opts.Logger.Errorf("failed to call UrgentTrigger on sub event-loop when stopping server")
+		}
 		return true
 	})
 
 	if svr.mainLoop != nil {
 		svr.ln.close()
-		logging.LogErr(svr.mainLoop.poller.UrgentTrigger(func(_ []byte) error {
+		err := svr.mainLoop.poller.UrgentTrigger(func(_ []byte) error {
 			return errors.ErrServerShutdown
-		}))
+		})
+		if err != nil {
+			svr.opts.Logger.Errorf("failed to call UrgentTrigger on main event-loop when stopping server")
+		}
 	}
 
 	// Wait on all loops to complete reading events
@@ -220,7 +225,10 @@ func (svr *server) stop(s Server) {
 	svr.closeEventLoops()
 
 	if svr.mainLoop != nil {
-		logging.LogErr(svr.mainLoop.poller.Close())
+		err := svr.mainLoop.poller.Close()
+		if err != nil {
+			svr.opts.Logger.Errorf("failed to close poller when stopping server")
+		}
 	}
 
 	// Stop the ticker.
@@ -282,7 +290,7 @@ func serve(eventHandler EventHandler, listener *listener, options *Options, prot
 
 	if err := svr.start(numEventLoop); err != nil {
 		svr.closeEventLoops()
-		logging.Errorf("gnet server is stopping with error: %v", err)
+		svr.opts.Logger.Errorf("gnet server is stopping with error: %v", err)
 		return err
 	}
 	defer svr.stop(server)

server_windows.go

@@ -29,7 +29,6 @@ import (
 	"sync/atomic"
 
 	gerrors "github.com/panjf2000/gnet/errors"
-	"github.com/panjf2000/gnet/internal/logging"
 )
 
 var errCloseAllConns = errors.New("close all connections in event-loop")
@@ -114,7 +113,7 @@ func (svr *server) startEventLoops(numEventLoop int) {
 
 func (svr *server) stop(s Server) {
 	// Wait on a signal for shutdown.
-	logging.Infof("Server is being shutdown on the signal error: %v", svr.waitForShutdown())
+	svr.opts.Logger.Infof("Server is being shutdown on the signal error: %v", svr.waitForShutdown())
 
 	svr.eventHandler.OnShutdown(s)