diff options
23 files changed, 136 insertions, 65 deletions
diff --git a/client/dial_test.go b/client/dial_test.go index c04f23046..ff3716e77 100644 --- a/client/dial_test.go +++ b/client/dial_test.go @@ -805,5 +805,5 @@ func startFakeGitalyServer(t *testing.T) string { } func newLogger(tb testing.TB) *logrus.Entry { - return testhelper.SharedLogger(tb).Entry + return testhelper.SharedLogger(tb).LogrusEntry() //nolint:staticcheck } diff --git a/cmd/gitaly-backup/main.go b/cmd/gitaly-backup/main.go index f663be660..6c12d1926 100644 --- a/cmd/gitaly-backup/main.go +++ b/cmd/gitaly-backup/main.go @@ -32,13 +32,15 @@ func main() { _ = flags.Parse(os.Args) if flags.NArg() < 2 { - logger.Fatal("missing subcommand") + logger.Error("missing subcommand") + os.Exit(1) } subcmdName := flags.Arg(1) subcmd, ok := subcommands[subcmdName] if !ok { - logger.Fatalf("unknown subcommand: %q", flags.Arg(1)) + logger.Errorf("unknown subcommand: %q", flags.Arg(1)) + os.Exit(1) } subcmdFlags := flag.NewFlagSet(subcmdName, flag.ExitOnError) @@ -47,10 +49,12 @@ func main() { ctx, err := storage.InjectGitalyServersEnv(context.Background()) if err != nil { - logger.Fatalf("%s", err) + logger.Errorf("%s", err) + os.Exit(1) } if err := subcmd.Run(ctx, logger, os.Stdin, os.Stdout); err != nil { - logger.Fatalf("%s", err) + logger.Errorf("%s", err) + os.Exit(1) } } diff --git a/cmd/gitaly-blackbox/main.go b/cmd/gitaly-blackbox/main.go index a0a520af3..b71ab54f7 100644 --- a/cmd/gitaly-blackbox/main.go +++ b/cmd/gitaly-blackbox/main.go @@ -50,7 +50,8 @@ func main() { prometheus.MustRegister(bb) if err := bb.Run(); err != nil { - logger.WithError(err).Fatal() + logger.WithError(err).Error("blackbox probe failed") + os.Exit(1) } } diff --git a/cmd/gitaly-lfs-smudge/main.go b/cmd/gitaly-lfs-smudge/main.go index 846d94a68..85d3fdc14 100644 --- a/cmd/gitaly-lfs-smudge/main.go +++ b/cmd/gitaly-lfs-smudge/main.go @@ -47,7 +47,7 @@ func main() { defer closer.Close() if err := run(ctx, os.Environ(), os.Stdout, os.Stdin, logger); err != nil { - logger.WithError(err).Error(err) + logger.WithError(err).Error("gitaly-lfs-smudge failed") os.Exit(1) } } diff --git a/cmd/gitaly-lfs-smudge/smudge.go b/cmd/gitaly-lfs-smudge/smudge.go index 3b5481acd..69554e766 100644 --- a/cmd/gitaly-lfs-smudge/smudge.go +++ b/cmd/gitaly-lfs-smudge/smudge.go @@ -311,7 +311,7 @@ func smudgeOneObject(ctx context.Context, cfg smudge.Config, gitlabClient *gitla } if err := response.Body.Close(); err != nil { - logger.WithError(err).Error("closing LFS pointer body: %w", err) + logger.WithError(err).Error("closing LFS pointer body failed") } return io.NopCloser(contents), nil diff --git a/cmd/gitaly-ssh/main.go b/cmd/gitaly-ssh/main.go index b34e99f32..4b4138abb 100644 --- a/cmd/gitaly-ssh/main.go +++ b/cmd/gitaly-ssh/main.go @@ -50,7 +50,8 @@ func main() { // < 4 since git throws on 2x garbage here if n := len(os.Args); n < 4 { // TODO: Errors needs to be sent back some other way... pipes? - logger.Fatalf("invalid number of arguments, expected at least 1, got %d", n-1) + logger.Errorf("invalid number of arguments, expected at least 1, got %d", n-1) + os.Exit(1) } command := os.Args[1] @@ -67,7 +68,8 @@ func main() { case "upload-archive": packer = uploadArchive default: - logger.Fatalf("invalid pack command: %q", command) + logger.Errorf("invalid pack command: %q", command) + os.Exit(1) } cmd := gitalySSHCommand{ @@ -80,7 +82,8 @@ func main() { code, err := cmd.run(logger) if err != nil { - logger.Printf("%s: %v", command, err) + logger.Infof("%s: %v", command, err) + os.Exit(1) } os.Exit(code) diff --git a/cmd/gitaly-wrapper/main.go b/cmd/gitaly-wrapper/main.go index c1ab2bc3b..fda9d04c0 100644 --- a/cmd/gitaly-wrapper/main.go +++ b/cmd/gitaly-wrapper/main.go @@ -36,7 +36,8 @@ func main() { logger = logger.WithField("wrapper", os.Getpid()) if len(os.Args) < 2 { - logger.Fatalf("usage: %s forking_binary [args]", os.Args[0]) + logger.Errorf("usage: %s forking_binary [args]", os.Args[0]) + os.Exit(1) } binary, arguments := os.Args[1], os.Args[2:] @@ -45,13 +46,15 @@ func main() { pidFilePath := os.Getenv(bootstrap.EnvPidFile) if pidFilePath == "" { - logger.Fatalf("missing pid file ENV variable %q", bootstrap.EnvPidFile) + logger.Errorf("missing pid file ENV variable %q", bootstrap.EnvPidFile) + os.Exit(1) } logger.WithField("pid_file", pidFilePath).Info("finding process") process, err := findProcess(pidFilePath) if err != nil && !isRecoverable(err) { - logger.WithError(err).Fatal("find process") + logger.WithError(err).Errorf("find process") + os.Exit(1) } else if err != nil { logger.WithError(err).Error("find process") } @@ -63,7 +66,8 @@ func main() { proc, err := spawnProcess(logger, binary, arguments) if err != nil { - logger.WithError(err).Fatal("spawn gitaly") + logger.WithError(err).Errorf("spawn gitaly") + os.Exit(1) } process = proc @@ -143,7 +147,7 @@ func forwardSignals(gitaly *os.Process, log log.Logger) { continue } - log.WithField("signal", sig).Warning("forwarding signal") + log.WithField("signal", sig).Warn("forwarding signal") if err := gitaly.Signal(sig); err != nil { log.WithField("signal", sig).WithError(err).Error("can't forward the signal") diff --git a/internal/cache/walker.go b/internal/cache/walker.go index aed509046..17d668f71 100644 --- a/internal/cache/walker.go +++ b/internal/cache/walker.go @@ -117,7 +117,7 @@ func (c *DiskCache) walkLoop(walkPath string) { } if err := c.cleanWalk(walkPath); err != nil { - logger.Error(err) + logger.WithError(err).Error("disk cache cleanup failed") } select { diff --git a/internal/cli/praefect/subcmd_dataloss.go b/internal/cli/praefect/subcmd_dataloss.go index 80b3d7366..f685221a2 100644 --- a/internal/cli/praefect/subcmd_dataloss.go +++ b/internal/cli/praefect/subcmd_dataloss.go @@ -86,7 +86,7 @@ func datalossAction(ctx *cli.Context) error { } defer func() { if err := conn.Close(); err != nil { - logger.Printf("error closing connection: %v\n", err) + logger.Infof("error closing connection: %v\n", err) } }() diff --git a/internal/command/command_test.go b/internal/command/command_test.go index ad1b5fd6c..209e84b3b 100644 --- a/internal/command/command_test.go +++ b/internal/command/command_test.go @@ -494,7 +494,7 @@ func TestCommand_logMessage(t *testing.T) { t.Parallel() logger := testhelper.NewLogger(t) - logger.Logger.SetLevel(logrus.DebugLevel) + logger.LogrusEntry().Logger.SetLevel(logrus.DebugLevel) //nolint:staticcheck hook := testhelper.AddLoggerHook(logger) ctx := logger.ToContext(testhelper.Context(t)) diff --git a/internal/git/localrepo/refs.go b/internal/git/localrepo/refs.go index fe38e93c3..984f916b7 100644 --- a/internal/git/localrepo/refs.go +++ b/internal/git/localrepo/refs.go @@ -164,7 +164,7 @@ func (repo *Repo) setDefaultBranchWithTransaction(ctx context.Context, txManager } defer func() { if err := lockingFileWriter.Close(); err != nil { - log.FromContext(ctx).WithError(err).Error("closing locked HEAD: %w", err) + log.FromContext(ctx).WithError(err).Error("closing locked HEAD failed") } }() diff --git a/internal/gitaly/repoutil/lock.go b/internal/gitaly/repoutil/lock.go index 3bbf30716..f0c13d29a 100644 --- a/internal/gitaly/repoutil/lock.go +++ b/internal/gitaly/repoutil/lock.go @@ -41,7 +41,7 @@ func Lock(ctx context.Context, locator storage.Locator, repository storage.Repos unlock := func() { if err := locker.Close(); err != nil { - log.FromContext(ctx).Error("closing repository locker: %w", err) + log.FromContext(ctx).WithError(err).Error("closing repository locker failed") } } diff --git a/internal/gitaly/service/repository/rename.go b/internal/gitaly/service/repository/rename.go index 296d59e5c..29c35085e 100644 --- a/internal/gitaly/service/repository/rename.go +++ b/internal/gitaly/service/repository/rename.go @@ -62,7 +62,7 @@ func (s *server) renameRepository(ctx context.Context, sourceRepo, targetRepo *g } defer func() { if err := sourceLocker.Close(); err != nil { - log.FromContext(ctx).Error("closing source repo locker: %w", err) + log.FromContext(ctx).WithError(err).Error("closing source repo locker failed") } }() @@ -72,7 +72,7 @@ func (s *server) renameRepository(ctx context.Context, sourceRepo, targetRepo *g } defer func() { if err := targetLocker.Close(); err != nil { - log.FromContext(ctx).Error("closing target repo locker: %w", err) + log.FromContext(ctx).WithError(err).Error("closing target repo locker failed") } }() diff --git a/internal/gitaly/storage/storagemgr/database.go b/internal/gitaly/storage/storagemgr/database.go index 24146f44a..526c7eda6 100644 --- a/internal/gitaly/storage/storagemgr/database.go +++ b/internal/gitaly/storage/storagemgr/database.go @@ -2,19 +2,28 @@ package storagemgr import ( "github.com/dgraph-io/badger/v4" + "gitlab.com/gitlab-org/gitaly/v16/internal/log" ) // OpenDatabase opens a new database handle to a database at the given path. -func OpenDatabase(logger badger.Logger, databasePath string) (*badger.DB, error) { +func OpenDatabase(logger log.Logger, databasePath string) (*badger.DB, error) { dbOptions := badger.DefaultOptions(databasePath) // Enable SyncWrites to ensure all writes are persisted to disk before considering // them committed. dbOptions.SyncWrites = true - dbOptions.Logger = logger + dbOptions.Logger = badgerLogger{logger} return badger.Open(dbOptions) } +type badgerLogger struct { + log.Logger +} + +func (l badgerLogger) Warningf(msg string, args ...any) { + l.Warnf(msg, args...) +} + // databaseAdapter adapts a *badger.DB to the internal database interface used by the hooks in tests. type databaseAdapter struct{ *badger.DB } diff --git a/internal/grpc/backchannel/backchannel.go b/internal/grpc/backchannel/backchannel.go index f5cbe05bf..d992ecb84 100644 --- a/internal/grpc/backchannel/backchannel.go +++ b/internal/grpc/backchannel/backchannel.go @@ -29,6 +29,7 @@ package backchannel import ( + "fmt" "net" "sync" @@ -36,13 +37,30 @@ import ( "gitlab.com/gitlab-org/gitaly/v16/internal/log" ) +type yamuxLogWrapper struct { + logger log.Logger +} + +func (l yamuxLogWrapper) Print(args ...any) { + l.logger.Info(fmt.Sprint(args...)) +} + +func (l yamuxLogWrapper) Printf(format string, args ...any) { + l.logger.Infof(format, args...) +} + +func (l yamuxLogWrapper) Println(args ...any) { + msg := fmt.Sprintln(args...) + l.logger.Info(msg[:len(msg)-1]) +} + // magicBytes are sent by the client to server to identify as a multiplexing aware client. var magicBytes = []byte("backchannel") // muxConfig returns a new config to use with the multiplexing session. func muxConfig(logger log.Logger, cfg Configuration) *yamux.Config { yamuxCfg := yamux.DefaultConfig() - yamuxCfg.Logger = logger + yamuxCfg.Logger = yamuxLogWrapper{logger} yamuxCfg.LogOutput = nil // gRPC is already configured to send keep alives so we don't need yamux to do this for us. // gRPC is a better choice as it sends the keep alives also to non-multiplexed connections. diff --git a/internal/grpc/middleware/cache/cache.go b/internal/grpc/middleware/cache/cache.go index b9d5474ba..39dab9596 100644 --- a/internal/grpc/middleware/cache/cache.go +++ b/internal/grpc/middleware/cache/cache.go @@ -16,7 +16,7 @@ import ( func methodErrLogger(logger log.Logger, method string) func(error) { return func(err error) { countMethodErr(method) - logger.WithField("full_method_name", method).Error(err) + logger.WithField("full_method_name", method).Error(err.Error()) } } diff --git a/internal/grpc/middleware/featureflag/featureflag_handler_test.go b/internal/grpc/middleware/featureflag/featureflag_handler_test.go index f0b62f1b8..45eb31d80 100644 --- a/internal/grpc/middleware/featureflag/featureflag_handler_test.go +++ b/internal/grpc/middleware/featureflag/featureflag_handler_test.go @@ -39,7 +39,7 @@ func TestFeatureFlagLogs(t *testing.T) { server := grpc.NewServer( grpc.ChainUnaryInterceptor( grpcmwlogrus.UnaryServerInterceptor( - logger.Entry, + logger.LogrusEntry(), //nolint:staticcheck grpcmwlogrus.WithMessageProducer( log.MessageProducer( grpcmwlogrus.DefaultMessageProducer, diff --git a/internal/log/logger.go b/internal/log/logger.go index 9ed4aab73..a1baac5c8 100644 --- a/internal/log/logger.go +++ b/internal/log/logger.go @@ -20,30 +20,13 @@ type Logger interface { Debugf(format string, args ...any) Infof(format string, args ...any) - Printf(format string, args ...any) Warnf(format string, args ...any) - Warningf(format string, args ...any) Errorf(format string, args ...any) - Fatalf(format string, args ...any) - Panicf(format string, args ...any) - - Debug(args ...any) - Info(args ...any) - Print(args ...any) - Warn(args ...any) - Warning(args ...any) - Error(args ...any) - Fatal(args ...any) - Panic(args ...any) - - Debugln(args ...any) - Infoln(args ...any) - Println(args ...any) - Warnln(args ...any) - Warningln(args ...any) - Errorln(args ...any) - Fatalln(args ...any) - Panicln(args ...any) + + Debug(msg string) + Info(msg string) + Warn(msg string) + Error(msg string) StreamServerInterceptor(...grpcmwlogrus.Option) grpc.StreamServerInterceptor UnaryServerInterceptor(...grpcmwlogrus.Option) grpc.UnaryServerInterceptor @@ -51,49 +34,98 @@ type Logger interface { // LogrusLogger is an implementation of the Logger interface that is implemented via a `logrus.FieldLogger`. type LogrusLogger struct { - *logrus.Entry + entry *logrus.Entry } // FromLogrusEntry constructs a new Gitaly-specific logger from a `logrus.Logger`. func FromLogrusEntry(entry *logrus.Entry) LogrusLogger { - return LogrusLogger{Entry: entry} + return LogrusLogger{entry: entry} +} + +// LogrusEntry returns the `logrus.Entry` that backs this logger. Note that this interface only exists during the +// transition period and will be eventually removed. It is thus heavily discouraged to use it. +// +// Deprecated: This will be removed once all callsites have been converted to do something that is independent of the +// logrus logger. +func (l LogrusLogger) LogrusEntry() *logrus.Entry { + return l.entry } // WithField creates a new logger with the given field appended. func (l LogrusLogger) WithField(key string, value any) Logger { - return LogrusLogger{Entry: l.Entry.WithField(key, value)} + return LogrusLogger{entry: l.entry.WithField(key, value)} } // WithFields creates a new logger with the given fields appended. func (l LogrusLogger) WithFields(fields Fields) Logger { - return LogrusLogger{Entry: l.Entry.WithFields(fields)} + return LogrusLogger{entry: l.entry.WithFields(fields)} } // WithError creates a new logger with an appended error field. func (l LogrusLogger) WithError(err error) Logger { - return LogrusLogger{Entry: l.Entry.WithError(err)} + return LogrusLogger{entry: l.entry.WithError(err)} +} + +// Debugf writes a formatted log message at debug level. +func (l LogrusLogger) Debugf(format string, args ...any) { + l.entry.Debugf(format, args...) +} + +// Infof writes a formatted log message at info level. +func (l LogrusLogger) Infof(format string, args ...any) { + l.entry.Infof(format, args...) +} + +// Warnf writes a formatted log message at warn level. +func (l LogrusLogger) Warnf(format string, args ...any) { + l.entry.Warnf(format, args...) +} + +// Errorf writes a formatted log message at error level. +func (l LogrusLogger) Errorf(format string, args ...any) { + l.entry.Errorf(format, args...) +} + +// Debug writes a log message at debug level. +func (l LogrusLogger) Debug(msg string) { + l.entry.Debug(msg) +} + +// Info writes a log message at info level. +func (l LogrusLogger) Info(msg string) { + l.entry.Info(msg) +} + +// Warn writes a log message at warn level. +func (l LogrusLogger) Warn(msg string) { + l.entry.Warn(msg) +} + +// Error writes a log message at error level. +func (l LogrusLogger) Error(msg string) { + l.entry.Error(msg) } // ToContext injects the logger into the given context so that it can be retrieved via `FromContext()`. func (l LogrusLogger) ToContext(ctx context.Context) context.Context { - return ctxlogrus.ToContext(ctx, l.Entry) + return ctxlogrus.ToContext(ctx, l.entry) } // StreamServerInterceptor creates a gRPC interceptor that generates log messages for streaming RPC calls. func (l LogrusLogger) StreamServerInterceptor(opts ...grpcmwlogrus.Option) grpc.StreamServerInterceptor { - return grpcmwlogrus.StreamServerInterceptor(l.Entry, opts...) + return grpcmwlogrus.StreamServerInterceptor(l.entry, opts...) } // UnaryServerInterceptor creates a gRPC interceptor that generates log messages for unary RPC calls. func (l LogrusLogger) UnaryServerInterceptor(opts ...grpcmwlogrus.Option) grpc.UnaryServerInterceptor { - return grpcmwlogrus.UnaryServerInterceptor(l.Entry, opts...) + return grpcmwlogrus.UnaryServerInterceptor(l.entry, opts...) } // FromContext extracts the logger from the context. If no logger has been injected then this will return a discarding // logger. func FromContext(ctx context.Context) LogrusLogger { return LogrusLogger{ - Entry: ctxlogrus.Extract(ctx), + entry: ctxlogrus.Extract(ctx), } } diff --git a/internal/log/middleware.go b/internal/log/middleware.go index d177132d2..4cb82541a 100644 --- a/internal/log/middleware.go +++ b/internal/log/middleware.go @@ -190,7 +190,7 @@ func UnaryLogDataCatcherServerInterceptor() grpc.UnaryServerInterceptor { return func(ctx context.Context, req interface{}, info *grpc.UnaryServerInfo, handler grpc.UnaryHandler) (interface{}, error) { mpp := messageProducerPropagationFrom(ctx) if mpp != nil { - mpp.fields = FromContext(ctx).Entry.Data + mpp.fields = FromContext(ctx).entry.Data } return handler(ctx, req) } @@ -203,7 +203,7 @@ func StreamLogDataCatcherServerInterceptor() grpc.StreamServerInterceptor { ctx := ss.Context() mpp := messageProducerPropagationFrom(ctx) if mpp != nil { - mpp.fields = FromContext(ctx).Entry.Data + mpp.fields = FromContext(ctx).entry.Data } return handler(srv, ss) } diff --git a/internal/praefect/repocleaner/repository_test.go b/internal/praefect/repocleaner/repository_test.go index ed5f55bb8..94501ea6c 100644 --- a/internal/praefect/repocleaner/repository_test.go +++ b/internal/praefect/repocleaner/repository_test.go @@ -287,7 +287,7 @@ func TestRunner_Run_noAvailableStorages(t *testing.T) { defer close(releaseFirst) logger := testhelper.NewLogger(t) - logger.Logger.SetLevel(logrus.DebugLevel) + logger.LogrusEntry().Logger.SetLevel(logrus.DebugLevel) //nolint:staticcheck loggerHook := testhelper.AddLoggerHook(logger) runner := NewRunner(cfg, logger, praefect.StaticHealthChecker{virtualStorage: []string{storage1}}, nodeSet.Connections(), storageCleanup, storageCleanup, actionStub{ diff --git a/internal/tempdir/clean.go b/internal/tempdir/clean.go index 489fefab3..cb97f1968 100644 --- a/internal/tempdir/clean.go +++ b/internal/tempdir/clean.go @@ -67,7 +67,7 @@ func clean(logger log.Logger, locator storage.Locator, storage config.Storage) e // If we start "cleaning up" the wrong directory we may delete user data // which is Really Bad. if !strings.HasSuffix(dir, tmpRootPrefix) { - logger.Print(dir) + logger.Info(dir) panic(invalidCleanRoot("invalid tempdir clean root: panicking to prevent data loss")) } diff --git a/internal/testhelper/logger.go b/internal/testhelper/logger.go index bac918e51..8e47d4ec1 100644 --- a/internal/testhelper/logger.go +++ b/internal/testhelper/logger.go @@ -103,7 +103,7 @@ type LoggerHook struct { // AddLoggerHook installs a hook on the logger. func AddLoggerHook(logger log.LogrusLogger) LoggerHook { - return LoggerHook{hook: test.NewLocal(logger.Logger)} + return LoggerHook{hook: test.NewLocal(logger.LogrusEntry().Logger)} //nolint:staticcheck } // AllEntries returns all log entries that have been intercepted by the hook. diff --git a/internal/testhelper/testserver/praefect.go b/internal/testhelper/testserver/praefect.go index 4024a69e4..59331264c 100644 --- a/internal/testhelper/testserver/praefect.go +++ b/internal/testhelper/testserver/praefect.go @@ -64,7 +64,7 @@ func StartPraefect(tb testing.TB, cfg config.Config) PraefectServer { // Redirect log output of the server to the Praefect server logger. This will cause us to write logs into a // Praefect-specific logger. - logWriter := testhelper.NewLogger(tb, testhelper.WithLoggerName("praefect")).Entry.WithField("component", "praefect").Writer() + logWriter := testhelper.NewLogger(tb, testhelper.WithLoggerName("praefect")).LogrusEntry().WithField("component", "praefect").Writer() //nolint:staticcheck tb.Cleanup(func() { testhelper.MustClose(tb, logWriter) }) cmd := exec.Command(binaryPath, "-config", configFilePath) |