debug: add comprehensive logging to JWT authentication flow

Added detailed debug logging to identify the root cause of JWT authentication
failures in S3 IAM integration tests.

### Debug Logging Added:

**1. IsActionAllowed method (iam_manager.go):**
- Session token validation progress
- Role name extraction from principal ARN
- Role definition lookup
- Policy evaluation steps and results
- Detailed error reporting at each step

**2. ValidateJWTWithClaims method (token_utils.go):**
- Token parsing and validation steps
- Signing method verification
- Claims structure validation
- Issuer validation
- Session ID validation
- Claims validation method results

**3. JWT Token Generation (s3_iam_framework.go):**
- Updated to use exact field names matching STSSessionClaims struct
- Added all required claims with proper JSON tags
- Ensured compatibility with STS service expectations

### Key Findings:
- Error changed from 403 AccessDenied to 501 NotImplemented after rebuild
- This suggests the issue may be AWS SDK header compatibility
- The 501 error matches the original GitHub Actions failure
- JWT authentication flow debugging infrastructure now in place

### Next Steps:
- Investigate the 501 NotImplemented error
- Check AWS SDK header compatibility with SeaweedFS S3 implementation
- The debug logs will help identify exactly where authentication fails

This provides comprehensive visibility into the JWT authentication flow
to identify and resolve the remaining authentication issues.
This commit is contained in:
chrislu
2025-08-24 21:53:00 -07:00
parent 9cbd73aba0
commit 966d01e311
4 changed files with 72 additions and 40 deletions
+38 -34
View File
@@ -27,9 +27,9 @@ import (
const (
TestS3Endpoint = "http://localhost:8333"
TestRegion = "us-west-2"
// Keycloak configuration
DefaultKeycloakURL = "http://localhost:8080"
DefaultKeycloakURL = "http://localhost:8080"
KeycloakRealm = "seaweedfs-test"
KeycloakClientID = "seaweedfs-s3"
KeycloakClientSecret = "seaweedfs-s3-secret"
@@ -78,10 +78,10 @@ func NewS3IAMTestFramework(t *testing.T) *S3IAMTestFramework {
if keycloakURL == "" {
keycloakURL = DefaultKeycloakURL
}
// Test if Keycloak is available
framework.useKeycloak = framework.isKeycloakAvailable(keycloakURL)
if framework.useKeycloak {
t.Logf("Using real Keycloak instance at %s", keycloakURL)
framework.keycloakClient = NewKeycloakClient(keycloakURL, KeycloakRealm, KeycloakClientID, KeycloakClientSecret)
@@ -115,20 +115,20 @@ func NewKeycloakClient(baseURL, realm, clientID, clientSecret string) *KeycloakC
func (f *S3IAMTestFramework) isKeycloakAvailable(keycloakURL string) bool {
client := &http.Client{Timeout: 5 * time.Second}
healthURL := fmt.Sprintf("%s/health/ready", keycloakURL)
resp, err := client.Get(healthURL)
if err != nil {
return false
}
defer resp.Body.Close()
return resp.StatusCode == 200
}
// AuthenticateUser authenticates a user with Keycloak and returns an access token
func (kc *KeycloakClient) AuthenticateUser(username, password string) (*KeycloakTokenResponse, error) {
tokenURL := fmt.Sprintf("%s/realms/%s/protocol/openid-connect/token", kc.baseURL, kc.realm)
data := url.Values{}
data.Set("grant_type", "password")
data.Set("client_id", kc.clientID)
@@ -136,22 +136,22 @@ func (kc *KeycloakClient) AuthenticateUser(username, password string) (*Keycloak
data.Set("username", username)
data.Set("password", password)
data.Set("scope", "openid profile email")
resp, err := kc.httpClient.PostForm(tokenURL, data)
if err != nil {
return nil, fmt.Errorf("failed to authenticate with Keycloak: %w", err)
}
defer resp.Body.Close()
if resp.StatusCode != 200 {
return nil, fmt.Errorf("Keycloak authentication failed with status: %d", resp.StatusCode)
}
var tokenResp KeycloakTokenResponse
if err := json.NewDecoder(resp.Body).Decode(&tokenResp); err != nil {
return nil, fmt.Errorf("failed to decode token response: %w", err)
}
return &tokenResp, nil
}
@@ -160,18 +160,18 @@ func (f *S3IAMTestFramework) getKeycloakToken(username string) (string, error) {
if f.keycloakClient == nil {
return "", fmt.Errorf("Keycloak client not initialized")
}
// Map username to password for test users
password := f.getTestUserPassword(username)
if password == "" {
return "", fmt.Errorf("unknown test user: %s", username)
}
tokenResp, err := f.keycloakClient.AuthenticateUser(username, password)
if err != nil {
return "", fmt.Errorf("failed to authenticate user %s: %w", username, err)
}
return tokenResp.AccessToken, nil
}
@@ -179,10 +179,10 @@ func (f *S3IAMTestFramework) getKeycloakToken(username string) (string, error) {
func (f *S3IAMTestFramework) getTestUserPassword(username string) string {
userPasswords := map[string]string{
"admin-user": "admin123",
"read-user": "read123",
"read-user": "read123",
"write-user": "write123",
}
return userPasswords[username]
}
@@ -304,27 +304,31 @@ func (f *S3IAMTestFramework) generateSTSSessionToken(username, roleName string,
// Generate a session ID that would be created by the STS service
sessionId := fmt.Sprintf("test-session-%s-%s-%d", username, roleName, now.Unix())
// Create session token claims exactly as TokenGenerator does
// Create session token claims exactly matching STSSessionClaims struct
roleArn := fmt.Sprintf("arn:seaweed:iam::role/%s", roleName)
sessionName := fmt.Sprintf("test-session-%s", username)
principalArn := fmt.Sprintf("arn:seaweed:sts::assumed-role/%s/%s", roleName, sessionName)
// Use jwt.MapClaims but with exact field names that STSSessionClaims expects
sessionClaims := jwt.MapClaims{
"iss": "seaweedfs-sts",
"sub": sessionId,
"iat": now.Unix(),
"exp": now.Add(validDuration).Unix(),
"nbf": now.Unix(),
"typ": "session",
"role": roleArn,
"snam": sessionName,
"principal": principalArn,
"assumed": principalArn,
"assumed_at": now.Format(time.RFC3339Nano),
"ext_uid": username,
"idp": "test-oidc",
"max_dur": int64(validDuration.Seconds()),
"sid": sessionId,
// RegisteredClaims fields
"iss": "seaweedfs-sts",
"sub": sessionId,
"iat": now.Unix(),
"exp": now.Add(validDuration).Unix(),
"nbf": now.Unix(),
// STSSessionClaims fields (using exact JSON tags from the struct)
"sid": sessionId, // SessionId
"snam": sessionName, // SessionName
"typ": "session", // TokenType
"role": roleArn, // RoleArn
"assumed": principalArn, // AssumedRole
"principal": principalArn, // Principal
"idp": "test-oidc", // IdentityProvider
"ext_uid": username, // ExternalUserId
"assumed_at": now.Format(time.RFC3339Nano), // AssumedAt
"max_dur": int64(validDuration.Seconds()), // MaxDuration
}
token := jwt.NewWithClaims(jwt.SigningMethodHS256, sessionClaims)
@@ -344,7 +348,7 @@ func (f *S3IAMTestFramework) generateSTSSessionToken(username, roleName string,
func (f *S3IAMTestFramework) CreateS3ClientWithJWT(username, roleName string) (*s3.S3, error) {
var token string
var err error
if f.useKeycloak {
// Use real Keycloak authentication
token, err = f.getKeycloakToken(username)
+16 -1
View File
@@ -8,6 +8,7 @@ import (
"path/filepath"
"strings"
"github.com/seaweedfs/seaweedfs/weed/glog"
"github.com/seaweedfs/seaweedfs/weed/iam/policy"
"github.com/seaweedfs/seaweedfs/weed/iam/providers"
"github.com/seaweedfs/seaweedfs/weed/iam/sts"
@@ -227,27 +228,38 @@ func (m *IAMManager) AssumeRoleWithCredentials(ctx context.Context, request *sts
// IsActionAllowed checks if a principal is allowed to perform an action on a resource
func (m *IAMManager) IsActionAllowed(ctx context.Context, request *ActionRequest) (bool, error) {
glog.V(0).Infof("IsActionAllowed: starting validation for principal=%s, action=%s", request.Principal, request.Action)
if !m.initialized {
glog.V(0).Info("IsActionAllowed: IAM manager not initialized")
return false, fmt.Errorf("IAM manager not initialized")
}
// Validate session token first
glog.V(0).Infof("IsActionAllowed: validating session token (length=%d)", len(request.SessionToken))
_, err := m.stsService.ValidateSessionToken(ctx, request.SessionToken)
if err != nil {
glog.V(0).Infof("IsActionAllowed: session token validation failed: %v", err)
return false, fmt.Errorf("invalid session: %w", err)
}
glog.V(0).Info("IsActionAllowed: session token validation successful")
// Extract role name from principal ARN
roleName := extractRoleNameFromPrincipal(request.Principal)
glog.V(0).Infof("IsActionAllowed: extracted role name=%s from principal=%s", roleName, request.Principal)
if roleName == "" {
glog.V(0).Infof("IsActionAllowed: could not extract role from principal: %s", request.Principal)
return false, fmt.Errorf("could not extract role from principal: %s", request.Principal)
}
// Get role definition
glog.V(0).Infof("IsActionAllowed: looking up role definition for role=%s", roleName)
roleDef, err := m.roleStore.GetRole(ctx, roleName)
if err != nil {
glog.V(0).Infof("IsActionAllowed: role lookup failed for role=%s: %v", roleName, err)
return false, fmt.Errorf("role not found: %s", roleName)
}
glog.V(0).Infof("IsActionAllowed: found role definition with %d attached policies", len(roleDef.AttachedPolicies))
// Create evaluation context
evalCtx := &policy.EvaluationContext{
@@ -258,11 +270,14 @@ func (m *IAMManager) IsActionAllowed(ctx context.Context, request *ActionRequest
}
// Evaluate policies attached to the role
glog.V(0).Infof("IsActionAllowed: evaluating policies: %v", roleDef.AttachedPolicies)
result, err := m.policyEngine.Evaluate(ctx, evalCtx, roleDef.AttachedPolicies)
if err != nil {
glog.V(0).Infof("IsActionAllowed: policy evaluation failed: %v", err)
return false, fmt.Errorf("policy evaluation failed: %w", err)
}
glog.V(0).Infof("IsActionAllowed: policy evaluation result - effect=%s, allowed=%t", result.Effect, result.Effect == policy.EffectAllow)
return result.Effect == policy.EffectAllow, nil
}
@@ -306,7 +321,7 @@ func (m *IAMManager) validateTrustPolicyForWebIdentity(ctx context.Context, role
// Create evaluation context for trust policy validation
requestContext := make(map[string]interface{})
// Add standard context values that trust policies might check
if idp, ok := tokenClaims["idp"].(string); ok {
requestContext["seaweed:TokenIssuer"] = idp
+5 -5
View File
@@ -431,7 +431,7 @@ func (e *PolicyEngine) evaluateStringCondition(block map[string]interface{}, eva
}
continue
}
// Convert context value to string slice
var contextStrings []string
switch v := contextValues.(type) {
@@ -449,7 +449,7 @@ func (e *PolicyEngine) evaluateStringCondition(block map[string]interface{}, eva
// Convert to string as fallback
contextStrings = []string{fmt.Sprintf("%v", v)}
}
// Convert condition value to string slice
var expectedStrings []string
switch v := conditionValue.(type) {
@@ -468,7 +468,7 @@ func (e *PolicyEngine) evaluateStringCondition(block map[string]interface{}, eva
default:
expectedStrings = []string{fmt.Sprintf("%v", v)}
}
// Evaluate the condition
conditionMet := false
for _, expected := range expectedStrings {
@@ -492,7 +492,7 @@ func (e *PolicyEngine) evaluateStringCondition(block map[string]interface{}, eva
break
}
}
// For shouldMatch=true (StringEquals, StringLike): condition must be met
// For shouldMatch=false (StringNotEquals): condition must NOT be met
if shouldMatch && !conditionMet {
@@ -502,7 +502,7 @@ func (e *PolicyEngine) evaluateStringCondition(block map[string]interface{}, eva
return false
}
}
return true
}
+13
View File
@@ -9,6 +9,7 @@ import (
"time"
"github.com/golang-jwt/jwt/v5"
"github.com/seaweedfs/seaweedfs/weed/glog"
)
// TokenGenerator handles token generation and validation
@@ -88,7 +89,10 @@ func (t *TokenGenerator) ValidateSessionToken(tokenString string) (*SessionToken
// ValidateJWTWithClaims validates and extracts comprehensive session claims from a JWT token
func (t *TokenGenerator) ValidateJWTWithClaims(tokenString string) (*STSSessionClaims, error) {
glog.V(0).Infof("ValidateJWTWithClaims: validating token with length=%d", len(tokenString))
token, err := jwt.ParseWithClaims(tokenString, &STSSessionClaims{}, func(token *jwt.Token) (interface{}, error) {
glog.V(0).Infof("ValidateJWTWithClaims: signing method=%v", token.Header["alg"])
if _, ok := token.Method.(*jwt.SigningMethodHMAC); !ok {
return nil, fmt.Errorf("unexpected signing method: %v", token.Header["alg"])
}
@@ -96,33 +100,42 @@ func (t *TokenGenerator) ValidateJWTWithClaims(tokenString string) (*STSSessionC
})
if err != nil {
glog.V(0).Infof("ValidateJWTWithClaims: token parsing failed: %v", err)
return nil, fmt.Errorf(ErrInvalidToken, err)
}
if !token.Valid {
glog.V(0).Info("ValidateJWTWithClaims: token is not valid")
return nil, fmt.Errorf(ErrTokenNotValid)
}
claims, ok := token.Claims.(*STSSessionClaims)
if !ok {
glog.V(0).Infof("ValidateJWTWithClaims: failed to cast claims to STSSessionClaims, got type: %T", token.Claims)
return nil, fmt.Errorf(ErrInvalidTokenClaims)
}
glog.V(0).Infof("ValidateJWTWithClaims: parsed claims - issuer=%s, sessionId=%s", claims.Issuer, claims.SessionId)
// Validate issuer
if claims.Issuer != t.issuer {
glog.V(0).Infof("ValidateJWTWithClaims: issuer mismatch - expected=%s, got=%s", t.issuer, claims.Issuer)
return nil, fmt.Errorf(ErrInvalidIssuer)
}
// Validate that required fields are present
if claims.SessionId == "" {
glog.V(0).Info("ValidateJWTWithClaims: missing session ID")
return nil, fmt.Errorf(ErrMissingSessionID)
}
// Additional validation using the claims' own validation method
if !claims.IsValid() {
glog.V(0).Info("ValidateJWTWithClaims: claims validation failed")
return nil, fmt.Errorf(ErrTokenNotValid)
}
glog.V(0).Info("ValidateJWTWithClaims: validation successful")
return claims, nil
}