SAML flow within MFA flow - possible c14n problem

Tue Sep 13 14:19:17 UTC 2022

Thanks Scott, this is really helpful and is going to inform a review of the MFA flow I've been working on.

Because the c14n results are reported as consistent in the logs later on, and the SAML flow to Azure works OK in this respect, I've taken a step back and set SAML as the only flow in idp.authn.flows to see if the session timeout/reuse issue is being seen on this flow alone and I find it is.

For testing I set all properties for lifetimes and timeouts to 5 minutes. When using the SAML flow alone the AuthN result reports as being reusable during the 5 minute lifetime/timeout period. Once this period is reached the result never seems to be usable again, despite it being reported as saved just beforehand.

I've included a grep of authn/SAML in the log below just as an illustration, with the actions visiting different Service Providers as sections. I was expecting Service visits 4 and 5 to look like Service 2 but they don't seem to be able to reuse the result from a minute or so ago after the lifetime expiry. By starting with a fresh browser (or complete cache clear) we can get back to Service 1 behaviour, but after the lifetime expiry it gets stuck never being able to reuse the results. (The Password flow has no problem reusing results once the lifetime has been reached.)

The only thing I can think of is that the result from Service 1 involves the actual process of logging in to Azure (and doing MFA) whereas afterwards it's just confirming an existing Azure session, so may be being treated differently from Service 3 onwards, but I'm not sure the session stores anything that would be able to make that distinction. But also I'd still be glad to find out this is expected behaviour for this flow!

Thanks,
John

Visit Service 1: (AuthN Request to Azure - Password and MFA provided)

2022-09-13 14:06:31,916 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:369] - Profile Action SelectAuthenticationFlow: Selecting inactive authentication flow authn/SAML
2022-09-13 14:07:12,270 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:572] - Saving AuthenticationResult for flow authn/SAML in session d4343e9ee9274e43ece74b8fb24094f0b8d5d8110616f2598ee9d3817f929c29

Visit Service 2:

2022-09-13 14:08:06,504 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:540] - Loading AuthenticationResult for flow authn/SAML in session d4343e9ee9274e43ece74b8fb24094f0b8d5d8110616f2598ee9d3817f929c29
2022-09-13 14:08:06,510 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.ExtractActiveAuthenticationResults:134] - Profile Action ExtractActiveAuthenticationResults: Authentication result authn/SAML is active, copying from session
2022-09-13 14:08:06,513 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:385] - Profile Action SelectAuthenticationFlow: Reusing active result authn/SAML
2022-09-13 14:08:06,514 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.UpdateSessionWithAuthenticationResult:206] - Profile Action UpdateSessionWithAuthenticationResult: Updating activity time on reused AuthenticationResult for flow authn/SAML in existing session d4343e9ee9274e43ece74b8fb24094f0b8d5d8110616f2598ee9d3817f929c29

Visit Service 3: (AuthN Request to Azure) 5min TIMEOUT REACHED

2022-09-13 14:14:39,079 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:369] - Profile Action SelectAuthenticationFlow: Selecting inactive authentication flow authn/SAML
2022-09-13 14:14:39,533 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:572] - Saving AuthenticationResult for flow authn/SAML in session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392

Visit Service 4: (AuthN Request to Azure)

2022-09-13 14:15:11,423 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:540] - Loading AuthenticationResult for flow authn/SAML in session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392
2022-09-13 14:15:11,425 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.ExtractActiveAuthenticationResults:138] - Profile Action ExtractActiveAuthenticationResults: Authentication result authn/SAML is inactive, skipping it
2022-09-13 14:15:11,427 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:369] - Profile Action SelectAuthenticationFlow: Selecting inactive authentication flow authn/SAML
2022-09-13 14:15:11,750 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.UpdateSessionWithAuthenticationResult:201] - Profile Action UpdateSessionWithAuthenticationResult: Adding new AuthenticationResult for flow authn/SAML to existing session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392
2022-09-13 14:15:11,751 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:572] - Saving AuthenticationResult for flow authn/SAML in session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392
2022-09-13 14:15:11,752 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.AbstractIdPSession:300] - IdPSession 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392: replaced old AuthenticationResult for flow ID authn/SAML

Visit Service 5: (AuthN Request to Azure)

2022-09-13 14:15:52,481 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:540] - Loading AuthenticationResult for flow authn/SAML in session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392
2022-09-13 14:15:52,483 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.ExtractActiveAuthenticationResults:138] - Profile Action ExtractActiveAuthenticationResults: Authentication result authn/SAML is inactive, skipping it
2022-09-13 14:15:52,486 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:369] - Profile Action SelectAuthenticationFlow: Selecting inactive authentication flow authn/SAML
2022-09-13 14:15:52,845 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.UpdateSessionWithAuthenticationResult:201] - Profile Action UpdateSessionWithAuthenticationResult: Adding new AuthenticationResult for flow authn/SAML to existing session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392
2022-09-13 14:15:52,845 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.impl.StorageBackedIdPSession:572] - Saving AuthenticationResult for flow authn/SAML in session 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392
2022-09-13 14:15:52,848 - XX.XX.XX.XX - DEBUG [net.shibboleth.idp.session.AbstractIdPSession:300] - IdPSession 1a2d4f4af7aca52935b8350cdcb05f32c87e34ecb5e2f77e3fb32287d8e6c392: replaced old AuthenticationResult for flow ID authn/SAML

________________________________
From: Cantor, Scott <cantor.2 at osu.edu>
Sent: 09 September 2022 16:50
To: Shib Users <users at shibboleth.net>
Cc: John Watt <John.Watt at glasgow.ac.uk>
Subject: Re: SAML flow within MFA flow - possible c14n problem

I can't really debug this for somebody on list but I will outline a bit about the way c14n works in general and for the MFA flow, and correct a point of understandable confusion.

Every login flow in isolation needs to be able to produce a string value. And anything that's not just simple stuff is not going to be simple to get a value out. With SAML, you have to obviously deal with the NameID or the Attribute(s) and generally leverage the fancy stuff that got added to get a string out to use, vs. the Password case where you start with the username and can pretty much just manipulate that directly.

Assuming you have that working, the MFA flow by default will merge all the Principal objects from all the Java Subjects being run together, and then it runs c14n again on that merged Subject.

In principle (sic), the same c14n settings that work in isolation on each constituent flow generally tend to work correctly on that merged result, but there can be cases where it's not that easy or the ordering of the c14n flows that are "active" might get in the way of things, so you have to have some sense of what's in the Subject after the merge and then make sure the intended c14n behavior will handle that.

There are also ways to build a custom function to do the final merge and produce the MFA Subject result when absolutely necessary, though I'm not sure it's come up much.

Basically, if you're getting the wrong c14n result, one of the c14n flows is doing the wrong thing with the Principal collection that it operated on for whatever Subject it was running against.

The other note I will add is that the log statements where it says "authenticatedPrincipal=..." are just the output of the toString() method on the AuthenticationResult object, and the value for that field is just a heuristic. It's NOT the c14n result.

It's a guess at a value to spit out that might make sense, and is either the first UsernamePrincipal value it finds in the Subject, or failing that, the first Principal it finds. In the case of SAML, it's a NameIDPrincipal wrapped around the NameID it got, which is just part of the output of the SAML flow. It's nothing to do with c14n.

That isn't obvious, and would be easy to misconstrue.

I don't know if that helps but it's what I can do on list.

-- Scott

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20220913/97218ea4/attachment.htm>