diff options
author | karthik nayak <knayak@gitlab.com> | 2023-08-15 13:11:44 +0300 |
---|---|---|
committer | karthik nayak <knayak@gitlab.com> | 2023-08-15 13:11:44 +0300 |
commit | 5bdafbc7693c7dfacc1c0932cfa8d62004c7097b (patch) | |
tree | c2cf71ae883a07c38ec90d4cb81301044fcef9fd | |
parent | d179ec93f38825fb373ce6b2692e4beb58a9e463 (diff) | |
parent | 9b2c13df769467811da5e1b958daac59262aa999 (diff) |
Merge branch 'pks-log-stop-using-standard-logger-pt1' into 'master'
log: Refactor to stop using standard logger (pt.1)
See merge request https://gitlab.com/gitlab-org/gitaly/-/merge_requests/6218
Merged-by: karthik nayak <knayak@gitlab.com>
Approved-by: karthik nayak <knayak@gitlab.com>
Reviewed-by: karthik nayak <knayak@gitlab.com>
Co-authored-by: Patrick Steinhardt <psteinhardt@gitlab.com>
30 files changed, 108 insertions, 122 deletions
diff --git a/.golangci.yml b/.golangci.yml index aaca0828f..80720509c 100644 --- a/.golangci.yml +++ b/.golangci.yml @@ -70,17 +70,11 @@ linters-settings: - (net.Listener).Close forbidigo: forbid: - # Tests and code which use timing-based setups have repeatedly resulted - # in flaky tests and are considered a code smell. Tests should be - # rewritten to use deterministic timing sources like tickers. Using the - # following functions is thus disallowed. and a code smell. - - ^context.WithDeadline$ - - ^context.WithTimeout$ - # Tests should always use `testhelper.Context()`: this context has - # special handling for feature flags which allows us to assert that - # they're tested as expected. - - ^context.Background$ - - ^context.TODO$ + - p: ^logrus\.(Debug,Error,Fatal,Info,Panic,Print,Trace,Warn,Warning)(f|ln)?$ + msg: Use the logger provided by `log.Default()` or `ctxlogrus.Extract()`. + - p: ^logrus\.StandardLogger$ + msg: Use the logger provided by `log.Default()` or `ctxlogrus.Extract()`. + analyze-types: true paralleltest: # Ignore missing calls to `t.Parallel()` and only report incorrect uses of it. ignore-missing: true @@ -150,11 +144,6 @@ linters-settings: issues: exclude-use-default: false - exclude-rules: - - linters: - - forbidigo - # This fine thing excludes all paths which don't end with "_test.go". - path: "^([^_]|_([^t]|t([^e]|e([^s]|s([^t]|t([^\\.]|\\.([^g]|g[^o])))))))*$" # Maximum issues count per one linter. Set to 0 to disable. Default is 50. max-issues-per-linter: 0 # Maximum count of issues with the same text. Set to 0 to disable. Default is 3. diff --git a/client/dial.go b/client/dial.go index 2d7fc18e3..5d5c6d190 100644 --- a/client/dial.go +++ b/client/dial.go @@ -5,11 +5,11 @@ import ( "math/rand" "time" - "github.com/sirupsen/logrus" "gitlab.com/gitlab-org/gitaly/v16/internal/backoff" "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/client" "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/dnsresolver" "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/sidechannel" + "gitlab.com/gitlab-org/gitaly/v16/internal/log" "google.golang.org/grpc" healthpb "google.golang.org/grpc/health/grpc_health_v1" ) @@ -80,7 +80,7 @@ func DefaultDNSResolverBuilderConfig() *DNSResolverBuilderConfig { return &DNSResolverBuilderConfig{ RefreshRate: 5 * time.Minute, LookupTimeout: 15 * time.Second, - Logger: logrus.StandardLogger(), + Logger: log.Default(), Backoff: backoff.NewDefaultExponential(rand.New(rand.NewSource(time.Now().UnixNano()))), DefaultGrpcPort: "443", } diff --git a/client/sidechannel.go b/client/sidechannel.go index 4375d780a..b9ccf8f4a 100644 --- a/client/sidechannel.go +++ b/client/sidechannel.go @@ -16,11 +16,11 @@ import ( // gRPC calls. type SidechannelRegistry struct { registry *sidechannel.Registry - logger *logrus.Entry + logger logrus.FieldLogger } // NewSidechannelRegistry returns a new registry. -func NewSidechannelRegistry(logger *logrus.Entry) *SidechannelRegistry { +func NewSidechannelRegistry(logger logrus.FieldLogger) *SidechannelRegistry { return &SidechannelRegistry{ registry: sidechannel.NewRegistry(), logger: logger, diff --git a/cmd/gitaly-backup/create.go b/cmd/gitaly-backup/create.go index c53869e02..010f1055a 100644 --- a/cmd/gitaly-backup/create.go +++ b/cmd/gitaly-backup/create.go @@ -9,7 +9,7 @@ import ( "runtime" "time" - log "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus" "gitlab.com/gitlab-org/gitaly/v16/client" "gitlab.com/gitlab-org/gitaly/v16/internal/backup" "gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/storage" @@ -44,7 +44,7 @@ func (cmd *createSubcommand) Flags(fs *flag.FlagSet) { fs.BoolVar(&cmd.serverSide, "server-side", false, "use server-side backups. Note: The feature is not ready for production use.") } -func (cmd *createSubcommand) Run(ctx context.Context, stdin io.Reader, stdout io.Writer) error { +func (cmd *createSubcommand) Run(ctx context.Context, logger logrus.FieldLogger, stdin io.Reader, stdout io.Writer) error { pool := client.NewPool(internalclient.UnaryInterceptor(), internalclient.StreamInterceptor()) defer pool.Close() @@ -70,7 +70,7 @@ func (cmd *createSubcommand) Run(ctx context.Context, stdin io.Reader, stdout io } var pipeline backup.Pipeline - pipeline = backup.NewLoggingPipeline(log.StandardLogger()) + pipeline = backup.NewLoggingPipeline(logger) if cmd.parallel > 0 || cmd.parallelStorage > 0 { pipeline = backup.NewParallelPipeline(pipeline, cmd.parallel, cmd.parallelStorage) } diff --git a/cmd/gitaly-backup/create_test.go b/cmd/gitaly-backup/create_test.go index 66895335f..145a161d1 100644 --- a/cmd/gitaly-backup/create_test.go +++ b/cmd/gitaly-backup/create_test.go @@ -61,7 +61,7 @@ func TestCreateSubcommand(t *testing.T) { require.NoError(t, fs.Parse([]string{"-path", path, "-id", "the-new-backup"})) require.EqualError(t, - cmd.Run(ctx, &stdin, io.Discard), + cmd.Run(ctx, testhelper.NewDiscardingLogger(t), &stdin, io.Discard), "create: pipeline: 1 failures encountered:\n - invalid: manager: could not dial source: invalid connection string: \"invalid\"\n") for _, repo := range repos { @@ -118,7 +118,7 @@ func TestCreateSubcommand_serverSide(t *testing.T) { require.NoError(t, fs.Parse([]string{"-server-side", "-id", "the-new-backup"})) require.EqualError(t, - cmd.Run(ctx, &stdin, io.Discard), + cmd.Run(ctx, testhelper.NewDiscardingLogger(t), &stdin, io.Discard), "create: pipeline: 1 failures encountered:\n - invalid: server-side create: could not dial source: invalid connection string: \"invalid\"\n") for _, repo := range repos { diff --git a/cmd/gitaly-backup/main.go b/cmd/gitaly-backup/main.go index 3f3d02315..287342dec 100644 --- a/cmd/gitaly-backup/main.go +++ b/cmd/gitaly-backup/main.go @@ -6,13 +6,14 @@ import ( "io" "os" + "github.com/sirupsen/logrus" "gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/storage" "gitlab.com/gitlab-org/gitaly/v16/internal/log" ) type subcmd interface { Flags(*flag.FlagSet) - Run(ctx context.Context, stdin io.Reader, stdout io.Writer) error + Run(ctx context.Context, logger logrus.FieldLogger, stdin io.Reader, stdout io.Writer) error } var subcommands = map[string]subcmd{ @@ -21,9 +22,7 @@ var subcommands = map[string]subcmd{ } func main() { - log.Configure(os.Stdout, "json", "") - - logger := log.Default() + logger := log.Configure(os.Stdout, "json", "") flags := flag.NewFlagSet("gitaly-backup", flag.ExitOnError) _ = flags.Parse(os.Args) @@ -47,7 +46,7 @@ func main() { logger.Fatalf("%s", err) } - if err := subcmd.Run(ctx, os.Stdin, os.Stdout); err != nil { + if err := subcmd.Run(ctx, logger, os.Stdin, os.Stdout); err != nil { logger.Fatalf("%s", err) } } diff --git a/cmd/gitaly-backup/restore.go b/cmd/gitaly-backup/restore.go index c81b3e1aa..c5a5c8fc5 100644 --- a/cmd/gitaly-backup/restore.go +++ b/cmd/gitaly-backup/restore.go @@ -10,7 +10,7 @@ import ( "runtime" "strings" - log "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus" "gitlab.com/gitlab-org/gitaly/v16/client" "gitlab.com/gitlab-org/gitaly/v16/internal/backup" "gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/storage" @@ -49,7 +49,7 @@ func (cmd *restoreSubcommand) Flags(fs *flag.FlagSet) { fs.BoolVar(&cmd.serverSide, "server-side", false, "use server-side backups. Note: The feature is not ready for production use.") } -func (cmd *restoreSubcommand) Run(ctx context.Context, stdin io.Reader, stdout io.Writer) error { +func (cmd *restoreSubcommand) Run(ctx context.Context, logger logrus.FieldLogger, stdin io.Reader, stdout io.Writer) error { pool := client.NewPool(internalclient.UnaryInterceptor(), internalclient.StreamInterceptor()) defer pool.Close() @@ -72,8 +72,6 @@ func (cmd *restoreSubcommand) Run(ctx context.Context, stdin io.Reader, stdout i manager = backup.NewManager(sink, locator, pool) } - logger := log.StandardLogger() - for _, storageName := range cmd.removeAllRepositories { err := manager.RemoveAllRepositories(ctx, &backup.RemoveAllRepositoriesRequest{ StorageName: storageName, diff --git a/cmd/gitaly-backup/restore_test.go b/cmd/gitaly-backup/restore_test.go index 7a15daeff..222acdcc3 100644 --- a/cmd/gitaly-backup/restore_test.go +++ b/cmd/gitaly-backup/restore_test.go @@ -77,7 +77,7 @@ func TestRestoreSubcommand(t *testing.T) { require.NoError(t, fs.Parse([]string{"-path", path, "-remove-all-repositories", existingRepo.StorageName})) require.EqualError(t, - cmd.Run(ctx, &stdin, io.Discard), + cmd.Run(ctx, testhelper.NewDiscardingLogger(t), &stdin, io.Discard), "restore: pipeline: 1 failures encountered:\n - invalid: manager: could not dial source: invalid connection string: \"invalid\"\n") require.NoDirExists(t, existRepoPath) @@ -155,7 +155,7 @@ func TestRestoreSubcommand_serverSide(t *testing.T) { require.NoError(t, fs.Parse([]string{"-server-side", "-remove-all-repositories", existingRepo.StorageName})) require.EqualError(t, - cmd.Run(ctx, &stdin, io.Discard), + cmd.Run(ctx, testhelper.NewDiscardingLogger(t), &stdin, io.Discard), "restore: pipeline: 1 failures encountered:\n - invalid: server-side restore: could not dial source: invalid connection string: \"invalid\"\n") require.NoDirExists(t, existRepoPath) diff --git a/cmd/gitaly-hooks/hooks.go b/cmd/gitaly-hooks/hooks.go index c6c422daa..6d737acd3 100644 --- a/cmd/gitaly-hooks/hooks.go +++ b/cmd/gitaly-hooks/hooks.go @@ -215,6 +215,9 @@ func initializeTracing() { // All stdout and stderr are captured by Gitaly process. They may be sent back to users. // We don't want to bother them with these redundant logs. As a result, all logs should be // suppressed while labkit is in initialization phase. + // + //nolint:forbidigo // LabKit does not allow us to supply our own logger, so we must modify the standard logger + // instead. output := logrus.StandardLogger().Out logrus.SetOutput(io.Discard) defer logrus.SetOutput(output) diff --git a/cmd/gitaly-ssh/main.go b/cmd/gitaly-ssh/main.go index 1b8bd860a..f5f0fad92 100644 --- a/cmd/gitaly-ssh/main.go +++ b/cmd/gitaly-ssh/main.go @@ -3,7 +3,6 @@ package main import ( "context" "fmt" - "log" "os" "strconv" "strings" @@ -13,6 +12,7 @@ import ( "gitlab.com/gitlab-org/gitaly/v16/client" "gitlab.com/gitlab-org/gitaly/v16/internal/featureflag" internalclient "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/client" + "gitlab.com/gitlab-org/gitaly/v16/internal/log" "gitlab.com/gitlab-org/labkit/tracing" "google.golang.org/grpc" ) @@ -42,10 +42,12 @@ type gitalySSHCommand struct { // GITALY_USE_SIDECHANNEL=1 if desired // gitaly-ssh upload-pack <git-garbage-x2> func main() { + logger := log.Configure(os.Stderr, "", "info") + // < 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? - log.Fatalf("invalid number of arguments, expected at least 1, got %d", n-1) + logger.Fatalf("invalid number of arguments, expected at least 1, got %d", n-1) } command := os.Args[1] @@ -62,7 +64,7 @@ func main() { case "upload-archive": packer = uploadArchive default: - log.Fatalf("invalid pack command: %q", command) + logger.Fatalf("invalid pack command: %q", command) } cmd := gitalySSHCommand{ @@ -73,15 +75,15 @@ func main() { featureFlags: os.Getenv("GITALY_FEATUREFLAGS"), } - code, err := cmd.run() + code, err := cmd.run(logger) if err != nil { - log.Printf("%s: %v", command, err) + logger.Printf("%s: %v", command, err) } os.Exit(code) } -func (cmd gitalySSHCommand) run() (int, error) { +func (cmd gitalySSHCommand) run(logger logrus.FieldLogger) (int, error) { // Configure distributed tracing closer := tracing.Initialize(tracing.WithServiceName("gitaly-ssh")) defer closer.Close() @@ -111,7 +113,7 @@ func (cmd gitalySSHCommand) run() (int, error) { } } - registry := client.NewSidechannelRegistry(logrus.NewEntry(logrus.StandardLogger())) + registry := client.NewSidechannelRegistry(logger) conn, err := getConnection(ctx, cmd.address, registry) if err != nil { return 1, err diff --git a/cmd/gitaly-ssh/main_test.go b/cmd/gitaly-ssh/main_test.go index 1822e15a4..a3bfc1078 100644 --- a/cmd/gitaly-ssh/main_test.go +++ b/cmd/gitaly-ssh/main_test.go @@ -103,7 +103,7 @@ func TestRun(t *testing.T) { payload: "{}", } - gotCode, err := cmd.run() + gotCode, err := cmd.run(testhelper.NewDiscardingLogger(t)) if tt.wantErr { assert.Error(t, err) } else { diff --git a/cmd/gitaly/main_test.go b/cmd/gitaly/main_test.go index ca4bc3698..d9335f74c 100644 --- a/cmd/gitaly/main_test.go +++ b/cmd/gitaly/main_test.go @@ -36,7 +36,7 @@ func TestGitalyCLI(t *testing.T) { desc: "with non-existent config", args: []string{"non-existent-file"}, exitCode: 1, - stderr: `msg="load config: config_path \"non-existent-file\"`, + stderr: `load config: config_path "non-existent-file"`, }, { desc: "check without config", diff --git a/internal/backup/pipeline_test.go b/internal/backup/pipeline_test.go index b16f658f0..63d2733f7 100644 --- a/internal/backup/pipeline_test.go +++ b/internal/backup/pipeline_test.go @@ -7,7 +7,6 @@ import ( "testing" "time" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" "gitlab.com/gitlab-org/gitaly/v16/internal/testhelper" @@ -18,7 +17,7 @@ func TestLoggingPipeline(t *testing.T) { t.Parallel() testPipeline(t, func() Pipeline { - return NewLoggingPipeline(logrus.StandardLogger()) + return NewLoggingPipeline(testhelper.NewDiscardingLogger(t)) }) } @@ -26,7 +25,7 @@ func TestParallelPipeline(t *testing.T) { t.Parallel() testPipeline(t, func() Pipeline { - return NewParallelPipeline(NewLoggingPipeline(logrus.StandardLogger()), 2, 0) + return NewParallelPipeline(NewLoggingPipeline(testhelper.NewDiscardingLogger(t)), 2, 0) }) t.Run("parallelism", func(t *testing.T) { @@ -65,7 +64,7 @@ func TestParallelPipeline(t *testing.T) { }, } var p Pipeline - p = NewLoggingPipeline(logrus.StandardLogger()) + p = NewLoggingPipeline(testhelper.NewDiscardingLogger(t)) p = NewParallelPipeline(p, tc.parallel, tc.parallelStorage) ctx := testhelper.Context(t) @@ -81,7 +80,7 @@ func TestParallelPipeline(t *testing.T) { t.Run("context done", func(t *testing.T) { var strategy MockStrategy var p Pipeline - p = NewLoggingPipeline(logrus.StandardLogger()) + p = NewLoggingPipeline(testhelper.NewDiscardingLogger(t)) p = NewParallelPipeline(p, 0, 0) // make sure worker channels always block ctx, cancel := context.WithCancel(testhelper.Context(t)) diff --git a/internal/cli/gitaly/serve.go b/internal/cli/gitaly/serve.go index 5f80d28e5..302fd880d 100644 --- a/internal/cli/gitaly/serve.go +++ b/internal/cli/gitaly/serve.go @@ -10,7 +10,7 @@ import ( "github.com/go-enry/go-license-detector/v4/licensedb" "github.com/prometheus/client_golang/prometheus" "github.com/prometheus/client_golang/prometheus/promauto" - log "github.com/sirupsen/logrus" + "github.com/sirupsen/logrus" "github.com/urfave/cli/v2" "gitlab.com/gitlab-org/gitaly/v16" "gitlab.com/gitlab-org/gitaly/v16/client" @@ -42,7 +42,7 @@ import ( "gitlab.com/gitlab-org/gitaly/v16/internal/helper" "gitlab.com/gitlab-org/gitaly/v16/internal/helper/env" "gitlab.com/gitlab-org/gitaly/v16/internal/limiter" - glog "gitlab.com/gitlab-org/gitaly/v16/internal/log" + "gitlab.com/gitlab-org/gitaly/v16/internal/log" "gitlab.com/gitlab-org/gitaly/v16/internal/streamcache" "gitlab.com/gitlab-org/gitaly/v16/internal/tempdir" "gitlab.com/gitlab-org/gitaly/v16/internal/tracing" @@ -90,58 +90,57 @@ func serveAction(ctx *cli.Context) error { cli.ShowSubcommandHelpAndExit(ctx, 2) } - log.Infof("Starting %s", version.GetVersionString("Gitaly")) - fips.Check() - - cfg, err := configure(ctx.Args().First()) + cfg, logger, err := configure(ctx.Args().First()) if err != nil { - log.Fatal(err) + return cli.Exit(err, 1) } - if err := run(cfg); err != nil { - log.WithError(err).Error("Gitaly shutdown") - os.Exit(1) + logger.Infof("Starting %s", version.GetVersionString("Gitaly")) + fips.Check() + + if err := run(cfg, logger); err != nil { + return cli.Exit(fmt.Errorf("unclean Gitaly shutdown: %w", err), 1) } - log.Info("Gitaly shutdown") + logger.Info("Gitaly shutdown") return nil } -func configure(configPath string) (config.Cfg, error) { +func configure(configPath string) (config.Cfg, logrus.FieldLogger, error) { cfg, err := loadConfig(configPath) if err != nil { - return config.Cfg{}, fmt.Errorf("load config: config_path %q: %w", configPath, err) + return config.Cfg{}, nil, fmt.Errorf("load config: config_path %q: %w", configPath, err) } - urlSanitizer := glog.NewURLSanitizerHook() + urlSanitizer := log.NewURLSanitizerHook() urlSanitizer.AddPossibleGrpcMethod( "CreateRepositoryFromURL", "FetchRemote", "UpdateRemoteMirror", ) - glog.Configure(os.Stdout, cfg.Logging.Format, cfg.Logging.Level, urlSanitizer) + logger := log.Configure(os.Stdout, cfg.Logging.Format, cfg.Logging.Level, urlSanitizer) sentry.ConfigureSentry(version.GetVersion(), sentry.Config(cfg.Logging.Sentry)) cfg.Prometheus.Configure() labkittracing.Initialize(labkittracing.WithServiceName("gitaly")) - preloadLicenseDatabase() + preloadLicenseDatabase(logger) - return cfg, nil + return cfg, logger, nil } -func preloadLicenseDatabase() { +func preloadLicenseDatabase(logger logrus.FieldLogger) { // the first call to `licensedb.Detect` could be too long // https://github.com/go-enry/go-license-detector/issues/13 // this is why we're calling it here to preload license database // on server startup to avoid long initialization on gRPC // method handling. licensedb.Preload() - log.Info("License database preloaded") + logger.Info("License database preloaded") } -func run(cfg config.Cfg) error { +func run(cfg config.Cfg, logger logrus.FieldLogger) error { ctx, cancel := context.WithCancel(context.Background()) defer cancel() @@ -149,7 +148,7 @@ func run(cfg config.Cfg) error { defer bootstrapSpan.Finish() if cfg.RuntimeDir != "" { - if err := config.PruneOldGitalyProcessDirectories(log.StandardLogger(), cfg.RuntimeDir); err != nil { + if err := config.PruneOldGitalyProcessDirectories(logger, cfg.RuntimeDir); err != nil { return fmt.Errorf("prune runtime directories: %w", err) } } @@ -164,7 +163,7 @@ func run(cfg config.Cfg) error { // time a gitaly process is spawned. Look through the hierarchy root // to find any cgroup directories that belong to old gitaly processes // and remove them. - cgroups.PruneOldCgroups(cfg.Cgroups, log.StandardLogger()) + cgroups.PruneOldCgroups(cfg.Cgroups, logger) cgroupMgr := cgroups.NewManager(cfg.Cgroups, os.Getpid()) if err := cgroupMgr.Setup(); err != nil { @@ -173,13 +172,13 @@ func run(cfg config.Cfg) error { defer func() { if err := cgroupMgr.Cleanup(); err != nil { - log.WithError(err).Warn("error cleaning up cgroups") + logger.WithError(err).Warn("error cleaning up cgroups") } }() defer func() { if err := os.RemoveAll(cfg.RuntimeDir); err != nil { - log.Warn("could not clean up runtime dir") + logger.Warn("could not clean up runtime dir") } }() @@ -232,16 +231,16 @@ func run(cfg config.Cfg) error { repoCounter := counter.NewRepositoryCounter(cfg.Storages) prometheus.MustRegister(repoCounter) - repoCounter.StartCountingRepositories(ctx, locator, log.StandardLogger()) + repoCounter.StartCountingRepositories(ctx, locator, logger) tempdir.StartCleaning(locator, cfg.Storages, time.Hour) prometheus.MustRegister(gitCmdFactory) if skipHooks { - log.Warn("skipping GitLab API client creation since hooks are bypassed via GITALY_TESTING_NO_GIT_HOOKS") + logger.Warn("skipping GitLab API client creation since hooks are bypassed via GITALY_TESTING_NO_GIT_HOOKS") } else { - gitlabClient, err := gitlab.NewHTTPClient(glog.Default(), cfg.Gitlab, cfg.TLS, cfg.Prometheus) + gitlabClient, err := gitlab.NewHTTPClient(logger, cfg.Gitlab, cfg.TLS, cfg.Prometheus) if err != nil { return fmt.Errorf("could not create GitLab API client: %w", err) } @@ -313,7 +312,7 @@ func run(cfg config.Cfg) error { gitalyServerFactory := server.NewGitalyServerFactory( cfg, - glog.Default(), + logger, registry, diskCache, []*limithandler.LimiterMiddleware{concurrencyLimitHandler, rateLimitHandler}, @@ -324,7 +323,7 @@ func run(cfg config.Cfg) error { updaterWithHooks := updateref.NewUpdaterWithHooks(cfg, locator, hookManager, gitCmdFactory, catfileCache) - streamCache := streamcache.New(cfg.PackObjectsCache, glog.Default()) + streamCache := streamcache.New(cfg.PackObjectsCache, logger) var backupSink backup.Sink var backupLocator backup.Locator @@ -391,7 +390,7 @@ func run(cfg config.Cfg) error { return err } - log.WithField("address", addr).Info("starting prometheus listener") + logger.WithField("address", addr).Info("starting prometheus listener") go func() { opts := []monitoring.Option{ @@ -406,7 +405,7 @@ func run(cfg config.Cfg) error { } if err := monitoring.Start(opts...); err != nil { - log.WithError(err).Error("Unable to serve prometheus") + logger.WithError(err).Error("Unable to serve prometheus") } }() @@ -417,7 +416,7 @@ func run(cfg config.Cfg) error { for _, shard := range cfg.Storages { if err := storage.WriteMetadataFile(shard.Path); err != nil { // TODO should this be a return? https://gitlab.com/gitlab-org/gitaly/issues/1893 - log.WithError(err).Error("Unable to write gitaly metadata file") + logger.WithError(err).Error("Unable to write gitaly metadata file") } } @@ -428,7 +427,7 @@ func run(cfg config.Cfg) error { shutdownWorkers, err := maintenance.StartWorkers( ctx, - glog.Default(), + logger, maintenance.DailyOptimizationWorker(cfg, maintenance.OptimizerFunc(func(ctx context.Context, repo storage.Repository) error { return housekeepingManager.OptimizeRepository(ctx, localrepo.New(locator, gitCmdFactory, catfileCache, repo)) })), diff --git a/internal/featureflag/context_test.go b/internal/featureflag/context_test.go index b41128d70..5cebf88db 100644 --- a/internal/featureflag/context_test.go +++ b/internal/featureflag/context_test.go @@ -14,9 +14,8 @@ var ( ffB = FeatureFlag{"feature-b", false} ) -// already. -// -//nolint:forbidigo // We cannot use `testhelper.Context()` given that it would inject feature flags +// createContext creates a context for testing purposes. We cannot use `testhelper.Context()` given that it would inject +// feature flags already. func createContext() context.Context { return context.Background() } diff --git a/internal/gitaly/server/server.go b/internal/gitaly/server/server.go index 0ea9186d4..2b1127d97 100644 --- a/internal/gitaly/server/server.go +++ b/internal/gitaly/server/server.go @@ -111,7 +111,7 @@ func (s *GitalyServerFactory) New(secure bool, opts ...Option) (*grpc.Server, er metadatahandler.StreamInterceptor, grpcprometheus.StreamServerInterceptor, customfieldshandler.StreamInterceptor, - grpcmwlogrus.StreamServerInterceptor(s.logger, + grpcmwlogrus.StreamServerInterceptor(s.logger.WithField("component", "gitaly.StreamServerInterceptor"), grpcmwlogrus.WithTimestampFormat(gitalylog.LogTimestampFormat), logMsgProducer, gitalylog.DeciderOption(), @@ -127,7 +127,7 @@ func (s *GitalyServerFactory) New(secure bool, opts ...Option) (*grpc.Server, er metadatahandler.UnaryInterceptor, grpcprometheus.UnaryServerInterceptor, customfieldshandler.UnaryInterceptor, - grpcmwlogrus.UnaryServerInterceptor(s.logger, + grpcmwlogrus.UnaryServerInterceptor(s.logger.WithField("component", "gitaly.UnaryServerInterceptor"), grpcmwlogrus.WithTimestampFormat(gitalylog.LogTimestampFormat), logMsgProducer, gitalylog.DeciderOption(), diff --git a/internal/gitaly/server/server_factory.go b/internal/gitaly/server/server_factory.go index 10afb3ce3..8639a8e0e 100644 --- a/internal/gitaly/server/server_factory.go +++ b/internal/gitaly/server/server_factory.go @@ -17,7 +17,7 @@ type GitalyServerFactory struct { cacheInvalidator cache.Invalidator limitHandlers []*limithandler.LimiterMiddleware cfg config.Cfg - logger *logrus.Entry + logger logrus.FieldLogger externalServers []*grpc.Server internalServers []*grpc.Server } @@ -25,7 +25,7 @@ type GitalyServerFactory struct { // NewGitalyServerFactory allows to create and start secure/insecure 'grpc.Server's. func NewGitalyServerFactory( cfg config.Cfg, - logger *logrus.Entry, + logger logrus.FieldLogger, registry *backchannel.Registry, cacheInvalidator cache.Invalidator, limitHandlers []*limithandler.LimiterMiddleware, diff --git a/internal/gitaly/storage/servers_test.go b/internal/gitaly/storage/servers_test.go index 61b977823..bb737e0fb 100644 --- a/internal/gitaly/storage/servers_test.go +++ b/internal/gitaly/storage/servers_test.go @@ -80,8 +80,8 @@ func TestInjectGitalyServers(t *testing.T) { } t.Run("brand new context", func(t *testing.T) { - //nolint:forbidigo // We need to check for metadata and thus cannot use the - // testhelper context, which injects feature flags. + // We need to check for metadata and thus cannot use the testhelper context, which injects feature + // flags. ctx := context.Background() check(t, ctx) @@ -90,8 +90,8 @@ func TestInjectGitalyServers(t *testing.T) { t.Run("context with existing outgoing metadata should not be re-written", func(t *testing.T) { existing := metadata.New(map[string]string{"foo": "bar"}) - //nolint:forbidigo // We need to check for metadata and thus cannot use the - // testhelper context, which injects feature flags. + // We need to check for metadata and thus cannot use the testhelper context, which injects feature + // flags. ctx := metadata.NewOutgoingContext(context.Background(), existing) check(t, ctx) diff --git a/internal/gitaly/storage/storagemgr/partition_manager_test.go b/internal/gitaly/storage/storagemgr/partition_manager_test.go index 45346466b..4d5eac853 100644 --- a/internal/gitaly/storage/storagemgr/partition_manager_test.go +++ b/internal/gitaly/storage/storagemgr/partition_manager_test.go @@ -7,7 +7,6 @@ import ( "path/filepath" "testing" - "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" "gitlab.com/gitlab-org/gitaly/v16/internal/git" "gitlab.com/gitlab-org/gitaly/v16/internal/git/catfile" @@ -622,7 +621,7 @@ func TestPartitionManager(t *testing.T) { txManager := transaction.NewManager(cfg, backchannel.NewRegistry()) housekeepingManager := housekeeping.NewManager(cfg.Prometheus, txManager) - partitionManager, err := NewPartitionManager(cfg.Storages, cmdFactory, housekeepingManager, localRepoFactory, logrus.StandardLogger()) + partitionManager, err := NewPartitionManager(cfg.Storages, cmdFactory, housekeepingManager, localRepoFactory, testhelper.NewDiscardingLogger(t)) require.NoError(t, err) defer func() { diff --git a/internal/grpc/backchannel/client.go b/internal/grpc/backchannel/client.go index c4526b7cc..fe3ff8a77 100644 --- a/internal/grpc/backchannel/client.go +++ b/internal/grpc/backchannel/client.go @@ -50,14 +50,14 @@ func DefaultConfiguration() Configuration { // ClientHandshaker implements the client side handshake of the multiplexed connection. type ClientHandshaker struct { - logger *logrus.Entry + logger logrus.FieldLogger serverFactory ServerFactory cfg Configuration } // NewClientHandshaker returns a new client side implementation of the backchannel. The provided // logger is used to log multiplexing errors. -func NewClientHandshaker(logger *logrus.Entry, serverFactory ServerFactory, cfg Configuration) ClientHandshaker { +func NewClientHandshaker(logger logrus.FieldLogger, serverFactory ServerFactory, cfg Configuration) ClientHandshaker { return ClientHandshaker{logger: logger, serverFactory: serverFactory, cfg: cfg} } @@ -71,7 +71,7 @@ func (ch ClientHandshaker) ClientHandshake(tc credentials.TransportCredentials) type clientHandshake struct { credentials.TransportCredentials serverFactory ServerFactory - logger *logrus.Entry + logger logrus.FieldLogger cfg Configuration } @@ -115,7 +115,7 @@ func (ch clientHandshake) serve(ctx context.Context, conn net.Conn) (net.Conn, e return nil, fmt.Errorf("write backchannel magic bytes: %w", err) } - logger := ch.logger.WriterLevel(logrus.ErrorLevel) + logger := ch.logger.WithField("component", "backchannel.YamuxClient").WriterLevel(logrus.ErrorLevel) // Initiate the multiplexing session. muxSession, err := yamux.Client(conn, muxConfig(logger, ch.cfg)) diff --git a/internal/grpc/backchannel/server.go b/internal/grpc/backchannel/server.go index a6fe677ee..44e2e6405 100644 --- a/internal/grpc/backchannel/server.go +++ b/internal/grpc/backchannel/server.go @@ -73,7 +73,7 @@ func withSessionInfo(authInfo credentials.AuthInfo, id ID, muxSession *yamux.Ses // ServerHandshaker implements the server side handshake of the multiplexed connection. type ServerHandshaker struct { registry *Registry - logger *logrus.Entry + logger logrus.FieldLogger dialOpts []grpc.DialOption } @@ -85,7 +85,7 @@ func (s *ServerHandshaker) Magic() string { return string(magicBytes) } // are handshaked prior to initializing the multiplexing session. The Registry is used to store the backchannel connections. // DialOptions can be used to set custom dial options for the backchannel connections. They must not contain a dialer or // transport credentials as those set by the handshaker. -func NewServerHandshaker(logger *logrus.Entry, reg *Registry, dialOpts []grpc.DialOption) *ServerHandshaker { +func NewServerHandshaker(logger logrus.FieldLogger, reg *Registry, dialOpts []grpc.DialOption) *ServerHandshaker { return &ServerHandshaker{registry: reg, logger: logger, dialOpts: dialOpts} } @@ -99,7 +99,7 @@ func (s *ServerHandshaker) Handshake(conn net.Conn, authInfo credentials.AuthInf // gRPC server closes the conn if there is an error, which closes the multiplexing // session as well. - logger := s.logger.WriterLevel(logrus.ErrorLevel) + logger := s.logger.WithField("component", "backchannel.YamuxServer").WriterLevel(logrus.ErrorLevel) // Open the server side of the multiplexing session. // diff --git a/internal/grpc/dnsresolver/builder.go b/internal/grpc/dnsresolver/builder.go index 8dba5ab54..810a68ab8 100644 --- a/internal/grpc/dnsresolver/builder.go +++ b/internal/grpc/dnsresolver/builder.go @@ -31,7 +31,7 @@ type BuilderConfig struct { // LookupTimeout determines the timeout of underlying DNS query. LookupTimeout time.Duration // Logger defines a logger for logging internal activities - Logger *logrus.Logger + Logger logrus.FieldLogger // Backoff defines the backoff strategy when the resolver fails to resolve or pushes new // state to client connection Backoff backoff.Strategy @@ -93,7 +93,7 @@ func (d *Builder) Build(target resolver.Target, cc resolver.ClientConn, _ resolv ctx, cancel := context.WithCancel(context.Background()) dr := &dnsResolver{ - logger: logrus.NewEntry(d.opts.Logger).WithField("target", target.URL.String()), + logger: d.opts.Logger.WithField("target", target.URL.String()), retry: d.opts.Backoff, ctx: ctx, diff --git a/internal/grpc/middleware/featureflag/featureflag_handler_test.go b/internal/grpc/middleware/featureflag/featureflag_handler_test.go index 5df5850af..c8ed414e0 100644 --- a/internal/grpc/middleware/featureflag/featureflag_handler_test.go +++ b/internal/grpc/middleware/featureflag/featureflag_handler_test.go @@ -117,7 +117,8 @@ func TestFeatureFlagLogs(t *testing.T) { loggerHook.Reset() service.err = tc.returnedErr - //nolint:forbidigo // This test tests feature flags. We want context to be in a clean state + // This test tests feature flags. We want context to be in a clean state and thus cannot use + // `testhelper.Context()`. ctx := context.Background() for flag, value := range tc.featureFlags { ctx = featureflag.OutgoingCtxWithFeatureFlag(ctx, flag, value) diff --git a/internal/grpc/middleware/metadatahandler/metadatahandler_test.go b/internal/grpc/middleware/metadatahandler/metadatahandler_test.go index 3c923328f..460dd2f68 100644 --- a/internal/grpc/middleware/metadatahandler/metadatahandler_test.go +++ b/internal/grpc/middleware/metadatahandler/metadatahandler_test.go @@ -200,8 +200,7 @@ func TestAddMetadataTags(t *testing.T) { ctx := metadata.NewIncomingContext(baseContext, tc.metadata) if tc.deadline { var cancel func() - //nolint:forbidigo // We explicitly need to test whether deadlines - // propagate as expected. + ctx, cancel = context.WithDeadline(ctx, time.Now().Add(50*time.Millisecond)) defer cancel() } diff --git a/internal/grpc/middleware/statushandler/statushandler_test.go b/internal/grpc/middleware/statushandler/statushandler_test.go index 077806ba5..e4af4d044 100644 --- a/internal/grpc/middleware/statushandler/statushandler_test.go +++ b/internal/grpc/middleware/statushandler/statushandler_test.go @@ -20,7 +20,7 @@ func TestStatushandler(t *testing.T) { ctx := testhelper.Context(t) cancelledCtx, cancel := context.WithCancel(ctx) cancel() - timeoutCtx, timeout := context.WithTimeout(ctx, 0) //nolint:forbidigo + timeoutCtx, timeout := context.WithTimeout(ctx, 0) timeout() for desc, tc := range map[string]struct { diff --git a/internal/grpc/sidechannel/sidechannel.go b/internal/grpc/sidechannel/sidechannel.go index 0a0dd0b7e..aff38728c 100644 --- a/internal/grpc/sidechannel/sidechannel.go +++ b/internal/grpc/sidechannel/sidechannel.go @@ -136,7 +136,7 @@ func NewServerHandshaker(registry *Registry) *ServerHandshaker { // NewClientHandshaker is used to enable sidechannel support on outbound // gRPC connections. -func NewClientHandshaker(logger *logrus.Entry, registry *Registry) client.Handshaker { +func NewClientHandshaker(logger logrus.FieldLogger, registry *Registry) client.Handshaker { cfg := backchannel.DefaultConfiguration() // If a client hangs up while the server is writing data to it then the // server will block for 5 minutes by default before erroring out. This diff --git a/internal/helper/suppressed_context_test.go b/internal/helper/suppressed_context_test.go index 70c45ce4e..7c910e6ca 100644 --- a/internal/helper/suppressed_context_test.go +++ b/internal/helper/suppressed_context_test.go @@ -8,7 +8,6 @@ import ( "github.com/stretchr/testify/require" ) -//nolint:forbidigo // We're explicitly testing that deadline cancellation works as expected. func TestSuppressCancellation(t *testing.T) { type key struct{} diff --git a/internal/log/logger.go b/internal/log/logger.go index e4197d298..fd45e3676 100644 --- a/internal/log/logger.go +++ b/internal/log/logger.go @@ -42,6 +42,8 @@ func UTCTextFormatter() logrus.Formatter { // `logrus.Info()`. By default it is configured to log to standard output, but in practice it should be configured via // a call to `Configure()` after the configuration has been loaded. var defaultLogger = func() *logrus.Logger { + //nolint:forbidigo // We reuse the standard logger such that dependencies which might use logrus are properly + // configured, as well. logger := logrus.StandardLogger() logger.Out = os.Stdout return logger @@ -55,14 +57,16 @@ type Config struct { } // Configure configures the default and gRPC loggers. The gRPC logger's log level will be mapped in order to decrease -// its default verbosity. -func Configure(out io.Writer, format string, level string, hooks ...logrus.Hook) { +// its default verbosity. Returns the configured default logger that would also be returned by `Default()`. +func Configure(out io.Writer, format string, level string, hooks ...logrus.Hook) logrus.FieldLogger { configure(defaultLogger, out, format, level, hooks...) // We replace the gRPC logger with a custom one because the default one is too chatty. grpcLogger := logrus.New() configure(grpcLogger, out, format, mapGRPCLogLevel(level), hooks...) grpcmwlogrus.ReplaceGrpcLogger(grpcLogger.WithField("pid", os.Getpid())) + + return Default() } func configure(logger *logrus.Logger, out io.Writer, format, level string, hooks ...logrus.Hook) { diff --git a/internal/log/middleware_test.go b/internal/log/middleware_test.go index d3a791580..734d91d97 100644 --- a/internal/log/middleware_test.go +++ b/internal/log/middleware_test.go @@ -15,7 +15,7 @@ import ( "github.com/sirupsen/logrus/hooks/test" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" - "gitlab.com/gitlab-org/gitaly/v16/client" + "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/client" "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/grpcstats" "google.golang.org/grpc" "google.golang.org/grpc/codes" @@ -74,7 +74,7 @@ func TestPayloadBytes(t *testing.T) { t.Cleanup(srv.GracefulStop) go func() { assert.NoError(t, srv.Serve(lis)) }() - cc, err := client.DialContext(ctx, "unix://"+sock.Name(), nil) + cc, err := client.Dial(ctx, "unix://"+sock.Name()) require.NoError(t, err) t.Cleanup(func() { require.NoError(t, cc.Close()) }) @@ -379,9 +379,8 @@ func TestStreamLogDataCatcherServerInterceptor(t *testing.T) { }) } +// createContext creates a new context for testing purposes. We cannot use `testhelper.Context()` because of a cyclic dependency between // this package and the `testhelper` package. -// -//nolint:forbidigo // We cannot use `testhelper.Context()` because of a cyclic dependency between func createContext() context.Context { return context.Background() } diff --git a/internal/praefect/coordinator_test.go b/internal/praefect/coordinator_test.go index 1d9227d8e..754e67d68 100644 --- a/internal/praefect/coordinator_test.go +++ b/internal/praefect/coordinator_test.go @@ -2837,8 +2837,6 @@ func TestNewRequestFinalizer_contextIsDisjointedFromTheRPC(t *testing.T) { parentDeadline := time.Now() ctx := testhelper.Context(t) - //nolint:forbidigo // We explicitly want to test that the deadline does not propagate into - // the request's context. ctx, cancel := context.WithDeadline(context.WithValue(ctx, ctxKey{}, "value"), parentDeadline) defer cancel() @@ -3020,9 +3018,8 @@ func TestStreamParametersContext(t *testing.T) { return metadata.Pairs(pairs...) } - //nolint:forbidigo // We explicitly test context values, so we cannot use the testhelper - // context here given that it would contain unrelated data and thus change the system under - // test. + // We explicitly test context values, so we cannot use the testhelper context here given that it would contain + // unrelated data and thus change the system under test. for _, tc := range []struct { desc string setupContext func() context.Context |