cmd/gitaly-git2go: Use log writer instead of splicing log outputs

When spawning gitaly-git2go processes, we redirect their stderr to print
to the writer used by our global logging mechanism. This should in the
general case be stderr of the Gitaly process, which means that any logs
would get spliced into the main logging stream generated by Gitaly.

The mechanism isn't great though, and we're about to get rid of the
global logging instance in favor of the injected ones. Given that this
is the last instance where we still rely on the global logger's internal
workings, and that the gitaly-git2go command is going away in a release
or two anyway, there is thus a strong urge to adapt it to unblock our
remaining logging refactorings.

And that's exactly what we do now. Instead of reaching into the global
logging instance to retrieve its writer, we simply construct a writer
from the logger and pass that to the newly created process. Now this has
the downside that we're unable to control the log level, and furthermore
it will cause the log messages themselves to be encoded in JSON again.
But as said, this is only a temporary measure that we can get rid of in
the near future by removing the complete gitaly-git2go command.

This change removes the last instance where we rely on our logger to be
a `logrus.Logger` and is also the last user of `log.Default()`.

5 files changed, 20 insertions, 11 deletions

diff --git a/cmd/gitaly-git2go/testhelper_test.go b/cmd/gitaly-git2go/testhelper_test.go
index f798dc417..0d72bec57 100644
--- a/cmd/gitaly-git2go/testhelper_test.go
+++ b/cmd/gitaly-git2go/testhelper_test.go
@@ -40,5 +40,5 @@ func TestMain(m *testing.M) {
 }
 
 func buildExecutor(tb testing.TB, cfg config.Cfg) *git2go.Executor {
-	return git2go.NewExecutor(cfg, gittest.NewCommandFactory(tb, cfg), config.NewLocator(cfg))
+	return git2go.NewExecutor(cfg, gittest.NewCommandFactory(tb, cfg), config.NewLocator(cfg), testhelper.SharedLogger(tb))
 }
diff --git a/internal/cli/gitaly/serve.go b/internal/cli/gitaly/serve.go
index fd4470241..825bb19d8 100644
--- a/internal/cli/gitaly/serve.go
+++ b/internal/cli/gitaly/serve.go
@@ -320,7 +320,7 @@ func run(cfg config.Cfg, logger logrus.FieldLogger) error {
 	)
 	defer gitalyServerFactory.Stop()
 
-	git2goExecutor := git2go.NewExecutor(cfg, gitCmdFactory, locator)
+	git2goExecutor := git2go.NewExecutor(cfg, gitCmdFactory, locator, logger)
 
 	updaterWithHooks := updateref.NewUpdaterWithHooks(cfg, locator, hookManager, gitCmdFactory, catfileCache)
 
diff --git a/internal/git2go/executor.go b/internal/git2go/executor.go
index c59000020..f5cca8252 100644
--- a/internal/git2go/executor.go
+++ b/internal/git2go/executor.go
@@ -9,13 +9,13 @@ import (
 	"io"
 	"strings"
 
+	"github.com/sirupsen/logrus"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/command"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/featureflag"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/git"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/git/alternates"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/config"
 	"gitlab.com/gitlab-org/gitaly/v16/internal/gitaly/storage"
-	glog "gitlab.com/gitlab-org/gitaly/v16/internal/log"
 	"gitlab.com/gitlab-org/labkit/correlation"
 )
 
@@ -33,17 +33,19 @@ type Executor struct {
 	signingKey          string
 	gitCmdFactory       git.CommandFactory
 	locator             storage.Locator
+	logger              logrus.FieldLogger
 	logFormat, logLevel string
 }
 
 // NewExecutor returns a new gitaly-git2go executor using binaries as configured in the given
 // configuration.
