NAM authentication failure against NPS

[csco11552159]

Hi,

I am working deploy Anyconnect with NAM to endpoints. During the test, we found an issue with Wireless connection, NAM authenticated against NPS. We are planning to replace NPS with ISE next year, but now we try to make NPS work with AC right now .

Current setup:

endpoint with NAM----> Aruba wireless (not terminated on controller)------>NPS-----> AD

if create a local profile just like this one, it is working well.

But once I use NAM profile editor to create one and push down, then the authentication will fail.

Anyone has any thoughts about this issue ?

Thank you.

[csco11552159]

here is the DART LOgs:

3950: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: deferred (1)...

3951: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Sending NOTIFICATION__DEFERRED to subscribers

3952: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network auth request NOTIFICATION__DEFERRED

3953: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: AccessStateMachine current state = ACCESS_CONNECTING, received userEvent = EXTEND

3954: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: Resetting the connection duration timer. Timeout = 40 seconds

1336: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAMSSO-7-DEBUG_MSG: %[tid=1856]: Rx NAM Msg: <SOAP-ENV:Body xmlns:SOAP-ENV="http://schemas.xmlsoap.org/soap/envelope/">   <getLogonUsernameAndPasswordRequest xmlns="http://www.cisco.com/ssc">    <sequenceNumber>383</sequenceNumber>   </getLogonUsernameAndPasswordRequest>  </SOAP-ENV:Body> 

3955: D19C4Q: Sep 28 2016 14:23:40.138 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: AccessStateMachine new state = ACCESS_CONNECTING

1337: D19C4Q: Sep 28 2016 14:23:40.139 +0500: %NAMSSO-7-DEBUG_MSG: %[tid=1856]: Sensitive Information removed

1338: D19C4Q: Sep 28 2016 14:23:40.139 +0500: %NAMSSO-7-DEBUG_MSG: %[tid=1856]: leaving cs...

3956: D19C4Q: Sep 28 2016 14:23:40.140 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: User logon and password received from user.

3957: D19C4Q: Sep 28 2016 14:23:40.140 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Received username/password response

3958: D19C4Q: Sep 28 2016 14:23:40.140 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: ...resumed

3959: D19C4Q: Sep 28 2016 14:23:40.141 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Sending NOTIFICATION__RESUMED to subscribers

3960: D19C4Q: Sep 28 2016 14:23:40.141 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: resuming credential request CRED_REQ_IDENTITY

3961: D19C4Q: Sep 28 2016 14:23:40.141 +0500: %NAM-6-INFO_MSG: %[tid=1776]: EAP: Identity requested

3962: D19C4Q: Sep 28 2016 14:23:40.141 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Performing full authentication

3963: D19C4Q: Sep 28 2016 14:23:40.141 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Disabling fast reauthentication

3964: D19C4Q: Sep 28 2016 14:23:40.141 +0500: %NAM-6-INFO_MSG: %[tid=1776]: Getting credentials from logon.

3965: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-6-INFO_MSG: %[tid=1776]: Sending unprotected identity = anonymous.

3966: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-6-INFO_MSG: %[tid=1776]: EAP: Identity sent

3967: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: identity sent: sync=18

3968: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: credential request 18: state transition: PENDING -> RESPONDED

3969: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Authentication state transition: AUTH_STATE_STARTED -> AUTH_STATE_UNPROTECTED_IDENTITY_SENT_FOR_FULL_AUTHENTICATION

3970: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: credential request completed, response sent: sync=18

3971: D19C4Q: Sep 28 2016 14:23:40.142 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: credential request 18: state transition: RESPONDED -> COMPLETED

3972: D19C4Q: Sep 28 2016 14:23:40.153 +0500: %NAM-7-DEBUG_MSG: %[tid=1808]: EAP-CB: EAP status notification: session-id=1, handle=0342B0BC, status=AC_EAP_STATUS_EAP_FAILURE

3973: D19C4Q: Sep 28 2016 14:23:40.153 +0500: %NAM-7-DEBUG_MSG: %[tid=1808]: EAP-CB: sending EapStatusEvent...

3974: D19C4Q: Sep 28 2016 14:23:40.153 +0500: %NAM-7-DEBUG_MSG: %[tid=1808]: EAP-CB: EAP status notification: session-id=1, handle=0342B0BC, status=AC_EAP_STATUS_ERR_CLIENT_IDENTITY_REJECTED

