From c6593f4591336778a4e3887cb6c81bff60b04126 Mon Sep 17 00:00:00 2001 From: chrislu Date: Tue, 26 Aug 2025 17:50:27 -0700 Subject: [PATCH] more logs --- weed/s3api/s3_iam_middleware.go | 54 ++++++++++++------------- weed/s3api/s3api_object_handlers_put.go | 6 +++ 2 files changed, 33 insertions(+), 27 deletions(-) diff --git a/weed/s3api/s3_iam_middleware.go b/weed/s3api/s3_iam_middleware.go index 852cdd558..4f4f0763a 100644 --- a/weed/s3api/s3_iam_middleware.go +++ b/weed/s3api/s3_iam_middleware.go @@ -42,27 +42,27 @@ 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) - + glog.V(0).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") + glog.V(0).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") + glog.V(0).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") + glog.V(0).Infof("🔐 AuthenticateJWT: Empty session token") return nil, s3err.ErrAccessDenied } - - glog.V(2).Infof("🔐 AuthenticateJWT: Processing JWT token (length: %d)", len(sessionToken)) + + glog.V(0).Infof("🔐 AuthenticateJWT: Processing JWT token (length: %d)", len(sessionToken)) // Basic token format validation - reject obviously invalid tokens if sessionToken == "invalid-token" || len(sessionToken) < 10 { @@ -80,19 +80,19 @@ 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 == "" { - glog.V(2).Infof("🔐 AuthenticateJWT: No 'role' claim found, treating as OIDC token") - + glog.V(0).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...") + glog.V(0).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 { // Check if it's a timeout error and log accordingly if ctx.Err() == context.DeadlineExceeded { @@ -102,8 +102,8 @@ func (s3iam *S3IAMIntegration) AuthenticateJWT(ctx context.Context, r *http.Requ } return nil, s3err.ErrAccessDenied } - - glog.V(2).Infof("🔐 AuthenticateJWT: OIDC token validation SUCCEEDED after %v", elapsed) + + glog.V(0).Infof("🔐 AuthenticateJWT: OIDC token validation SUCCEEDED after %v", elapsed) // Extract role from OIDC identity if identity.RoleArn == "" { @@ -460,38 +460,38 @@ 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") - + glog.V(0).Infof("🔍 validateOIDCToken: Starting OIDC token validation") + if s3iam.iamManager == nil { - glog.V(2).Infof("🔍 validateOIDCToken: IAM manager not available") + glog.V(0).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") + glog.V(0).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)) - + glog.V(0).Infof("🔍 validateOIDCToken: Found %d providers to try", len(providers)) + for providerName, provider := range providers { - glog.V(2).Infof("🔍 validateOIDCToken: Trying provider '%s'...", providerName) + glog.V(0).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(2).Infof("🔍 validateOIDCToken: Provider '%s' FAILED after %v: %v", providerName, elapsed, err) + glog.V(0).Infof("🔍 validateOIDCToken: Provider '%s' FAILED after %v: %v", providerName, elapsed, err) continue } - - glog.V(2).Infof("🔍 validateOIDCToken: Provider '%s' SUCCEEDED after %v", providerName, elapsed) + + glog.V(0).Infof("🔍 validateOIDCToken: Provider '%s' SUCCEEDED after %v", providerName, elapsed) // Extract role from external identity attributes rolesAttr, exists := externalIdentity.Attributes["roles"] diff --git a/weed/s3api/s3api_object_handlers_put.go b/weed/s3api/s3api_object_handlers_put.go index 148b9ed7a..f6bbda321 100644 --- a/weed/s3api/s3api_object_handlers_put.go +++ b/weed/s3api/s3api_object_handlers_put.go @@ -64,6 +64,12 @@ func (s3a *S3ApiServer) PutObjectHandler(w http.ResponseWriter, r *http.Request) // http://docs.aws.amazon.com/AmazonS3/latest/dev/UploadingObjects.html bucket, object := s3_constants.GetBucketAndObject(r) + authHeader := r.Header.Get("Authorization") + authPreview := authHeader + if len(authHeader) > 50 { + authPreview = authHeader[:50] + "..." + } + glog.V(0).Infof("🟦 PutObjectHandler: Starting PUT %s/%s (Auth: %s)", bucket, object, authPreview) glog.V(3).Infof("PutObjectHandler %s %s", bucket, object) _, err := validateContentMd5(r.Header)