Uploaded image for project: 'OpenAM'
  1. OpenAM
  2. OPENAM-12458

Entitlement log contains errors on successful policy evaluation

    XMLWordPrintable

    Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Duplicate
    • 14.1.0, 5.5.1
    • None
    • entitlements, policy
    • Rank:
      1|hzvpun:
    • AM Sustaining Sprint 50, AM Sustaining Sprint 51, AM Sustaining Sprint 52, AM Sustaining Sprint 53
    • 3

      Description

      Bug description

      An error will be written for every policy check, potentially quickly filling up disk space.

      How to reproduce the issue

      • Create a realm 'testrealm'
      • In the realm:
      • Set User Profile to Ignored
      • Delete the embedded datastore
      • Create a policy set (application) called 'TEST' with policy for
        *://*:*/*
      • Give All Authenticated Users the privilege 'REST calls for policy evaluation'.
      • In the root realm:
      • Create a group 'policygroup' with privilege 'Read and write access for policy administration'.
      • Authenticate to testrealm using ?module=LDAP
      • Use the token in a policy evaluation.
        curl -v --request POST --header 'iPlanetDirectoryPro: 8s6zrYUUpM21z0_UyooRichfgsM.*AAJTSQACMDEAAlNLABxGZlF1U0pvZHNvQXRla2hPY0lOMUhqOWRwMjg9AAJTMQAA*' --header 'Content-Type: application/json' --data '{
        	"resources": ["http://am551.fr.local/test"], "application": "TEST", "environment": {}
        }' 'http://am551.fr.local:8080/openam/json/realms/root/realms/testrealm/policies?_action=evaluate'
        
        [{"ttl":9223372036854775807,"advices":{},"resource":"http://am551.fr.local/test","actions":{"GET":true},"attributes":{}}]
        
      Expected behaviour

      No error log on successful policy evaluation.

      Current behaviour

      On every evaluation the Entitlement log contains:

      Entitlement:02/15/2018 05:22:54:828 PM GMT: Thread[entitlementThreadPool3,5,main]: TransactionId[57f23372-e0f6-46ce-b8c0-400ca46a3f9a-8573]
      ERROR: OpenSSOPrivilege.evaluate
      com.sun.identity.entitlement.EntitlementException: Subject evaluation fails.
      	at com.sun.identity.entitlement.opensso.PolicySubject.evaluate(PolicySubject.java:225)
      	at com.sun.identity.entitlement.Privilege.doesSubjectMatch(Privilege.java:669)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.internalEvaluate(OpenSSOPrivilege.java:140)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.access$000(OpenSSOPrivilege.java:63)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege$1.run(OpenSSOPrivilege.java:105)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege$1.run(OpenSSOPrivilege.java:99)
      	at com.sun.identity.session.util.RestrictedTokenContext.doUsing(RestrictedTokenContext.java:81)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.evaluate(OpenSSOPrivilege.java:98)
      	at com.sun.identity.entitlement.PrivilegeEvaluator$PrivilegeTask.run(PrivilegeEvaluator.java:421)
      	at com.sun.identity.entitlement.ThreadPool$WorkerThread.run(ThreadPool.java:166)
      Caused by: com.sun.identity.policy.PolicyException: AMIdentitySubject - can not check membership for user uid=george,ou=people,dc=openam,dc=forgerock,dc=org and subject id=policyg,ou=group,dc=openam,dc=forgerock,dc=org
      Identity george of type user not found.
      Identity george of type user not found.
      	at com.sun.identity.policy.plugins.AMIdentitySubject.isMember(AMIdentitySubject.java:427)
      	at com.sun.identity.entitlement.opensso.PolicySubject.evaluate(PolicySubject.java:220)
      	... 9 more
      Entitlement:02/15/2018 05:22:54:830 PM GMT: Thread[http-bio-8080-exec-2,5,main]: TransactionId[57f23372-e0f6-46ce-b8c0-400ca46a3f9a-44552]
      ERROR: OpenSSOPrivilege.evaluate
      com.sun.identity.entitlement.EntitlementException: Subject evaluation fails.
      	at com.sun.identity.entitlement.opensso.PolicySubject.evaluate(PolicySubject.java:225)
      	at com.sun.identity.entitlement.Privilege.doesSubjectMatch(Privilege.java:669)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.internalEvaluate(OpenSSOPrivilege.java:140)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.access$000(OpenSSOPrivilege.java:63)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege$1.run(OpenSSOPrivilege.java:105)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege$1.run(OpenSSOPrivilege.java:99)
      	at com.sun.identity.session.util.RestrictedTokenContext.doUsing(RestrictedTokenContext.java:81)
      	at com.sun.identity.entitlement.opensso.OpenSSOPrivilege.evaluate(OpenSSOPrivilege.java:98)
      	at com.sun.identity.entitlement.PrivilegeEvaluator$PrivilegeTask.run(PrivilegeEvaluator.java:421)
      	at com.sun.identity.entitlement.PrivilegeEvaluator.evaluate(PrivilegeEvaluator.java:335)
      	at com.sun.identity.entitlement.PrivilegeEvaluator.evaluate(PrivilegeEvaluator.java:252)
      	at com.sun.identity.entitlement.Evaluator.evaluate(Evaluator.java:198)
      	at com.sun.identity.policy.PolicyEvaluator.getPolicyDecision(PolicyEvaluator.java:770)
      	at com.sun.identity.policy.PolicyEvaluator.getPolicyDecision(PolicyEvaluator.java:720)
      	at com.sun.identity.delegation.plugins.DelegationPolicyImpl.isAllowed(DelegationPolicyImpl.java:550)
      	at com.sun.identity.delegation.DelegationEvaluatorImpl.isAllowed(DelegationEvaluatorImpl.java:219)
      	at com.sun.identity.idm.server.IdServicesImpl.checkPermission(IdServicesImpl.java:2569)
      	at com.sun.identity.idm.server.IdServicesImpl.getAttributes(IdServicesImpl.java:618)
      	at com.sun.identity.idm.server.IdCachedServicesImpl.getAttributes(IdCachedServicesImpl.java:381)
      	at com.sun.identity.idm.AMIdentity.getAttribute(AMIdentity.java:420)
      	at com.sun.identity.common.configuration.AgentConfiguration.getAgentType(AgentConfiguration.java:1026)
      	at org.forgerock.openam.identity.idm.IdentityUtils.isCASPAorJASPA(IdentityUtils.java:90)
      	at org.forgerock.openam.authz.PrivilegeAuthzModule.evaluate(PrivilegeAuthzModule.java:146)
      	at org.forgerock.openam.authz.PrivilegeAuthzModule.evaluate(PrivilegeAuthzModule.java:98)
      	at org.forgerock.openam.rest.authz.CrestPrivilegeAuthzModule.evaluateAsPromise(CrestPrivilegeAuthzModule.java:120)
      	at org.forgerock.openam.rest.authz.CrestPrivilegeAuthzModule.authorizeAction(CrestPrivilegeAuthzModule.java:115)
      	at org.forgerock.openam.rest.authz.LoggingAuthzModule.authorizeAction(LoggingAuthzModule.java:110)
      	at org.forgerock.authz.filter.crest.AuthorizationFilters$AuthorizationFilter.filterAction(AuthorizationFilters.java:223)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:53)
      	at org.forgerock.json.resource.FilterChain.handleAction(FilterChain.java:222)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:55)
      	at org.forgerock.openam.rest.fluent.AuditFilter.filterAction(AuditFilter.java:81)
      	at org.forgerock.openam.rest.fluent.AuditFilterWrapper.filterAction(AuditFilterWrapper.java:52)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:53)
      	at org.forgerock.openam.rest.fluent.CrestLoggingFilter.filterAction(CrestLoggingFilter.java:66)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:53)
      	at org.forgerock.openam.rest.ContextFilter.filterAction(ContextFilter.java:49)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:53)
      	at org.forgerock.openam.rest.AuthenticationEnforcer.filterAction(AuthenticationEnforcer.java:129)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:53)
      	at org.forgerock.json.resource.FilterChain.handleAction(FilterChain.java:222)
      	at org.forgerock.json.resource.Router.handleAction(Router.java:250)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:55)
      	at org.forgerock.openam.rest.ContextFilter.filterAction(ContextFilter.java:49)
      	at org.forgerock.json.resource.FilterChain$Cursor.handleAction(FilterChain.java:53)
      	at org.forgerock.json.resource.FilterChain.handleAction(FilterChain.java:222)
      	at org.forgerock.json.resource.InternalConnection.actionAsync(InternalConnection.java:29)
      	at org.forgerock.json.resource.http.RequestRunner.visitActionRequest(RequestRunner.java:136)
      	at org.forgerock.json.resource.http.RequestRunner.visitActionRequest(RequestRunner.java:82)
      	at org.forgerock.json.resource.Requests$ActionRequestImpl.accept(Requests.java:177)
      	at org.forgerock.json.resource.http.RequestRunner.handleResult(RequestRunner.java:128)
      	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:252)
      	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:241)
      	at org.forgerock.json.resource.http.HttpAdapter.doRequest(HttpAdapter.java:712)
      	at org.forgerock.json.resource.http.HttpAdapter.doAction(HttpAdapter.java:618)
      	at org.forgerock.json.resource.http.HttpAdapter.handle(HttpAdapter.java:282)
      	at org.forgerock.http.handler.Handlers$HandlerDescribableAsDescribableHandler.handle(Handlers.java:146)
      	at org.forgerock.http.filter.OptionsFilter.filter(OptionsFilter.java:69)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.openam.rest.RealmContextFilter.filter(RealmContextFilter.java:80)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.openam.rest.RealmRoutingFactory$ChfRealmRouter.handle(RealmRoutingFactory.java:139)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.openam.rest.RealmRoutingFactory$ChfRealmRouter.handle(RealmRoutingFactory.java:139)
      	at org.forgerock.http.handler.Handlers$UndescribedAsDescribableHandler.handle(Handlers.java:179)
      	at org.forgerock.openam.rest.RealmRoutingFactory$HostnameFilter.filter(RealmRoutingFactory.java:116)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.http.routing.ResourceApiVersionRoutingFilter.filter(ResourceApiVersionRoutingFilter.java:59)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.caf.authentication.framework.AuthenticationFramework.grantAccess(AuthenticationFramework.java:188)
      	at org.forgerock.caf.authentication.framework.AuthenticationFramework.lambda$onValidateRequestSuccess$1(AuthenticationFramework.java:181)
      	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:252)
      	at org.forgerock.util.promise.Promises$CompletedPromise.thenAsync(Promises.java:241)
      	at org.forgerock.caf.authentication.framework.AuthenticationFramework.validateRequest(AuthenticationFramework.java:144)
      	at org.forgerock.caf.authentication.framework.AuthenticationFramework.processMessage(AuthenticationFramework.java:134)
      	at org.forgerock.caf.authentication.framework.AuthenticationFilter.filter(AuthenticationFilter.java:84)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.openam.http.GuiceHandler.handle(GuiceHandler.java:51)
      	at org.forgerock.openam.http.HttpRoute$6.handle(HttpRoute.java:206)
      	at org.forgerock.http.routing.Router.handle(Router.java:100)
      	at org.forgerock.openam.dpro.session.ProofOfPossessionTokenFilter.filter(ProofOfPossessionTokenFilter.java:88)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.http.swagger.OpenApiRequestFilter.filter(OpenApiRequestFilter.java:62)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.openam.http.ApiDescriptorFilter.filter(ApiDescriptorFilter.java:139)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.openam.http.OpenAMHttpApplication$1.filter(OpenAMHttpApplication.java:74)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.http.filter.TransactionIdInboundFilter.filter(TransactionIdInboundFilter.java:75)
      	at org.forgerock.http.handler.Handlers$1.handle(Handlers.java:53)
      	at org.forgerock.http.servlet.HttpFrameworkServlet.service(HttpFrameworkServlet.java:258)
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at org.forgerock.openam.rest.ProtocolVersionFilter.doFilter(ProtocolVersionFilter.java:62)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at org.forgerock.openam.validation.ResponseValidationFilter.doFilter(ResponseValidationFilter.java:36)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at org.forgerock.openam.headers.SetHeadersFilter.doFilter(SetHeadersFilter.java:80)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at com.sun.identity.setup.AMSetupFilter.doFilter(AMSetupFilter.java:111)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at org.forgerock.openam.audit.context.AuditContextFilter.doFilter(AuditContextFilter.java:46)
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
      	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
      	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
      	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:503)
      	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
      	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
      	at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
      	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
      	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
      	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1070)
      	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
      	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:314)
      	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
      	at java.lang.Thread.run(Thread.java:745)
      Caused by: com.sun.identity.policy.PolicyException: AMIdentitySubject - can not check membership for user uid=george,ou=people,dc=openam,dc=forgerock,dc=org and subject id=policyg,ou=group,dc=openam,dc=forgerock,dc=org
      Identity george of type user not found.
      Identity george of type user not found.
      	at com.sun.identity.policy.plugins.AMIdentitySubject.isMember(AMIdentitySubject.java:427)
      	at com.sun.identity.entitlement.opensso.PolicySubject.evaluate(PolicySubject.java:220)
      	... 131 more
      

        Attachments

          Issue Links

            Activity

              People

              sachiko Sachiko Wallace
              andrew.dunn Andrew Dunn [X] (Inactive)
              Votes:
              1 Vote for this issue
              Watchers:
              5 Start watching this issue

                Dates

                Created:
                Updated:
                Resolved: