add logs

weed/s3api/s3_iam_middleware.go

@@ -6,6 +6,7 @@ import (
 	"net"
 	"net/http"
 	"strings"
+	"time"
 
 	"github.com/golang-jwt/jwt/v5"
 	"github.com/seaweedfs/seaweedfs/weed/glog"
@@ -41,21 +42,28 @@ func NewS3IAMIntegration(iamManager *integration.IAMManager, filerAddress string
 
 // AuthenticateJWT authenticates JWT tokens using our STS service
 func (s3iam *S3IAMIntegration) AuthenticateJWT(ctx context.Context, r *http.Request) (*IAMIdentity, s3err.ErrorCode) {
+	glog.V(2).Infof("🔐 AuthenticateJWT: Starting JWT authentication for %s %s", r.Method, r.URL.Path)
+	
 	if !s3iam.enabled {
+		glog.V(2).Infof("🔐 AuthenticateJWT: IAM integration not enabled")
 		return nil, s3err.ErrNotImplemented
 	}
 
 	// Extract bearer token from Authorization header
 	authHeader := r.Header.Get("Authorization")
 	if !strings.HasPrefix(authHeader, "Bearer ") {
+		glog.V(2).Infof("🔐 AuthenticateJWT: No Bearer token found")
 		return nil, s3err.ErrAccessDenied
 	}
 
 	sessionToken := strings.TrimPrefix(authHeader, "Bearer ")
 	if sessionToken == "" {
+		glog.V(2).Infof("🔐 AuthenticateJWT: Empty session token")
 		return nil, s3err.ErrAccessDenied
 	}
 	
+	glog.V(2).Infof("🔐 AuthenticateJWT: Processing JWT token (length: %d)", len(sessionToken))
+
 	// Basic token format validation - reject obviously invalid tokens
 	if sessionToken == "invalid-token" || len(sessionToken) < 10 {
 		glog.V(3).Info("Session token format is invalid")
@@ -72,13 +80,31 @@ func (s3iam *S3IAMIntegration) AuthenticateJWT(ctx context.Context, r *http.Requ
 	// Check if this is an STS session token (has "role" claim)
 	roleName, ok := tokenClaims["role"].(string)
 	if !ok || roleName == "" {
-		// Not an STS session token, try to validate as OIDC token
+		glog.V(2).Infof("🔐 AuthenticateJWT: No 'role' claim found, treating as OIDC token")
+		
+		// Not an STS session token, try to validate as OIDC token with timeout
+		// Create a context with a reasonable timeout to prevent hanging
+		glog.V(2).Infof("🔐 AuthenticateJWT: Starting OIDC token validation with 15s timeout...")
+		start := time.Now()
+		
+		ctx, cancel := context.WithTimeout(ctx, 15*time.Second)
+		defer cancel()
+		
 		identity, err := s3iam.validateOIDCToken(ctx, sessionToken)
+		elapsed := time.Since(start)
+		
 		if err != nil {
-			glog.V(0).Infof("Failed to validate as OIDC token: %v", err)
+			// Check if it's a timeout error and log accordingly
+			if ctx.Err() == context.DeadlineExceeded {
+				glog.V(0).Infof("🔐 AuthenticateJWT: OIDC token validation TIMED OUT after %v: %v", elapsed, err)
+			} else {
+				glog.V(0).Infof("🔐 AuthenticateJWT: OIDC token validation FAILED after %v: %v", elapsed, err)
+			}
 			return nil, s3err.ErrAccessDenied
 		}
 		
+		glog.V(2).Infof("🔐 AuthenticateJWT: OIDC token validation SUCCEEDED after %v", elapsed)
+
 		// Extract role from OIDC identity
 		if identity.RoleArn == "" {
 			glog.V(0).Info("No role found in OIDC token")
@@ -434,26 +460,39 @@ type OIDCIdentity struct {
 
 // validateOIDCToken validates an OIDC token using registered identity providers
 func (s3iam *S3IAMIntegration) validateOIDCToken(ctx context.Context, token string) (*OIDCIdentity, error) {
+	glog.V(2).Infof("🔍 validateOIDCToken: Starting OIDC token validation")
+	
 	if s3iam.iamManager == nil {
+		glog.V(2).Infof("🔍 validateOIDCToken: IAM manager not available")
 		return nil, fmt.Errorf("IAM manager not available")
 	}
 
 	// Get STS service to access identity providers
 	stsService := s3iam.iamManager.GetSTSService()
 	if stsService == nil {
+		glog.V(2).Infof("🔍 validateOIDCToken: STS service not available")
 		return nil, fmt.Errorf("STS service not available")
 	}
 
 	// Try to validate token with each registered OIDC provider
 	providers := stsService.GetProviders()
+	glog.V(2).Infof("🔍 validateOIDCToken: Found %d providers to try", len(providers))
+	
 	for providerName, provider := range providers {
+		glog.V(2).Infof("🔍 validateOIDCToken: Trying provider '%s'...", providerName)
+		start := time.Now()
+		
 		// Try to authenticate with this provider
 		externalIdentity, err := provider.Authenticate(ctx, token)
+		elapsed := time.Since(start)
+		
 		if err != nil {
-			glog.V(3).Infof("Provider %s failed to authenticate token: %v", providerName, err)
+			glog.V(2).Infof("🔍 validateOIDCToken: Provider '%s' FAILED after %v: %v", providerName, elapsed, err)
 			continue
 		}
 		
+		glog.V(2).Infof("🔍 validateOIDCToken: Provider '%s' SUCCEEDED after %v", providerName, elapsed)
+
 		// Extract role from external identity attributes
 		rolesAttr, exists := externalIdentity.Attributes["roles"]
 		if !exists || rolesAttr == "" {