Improve logs and avoid excessive info-level logging

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

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
 	}
 

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 {

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)
 	}

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)))

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

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
 	}