Log command invocation499-log-command-invocation

Use reflection to log the command we are about to execute, both in
gitlab-shell and gitlab-sshd. Include the environment, which has all
the context we need to understand what the command is expected to do.

Changelog: added

2 files changed, 18 insertions, 1 deletions

diff --git a/cmd/gitlab-shell/main.go b/cmd/gitlab-shell/main.go
index 2576e8b..a945d0c 100644
--- a/cmd/gitlab-shell/main.go
+++ b/cmd/gitlab-shell/main.go
@@ -3,6 +3,9 @@ package main
 import (
 	"fmt"
 	"os"
+	"reflect"
+
+	"gitlab.com/gitlab-org/labkit/log"
 
 	shellCmd "gitlab.com/gitlab-org/gitlab-shell/cmd/gitlab-shell/command"
 	"gitlab.com/gitlab-org/gitlab-shell/internal/command"
@@ -62,8 +65,15 @@ func main() {
 	ctx, finished := command.Setup(executable.Name, config)
 	defer finished()
 
-	if err = cmd.Execute(ctx); err != nil {
+	cmdName := reflect.TypeOf(cmd).String()
+	ctxlog := log.ContextLogger(ctx)
+	ctxlog.WithFields(log.Fields{"env": env, "command": cmdName}).Info("gitlab-shell: main: executing command")
+
+	if err := cmd.Execute(ctx); err != nil {
+		ctxlog.WithError(err).Warn("gitlab-shell: main: command execution failed")
 		console.DisplayWarningMessage(err.Error(), readWriter.ErrOut)
 		os.Exit(1)
 	}
+
+	ctxlog.Info("gitlab-shell: main: command executed successfully")
 }
diff --git a/internal/sshd/session.go b/internal/sshd/session.go
index b26edc5..b8e8625 100644
--- a/internal/sshd/session.go
+++ b/internal/sshd/session.go
@@ -4,6 +4,7 @@ import (
 	"context"
 	"errors"
 	"fmt"
+	"reflect"
 
 	"gitlab.com/gitlab-org/labkit/log"
 	"golang.org/x/crypto/ssh"
@@ -149,11 +150,17 @@ func (s *session) handleShell(ctx context.Context, req *ssh.Request) uint32 {
 		return 128
 	}
 
+	cmdName := reflect.TypeOf(cmd).String()
+	ctxlog := log.ContextLogger(ctx)
+	ctxlog.WithFields(log.Fields{"env": env, "command": cmdName}).Info("session: handleShell: executing command")
+
 	if err := cmd.Execute(ctx); err != nil {
 		s.toStderr(ctx, "remote: ERROR: %v\n", err.Error())
 		return 1
 	}
 
+	ctxlog.Info("session: handleShell: command executed successfully")
+
 	return 0
 }