LogoutRequest not fulfilled by IdP

[vyal2k]

Scott,
 Thanks for your reply.

IdP does have the session for the user identified by NameId; when the SP issues AuthnRequest immediately following the failed LogoutRequest, the IdP logs says "Existing IdP session available for principal user2".
Here "user2" is an user (cn) in LDAP directory.

I have tried "urn:oasis:names:tc:SAML:2.0:nameid-format:transient" and "urn:oasis:names:tc:SAML:1.1:nameid-format:emailAddress" as the NameIdFormat, but in both cases, LogoutRequest is not processed by IdP even though there is active session.

Here is the idp-process.log:

22:01:53.633 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SLOProfileHandler:154] - Processing incoming SAML LogoutRequest
22:01:53.633 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SLOProfileHandler:502] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect'
22:01:53.644 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SLOProfileHandler:516] - Decoded request from relying party 'https://inw00003973:8443'
22:01:53.645 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SLOProfileHandler:259] - Querying SessionManager based on NameID '_0edf84c284fd5f35a5e2d2e5f9f81bc6|urn:oasis:names:tc:SAML:2.0:nameid-format:transient|https://inw00003973.informatica.com/idp/shibboleth'
22:01:53.645 - INFO [edu.internet2.middleware.shibboleth.idp.profile.saml2.SLOProfileHandler:266] - LogoutRequest did not reference an active session.
22:01:53.647 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.AbstractSAMLProfileHandler:796] - Encoding response to SAML request 888d5eaa-a478-4f25-9e56-ab9bae6292a5 from relying party https://inw00003973:8443
22:01:53.661 - INFO [Shibboleth-Audit:1028] - 20131126T163153Z|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect|888d5eaa-a478-4f25-9e56-ab9bae6292a5|https://inw00003973:8443|urn:mace:shibboleth:2.0:profiles:saml2:logout|https://inw00003973.informatica.com/idp/shibboleth|urn:oasis:names:tc:SAML:2.0:bindings:HTTP-POST|_daa6be06c76bce4322ad25421c3c5c07|user2|urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport||_0edf84c284fd5f35a5e2d2e5f9f81bc6||
22:04:30.355 - INFO [Shibboleth-Access:73] - 20131126T163430Z|192.168.1.8|inw00003973.informatica.com:443|/profile/SAML2/Redirect/SSO|
22:04:30.355 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:86] - shibboleth.HandlerManager: Looking up profile handler for request path: /SAML2/Redirect/SSO
22:04:30.355 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.IdPProfileHandlerManager:97] - shibboleth.HandlerManager: Located profile handler of the following type for the request path: edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler
22:04:30.355 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:188] - Incoming request does not contain a login context, processing as first leg of request
22:04:30.356 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:366] - Decoding message with decoder binding 'urn:oasis:names:tc:SAML:2.0:bindings:HTTP-Redirect'
22:04:30.357 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:387] - Decoded request from relying party 'https://inw00003973:8443'
22:04:30.357 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:226] - Creating login context and transferring control to authentication engine
22:04:30.358 - DEBUG [edu.internet2.middleware.shibboleth.idp.profile.saml2.SSOProfileHandler:240] - Redirecting user to authentication engine at https://inw00003973.informatica.com:443/idp/AuthnEngine
22:04:30.361 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request
22:04:30.361 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:240] - Beginning user authentication process.
22:04:30.361 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:244] - Existing IdP session available for principal user2
22:04:30.361 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:283] - Filtering configured LoginHandlers: {urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession=edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler at 2058e3ec, urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler at 2bdbab8b}
22:04:30.362 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:464] - Selecting appropriate login handler from filtered set {urn:oasis:names:tc:SAML:2.0:ac:classes:PreviousSession=edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler at 2058e3ec, urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport=edu.internet2.middleware.shibboleth.idp.authn.provider.UsernamePasswordLoginHandler at 2bdbab8b}
22:04:30.362 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:467] - Authenticating user with previous session LoginHandler
22:04:30.362 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:478] - Basing previous session authentication on active authentication method urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport
22:04:30.362 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.provider.PreviousSessionLoginHandler:112] - Using existing IdP session for user2
22:04:30.362 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:144] - Returning control to authentication engine
22:04:30.362 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:209] - Processing incoming request
22:04:30.363 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:514] - Completing user authentication process
22:04:30.363 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:585] - Validating authentication was performed successfully
22:04:30.363 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:696] - Updating session information for principal user2
22:04:30.363 - DEBUG [edu.internet2.middleware.shibboleth.idp.authn.AuthenticationEngine:560] - User user2 authenticated with method urn:oasis:names:tc:SAML:2.0:ac:classes:PasswordProtectedTransport

Thanks,
Vasu

________________________________
 From: "Cantor, Scott" <cantor.2 at osu.edu>
To: Shib Users <users at shibboleth.net> 
Sent: Tuesday, 26 November 2013 8:20 PM
Subject: Re: LogoutRequest not fulfilled by IdP
 

On 11/26/13, 2:04 AM, "vyal2k" <vyal2k at yahoo.com> wrote:


>Hi,
> I am trying to send a LogoutRequest from SP to IdP, but the request is
>not fulfilled by IdP.
>idp-process.log says "LogoutRequest did not reference an active session."
>even though the LogoutRequest contains sessionIndex from Assertion's
>AuthnStatement.

There's nothing else to tell you. The session cache didn't have a session
matching the NameID. The SessionIndex is not relevant, the IdP doesn't
support that feature.

-- 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/20131126/61f4d388/attachment.html