common: fix unclosed logrus logging pipes

Author: lzap

cmd/osbuild-composer/main.go

@@ -80,10 +80,12 @@ func main() {
 	}
 
 	logrus.Info("Loaded configuration:")
-	err = DumpConfig(*config, logrus.StandardLogger().WriterLevel(logrus.InfoLevel))
+	dumpWriter := logrus.StandardLogger().WriterLevel(logrus.DebugLevel)
+	err = DumpConfig(*config, dumpWriter)
 	if err != nil {
 		logrus.Fatalf("Error printing configuration: %v", err)
 	}
+	dumpWriter.Close()
 
 	if config.DeploymentChannel != "" {
 		logrus.AddHook(&slogger.EnvironmentHook{Channel: config.DeploymentChannel})

cmd/osbuild-worker/main.go

@@ -190,11 +190,13 @@ var run = func() {
 	}
 
 	logrus.Info("Composer configuration:")
-	encoder := toml.NewEncoder(logrus.StandardLogger().WriterLevel(logrus.InfoLevel))
+	configWriter := logrus.StandardLogger().WriterLevel(logrus.DebugLevel)
+	encoder := toml.NewEncoder(configWriter)
 	err = encoder.Encode(&config)
 	if err != nil {
 		logrus.Fatalf("Could not print config: %v", err)
 	}
+	configWriter.Close()
 
 	if config.DeploymentChannel != "" {
 		logrus.AddHook(&slogger.EnvironmentHook{Channel: config.DeploymentChannel})

internal/common/echo_logrus.go

@@ -4,22 +4,41 @@ import (
 	"context"
 	"encoding/json"
 	"io"
+	"runtime"
 
 	lslog "github.com/labstack/gommon/log"
 	"github.com/sirupsen/logrus"
 )
 
-// EchoLogrusLogger extend logrus.Logger
+// EchoLogrusLogger extend logrus.Logger to implement Echo's Logger interface.
 type EchoLogrusLogger struct {
-	*logrus.Logger
-	Ctx context.Context
+	logger *logrus.Logger
+	ctx    context.Context
+	writer *io.PipeWriter
+}
+
+// NewEchoLogrusLogger creates a new EchoLogrusLogger instance. Logger must be closed
+// with Close() method to avoid memory leaks.
+func NewEchoLogrusLogger(logger *logrus.Logger, ctx context.Context) *EchoLogrusLogger {
+	return &EchoLogrusLogger{
+		logger: logger,
+		ctx:    ctx,
+		writer: logger.Writer(),
+	}
+}
+
+var commonLogger *EchoLogrusLogger
+
+func init() {
+	commonLogger = NewEchoLogrusLogger(logrus.StandardLogger(), context.Background())
+	runtime.SetFinalizer(commonLogger, close)
 }
 
-var commonLogger = &EchoLogrusLogger{
-	Logger: logrus.StandardLogger(),
-	Ctx:    context.Background(),
+func close(l *EchoLogrusLogger) {
+	l.Close()
 }
 
+// Logger returns the common logger configured with logrus StandardLogger and context.Background().
 func Logger() *EchoLogrusLogger {
 	return commonLogger
 }
@@ -39,16 +58,23 @@ func toEchoLevel(level logrus.Level) lslog.Lvl {
 	return lslog.OFF
 }
 
+func (l *EchoLogrusLogger) Close() {
+	if l.writer != nil {
+		l.writer.Close()
+		l.writer = nil
+	}
+}
+
 func (l *EchoLogrusLogger) Output() io.Writer {
-	return l.Out
+	return l.writer
 }
 
 func (l *EchoLogrusLogger) SetOutput(w io.Writer) {
 	// disable operations that would change behavior of global logrus logger.
 }
 
 func (l *EchoLogrusLogger) Level() lslog.Lvl {
-	return toEchoLevel(l.Logger.Level)
+	return toEchoLevel(l.logger.Level)
 }
 
 func (l *EchoLogrusLogger) SetLevel(v lslog.Lvl) {
@@ -66,117 +92,119 @@ func (l *EchoLogrusLogger) SetPrefix(p string) {
 }
 
 func (l *EchoLogrusLogger) Print(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Print(i...)
+	l.logger.WithContext(l.ctx).Print(i...)
 }
 
 func (l *EchoLogrusLogger) Printf(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Printf(format, args...)
+	l.logger.WithContext(l.ctx).Printf(format, args...)
 }
 
 func (l *EchoLogrusLogger) Printj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Println(string(b))
+	l.logger.WithContext(l.ctx).Println(string(b))
 }
 
 func (l *EchoLogrusLogger) Debug(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Debug(i...)
+	l.logger.WithContext(l.ctx).Debug(i...)
 }
 
 func (l *EchoLogrusLogger) Debugf(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Debugf(format, args...)
+	l.logger.WithContext(l.ctx).Debugf(format, args...)
 }
 
 func (l *EchoLogrusLogger) Debugj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Debugln(string(b))
+	l.logger.WithContext(l.ctx).Debugln(string(b))
 }
 
 func (l *EchoLogrusLogger) Info(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Info(i...)
+	l.logger.WithContext(l.ctx).Info(i...)
 }
 
 func (l *EchoLogrusLogger) Infof(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Infof(format, args...)
+	l.logger.WithContext(l.ctx).Infof(format, args...)
 }
 
 func (l *EchoLogrusLogger) Infoj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Infoln(string(b))
+	l.logger.WithContext(l.ctx).Infoln(string(b))
 }
 
 func (l *EchoLogrusLogger) Warn(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Warn(i...)
+	l.logger.WithContext(l.ctx).Warn(i...)
 }
 
 func (l *EchoLogrusLogger) Warnf(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Warnf(format, args...)
+	l.logger.WithContext(l.ctx).Warnf(format, args...)
 }
 
 func (l *EchoLogrusLogger) Warnj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Warnln(string(b))
+	l.logger.WithContext(l.ctx).Warnln(string(b))
 }
 
 func (l *EchoLogrusLogger) Error(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Error(i...)
+	l.logger.WithContext(l.ctx).Error(i...)
 }
 
 func (l *EchoLogrusLogger) Errorf(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Errorf(format, args...)
+	l.logger.WithContext(l.ctx).Errorf(format, args...)
 }
 
 func (l *EchoLogrusLogger) Errorj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Errorln(string(b))
