From e3eaaeaf171a55089d653314552008c56e501d66 Mon Sep 17 00:00:00 2001 From: Jens Langhammer Date: Thu, 11 Feb 2021 23:48:54 +0100 Subject: [PATCH] outpost: improve logging output, ensure fields match api server --- outpost/pkg/ak/api.go | 6 ++++-- outpost/pkg/ak/api_ws.go | 4 ++-- outpost/pkg/ak/global.go | 7 ++++++- outpost/pkg/proxy/api.go | 2 +- outpost/pkg/proxy/api_bundle.go | 2 +- outpost/pkg/proxy/middleware.go | 26 ++++++++++++-------------- outpost/pkg/proxy/proxy.go | 6 ++++-- outpost/pkg/proxy/server.go | 14 +++++++++----- 8 files changed, 39 insertions(+), 28 deletions(-) diff --git a/outpost/pkg/ak/api.go b/outpost/pkg/ak/api.go index 22703c76e..2cb94517a 100644 --- a/outpost/pkg/ak/api.go +++ b/outpost/pkg/ak/api.go @@ -49,12 +49,14 @@ func NewAPIController(pbURL url.URL, token string) *APIController { // create the API client, with the transport apiClient := client.New(transport, strfmt.Default) + log := log.WithField("logger", "authentik.outpost.ak-api-controller") + // Because we don't know the outpost UUID, we simply do a list and pick the first // The service account this token belongs to should only have access to a single outpost outposts, err := apiClient.Outposts.OutpostsOutpostsList(outposts.NewOutpostsOutpostsListParams(), auth) if err != nil { - panic(err) + log.WithError(err).Panic("Failed to fetch configuration") } outpost := outposts.Payload.Results[0] doGlobalSetup(outpost.Config.(map[string]interface{})) @@ -64,7 +66,7 @@ func NewAPIController(pbURL url.URL, token string) *APIController { Auth: auth, token: token, - logger: log.WithField("component", "ak-api-controller"), + logger: log, reloadOffset: time.Duration(rand.Intn(10)) * time.Second, diff --git a/outpost/pkg/ak/api_ws.go b/outpost/pkg/ak/api_ws.go index 93eace7f3..c2fe4dc31 100644 --- a/outpost/pkg/ak/api_ws.go +++ b/outpost/pkg/ak/api_ws.go @@ -40,7 +40,7 @@ func (ac *APIController) initWS(pbURL url.URL, outpostUUID strfmt.UUID) { } ws.Dial(fmt.Sprintf(pathTemplate, scheme, pbURL.Host, outpostUUID.String()), header) - ac.logger.WithField("component", "ak-ws").WithField("outpost", outpostUUID.String()).Debug("connecting to authentik") + ac.logger.WithField("logger", "authentik.outpost.ak-ws").WithField("outpost", outpostUUID.String()).Debug("connecting to authentik") ac.wsConn = ws // Send hello message with our version @@ -52,7 +52,7 @@ func (ac *APIController) initWS(pbURL url.URL, outpostUUID strfmt.UUID) { } err := ws.WriteJSON(msg) if err != nil { - ac.logger.WithField("component", "ak-ws").WithError(err).Warning("Failed to hello to authentik") + ac.logger.WithField("logger", "authentik.outpost.ak-ws").WithError(err).Warning("Failed to hello to authentik") } } diff --git a/outpost/pkg/ak/global.go b/outpost/pkg/ak/global.go index d3d509cfd..f6678f6b9 100644 --- a/outpost/pkg/ak/global.go +++ b/outpost/pkg/ak/global.go @@ -13,7 +13,12 @@ import ( ) func doGlobalSetup(config map[string]interface{}) { - log.SetFormatter(&log.JSONFormatter{}) + log.SetFormatter(&log.JSONFormatter{ + FieldMap: log.FieldMap{ + log.FieldKeyMsg: "event", + log.FieldKeyTime: "timestamp", + }, + }) switch config[ConfigLogLevel].(string) { case "debug": log.SetLevel(log.DebugLevel) diff --git a/outpost/pkg/proxy/api.go b/outpost/pkg/proxy/api.go index ee44f4a73..87d982a78 100644 --- a/outpost/pkg/proxy/api.go +++ b/outpost/pkg/proxy/api.go @@ -31,7 +31,7 @@ func (s *Server) bundleProviders(providers []*models.ProxyOutpostConfig) []*prov bundles[idx] = &providerBundle{ s: s, Host: externalHost.Host, - log: log.WithField("component", "proxy-bundle").WithField("provider", provider.Name), + log: log.WithField("logger", "authentik.outpost.proxy-bundle").WithField("provider", provider.Name), } bundles[idx].Build(provider) } diff --git a/outpost/pkg/proxy/api_bundle.go b/outpost/pkg/proxy/api_bundle.go index 10f61d9b1..55a94794e 100644 --- a/outpost/pkg/proxy/api_bundle.go +++ b/outpost/pkg/proxy/api_bundle.go @@ -129,7 +129,7 @@ func (pb *providerBundle) Build(provider *models.ProxyOutpostConfig) { log.Printf("%s", err) os.Exit(1) } - oauthproxy, err := NewOAuthProxy(opts) + oauthproxy, err := NewOAuthProxy(opts, provider) if err != nil { log.Errorf("ERROR: Failed to initialise OAuth2 Proxy: %v", err) os.Exit(1) diff --git a/outpost/pkg/proxy/middleware.go b/outpost/pkg/proxy/middleware.go index ae95ed346..3e9e924fc 100644 --- a/outpost/pkg/proxy/middleware.go +++ b/outpost/pkg/proxy/middleware.go @@ -95,7 +95,7 @@ type loggingHandler struct { func LoggingHandler(h http.Handler) http.Handler { return loggingHandler{ handler: h, - logger: log.WithField("component", "proxy-http-server"), + logger: log.WithField("logger", "authentik.outpost.proxy-http-server"), } } @@ -104,19 +104,17 @@ func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) { url := *req.URL responseLogger := &responseLogger{w: w} h.handler.ServeHTTP(responseLogger, req) - duration := float64(time.Since(t)) / float64(time.Second) + duration := float64(time.Since(t)) / float64(time.Millisecond) h.logger.WithFields(log.Fields{ - "Client": req.RemoteAddr, - "Host": req.Host, - "Protocol": req.Proto, - "RequestDuration": fmt.Sprintf("%0.3f", duration), - "RequestMethod": req.Method, - "ResponseSize": responseLogger.Size(), - "StatusCode": responseLogger.Status(), - "Timestamp": t, - "Upstream": responseLogger.upstream, - "UserAgent": req.UserAgent(), - "Username": responseLogger.authInfo, + "host": req.RemoteAddr, + "vhost": req.Host, + "request_protocol": req.Proto, + "runtime": fmt.Sprintf("%0.3f", duration), + "method": req.Method, + "size": responseLogger.Size(), + "status": responseLogger.Status(), + "upstream": responseLogger.upstream, + "request_useragent": req.UserAgent(), + "request_username": responseLogger.authInfo, }).Info(url.RequestURI()) - // logger.PrintReq(responseLogger.authInfo, responseLogger.upstream, req, url, t, , ) } diff --git a/outpost/pkg/proxy/proxy.go b/outpost/pkg/proxy/proxy.go index 366c0a75e..44643c959 100644 --- a/outpost/pkg/proxy/proxy.go +++ b/outpost/pkg/proxy/proxy.go @@ -21,6 +21,7 @@ import ( "github.com/oauth2-proxy/oauth2-proxy/pkg/sessions" "github.com/oauth2-proxy/oauth2-proxy/pkg/upstream" "github.com/oauth2-proxy/oauth2-proxy/providers" + "goauthentik.io/outpost/pkg/models" log "github.com/sirupsen/logrus" ) @@ -92,8 +93,8 @@ type OAuthProxy struct { } // NewOAuthProxy creates a new instance of OAuthProxy from the options provided -func NewOAuthProxy(opts *options.Options) (*OAuthProxy, error) { - logger := log.WithField("component", "proxy").WithField("client-id", opts.ClientID) +func NewOAuthProxy(opts *options.Options, provider *models.ProxyOutpostConfig) (*OAuthProxy, error) { + logger := log.WithField("logger", "authentik.outpost.proxy").WithField("provider", provider.Name) sessionStore, err := sessions.NewSessionStore(&opts.Session, &opts.Cookie) if err != nil { return nil, fmt.Errorf("error initialising session store: %v", err) @@ -434,6 +435,7 @@ func (p *OAuthProxy) addHeadersForProxying(rw http.ResponseWriter, req *http.Req authVal := b64.StdEncoding.EncodeToString([]byte(username + ":" + password)) req.Header["Authorization"] = []string{fmt.Sprintf("Basic %s", authVal)} } + rw.Header().Set("GAP-Auth", session.PreferredUsername) // Check if user has additional headers set that we should sent if additionalHeaders, ok := userAttributes["additionalHeaders"].(map[string]string); ok { if additionalHeaders == nil { diff --git a/outpost/pkg/proxy/server.go b/outpost/pkg/proxy/server.go index 23db5fc8e..e01dbee95 100644 --- a/outpost/pkg/proxy/server.go +++ b/outpost/pkg/proxy/server.go @@ -6,6 +6,7 @@ import ( "errors" "net" "net/http" + "strings" "time" log "github.com/sirupsen/logrus" @@ -30,7 +31,7 @@ func NewServer(ac *ak.APIController) *Server { } return &Server{ Handlers: make(map[string]*providerBundle), - logger: log.WithField("component", "proxy-http-server"), + logger: log.WithField("logger", "authentik.outpost.proxy-http-server"), defaultCert: defaultCert, ak: ac, } @@ -50,12 +51,15 @@ func (s *Server) handler(w http.ResponseWriter, r *http.Request) { return } } - s.logger.WithField("host", r.Host).Debug("Host header does not match any we know of") - s.logger.Printf("%v+\n", s.Handlers) - w.WriteHeader(400) + // Get a list of all host keys we know + hostKeys := make([]string, 0, len(s.Handlers)) + for k := range s.Handlers { + hostKeys = append(hostKeys, k) + } + s.logger.WithField("host", r.Host).WithField("known-hosts", strings.Join(hostKeys, ", ")).Debug("Host header does not match any we know of") + w.WriteHeader(404) return } - s.logger.WithField("host", r.Host).Debug("passing request from host head") handler.ServeHTTP(w, r) }