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

PolicyRequestHandler throws Guice error for failed session read from CTS

    Details

    • Type: Bug
    • Status: Open
    • Priority: Minor
    • Resolution: Unresolved
    • Affects Version/s: 14.1.0, 14.1.1, 5.5.1, 6.0.0.2
    • Fix Version/s: None
    • Component/s: policy, session
    • Labels:
    • Rank:
      1|hzwdhj:

      Description

      Bug description

      When policy evaluation is done on a and if the appToken for some reason like having CTS
      slowness causing the apptoken to fail to be retrieved, the policy evaluation fail
      with some Guice ProvisionError.

      Entitlement:07/21/2018 10:09:27:204 AM SGT: Thread[default task-43,5,main]: TransactionId[946da963-590a-470e-afb4-51142b5d1bc4-301561]
      ERROR: SubjectUtils.createSubject
      com.iplanet.sso.SSOException: org.forgerock.openam.cts.exceptions.ReadFailedException:
      CTS: Failed to read Token: -8858327072291277850
              at com.iplanet.sso.providers.dpro.SSOTokenImpl.getPropertyInternal(SSOTokenImpl.java:369)
              at com.iplanet.sso.providers.dpro.SSOTokenImpl.getProperty(SSOTokenImpl.java:386)
              at com.sun.identity.entitlement.opensso.SubjectUtils.createSubject(SubjectUtils.java:59)
              at com.sun.identity.policy.remote.PolicyRequestHandler.getPolicyEvaluator(PolicyRequestHandler.java:733)
              at com.sun.identity.policy.remote.PolicyRequestHandler.processPolicyRequest(PolicyRequestHandler.java:443)
              at com.sun.identity.policy.remote.PolicyRequestHandler.processPolicyServiceRequest(PolicyRequestHandler.java:249)
              at com.sun.identity.policy.remote.PolicyRequestHandler.processRequest(PolicyRequestHandler.java:203)
              at com.sun.identity.policy.remote.PolicyRequestHandler.process(PolicyRequestHandler.java:140)
              at com.iplanet.services.comm.server.PLLRequestServlet.handleRequest(PLLRequestServlet.java:202)
              at com.iplanet.services.comm.server.PLLRequestServlet.doPost(PLLRequestServlet.java:140)
      ....
      Caused by: com.iplanet.dpro.session.SessionUnavailableException: org.forgerock.openam.cts.exceptions.ReadFailedException:
      CTS: Failed to read Token: -8858327072291277850
              at org.forgerock.openam.session.service.SessionAccessManager.getInternalSession(SessionAccessManager.java:90)
              at org.forgerock.openam.session.cts.InternalSessionWrapper.getSession(InternalSessionWrapper.java:319)
              at org.forgerock.openam.session.cts.InternalSessionWrapper.getProperty(InternalSessionWrapper.java:278)
              at com.iplanet.sso.providers.dpro.SSOTokenImpl.getPropertyInternal(SSOTokenImpl.java:366)
              ... 55 more
      Caused by: org.forgerock.openam.session.service.access.persistence.SessionPersistenceException: org.forgerock.openam.cts.exceptions.ReadFailedException:
      CTS: Failed to read Token: -8858327072291277850
              at org.forgerock.openam.session.service.access.persistence.SessionPersistenceStore.recoverSession(SessionPersistenceStore.java:152)
              at org.forgerock.openam.session.service.access.persistence.InternalSessionPersistenceStore.getBySessionID(InternalSessionPersistenceStore.java:40)
              at org.forgerock.openam.session.service.access.persistence.InternalSessionStoreChain$ChainIterator.getBySessionID(InternalSessionStoreChain.java:54)
              at org.forgerock.openam.session.service.access.persistence.SessionPersistenceManagerStep.getBySessionID(SessionPersistenceManagerStep.java:36)
      ...
      Caused by: org.forgerock.openam.cts.exceptions.CoreTokenException:
      CTS:
      CTS: Operation failed:
      Result Code: Client-Side Timeout
      Diagnostic Message: The request has failed because no response was received from the server within the 10000 ms timeout
      Matched DN:
              at org.forgerock.openam.cts.impl.queue.AsyncResultHandler.getResults(AsyncResultHandler.java:95)
              at org.forgerock.o...
      

      Now the above cause is not the issue, the issue is this resulting error later

      amPolicy:07/21/2018 10:09:27:230 AM SGT: Thread[default task-43,5,main]: TransactionId[946da963-590a-470e-afb4-51142b5d1bc4-301561]
      ERROR: PolicyRequestHandler: Evaluation error
      com.google.inject.ProvisionException: Guice provision errors:
      
      1) null returned by binding at org.forgerock.openam.entitlement.service.ApplicationServiceFactory.create()
       but parameter 0 of org.forgerock.openam.entitlement.service.ApplicationServiceImpl.<init>() is not @Nullable
        while locating javax.security.auth.Subject annotated with @com.google.inject.assistedinject.Assisted(value=)
          for parameter 0 at org.forgerock.openam.entitlement.service.ApplicationServiceImpl.<init>(Unknown Source)
        while locating org.forgerock.openam.entitlement.service.ApplicationService annotated with interface com.google.inject.assistedinject.Assisted
      
      1 error
              at com.google.inject.internal.InjectorImpl$4.get(InjectorImpl.java:987)
              at com.google.inject.assistedinject.FactoryProvider2.invoke(FactoryProvider2.java:632)
              at com.sun.proxy.$Proxy34.create(Unknown Source)
              at org.forgerock.openam.entitlement.utils.EntitlementUtils.getApplicationService(EntitlementUtils.java:505)
              at com.sun.identity.policy.remote.PolicyRequestHandler.getPolicyEvaluator(PolicyRequestHandler.java:734)
              at com.sun.identity.policy.remote.PolicyRequestHandler.processPolicyRequest(PolicyRequestHandler.java:443)
      

      Impact: Minor (as the main issue will be the session failure). However the exception may cause be better handled.

      How to reproduce the issue

      The actual stress test when there is CTS failures happening shown this issue. However this may prove a bit difficult to reproduce this means stress test with webagent on a AM CTS that may fail.

      This may be hard to reproduce as it means the need to cause CTS failures. However
      It is know that the call at

      org.forgerock.openam.entitlement.utils.EntitlementUtils.getApplicationService(EntitlementUtils.java:505)
      

      cannot take null for session and this happens if the SSOToken happens. Once can delibrately cause fault injection to see this. It is obviously that
      com.sun.identity.entitlement.opensso.SubjectUtils.createSubject(SubjectUtils.java:59)
      may return NULL if there is issue getting the subject.

      Expected behaviour
      NPE or Guice error should not appear in the PLL request or the logs. However
      it could be good to log this properly when the appToken returned is NULL
      
      Current behaviour
      Guice exception seen on logs
      

      Work around

      As long as tany code can recover from thiis there is no issue.

      Code analysis

      In PolicyRequestHandler.java

      721            final Subject appSubject = SubjectUtils.createSubject(appToken);
      722            final Application application = getApplicationService(appSubject, realm).getApplication(applicationName);
      

      appSubject is null (due to whatever reason) so
      getApplicationService(null,...) will throw Guice issue. Checking
      is appSubject is valid first should avoid the issue and maybe treat this
      as the same error as when "application == null"

        Attachments

          Activity

            People

            • Assignee:
              Unassigned
              Reporter:
              chee-weng.chea C-Weng C
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated: