Improve logger (#566)

* Improve logger - Try to log to jorunald if available - fallback to file writing if not - write to single file instead of appending times - add a locking mechanism so several processes cant write to the same file - prepend the PID of the process if we are running outside journald for easy tracking of grouped messages Signed-off-by: Itxaka <itxaka@kairos.io> * Simplify Signed-off-by: Itxaka <itxaka@kairos.io> --------- Signed-off-by: Itxaka <itxaka@kairos.io>
2025-09-19 09:35:35 +00:00 · 2025-02-24 11:34:54 +01:00
parent c52bfb5708
commit aa62f8ba73
3 changed files with 86 additions and 31 deletions
--- a/go.mod
+++ b/go.mod
@@ -9,7 +9,7 @@ require (
 	github.com/diskfs/go-diskfs v1.4.2
 	github.com/docker/docker v27.5.1+incompatible
 	github.com/edsrzf/mmap-go v1.2.0
-	github.com/foxboron/go-uefi 69fb7dba244f
+	github.com/foxboron/go-uefi v0.0.0-20250207204325-69fb7dba244f
 	github.com/google/go-containerregistry v0.20.3
 	github.com/google/shlex v0.0.0-20191202100458-e7afc7fbc510
 	github.com/hashicorp/go-multierror v1.1.1
@@ -50,6 +50,7 @@ require (
 	github.com/containerd/log v0.1.0 // indirect
 	github.com/containerd/stargz-snapshotter/estargz v0.16.3 // indirect
 	github.com/containerd/typeurl/v2 v2.2.3 // indirect
+	github.com/coreos/go-systemd/v22 v22.5.0 // indirect
 	github.com/cpuguy83/go-md2man/v2 v2.0.6 // indirect
 	github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc // indirect
 	github.com/distribution/reference v0.6.0 // indirect
--- a/go.sum
+++ b/go.sum
@@ -107,6 +107,7 @@ github.com/containerd/stargz-snapshotter/estargz v0.16.3 h1:7evrXtoh1mSbGj/pfRcc
 github.com/containerd/stargz-snapshotter/estargz v0.16.3/go.mod h1:uyr4BfYfOj3G9WBVE8cOlQmXAbPN9VEQpBBeJIuOipU=
 github.com/containerd/typeurl/v2 v2.2.3 h1:yNA/94zxWdvYACdYO8zofhrTVuQY73fFU1y++dYSw40=
 github.com/containerd/typeurl/v2 v2.2.3/go.mod h1:95ljDnPfD3bAbDJRugOiShd/DlAAsxGtUBhJxIn7SCk=
+github.com/coreos/go-systemd/v22 v22.5.0 h1:RrqgGjYQKalulkV8NGVIfkXQf6YYmOyiJKk8iXXhfZs=
 github.com/coreos/go-systemd/v22 v22.5.0/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc=
 github.com/cpuguy83/go-md2man/v2 v2.0.6 h1:XJtiaUW6dEEqVuZiMTn1ldk455QWwEIsMIJlo5vtkx0=
 github.com/cpuguy83/go-md2man/v2 v2.0.6/go.mod h1:oOW0eioCTA6cOiMLiUPZOpcVxMig6NIQQ7OS05n1F4g=
@@ -147,8 +148,8 @@ github.com/envoyproxy/go-control-plane v0.9.9-0.20201210154907-fd9021fe5dad/go.m
 github.com/envoyproxy/protoc-gen-validate v0.1.0/go.mod h1:iSmxcyjqTsJpI2R4NaDN7+kN2VEUnK/pcBlmesArF7c=
 github.com/felixge/httpsnoop v1.0.4 h1:NFTV2Zj1bL4mc9sqWACXbQFVBBg2W3GPvqp8/ESS2Wg=
 github.com/felixge/httpsnoop v1.0.4/go.mod h1:m8KPJKqk1gH5J9DgRY2ASl2lWCfGKXixSwevea8zH2U=
-github.com/foxboron/go-uefi v0.0.0-20241219185318-19dc140271bf h1:eKPYdh9Dq7P/Tc6GRt4HqqsVK8b2vt0IGP+xmZ8dMjo=
-github.com/foxboron/go-uefi v0.0.0-20241219185318-19dc140271bf/go.mod h1:q85c4IRlhhwdRJgGIUWrisDjU8dgcMj8dnXZCXo3hus=
+github.com/foxboron/go-uefi v0.0.0-20250207204325-69fb7dba244f h1:SGo7y1xmmGWiQzp7QU3ueehmdMVkjj9Yyo1IDEuHbYw=
+github.com/foxboron/go-uefi v0.0.0-20250207204325-69fb7dba244f/go.mod h1:q85c4IRlhhwdRJgGIUWrisDjU8dgcMj8dnXZCXo3hus=
 github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMoQvtojpjFo=
 github.com/fsnotify/fsnotify v1.4.9/go.mod h1:znqG4EE+3YCdAaPaxE2ZRY/06pZUdp0tY4IgpuI1SZQ=
 github.com/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA=
@@ -507,8 +508,8 @@ golang.org/x/mod v0.4.0/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
 golang.org/x/mod v0.4.1/go.mod h1:s0Qsj1ACt9ePp/hMypM3fl4fZqREWJwdYDEqhRiZZUA=
 golang.org/x/mod v0.6.0-dev.0.20220419223038-86c51ed26bb4/go.mod h1:jJ57K6gSWd91VN4djpZkiMVwK6gcyfeH4XE8wZrZaV4=
 golang.org/x/mod v0.8.0/go.mod h1:iBbtSCu2XBx23ZKBPSOrRkjjQPZFPuis4dIYUhu/chs=
-golang.org/x/mod v0.22.0 h1:D4nJWe9zXqHOmWqj4VMOJhvzj7bEZg4wEYa759z1pH4=
-golang.org/x/mod v0.22.0/go.mod h1:6SkKJ3Xj0I0BrPOZoBy3bdMptDDU9oJrpohJ3eWZ1fY=
+golang.org/x/mod v0.23.0 h1:Zb7khfcRGKk+kqfxFaP5tZqCnDZMjC5VtUBs87Hr6QM=
+golang.org/x/mod v0.23.0/go.mod h1:6SkKJ3Xj0I0BrPOZoBy3bdMptDDU9oJrpohJ3eWZ1fY=
 golang.org/x/net v0.0.0-20180724234803-3673e40ba225/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
 golang.org/x/net v0.0.0-20180826012351-8a410e7b638d/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
 golang.org/x/net v0.0.0-20180906233101-161cd47e91fd/go.mod h1:mL1N/T3taQHkDXs73rZJwtUhF3w3ftmwwsq0BUmARs4=
--- a/types/logger.go
+++ b/types/logger.go
@@ -4,35 +4,48 @@ import (
 	"bytes"
 	"fmt"
 	"io"
+	"net"
 	"os"
 	"path/filepath"
 	"strings"
 	"time"

 	"github.com/rs/zerolog"
+	"github.com/rs/zerolog/journald"
 )

+func isJournaldAvailable() bool {
+	conn, err := net.Dial("unixgram", "/run/systemd/journal/socket")
+	if err != nil {
+		return false
+	}
+	defer conn.Close()
+	return true
+}
+
 // NewKairosLogger creates a new logger with the given name and level.
-// The name is used to create a log file in /run/kairos/NAME-DATE.log and /var/log/kairos/NAME-DATE.log
 // The level is used to set the log level, defaulting to info
 // The log level can be overridden by setting the environment variable $NAME_DEBUG to any parseable value.
 // If quiet is true, the logger will not log to the console.
 func NewKairosLogger(name, level string, quiet bool) KairosLogger {
 	var loggers []io.Writer
 	var l zerolog.Level
+	var err error
+
+	// Add journald logger
+	if isJournaldAvailable() {
+		loggers = append(loggers, journald.NewJournalDWriter())
+	} else {
+		// Default to file logging
+		logName := fmt.Sprintf("%s.log", name)
+		_ = os.MkdirAll("/var/log/kairos/", os.ModeDir|os.ModePerm)
+		logFileName := filepath.Join("/var/log/kairos/", logName)
+
+		logfile, err := os.OpenFile(logFileName, os.O_APPEND|os.O_CREATE|os.O_WRONLY, 0644)
+		if err == nil {
+			loggers = append(loggers, zerolog.ConsoleWriter{Out: logfile, TimeFormat: time.RFC3339, NoColor: true})
+		}

-	// Have I ever mentioned how terrible the format of time is in golang?
-	// Whats with this 20060102150405 format? Do anyone actually remembers that?
-	logName := fmt.Sprintf("%s-%s.log", name, time.Now().Format("20060102150405.0000"))
-	_ = os.MkdirAll("/run/kairos/", os.ModeDir|os.ModePerm)
-	_ = os.MkdirAll("/var/log/kairos/", os.ModeDir|os.ModePerm)
-	logfileRun, err := os.Create(filepath.Join("/run/kairos/", logName))
-	if err == nil {
-		loggers = append(loggers, zerolog.ConsoleWriter{Out: logfileRun, TimeFormat: time.RFC3339, NoColor: true})
-	}
-	logfileVar, err := os.Create(filepath.Join("/var/log/kairos/", logName))
-	if err == nil {
-		loggers = append(loggers, zerolog.ConsoleWriter{Out: logfileVar, TimeFormat: time.RFC3339, NoColor: true})
 	}

 	if !quiet {
@@ -61,7 +74,7 @@ func NewKairosLogger(name, level string, quiet bool) KairosLogger {
 	}
 	k := KairosLogger{
 		zerolog.New(multi).With().Timestamp().Logger().Level(l),
-		loggers,
+		isJournaldAvailable(),
 	}

 	return k
@@ -70,21 +83,21 @@ func NewKairosLogger(name, level string, quiet bool) KairosLogger {
 func NewBufferLogger(b *bytes.Buffer) KairosLogger {
 	return KairosLogger{
 		zerolog.New(b).With().Timestamp().Logger(),
-		[]io.Writer{},
+		true,
 	}
 }

 func NewNullLogger() KairosLogger {
 	return KairosLogger{
 		zerolog.New(io.Discard).With().Timestamp().Logger(),
-		[]io.Writer{},
+		true,
 	}
 }

 // KairosLogger implements the bridge between zerolog and the logger.Interface that yip needs.
 type KairosLogger struct {
 	zerolog.Logger
-	logFiles []io.Writer
+	journald bool // Whether we are logging to journald, to avoid the file lock
 }

 func (m *KairosLogger) SetLevel(level string) {
@@ -101,65 +114,105 @@ func (m KairosLogger) IsDebug() bool {
 	return m.Logger.GetLevel() == zerolog.DebugLevel
 }

-// Close Try to close all log files
-func (m KairosLogger) Close() {
-	for _, f := range m.logFiles {
-		if c, ok := f.(io.Closer); ok {
-			_ = c.Close()
-		}
-	}
-}
-
 // Functions to implement the logger.Interface that most of our other stuff needs

 func (m KairosLogger) Infof(tpl string, args ...interface{}) {
+	if !m.journald {
+		// Add the pid to the log line so searching for it is easier
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Info().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Info(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Info().Msg(fmt.Sprint(args...))
 }
 func (m KairosLogger) Warnf(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Warn().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Warn(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Warn().Msg(fmt.Sprint(args...))
 }

 func (m KairosLogger) Warning(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Warn().Msg(fmt.Sprint(args...))
 }

 func (m KairosLogger) Warningf(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Warn().Msg(fmt.Sprintf(tpl, args...))
 }

 func (m KairosLogger) Debugf(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Debug().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Debug(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Debug().Msg(fmt.Sprint(args...))
 }
 func (m KairosLogger) Errorf(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Error().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Error(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Error().Msg(fmt.Sprint(args...))
 }
 func (m KairosLogger) Fatalf(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Fatal().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Fatal(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Fatal().Msg(fmt.Sprint(args...))
 }
 func (m KairosLogger) Panicf(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Panic().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Panic(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Panic().Msg(fmt.Sprint(args...))
 }
 func (m KairosLogger) Tracef(tpl string, args ...interface{}) {
+	if !m.journald {
+		tpl = fmt.Sprintf("[%v] ", os.Getpid()) + tpl
+	}
 	m.Logger.Trace().Msg(fmt.Sprintf(tpl, args...))
 }
 func (m KairosLogger) Trace(args ...interface{}) {
+	if !m.journald {
+		args = append([]interface{}{fmt.Sprintf("[%v]", os.Getpid())}, args...)
+	}
 	m.Logger.Trace().Msg(fmt.Sprint(args...))
 }