Is SP expiring user session prematurely?

Wed Mar 20 13:08:49 EDT 2013

> From: cantor.2 at osu.edu
> Date: Wed, 20 Mar 2013 16:58:23 +0000

> The session is expired whenever it's expired but that won't matter much if nobody tries to use it.
> 

Following is what we are seeing

- Session created at 11:46
- User is actively performing operations in the application
- Shib logs show that the session is expired at 11:54

Following are excerpts of the logs (PS - SP resides in EST while the IdP is GMT)

2013-03-20 07:46:15 DEBUG XMLTooling.StorageService [32]: inserted record (session) in context (_83f7a6aea4ce297c6a776f9f9a7c8430) with expiration (1363783575)
2013-03-20 07:46:15 DEBUG XMLTooling.StorageService [32]: updated record (ABCDEF) in context (NameID) with expiration (1363780164)
2013-03-20 07:46:15 DEBUG XMLTooling.StorageService [32]: inserted record (id-0JZ1KSPVnkNuIr8DpKGFhqFJQRg-) in context (_83f7a6aea4ce297c6a776f9f9a7c8430) with expiration (1363783575)
2013-03-20 07:46:15 INFO Shibboleth.SessionCache [32]: new session created: ID (_12345) IdP (IdP) Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address (1.1.1.1)
2013-03-20 07:46:15 DEBUG Shibboleth.SSO.SAML2 [32]: ACS returning via redirect to: https://myhost.com/myapp/index.html
2013-03-20 07:46:15 DEBUG Shibboleth.Listener [32]: dispatching message (find::StorageService::SessionCache)
2013-03-20 07:46:15 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783575)
2013-03-20 07:46:17 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:17 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783577)
2013-03-20 07:46:20 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:20 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783580)
2013-03-20 07:46:20 DEBUG Shibboleth.Listener [34]: dispatching message (find::StorageService::SessionCache)
2013-03-20 07:46:20 DEBUG XMLTooling.StorageService [34]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783580)
2013-03-20 07:46:20 DEBUG Shibboleth.Listener [30]: dispatching message (find::StorageService::SessionCache)
2013-03-20 07:46:20 DEBUG XMLTooling.StorageService [30]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783580)
2013-03-20 07:46:20 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:20 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783580)
2013-03-20 07:46:20 DEBUG Shibboleth.Listener [21]: dispatching message (find::StorageService::SessionCache)
2013-03-20 07:46:20 DEBUG XMLTooling.StorageService [21]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783580)
2013-03-20 07:46:20 DEBUG Shibboleth.Listener [31]: dispatching message (find::StorageService::SessionCache)
2013-03-20 07:46:20 DEBUG XMLTooling.StorageService [31]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783580)
2013-03-20 07:46:21 DEBUG Shibboleth.Listener [34]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:21 DEBUG XMLTooling.StorageService [34]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783581)
2013-03-20 07:46:21 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:21 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783581)
2013-03-20 07:46:22 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:22 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783582)
2013-03-20 07:46:22 DEBUG Shibboleth.Listener [34]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:22 DEBUG XMLTooling.StorageService [34]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783582)
2013-03-20 07:46:22 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:22 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783582)
2013-03-20 07:46:24 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:24 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783584)
2013-03-20 07:46:24 DEBUG Shibboleth.Listener [32]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:24 DEBUG XMLTooling.StorageService [32]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783584)
2013-03-20 07:46:24 DEBUG Shibboleth.Listener [30]: dispatching message (touch::StorageService::SessionCache)
2013-03-20 07:46:24 DEBUG XMLTooling.StorageService [30]: updated expiration of valid records in context (_83f7a6aea4ce297c6a776f9f9a7c8430) to (1363783584)
2013-03-20 07:46:26 DEBUG Shibboleth.Listener [30]: dispatching message (touch::StorageService::SessionCache)

 		 	   		  
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://shibboleth.net/pipermail/users/attachments/20130320/b4e1a978/attachment.html