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

Restricted tokens fails randomly and causes looping

    Details

    • Type: Bug
    • Status: Closed
    • Priority: Major
    • Resolution: Cannot Reproduce
    • Affects Version/s: 13.0.0, 13.5.0
    • Fix Version/s: None
    • Component/s: cdsso, j2ee agents
    • Labels:
    • Environment:
    • Support Ticket IDs:

      Description

      Steps to reproduce.

      1. Setup CDSSO and anti-cookie hijack mode as per:
      https://backstage.forgerock.com/docs/openam/13.5/admin-guide#enable-cdsso-jee-agent
      In addition:

      • 'Global->Session->DN Restriction Only Enabled' set to enabled.
      • 'Authentication->Core->XUI Interface' set to disabled.

      2. Configure two 3.5.1 J2EE Agents, app1 and app2.

      3. Login to app1 then login to app2, or vice-versa

      4. If it works, close browser session and try again. It's somewhat random, but after a handful of tries it should be possible to see the browser get into a loop between the Agent and OpenAM.

      Note: swapping the 13.5.0 OpenAM for 11.0.3 prevents the error.

      AM Session Log:

      amSession:01/30/2017 05:08:32:188 PM GMT: Thread[http-bio-8080-exec-1,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1027]
      Session Cache cleanup is set to true
      amSession:01/30/2017 05:08:32:206 PM GMT: Thread[http-bio-8080-exec-8,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1042]
      com.iplanet.dpro.session.Session@66fb92da: LocalOperations selected.
      amSession:01/30/2017 05:08:32:206 PM GMT: Thread[http-bio-8080-exec-8,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1042]
      Local fetch SessionInfo for AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
      Reset: true
      amSession:01/30/2017 05:08:32:207 PM GMT: Thread[http-bio-8080-exec-8,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1042]
      session.Refresh Removed SID:AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
      amSession:01/30/2017 05:08:32:207 PM GMT: Thread[http-bio-8080-exec-8,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1042]
      processSessionRequest caught exception: Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzO
      TczMTcx*
      com.iplanet.dpro.session.SessionException: Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMj
      AzOTczMTcx*
              at com.iplanet.dpro.session.service.SessionService.resolveToken(SessionService.java:611)
              at com.iplanet.dpro.session.service.SessionService.getSessionInfo(SessionService.java:845)
              at com.iplanet.dpro.session.service.SessionRequestHandler.processSessionRequest(SessionRequestHandler.java:424)
              at com.iplanet.dpro.session.service.SessionRequestHandler.access$000(SessionRequestHandler.java:74)
              at com.iplanet.dpro.session.service.SessionRequestHandler$1.run(SessionRequestHandler.java:192)
              at com.sun.identity.session.util.RestrictedTokenContext.doUsing(RestrictedTokenContext.java:81)
              at com.iplanet.dpro.session.service.SessionRequestHandler.processRequest(SessionRequestHandler.java:189)
              at com.iplanet.dpro.session.service.SessionRequestHandler.process(SessionRequestHandler.java:132)
              at com.iplanet.services.comm.server.PLLRequestServlet.handleRequest(PLLRequestServlet.java:202)
              at com.iplanet.services.comm.server.PLLRequestServlet.doPost(PLLRequestServlet.java:140)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
              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.validation.ResponseValidationFilter.doFilter(ResponseValidationFilter.java:44)
              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:51)
              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:1145)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at java.lang.Thread.run(Thread.java:745)
      
      amSession:01/30/2017 05:08:32:224 PM GMT: Thread[http-bio-8080-exec-4,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1045]
      DNOrIPAddressListTokenRestriction.isSatisfied(): context is instance of SSOToken
      amSession:01/30/2017 05:08:32:243 PM GMT: Thread[http-bio-8080-exec-9,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1048]
      DNOrIPAddressListTokenRestriction.isSatisfied(): context is instance of SSOToken
      amSession:01/30/2017 05:08:40:750 PM GMT: Thread[http-bio-8080-exec-1,5,main]: TransactionId[9833658b-b93a-4ed5-91a0-78ff441c02e8-1053]
      SessionID(HttpServletRequest) : is forward = null
      

      Agent log:

      PLLClient:01/30/2017 05:08:32:852 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      sending cookies: null=AQIC5wM2LY4Sfcy8vdiTIjxRXxVLSX7F80N7GNPiYtO_fRk.*AAJTSQACMDIAAlMxAAIwMQACU0sAEjY3ODA0MzkyMjI5NTU4MTk4MQ..*;amlbcookie=01
      amFilter:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SSOTaskHandler: caching SSO Token for user id=demo,ou=user,o=openam
      amSession:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Remote fetch SessionInfo for AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
      Reset: true
      amSession:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SessionID.getComingFromAuth():comingFromAuth:false
      amSession:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.createContext():, setting context to  application SSO token
      amSession:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.getLBCookie()lbCookieName is:amlbcookie
      amNaming:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      WebtopNaming.getLBCookieValue(): lbCookieValuefor 01 is 01
      amNaming:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.getAvailableSites()
      amNaming:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      availableSiteList : [02]
      amNaming:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.isAvailable()
      amNaming:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SiteID http://ha.example.com:80/openam/sessionservice is UP.
      PLLClient:01/30/2017 05:08:32:856 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      sending cookies: null=AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*;amlbcookie=01
      amSession:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.processSessionResponseException: exception received from server:Application token passed in, is invalid.token:AQIC5wM2LY4SfcwsICuDPARrQCUfiJMgxjEb-p3j1_wrt2c.*AAJTSQACMDIAAlNLABMxOTAwOTU3NzAyMDQ4ODY4NTI1AAJTMQACMDE.*
      amSession:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.processSessionResponseException: AppTokenInvalid = TRUE
      amSession:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.processSessionResponseException: Destorying AppToken
      amSecurity:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      **********************************************
      amSecurity:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AdminTokenAction:invalid called
      amSession:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      WARNING: Session.processSessionResponseException processSessionResponseException: server responded with app token invalid error,refetching the app sso token
      amSecurity:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AdminTokenAction::run Unable to get SSOToken  from serverconfig.xml
      amAuthContext:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AuthContext.login : runLogin against http://ha.example.com:80/openam/authservice
      amAuthContext:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      in setLocalFlag(), url : http://ha.example.com:80
      amAuthContext:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AuthContext.localAuthServiceID : null
      amAuthContext:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Not including req/res false
      amAuthContext:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Service URL : http://ha.example.com:80/openam/authservice
      amNaming:01/30/2017 05:08:32:860 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.getAvailableSites()
      amNaming:01/30/2017 05:08:32:861 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      availableSiteList : [02]
      amNaming:01/30/2017 05:08:32:861 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.isAvailable()
      amNaming:01/30/2017 05:08:32:861 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SiteID http://ha.example.com:80/openam/authservice is UP.
      PLLClient:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      header in parseCookies(): {null=[HTTP/1.1 200 OK], Date=[Mon, 30 Jan 2017 17:08:32 GMT], Content-Length=[611], Set-Cookie=[amlbcookie=01; Path=/, JSESSIONID=285B3EEE5EEFC0CD2195555ECF14C478; Path=/openam/; HttpOnly], Server=[Apache-Coyote/1.1]}
      PLLClient:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      cookie: amlbcookie=01; Path=/
      PLLClient:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      cookie: JSESSIONID=285B3EEE5EEFC0CD2195555ECF14C478; Path=/openam/; HttpOnly
      amAuthContext:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      useNewStyleRemoteAuthentication : true
      amAuthContext:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      useOldStyleRemoteAuthentication : false
      amAuthContext:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      receivedDocument : [#document: null]
      amAuthContext:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      loginException : null
      amAuthXMLUtils:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      **********************************************
      amAuthXMLUtils:01/30/2017 05:08:32:868 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Callbacks length is : 2
      amAuthXMLUtils:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Value is : null
      amAuthXMLUtils:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Callbacks length is : 2
      amAuthXMLUtils:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Value is : null
      amAuthContext:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      submitRequirements with Callbacks : [Ljavax.security.auth.callback.Callback;@1bb8b38d
      amAuthContext:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Service URL : http://ha.example.com:80/openam/authservice
      amNaming:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.getAvailableSites()
      amNaming:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      availableSiteList : [02]
      amNaming:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.isAvailable()
      amNaming:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SiteID http://ha.example.com:80/openam/authservice is UP.
      PLLClient:01/30/2017 05:08:32:869 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      sending cookies: JSESSIONID=285B3EEE5EEFC0CD2195555ECF14C478;amlbcookie=01
      PLLClient:01/30/2017 05:08:32:886 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      header in parseCookies(): {null=[HTTP/1.1 200 OK], Date=[Mon, 30 Jan 2017 17:08:32 GMT], Content-Length=[2001], Server=[Apache-Coyote/1.1]}
      amAuthContext:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      LoginStatus : success
      amSession:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Remote fetch SessionInfo for AQIC5wM2LY4Sfcwve7td-ZOh2ZsLLdbv1_QifrKn2tq4iOo.*AAJTSQACMDIAAlNLABQtNTk2MTYxMTgwMDgyODM2NzEwMAACUzEAAjAx*
      Reset: true
      amNaming:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      WebtopNaming : SecondarySites for 01 is null
      amSession:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SessionID.getComingFromAuth():comingFromAuth:true
      amSession:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.getLBCookie()lbCookieName is:amlbcookie
      amNaming:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      WebtopNaming.getLBCookieValue(): lbCookieValuefor 01 is 01
      amNaming:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.getAvailableSites()
      amNaming:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      availableSiteList : [02]
      amNaming:01/30/2017 05:08:32:887 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.isAvailable()
      amNaming:01/30/2017 05:08:32:888 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SiteID http://ha.example.com:80/openam/sessionservice is UP.
      PLLClient:01/30/2017 05:08:32:888 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      sending cookies: null=AQIC5wM2LY4Sfcwve7td-ZOh2ZsLLdbv1_QifrKn2tq4iOo.*AAJTSQACMDIAAlNLABQtNTk2MTYxMTgwMDgyODM2NzEwMAACUzEAAjAx*;amlbcookie=01
      amSession:01/30/2017 05:08:32:892 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In parse session com.iplanet.dpro.session.share.SessionInfo@7b13fc32
      amSession:01/30/2017 05:08:32:892 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.isPollingEnabled is false
      amSession:01/30/2017 05:08:32:892 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session Cache cleanup is set to true
      amSession:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.isPollingEnabled is false
      amSession:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session Cache cleanup is set to true
      amSession:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SessionID.getComingFromAuth():comingFromAuth:true
      amSession:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.getLBCookie()lbCookieName is:amlbcookie
      amNaming:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      WebtopNaming.getLBCookieValue(): lbCookieValuefor 01 is 01
      amNaming:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.getAvailableSites()
      amNaming:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      availableSiteList : [02]
      amNaming:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.isAvailable()
      amNaming:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SiteID http://ha.example.com:80/openam/sessionservice is UP.
      PLLClient:01/30/2017 05:08:32:893 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      sending cookies: null=AQIC5wM2LY4Sfcwve7td-ZOh2ZsLLdbv1_QifrKn2tq4iOo.*AAJTSQACMDIAAlNLABQtNTk2MTYxMTgwMDgyODM2NzEwMAACUzEAAjAx*;amlbcookie=01
      amAgentCore:01/30/2017 05:08:32:899 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      ClientSDKAppSSOProvider.getAppSSOToken: got SSO Token =com.iplanet.sso.providers.dpro.SSOTokenImpl@5d1275be
      amSession:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.processSessionResponseException: creating New AppToken TokenID = com.iplanet.sso.providers.dpro.SSOTokenImpl@5d1275be
      amSession:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.createContext():, setting context to  application SSO token
      amSession:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.getLBCookie()lbCookieName is:amlbcookie
      amNaming:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      WebtopNaming.getLBCookieValue(): lbCookieValuefor 01 is 01
      amNaming:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.getAvailableSites()
      amNaming:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      availableSiteList : [02]
      amNaming:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      In SiteMonitor.isAvailable()
      amNaming:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SiteID http://ha.example.com:80/openam/sessionservice is UP.
      PLLClient:01/30/2017 05:08:32:900 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      sending cookies: null=AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*;amlbcookie=01
      amSession:01/30/2017 05:08:32:905 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      Session.processSessionResponseException: exception received from server:AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx* Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
      amRemotePolicy:01/30/2017 05:08:32:905 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      **********************************************
      amRemotePolicy:01/30/2017 05:08:32:905 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      ResourceResultCache.ssoTokenChanged():for tokenID=*********
      amRemotePolicy:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      ResourceResultCache.ssoTokenChanged():removing cache results for tokenID=*********:serviceName=iPlanetAMWebAgentService:resource=http://app2.example.com:8180/agentsample/
      amRemotePolicy:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      ResourceResultCache. tokenID= ********* not found in Token Registry.
      amRemotePolicy:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      ResourceResultCache.ssoTokenChanged():removing cache results for tokenID=*********:serviceName=iPlanetAMWebAgentService:resource=http://app2.example.com:8180/agentsample/images/logo.png
      amFilter:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AmBaseSSOCache: removed expired sso cache entry for user: id=demo,ou=user,o=openam
      amFilter:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AmBaseSSOCache: cache size = 0
      amFilter:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      AmSSOCacheTokenListener: User id=demo,ou=user,o=openam Token Event: SSO_TOKEN_DESTROY
      amSession:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      session.Refresh Removed SID:AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
      amSSOProvider:01/30/2017 05:08:32:907 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      could not create SSOToken for token ID "AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*"
      com.iplanet.dpro.session.SessionException: AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx* Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
              at com.iplanet.dpro.session.Session.refresh(Session.java:1557)
              at com.iplanet.dpro.session.Session.getState(Session.java:779)
              at com.iplanet.dpro.session.Session.getSession(Session.java:1169)
              at com.iplanet.dpro.session.Session.getSession(Session.java:1133)
              at com.iplanet.dpro.session.Session.getSession(Session.java:1118)
              at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:237)
              at com.iplanet.sso.SSOTokenManager.createSSOToken(SSOTokenManager.java:329)
              at com.sun.identity.agents.common.SSOTokenValidator.validateInternal(SSOTokenValidator.java:231)
              at com.sun.identity.agents.common.SSOTokenValidator.validate(SSOTokenValidator.java:112)
              at com.sun.identity.agents.filter.AmBaseSSOCache.getSSOTokenForUserInternal(AmBaseSSOCache.java:162)
              at com.sun.identity.agents.filter.AmBaseSSOCache.addSSOCacheEntry(AmBaseSSOCache.java:79)
              at com.sun.identity.agents.filter.SSOTaskHandler.cacheSSOToken(SSOTaskHandler.java:201)
              at com.sun.identity.agents.filter.SSOTaskHandler.process(SSOTaskHandler.java:116)
              at com.sun.identity.agents.filter.AmFilter.processTaskHandlers(AmFilter.java:194)
              at com.sun.identity.agents.filter.AmFilter.isAccessAllowed(AmFilter.java:157)
              at com.sun.identity.agents.filter.AmAgentBaseFilter.doFilter(AmAgentBaseFilter.java:70)
              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:316)
              at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
              at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
              at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
              at java.lang.Thread.run(Thread.java:745)
      Caused by: com.iplanet.dpro.session.SessionException: AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx* Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
              at com.iplanet.dpro.session.Requests.getSessionResponseWithRetry(Requests.java:123)
              at com.iplanet.dpro.session.Requests.sendRequestWithRetry(Requests.java:87)
              at com.iplanet.dpro.session.operations.strategies.RemoteOperations.refresh(RemoteOperations.java:76)
              at com.iplanet.dpro.session.Session.doRefresh(Session.java:1570)
              at com.iplanet.dpro.session.Session.access$400(Session.java:118)
              at com.iplanet.dpro.session.Session$3.run(Session.java:1546)
              at com.sun.identity.session.util.RestrictedTokenContext.doUsing(RestrictedTokenContext.java:86)
              at com.iplanet.dpro.session.Session.refresh(Session.java:1543)
              ... 32 more
      Caused by: com.iplanet.dpro.session.SessionException: AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx* Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
              at com.iplanet.dpro.session.Session.processSessionResponseException(Session.java:1729)
              at com.iplanet.dpro.session.Requests.getSessionResponseWithRetry(Requests.java:114)
              ... 39 more
      Caused by: com.iplanet.dpro.session.SessionException: AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx* Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
              at com.iplanet.dpro.session.Session.processSessionResponseException(Session.java:1726)
              ... 40 more
      
      amFilter:01/30/2017 05:08:32:908 PM GMT: Thread[http-bio-8180-exec-3,5,main]
      SSOTokenValidator.validate(): Exception caught
      com.iplanet.sso.SSOException: AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx* Invalid session ID.AQIC5wM2LY4SfcwtSMHCcUrcYbImdSP93_KRxVeUw8CROaQ.*AAJTSQACMDIAAlMxAAIwMQACU0sAFC0yMzAyNzY4ODIxMjAzOTczMTcx*
              at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:249)
              at com.iplanet.sso.SSOTokenManager.createSSOToken(SSOTokenManager.java:329)
              at com.sun.identity.agents.common.SSOTokenValidator.validateInternal(SSOTokenValidator.java:231)
              at com.sun.identity.agents.common.SSOTokenValidator.validate(SSOTokenValidator.java:112)
              at com.sun.identity.agents.filter.AmBaseSSOCache.getSSOTokenForUserInternal(AmBaseSSOCache.java:162)
              at com.sun.identity.agents.filter.AmBaseSSOCache.addSSOCacheEntry(AmBaseSSOCache.java:79)
              at com.sun.identity.agents.filter.SSOTaskHandler.cacheSSOToken(SSOTaskHandler.java:201)
              at com.sun.identity.agents.filter.SSOTaskHandler.process(SSOTaskHandler.java:116)
              at com.sun.identity.agents.filter.AmFilter.processTaskHandlers(AmFilter.java:194)
              at com.sun.identity.agents.filter.AmFilter.isAccessAllowed(AmFilter.java:157)
              at com.sun.identity.agents.filter.AmAgentBaseFilter.doFilter(AmAgentBaseFilter.java:70)
              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)
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                andrew.dunn Andrew Dunn [X] (Inactive)
              • Votes:
                0 Vote for this issue
                Watchers:
                4 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: