package services import ( "authorization/models" "authorization/redisclient" "authorization/repository" "context" "encoding/json" "errors" "fmt" "log" "sync" "time" ) const ( permissionCachePrefix = "authz:perm:" policyCachePrefix = "authz:policy:" userAttrCachePrefix = "authz:userattr:" cacheTTL = 5 * time.Second ) // getCachedUserAttributes retrieves user attributes from Redis or DB func getCachedUserAttributes(s *models.CachedAuthorizationService, userID string) (map[string]string, error) { // Try Redis first if available if redisclient.RDB != nil { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() key := userAttrCachePrefix + userID val, err := redisclient.RDB.Get(ctx, key).Result() if err == nil { var attrs map[string]string if json.Unmarshal([]byte(val), &attrs) == nil { return attrs, nil } } } // Fallback to local cache for backward compatibility userAttrMutex := s.UserAttrMutex.(*sync.RWMutex) userAttrMutex.RLock() attrs, exists := s.UserAttrCache[userID] userAttrMutex.RUnlock() if exists { return attrs, nil } // Cache miss - fetch from DB attrs, err := repository.GetUserAttributes(userID) if err != nil { return nil, err } // Store in both Redis and local cache if redisclient.RDB != nil { go func() { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() attrsJSON, _ := json.Marshal(attrs) key := userAttrCachePrefix + userID redisclient.RDB.Set(ctx, key, attrsJSON, cacheTTL) }() } userAttrMutex.Lock() s.UserAttrCache[userID] = attrs userAttrMutex.Unlock() return attrs, nil } // getPermissionFromCache retrieves permission from Redis or local cache func getPermissionFromCache(s *models.CachedAuthorizationService, cacheKey string) (*models.Permission, bool) { // Try Redis first if available if redisclient.RDB != nil { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() key := permissionCachePrefix + cacheKey val, err := redisclient.RDB.Get(ctx, key).Result() if err == nil { var perm models.Permission if json.Unmarshal([]byte(val), &perm) == nil { return &perm, true } } } // Fallback to local cache cacheMutex := s.CacheMutex.(*sync.RWMutex) cacheMutex.RLock() permission, exists := s.PermissionCache[cacheKey] cacheMutex.RUnlock() return permission, exists } func storePermissionInCache(s *models.CachedAuthorizationService, cacheKey string, permission *models.Permission) { // Store in Redis (async) if redisclient.RDB != nil { go func() { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() permJSON, _ := json.Marshal(permission) key := permissionCachePrefix + cacheKey redisclient.RDB.Set(ctx, key, permJSON, cacheTTL) }() } // Store in local cache cacheMutex := s.CacheMutex.(*sync.RWMutex) cacheMutex.Lock() s.PermissionCache[cacheKey] = permission cacheMutex.Unlock() } // getPoliciesFromCache retrieves policies from Redis or local cache func getPoliciesFromCache(s *models.CachedAuthorizationService, permissionID int) []models.PolicyAttribute { // Try Redis first if available if redisclient.RDB != nil { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() key := fmt.Sprintf("%s%d", policyCachePrefix, permissionID) val, err := redisclient.RDB.Get(ctx, key).Result() if err == nil { var policies []models.PolicyAttribute if json.Unmarshal([]byte(val), &policies) == nil { return policies } } } // Fallback to local cache cacheMutex := s.CacheMutex.(*sync.RWMutex) cacheMutex.RLock() policies := s.PolicyCache[permissionID] cacheMutex.RUnlock() return policies } // refreshCache reloads permissions and policies from database and stores in Redis func refreshCache(s *models.CachedAuthorizationService) { // Note: We no longer pre-cache all permissions since we need role-specific lookups. // Permissions will be cached on-demand as users access them (lazy loading). // Load all policies (these are permission-specific, not role-specific) policies, err := repository.GetAllPolicyAttributes() if err != nil { log.Printf("ERROR: Failed to refresh policies cache: %v", err) return } // Update policy cache atomically cacheMutex := s.CacheMutex.(*sync.RWMutex) cacheMutex.Lock() s.PolicyCache = policies s.LastCacheRefresh = time.Now() cacheMutex.Unlock() // log.Printf("✓ Cache refreshed: %d policy groups cached", len(policies)) // Store policies in Redis for distributed access (non-blocking) // Permissions are now cached on-demand with role awareness if redisclient.RDB != nil { go func() { ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) defer cancel() // Store policies in Redis for permID, policyList := range policies { policiesJSON, _ := json.Marshal(policyList) redisKey := fmt.Sprintf("%s%d", policyCachePrefix, permID) redisclient.RDB.Set(ctx, redisKey, policiesJSON, cacheTTL) } // log.Printf("INFO: Policy cache synced to Redis - %d policy groups", len(policies)) }() } } // cleanUserAttributeCache removes old user attribute cache entries func cleanUserAttributeCache(s *models.CachedAuthorizationService) { userAttrMutex := s.UserAttrMutex.(*sync.RWMutex) userAttrMutex.Lock() defer userAttrMutex.Unlock() // Clear local cache if too large (Redis handles its own TTL) if len(s.UserAttrCache) > 10000 { s.UserAttrCache = make(map[string]map[string]string) } } // cacheRefreshLoop periodically refreshes the cache func cacheRefreshLoop(s *models.CachedAuthorizationService) { ticker := time.NewTicker(s.CacheExpiry) defer ticker.Stop() for range ticker.C { refreshCache(s) cleanUserAttributeCache(s) } } func NewCachedAuthorizationService() *models.CachedAuthorizationService { service := &models.CachedAuthorizationService{ PermissionCache: make(map[string]*models.Permission), PolicyCache: make(map[int][]models.PolicyAttribute), UserAttrCache: make(map[string]map[string]string), CacheMutex: &sync.RWMutex{}, UserAttrMutex: &sync.RWMutex{}, CacheExpiry: 5 * time.Second, // Changed from 5 minutes for faster updates LastCacheRefresh: time.Now(), } // Initial cache load refreshCache(service) // Background cache refresh go cacheRefreshLoop(service) return service } // AuthorizeWithCache performs cached RBAC + ABAC authorization with distributed caching func AuthorizeWithCache(s *models.CachedAuthorizationService, ctx *models.AuthorizationContext) (*models.AuthorizationResult, error) { startTime := time.Now() log.Printf("[CACHE-ENTRY] AuthorizeWithCache() called - UsersID=%s, Resource=%s, Action=%s, RoleID=%d", ctx.UsersID, ctx.Resource, ctx.Action, ctx.RoleID) log.Printf("[CACHE-ENTRY] Full context: %+v", ctx) log.Printf("[AuthZ Cached] Starting authorization check for user=%s, resource=%s, action=%s", ctx.UsersID, ctx.Resource, ctx.Action) // Step 0: Get user to retrieve role_id (needed for role-based permission lookup) log.Printf("[AuthZ Step 0] Fetching user details for userID=%s", ctx.UsersID) user, err := repository.GetUserByID(ctx.UsersID) if err != nil { if errors.Is(err, repository.ErrUserDeleted) { log.Printf("✗ Deleted user attempted authorization for userID=%s", ctx.UsersID) return &models.AuthorizationResult{ Allowed: false, RedirectRoute: "/login", Message: "Account deleted", }, nil } log.Printf("✗ User not found for userID=%s: %v", ctx.UsersID, err) return &models.AuthorizationResult{ Allowed: false, Message: fmt.Sprintf("User not found: %v", err), }, nil } log.Printf("[AuthZ Step 0] User found: role_id=%d", user.RoleID) roleCandidates := getRoleCandidates(ctx) var permission *models.Permission permissionFound := false for _, roleID := range roleCandidates { cacheKey := fmt.Sprintf("%d:%s:%s", roleID, ctx.Resource, ctx.Action) log.Printf("[AuthZ Step 1] Looking up permission in cache with role: %s", cacheKey) cachedPermission, exists := getPermissionFromCache(s, cacheKey) if exists { permission = cachedPermission ctx.RoleID = roleID permissionFound = true log.Printf("✓ [AuthZ Step 1] Permission found in cache for role_id=%d: ID=%d, Name=%s", roleID, permission.ID, permission.PermissionName) break } log.Printf("[AuthZ Step 1] Cache miss - querying database for role_id=%d, resource=%s, action=%s", roleID, ctx.Resource, ctx.Action) dbPermission, lookupErr := repository.GetPermissionByResourceActionAndRole(ctx.Resource, ctx.Action, roleID) if lookupErr != nil { log.Printf("[AuthZ Step 1] Permission not granted for role_id=%d, trying next role: %v", roleID, lookupErr) continue } permission = dbPermission ctx.RoleID = roleID permissionFound = true log.Printf("✓ [AuthZ Step 1] Permission found in DB for role_id=%d: ID=%d, Name=%s", roleID, permission.ID, permission.PermissionName) storePermissionInCache(s, cacheKey, permission) break } if !permissionFound { log.Printf("✗ [AuthZ Step 1] Permission not granted for any role candidate=%v, resource=%s, action=%s", roleCandidates, ctx.Resource, ctx.Action) return &models.AuthorizationResult{ Allowed: false, Message: "Permission not granted to your role", }, nil } // Step 2: Get user attributes (with distributed cache) log.Printf("[AuthZ Step 2] Fetching user attributes for userID=%s", ctx.UsersID) userAttrs, err := getCachedUserAttributes(s, ctx.UsersID) if err != nil { log.Printf("✗ Failed to get user attributes for userID=%s: %v", ctx.UsersID, err) return &models.AuthorizationResult{ Allowed: false, Message: "Failed to get user attributes", }, err } ctx.UserAttributes = userAttrs fmt.Printf("[DEBUG] User attributes map: %+v\n", userAttrs) fmt.Println("[DEBUG] About to print user attributes (cache)") for k, v := range userAttrs { log.Printf("User Attribute (cache) - %s: %v", k, v) fmt.Printf("[DEBUG] User Attribute (cache) - %s: %v\n", k, v) } fmt.Println("[DEBUG] Finished printing user attributes (cache)") log.Printf("[AuthZ Step 2] User attributes retrieved: %d attributes", len(userAttrs)) // Step 3: Get policies from distributed cache log.Printf("[AuthZ Step 3] Fetching policies for permissionID=%d", permission.ID) policies := getPoliciesFromCache(s, permission.ID) log.Printf("[AuthZ Step 3] Policies retrieved: %d policies to evaluate", len(policies)) if len(policies) > 0 { for i, p := range policies { log.Printf("[DEBUG] Policy %d: AttributeType=%s, AttributeName=%s, Comparison=%s, AttributeValue=%s", i+1, p.AttributeType, p.AttributeName, p.Comparison, p.AttributeValue) } } else { log.Printf("[DEBUG] No policies loaded for permissionID=%d", permission.ID) } log.Printf("[AuthZ Step 4] Using RoleID: %d (from context or user record)", ctx.RoleID) allowed, reason := EvaluatePolicies(policies, ctx) result := &models.AuthorizationResult{ Allowed: allowed, } if allowed { result.Message = "Access granted" log.Printf("✓ Authorization GRANTED for user=%s, resource=%s, action=%s (evaluated in %v)", ctx.UsersID, ctx.Resource, ctx.Action, time.Since(startTime)) } else { result.Message = reason log.Printf("✗ Authorization DENIED for user=%s, resource=%s, action=%s - Reason: %s (evaluated in %v)", ctx.UsersID, ctx.Resource, ctx.Action, reason, time.Since(startTime)) } // Performance monitoring evalTime := time.Since(startTime) if evalTime < 50*time.Millisecond { log.Print("Cached authorization evaluation time: ", evalTime, " for user=", ctx.UsersID, ", resource=", ctx.Resource, ", action=", ctx.Action) } if evalTime > 50*time.Millisecond { log.Print("WARN: Slow cached authorization evaluation: ", evalTime, " for user=", ctx.UsersID, ", resource=", ctx.Resource, ", action=", ctx.Action) } return result, nil } func getRoleCandidates(ctx *models.AuthorizationContext) []int { if len(ctx.CandidateRoles) > 0 { return ctx.CandidateRoles } if len(ctx.RoleIDs) > 0 { return ctx.RoleIDs } if ctx.RoleID != 0 { return []int{ctx.RoleID} } return nil } // InvalidateUserCache clears cache for a specific user from both Redis and local cache func InvalidateUserCache(s *models.CachedAuthorizationService, userID string) { // Clear from Redis if redisclient.RDB != nil { go func() { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() key := userAttrCachePrefix + userID redisclient.RDB.Del(ctx, key) }() } // Clear from local cache userAttrMutex := s.UserAttrMutex.(*sync.RWMutex) userAttrMutex.Lock() delete(s.UserAttrCache, userID) userAttrMutex.Unlock() } // RefreshCacheNow forces an immediate cache refresh (useful for admin endpoints) func RefreshCacheNow(s *models.CachedAuthorizationService) { refreshCache(s) } // GetCacheStats returns cache statistics including Redis availability func GetCacheStats(s *models.CachedAuthorizationService) map[string]interface{} { cacheMutex := s.CacheMutex.(*sync.RWMutex) userAttrMutex := s.UserAttrMutex.(*sync.RWMutex) cacheMutex.RLock() userAttrMutex.RLock() defer cacheMutex.RUnlock() defer userAttrMutex.RUnlock() stats := map[string]interface{}{ "permissions_cached": len(s.PermissionCache), "policies_cached": len(s.PolicyCache), "user_attributes_cached": len(s.UserAttrCache), "last_refresh": s.LastCacheRefresh, "cache_age_seconds": time.Since(s.LastCacheRefresh).Seconds(), "distributed_cache": redisclient.RDB != nil, } // Add Redis cache stats if available if redisclient.RDB != nil { ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond) defer cancel() // Try to get Redis info if info, err := redisclient.RDB.Info(ctx, "stats").Result(); err == nil { stats["redis_available"] = true stats["redis_info"] = info } else { stats["redis_available"] = false } } return stats }