add logging

internal/rbac/middleware.go

@@ -2,6 +2,8 @@ package rbac
 
 import (
 	"errors"
+	"fmt"
+	"log/slog"
 	"net/http"
 	"strings"
 
@@ -17,6 +19,7 @@ type JWTConfig struct {
 	RequiredGroups []string // Groups that are required for access (any one of these)
 	ContextKey     string   // Key to store the claims in the context
 	ErrorHandler   func(echo.Context, error) error
+	Logger         *slog.Logger // Logger instance for middleware
 }
 
 // DefaultJWTConfig is the default JWT auth middleware config
@@ -45,36 +48,56 @@ func extractToken(config JWTConfig) func(echo.Context) (string, error) {
 }
 
 // validateGroups checks if the user belongs to any of the required groups
-func validateGroups(claims jwt.MapClaims, requiredGroups []string) bool {
+func validateGroups(claims jwt.MapClaims, requiredGroups []string, logger *slog.Logger) bool {
 	if len(requiredGroups) == 0 {
+		logger.Debug("no required groups specified, access granted")
 		return true
 	}
 
 	groups, ok := claims["cognito:groups"].([]interface{})
 	if !ok {
+		logger.Warn("no groups found in claims", "user", claims["sub"])
 		return false
 	}
 
+	userGroups := make([]string, 0)
+	for _, group := range groups {
+		if groupStr, ok := group.(string); ok {
+			userGroups = append(userGroups, groupStr)
+		}
+	}
+
 	for _, reqGroup := range requiredGroups {
 		for _, group := range groups {
 			if groupStr, ok := group.(string); ok && strings.EqualFold(groupStr, reqGroup) {
+				logger.Debug("group validation successful",
+					"user", claims["sub"],
+					"required_group", reqGroup,
+					"user_groups", userGroups)
 				return true
 			}
 		}
 	}
+
+	logger.Warn("group validation failed",
+		"user", claims["sub"],
+		"required_groups", requiredGroups,
+		"user_groups", userGroups)
 	return false
 }
 
 // parseJWT parses and validates the JWT token
-func parseJWT(tokenString string, keyProvider KeyProvider) (*jwt.Token, jwt.MapClaims, error) {
+func parseJWT(tokenString string, keyProvider KeyProvider, logger *slog.Logger) (*jwt.Token, jwt.MapClaims, error) {
 	token, err := jwt.Parse(tokenString, func(token *jwt.Token) (interface{}, error) {
 		if _, ok := token.Method.(*jwt.SigningMethodRSA); !ok {
+			logger.Error("unexpected signing method", "method", token.Method.Alg())
 			return nil, errors.New("unexpected signing method")
 		}
 
 		// Get key ID from token header
 		kid, ok := token.Header["kid"].(string)
 		if !ok {
+			logger.Error("no key ID in token header")
 			return nil, errors.New("no key ID (kid) in token header")
 		}
 
@@ -83,14 +106,19 @@ func parseJWT(tokenString string, keyProvider KeyProvider) (*jwt.Token, jwt.MapC
 	})
 
 	if err != nil {
+		logger.Error("failed to parse JWT", "error", err)
 		return nil, nil, err
 	}
 
 	claims, ok := token.Claims.(jwt.MapClaims)
 	if !ok || !token.Valid {
+		logger.Error("invalid token claims")
 		return nil, nil, errors.New("invalid token")
 	}
 
+	logger.Debug("JWT parsed successfully",
+		"user", claims["sub"],
+		"email", claims["email"])
 	return token, claims, nil
 }
 
@@ -112,6 +140,9 @@ func JWTWithConfig(config JWTConfig) echo.MiddlewareFunc {
 	if config.KeyProvider == nil {
 		panic("JWT middleware requires a KeyProvider")
 	}
+	if config.Logger == nil {
+		config.Logger = slog.Default()
+	}
 
 	extractor := extractToken(config)
 
@@ -119,21 +150,39 @@ func JWTWithConfig(config JWTConfig) echo.MiddlewareFunc {
 		return func(c echo.Context) error {
 			tokenString, err := extractor(c)
 			if err != nil {
+				config.Logger.Error("failed to extract token",
+					"error", err,
+					"path", c.Request().URL.Path,
+					"method", c.Request().Method)
 				return config.ErrorHandler(c, err)
 			}
 
-			_, claims, err := parseJWT(tokenString, config.KeyProvider)
+			_, claims, err := parseJWT(tokenString, config.KeyProvider, config.Logger)
 			if err != nil {
+				config.Logger.Error("failed to validate JWT",
+					"error", err,
+					"path", c.Request().URL.Path,
+					"method", c.Request().Method)
 				return config.ErrorHandler(c, err)
 			}
 
 			// Check required groups if specified
-			if !validateGroups(claims, config.RequiredGroups) {
+			if !validateGroups(claims, config.RequiredGroups, config.Logger) {
+				config.Logger.Warn("insufficient permissions",
+					"user", claims["sub"],
+					"path", c.Request().URL.Path,
+					"method", c.Request().Method)
 				return echo.NewHTTPError(http.StatusForbidden, "insufficient permissions")
 			}
 
 			// Store user information in context
 			c.Set(config.ContextKey, claims)
+
+			config.Logger.Info("authenticated request",
+				"user", claims["sub"],
+				"path", c.Request().URL.Path,
+				"method", c.Request().Method)
+
 			return next(c)
 		}
 	}
@@ -151,14 +200,14 @@ func tokenFromHeader(header string, authScheme string) func(echo.Context) (strin
 	return func(c echo.Context) (string, error) {
 		auth := c.Request().Header.Get(header)
 		if auth == "" {
-			return "", errors.New("missing auth header")
+			return "", fmt.Errorf("missing auth header: %s", header)
 		}
 
 		l := len(authScheme)
 		if len(auth) > l+1 && auth[:l] == authScheme {
 			return auth[l+1:], nil
 		}
-		return "", errors.New("invalid auth header")
+		return "", fmt.Errorf("invalid auth header format for scheme: %s", authScheme)
 	}
 }