SPNEGO and MFA - No potential flows left to choose from, canonicalization will fail

Wed Sep 25 08:47:09 EDT 2019

Hi list,

this is somewhat complicated. IdP v3.4.3. I want Password, or SPNEGO, as
a first factor, and a second factor if the user has registered a TOTP
token in our privacyIDEA server.

Without SPNEGO, this worked as intended. Now I followed the
SPNEGOAuthnConfiguration topic as we usually do. If the  user has no 2FA
Token, this works as well. However we do not seem to get both working -
we are hitting an error and the MFA logic seems weird. For once, it
looks as if c14n is being applied twice, erroneously. On the other hand,
logs first say MFA is complete, and then it's incomplete. Do you have
some idea what is wrong?

Regards

Martin

Here are some config snippets:

idp.authn.flows=SPNEGO|MFA

<util:map id="shibboleth.authn.MFA.TransitionMap">
        <entry key="">
             <bean parent="shibboleth.authn.MFA.Transition"
p:nextFlow="authn/Password" />
        </entry>

        <entry key="authn/Password">
            <bean parent="shibboleth.authn.MFA.Transition"
p:nextFlowStrategy-ref="checkFor2FAToken" /> <!-- returns
authn/privacyidea or null -->
        </entry>

        <entry key="authn/SPNEGO">
            <bean parent="shibboleth.authn.MFA.Transition"
p:nextFlowStrategy-ref="checkFor2FAToken" /> <!-- returns
authn/privacyidea or null -->
        </entry>
</util:map>

<util:list id="shibboleth.c14n.simple.Transforms">
        <bean parent="shibboleth.Pair" p:first="^(.+)@DOMAIN\.ORG$"
p:second="$1" />
</util:list>

And here some log extracts:

2019-09-25 10:42:08,409 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:264] - Profile
Action SelectAuthenticationFlow: No specific Principals requested
2019-09-25 10:42:08,409 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:309] - Profile
Action SelectAuthenticationFlow: No usable active results available,
selecting an inactive flow
2019-09-25 10:42:08,409 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:363] - Profile
Action SelectAuthenticationFlow: Selecting inactive authentication flow
authn/MFA

2019-09-25 10:42:08,567 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:221]
- Profile Action TransitionMultiFactorAuthentication: MFA flow
transition after 'proceed' event to 'authn/Password' flow

(user pushes SPNEGO Button)

2019-09-25 10:42:16,943 - 10.51.0.44 - TRACE
[net.shibboleth.idp.authn.spnego.impl.SPNEGOAuthnController:100] -
SPNEGO negotiation started, answering request with 401
(WWW-Authenticate: Negotiate)

2019-09-25 10:42:17,067 - 10.51.0.44 - INFO
[net.shibboleth.idp.authn.impl.ValidateExternalAuthentication:139] -
Profile Action ValidateExternalAuthentication: External authentication
succeeded for Subject:
[UsernamePrincipal{username=*userabc at DOMAIN.ORG*}, userabc at DOMAIN.ORG]

2019-09-25 10:42:17,332 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.AbstractSubjectCanonicalizationAction:247] -
Profile Action *SimpleSubjectCanonicalization: result of replacement is
'userabc'*
2019-09-25 10:42:17,340 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:192]
- Profile Action TransitionMultiFactorAuthentication: Preserving
authentication result from 'authn/SPNEGO' flow
2019-09-25 10:42:17,341 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:209]
- Profile Action TransitionMultiFactorAuthentication: Applying MFA
transition rule to exit state 'authn/Password'
2019-09-25 10:42:17,359 - 10.51.0.44 - DEBUG [checkFor2FAToken:3] -
Checking if user is enabled for 2FA
2019-09-25 10:42:17,424 - 10.51.0.44 - DEBUG [checkFor2FAToken:11] -
Looking up user: userabc
2019-09-25 10:42:17,431 - 10.51.0.44 - DEBUG
[ca.ab.concordia.privacyIDEAtfa.TokenGenerator:124] - Checking if user
has one or more tokens

2019-09-25 10:42:18,269 - 10.51.0.44 - DEBUG [checkFor2FAToken:19] -
Token(s) found for userabc. Proceeding to authentication.
2019-09-25 10:42:18,270 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:221]
- Profile Action TransitionMultiFactorAuthentication: MFA flow
transition after 'proceed' event to 'authn/privacyidea' flow

(user inputs TOTP token)

