Shibboleth session are dropped after upgrading to version SP 2.5.4

Thu Jul 2 00:07:15 EDT 2015

Thanks Scott. Appreciate your response.

The incoming request has the shibsession cookie as you can see below.

*******
GET /zip_services/show HTTP/1.1
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:38.0)
Gecko/20100101 Firefox/38.0
Accept: text/html, */*
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip, deflate
X-Requested-With: XMLHttpRequest
Referer: https://awsqa2.pfoperations.com/pf/pfdomain/promotions/index
Cookie: __utma=169413937.2058668447.1435710020.1435719877.1435726863.4;
__utmz=169413937.1435710020.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
search_criteria=3600;
_shibsession_64656661756c7468747470733a2f2f6177737161322e70666f7065726174696f6e732e636f6d=_f8234ffd7cf313bd26405f8c50605112;
__utmb=169413937.12.10.1435726863; __utmc=169413937; __utmt=1
Connection: keep-alive
********

The response shows the redirection to IdP instead of getting the HTTP 200
OK. Also, the shibboleth expires the shibsession cookie.

********
HTTP/1.1 302 Found
Cache-Control: private,no-store,no-cache,max-age=0
Content-Type: text/html; charset=iso-8859-1
Date: Wed, 01 Jul 2015 05:14:42 GMT
Expires: Wed, 01 Jan 1997 12:00:00 GMT
Location: https://nnnnnnnnn.okta.com/app/template_saml_2_0/8ed6b25a9d60
----------------------
Set-Cookie:
_shibsession_64656661756c7468747470733a2f2f6177737161322e70666f7065726174696f6e732e636f6d=;
path=/; secure; HttpOnly; expires=Mon, 01 Jan 2001 00:00:00 GMT
---------------------
Content-Length: 856
Connection: keep-alive
********

I have turned on debug messages for shibboleth. It does not show any reason
why shibboleth is closing the session. The session got closed in 2 mins.

********
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [117]: inserted record
(id138583305896505261075050264) in context
(_d1d2bdac5515cdc5c16493ddfa809e4e) with expiration (1435811017)
2015-07-01 20:23:37 INFO Shibboleth.SessionCache [117]: new session
created: ID (_d1d2bdac5515cdc5c16493ddfa809e4e) IdP (
http://www.okta.com/ssssssssssss)
Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address ()
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [117]: deleted record
(de8322461f299d6809ee6e5d1cd57a5125d7429f10ed2cdd580faebf81cd148a) in
context (RelayState)
2015-07-01 20:23:37 DEBUG Shibboleth.SSO.SAML2 [117]: ACS returning via
redirect to: https://qa2.aaa.com/home
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [138]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [138]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [144]: dispatching message
(default::getHeaders::Application)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [144]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [144]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [135]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [135]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [99]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [99]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [110]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [110]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [84]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [84]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [140]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [140]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [48]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [48]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:37 DEBUG Shibboleth.Listener [136]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [136]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811017)
2015-07-01 20:23:38 DEBUG Shibboleth.Listener [143]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:23:38 DEBUG XMLTooling.StorageService [143]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811018)
2015-07-01 20:23:41 DEBUG Shibboleth.Listener [110]: dispatching message
(touch::StorageService::SessionCache)
2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [110]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811021)
2015-07-01 20:23:41 DEBUG Shibboleth.Listener [140]: dispatching message
(touch::StorageService::SessionCache)
2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [140]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811021)
2015-07-01 20:23:41 DEBUG Shibboleth.Listener [48]: dispatching message
(touch::StorageService::SessionCache)
2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [48]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811021)
2015-07-01 20:23:41 DEBUG Shibboleth.Listener [136]: dispatching message
(touch::StorageService::SessionCache)
2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [136]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811021)
2015-07-01 20:25:05 DEBUG Shibboleth.Listener [67]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:25:05 DEBUG XMLTooling.StorageService [67]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811105)
2015-07-01 20:25:05 DEBUG Shibboleth.Listener [141]: dispatching message
(find::StorageService::SessionCache)
2015-07-01 20:25:05 DEBUG XMLTooling.StorageService [141]: updated
expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e)
to (1435811105)
2015-07-01 20:25:05 DEBUG Shibboleth.Listener [141]: dispatching message
(remove::StorageService::SessionCache)
2015-07-01 20:25:05 INFO Shibboleth.SessionCache [141]: removed session
(_d1d2bdac5515cdc5c16493ddfa809e4e)
2015-07-01 20:25:05 DEBUG Shibboleth.Listener [141]: dispatching message
(default/Login::run::SAML2SI)
2015-07-01 20:25:05 DEBUG XMLTooling.StorageService [141]: inserted record
(ffe592c0772aab4e6851b80be26a363d98bdb2d360f794986103477c0d6cfa52) in
context (RelayState) with expiration (1435808105)
********

Also, I saw the following messages in the log file. I do not know if it is
useful for debugging.

*******
2015-07-01 20:23:37 DEBUG OpenSAML.SecurityPolicyRule.MessageFlow [117]:
evaluating message flow policy (replay checking on, expiration 60)
2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [117]: inserted record
(id138583305896505261075050264) in context (MessageFlow) with expiration
(1435807657)

2015-07-01 20:23:37 DEBUG Shibboleth.SSO.SAML2 [117]: extracting pushed
attributes...
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeExtractor.XML [117]: unable
to extract attributes, unknown XML object type: saml2p:Response
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeExtractor.XML [117]: skipping
unmapped NameID with format
(urn:oasis:names:tc:SAML:1.1:nameid-format:emailAddress)
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeExtractor.XML [117]: unable
to extract attributes, unknown XML object type: saml2:AuthnStatement
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]:
decoding SimpleAttribute (FirstName) from SAML 2 Attribute (FirstName) with
1 value(s)
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]:
decoding SimpleAttribute (LastName) from SAML 2 Attribute (LastName) with 1
value(s)
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]:
decoding SimpleAttribute (Email) from SAML 2 Attribute (Email) with 1
value(s)
2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]:
decoding SimpleAttribute (UserName) from SAML 2 Attribute (UserName) with 1
value(s)
**********

Sorry for the long message.

Thanks

Nara

On Wed, Jul 1, 2015 at 5:18 PM, Cantor, Scott <cantor.2 at osu.edu> wrote:

> On 7/1/15, 8:13 PM, "users on behalf of nr673 ." <
> users-bounces at shibboleth.net on behalf of nara.rama.us at gmail.com> wrote:
>
>
> >
> >But, we still see the shibsession expiry issue. Appreciate any feedbacks
> on this issue.
>
> If it's refusing to accept the session, the log(s) wlll tell you why. If
> it doesn't log anything, then it is not getting any session cookie to
> process, which is not anything the SP has any control over.
>
> There is/was no change in the software in any way related to this.
>
> -- Scott
>
> --
> To unsubscribe from this list send an email to
> users-unsubscribe at shibboleth.net
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20150701/5861dcfd/attachment.html>