-func NewExecutor(cfg config.Cfg, gitCmdFactory git.CommandFactory, locator storage.Locator) *Executor {
+func NewExecutor(cfg config.Cfg, gitCmdFactory git.CommandFactory, locator storage.Locator, logger logrus.FieldLogger) *Executor {
 	return &Executor{
 		binaryPath:    cfg.BinaryPath(BinaryName),
 		signingKey:    cfg.Git.SigningKey,
 		gitCmdFactory: gitCmdFactory,
 		locator:       locator,
+		logger:        logger,
 		logFormat:     cfg.Logging.Format,
 		logLevel:      cfg.Logging.Level,
 	}
@@ -69,10 +71,17 @@ func (b *Executor) run(ctx context.Context, repo storage.Repository, stdin io.Re
 	env := alternates.Env(repoPath, repo.GetGitObjectDirectory(), repo.GetGitAlternateObjectDirectories())
 	env = append(env, b.gitCmdFactory.GetExecutionEnvironment(ctx).EnvironmentVariables...)
 
-	// Pass the log output directly to gitaly-git2go. No need to reinterpret
-	// these logs as long as the destination is an append-only file. See
-	// https://pkg.go.dev/github.com/sirupsen/logrus#readme-thread-safety
-	log := glog.Default().Logger.Out
+	// Construct a log writer that we pass to gitaly-git2go. Note that this is not exactly pretty: the output
+	// generated by the logger is not going to be parsed, but will be written to the log without any change as log
+	// message.
+	//
+	// Previously, we would have written these messages to `logrus.Logger.Out` directly. But we have refactored our
+	// code to get rid of the global logger instance, and thus we cannot access that field anymore. Given that the
+	// git2go executor is going away next release anyway, let's just live with this ugly workaround here. We still
+	// have visibility into what the process is doing, but with a bit less comfort. That seems like an acceptable
+	// tradeoff in order to get rid of the global logger altogether.
+	logWriter := b.logger.WithField("component", "git2go."+subcmd).Writer()
+	defer logWriter.Close()
 
 	args = append([]string{
 		"-log-format", b.logFormat,
@@ -87,7 +96,7 @@ func (b *Executor) run(ctx context.Context, repo storage.Repository, stdin io.Re
 	cmd, err := command.New(ctx, append([]string{b.binaryPath}, args...),
 		command.WithStdin(stdin),
 		command.WithStdout(&stdout),
-		command.WithStderr(log),
+		command.WithStderr(logWriter),
 		command.WithEnvironment(env),
 		command.WithCommandName("gitaly-git2go", subcmd),
 	)
diff --git a/internal/git2go/featureflags_test.go b/internal/git2go/featureflags_test.go
index e8c65c63b..db2a35992 100644
--- a/internal/git2go/featureflags_test.go
+++ b/internal/git2go/featureflags_test.go
@@ -52,7 +52,7 @@ func testExecutorFeatureFlags(t *testing.T, ctx context.Context) {
 
 	repo := localrepo.NewTestRepo(t, cfg, repoProto)
 
-	executor := NewExecutor(cfg, gittest.NewCommandFactory(t, cfg), config.NewLocator(cfg))
+	executor := NewExecutor(cfg, gittest.NewCommandFactory(t, cfg), config.NewLocator(cfg), testhelper.SharedLogger(t))
 
 	flags, err := executor.FeatureFlags(ctx, repo)
 	require.NoError(t, err)
diff --git a/internal/testhelper/testserver/gitaly.go b/internal/testhelper/testserver/gitaly.go
index 0b473ea18..6baae7859 100644
--- a/internal/testhelper/testserver/gitaly.go
+++ b/internal/testhelper/testserver/gitaly.go
@@ -344,7 +344,7 @@ func (gsd *gitalyServerDeps) createDependencies(tb testing.TB, cfg config.Cfg) *
 	}
 
 	if gsd.git2goExecutor == nil {
-		gsd.git2goExecutor = git2go.NewExecutor(cfg, gsd.gitCmdFactory, gsd.locator)
+		gsd.git2goExecutor = git2go.NewExecutor(cfg, gsd.gitCmdFactory, gsd.locator, gsd.logger)
 	}
 
 	if gsd.updaterWithHooks == nil {