From 2f69a1b6d28008efb3aa5bc981555d7541eb9580 Mon Sep 17 00:00:00 2001 From: Mario Hros Date: Thu, 13 Feb 2020 21:05:11 +0100 Subject: [PATCH] avoid excessive info-level logging for every request and introduce new extra checks --- adapter/adapter.go | 17 ++++++++++------- adapter/authserver/authserver.go | 4 ++-- adapter/networking/networking.go | 7 ++++--- adapter/policy/controller/controller.go | 4 ++-- .../policy/handler/crdeventhandler/add_event.go | 17 +++++++++++------ adapter/policy/policy.go | 3 --- adapter/strategy/web/web.go | 10 +++++----- 7 files changed, 34 insertions(+), 28 deletions(-) diff --git a/adapter/adapter.go b/adapter/adapter.go index c826d7f..d77035b 100644 --- a/adapter/adapter.go +++ b/adapter/adapter.go @@ -23,9 +23,9 @@ import ( "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/policy/initializer" storePolicy "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/policy/store/policy" "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/strategy" - "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/strategy/api" - "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/strategy/web" - "github.com/ibm-cloud-security/app-identity-and-access-adapter/config/template" + apistrategy "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/strategy/api" + webstrategy "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/strategy/web" + authnz "github.com/ibm-cloud-security/app-identity-and-access-adapter/config/template" ) type ( @@ -59,19 +59,22 @@ func (s *AppidAdapter) HandleAuthnZ(ctx context.Context, r *authnz.HandleAuthnZR ///// Check policy action, err := s.engine.Evaluate(r.Instance.Target) if err != nil { - zap.L().Debug("Could not check policies", zap.Error(err)) + zap.L().Warn("Could not check policies", zap.Error(err)) return nil, err } switch action.Type { case policy.JWT: - zap.L().Info("Executing JWT policies") + zap.L().Debug("Executing JWT policies", zap.String("method", r.Instance.Target.Method), + zap.String("path", r.Instance.Target.Path), zap.String("service", r.Instance.Target.Service)) return s.apistrategy.HandleAuthnZRequest(r, action) case policy.OIDC: - zap.L().Info("Executing OIDC policies") + zap.L().Debug("Executing OIDC policies", zap.String("method", r.Instance.Target.Method), + zap.String("path", r.Instance.Target.Path), zap.String("service", r.Instance.Target.Service)) return s.webstrategy.HandleAuthnZRequest(r, action) default: - zap.L().Info("No OIDC/JWT policies configured") + zap.L().Debug("No OIDC/JWT policies configured", zap.String("method", r.Instance.Target.Method), + zap.String("path", r.Instance.Target.Path), zap.String("service", r.Instance.Target.Service)) return &authnz.HandleAuthnZResponse{ Result: &v1beta1.CheckResult{Status: status.OK}, }, nil diff --git a/adapter/authserver/authserver.go b/adapter/authserver/authserver.go index 86746f3..cbca4b6 100644 --- a/adapter/authserver/authserver.go +++ b/adapter/authserver/authserver.go @@ -77,7 +77,7 @@ func New(discoveryEndpoint string) AuthorizationServerService { zap.L().Debug("Initialization from discovery endpoint failed. Will retry later.", zap.String("url", discoveryEndpoint)) return s } - zap.L().Debug("Initialized discovery configuration successfully", zap.String("url", discoveryEndpoint)) + zap.L().Debug("Initialized successfully using discovery endpoint", zap.String("url", discoveryEndpoint)) return s } @@ -206,7 +206,7 @@ func (s *RemoteService) loadDiscoveryEndpoint() (interface{}, error) { zap.L().Debug("Could not sync discovery endpoint", zap.String("url", s.discoveryURL), zap.Error(err)) return nil, err } else if res.StatusCode != http.StatusOK { - zap.L().Debug("Could not sync discovery endpoint", zap.String("url", s.discoveryURL), zap.Error(oa2Err)) + zap.L().Debug("Could not sync discovery endpoint", zap.String("url", s.discoveryURL), zap.Int("status", res.StatusCode), zap.Error(oa2Err)) return nil, oa2Err } diff --git a/adapter/networking/networking.go b/adapter/networking/networking.go index ce9ad2b..cfa6cd4 100644 --- a/adapter/networking/networking.go +++ b/adapter/networking/networking.go @@ -2,9 +2,10 @@ package networking import ( "encoding/json" - "go.uber.org/zap" "net/http" "time" + + "go.uber.org/zap" ) const ( @@ -71,13 +72,13 @@ func decodeResponse(res *http.Response, successV, failureV OK) error { // decodeJSON parses a JSON body and calls validate func decodeJSON(r *http.Response, v OK) error { if err := json.NewDecoder(r.Body).Decode(v); err != nil { - zap.L().Debug("Could not parse request body.", zap.Error(err)) + zap.L().Debug("Could not parse response body", zap.Error(err)) return err } return v.OK() } -// retry provides a recursive function retry implementation +// Retry provides a recursive function retry implementation func Retry(attempts int, sleep time.Duration, fn func() (interface{}, error)) (interface{}, error) { res, err := fn() if err != nil { diff --git a/adapter/policy/controller/controller.go b/adapter/policy/controller/controller.go index 18f76d8..f2169b1 100644 --- a/adapter/policy/controller/controller.go +++ b/adapter/policy/controller/controller.go @@ -113,11 +113,11 @@ func (c *Controller) processNextItem() bool { // after both instances, we want to forget the key from the queue, as this indicates // a code path of successful queue key processing if !exists { - zap.L().Debug("Controller.processNextItem: object deleted detected: %s", zap.String("key", keyRaw)) + zap.L().Debug("Controller.processNextItem: object deletion detected: %s", zap.String("key", keyRaw)) c.Handler.HandleDeleteEvent(policy.CrdKey{Id: keyRaw, CrdType: c.CrdType}) c.Queue.Forget(key) } else { - zap.L().Debug("Controller.processNextItem: object created detected: %s", zap.String("key", keyRaw)) + zap.L().Debug("Controller.processNextItem: object creation detected: %s", zap.String("key", keyRaw)) c.Handler.HandleAddUpdateEvent(item) c.Queue.Forget(key) } diff --git a/adapter/policy/handler/crdeventhandler/add_event.go b/adapter/policy/handler/crdeventhandler/add_event.go index 4498719..257b28b 100644 --- a/adapter/policy/handler/crdeventhandler/add_event.go +++ b/adapter/policy/handler/crdeventhandler/add_event.go @@ -17,18 +17,18 @@ type AddUpdateEventHandler interface { } type JwtConfigAddEventHandler struct { - Obj *v1.JwtConfig + Obj *v1.JwtConfig Store storepolicy.PolicyStore } type OidcConfigAddEventHandler struct { - Obj *v1.OidcConfig + Obj *v1.OidcConfig KubeClient kubernetes.Interface - Store storepolicy.PolicyStore + Store storepolicy.PolicyStore } type PolicyAddEventHandler struct { - Obj *v1.Policy + Obj *v1.Policy Store storepolicy.PolicyStore } @@ -45,6 +45,11 @@ func (e *OidcConfigAddEventHandler) HandleAddUpdateEvent() { if e.Obj.Spec.AuthMethod == "" { e.Obj.Spec.AuthMethod = "client_secret_basic" } + + if len(e.Obj.Spec.DiscoveryURL) == 0 { + zap.L().Warn("Empty discoveryURL in OidcConfig", zap.String("name", e.Obj.ObjectMeta.Name), zap.String("namespace", e.Obj.ObjectMeta.Namespace)) + } + authorizationServer := authserver.New(e.Obj.Spec.DiscoveryURL) keySets := keyset.New(authorizationServer.JwksEndpoint(), nil) authorizationServer.SetKeySet(keySets) @@ -57,11 +62,11 @@ func (e *OidcConfigAddEventHandler) HandleAddUpdateEvent() { func (e *PolicyAddEventHandler) HandleAddUpdateEvent() { zap.L().Debug("Create/Update Policy", zap.String("ID", string(e.Obj.ObjectMeta.UID)), zap.String("name", e.Obj.ObjectMeta.Name), zap.String("namespace", e.Obj.ObjectMeta.Namespace)) - mappingId := e.Obj.ObjectMeta.Namespace + "/" +e.Obj.ObjectMeta.Name + mappingId := e.Obj.ObjectMeta.Namespace + "/" + e.Obj.ObjectMeta.Name parsedPolicies := ParseTarget(e.Obj.Spec.Target, e.Obj.ObjectMeta.Namespace) for _, policies := range parsedPolicies { zap.S().Debug("Adding policy for endpoint", policies.Endpoint) - e.Store.SetPolicies(policies.Endpoint, policy.RoutePolicy{ PolicyReference: mappingId, Actions: policies.Actions}) + e.Store.SetPolicies(policies.Endpoint, policy.RoutePolicy{PolicyReference: mappingId, Actions: policies.Actions}) } e.Store.AddPolicyMapping(mappingId, parsedPolicies) zap.L().Info("Policy created/updated", zap.String("ID", string(e.Obj.ObjectMeta.UID))) diff --git a/adapter/policy/policy.go b/adapter/policy/policy.go index fb86987..9ad1d27 100644 --- a/adapter/policy/policy.go +++ b/adapter/policy/policy.go @@ -1,8 +1,6 @@ package policy import ( - "go.uber.org/zap" - v1 "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/pkg/apis/policies/v1" ) @@ -66,7 +64,6 @@ func (t Type) String() string { } func NewType(t string) Type { - zap.S().Info("Type: ", t) switch t { case "jwt": return JWT diff --git a/adapter/strategy/web/web.go b/adapter/strategy/web/web.go index 81e95cf..234dd2f 100644 --- a/adapter/strategy/web/web.go +++ b/adapter/strategy/web/web.go @@ -7,7 +7,7 @@ import ( "sync" "time" - "k8s.io/api/core/v1" + v1 "k8s.io/api/core/v1" "k8s.io/client-go/kubernetes" "github.com/gogo/googleapis/google/rpc" @@ -30,7 +30,7 @@ import ( "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/policy/engine" "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/strategy" "github.com/ibm-cloud-security/app-identity-and-access-adapter/adapter/validator" - "github.com/ibm-cloud-security/app-identity-and-access-adapter/config/template" + authnz "github.com/ibm-cloud-security/app-identity-and-access-adapter/config/template" ) const ( @@ -139,17 +139,17 @@ func (w *WebStrategy) isAuthorized(cookies string, action *engine.Action) (*auth sessionCookie, err := request.Cookie(buildTokenCookieName(sessionCookie, action.Client)) if err != nil { - zap.L().Debug("Current session does not exist.", zap.String("client_name", action.Client.Name())) + zap.L().Debug("Session cookie not provided", zap.String("client_name", action.Client.Name())) return nil, nil } // Load session information var session *authserver.TokenResponse if storedSession, ok := w.tokenCache.Load(sessionCookie.Value); !ok { - zap.L().Debug("Tokens not found in cache.", zap.String("client_name", action.Client.Name())) + zap.L().Debug("Session token does not exist", zap.String("client_name", action.Client.Name())) return nil, nil } else if session, ok = storedSession.(*authserver.TokenResponse); !ok { - zap.L().Debug("Tokens not found in cache.", zap.String("client_name", action.Client.Name())) + zap.L().Debug("Incompatible session token", zap.String("client_name", action.Client.Name())) return nil, nil }