Handle log configuration via config.toml file

commands/multi.go

@@ -259,12 +259,9 @@ func (mr *RunCommand) loadConfig() error {
 	}
 
 	// Set log level
-	if !log.IsCustomLevelUsed() && mr.config.LogLevel != nil {
-		level, err := logrus.ParseLevel(*mr.config.LogLevel)
-		if err != nil {
-			logrus.WithError(err).Fatal("Failed to parse error level from configuration file")
-		}
-		logrus.SetLevel(level)
+	err = mr.updateLoggingConfiguration()
+	if err != nil {
+		return err
 	}
 
 	// pass user to execute scripts as specific user
@@ -290,6 +287,34 @@ func (mr *RunCommand) loadConfig() error {
 	return nil
 }
 
+func (mr *RunCommand) updateLoggingConfiguration() error {
+	reloadNeeded := false
+
+	if mr.config.LogLevel != nil && !log.Configuration().IsLevelSetWithCli() {
+		err := log.Configuration().SetLevel(*mr.config.LogLevel)
+		if err != nil {
+			return err
+		}
+
+		reloadNeeded = true
+	}
+
+	if mr.config.LogFormat != nil && !log.Configuration().IsFormatSetWithCli() {
+		err := log.Configuration().SetFormat(*mr.config.LogFormat)
+		if err != nil {
+			return err
+		}
+
+		reloadNeeded = true
+	}
+
+	if reloadNeeded {
+		log.Configuration().ReloadConfiguration()
+	}
+
+	return nil
+}
+
 func (mr *RunCommand) checkConfig() (err error) {
 	info, err := os.Stat(mr.ConfigFile)
 	if err != nil {

common/config.go

@@ -306,6 +306,7 @@ type Config struct {
 	Concurrent    int             `toml:"concurrent" json:"concurrent"`
 	CheckInterval int             `toml:"check_interval" json:"check_interval" description:"Define active checking interval of jobs"`
 	LogLevel      *string         `toml:"log_level" json:"log_level" description:"Define log level (one of: panic, fatal, error, warning, info, debug)"`
+	LogFormat     *string         `toml:"log_format" json:"log_format" description:"Define log format (one of: runner, text, json)"`
 	User          string          `toml:"user,omitempty" json:"user"`
 	Runners       []*RunnerConfig `toml:"runners" json:"runners"`
 	SentryDSN     *string         `toml:"sentry_dsn"`

docs/configuration/advanced-configuration.md

@@ -17,7 +17,8 @@ This defines global settings of GitLab Runner.
 | Setting | Description |
 | ------- | ----------- |
 | `concurrent`     | limits how many jobs globally can be run concurrently. The most upper limit of jobs using all defined runners. `0` **does not** mean unlimited |
-| `log_level`      | Log level (options: debug, info, warn, error, fatal, panic). Note that this setting has lower priority than log-level set by command line argument --debug, -l or --log-level |
+| `log_level`      | Log level (options: debug, info, warn, error, fatal, panic). Note that this setting has lower priority than level set by command line argument `--debug`, `-l` or `--log-level` |
+| `log_format`     | Log format (options: runner, text, json). Note that this setting has lower priority than format set by command line argument `--log-format` |
 | `check_interval` | defines the interval length, in seconds, between new jobs check. The default value is `3`; if set to `0` or lower, the default value will be used. |
 | `sentry_dsn`     | enable tracking of all system level errors to sentry |
 | `listen_address` | address (`<host>:<port>`) on which the Prometheus metrics HTTP server should be listening |

log/configuration.go

 package log
 
 import (
+	"fmt"
 	"os"
 
 	"github.com/sirupsen/logrus"
@@ -14,8 +15,7 @@ const (
 )
 
 var (
-	defaultLogLevel = logrus.InfoLevel
-	customLevelUsed = false
+	configuration = NewConfig()
 
 	logFlags = []cli.Flag{
 		cli.BoolFlag{
@@ -27,7 +27,6 @@ var (
 			Name:   "log-format",
 			Usage:  "Choose log format (options: runner, text, json)",
 			EnvVar: "LOG_FORMAT",
-			Value:  FormatRunner,
 		},
 		cli.StringFlag{
 			Name:   "log-level, l",
@@ -43,68 +42,139 @@ var (
 	}
 )
 
-func IsCustomLevelUsed() bool {
-	return customLevelUsed
+func formatNames() []string {
+	formatNames := make([]string, 0)
+	for name := range formats {
+		formatNames = append(formatNames, name)
+	}
+
+	return formatNames
 }
 
-func ConfigureLogging(app *cli.App) {
-	app.Flags = append(app.Flags, logFlags...)
+type Config struct {
+	level  logrus.Level
+	format logrus.Formatter
 
-	appBefore := app.Before
-	app.Before = func(cliCtx *cli.Context) error {
-		logrus.SetOutput(os.Stderr)
+	levelSetWithCli  bool
+	formatSetWithCli bool
 
-		setupFormatter(cliCtx)
-		setupLevel(cliCtx)
+	goroutinesDumpStopCh chan bool
+}
 
-		if appBefore != nil {
-			return appBefore(cliCtx)
+func (l *Config) IsLevelSetWithCli() bool {
+	return l.levelSetWithCli
+}
+
+func (l *Config) IsFormatSetWithCli() bool {
+	return l.formatSetWithCli
+}
+
+func (l *Config) handleCliCtx(cliCtx *cli.Context) error {
+	if cliCtx.IsSet("log-level") || cliCtx.IsSet("l") {
+		err := l.SetLevel(cliCtx.String("log-level"))
+		if err != nil {
+			return err
 		}
-		return nil
+		l.levelSetWithCli = true
 	}
-}
 
-func setupFormatter(cliCtx *cli.Context) {
-	format := cliCtx.String("log-format")
-	formatter, ok := formats[format]
+	if cliCtx.Bool("debug") {
+		l.level = logrus.DebugLevel
+		l.levelSetWithCli = true
+	}
 
-	if !ok {
-		logrus.WithField("format", format).Fatalf("Unknown log format. Expected one of: %v", formatNames())
+	if cliCtx.IsSet("log-format") {
+		err := l.SetFormat(cliCtx.String("log-format"))
+		if err != nil {
+			return err
+		}
+
+		l.formatSetWithCli = true
 	}
 
-	logrus.SetFormatter(formatter)
+	l.ReloadConfiguration()
+
+	return nil
 }
 
-func formatNames() []string {
-	formatNames := make([]string, 0)
-	for name := range formats {
-		formatNames = append(formatNames, name)
+func (l *Config) SetLevel(levelString string) error {
+	level, err := logrus.ParseLevel(levelString)
+	if err != nil {
+		return fmt.Errorf("failed to parse log level: %v", err)
 	}
 
-	return formatNames
+	l.level = level
+
+	return nil
 }
 
-func setupLevel(cliCtx *cli.Context) {
-	if cliCtx.IsSet("log-level") || cliCtx.IsSet("l") {
-		level, err := logrus.ParseLevel(cliCtx.String("log-level"))
-		if err != nil {
-			logrus.WithError(err).Fatal("Failed to parse log level")
-		}
+func (l *Config) SetFormat(format string) error {
+	formatter, ok := formats[format]
+	if !ok {
+		return fmt.Errorf("unknown log format %q, expected one of: %v", l.format, formatNames())
+	}
+
+	l.format = formatter
+
+	return nil
+}
 
-		logrus.SetLevel(level)
-		customLevelUsed = true
+func (l *Config) ReloadConfiguration() {
+	logrus.SetFormatter(l.format)
+	logrus.SetLevel(l.level)
 
+	if l.level == logrus.DebugLevel {
+		l.enableGoroutinesDump()
+	} else {
+		l.disableGoroutinesDump()
+	}
+}
+
+func (l *Config) enableGoroutinesDump() {
+	if l.goroutinesDumpStopCh != nil {
 		return
 	}
 
-	if cliCtx.Bool("debug") {
-		go watchForGoroutinesDump()
+	l.goroutinesDumpStopCh = make(chan bool)
 
-		logrus.SetLevel(logrus.DebugLevel)
-		customLevelUsed = true
+	watchForGoroutinesDump(l.goroutinesDumpStopCh)
+}
 
+func (l *Config) disableGoroutinesDump() {
+	if l.goroutinesDumpStopCh == nil {
 		return
 	}
 
-	logrus.SetLevel(defaultLogLevel)
+	close(l.goroutinesDumpStopCh)
+	l.goroutinesDumpStopCh = nil
+}
+
+func NewConfig() *Config {
+	return &Config{
+		level:  logrus.InfoLevel,
+		format: new(RunnerTextFormatter),
+	}
+}
+
+func Configuration() *Config {
+	return configuration
+}
+
+func ConfigureLogging(app *cli.App) {
+	app.Flags = append(app.Flags, logFlags...)
+
+	appBefore := app.Before
+	app.Before = func(cliCtx *cli.Context) error {
+		logrus.SetOutput(os.Stderr)
+
+		err := Configuration().handleCliCtx(cliCtx)
+		if err != nil {
+			logrus.WithError(err).Fatal("Error while setting up logging configuration")
+		}
+
+		if appBefore != nil {
+			return appBefore(cliCtx)
+		}
+		return nil
+	}
 }

log/configuration_test.go

+package log
+
+import (
+	"testing"
+
+	"github.com/sirupsen/logrus"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"github.com/urfave/cli"
+
+	"gitlab.com/gitlab-org/gitlab-runner/helpers"
+)
+
+func prepareFakeConfiguration() func() {
+	oldConfiguration := configuration
+	configuration = NewConfig()
+
+	return func() {
+		configuration = oldConfiguration
+		configuration.ReloadConfiguration()
+	}
+}
+
+func testCommandRun(args ...string) {
+	app := cli.NewApp()
+	app.Commands = []cli.Command{
+		{
+			Name:   "logtest",
+			Action: func(cliCtx *cli.Context) {},
+		},
+	}
+
+	ConfigureLogging(app)
+
+	args = append([]string{"binary"}, args...)
+	args = append(args, "logtest")
+
+	app.Run(args)
+}
+
+type handleCliCtxTestCase struct {
+	args                       []string
+	expectedError              string
+	expectedLevel              logrus.Level
+	expectedFormatter          logrus.Formatter
+	expectedLevelSetWithCli    bool
+	expectedFormatSetWithCli   bool
+	goroutinesDumpStopChExists bool
+}
+
+func TestHandleCliCtx(t *testing.T) {
+	tests := map[string]handleCliCtxTestCase{
+		"no configuration specified": {
+			expectedLevel:     logrus.InfoLevel,
+			expectedFormatter: new(RunnerTextFormatter),
+		},
+		"--log-level specified": {
+			args:                    []string{"--log-level", "error"},
+			expectedLevel:           logrus.ErrorLevel,
+			expectedFormatter:       new(RunnerTextFormatter),
+			expectedLevelSetWithCli: true,
+		},
+		"--debug specified": {
+			args:                       []string{"--debug"},
+			expectedLevel:              logrus.DebugLevel,
+			expectedFormatter:          new(RunnerTextFormatter),
+			expectedLevelSetWithCli:    true,
+			goroutinesDumpStopChExists: true,
+		},
+		"--log-level and --debug specified": {
+			args:                       []string{"--log-level", "error", "--debug"},
+			expectedLevel:              logrus.DebugLevel,
+			expectedFormatter:          new(RunnerTextFormatter),
+			expectedLevelSetWithCli:    true,
+			goroutinesDumpStopChExists: true,
+		},
+		"invalid --log-level specified": {
+			args:          []string{"--log-level", "test"},
+			expectedError: "failed to parse log level",
+		},
+		"--log-format specified": {
+			args:                     []string{"--log-format", "json"},
+			expectedLevel:            logrus.InfoLevel,
+			expectedFormatter:        new(logrus.JSONFormatter),
+			expectedFormatSetWithCli: true,
+		},
+		"invalid --log-format specified": {
+			args:          []string{"--log-format", "test"},
+			expectedError: "unknown log format",
+		},
+	}
+
+	for name, test := range tests {
+		t.Run(name, func(t *testing.T) {
+			defer prepareFakeConfiguration()()
+			defer helpers.MakeFatalToPanic()()
+
+			testFunc := func() {
+				testCommandRun(test.args...)
+				if test.expectedError == "" {
+					assert.Equal(t, test.expectedLevel, Configuration().level)
+					assert.Equal(t, test.expectedFormatter, Configuration().format)
+					assert.Equal(t, test.expectedLevelSetWithCli, Configuration().IsLevelSetWithCli())
+					assert.Equal(t, test.expectedFormatSetWithCli, Configuration().IsFormatSetWithCli())
+
+					if test.goroutinesDumpStopChExists {
+						assert.NotNil(t, Configuration().goroutinesDumpStopCh)
+					} else {
+						assert.Nil(t, Configuration().goroutinesDumpStopCh)
+					}
+				}
+			}
+
+			if test.expectedError != "" {
+				var message *logrus.Entry
+				var ok bool
+
+				func() {
+					defer func() {
+						message, ok = recover().(*logrus.Entry)
+					}()
+
+					testFunc()
+				}()
+
+				require.True(t, ok)
+
+				panicMessage, err := message.String()
+				require.NoError(t, err)
+
+				assert.Contains(t, panicMessage, "Error while setting up logging configuration")
+				assert.Contains(t, panicMessage, test.expectedError)
+
+			} else {
+				assert.NotPanics(t, testFunc)
+			}
+		})
+	}
+}
+
+func TestGoroutinesDumpDisabling(t *testing.T) {
+	config := new(Config)
+	config.level = logrus.DebugLevel
+	config.ReloadConfiguration()
+	config.ReloadConfiguration()
+
+	assert.NotNil(t, config.goroutinesDumpStopCh)
+
+	config.level = logrus.InfoLevel
+	config.ReloadConfiguration()
+	config.ReloadConfiguration()
+
+	assert.Nil(t, config.goroutinesDumpStopCh)
+}

log/dump_unix.go

@@ -11,15 +11,20 @@ import (
 	"github.com/sirupsen/logrus"
 )
 
-func watchForGoroutinesDump() {
+func watchForGoroutinesDump(stopCh chan bool) {
 	dumpStacks := make(chan os.Signal, 1)
 
 	// On USR1 dump stacks of all go routines
 	signal.Notify(dumpStacks, syscall.SIGUSR1)
 
-	for range dumpStacks {
-		buf := make([]byte, 1<<20)
-		len := runtime.Stack(buf, true)
-		logrus.Printf("=== received SIGUSR1 ===\n*** goroutine dump...\n%s\n*** end\n", buf[0:len])
+	for {
+		select {
+		case <-dumpStacks:
+			buf := make([]byte, 1<<20)
+			len := runtime.Stack(buf, true)
+			logrus.Printf("=== received SIGUSR1 ===\n*** goroutine dump...\n%s\n*** end\n", buf[0:len])
+		case <-stopCh:
+			return
+		}
 	}
 }

log/dump_windows.go

 package log
 
-func watchForGoroutinesDump() {
+func watchForGoroutinesDump(stopCh chan bool) {
 }