AW: SPNEGO as first factor in MFA

[Rabe, Jens]

Hi Simon,

even if I enable forceAuthn for SPNEGO it doesn't work with the following scenario:


Authentication against first SP1 with SPNEGO:

2025-03-31 11:58:52,408 - INFO [net.shibboleth.idp.hsmw:5] - firstFactor
2025-03-31 11:58:52,957 - INFO [net.shibboleth.idp.authn.spnego.impl.SPNEGOAuthnController:227] - SPNEGO/Kerberos authentication succeeded for principal: user at UNI
2025-03-31 11:58:52,969 - INFO [net.shibboleth.idp.authn.impl.ValidateExternalAuthentication:187] - Profile Action ValidateExternalAuthentication: External authentication succeeded for Subject
2025-03-31 11:58:52,971 - INFO [Shibboleth-Audit.SPNEGO:333] - IP|2025-03-31T09:58:52.971305428Z|https://sp1|_ID||authn/SPNEGO|
user at UNI|Success|aBrowser
2025-03-31 11:58:53,005 - INFO [net.shibboleth.idp.authn.impl.FinalizeAuthentication:201] - Profile Action FinalizeAuthentication: Principal user authenticated
2025-03-31 11:58:53,183 - WARN [org.opensaml.saml.common.binding.SAMLBindingSupport:92] - Relay state exceeds 80 bytes: https://sp1
2025-03-31 11:58:53,195 - INFO [Shibboleth-Audit.SSO:333] - IP|2025-03-31T09:58:42.033819212Z|2025-03-31T09:58:53.195670730Z|user|https://sp1|_ID|urn:oasis:names:tc:SAML:2.0:ac:classes:Kerberos|2025-03-31T09:58:52.971994355Z|eduPersonEntitlement,mail,eduPersonAffiliation,displayName,ou,givenName,cn,o,uid,samlPairwiseID,eduPersonScopedAffiliation,eduPersonTargetedID,schacHomeOrganization,eduPersonPrincipalName,sn|ID|transient|false|false||Redirect|POST||Success||ID|aBrowser


Authentication against second SP2 with falling back to Password because of forceAuthn and the scripted firstfactor:

2025-03-31 11:59:02,624 - INFO [net.shibboleth.idp.hsmw:5] - firstFactor
2025-03-31 11:59:02,626 - INFO [net.shibboleth.idp.hsmw:8] - forceAuthn is set, falling back to authn/Password
2025-03-31 11:59:09,397 - INFO [net.shibboleth.idp.authn.impl.LDAPCredentialValidator:176] - Credential Validator ldap: Login by 'user' succeeded
2025-03-31 11:59:09,398 - INFO [Shibboleth-Audit.Password:333] - IP|2025-03-31T09:59:09.398112441Z|https://sp2|_ID|ID|authn/Password|ldap|user|user|Success|aBrowser
2025-03-31 11:59:09,415 - INFO [net.shibboleth.idp.authn.impl.FinalizeAuthentication:201] - Profile Action FinalizeAuthentication: Principal user authenticated
2025-03-31 11:59:09,529 - INFO [Shibboleth-Audit.SSO:333] - IP|2025-03-31T09:59:02.608852627Z|2025-03-31T09:59:09.528932363Z|user|https://sp2|_ID|password|2025-03-31T09:59:09.398495538Z|eduPersonEntitlement,mail,eduPersonAffiliation,ou,displayName,givenName,cn,o,eduPersonAssurance,samlPairwiseID,uid,eduPersonScopedAffiliation,eduPersonTargetedID,samlSubjectID,schacHomeOrganization,eduPe
rsonPrincipalName,eduPersonUniqueId,sn|ID|transient|false|false|AES128-GCM|Redirect|POST||Success||ID|aBrowser


Authentication against third SP3 with SPNEGO but after forceAuthn:

2025-03-31 11:59:19,377 - INFO [net.shibboleth.idp.hsmw:5] - firstFactor
2025-03-31 11:59:19,619 - INFO [net.shibboleth.idp.authn.spnego.impl.SPNEGOAuthnController:227] - SPNEGO/Kerberos authentication succeeded for principal: user at UNI
2025-03-31 11:59:19,631 - INFO [net.shibboleth.idp.authn.impl.ValidateExternalAuthentication:187] - Profile Action ValidateExternalAuthentication: External authentication succeeded for Subject
2025-03-31 11:59:19,631 - INFO [Shibboleth-Audit.SPNEGO:333] - IP|2025-03-31T09:59:19.631340461Z|https://sp3|ID|authn/SPNEGO|user@UNI|Success|aBrowser
2025-03-31 11:59:19,656 - ERROR [net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:76] - Profile Action SelectSubjectCanonicalizationFlow: No potential flows left to choose from, canonicalization will fail
2025-03-31 11:59:19,657 - INFO [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:137] - Profile Action SelectAuthenticationFlow: Moving incomplete flow authn/MFA to intermediate set
2025-03-31 11:59:19,657 - INFO [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:313] - Profile Action SelectAuthenticationFlow: No potential flows left to choose from, authentication failed
2025-03-31 11:59:19,705 - INFO [Shibboleth-Audit.SSO:333] - IP|2025-03-31T09:59:19.365179648Z|2025-03-31T09:59:19.704986967Z||https://sp3|||||||false|false||Redirect|POST||Requester|urn:oasis:names:tc:SAML:2.0:status:AuthnFailed|ID|aBrowser

To me, it looks like it's doing SPNEGO, but after that, it can't find any more flows for canonicalization.
Is this because the filter removes the flow?

I'm trying to increase the logging, maybe then I'll understand it better

Thanks
Jens