+	l.logger.WithContext(l.ctx).Errorln(string(b))
 }
 
 func (l *EchoLogrusLogger) Fatal(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Fatal(i...)
+	l.logger.WithContext(l.ctx).Fatal(i...)
 }
 
 func (l *EchoLogrusLogger) Fatalf(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Fatalf(format, args...)
+	l.logger.WithContext(l.ctx).Fatalf(format, args...)
 }
 
 func (l *EchoLogrusLogger) Fatalj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Fatalln(string(b))
+	l.logger.WithContext(l.ctx).Fatalln(string(b))
 }
 
 func (l *EchoLogrusLogger) Panic(i ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Panic(i...)
+	l.logger.WithContext(l.ctx).Panic(i...)
 }
 
 func (l *EchoLogrusLogger) Panicf(format string, args ...interface{}) {
-	l.Logger.WithContext(l.Ctx).Panicf(format, args...)
+	l.logger.WithContext(l.ctx).Panicf(format, args...)
 }
 
 func (l *EchoLogrusLogger) Panicj(j lslog.JSON) {
 	b, err := json.Marshal(j)
 	if err != nil {
 		panic(err)
 	}
-	l.Logger.WithContext(l.Ctx).Panicln(string(b))
+	l.logger.WithContext(l.ctx).Panicln(string(b))
 }
 
+// Write method is heavily used by the stdlib log package and called
+// from the weldr API.
 func (l *EchoLogrusLogger) Write(p []byte) (n int, err error) {
-	return l.Logger.WithContext(l.Ctx).Writer().Write(p)
+	return l.writer.Write(p)
 }

internal/common/logger_middleware.go

@@ -8,11 +8,10 @@ import (
 // Store context in request logger to propagate correlation ids
 func LoggerMiddleware(next echo.HandlerFunc) echo.HandlerFunc {
 	return func(c echo.Context) error {
-		c.SetLogger(&EchoLogrusLogger{
-			Logger: logrus.StandardLogger(),
-			Ctx:    c.Request().Context(),
-		})
+		ell := NewEchoLogrusLogger(logrus.StandardLogger(), c.Request().Context())
+		defer ell.Close()
 
+		c.SetLogger(ell)
 		return next(c)
 	}
 }