Infinite Number Of Requests To /opensso/sessionservice on OpenSSO and Agent is seeing many Session.processSessionResponseException: exception received from server:Application token passed in, is invalid.token (Doc ID 1902360.1)

Last updated on MARCH 08, 2017

Applies to:

Oracle OpenSSO - Version 8.0.2 and later
Information in this document applies to any platform.

Symptoms

Customer seeing looping of invalid sessions between the OpenSSO Servers

 

Tomcat J2EE 3.0-01 Agent logs are showing this error:

Session.processSessionResponseException: exception received from server:Application token
passed in, is invalid.token:AQIC5wM2LY4SfczHjIwpRjn20L98/gzIjVat/LTqEEjDJio=@AAJTSQACMDQ
AAlMxAAIwMg==#

 

 

as seen here:

amNaming:05/09/2014 07:10:54:122 PM GMT+00:00: Thread[http-7070-2,5,main]
SiteID http://celvpint6009.us.oracle.com:80/opensso/sessionservice is UP.
PLLClient:05/09/2014 07:10:54:122 PM GMT+00:00: Thread[http-7070-2,5,main]
sending cookies: null=AQIC5wM2LY4SfczHjIwpRjn20L98/gzIjVat/LTqEEjDJio=@AAJTSQACMDQAAlMxAA
IwMg==#;amlbcookie=02
amSession:05/09/2014 07:10:54:302 PM GMT+00:00: Thread[http-7070-2,5,main]
Session.processSessionResponseException: exception received from server:Application token
passed in, is invalid.token:AQIC5wM2LY4SfczHjIwpRjn20L98/gzIjVat/LTqEEjDJio=@AAJTSQACMDQ
AAlMxAAIwMg==#
amSession:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]
SessionID.getComingFromAuth():comingFromAuth:true
amSession:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]
Session.getLBCookie()lbCookieName is:amlbcookie
amNaming:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]
WebtopNaming.getLBCookieValue(): lbCookieValuefor 02 is 02
amNaming:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]
In SiteMonitor.getAvailableSites()
amNaming:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]
availableSiteList : [04]
amNaming:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]
In SiteMonitor.isAvailable()
amNaming:05/09/2014 07:10:54:303 PM GMT+00:00: Thread[http-7070-2,5,main]

 

 

On the OpenSSO Server we are seeing these:

 

localhost_access.log
====================

192.168.0.2 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 401
192.168.0.4 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 401
192.168.0.6 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 400
10.218.20.59 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 443
10.216.20.28 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 400
10.218.20.59 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 443
192.168.0.6 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 400
10.216.20.28 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 400
192.168.0.4 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 401
192.168.0.6 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 400
10.218.20.59 - - [26/Mar/2014:09:06:06 -0500] "POST /opensso/sessionservice HTTP/1.1" 200 443


Session.log
===========

###SUSTAINING: sessionServerID : 05
amSession:03/26/2014 09:06:06:724 AM CDT: Thread[http-10.216.23.99-2223-3,5,main]
session.Refresh Removed SID:AQIC6wM2LY6SfcyMoPk3hQpPzgY0WdIPQOcYa6W_mhOXyS2.*AAJSSRACMDUABlMxAAIwNw..*
amSSOProvider:03/26/2014 09:06:06:724 AM CDT: Thread[http-10.216.23.99-2223-3,5,main]
SSOProviderImpl.createSSOToken(tokenId, boolean)could not create SSOTOken for token ID AQIC6wM2LY6SfcyMoPk3hQpPzgY0WdIPQOcYa6W_mhOXyS2.*AA
JSSRACMDUABlMxAAIwNw..*
com.iplanet.dpro.session.SessionException: Invalid session ID.AQIC6wM2LY6SfcyMoPk3hQpPzgY0WdIPQOcYa6W_mhOXyS2.*AAJSSRACMDUABlMxAAIwNw..*
at com.iplanet.dpro.session.Session.refresh(Session.java:1418)
at com.iplanet.dpro.session.Session.getSession(Session.java:1061)
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:176)
at com.iplanet.sso.providers.dpro.SSOProviderImpl.createSSOToken(SSOProviderImpl.java:200)
at com.iplanet.sso.SSOTokenManager.createSSOToken(SSOTokenManager.java:304)
at com.sun.identity.session.util.RestrictedTokenContext.unmarshal(RestrictedTokenContext.java:121)
at com.iplanet.dpro.session.service.SessionRequestHandler.processRequest(SessionRequestHandler.java:102)
at com.iplanet.dpro.session.service.SessionRequestHandler.process(SessionRequestHandler.java:81)
at com.iplanet.services.comm.server.PLLRequestServlet.handleRequest(PLLRequestServlet.java:180)
at com.iplanet.services.comm.server.PLLRequestServlet.doPost(PLLRequestServlet.java:134)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at com.sun.identity.setup.AMSetupFilter.doFilter(AMSetupFilter.java:113)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:615)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)
at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)
at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
at java.lang.Thread.run(Thread.java:662)
amSession:03/26/2014 09:06:06:725 AM CDT: Thread[http-10.216.23.99-2223-3,5,main]
WARNING: SessionRequestHandler.processRequest:app token invalid, sending Session response with Exception
amSession:03/26/2014 09:06:06:731 AM CDT: Thread[http-10.216.23.99-2223-10,5,main]
###SUSTAINING: secondaryServerIDs : [06]
amSession:03/26/2014 09:06:06:731 AM CDT: Thread[http-10.216.23.99-2223-10,5,main]
###SUSTAINING: sessionServerID : 05
amSession:03/26/2014 09:06:06:731 AM CDT: Thread[http-10.216.23.99-2223-10,5,main]
session.Refresh Removed SID:AQIC6wM2LY6SfcyMoPk3hQpPzgY0WdIPQOcYa6W_mhOXyS2.*AAJSSRACMDUABlMxAAIwNw..*


CoreSystem.log
===============

amComm:03/26/2014 09:06:06:724 AM CDT: Thread[http-10.216.23.99-2223-3,5,main]
Received RequestSet XML :
<?xml version="1.0" encoding="UTF-8" standalone="yes"?>
<RequestSet vers="1.0" svcid="session" reqid="2518399">
<Request><![CDATA[<SessionRequest vers="1.0" reqid="1903" requester="dG9rZW46QVFJQzV3TTJMWTRTZmN5TG9QazJoUXBQWmdZMFdkSVBRT2NZYTZXX21oT1h5U
zQuKkFBSlRTUUFDTURVQUFsTXhBQUl3TXcuLio=">
<DestroySession>
<SessionID>AQIC6wM2LY6SfcyMoPk3hQpPzgY0WdIPQOcYa6W_mhOXyS2.*AAJSSRACMDUABlMxAAIwNw..*</SessionID>
<DestroySessionID>AQIC6wM2LY6SfcyMoPk3hQpPzgY0WdIPQOcYa6W_mhOXyS2.*AAJSSRACMDUABlMxAAIwNw..*</DestroySessionID>
</DestroySession>
</SessionRequest>]]></Request>
</RequestSet>
amNaming:03/26/2014 09:06:06:724 AM CDT: Thread[http-10.216.23.99-2223-3,5,main]
###SUSTAINING serverID is : 05
amNaming:03/26/2014 09:06:06:724 AM CDT: Thread[http-10.216.23.99-2223-3,5,main]
###SUSTAINING namingTable is : {iplanet-am-platform-site-id-list=01|05|06,04|05|06,02|05|06,05,06,03|05|06, iplanet-am-naming-policy-url=%



Cause

Sign In with your My Oracle Support account

Don't have a My Oracle Support account? Click to get started

My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms