<div dir="ltr">One more thing....When session is removed, the shibd.log file shows the following messages.<div><br></div><div>







<p class="">2015-07-01 22:16:19 INFO Shibboleth.SessionCache [7]: new session created: ID (_7020e2ae4d02020eee9eddd240d7da8b) IdP (<a href="http://www.okta.com/nnnnnnnnnnnnnnnnnn">http://www.okta.com/nnnnnnnnnnnnnnnnnn</a>) Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address (nn.nn.nn.nn)</p>
<p class="">2015-07-01 22:17:22 INFO Shibboleth.SessionCache [29]: removed session (_7020e2ae4d02020eee9eddd240d7da8b)</p>
<p class="">2015-07-01 22:17:23 INFO Shibboleth.SessionCache [15]: new session created: ID (_5f925bc72f835e70b77c70eb977b8463) IdP (<a href="http://www.okta.com/nnnnnnnnnnnnnnnnnn">http://www.okta.com/nnnnnnnnnnnnnnnnnn</a>) Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address (nn.nn.nn.nn)</p>
<p class="">2015-07-01 22:17:49 INFO Shibboleth.Listener [12]: detected socket closure, shutting down worker thread</p>
<p class="">2015-07-01 22:17:51 INFO Shibboleth.Listener [32]: detected socket closure, shutting down worker thread</p>
<p class="">2015-07-01 22:17:52 INFO Shibboleth.Listener [10]: detected socket closure, shutting down worker thread</p>
<p class="">2015-07-01 22:17:54 INFO Shibboleth.Listener [27]: detected socket closure, shutting down worker thread</p>
<p class="">2015-07-01 22:17:55 INFO Shibboleth.Listener [5]: detected socket closure, shutting down worker thread</p>
<p class="">2015-07-01 22:17:56 INFO Shibboleth.Listener [29]: detected socket closure, shutting down worker thread</p><p class="">Thanks</p><p class="">Nara</p><p class=""><br></p></div></div><div class="gmail_extra"><br><div class="gmail_quote">On Wed, Jul 1, 2015 at 9:07 PM, nr673 . <span dir="ltr"><<a href="mailto:nara.rama.us@gmail.com" target="_blank">nara.rama.us@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div dir="ltr">Thanks Scott. Appreciate your response.<div><br></div><div>The incoming request has the shibsession cookie as you can see below.</div><div><br></div><div>*******</div><div><span class=""><div>GET /zip_services/show HTTP/1.1</div><div>User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.9; rv:38.0) Gecko/20100101 Firefox/38.0<br></div><div>Accept: text/html, */*</div><div>Accept-Language: en-US,en;q=0.5</div><div>Accept-Encoding: gzip, deflate</div><div>X-Requested-With: XMLHttpRequest</div></span><div>Referer: <a href="https://awsqa2.pfoperations.com/pf/pfdomain/promotions/index" target="_blank">https://awsqa2.pfoperations.com/pf/pfdomain/promotions/index</a></div><div>Cookie: __utma=169413937.<a href="tel:2058668447" value="+12058668447" target="_blank">2058668447</a>.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</div><div>Connection: keep-alive</div><div>********</div><div><br></div><div>The response shows the redirection to IdP instead of getting the HTTP 200 OK. Also, the shibboleth expires the shibsession cookie.</div><div><br></div><div>********</div><span class=""><div>HTTP/1.1 302 Found</div><div>Cache-Control: private,no-store,no-cache,max-age=0</div><div>Content-Type: text/html; charset=iso-8859-1</div></span><div>Date: Wed, 01 Jul 2015 05:14:42 GMT</div><span class=""><div>Expires: Wed, 01 Jan 1997 12:00:00 GMT</div></span><div>Location: <a href="https://nnnnnnnnn.okta.com/app/template_saml_2_0/8ed6b25a9d60" target="_blank">https://nnnnnnnnn.okta.com/app/template_saml_2_0/8ed6b25a9d60</a></div><div>----------------------</div><span class=""><div>Set-Cookie: _shibsession_64656661756c7468747470733a2f2f6177737161322e70666f7065726174696f6e732e636f6d=; path=/; secure; HttpOnly; expires=Mon, 01 Jan 2001 00:00:00 GMT</div></span><div>---------------------</div><div>Content-Length: 856</div><div>Connection: keep-alive</div></div><div>********</div><div><br></div><div>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.</div><div><br></div><div>********</div><div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [117]: inserted record (id138583305896505261075050264) in context (_d1d2bdac5515cdc5c16493ddfa809e4e) with expiration (1435811017)</div><div>2015-07-01 20:23:37 INFO Shibboleth.SessionCache [117]: new session created: ID (_d1d2bdac5515cdc5c16493ddfa809e4e) IdP (<a href="http://www.okta.com/ssssssssssss" target="_blank">http://www.okta.com/ssssssssssss</a>) Protocol(urn:oasis:names:tc:SAML:2.0:protocol) Address ()</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [117]: deleted record (de8322461f299d6809ee6e5d1cd57a5125d7429f10ed2cdd580faebf81cd148a) in context (RelayState)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.SSO.SAML2 [117]: ACS returning via redirect to: <a href="https://qa2.aaa.com/home" target="_blank">https://qa2.aaa.com/home</a></div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [138]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [138]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [144]: dispatching message (default::getHeaders::Application)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [144]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [144]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [135]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [135]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [99]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [99]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [110]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [110]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [84]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [84]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [140]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [140]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [48]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [48]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.Listener [136]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [136]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811017)</div><div>2015-07-01 20:23:38 DEBUG Shibboleth.Listener [143]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:23:38 DEBUG XMLTooling.StorageService [143]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811018)</div><div>2015-07-01 20:23:41 DEBUG Shibboleth.Listener [110]: dispatching message (touch::StorageService::SessionCache)</div><div>2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [110]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811021)</div><div>2015-07-01 20:23:41 DEBUG Shibboleth.Listener [140]: dispatching message (touch::StorageService::SessionCache)</div><div>2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [140]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811021)</div><div>2015-07-01 20:23:41 DEBUG Shibboleth.Listener [48]: dispatching message (touch::StorageService::SessionCache)</div><div>2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [48]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811021)</div><div>2015-07-01 20:23:41 DEBUG Shibboleth.Listener [136]: dispatching message (touch::StorageService::SessionCache)</div><div>2015-07-01 20:23:41 DEBUG XMLTooling.StorageService [136]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811021)</div><div>2015-07-01 20:25:05 DEBUG Shibboleth.Listener [67]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:25:05 DEBUG XMLTooling.StorageService [67]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811105)</div><div>2015-07-01 20:25:05 DEBUG Shibboleth.Listener [141]: dispatching message (find::StorageService::SessionCache)</div><div>2015-07-01 20:25:05 DEBUG XMLTooling.StorageService [141]: updated expiration of valid records in context (_d1d2bdac5515cdc5c16493ddfa809e4e) to (1435811105)</div><div>2015-07-01 20:25:05 DEBUG Shibboleth.Listener [141]: dispatching message (remove::StorageService::SessionCache)</div><div>2015-07-01 20:25:05 INFO Shibboleth.SessionCache [141]: removed session (_d1d2bdac5515cdc5c16493ddfa809e4e)</div><div>2015-07-01 20:25:05 DEBUG Shibboleth.Listener [141]: dispatching message (default/Login::run::SAML2SI)</div><div>2015-07-01 20:25:05 DEBUG XMLTooling.StorageService [141]: inserted record (ffe592c0772aab4e6851b80be26a363d98bdb2d360f794986103477c0d6cfa52) in context (RelayState) with expiration (1435808105)</div></div><div>********</div><div><br></div><div>Also, I saw the following messages in the log file. I do not know if it is useful for debugging. </div><div><br></div><div><br></div><div>*******</div><div><div>2015-07-01 20:23:37 DEBUG OpenSAML.SecurityPolicyRule.MessageFlow [117]: evaluating message flow policy (replay checking on, expiration 60)</div><div>2015-07-01 20:23:37 DEBUG XMLTooling.StorageService [117]: inserted record (id138583305896505261075050264) in context (MessageFlow) with expiration (1435807657)</div><div><br></div><div><br></div><div>2015-07-01 20:23:37 DEBUG Shibboleth.SSO.SAML2 [117]: extracting pushed attributes...</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.AttributeExtractor.XML [117]: unable to extract attributes, unknown XML object type: saml2p:Response</div><div>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)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.AttributeExtractor.XML [117]: unable to extract attributes, unknown XML object type: saml2:AuthnStatement</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]: decoding SimpleAttribute (FirstName) from SAML 2 Attribute (FirstName) with 1 value(s)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]: decoding SimpleAttribute (LastName) from SAML 2 Attribute (LastName) with 1 value(s)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]: decoding SimpleAttribute (Email) from SAML 2 Attribute (Email) with 1 value(s)</div><div>2015-07-01 20:23:37 DEBUG Shibboleth.AttributeDecoder.String [117]: decoding SimpleAttribute (UserName) from SAML 2 Attribute (UserName) with 1 value(s)</div></div><div>**********</div><div><br></div><div>Sorry for the long message.</div><div><br></div><div>Thanks</div><div><br></div><div>Nara</div><div><br></div><div><br></div><div><br></div></div><div class="HOEnZb"><div class="h5"><div class="gmail_extra"><br><div class="gmail_quote">On Wed, Jul 1, 2015 at 5:18 PM, Cantor, Scott <span dir="ltr"><<a href="mailto:cantor.2@osu.edu" target="_blank">cantor.2@osu.edu</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><span>On 7/1/15, 8:13 PM, "users on behalf of nr673 ." <<a href="mailto:users-bounces@shibboleth.net" target="_blank">users-bounces@shibboleth.net</a> on behalf of <a href="mailto:nara.rama.us@gmail.com" target="_blank">nara.rama.us@gmail.com</a>> wrote:<br>
<br>
<br>
><br>
>But, we still see the shibsession expiry issue. Appreciate any feedbacks on this issue.<br>
<br>
</span>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.<br>
<br>
There is/was no change in the software in any way related to this.<br>
<span><font color="#888888"><br>
-- Scott<br>
<br>
--<br>
To unsubscribe from this list send an email to <a href="mailto:users-unsubscribe@shibboleth.net" target="_blank">users-unsubscribe@shibboleth.net</a><br>
</font></span></blockquote></div><br></div>
</div></div></blockquote></div><br></div>