Merge branch 'pks-log-subcommands-consistent-configuration' into 'master'

cli: Consistent set up of logging infrastructure for subcommands

Closes #5509 and #5479

See merge request https://gitlab.com/gitlab-org/gitaly/-/merge_requests/6329

Merged-by: Patrick Steinhardt <psteinhardt@gitlab.com>
Approved-by: Toon Claes <toon@gitlab.com>
Approved-by: James Liu <jliu@gitlab.com>

23 files changed, 78 insertions, 43 deletions

diff --git a/internal/cli/gitaly/check.go b/internal/cli/gitaly/subcmd_check.go
index 7e7153030..1cdc2ae94 100644
--- a/internal/cli/gitaly/check.go
+++ b/internal/cli/gitaly/subcmd_check.go
@@ -3,7 +3,6 @@ package gitaly
 import (
 	"context"
 	"fmt"
-	"os"
 
 	"github.com/sirupsen/logrus"
 	"github.com/urfave/cli/v2"
@@ -29,6 +28,8 @@ Example: gitaly check gitaly.config.toml`,
 }
 
 func checkAction(ctx *cli.Context) error {
+	logger := log.ConfigureCommand()
+
 	if ctx.NArg() != 1 || ctx.Args().First() == "" {
 		if err := cli.ShowSubcommandHelp(ctx); err != nil {
 			return err
@@ -43,11 +44,6 @@ func checkAction(ctx *cli.Context) error {
 		return fmt.Errorf("loading configuration %q: %w", configPath, err)
 	}
 
-	logger, err := log.Configure(os.Stderr, "text", "error")
-	if err != nil {
-		return cli.Exit(fmt.Errorf("configuring logger failed: %w", err), 1)
-	}
-
 	fmt.Fprint(ctx.App.Writer, "Checking GitLab API access: ")
 	info, err := checkAPI(cfg, logger)
 	if err != nil {
diff --git a/internal/cli/gitaly/configuration-validate.go b/internal/cli/gitaly/subcmd_configuration.go
index 4495f5461..1e3f5879f 100644
--- a/internal/cli/gitaly/configuration-validate.go
+++ b/internal/cli/gitaly/subcmd_configuration.go
@@ -1,10 +1,10 @@
 package gitaly
 
 import (
-	"github.com/sirupsen/logrus"
 	"github.com/urfave/cli/v2"
 	"gitlab.com/gitlab-org/gitaly/v16/cmd"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/config"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 )
 
 const validationErrorCode = 2
@@ -40,7 +40,7 @@ Example: gitaly configuration validate < gitaly.config.toml`,
 }
 
 func validateConfigurationAction(ctx *cli.Context) error {
-	logrus.SetLevel(logrus.ErrorLevel)
+	log.ConfigureCommand()
 
 	cfg, err := config.Load(ctx.App.Reader)
 	if err != nil {
diff --git a/internal/cli/gitaly/configuration-validate_test.go b/internal/cli/gitaly/subcmd_configuration_test.go
index 105004a4f..105004a4f 100644
--- a/internal/cli/gitaly/configuration-validate_test.go
+++ b/internal/cli/gitaly/subcmd_configuration_test.go
diff --git a/internal/cli/gitaly/hooks.go b/internal/cli/gitaly/subcmd_hooks.go
index e73ff0178..f0d0946d6 100644
--- a/internal/cli/gitaly/hooks.go
+++ b/internal/cli/gitaly/subcmd_hooks.go
@@ -5,7 +5,6 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"os"
 	"time"
 
 	"github.com/urfave/cli/v2"
@@ -13,7 +12,7 @@ import (
 	"gitlab.com/gitlab-org/gitaly/v16/client"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/config"
 	internalclient "gitlab.com/gitlab-org/gitaly/v16/internal/grpc/client"
-	gitalylog "gitlab.com/gitlab-org/gitaly/v16/internal/log"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/proto/go/gitalypb"
 	"gitlab.com/gitlab-org/gitaly/v16/streamio"
 	"google.golang.org/grpc"
@@ -68,15 +67,13 @@ To remove custom Git hooks for a specified repository, run the set subcommand wi
 }
 
 func setHooksAction(ctx *cli.Context) error {
+	log.ConfigureCommand()
+
 	cfg, err := loadConfig(ctx.String(flagConfig))
 	if err != nil {
 		return fmt.Errorf("load config: %w", err)
 	}
 
-	if _, err := gitalylog.Configure(os.Stdout, cfg.Logging.Format, cfg.Logging.Level); err != nil {
-		return fmt.Errorf("configuring loggers: %w", err)
-	}
-
 	storage := ctx.String(flagStorage)
 	if storage == "" {
 		if len(cfg.Storages) != 1 {
diff --git a/internal/cli/gitaly/hooks_test.go b/internal/cli/gitaly/subcmd_hooks_test.go
index a3287c830..a3287c830 100644
--- a/internal/cli/gitaly/hooks_test.go
+++ b/internal/cli/gitaly/subcmd_hooks_test.go
diff --git a/internal/cli/praefect/subcmd_accept_dataloss.go b/internal/cli/praefect/subcmd_accept_dataloss.go
index b8d42e263..6228940a0 100644
--- a/internal/cli/praefect/subcmd_accept_dataloss.go
+++ b/internal/cli/praefect/subcmd_accept_dataloss.go
@@ -4,6 +4,7 @@ import (
 	"fmt"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/proto/go/gitalypb"
 )
 
@@ -47,6 +48,8 @@ Example: praefect --config praefect.config.toml accept-dataloss --virtual-storag
 }
 
 func acceptDatalossAction(ctx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(ctx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_check.go b/internal/cli/praefect/subcmd_check.go
index a88e0b3b8..5d8513600 100644
--- a/internal/cli/praefect/subcmd_check.go
+++ b/internal/cli/praefect/subcmd_check.go
@@ -8,6 +8,7 @@ import (
 	"time"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/service"
 )
 
@@ -40,6 +41,8 @@ var errFatalChecksFailed = errors.New("checks failed")
 
 func checkAction(checkFuncs []service.CheckFunc) func(ctx *cli.Context) error {
 	return func(ctx *cli.Context) error {
+		log.ConfigureCommand()
+
 		conf, err := readConfig(ctx.String(configFlagName))
 		if err != nil {
 			return err
diff --git a/internal/cli/praefect/subcmd_configuration_validate.go b/internal/cli/praefect/subcmd_configuration_validate.go
index 6d96ca673..949f297b5 100644
--- a/internal/cli/praefect/subcmd_configuration_validate.go
+++ b/internal/cli/praefect/subcmd_configuration_validate.go
@@ -5,6 +5,7 @@ import (
 
 	"github.com/urfave/cli/v2"
 	"gitlab.com/gitlab-org/gitaly/v16/cmd"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/config"
 )
 
@@ -26,6 +27,8 @@ Example: praefect configuration validate < praefect.config.toml`,
 }
 
 func configurationValidateAction(ctx *cli.Context) error {
+	log.ConfigureCommand()
+
 	if ctx.Args().Present() {
 		_ = cli.ShowSubcommandHelp(ctx)
 		return cli.Exit("invalid argument(s)", 1)
diff --git a/internal/cli/praefect/subcmd_dataloss.go b/internal/cli/praefect/subcmd_dataloss.go
index a97e8e2d6..80b3d7366 100644
--- a/internal/cli/praefect/subcmd_dataloss.go
+++ b/internal/cli/praefect/subcmd_dataloss.go
@@ -3,7 +3,6 @@ package praefect
 import (
 	"fmt"
 	"io"
-	"os"
 	"sort"
 	"strings"
 
@@ -58,16 +57,13 @@ Example: praefect --config praefect.config.toml dataloss`,
 }
 
 func datalossAction(ctx *cli.Context) error {
+	logger := log.ConfigureCommand()
+
 	conf, err := readConfig(ctx.String(configFlagName))
 	if err != nil {
 		return err
 	}
 
-	logger, err := log.Configure(os.Stderr, "text", "error")
-	if err != nil {
-		return fmt.Errorf("configuring logger: %w", err)
-	}
-
 	includePartiallyAvailable := ctx.Bool("partially-unavailable")
 
 	virtualStorages := []string{ctx.String(paramVirtualStorage)}
diff --git a/internal/cli/praefect/subcmd_dial_nodes.go b/internal/cli/praefect/subcmd_dial_nodes.go
index ec14b6e65..7c2bda57e 100644
--- a/internal/cli/praefect/subcmd_dial_nodes.go
+++ b/internal/cli/praefect/subcmd_dial_nodes.go
@@ -4,6 +4,7 @@ import (
 	"context"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/nodes"
 )
 
@@ -37,6 +38,8 @@ Example: praefect --config praefect.config.toml dial-nodes`,
 }
 
 func dialNodesAction(ctx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(ctx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_list_storages.go b/internal/cli/praefect/subcmd_list_storages.go
index 4f4d91b46..816a811bf 100644
--- a/internal/cli/praefect/subcmd_list_storages.go
+++ b/internal/cli/praefect/subcmd_list_storages.go
@@ -5,6 +5,7 @@ import (
 
 	"github.com/olekukonko/tablewriter"
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 )
 
 func newListStoragesCommand() *cli.Command {
@@ -44,6 +45,8 @@ Example: praefect --config praefect.config.toml list-storages --virtual-storage
 }
 
 func listStoragesAction(ctx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(ctx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_list_untracked_repositories.go b/internal/cli/praefect/subcmd_list_untracked_repositories.go
index 0551061c1..289ede89f 100644
--- a/internal/cli/praefect/subcmd_list_untracked_repositories.go
+++ b/internal/cli/praefect/subcmd_list_untracked_repositories.go
@@ -6,7 +6,6 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"os"
 	"time"
 
 	"github.com/urfave/cli/v2"
@@ -64,16 +63,13 @@ Examples:
 }
 
 func listUntrackedRepositoriesAction(appCtx *cli.Context) error {
+	logger := log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
 	}
 
-	logger, err := log.Configure(os.Stderr, "text", "error")
-	if err != nil {
-		return fmt.Errorf("configuring logger: %w", err)
-	}
-
 	onlyIncludeOlderThan := appCtx.Duration("older-than")
 	delimiter := appCtx.String("delimiter")
 
diff --git a/internal/cli/praefect/subcmd_metadata.go b/internal/cli/praefect/subcmd_metadata.go
index ed89d6d0a..5393e6f89 100644
--- a/internal/cli/praefect/subcmd_metadata.go
+++ b/internal/cli/praefect/subcmd_metadata.go
@@ -5,6 +5,7 @@ import (
 	"fmt"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/proto/go/gitalypb"
 )
 
@@ -57,6 +58,8 @@ Examples:
 }
 
 func metadataAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_remove_repository.go b/internal/cli/praefect/subcmd_remove_repository.go
index 1efdd701b..bb4b0a4a9 100644
--- a/internal/cli/praefect/subcmd_remove_repository.go
+++ b/internal/cli/praefect/subcmd_remove_repository.go
@@ -6,7 +6,6 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"os"
 	"sync"
 	"time"
 
@@ -74,16 +73,13 @@ func newRemoveRepositoryCommand() *cli.Command {
 }
 
 func removeRepositoryAction(appCtx *cli.Context) error {
+	logger := log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
 	}
 
-	logger, err := log.Configure(os.Stderr, "text", "error")
-	if err != nil {
-		return fmt.Errorf("configuring logger: %w", err)
-	}
-
 	ctx := appCtx.Context
 	openDBCtx, cancel := context.WithTimeout(ctx, 30*time.Second)
 	defer cancel()
diff --git a/internal/cli/praefect/subcmd_set_replication_factor.go b/internal/cli/praefect/subcmd_set_replication_factor.go
index a274139cb..eaa5b6158 100644
--- a/internal/cli/praefect/subcmd_set_replication_factor.go
+++ b/internal/cli/praefect/subcmd_set_replication_factor.go
@@ -5,6 +5,7 @@ import (
 	"strings"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/proto/go/gitalypb"
 )
 
@@ -66,6 +67,8 @@ Example: praefect --config praefect.config.toml set-replication-factor --virtual
 }
 
 func setReplicationFactorAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_sql_migrate.go b/internal/cli/praefect/subcmd_sql_migrate.go
index e2fa0428b..a98b14aa9 100644
--- a/internal/cli/praefect/subcmd_sql_migrate.go
+++ b/internal/cli/praefect/subcmd_sql_migrate.go
@@ -6,6 +6,7 @@ import (
 
 	migrate "github.com/rubenv/sql-migrate"
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/datastore/glsql"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/datastore/migrations"
 )
@@ -46,6 +47,8 @@ func newSQLMigrateCommand() *cli.Command {
 }
 
 func sqlMigrateAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_sql_migrate_down.go b/internal/cli/praefect/subcmd_sql_migrate_down.go
index 02105e3f5..4c643cc54 100644
--- a/internal/cli/praefect/subcmd_sql_migrate_down.go
+++ b/internal/cli/praefect/subcmd_sql_migrate_down.go
@@ -5,6 +5,7 @@ import (
 	"strconv"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/datastore"
 )
 
@@ -39,6 +40,8 @@ func newSQLMigrateDownCommand() *cli.Command {
 }
 
 func sqlMigrateDownAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_sql_migrate_status.go b/internal/cli/praefect/subcmd_sql_migrate_status.go
index b20b3eaf1..45bdd8097 100644
--- a/internal/cli/praefect/subcmd_sql_migrate_status.go
+++ b/internal/cli/praefect/subcmd_sql_migrate_status.go
@@ -5,6 +5,7 @@ import (
 
 	"github.com/olekukonko/tablewriter"
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/datastore"
 )
 
@@ -29,6 +30,8 @@ func newSQLMigrateStatusCommand() *cli.Command {
 }
 
 func sqlMigrateStatusAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_sql_ping.go b/internal/cli/praefect/subcmd_sql_ping.go
index 7d452dfb3..3811c8739 100644
--- a/internal/cli/praefect/subcmd_sql_ping.go
+++ b/internal/cli/praefect/subcmd_sql_ping.go
@@ -4,6 +4,7 @@ import (
 	"fmt"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/praefect/datastore"
 )
 
@@ -27,6 +28,8 @@ func newSQLPingCommand() *cli.Command {
 }
 
 func sqlPingAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/cli/praefect/subcmd_track_repositories.go b/internal/cli/praefect/subcmd_track_repositories.go
index 4c942cc35..9de4ddfbf 100644
--- a/internal/cli/praefect/subcmd_track_repositories.go
+++ b/internal/cli/praefect/subcmd_track_repositories.go
@@ -58,16 +58,13 @@ func newTrackRepositoriesCommand() *cli.Command {
 }
 
 func trackRepositoriesAction(appCtx *cli.Context) error {
+	logger := log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
 	}
 
-	logger, err := log.Configure(os.Stderr, "text", "error")
-	if err != nil {
-		return fmt.Errorf("configuring logger: %w", err)
-	}
-
 	db, clean, err := openDB(conf.DB, appCtx.App.ErrWriter)
 	if err != nil {
 		return fmt.Errorf("connect to database: %w", err)
diff --git a/internal/cli/praefect/subcmd_track_repository.go b/internal/cli/praefect/subcmd_track_repository.go
index 576913f88..1dab90546 100644
--- a/internal/cli/praefect/subcmd_track_repository.go
+++ b/internal/cli/praefect/subcmd_track_repository.go
@@ -7,7 +7,6 @@ import (
 	"fmt"
 	"io"
 	"math/rand"
-	"os"
 	"time"
 
 	"github.com/sirupsen/logrus"
@@ -87,16 +86,13 @@ type trackRepositoryRequest struct {
 var errAuthoritativeRepositoryNotExist = errors.New("authoritative repository does not exist")
 
 func trackRepositoryAction(appCtx *cli.Context) error {
+	logger := log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
 	}
 
-	logger, err := log.Configure(os.Stderr, "text", "error")
-	if err != nil {
-		return fmt.Errorf("configuring logger: %w", err)
-	}
-
 	virtualStorage := appCtx.String(paramVirtualStorage)
 	relativePath := appCtx.String(paramRelativePath)
 	replicaPath := appCtx.String(paramReplicaPath)
diff --git a/internal/cli/praefect/subcmd_verify.go b/internal/cli/praefect/subcmd_verify.go
index 2d3f7b1bb..6c5da4a56 100644
--- a/internal/cli/praefect/subcmd_verify.go
+++ b/internal/cli/praefect/subcmd_verify.go
@@ -5,6 +5,7 @@ import (
 	"fmt"
 
 	"github.com/urfave/cli/v2"
+	"gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/gitaly/v16/proto/go/gitalypb"
 )
 
@@ -58,6 +59,8 @@ Examples:
 }
 
 func verifyAction(appCtx *cli.Context) error {
+	log.ConfigureCommand()
+
 	conf, err := readConfig(appCtx.String(configFlagName))
 	if err != nil {
 		return err
diff --git a/internal/log/logger.go b/internal/log/logger.go
index 899cf5d06..d7a60946d 100644
--- a/internal/log/logger.go
+++ b/internal/log/logger.go
@@ -88,6 +88,31 @@ func Configure(out io.Writer, format string, level string, hooks ...logrus.Hook)
 	return logger.WithField("pid", os.Getpid()), nil
 }
 
+// ConfigureCommand configures the logging infrastructure such that it can be used with simple one-off commands. This
+// configuration is supposed to be opinionated and ensures that all one-off commands behave in a sane way:
+//
+//   - The server configuration does not influence logs generated by the command. This is done intentionally as you don't
+//     want to force administrators to adapt the server configuration to influence normal commands.
+//
+//   - The output always goes to stderr such that output that is supposed to be consumed can be separated from log
+//     messages.
+//
+//   - The output uses text format as it is supposed to be human-readable, not machine-readable.
+//
+//   - The default log level is set to "error" such that we don't generate tons of log messages that are ultimately
+//     uninteresting.
+//
+// Servers and commands with special requirements should instead use `Configure()`.
+func ConfigureCommand() logrus.FieldLogger {
+	logger, err := Configure(os.Stderr, "text", "error")
+	if err != nil {
+		// The configuration can't really return an error as we invoke it with known-good parameters.
+		panic(err)
+	}
+
+	return logger
+}
+
 func configure(logger *logrus.Logger, out io.Writer, format, level string, hooks ...logrus.Hook) error {
 	var formatter logrus.Formatter
 	switch format {