From 7895f449492bb0f8832d4fe77a3bf822191a1a5b Mon Sep 17 00:00:00 2001 From: Ralf Haferkamp Date: Thu, 16 Mar 2023 17:17:41 +0100 Subject: [PATCH] proxy: Cache the role Mapping for some time Avoid torturing the settings service with "ListRoles" request for every incoming request to the proxy. The role Mapping is refreshed if cached data is older than 5 minutes. --- services/proxy/pkg/userroles/oidcroles.go | 102 +++++++++++++++------- 1 file changed, 69 insertions(+), 33 deletions(-) diff --git a/services/proxy/pkg/userroles/oidcroles.go b/services/proxy/pkg/userroles/oidcroles.go index 7b2eae83054..0d5b8021bb6 100644 --- a/services/proxy/pkg/userroles/oidcroles.go +++ b/services/proxy/pkg/userroles/oidcroles.go @@ -3,6 +3,8 @@ package userroles import ( "context" "errors" + "sync" + "time" cs3 "github.com/cs3org/go-cs3apis/cs3/identity/user/v1beta1" types "github.com/cs3org/go-cs3apis/cs3/types/v1beta1" @@ -31,81 +33,78 @@ func NewOIDCRoleAssigner(opts ...Option) UserRoleAssigner { // UpdateUserRoleAssignment assigns the role "User" to the supplied user. Unless the user // already has a different role assigned. func (ra oidcRoleAssigner) UpdateUserRoleAssignment(ctx context.Context, user *cs3.User, claims map[string]interface{}) (*cs3.User, error) { - - // To list roles and update assignment we need some elevated access to the settings service - // prepare a new request context for that until we have service accounts - newctx, err := ra.prepareAdminContext() - if err != nil { - ra.logger.Error().Err(err).Msg("Error creating admin context") - return nil, err - } - - claimValueToRoleID, err := ra.oidcClaimvaluesToRoleIDs(newctx) + logger := ra.logger.SubloggerWithRequestID(ctx).With().Str("userid", user.GetId().GetOpaqueId()).Logger() + claimValueToRoleID, err := ra.oidcClaimvaluesToRoleIDs() if err != nil { - ra.logger.Error().Err(err).Msg("Error mapping claims to roles ids") + logger.Error().Err(err).Msg("Error mapping claims to roles ids") return nil, err } roleIDsFromClaim := make([]string, 0, 1) - ra.logger.Error().Interface("rolesclaim", claims[ra.rolesClaim]).Msg("Got ClaimRoles") claimRoles, ok := claims[ra.rolesClaim].([]interface{}) if !ok { - ra.logger.Error().Err(err).Msg("No roles in user claims.") + logger.Error().Err(err).Str("rolesClaim", ra.rolesClaim).Msg("No roles in user claims") return nil, err } + logger.Debug().Str("rolesClaim", ra.rolesClaim).Interface("rolesInClaim", claims[ra.rolesClaim]).Msg("got roles in claim") for _, cri := range claimRoles { cr, ok := cri.(string) if !ok { err := errors.New("invalid role in claims") - ra.logger.Error().Err(err).Interface("claim value", cri).Msg("Is not a valid string.") + logger.Error().Err(err).Interface("claimValue", cri).Msg("Is not a valid string.") return nil, err } id, ok := claimValueToRoleID[cr] if !ok { - ra.logger.Error().Str("role", cr).Msg("Skipping unmaped role from claims.") + logger.Debug().Str("role", cr).Msg("No mapping for claim role. Skipped.") continue } roleIDsFromClaim = append(roleIDsFromClaim, id) } - ra.logger.Error().Interface("roleIDs", roleIDsFromClaim).Msg("Mapped roles from claim") + logger.Debug().Interface("roleIDs", roleIDsFromClaim).Msg("Mapped claim roles to roleids") switch len(roleIDsFromClaim) { default: err := errors.New("too many roles found in claims") - ra.logger.Error().Err(err).Msg("Only one role per user is allowed.") + logger.Error().Err(err).Msg("Only one role per user is allowed.") return nil, err case 0: err := errors.New("no role in claim, maps to a ocis role") - ra.logger.Error().Err(err).Msg("") + logger.Error().Err(err).Msg("") return nil, err case 1: // exactly one mapping. This is right break } - - assignedRoles, err := loadRolesIDs(newctx, user.GetId().GetOpaqueId(), ra.roleService) + assignedRoles, err := loadRolesIDs(ctx, user.GetId().GetOpaqueId(), ra.roleService) if err != nil { - ra.logger.Error().Err(err).Msgf("Could not load roles") + logger.Error().Err(err).Msg("Could not load roles") return nil, err } if len(assignedRoles) > 1 { err := errors.New("too many roles assigned") - ra.logger.Error().Err(err).Msg("The user has too many roles assigned") + logger.Error().Err(err).Msg("The user has too many roles assigned") return nil, err } - ra.logger.Error().Interface("assignedRoleIds", assignedRoles).Msg("Currently assigned roles") + logger.Debug().Interface("assignedRoleIds", assignedRoles).Msg("Currently assigned roles") if len(assignedRoles) == 0 || (assignedRoles[0] != roleIDsFromClaim[0]) { + logger.Debug().Interface("assignedRoleIds", assignedRoles).Interface("newRoleIds", roleIDsFromClaim).Msg("Updating role assignment for user") + newctx, err := ra.prepareAdminContext() + if err != nil { + logger.Error().Err(err).Msg("Error creating admin context") + return nil, err + } if _, err = ra.roleService.AssignRoleToUser(newctx, &settingssvc.AssignRoleToUserRequest{ AccountUuid: user.GetId().GetOpaqueId(), RoleId: roleIDsFromClaim[0], }); err != nil { - ra.logger.Error().Err(err).Msg("Role assignment failed") + logger.Error().Err(err).Msg("Role assignment failed") return nil, err } } enc, err := encodeRoleIDs(roleIDsFromClaim) if err != nil { - ra.logger.Error().Err(err).Msg("Could not encode loaded roles") + logger.Error().Err(err).Msg("Could not encode loaded roles") return nil, err } @@ -166,26 +165,63 @@ func (ra oidcRoleAssigner) prepareAdminContext() (context.Context, error) { return newctx, nil } -func (ra oidcRoleAssigner) oidcClaimvaluesToRoleIDs(ctx context.Context) (map[string]string, error) { - roleClaimToID := map[string]string{} +type roleClaimToIDCache struct { + roleClaimToID map[string]string + lastRead time.Time + lock sync.RWMutex +} + +var roleClaimToID roleClaimToIDCache + +func (ra oidcRoleAssigner) oidcClaimvaluesToRoleIDs() (map[string]string, error) { + cacheTTL := 5 * time.Minute + roleClaimToID.lock.RLock() + + if !roleClaimToID.lastRead.IsZero() && time.Since(roleClaimToID.lastRead) < cacheTTL { + defer roleClaimToID.lock.RUnlock() + return roleClaimToID.roleClaimToID, nil + } + ra.logger.Debug().Msg("refreshing roles ids") + + // cache needs Refresh get a write lock + roleClaimToID.lock.RUnlock() + roleClaimToID.lock.Lock() + defer roleClaimToID.lock.Unlock() + + // check again, another goroutine might have updated while we "upgraded" the lock + if !roleClaimToID.lastRead.IsZero() && time.Since(roleClaimToID.lastRead) < cacheTTL { + return roleClaimToID.roleClaimToID, nil + } + // Get all roles to find the role IDs. - // TODO: we need to cache this. Roles IDs change rarely and this is a pretty expensiveV call + // To list roles we need some elevated access to the settings service + // prepare a new request context for that until we have service accounts + ctx, err := ra.prepareAdminContext() + if err != nil { + ra.logger.Error().Err(err).Msg("Error creating admin context") + return nil, err + } + req := &settingssvc.ListBundlesRequest{} res, err := ra.roleService.ListRoles(ctx, req) if err != nil { ra.logger.Error().Err(err).Msg("Failed to list all roles") - return roleClaimToID, err + return map[string]string{}, err } + newIDs := map[string]string{} for _, role := range res.Bundles { - ra.logger.Error().Str("role", role.Name).Str("id", role.Id).Msg("Got Role") + ra.logger.Debug().Str("role", role.Name).Str("id", role.Id).Msg("Got Role") roleClaim, ok := ra.roleMapping[role.Name] if !ok { err := errors.New("Incomplete role mapping") ra.logger.Error().Err(err).Str("role", role.Name).Msg("Role not mapped to a claim value") - return roleClaimToID, err + return map[string]string{}, err } - roleClaimToID[roleClaim] = role.Id + newIDs[roleClaim] = role.Id } - return roleClaimToID, nil + ra.logger.Debug().Interface("roleMap", newIDs).Msg("Claim Role to role ID map") + roleClaimToID.roleClaimToID = newIDs + roleClaimToID.lastRead = time.Now() + return roleClaimToID.roleClaimToID, nil }