3975: D19C4Q: Sep 28 2016 14:23:40.153 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: ...received EapStatusEvent: session-id=1, EAP handle=0342B0BC, status=AC_EAP_STATUS_EAP_FAILURE

3976: D19C4Q: Sep 28 2016 14:23:40.153 +0500: %NAM-7-DEBUG_MSG: %[tid=1808]: EAP-CB: sending EapStatusEvent...

3977: D19C4Q: Sep 28 2016 14:23:40.153 +0500: %NAM-6-INFO_MSG: %[tid=1776]: EAP: Eap status AC_EAP_STATUS_EAP_FAILURE.

3978: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: processing EapStatusEvent in the subscriber

3979: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Unprotected identity rejected, authentication failed.

3980: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Client certificate list has been cleared

3982: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Disabling fast reauthentication

3981: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-6-INFO_MSG: %[tid=1808][mac=1,6,e0:9d:31:99:8b:68]: {ACC0448B-58E4-403C-B306-8B25A84B2908}: Port State UNAUTHENTICATED and status EAP_FAILURE

3983: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Failed to authenticate with prelogon credentials.

3984: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Enforcing credentials to be requested from GUI

3985: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Disabling fast reauthentication

3986: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Authentication state transition: AUTH_STATE_UNPROTECTED_IDENTITY_SENT_FOR_FULL_AUTHENTICATION -> AUTH_STATE_FAILURE

3987: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Sending NOTIFICATION__FAILURE to subscribers

3988: D19C4Q: Sep 28 2016 14:23:40.154 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network auth request NOTIFICATION__FAILURE

3989: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: NetworkStateMachine current state USER_T_NOT_DISCONNECTED, received auth request AUTHENTICATION_FAILED

3990: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: NetworkStateMachine new state USER_T_NOT_DISCONNECTED

3991: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Finishing authentication

3992: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Authentication finished

3993: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: ...received EapStatusEvent: session-id=1, EAP handle=0342B0BC, status=AC_EAP_STATUS_ERR_CLIENT_IDENTITY_REJECTED

3994: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-6-INFO_MSG: %[tid=1776]: EAP: Eap status AC_EAP_STATUS_ERR_CLIENT_IDENTITY_REJECTED.

3995: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: EAP: processing EapStatusEvent in the subscriber

3996: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Auth[LAB_WIFI:user-auth]: Ignoring EAP status AC_EAP_STATUS_ERR_CLIENT_IDENTITY_REJECTED

3997: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: ACE: adapter SM current: state(STATE_AUTHENTICATING), event(EVENT_AUTH_FAIL)

3998: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: ACE: adapter SM state change: STATE_AUTHENTICATING -> STATE_AUTH_FAILED

3999: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: handleEventAndDoStateTransitionAction action : ACTION_AUTH_FAIL

4000: D19C4Q: Sep 28 2016 14:23:40.155 +0500: %NAM-3-ERROR_MSG: %[tid=1776]: {ACC0448B-58E4-403C-B306-8B25A84B2908}: Authentication Failed

4001: D19C4Q: Sep 28 2016 14:23:40.156 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: AccessStateMachine current state = ACCESS_CONNECTING, received adapterState = auth_failed

1339: D19C4Q: Sep 28 2016 14:23:40.156 +0500: %NAMSSO-7-DEBUG_MSG: %[tid=1856]: waiting for cs...

4002: D19C4Q: Sep 28 2016 14:23:40.156 +0500: %NAM-7-DEBUG_MSG: %[tid=1776]: Network LAB_WIFI: port authentication failed

[kthiruve · Accepted solution]

Hi Chao,

Via the profile I think NAM is sending anonymous as an outer identity for security. NPS is not able to understand this and fails as a result.

If you can configure NPS to understand this, you will get it working.

Thanks

Krishnan

[csco11552159]

update:  i changed on AC side without anonymous. it is working for now.

later once use ISE replace NPS, it will be better.

[Neelesh Marathe]

Hello Chao,

Need small help..

How do you changed it to not use anonymous.?

Just putting "[username]" in unprotected identity?

Thanks,

Neelesh Marathe

[Neelesh Marathe]

Hello Chao/Team,

Could anyone please help with above query?

Thanks,

Neelesh Marathe

[pcarco]

Machine

User

[csco11552159]

yes, that what i did. since it doesnt recognize the username.

[Neelesh Marathe]

Thanks Paul and Chao. I tried it but it is still not working for me. I believe I need to check on NPS now.