Merge branch 'ef-ensure-we-log-to-log-file' into 'main'

fix: ensure logs are routed to correct file with correct min level

See merge request https://gitlab.com/gitlab-org/gitlab-shell/-/merge_requests/1369

Merged-by: Igor Drozdov <idrozdov@gitlab.com>
Approved-by: Igor Drozdov <idrozdov@gitlab.com>
Co-authored-by: e_forbes <eforbes@gitlab.com>

Author: 2 people

cmd/gitlab-sshd/main.go

@@ -46,20 +46,19 @@ func overrideConfigFromEnvironment(cfg *config.Config) {
 func main() {
 	ctx := context.Background()
 	command.CheckForVersionFlag(os.Args, Version, BuildTime)
-
-	log := logger.ConfigureLogger()
 	flag.Parse()
 
 	cfg := new(config.Config)
 	if *configDir != "" {
 		var err error
 		cfg, err = config.NewFromDir(*configDir)
 		if err != nil {
-			log.ErrorContext(ctx, "failed to load configuration from specified directory", slog.String(
+			v2log.New().ErrorContext(ctx, "failed to load configuration from specified directory", slog.String(
 				fields.ErrorMessage, err.Error(),
 			))
 		}
 	}
+	log := logger.ConfigureLogger(cfg)
 	log.InfoContext(ctx, "gitlab-sshd starting up...")
 
 	overrideConfigFromEnvironment(cfg)

go.mod

@@ -23,7 +23,7 @@ require (
 	// Please do not override. Once v16.11.1 is released, this comment
 	// can be removed.
 	gitlab.com/gitlab-org/gitaly/v16 v16.11.0-rc1.0.20250408053233-c6d43513e93c
-	gitlab.com/gitlab-org/labkit v1.35.0
+	gitlab.com/gitlab-org/labkit v1.36.0
 	golang.org/x/crypto v0.41.0
 	golang.org/x/sync v0.16.0
 	google.golang.org/grpc v1.72.0

go.sum

@@ -554,8 +554,8 @@ gitlab.com/gitlab-org/gitaly/v16 v16.11.0-rc1.0.20250408053233-c6d43513e93c h1:x
 gitlab.com/gitlab-org/gitaly/v16 v16.11.0-rc1.0.20250408053233-c6d43513e93c/go.mod h1:/rkj6992VsNymUeG6N3VnLZ8Pvb1Y9ZUo00Yy35t8WQ=
 gitlab.com/gitlab-org/go/reopen v1.0.0 h1:6BujZ0lkkjGIejTUJdNO1w56mN1SI10qcVQyQlOPM+8=
 gitlab.com/gitlab-org/go/reopen v1.0.0/go.mod h1:D6OID8YJDzEVZNYW02R/Pkj0v8gYFSIhXFTArAsBQw8=
-gitlab.com/gitlab-org/labkit v1.35.0 h1:6PSRUvmuEKFrAZpQPLlMNIdbtZHyKHaqyRlM4PDYDbs=
-gitlab.com/gitlab-org/labkit v1.35.0/go.mod h1:JqQLdgjV/KKAZJ6gvNodaLStmWeTT9mxgJPIEi66VHI=
+gitlab.com/gitlab-org/labkit v1.36.0 h1:QA60DLXmtOyIRchrxaRwonrtbviWQogA623tR2JijE4=
+gitlab.com/gitlab-org/labkit v1.36.0/go.mod h1:JqQLdgjV/KKAZJ6gvNodaLStmWeTT9mxgJPIEi66VHI=
 go.etcd.io/raft/v3 v3.6.0 h1:5NtvbDVYpnfZWcIHgGRk9DyzkBIXOi8j+DDp1IcnUWQ=
 go.etcd.io/raft/v3 v3.6.0/go.mod h1:nLvLevg6+xrVtHUmVaTcTz603gQPHfh7kUAwV6YpfGo=
 go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU=

internal/logger/logger.go

@@ -18,13 +18,49 @@ import (
 // ConfigureLogger - gitlab-sshd's log output can be configured to text as per the documentation:
 // https://docs.gitlab.com/omnibus/settings/logs/#json-logging
 // This is currently controlled by the GITLAB_LOG_FORMAT environment variable.
-func ConfigureLogger() *slog.Logger {
+func ConfigureLogger(cfg *config.Config) *slog.Logger {
+	logConfig := &v2log.Config{
+		LogLevel: parseLogLevel(cfg.LogLevel),
+	}
+	logFile, err := os.OpenFile(cfg.LogFile, os.O_APPEND|os.O_WRONLY, 0600)
+	if err != nil {
+		syslogError(err)
+		logConfig.Writer = os.Stderr
+	} else {
+		logConfig.Writer = logFile
+	}
+
 	if gitlabLogFormat := os.Getenv("GITLAB_LOG_FORMAT"); gitlabLogFormat == "text" {
-		return v2log.NewWithConfig(&v2log.Config{
-			UseTextFormat: true,
-		})
+		logConfig.UseTextFormat = true
+	}
+	return v2log.NewWithConfig(logConfig)
+}
+
+func parseLogLevel(level string) slog.Level {
+	switch level {
+	case "DEBUG", "debug":
+		return slog.LevelDebug
+	case "INFO", "info":
+		return slog.LevelInfo
+	case "WARN", "warn":
+		return slog.LevelWarn
+	case "ERROR", "error":
+		return slog.LevelError
+	default:
+		return slog.LevelInfo
+	}
+}
+
+func syslogError(err error) {
+	syslogLogger, syslogLoggerErr := syslog.NewLogger(syslog.LOG_ERR|syslog.LOG_USER, 0)
+	progName, _ := os.Executable()
+	if syslogLoggerErr == nil {
+		msg := fmt.Sprintf("%s: Unable to configure logging: %v\n", progName, err.Error())
+		syslogLogger.Print(msg)
+	} else {
+		msg := fmt.Sprintf("%s: Unable to configure logging: %v, %v\n", progName, err.Error(), syslogLoggerErr.Error())
+		fmt.Fprintln(os.Stderr, msg)
 	}
-	return v2log.New()
 }
 
 func logFmt(inFmt string) string {
@@ -74,15 +110,7 @@ func Configure(cfg *config.Config) io.Closer {
 	}
 
 	if err != nil {
-		progName, _ := os.Executable()
-		syslogLogger, syslogLoggerErr := syslog.NewLogger(syslog.LOG_ERR|syslog.LOG_USER, 0)
-		if syslogLoggerErr == nil {
-			msg := fmt.Sprintf("%s: Unable to configure logging: %v\n", progName, err.Error())
-			syslogLogger.Print(msg)
-		} else {
-			msg := fmt.Sprintf("%s: Unable to configure logging: %v, %v\n", progName, err.Error(), syslogLoggerErr.Error())
-			fmt.Fprintln(os.Stderr, msg)
-		}
+		syslogError(err)
 
 		cfg.LogFile = "/dev/null"
 		closer, err = log.Initialize(buildOpts(cfg)...)

internal/logger/logger_test.go

@@ -98,3 +98,22 @@ func createTempFile(t *testing.T) string {
 
 	return tmpFile.Name()
 }
+
+func TestConfigureLabkitV2Log(t *testing.T) {
+	tmpFile := createTempFile(t)
+	config := config.Config{
+		LogFile:   tmpFile,
+		LogFormat: "json",
+		LogLevel:  "debug",
+	}
+
+	logger := ConfigureLogger(&config)
+	logger.Info("this is a test")
+	logger.Debug("debug log message")
+
+	data, err := os.ReadFile(tmpFile)
+	dataStr := string(data)
+	require.NoError(t, err)
+	require.Contains(t, dataStr, `"msg":"this is a test"`)
+	require.Contains(t, dataStr, `"msg":"debug log message"`)
+}