Move to logging contexts

Also restructured config_tx so it doesn't need copies of config data.

Author: IDisposable

internal/logging/pion.go

@@ -48,8 +48,8 @@ func (c pionLogger) Errorf(format string, args ...any) {
 type pionLoggerFactory struct{}
 
 func (c pionLoggerFactory) NewLogger(subsystem string) logging.LeveledLogger {
-	logger := rootLogger.getLogger(subsystem).With().
-		Str("scope", "pion").
+	logger := GetSubsystemLogger("pion").
+		With().
 		Str("component", subsystem).
 		Logger()
 

internal/logging/utils.go

@@ -93,17 +93,22 @@ func LogError(context zerolog.Context, err error, msg string, args ...any) error
 	return err
 }
 
+func LogAlways(context zerolog.Context, msg string, args ...any) {
+	logger := context.Logger()
+	logger.Log().Msgf(msg, args...)
+}
+
 func LogFatal(context zerolog.Context, err error, msg string, args ...any) error {
 	context, err = AddRequiredError(context, err, msg, args...)
 	logger := context.Logger()
-	logger.Fatal().Msgf(msg, args...)
+	logger.Fatal().AnErr("err", err).Msgf(msg, args...)
 	return err
 }
 
 func LogPanic(context zerolog.Context, err error, msg string, args ...any) error {
 	context, err = AddRequiredError(context, err, msg, args...)
 	logger := context.Logger()
-	logger.Panic().Msgf(msg, args...)
+	logger.Panic().AnErr("err", err).Msgf(msg, args...)
 	return err
 }
 

internal/usbgadget/changeset.go

@@ -8,7 +8,9 @@ import (
 	"reflect"
 	"time"
 
+	"github.com/jetkvm/kvm/internal/logging"
 	"github.com/prometheus/procfs"
+	"github.com/rs/zerolog"
 	"github.com/sourcegraph/tf-dag/dag"
 )
 
@@ -194,15 +196,15 @@ func (fc *FileChange) checkIfDirIsMountPoint() error {
 }
 
 // GetActualState returns the actual state of the file at the given path.
-func (fc *FileChange) getActualState() error {
-	l := defaultLogger.With().Str("path", fc.Path).Logger()
+func (fc *FileChange) getActualState(loggingContext *zerolog.Context) error {
+	context := loggingContext.Str("path", fc.Path)
 
 	fi, err := os.Lstat(fc.Path)
 	if err != nil {
 		if os.IsNotExist(err) {
 			fc.ActualState = FileStateAbsent
 		} else {
-			l.Warn().Err(err).Msg("failed to stat file")
+			_ = logging.LogWarnE(context, err, "failed to stat file")
 			fc.ActualState = FileStateUnknown
 		}
 		return nil
@@ -214,15 +216,15 @@ func (fc *FileChange) getActualState() error {
 		// get the target of the symlink
 		target, err := os.Readlink(fc.Path)
 		if err != nil {
-			l.Warn().Err(err).Msg("failed to read symlink")
+			_ = logging.LogWarnE(context, err, "failed to read symlink")
 			return fmt.Errorf("failed to read symlink")
 		}
 		// check if the target is a relative path
 		if !filepath.IsAbs(target) {
 			// make it absolute
 			target, err = filepath.Abs(filepath.Join(filepath.Dir(fc.Path), target))
 			if err != nil {
-				l.Warn().Err(err).Msg("failed to make symlink target absolute")
+				_ = logging.LogWarnE(context, err, "failed to make symlink target absolute")
 				return fmt.Errorf("failed to make symlink target absolute")
 			}
 		}
@@ -237,22 +239,20 @@ func (fc *FileChange) getActualState() error {
 		case FileStateMountedConfigFS:
 			err := fc.checkIfDirIsMountPoint()
 			if err != nil {
-				l.Warn().Err(err).Msg("failed to check if dir is mount point")
-				return err
+				return logging.LogWarnE(context, err, "failed to check if dir is mount point")
 			}
 		case FileStateSymlinkInOrderConfigFS:
-			state, err := checkIfSymlinksInOrder(fc, &l)
+			state, err := checkIfSymlinksInOrder(fc, &context)
 			if err != nil {
-				l.Warn().Err(err).Msg("failed to check if symlinks are in order")
-				return err
+				return logging.LogWarnE(context, err, "failed to check if symlinks are in order")
 			}
 			fc.ActualState = state
 		}
 		return nil
 	}
 
 	if fi.Mode()&os.ModeDevice == os.ModeDevice {
-		l.Info().Msg("file is a device")
+		logging.LogInfo(context, "file is a device")
 		return nil
 	}
 
@@ -262,15 +262,14 @@ func (fc *FileChange) getActualState() error {
 		// get the content of the file
 		content, err := os.ReadFile(fc.Path)
 		if err != nil {
-			l.Warn().Err(err).Msg("failed to read file")
+			logging.LogWarnE(context, err, "failed to read file")
 			return fmt.Errorf("failed to read file")
 		}
 		fc.ActualContent = content
 		return nil
 	}
 
-	l.Warn().Interface("file_info", fi.Mode()).Bool("is_dir", fi.IsDir()).Msg("unknown file type")
-
+	logging.LogWarn(context.Interface("file_info", fi.Mode()).Bool("is_dir", fi.IsDir()), "unknown file type")
 	return fmt.Errorf("unknown file type")
 }
 
@@ -280,18 +279,16 @@ func (fc *FileChange) ResetActionResolution() {
 	fc.changed = ChangeStateUnknown
 }
 
-func (fc *FileChange) Action() FileChangeResolvedAction {
+func (fc *FileChange) Action(loggingContext *zerolog.Context) FileChangeResolvedAction {
 	if !fc.checked {
-		fc.action = fc.getFileChangeResolvedAction()
+		fc.action = fc.getFileChangeResolvedAction(loggingContext)
 		fc.checked = true
 	}
 
 	return fc.action
 }
 
-func (fc *FileChange) getFileChangeResolvedAction() FileChangeResolvedAction {
-	l := defaultLogger.With().Str("path", fc.Path).Logger()
-
+func (fc *FileChange) getFileChangeResolvedAction(loggingContext *zerolog.Context) FileChangeResolvedAction {
 	// some actions are not needed to be checked
 	switch fc.ExpectedState {
 	case FileStateFileWrite:
@@ -300,8 +297,10 @@ func (fc *FileChange) getFileChangeResolvedAction() FileChangeResolvedAction {
 		return FileChangeResolvedActionTouch
 	}
 
+	context := loggingContext.Interface("expected_state", FileStateString[fc.ExpectedState])
+
 	// get the actual state of the file
-	err := fc.getActualState()
+	err := fc.getActualState(&context)
 	if err != nil {
 		return FileChangeResolvedActionDoNothing
 	}
@@ -348,7 +347,7 @@ func (fc *FileChange) getFileChangeResolvedAction() FileChangeResolvedAction {
 		}
 		return FileChangeResolvedActionCreateSymlink
 	case FileStateSymlinkInOrderConfigFS:
-		// if the file is already a symlink, check if the target is the same
+		// if the file is already a symlink to configfs, check if the target is the same
 		if fc.ActualState == FileStateSymlinkInOrderConfigFS {
 			return FileChangeResolvedActionDoNothing
 		}
@@ -364,7 +363,7 @@ func (fc *FileChange) getFileChangeResolvedAction() FileChangeResolvedAction {
 		}
 		return FileChangeResolvedActionMountConfigFS
 	default:
-		l.Warn().Interface("file_change", FileStateString[fc.ExpectedState]).Msg("unknown expected state")
+		logging.LogWarn(context, "unknown expected state")
 		return FileChangeResolvedActionDoNothing
 	}
 }
@@ -387,18 +386,19 @@ func (c *ChangeSet) AddFileChange(component string, path string, expectedState F
 	})
 }
 
-func (c *ChangeSet) ApplyChanges() error {
+func (c *ChangeSet) ApplyChanges(loggingContext *zerolog.Context) error {
 	r := ChangeSetResolver{
 		changeset: c,
 		g:         &dag.AcyclicGraph{},
-		l:         defaultLogger,
 	}
 
-	return r.Apply()
+	return r.Apply(loggingContext)
 }
 
-func (c *ChangeSet) applyChange(change *FileChange) error {
-	switch change.Action() {
+func (c *ChangeSet) applyChange(change *FileChange, loggingContext *zerolog.Context) error {
+	action := change.Action(loggingContext)
+
+	switch action {
 	case FileChangeResolvedActionWriteFile:
 		return os.WriteFile(change.Path, change.ExpectedContent, 0644)
 	case FileChangeResolvedActionUpdateFile:
@@ -413,7 +413,7 @@ func (c *ChangeSet) applyChange(change *FileChange) error {
 		}
 		return os.Symlink(string(change.ExpectedContent), change.Path)
 	case FileChangeResolvedActionReorderSymlinks:
-		return recreateSymlinks(change, nil)
+		return recreateSymlinks(change, loggingContext)
 	case FileChangeResolvedActionCreateDirectory:
 		return os.MkdirAll(change.Path, 0755)
 	case FileChangeResolvedActionRemove:
@@ -427,10 +427,10 @@ func (c *ChangeSet) applyChange(change *FileChange) error {
 	case FileChangeResolvedActionDoNothing:
 		return nil
 	default:
-		return fmt.Errorf("unknown action: %d", change.Action())
+		return fmt.Errorf("unknown action: %d", action)
 	}
 }
 
-func (c *ChangeSet) Apply() error {
-	return c.ApplyChanges()
+func (c *ChangeSet) Apply(loggingContext *zerolog.Context) error {
+	return c.ApplyChanges(loggingContext)
 }

internal/usbgadget/changeset_arm_test.go

@@ -75,20 +75,20 @@ var oldAbsoluteMouseCombinedReportDesc = []byte{
 
 func TestUsbGadgetInit(t *testing.T) {
 	assert := assert.New(t)
-	usbGadget = NewUsbGadget(usbGadgetName, usbDevices, usbConfig, nil)
+	usbGadget = NewUsbGadget(usbGadgetName, usbDevices, usbConfig)
 
 	assert.NotNil(usbGadget)
 }
 
 func TestUsbGadgetStrictModeInitFail(t *testing.T) {
 	usbConfig.strictMode = true
-	u := NewUsbGadget("test", usbDevices, usbConfig, nil)
+	u := NewUsbGadget("test", usbDevices, usbConfig)
 	assert.Nil(t, u, "should be nil")
 }
 
 func TestUsbGadgetUDCNotBoundAfterReportDescrChanged(t *testing.T) {
 	assert := assert.New(t)
-	usbGadget = NewUsbGadget(usbGadgetName, usbDevices, usbConfig, nil)
+	usbGadget = NewUsbGadget(usbGadgetName, usbDevices, usbConfig)
 	assert.NotNil(usbGadget)
 
 	// release the usb gadget and create a new one
@@ -100,7 +100,7 @@ func TestUsbGadgetUDCNotBoundAfterReportDescrChanged(t *testing.T) {
 	oldAbsoluteMouseConfig.reportDesc = oldAbsoluteMouseCombinedReportDesc
 	altGadgetConfig["absolute_mouse"] = oldAbsoluteMouseConfig
 
-	usbGadget = newUsbGadget(usbGadgetName, altGadgetConfig, usbDevices, usbConfig, nil)
+	usbGadget = newUsbGadget(usbGadgetName, altGadgetConfig, usbDevices, usbConfig)
 	assert.NotNil(usbGadget)
 
 	udcs := getUdcs()