Cookie SMSESSION - Session expired before timeout in Policy Server
Article ID: 191517
Updated On:
Products
Issue/Introduction
Running an API Gateway in an environment where Siteminder Agent produces SMSESSION cookies, one can see that the idle and max timeout of the session doesn't get honored as configured in the API Gateway.
To illustrate, when a SMSESSION cookie comes to an API Gateway Server protected resource, having an idle timeout of 5 min, after some time (around 60 minutes) the "Authenticate Against CA Single Sign-On assertion" returns code 4 which means that the session has expired.
The problem is that for the API Gateway, the session timeout is set to 8 hours and the idle timeout to 5 minutes. So the API Gateway curiously ends the session before the session timeout it has in its configuration.
Environment
API Gateway 9.4CR04;
Policy Server 12.7 on Windows 2016;
Policy Server JDK 1.8.0_202;
Cause
The problem is that the environment presents a mixture of Persistent and Non-Persistent realms across the browser journey. The first MYSESSION is created in the Persistent realm. The further MYSESSION cookies get updated on Non Persistent realms. As such, when the Agents ask to get the session update to the Policy Server, the Policy Server checks the value in the Session Store, even if the reached Realm is Non-Persistent. This is so as the MYSESSION sessionspec has a value by saying that the session is persistent.
Let's take a look at the full journey.
fiddler.saz :
The user <user1> logs in at IDP at Tue, 19 May 2020 08:02:37 GMT and gets its first MYSESSION cookie:
Line 101:
POST https://idp.example.com:20015/cred/login.fcc?TYPE=33554433&REALMOID=06-85544s544s-d44s-444s-5sss-2245d5s55d5&GUID&SMAUTHREASON=0&METHOD=GET&SMAGENTNAME=-SM-SeDSD454das564dd4e4sd44sd4455ed5d5s4d45e5e55s4cx11sas444s4s&SWATARGET=-SM-HTTP%3A%2F%2Fidp.example.com%3A20016%2Faffwebservices%2Fredirectjsp%2Fredirect.jsp%3FSPID%3Dmyspid%26ProtocolBinding%3Durn%3Aoasis%3Anames%3Atc%3ASAML%3A2.0%3Abindings%3AHTTP--POST%26SMPORTALURL%3Dhttp-%3A-%2F-%2Fidp.example.com%3A20016-%2Faffwebservices-%2Fpublic-%2Fsaml2sso%26SAMLTRANSACTIONID%3Dee7c9c18--60bda7cf--cefb212f--3a29b570--eb6d88a8--ccUSERPH=<name>&PASSWORD=xxasdasd%25&smquerydata=&smauthreason=0&smagentname=SeDSD454das564dd4e4sd44sd4455ed5d5s4d45e5e55s4cx11sas444s4s&USER=<name>%40SYSSEDE&postpreservationdata=&target=-SM-HTTP%253A%252F%252Fidp.example.com%253A20016%252Faffwebservices%252Fredirectjsp%252Fredirect.jsp%253FSPID%253Dmyspid%2526ProtocolBinding%253Durn%253Aoasis%253Anames%253Atc%253ASAML%253A2.0%253Abindings%253AHTTP--POST%2526SMPORTALURL%253Dhttp-%253A-%252F-%252Fidp.example.com-%253A20016-%252Faffwebservices-%252Fpublic-%252Fsaml2sso%2526SAMLTRANSACTIONID%253Dee7c9c18--60bda7cf--cefb212f--3a29b570--eb6d88a8--cc
HTTP/1.1 302 HTTP/1.1 302 Object Moved Server: Microsoft-IIS/7.5 MYOTHERSESSION=cmWv0F6RdzBg52LJr Date: Tue, 19 May 2020 08:02:34 GMT
Line 105:
POST https://sp.example.net/affwebservices/public/saml2assertionconsumerMYOTHERSESSION=ntmZUuz0w/fOIpfEteQ4qKPcCHFxmAkku2fbqwRJv3EeZTG5IZqZlSAMLResponse=PFJlc3BvbnNlIHhtbG5zPSJ1cm46b2FzaXM6bmFtZXM6dGM6U0FNTDoyLjA6cHJvdG9jb2wiIERl
HTTP/1.1 302 Moved Temporarily Date: Tue, 19 May 2020 08:02:37 GMT Server: Apache MYSESSION=Mb48J3Urd2guiSFJEO6QF/ne1PQLweGnsKCMzAquK1hclDcVaZQ4qfmsqjbPtlB
Line 107:
POST https://app.example.net/rest/SAMLMYOTHERSESSION=ntmZUuz0wMYSESSION=Mb48J3Urd2guiSFJEO6QFSAMLResponse=PFJlc3BvbnNlIHhtbG5zPSJ1cm46b2FzaXM6bmFtZXM6dGM6U0FNTDoyLjA6cHJvdG9jb2wiIERl
HTTP/1.1 302 Found Date: Tue, 19 May 2020 08:02:37 GMT
And later, the MYSESSION get renewed, even if the user session being isn't renewed in the Policy Servers since 08:02:37 (Browser time) 10:02:37 (Policy Server time):
Line 211:
GET https://app.example.net/rest/login/RefreshJwtMYOTHERSESSION=ntmZUuz0wMYSESSION=Mb48J3Urd2guiSFJEO6QF
HTTP/1.1 200 OK Date: Tue, 19 May 2020 08:06:07 GMT
MYSESSION=sVGLvgPnqH6ZBrsG4QCov0 [...] {"status":"ok","code":0,"message":"LoginJWT successfully retrieved.","content":{"result":"{\"expirationDate\":\"2020-05-19T08:11:07\"}"}}
Line 405:
GET https://app.example.net/rest/login/RefreshJwtMYOTHERSESSION=ntmZUuz0w/fOIpfEteQ4qKPcCHFxmAkku2fbqwRJv3EeZTG5IZqZlMYSESSION=5L2skVVITbvosHwHdVtfllpmBXhCmanpWHZc2FnYfDSx8c
HTTP/1.1 200 OK Date: Tue, 19 May 2020 08:59:07 GMT MYSESSION=LciE4ZSa5wtRp6vDSD1WCRPDj04ea6lHffeeaEECbVXfEvOV0ko3vZs2WTVNDCJbb [...]
{"status":"ok","code":0,"message":"LoginJWT successfully retrieved.","content":{"result":"{\"expirationDate\":\"2020-05-19T09:04:07\"}"}}
Line 409:
GET https://app.example.net/rest/login/RefreshJwtMYOTHERSESSION=ntmZUuz0w/fOIpfEteQ4qKPcCHFxmAkku2fbqwRJv3EeZTG5IZqZlMYSESSION=LciE4ZSa5wtRp6vDSD1WCRPDj04ea6lHffeeaEECbVXfEvOV0ko3vZs2WTVNDCJbb [...]
HTTP/1.1 200 OK Date: Tue, 19 May 2020 09:02:37 GMT MYSESSION=zNJK9B52YwhLR6eA9URM8VJmYpsmI0b33RWasGSe4oZ7g2gZ [...]
{"status":"ok","code":0,"message":"LoginJWT successfully retrieved.","content":{"result":"{\"expirationDate\":\"2020-05-19T09:07:37\"}"}}
Until the Agent requests to validate the session to the Policy Server an hour later:
Line 420:
GET https://app.example.net/rest/login/RefreshJwtMYOTHERSESSION=ntmZUuz0w/fOIpfEteQ4qKPcCHFxmAkku2fbqwRJv3EeZTG5IZqZl [...]MYSESSION=zNJK9B52YwhLR6eA9URM8VJmYpsmI0b3 [...]
HTTP/1.1 400 Bad Request Date: Tue, 19 May 2020 09:06:07 GMT
{"status":"error","code":400,"message":"ERROR in service JWT StatusCode = Unauthorized, Content = {\n\"status\":\"Unauthorized\",\n\"code\":\"401\",\n\"desc\":\"Invalid MYSESSION cookie.\"\nReason code: 4\nMessage:Session has expired.\n}","content":{}}
app.log :
The MYSESSION cookie gets refreshed:
2020-05-19T11:02:37.597+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | /rest/ | Start Method 2020-05-19T11:02:37.597+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | eyJ0eXAiOiJKV1QiLCJhbGciOiJFUzUxMiIsImtpZCI6InNpZ25hdHVyZWp3d [...] Authorization from request header. 2020-05-19T11:02:37.598+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | Validating JWT... 2020-05-19T11:02:37.598+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | JWT recived : eyJ0eXAiOiJKV1QiLCJhbGciOiJFUzUxMiIsImtpZCI6InNpZ25hdHVyZWp3d [...] 2020-05-19T11:02:37.608+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | Expiration time extracted : 1589879047. 2020-05-19T11:02:37.608+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | JWT succesfully validated. 2020-05-19T11:02:37.610+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | /rest/ | Routing to http://10.0.0.1/rest/login/RefreshJwt... 2020-05-19T11:02:37.611+0200 WARNING 2830 com.l7tech.common.http.prov.apache.components.HttpComponentsClient: Bad Authorization header presenteyJ0eXAiOiJKV1QiLCJhbGciOiJFUzUxMiIsImtpZCI6InNpZ25hdHVyZWp3d [...] 2020-05-19T11:02:37.736+0200 INFO 2830 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ce | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | Response:
Header: Access-Control-Expose-Headers:Set-Cookie, Access-Control-Max-Age:1728000, Cache-Control:no-cache, no-store, Content-Encoding:gzip, Content-Length:145, Content-Type:application/json;charset=utf-8, Date:Tue, 19 May 2020 09:02:37 GMT, Expires:-1, Pragma:no-cache, Set-Cookie:MYSESSION=zNJK9B52YwhLR6eA9URM8VJmYpsmI0b33RWasGSe4oZ7g2gZ+ [...] domain=.example.net; path=/; SameSite=None, mwall=user_account=vegBQDuO9EXtVU3+WIuI6uoAmWiFn/0rBugFd0jQMhChXXKhKmLNX6Z [...] domain=.example.net; path=/, securitysession=jwtSecurity=eyJ0eXAiOiJKV1QiLCJhbGciOiJFUzUxMiIsImtpZCI6InNpZ25h [...] domain=.example.net; path=/.
And then the Agent renews the Session by the Policy Server, which replies that Session has expired:
2020-05-19T11:06:07.621+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | Start Method 2020-05-19T11:06:07.621+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | Authorization from request header: eyJ0eXAiOiJKV1QiLCJhbGciOiJFUzUxMiIsImtpZCI [...] 2020-05-19T11:06:07.622+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | Validating JWT... 2020-05-19T11:06:07.622+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | JWT recived : eyJ0eXAiOiJKV1QiLCJhbGciOiJFUzUxMiIsImtpZCI6InNpZ [...] 2020-05-19T11:06:07.631+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | Expiration time extracted : 1589879257. 2020-05-19T11:06:07.631+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | JWT succesfully validated. 2020-05-19T11:06:07.633+0200 INFO 3214 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | AuthN: MYSESSION cookie zNJK9B52YwhLR6eA9URM8VJmYpsmI0b33RWasGSe4oZ7g2gZ+7ilvSx [...] 2020-05-19T11:06:07.640+0200 WARNING 3214 com.ca.siteminder.SiteMinderLowLevelAgent: Session Cookie expired! 2020-05-19T11:06:07.640+0200 WARNING 3214 com.l7tech.log.custom.apilog: -5: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | Invalid cookie detected. Reason code: 4, message:Session has expired. 2020-05-19T11:06:07.640+0200 WARNING 3214 com.l7tech.log.custom.apilog: -5: 0000017115e4c7f0-132ef | GWIP:10.0.0.100 | Refresh JWT | /oauth/v2/refresh/jwt* | End Method. APIGW HTTP response: 401 - Unauthorized. 2020-05-19T11:06:07.640+0200 SEVERE 3214 com.l7tech.server.SoapMessageProcessingServlet: RaiseErrorAssertion is stopping execution. 2020-05-19T11:06:07.641+0200 WARNING 3214 com.l7tech.external.assertions.siteminder.server.ServerSiteMinderAuthenticateAssertion: 10102: CA Single Sign-On Authenticate Against CA Single Sign-On assertion: Unable to authenticate user using SSO Token:zNJK9B52YwhLR6eA9URM8VJmYpsmI0b33RWasGSe4oZ7g2gZ+7ilvSx [...] 2020-05-19T11:06:07.643+0200 INFO 3302 com.l7tech.log.custom.apilog: -4: 0000017115e4c7f0-132ee | GWIP:10.0.0.100 | myspapplication.REST | /portalFI/v1/api/* | Response:
Header: Access-Control-Expose-Headers:Set-Cookie, Access-Control-Max-Age:1728000, Cache-Control:no-cache, no-store, Content-Encoding:gzip, Content-Length:201, Content-Type:application/json;charset=utf-8, Date:Tue, 19 May 2020 09:06:07 GMT, Expires:-1, Pragma:no-cache. Body: {"status":"error","code":400,"message":"ERROR in service JWT StatusCode = Unauthorized, Content = {\n\"status\":\"Unauthorized\",\n\"code\":\"401\",\n\"desc\":\"Invalid FMSession cookie.\"\nReason code: 4\nMessage:Session has expired.\n}","content":{}}.
But the Session hasn't expired, but rather the IdleTimeout has been reached from a long time ago:
smps.log:
[15216/15456][Tue May 19 2020 11:06:07][SmSessionServer.cpp:571][ERROR][sm-Server-06007] failed. Error code : 2
smtracedefault.log:
Policy Server creates the sessionspec for the MYSESSION on the Persistent Realm at 10:02:37:
"samlidp:idp" (06-erss44d44s5-1s55-ws44-dd4s-d1225444s55v) :
[05/19/2020][10:02:37.362][10:02:37][15216][17940][Sm_Auth_Message.cpp:4835][CSm_Auth_Message::SendReply][s21050/r49][samlidp:idp][][][][samlidp:idp][samlidp:idp][ldap][][][][][][][][][][][][][** Status: Authenticated. ][samlidp:idp_auth][][][cn=<name>,dc=example,dc=com][][][][][][06-erss44d44s5-1s55-ws44-dd4s-d1225444s55v][][][][]
and the Agent never comes back to the Policy Server to validate the MYSESSION sessionspec data until one hour after having first created the MYSESSION at 11:02:37:
[05/19/2020][11:02:37.584][11:02:37][15216][19340][SmMessage.cpp:557][CSmMessage::ParseAgentMessage][s23524/r4][agent][][][][][][][][][][][][][][][][][][/app/application][Receive request attribute 201, data size is 26][][][][][][][][][][][][][][] [05/19/2020][11:02:37.584][11:02:37][15216][19340][Sm_Az_Message.cpp:598][CSm_Az_Message::SendReply][s23524/r4][agent][][][][/app/application][application][][][][][][][][][][][][][][** Status: Protected. ][][][][][][][][][][][][][][]
and the validation of the cookie sessionspec is done against the Non-Persistent Realm:
"/app/application" (06-82fbddc4-5f61-404e-b679-24f749f30dc8)
[05/19/2020][11:06:07.560][11:06:07][15216][15456][SmMessage.cpp:557][CSmMessage::ParseAgentMessage][s23524/r10][agent][][][][][][][][][][][][][][][][][][/app/application][Receive request attribute 201, data size is 26][][][][][][][][][][][][][][] [05/19/2020][11:06:07.560][11:06:07][15216][15456][SmMessage.cpp:557][CSmMessage::ParseAgentMessage][s23524/r10][agent][][][][][][][][][][][][][][][][][][8aHhuj0rN4ViEkqismdYV
[...] Ze1Dt5Us1OKB][Receive request attribute 209, data size is 512][][][][][][][][][][][][][][]
But as the sessionspec as been created on a persistent realm, then the sessionspec data has "SessionPersistent" value set and as such, Policy Server looks in the Session Store to find it and read the
SessionMaxTimeout SessionIdleTimeout (1)(2)
values, and as the sessionspec data isn't being updated for more than an hour, then the idle timeout value triggers:
[05/19/2020][11:06:07.560][11:06:07][15216][15456][SmSSProvider.cpp:594][CSmSSProvider::GetSession][][][][][][][][][][][][][][][][][][][][][Enter function CSmSSProvider::GetSession][][][][][][][][][][][][][][] [05/19/2020][11:06:07.560][11:06:07][15216][15456][SmSSProvider.cpp:620][CSmSSProvider::GetSession][][][][][][][][][][][][][2][][][][][][][][Leave function CSmSSProvider::GetSession][][16][][][][][][][][][][][][] [05/19/2020][11:06:07.560][11:06:07][15216][15456][SmSessionServer.cpp:571][][][][][][][][][][][][][][][][][][][][][][LogMessage:ERROR:[sm-Server-06007] failed. Error code : 2][][][][][][][][][][][][][][] [05/19/2020][11:06:07.560][11:06:07][15216][15456][SmAuthSession.cpp:379][SmAuthSession][][][][][][][][][][][][][][][][][][][][][Idle timeout exceeded][][][][][][][][][][][][][][] [05/19/2020][11:06:07.560][11:06:07][15216][15456][Sm_Auth_Message.cpp:4835][CSm_Auth_Message::SendReply][s23524/r10][agent][][][][/app/application][application][][][][][][][][][][][][][][** Status: Not Validated. Session has expired][agent][][][][][][][][][06-55s5ddf4-5w5s-44s8-e556-224s55df4ffd4][][][Session has expired][]
pstore.xml:
realm "/app/application"
<Object Class="CA.SM::Realm" Xid="CA.SM::Realm@06-55s5ddf4-5w5s-44s8-e556-224s55df4ffd4"> <Property Name="CA.SM::Realm.Name"> <StringValue>/app/application</StringValue> </Property> <Property Name="CA.SM::Realm.ResourceFilter"> <StringValue>/app/application</StringValue> </Property> <Property Name="CA.SM::Realm.MaxTimeout"> <NumberValue>28800</NumberValue> </Property> <Property Name="CA.SM::Realm.IdleTimeout"> <NumberValue>300</NumberValue> <Property Name="CA.SM::Realm.SessionType"> <NumberValue>0</NumberValue>
Where 300 is 5 minutes and session type is non-persistent as per the value of "0".
realm "samlidp:idp"
<Object Class="CA.SM::Realm" Xid="CA.SM::Realm@06-erss44d44s5-1s55-ws44-dd4s-d1225444s55v">
<Property Name="CA.SM::Realm.Name"> <StringValue>samlidp:idp</StringValue> <Property Name="CA.SM::Realm.Desc"> <StringValue>Backing Object for Partnership Federation - do not edit</StringValue> <Property Name="CA.SM::Realm.MaxTimeout"> <NumberValue>28800</NumberValue> </Property> <Property Name="CA.SM::Realm.IdleTimeout"> <NumberValue>300</NumberValue> <Property Name="CA.SM::Realm.SessionType"> <NumberValue>1</NumberValue>
Where 300 is 5 minutes and session type is persistent as per value "1".
Resolution
Review the implementation and make all realms persistent or all non-persistent, but avoid having a mixture of persistent and non-persistent.
Additional Information
Feedback
