praefect: Remove global logger

Currently Praefect uses a global `logger` variable. When running
normally this is not an issue logged events occur serially.
However, in testing we try to run in parallel whenever possible, leading
to race-detector failures from events being logged concurrently. This
was occurring frequently in `TestAddRepositories_Exec()` in particular.

Make logger a local variable to resolve this.

6 files changed, 37 insertions, 31 deletions

diff --git a/cmd/praefect/main.go b/cmd/praefect/main.go
index 078db25df..cca44b121 100644
--- a/cmd/praefect/main.go
+++ b/cmd/praefect/main.go
@@ -100,7 +100,6 @@ import (
 var (
 	flagConfig  = flag.String("config", "", "Location for the config.toml")
 	flagVersion = flag.Bool("version", false, "Print version and exit")
-	logger      = log.Default()
 
 	errNoConfigFile = errors.New("the config flag must be passed")
 )
@@ -108,9 +107,10 @@ var (
 const progname = "praefect"
 
 func main() {
+	logger := log.Default()
 	flag.Usage = func() {
 		cmds := []string{}
-		for k := range subcommands {
+		for k := range subcommands(logger) {
 			cmds = append(cmds, k)
 		}
 
@@ -127,7 +127,7 @@ func main() {
 		os.Exit(0)
 	}
 
-	conf, err := initConfig()
+	conf, err := initConfig(logger)
 	if err != nil {
 		printfErr("%s: configuration error: %v\n", progname, err)
 		os.Exit(1)
@@ -136,7 +136,7 @@ func main() {
 	conf.ConfigureLogger()
 
 	if args := flag.Args(); len(args) > 0 {
-		os.Exit(subCommand(conf, args[0], args[1:]))
+		os.Exit(subCommand(conf, logger, args[0], args[1:]))
 	}
 
 	configure(conf)
@@ -162,12 +162,12 @@ func main() {
 
 	dbPromRegistry := prometheus.NewRegistry()
 
-	if err := run(starterConfigs, conf, b, promreg, dbPromRegistry); err != nil {
+	if err := run(starterConfigs, conf, logger, b, promreg, dbPromRegistry); err != nil {
 		logger.Fatalf("%v", err)
 	}
 }
 
-func initConfig() (config.Config, error) {
+func initConfig(logger *logrus.Entry) (config.Config, error) {
 	var conf config.Config
 
 	if *flagConfig == "" {
@@ -208,6 +208,7 @@ func configure(conf config.Config) {
 func run(
 	cfgs []starter.Config,
 	conf config.Config,
+	logger *logrus.Entry,
 	b bootstrap.Listener,
 	promreg prometheus.Registerer,
 	dbPromRegistry interface {
diff --git a/cmd/praefect/main_test.go b/cmd/praefect/main_test.go
index 3879a5437..b6b166591 100644
--- a/cmd/praefect/main_test.go
+++ b/cmd/praefect/main_test.go
@@ -24,7 +24,7 @@ func TestMain(m *testing.M) {
 }
 
 func TestNoConfigFlag(t *testing.T) {
-	_, err := initConfig()
+	_, err := initConfig(testhelper.NewDiscardingLogEntry(t))
 
 	assert.Equal(t, err, errNoConfigFile)
 }
@@ -227,7 +227,8 @@ func TestExcludeDatabaseMetricsFromDefaultMetrics(t *testing.T) {
 			metricRegisterer, dbMetricsRegisterer := newMockRegisterer(), newMockRegisterer()
 			go func() {
 				defer close(stopped)
-				assert.NoError(t, run(starterConfigs, conf, bootstrapper, metricRegisterer, dbMetricsRegisterer))
+				logger := testhelper.NewDiscardingLogEntry(t)
+				assert.NoError(t, run(starterConfigs, conf, logger, bootstrapper, metricRegisterer, dbMetricsRegisterer))
 			}()
 
 			bootstrapper.Terminate()
diff --git a/cmd/praefect/subcmd.go b/cmd/praefect/subcmd.go
index 53df26eee..0ac247f8f 100644
--- a/cmd/praefect/subcmd.go
+++ b/cmd/praefect/subcmd.go
@@ -10,6 +10,7 @@ import (
 	"os/signal"
 	"time"
 
+	"github.com/sirupsen/logrus"
 	gitalyauth "gitlab.com/gitlab-org/gitaly/v15/auth"
 	"gitlab.com/gitlab-org/gitaly/v15/client"
 	internalclient "gitlab.com/gitlab-org/gitaly/v15/internal/gitaly/client"
@@ -31,27 +32,29 @@ const (
 	paramAuthoritativeStorage = "authoritative-storage"
 )
 
-var subcommands = map[string]subcmd{
-	sqlPingCmdName:                &sqlPingSubcommand{},
-	sqlMigrateCmdName:             newSQLMigrateSubCommand(os.Stdout),
-	dialNodesCmdName:              newDialNodesSubcommand(os.Stdout),
-	sqlMigrateDownCmdName:         &sqlMigrateDownSubcommand{},
-	sqlMigrateStatusCmdName:       &sqlMigrateStatusSubcommand{},
-	datalossCmdName:               newDatalossSubcommand(),
-	acceptDatalossCmdName:         &acceptDatalossSubcommand{},
-	setReplicationFactorCmdName:   newSetReplicatioFactorSubcommand(os.Stdout),
-	removeRepositoryCmdName:       newRemoveRepository(logger, os.Stdout),
-	trackRepositoryCmdName:        newTrackRepository(logger, os.Stdout),
-	trackRepositoriesCmdName:      newTrackRepositories(logger, os.Stdout),
-	listUntrackedRepositoriesName: newListUntrackedRepositories(logger, os.Stdout),
-	checkCmdName:                  newCheckSubcommand(os.Stdout, service.AllChecks()...),
-	metadataCmdName:               newMetadataSubcommand(os.Stdout),
-	verifyCmdName:                 newVerifySubcommand(os.Stdout),
-	listStoragesCmdName:           newListStorages(os.Stdout),
+func subcommands(logger *logrus.Entry) map[string]subcmd {
+	return map[string]subcmd{
+		sqlPingCmdName:                &sqlPingSubcommand{},
+		sqlMigrateCmdName:             newSQLMigrateSubCommand(os.Stdout),
+		dialNodesCmdName:              newDialNodesSubcommand(os.Stdout),
+		sqlMigrateDownCmdName:         &sqlMigrateDownSubcommand{},
+		sqlMigrateStatusCmdName:       &sqlMigrateStatusSubcommand{},
+		datalossCmdName:               newDatalossSubcommand(),
+		acceptDatalossCmdName:         &acceptDatalossSubcommand{},
+		setReplicationFactorCmdName:   newSetReplicatioFactorSubcommand(os.Stdout),
+		removeRepositoryCmdName:       newRemoveRepository(logger, os.Stdout),
+		trackRepositoryCmdName:        newTrackRepository(logger, os.Stdout),
+		trackRepositoriesCmdName:      newTrackRepositories(logger, os.Stdout),
+		listUntrackedRepositoriesName: newListUntrackedRepositories(logger, os.Stdout),
+		checkCmdName:                  newCheckSubcommand(os.Stdout, service.AllChecks()...),
+		metadataCmdName:               newMetadataSubcommand(os.Stdout),
+		verifyCmdName:                 newVerifySubcommand(os.Stdout),
+		listStoragesCmdName:           newListStorages(os.Stdout),
+	}
 }
 
 // subCommand returns an exit code, to be fed into os.Exit.
-func subCommand(conf config.Config, arg0 string, argRest []string) int {
+func subCommand(conf config.Config, logger *logrus.Entry, arg0 string, argRest []string) int {
 	interrupt := make(chan os.Signal, 1)
 	signal.Notify(interrupt, os.Interrupt)
 
@@ -60,7 +63,7 @@ func subCommand(conf config.Config, arg0 string, argRest []string) int {
 		os.Exit(130) // indicates program was interrupted
 	}()
 
-	subcmd, ok := subcommands[arg0]
+	subcmd, ok := subcommands(logger)[arg0]
 	if !ok {
 		printfErr("%s: unknown subcommand: %q\n", progname, arg0)
 		return 1
diff --git a/cmd/praefect/subcmd_track_repositories.go b/cmd/praefect/subcmd_track_repositories.go
index 2ba8a88b1..8d8c9f7d0 100644
--- a/cmd/praefect/subcmd_track_repositories.go
+++ b/cmd/praefect/subcmd_track_repositories.go
@@ -76,7 +76,7 @@ func (cmd trackRepositories) Exec(flags *flag.FlagSet, cfg config.Config) error
 	}
 
 	ctx := correlation.ContextWithCorrelation(context.Background(), correlation.SafeRandomID())
-	logger = cmd.logger.WithField("correlation_id", correlation.ExtractFromContext(ctx))
+	logger := cmd.logger.WithField("correlation_id", correlation.ExtractFromContext(ctx))
 
 	openDBCtx, cancel := context.WithTimeout(ctx, 30*time.Second)
 	defer cancel()
@@ -164,7 +164,7 @@ func (cmd trackRepositories) Exec(flags *flag.FlagSet, cfg config.Config) error
 			continue
 		}
 
-		authoritativeRepoExists, err := request.authoritativeRepositoryExists(ctx, cfg, cmd.w, request.AuthoritativeStorage)
+		authoritativeRepoExists, err := request.authoritativeRepositoryExists(ctx, cfg, logger, cmd.w, request.AuthoritativeStorage)
 		if err != nil {
 			badReq.errs = append(badReq.errs, fmt.Errorf("checking repository on disk: %w", err))
 		} else if !authoritativeRepoExists {
diff --git a/cmd/praefect/subcmd_track_repositories_test.go b/cmd/praefect/subcmd_track_repositories_test.go
index ed9737864..798ebb478 100644
--- a/cmd/praefect/subcmd_track_repositories_test.go
+++ b/cmd/praefect/subcmd_track_repositories_test.go
@@ -75,6 +75,7 @@ func TestAddRepositories_Exec_invalidInput(t *testing.T) {
 	rs := datastore.NewPostgresRepositoryStore(db, nil)
 	ctx := testhelper.Context(t)
 	inputFile := "input_file"
+	logger := testhelper.NewDiscardingLogger(t)
 
 	trackRepo := func(relativePath string) error {
 		repositoryID, err := rs.ReserveRepositoryID(ctx, virtualStorageName, relativePath)
diff --git a/cmd/praefect/subcmd_track_repository.go b/cmd/praefect/subcmd_track_repository.go
index 8fc4fd0a6..e32fb6fd6 100644
--- a/cmd/praefect/subcmd_track_repository.go
+++ b/cmd/praefect/subcmd_track_repository.go
@@ -160,7 +160,7 @@ func (req *trackRepositoryRequest) execRequest(ctx context.Context,
 		}
 	}
 
-	authoritativeRepoExists, err := req.authoritativeRepositoryExists(ctx, cfg, w, primary)
+	authoritativeRepoExists, err := req.authoritativeRepositoryExists(ctx, cfg, logger, w, primary)
 	if err != nil {
 		return fmt.Errorf("%s: %w", trackRepoErrorPrefix, err)
 	}
@@ -300,7 +300,7 @@ func repositoryExists(ctx context.Context, repo *gitalypb.Repository, addr, toke
 	return res.GetExists(), nil
 }
 
-func (req *trackRepositoryRequest) authoritativeRepositoryExists(ctx context.Context, cfg config.Config, w io.Writer, nodeName string) (bool, error) {
+func (req *trackRepositoryRequest) authoritativeRepositoryExists(ctx context.Context, cfg config.Config, logger logrus.FieldLogger, w io.Writer, nodeName string) (bool, error) {
 	for _, vs := range cfg.VirtualStorages {
 		if vs.Name != req.VirtualStorage {
 			continue