internal: rework global logging settings, embedded outpost no longer overwrites core, clean up double init

Signed-off-by: Jens Langhammer <jens.langhammer@beryju.org>

cmd/proxy/server.go

@@ -26,6 +26,12 @@ Optionally, you can set these:
 
 func main() {
 	log.SetLevel(log.DebugLevel)
+	log.SetFormatter(&log.JSONFormatter{
+		FieldMap: log.FieldMap{
+			log.FieldKeyMsg:  "event",
+			log.FieldKeyTime: "timestamp",
+		},
+	})
 	akURL, found := os.LookupEnv("AUTHENTIK_HOST")
 	if !found {
 		fmt.Println("env AUTHENTIK_HOST not set!")

cmd/server/main.go

@@ -21,7 +21,12 @@ var running = true
 
 func main() {
 	log.SetLevel(log.DebugLevel)
-	log.SetFormatter(&log.JSONFormatter{})
+	log.SetFormatter(&log.JSONFormatter{
+		FieldMap: log.FieldMap{
+			log.FieldKeyMsg:  "event",
+			log.FieldKeyTime: "timestamp",
+		},
+	})
 	l := log.WithField("logger", "authentik.root")
 	config.DefaultConfig()
 	err := config.LoadConfig("./authentik/lib/default.yml")
@@ -73,9 +78,9 @@ func main() {
 
 		<-ex
 		running = false
-		l.WithField("logger", "authentik").Info("shutting down gunicorn")
+		l.Info("shutting down gunicorn")
 		go g.Kill()
-		l.WithField("logger", "authentik").Info("shutting down webserver")
+		l.Info("shutting down webserver")
 		go ws.Shutdown()
 	}
 }
@@ -93,8 +98,9 @@ func attemptStartBackend(g *gounicorn.GoUnicorn) {
 func attemptProxyStart(ws *web.WebServer, u *url.URL) {
 	maxTries := 100
 	attempt := 0
+	l := log.WithField("logger", "authentik.server")
 	for {
-		log.WithField("logger", "authentik").Debug("attempting to init outpost")
+		l.Debug("attempting to init outpost")
 		ac := ak.NewAPIController(*u, config.G.SecretKey)
 		if ac == nil {
 			attempt += 1
@@ -107,10 +113,10 @@ func attemptProxyStart(ws *web.WebServer, u *url.URL) {
 		srv := proxyv2.NewProxyServer(ac, 0)
 		ws.ProxyServer = srv
 		ac.Server = srv
-		log.WithField("logger", "authentik").Debug("attempting to start outpost")
+		l.Debug("attempting to start outpost")
 		err := ac.StartBackgorundTasks()
 		if err != nil {
-			log.WithField("logger", "authentik").WithError(err).Warning("outpost failed to start")
+			l.WithError(err).Warning("outpost failed to start")
 			attempt += 1
 			time.Sleep(15 * time.Second)
 			if attempt > maxTries {

internal/config/config.go

@@ -2,6 +2,7 @@ package config
 
 import (
 	"io/ioutil"
+	"strings"
 
 	env "github.com/Netflix/go-env"
 	"github.com/imdario/mergo"
@@ -62,7 +63,7 @@ func FromEnv() error {
 }
 
 func ConfigureLogger() {
-	switch G.LogLevel {
+	switch strings.ToLower(G.LogLevel) {
 	case "trace":
 		log.SetLevel(log.TraceLevel)
 	case "debug":
@@ -77,14 +78,14 @@ func ConfigureLogger() {
 		log.SetLevel(log.DebugLevel)
 	}
 
+	fm := log.FieldMap{
+		log.FieldKeyMsg:  "event",
+		log.FieldKeyTime: "timestamp",
+	}
+
 	if G.Debug {
-		log.SetFormatter(&log.TextFormatter{})
+		log.SetFormatter(&log.TextFormatter{FieldMap: fm})
 	} else {
-		log.SetFormatter(&log.JSONFormatter{
+		log.SetFormatter(&log.JSONFormatter{FieldMap: fm})
-			FieldMap: log.FieldMap{
-				log.FieldKeyMsg:  "event",
-				log.FieldKeyTime: "timestamp",
-			},
-		})
 	}
 }

internal/outpost/ak/api_ws.go

@@ -194,7 +194,13 @@ func (ac *APIController) startWSHealth() {
 func (ac *APIController) startIntervalUpdater() {
 	logger := ac.logger.WithField("loop", "interval-updater")
 	ticker := time.NewTicker(5 * time.Minute)
+	initial := false
 	for ; true; <-ticker.C {
+		if !initial {
+			initial = true
+			continue
+		}
+		logger.Debug("Running interval update")
 		err := ac.OnRefresh()
 		if err != nil {
 			logger.WithError(err).Debug("Failed to update")

internal/outpost/ak/global.go

@@ -13,31 +13,30 @@ import (
 )
 
 func doGlobalSetup(outpost api.Outpost, globalConfig api.Config) {
-	log.SetFormatter(&log.JSONFormatter{
+	l := log.WithField("logger", "authentik.outpost")
-		FieldMap: log.FieldMap{
+	if !outpost.Managed.IsSet() {
-			log.FieldKeyMsg:  "event",
+		switch outpost.Config[ConfigLogLevel].(string) {
-			log.FieldKeyTime: "timestamp",
+		case "trace":
-		},
+			log.SetLevel(log.TraceLevel)
-	})
+		case "debug":
-	switch outpost.Config[ConfigLogLevel].(string) {
+			log.SetLevel(log.DebugLevel)
-	case "trace":
+		case "info":
-		log.SetLevel(log.TraceLevel)
+			log.SetLevel(log.InfoLevel)
-	case "debug":
+		case "warning":
-		log.SetLevel(log.DebugLevel)
+			log.SetLevel(log.WarnLevel)
-	case "info":
+		case "error":
-		log.SetLevel(log.InfoLevel)
+			log.SetLevel(log.ErrorLevel)
-	case "warning":
+		default:
-		log.SetLevel(log.WarnLevel)
+			log.SetLevel(log.DebugLevel)
-	case "error":
+		}
-		log.SetLevel(log.ErrorLevel)
+	} else {
-	default:
+		l.Debug("Managed outpost, not seting global log level")
-		log.SetLevel(log.DebugLevel)
 	}
-	log.WithField("logger", "authentik.outpost").WithField("hash", constants.BUILD()).WithField("version", constants.VERSION).Info("Starting authentik outpost")
+	l.WithField("hash", constants.BUILD()).WithField("version", constants.VERSION).Info("Starting authentik outpost")
 
 	if globalConfig.ErrorReporting.Enabled {
 		dsn := "https://a579bb09306d4f8b8d8847c052d3a1d3@sentry.beryju.org/8"
-		log.WithField("env", globalConfig.ErrorReporting.Environment).Debug("Error reporting enabled")
+		l.WithField("env", globalConfig.ErrorReporting.Environment).Debug("Error reporting enabled")
 		err := sentry.Init(sentry.ClientOptions{
 			Dsn:              dsn,
 			Environment:      globalConfig.ErrorReporting.Environment,
@@ -47,7 +46,7 @@ func doGlobalSetup(outpost api.Outpost, globalConfig api.Config) {
 			},
 		})
 		if err != nil {
-			log.WithField("env", globalConfig.ErrorReporting.Environment).WithError(err).Warning("Failed to initialise sentry")
+			l.WithField("env", globalConfig.ErrorReporting.Environment).WithError(err).Warning("Failed to initialise sentry")
 		}
 	}
 }