2019-09-25 10:42:21,621 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.AbstractValidationAction:354] - Profile Action
TokenValidator: Adding custom Principal(s) defined on underlying flow
descriptor
2019-09-25 10:42:21,621 - 10.51.0.44 - DEBUG
[ca.ab.concordia.privacyIDEAtfa.TokenValidator:77] - Profile Action
TokenValidator: TokenValidator populateSubject is called
2019-09-25 10:42:21,622 - 10.51.0.44 - DEBUG
[ca.ab.concordia.privacyIDEAtfa.TokenValidator:79] - Profile Action
TokenValidator: Populate subject *userabc*
2019-09-25 10:42:21,628 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:192]
- Profile Action TransitionMultiFactorAuthentication: Preserving
authentication result from 'authn/privacyidea' flow
019-09-25 10:42:21,629 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:209]
- Profile Action TransitionMultiFactorAuthentication: Applying MFA
transition rule to exit state 'authn/privacyidea'
2019-09-25 10:42:21,629 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.TransitionMultiFactorAuthentication:226]
- Profile Action TransitionMultiFactorAuthentication: MFA flow
completing with event 'proceed'
2019-09-25 10:42:21,640 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.FinalizeMultiFactorAuthentication:193] -
Profile Action FinalizeMultiFactorAuthentication: *MFA complete*,
producing merged result

2019-09-25 10:42:21,648 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.PopulateSubjectCanonicalizationContext:79]
- Profile Action PopulateSubjectCanonicalizationContext: Installing 2
canonicalization flows into SubjectCanonicalization

2019-09-25 10:42:21,650 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:100] -
Profile Action SelectSubjectCanonicalizationFlow: Checking
canonicalization flow c14n/x500 for applicability...
2019-09-25 10:42:21,650 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:106] -
Profile Action SelectSubjectCanonicalizationFlow: Canonicalization flow
c14n/x500 was not applicable to this request
2019-09-25 10:42:21,651 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:100] -
Profile Action SelectSubjectCanonicalizationFlow: Checking
canonicalization flow c14n/simple for applicability...
2019-09-25 10:42:21,651 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:106] -
Profile Action SelectSubjectCanonicalizationFlow: Canonicalization flow
c14n/simple was not applicable to this request
2019-09-25 10:42:21,651 - 10.51.0.44 - *ERROR*
[net.shibboleth.idp.authn.impl.SelectSubjectCanonicalizationFlow:78] -
Profile Action SelectSubjectCanonicalizationFlow: No potential flows
left to choose from, canonicalization will fail

2019-09-25 10:42:21,679 - 10.51.0.44 - INFO
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:138] - Profile
Action SelectAuthenticationFlow: Moving *incomplete flow authn/MFA* to
intermediate set
2019-09-25 10:42:21,680 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:264] - Profile
Action SelectAuthenticationFlow: No specific Principals requested
2019-09-25 10:42:21,680 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:309] - Profile
Action SelectAuthenticationFlow: No usable active results available,
selecting an inactive flow
2019-09-25 10:42:21,702 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:363] - Profile
Action SelectAuthenticationFlow: Selecting inactive authentication flow
authn/SPNEGO
2019-09-25 10:42:21,704 - 10.51.0.44 - INFO
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:138] - Profile
Action SelectAuthenticationFlow: Moving incomplete flow authn/SPNEGO to
intermediate set
2019-09-25 10:42:21,704 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:264] - Profile
Action SelectAuthenticationFlow: No specific Principals requested
2019-09-25 10:42:21,705 - 10.51.0.44 - DEBUG
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:309] - Profile
Action SelectAuthenticationFlow: No usable active results available,
selecting an inactive flow
2019-09-25 10:42:21,705 - 10.51.0.44 - INFO
[net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:313] - Profile
Action SelectAuthenticationFlow: No potential flows left to choose from,
authentication failed
2019-09-25 10:42:21,724 - 10.51.0.44 - DEBUG
[org.opensaml.saml.common.profile.logic.DefaultLocalErrorPredicate:173]
- Error event NoPotentialFlow will be handled with response

-- 
Dr. Martin Haase, Solutions Engineer

DAASI International GmbH        
Europaplatz 3                   
D-72072 Tübingen                
Germany                    

phone: +49 7071 407109-0
fax:   +49 7071 407109-9  
email: martin.haase at daasi.de
web:   www.daasi.de

Sitz der Gesellschaft: Tübingen
Registergericht: Amtsgericht Stuttgart, HRB 382175
Geschäftsleitung: Peter Gietz

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20190925/2f626dd3/attachment.html>