diff --git a/cmd/authd/daemon/config.go b/cmd/authd/daemon/config.go index 6bacb36fb..1d51970ce 100644 --- a/cmd/authd/daemon/config.go +++ b/cmd/authd/daemon/config.go @@ -87,18 +87,13 @@ func installConfigFlag(cmd *cobra.Command) *string { // SetVerboseMode change ErrorFormat and logs between very, middly and non verbose. func setVerboseMode(level int) { - var reportCaller bool switch level { case 0: log.SetLevel(consts.DefaultLogLevel) case 1: log.SetLevel(log.InfoLevel) - case 3: - reportCaller = true - fallthrough default: log.SetLevel(log.DebugLevel) slog.SetLogLoggerLevel(slog.LevelDebug) } - log.SetReportCaller(reportCaller) } diff --git a/cmd/authd/main.go b/cmd/authd/main.go index 392604715..a005c0c22 100644 --- a/cmd/authd/main.go +++ b/cmd/authd/main.go @@ -32,15 +32,6 @@ type app interface { func run(a app) int { defer installSignalHandler(a)() - log.SetFormatter(&log.TextFormatter{ - DisableLevelTruncation: true, - DisableTimestamp: true, - - // ForceColors is necessary on Windows, not only to have colors but to - // prevent logrus from falling back to structured logs. - ForceColors: true, - }) - if err := a.Run(); err != nil { log.Error(context.Background(), err) diff --git a/go.mod b/go.mod index e2bb697ed..e5663c7d0 100644 --- a/go.mod +++ b/go.mod @@ -11,7 +11,6 @@ require ( github.com/google/uuid v1.6.0 github.com/msteinert/pam/v2 v2.0.0 github.com/muesli/termenv v0.15.2 - github.com/sirupsen/logrus v1.9.3 github.com/skip2/go-qrcode v0.0.0-20200617195104-da1b6568686e github.com/spf13/cobra v1.8.1 github.com/spf13/viper v1.19.0 @@ -51,6 +50,7 @@ require ( github.com/sagikazarmark/locafero v0.4.0 // indirect github.com/sagikazarmark/slog-shim v0.1.0 // indirect github.com/sahilm/fuzzy v0.1.1 // indirect + github.com/sirupsen/logrus v1.9.3 // indirect github.com/sourcegraph/conc v0.3.0 // indirect github.com/spf13/afero v1.11.0 // indirect github.com/spf13/cast v1.6.0 // indirect diff --git a/internal/consts/consts.go b/internal/consts/consts.go index 43fb6fcfe..cd2b0bb89 100644 --- a/internal/consts/consts.go +++ b/internal/consts/consts.go @@ -1,7 +1,7 @@ // Package consts defines the constants used by the project package consts -import log "github.com/sirupsen/logrus" +import log "github.com/ubuntu/authd/internal/log" var ( // Version is the version of the executable. diff --git a/internal/log/log.go b/internal/log/log.go index 5a0276afc..903fe4230 100644 --- a/internal/log/log.go +++ b/internal/log/log.go @@ -4,65 +4,97 @@ package log import ( "context" "fmt" + "io" + "log/slog" "maps" "sync" - - "github.com/sirupsen/logrus" + "sync/atomic" ) type ( - // TextFormatter is the text formatter for the logs. - TextFormatter = logrus.TextFormatter - // Level is the log level for the logs. - Level = logrus.Level + Level = slog.Level // Handler is the log handler function. Handler = func(_ context.Context, _ Level, format string, args ...interface{}) ) -var ( - // GetLevel gets the standard logger level. - GetLevel = logrus.GetLevel - // IsLevelEnabled checks if the log level is greater than the level param. - IsLevelEnabled = logrus.IsLevelEnabled - // SetFormatter sets the standard logger formatter. - SetFormatter = logrus.SetFormatter - // SetLevel sets the standard logger level. - SetLevel = logrus.SetLevel - // SetOutput sets the log output. - SetOutput = logrus.SetOutput - // SetReportCaller sets whether the standard logger will include the calling method as a field. - SetReportCaller = logrus.SetReportCaller -) +var logLevelMu = sync.RWMutex{} +var logLevel slog.Level + +var hasCustomOutput atomic.Pointer[io.Writer] const ( // ErrorLevel level. Logs. Used for errors that should definitely be noted. // Commonly used for hooks to send errors to an error tracking service. - ErrorLevel = logrus.ErrorLevel + ErrorLevel = slog.LevelError // WarnLevel level. Non-critical entries that deserve eyes. - WarnLevel = logrus.WarnLevel + WarnLevel = slog.LevelWarn // InfoLevel level. General operational entries about what's going on inside the application. - InfoLevel = logrus.InfoLevel + InfoLevel = slog.LevelInfo // DebugLevel level. Usually only enabled when debugging. Very verbose logging. - DebugLevel = logrus.DebugLevel + DebugLevel = slog.LevelDebug ) -func logFuncAdapter(logrusFunc func(args ...interface{})) Handler { - return func(_ context.Context, _ Level, format string, args ...interface{}) { - logrusFunc(fmt.Sprintf(format, args...)) +func logFuncAdapter(slogFunc func(ctx context.Context, msg string, args ...interface{})) Handler { + return func(ctx context.Context, _ Level, format string, args ...interface{}) { + slogFunc(ctx, fmt.Sprintf(format, args...)) } } +var allLevels = []slog.Level{ + slog.LevelDebug, + slog.LevelInfo, + slog.LevelWarn, + slog.LevelError, +} + var defaultHandlers = map[Level]Handler{ - DebugLevel: logFuncAdapter(logrus.Debug), - InfoLevel: logFuncAdapter(logrus.Info), - WarnLevel: logFuncAdapter(logrus.Warn), - ErrorLevel: logFuncAdapter(logrus.Error), + DebugLevel: logFuncAdapter(slog.DebugContext), + InfoLevel: logFuncAdapter(slog.InfoContext), + WarnLevel: logFuncAdapter(slog.WarnContext), + ErrorLevel: logFuncAdapter(slog.ErrorContext), } var handlers = maps.Clone(defaultHandlers) var handlersMu = sync.RWMutex{} +// GetLevel gets the standard logger level. +func GetLevel() Level { + logLevelMu.RLock() + defer logLevelMu.RUnlock() + return logLevel +} + +// IsLevelEnabled checks if the log level is greater than the level param. +func IsLevelEnabled(level Level) bool { + return isLevelEnabled(context.Background(), level) +} + +func isLevelEnabled(context context.Context, level Level) bool { + return slog.Default().Enabled(context, level) +} + +// SetLevel sets the standard logger level. +func SetLevel(level Level) (oldLevel Level) { + logLevelMu.Lock() + defer func() { + logLevelMu.Unlock() + if outPtr := hasCustomOutput.Load(); outPtr != nil { + SetOutput(*outPtr) + } + }() + logLevel = level + return slog.SetLogLoggerLevel(level) +} + +// SetOutput sets the log output. +func SetOutput(out io.Writer) { + hasCustomOutput.Store(&out) + slog.SetDefault(slog.New(slog.NewTextHandler(out, &slog.HandlerOptions{ + Level: GetLevel(), + }))) +} + // SetLevelHandler allows to define the default handler function for a given level. func SetLevelHandler(level Level, handler Handler) { handlersMu.Lock() @@ -85,13 +117,13 @@ func SetHandler(handler Handler) { handlers = maps.Clone(defaultHandlers) return } - for _, level := range logrus.AllLevels { + for _, level := range allLevels { handlers[level] = handler } } func log(context context.Context, level Level, args ...interface{}) { - if !IsLevelEnabled(level) { + if !isLevelEnabled(context, level) { return } @@ -99,7 +131,7 @@ func log(context context.Context, level Level, args ...interface{}) { } func logf(context context.Context, level Level, format string, args ...interface{}) { - if !IsLevelEnabled(level) { + if !isLevelEnabled(context, level) { return } diff --git a/internal/log/log_test.go b/internal/log/log_test.go index 02753866c..7417a82cf 100644 --- a/internal/log/log_test.go +++ b/internal/log/log_test.go @@ -10,10 +10,10 @@ import ( ) var supportedLevels = []log.Level{ - log.ErrorLevel, - log.WarnLevel, - log.InfoLevel, log.DebugLevel, + log.InfoLevel, + log.WarnLevel, + log.ErrorLevel, } func TestLevelEnabled(t *testing.T) { @@ -146,17 +146,22 @@ func TestSetHandler(t *testing.T) { require.Equal(t, wantLevel, l, "Log level should match %v", l) require.Equal(t, fmt.Sprint(wantArgs...), format, "Format should match") }) - for _, level := range supportedLevels { + for idx, level := range supportedLevels { t.Run(fmt.Sprintf("Set log handler, testing level %s", level), func(t *testing.T) {}) wantLevel = level handlerCalled = false log.SetLevel(level) + fmt.Println("Logging at level", level) callLogHandler(wantCtx, level, wantArgs...) require.True(t, handlerCalled, "Handler should have been called") handlerCalled = false - log.SetLevel(level - 1) + nextLevel := level + 1 + if idx < len(supportedLevels)-1 { + nextLevel = supportedLevels[idx+1] + } + log.SetLevel(nextLevel) callLogHandler(wantCtx, level, wantArgs...) require.False(t, handlerCalled, "Handler should not have been called") } @@ -180,7 +185,7 @@ func TestSetHandler(t *testing.T) { require.Equal(t, wantFormat, format, "Format should match") require.Equal(t, wantArgs, args, "Arguments should match") }) - for _, level := range supportedLevels { + for idx, level := range supportedLevels { t.Run(fmt.Sprintf("Set log handler, testing level %s", level), func(t *testing.T) {}) wantLevel = level @@ -190,7 +195,11 @@ func TestSetHandler(t *testing.T) { require.True(t, handlerCalled, "Handler should have been called") handlerCalled = false - log.SetLevel(level - 1) + nextLevel := level + 1 + if idx < len(supportedLevels)-1 { + nextLevel = supportedLevels[idx+1] + } + log.SetLevel(nextLevel) callLogHandlerf(wantCtx, level, wantFormat, wantArgs...) require.False(t, handlerCalled, "Handler should not have been called") } diff --git a/internal/services/errmessages/redactor.go b/internal/services/errmessages/redactor.go index fe1b46d3a..1bea03721 100644 --- a/internal/services/errmessages/redactor.go +++ b/internal/services/errmessages/redactor.go @@ -5,8 +5,8 @@ import ( "context" "errors" "fmt" - "log/slog" + "github.com/ubuntu/authd/internal/log" "google.golang.org/grpc" "google.golang.org/grpc/codes" "google.golang.org/grpc/status" @@ -18,7 +18,7 @@ import ( func RedactErrorInterceptor(ctx context.Context, req any, _ *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (any, error) { m, err := handler(ctx, req) if err != nil { - slog.Warn(err.Error()) + log.Warning(context.TODO(), err.Error()) var redactedError ErrToDisplay if !errors.As(err, &redactedError) { return m, err diff --git a/internal/services/manager.go b/internal/services/manager.go index 7e4906570..d163af2db 100644 --- a/internal/services/manager.go +++ b/internal/services/manager.go @@ -3,7 +3,6 @@ package services import ( "context" - "log/slog" "github.com/ubuntu/authd" "github.com/ubuntu/authd/internal/brokers" @@ -69,7 +68,7 @@ func (m Manager) RegisterGRPCServices(ctx context.Context) *grpc.Server { // stop stops the underlying cache. func (m *Manager) stop() error { - slog.Debug("Closing grpc manager and cache") + log.Debug(context.TODO(), "Closing grpc manager and cache") return m.userManager.Stop() } diff --git a/internal/users/cache/delete.go b/internal/users/cache/delete.go index cd1b37112..161a21748 100644 --- a/internal/users/cache/delete.go +++ b/internal/users/cache/delete.go @@ -1,13 +1,14 @@ package cache import ( + "context" "encoding/json" "errors" "fmt" - "log/slog" "slices" "strconv" + "github.com/ubuntu/authd/internal/log" "github.com/ubuntu/decorate" "go.etcd.io/bbolt" ) @@ -107,7 +108,7 @@ func deleteUser(buckets map[string]bucketWithName, uid uint32) (err error) { // deleteOrphanedUsers removes users from the UserByID bucket that are not in the UserByName bucket. func deleteOrphanedUsers(db *bbolt.DB) error { - slog.Debug("Cleaning up orphaned user records") + log.Debug(context.TODO(), "Cleaning up orphaned user records") err := db.Update(func(tx *bbolt.Tx) error { buckets, err := getAllBuckets(tx) @@ -118,17 +119,17 @@ func deleteOrphanedUsers(db *bbolt.DB) error { return buckets[userByIDBucketName].ForEach(func(k, v []byte) error { var user UserDB if err := json.Unmarshal(v, &user); err != nil { - slog.Warn(fmt.Sprintf("Error loading user record {%s: %s}: %v", string(k), string(v), err)) + log.Warningf(context.TODO(), "Error loading user record {%s: %s}: %v", k, v, err) return nil } user2, err := getFromBucket[userDB](buckets[userByNameBucketName], user.Name) if err != nil && !errors.Is(err, NoDataFoundError{}) { - slog.Warn(fmt.Sprintf("Error loading user record %q: %v", user.Name, err)) + log.Warningf(context.TODO(), "Error loading user record %q: %v", user.Name, err) return nil } if errors.Is(err, NoDataFoundError{}) || user2.UID != user.UID { - slog.Warn(fmt.Sprintf("Removing orphaned user record %q with UID %d", user.Name, user.UID)) + log.Warningf(context.TODO(), "Removing orphaned user record %q with UID %d", user.Name, user.UID) return deleteOrphanedUser(buckets, user.UID) } @@ -139,7 +140,7 @@ func deleteOrphanedUsers(db *bbolt.DB) error { return err } - slog.Debug("Done cleaning up orphaned user records") + log.Debug(context.TODO(), "Done cleaning up orphaned user records") return nil } diff --git a/internal/users/cache/update.go b/internal/users/cache/update.go index f6b2d35e7..9abb49d7d 100644 --- a/internal/users/cache/update.go +++ b/internal/users/cache/update.go @@ -5,7 +5,6 @@ import ( "encoding/json" "errors" "fmt" - "log/slog" "slices" "strconv" "time" @@ -66,13 +65,13 @@ func updateUser(buckets map[string]bucketWithName, userContent userDB) error { // If a user with the same UID exists, we need to ensure that it's the same user or fail the update otherwise. if existingUser.Name != "" && existingUser.Name != userContent.Name { - slog.Error(fmt.Sprintf("UID for user %q already in use by user %q", userContent.Name, existingUser.Name)) + log.Errorf(context.TODO(), "UID for user %q already in use by user %q", userContent.Name, existingUser.Name) return errors.New("UID already in use by a different user") } // Ensure that we use the same homedir as the one we have in cache. if existingUser.Dir != "" && existingUser.Dir != userContent.Dir { - slog.Warn(fmt.Sprintf("User %q already has a homedir. The existing %q one will be kept instead of %q", userContent.Name, existingUser.Dir, userContent.Dir)) + log.Warningf(context.TODO(), "User %q already has a homedir. The existing %q one will be kept instead of %q", userContent.Name, existingUser.Dir, userContent.Dir) userContent.Dir = existingUser.Dir } @@ -94,7 +93,7 @@ func updateGroups(buckets map[string]bucketWithName, groupContents []GroupDB) er // If a group with the same GID exists, we need to ensure that it's the same group or fail the update otherwise. if existingGroup.Name != "" && existingGroup.Name != groupContent.Name { - slog.Error(fmt.Sprintf("GID %d for group %q already in use by group %q", groupContent.GID, groupContent.Name, existingGroup.Name)) + log.Errorf(context.TODO(), "GID %d for group %q already in use by group %q", groupContent.GID, groupContent.Name, existingGroup.Name) return fmt.Errorf("GID for group %q already in use by a different group", groupContent.Name) } diff --git a/internal/users/localgroups/localgroups.go b/internal/users/localgroups/localgroups.go index 708e120a5..16b4d2a8e 100644 --- a/internal/users/localgroups/localgroups.go +++ b/internal/users/localgroups/localgroups.go @@ -3,15 +3,16 @@ package localgroups import ( "bufio" + "context" "errors" "fmt" - "log/slog" "os" "os/exec" "slices" "strings" "sync" + "github.com/ubuntu/authd/internal/log" "github.com/ubuntu/decorate" ) @@ -248,7 +249,7 @@ func runGPasswd(cmdName string, args ...string) error { out, err := cmd.CombinedOutput() if err != nil { if cmd.ProcessState.ExitCode() == 3 { - slog.Info(fmt.Sprintf("ignoring gpasswd error: %s", out)) + log.Infof(context.TODO(), "ignoring gpasswd error: %s", out) return nil } return fmt.Errorf("%q returned: %v\nOutput: %s", strings.Join(cmd.Args, " "), err, out) diff --git a/internal/users/manager.go b/internal/users/manager.go index 1ec4e470d..c19b153cd 100644 --- a/internal/users/manager.go +++ b/internal/users/manager.go @@ -2,15 +2,16 @@ package users import ( + "context" "crypto/sha256" "encoding/binary" "errors" "fmt" - "log/slog" "os" "strings" "syscall" + "github.com/ubuntu/authd/internal/log" "github.com/ubuntu/authd/internal/users/cache" "github.com/ubuntu/authd/internal/users/localgroups" "github.com/ubuntu/decorate" @@ -40,7 +41,7 @@ type Manager struct { // NewManager creates a new user manager. func NewManager(config Config, cacheDir string) (m *Manager, err error) { - slog.Debug(fmt.Sprintf("Creating user manager with config: %+v", config)) + log.Debugf(context.TODO(), "Creating user manager with config: %+v", config) // Check that the ID ranges are valid. if config.UIDMin >= config.UIDMax { @@ -173,10 +174,10 @@ func checkHomeDirOwnership(u UserInfo) error { // Check if the home directory is owned by the user. if oldUID != newUID { - slog.Warn(fmt.Sprintf("Home directory %q is not owned by UID %d. To fix this, run `sudo chown -R --from=%d %d %s`.", u.Dir, oldUID, oldUID, newUID, u.Dir)) + log.Warningf(context.TODO(), "Home directory %q is not owned by UID %d. To fix this, run `sudo chown -R --from=%d %d %s`.", u.Dir, oldUID, oldUID, newUID, u.Dir) } if oldGID != newGID { - slog.Warn(fmt.Sprintf("Home directory %q is not owned by GID %d. To fix this, run `sudo chown -R --from=:%d :%d %s`.", u.Dir, oldGID, oldGID, newGID, u.Dir)) + log.Warningf(context.TODO(), "Home directory %q is not owned by GID %d. To fix this, run `sudo chown -R --from=:%d :%d %s`.", u.Dir, oldGID, oldGID, newGID, u.Dir) } return nil