NativeSP, IDP-initiated, occasionally aborted flows.

[Cantor, Scott]

On 12/11/14, 2:22 AM, "James Nurmi" <jdnurmi at qwe.cc> wrote:

>2014-12-11 02:04:50 INFO Shibboleth.SessionCache [12]: 
>cookieBadness((null)): 27076856; _87ec0cc30f106cc6a9d28b7472075454; path=/

I don't know what that weird label refers to, if that's from the code it's 
just not in my memory bank.

>(Excuse some additional debugging statements I've added to try and trace 
>this);

Maybe that's what I'm seeing above.

>Occasionally, the requests end up on different (connections? threads?), 
>and those sessions get quickly aborted:

Well, I wouldn't say that's definitely not involved because those are 
unsupported versions now, and I'm not going to try and verify it either 
way, but I don't recall any such issue, certainly not that recently.

>2014-12-11 02:04:56 DEBUG XMLTooling.StorageService [12]: updated 
>expiration of valid records in context 
>(_8ffdfea62caae74a5c1d22260859a983) to (1418267096)
>2014-12-11 02:04:56 DEBUG Shibboleth.Listener [12]: dispatching message 
>(remove::StorageService::SessionCache)
>2014-12-11 02:04:56 INFO Shibboleth.SessionCache [12]: remove session:: 
>(ID: _8ffdfea62caae74a5c1d22260859a983)

That sequence there basically means the session just wasn't valid. The 
usual reason for that would be IP addresses changing. The other option 
would be an artificially low lifetime caused by a broken 
SessionNotOnOrAfter value.

>Such that by the time the redirect occurs, shibd's expired the session 
>(presumably) and can no longer look up the attribute.

No, that's after the redirect. That's happening when the resource request 
is handled and the session gets looked up. The act of looking up an 
invalid session invalidates it.

>In all cases, the NotBefore and NotAfter are well spread around the time 
>of the incident,

Those have nothing to do with session lifetime. SessionNotOnOrAfter would.

> and my ability to keep tracing this seems to have hit a wall, as I can't 
>readily identify any /cause/ of the session being removed, and my best 
>guess (some undocumented/hard-to-find
> cache race condition) isn't proving out in any obvious way.

That's very, very unlikely, but it's too old a version for me to issue any 
statements definitively since I won't back that up by doing any research.

>The only distinction I can readily find (other than the obvious 
>termination of a session) seems to be whether the thread/pid/whatever ID 
>stays constant through the transaction:
>2014-12-11 02:04:56 DEBUG Shibboleth.SSO.SAML2 [11]: ACS returning via 
>redirect to:
>https://qa1.climate.com/sso/
>2014-12-11 02:04:56 DEBUG Shibboleth.Listener [12]: dispatching message 
>(find::StorageService::SessionCache)

That shouldn't cause any problem. The ACS processing is one message, the 
find step is a later message from a different HTTP request to Apache.

>At this point I'm inclined to push back to at least enable SP-initiated 
>support so in the broken session case
>I can at least retry the session setup, but wanted to reach out and see 
>if anyone has any bright ideas on this particular one.  (Due to the age 
>of the system, testing 2.5 is non-trivial in my environment).

That's a problem since nothing else is supported. Sorry.

>(Currently using the in-memory cache, tried briefly w/ memcache, no 
>visible improvement;  I'm inclined to believe this is in IDP-initiated 
>flows, but all the rest of my deployments are permitted IDP/SP initiated, 
>so... add salt as desired).

It shouldn't make any difference, the SP has no memory of its requests.

-- Scott