FortiAuthenticator - Remote LDAP user authentication(mschap) with no token failed: invalid password

[heriherwanto]

We have problem connecting to FortiAuthenticator (EAP-PEAP) using Active Directory.

All setting is done, status connection to AD is joined and we can Syncronization the user from AD.

But, when we try to join using Access point using MSCHAP v2, the login success and the certificate can see but after login, the dialog is back to login again. 

If we tested to login using application 3rd party "ntradping" using the same user and the respons is success / accept

Log information is  Remote LDAP user authentication(mschap) with no token failed: invalid password.

In the debug the information is :

facauth: Remote ldap user 'misniru': NULL password is not allowed

When we try to login using user local from FortiAuthenticator is running well. the problem is using Remote user Active Directory.

If anybody here have a experience with this issue please help me.

For the information, we using Mikrotik and TP-LINK as a Access Point

[Markus_M · Accepted solution]

Hi Heri,

There is a solution, but it needs to be found.

When you login and the login is successful according to the logs, then why the SSID is asking again for a login?

From what it looks like, the Mikrotik is sending multiple access-requests via RADIUS, should get one answered and apparently gets another of the duplicated answered.

Authentication is usually serial, going one by one. Clients asks to somewhere, response comes back. No magic:

1) Windows asks the AP

2) AP asks to FAC

3) FortiAuthenticator asks to LDAP

4) LDAP sends OK

5) FAC sends OK

6) AP sends OK

7) client receives OK.

Your flow seems distorted such that the AP may not understand the OK or the Mikrotik is asking multiple times for an unknown reason.

2022-10-24T07:34:47.930204+07:00 FACMHP radiusd[1181]: (169) Ignoring duplicate packet from client Mikrotik port 56131 - ID: 181 due to unfinished request in component authenticate module eap_peap

2022-10-24T07:34:48.239477+07:00 FACMHP radiusd[1181]: (169) Ignoring duplicate packet from client Mikrotik port 56131 - ID: 181 due to unfinished request in component authenticate module eap_peap

The time it takes for FAC to authenticate the user, makes it looks like the LDAP server is taking 3 seconds to respond.

Or your FortiAuthenticator is incredibly slow:

2022-10-24T07:34:47.657902+07:00 FACMHP radiusd[1181]: (169) facauth: LDAP user found: misniru

2022-10-24T07:34:50.006677+07:00 FACMHP radiusd[1181]: (169) facauth: Remote Windows AD user authenticated

So check either of these:

- is FAC maybe out of RAM/CPU

- is your LDAP server slow

- why Mikrotik is making multiple duplicate requests

Best regards,

Markus

[Jean-Philippe_P]

Hello heriherwanto,

Thanks for posting on the Fortinet Community Forum!

I found this document that can help you:

https://docs.fortinet.com/document/fortiauthenticator/6.0.0/administration-guide/641286/remote-authe...

Can you tell me if it helped you or if you still have the same error following this guide?

Kindest regards,

[Sheikh]

  Hi heriherwanto,

"NULL password is not allowed", means that Your FortiAuthenticator is trying to make a username+password auth, but your client is trying to make some sort of non-password authentication and doesn't send a password or vice versa.

Another possibility would be that Fortiauthenticator expects MSCHAPv2 and you send PAP (or other way around)

regards,

Sheikh  

[heriherwanto]

Dear All 

Thank you for your solution, I have follow all instruction on the 

https://docs.fortinet.com/document/fortiauthenticator/6.0.0/administration-guide/641286/remote-authe...

but, we still cannot connect using remote AD.

Here is the debug result :

2022-10-24T07:34:47.582466+07:00 FACMHP radiusd[1181]: (168) eap: EAP session adding &reply:State = 0x7200e2957407fb35
2022-10-24T07:34:47.582496+07:00 FACMHP radiusd[1181]: (168) # Executing group from file /usr/etc/raddb/sites-enabled/default
2022-10-24T07:34:47.582515+07:00 FACMHP radiusd[1181]: (168) TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
2022-10-24T07:34:47.582537+07:00 FACMHP radiusd[1181]: (168) TLS-Session-Version = "TLS 1.2"
2022-10-24T07:34:47.582569+07:00 FACMHP radiusd[1181]: (168) Sent Access-Challenge Id 180 from 192.168.100.248:1812 to 192.168.100.229:38979 length 0
2022-10-24T07:34:47.582589+07:00 FACMHP radiusd[1181]: (168) EAP-Message = 0x0107004a1900170303003f75dfc65f74643a462d704dea3c752531b189bc14dbee8575f4b02217643947587e5cb5b0227de05072f80c848ba37f4ee28b120868318dfe1d449ab964805f
2022-10-24T07:34:47.582605+07:00 FACMHP radiusd[1181]: (168) Message-Authenticator = 0x00000000000000000000000000000000
2022-10-24T07:34:47.582619+07:00 FACMHP radiusd[1181]: (168) State = 0x7200e2957407fb35c4fcb4c1472470b0
2022-10-24T07:34:47.626136+07:00 FACMHP radiusd[1181]: Waking up in 0.5 seconds.
2022-10-24T07:34:47.626255+07:00 FACMHP radiusd[1181]: (169) Received Access-Request Id 181 from 192.168.100.229:56131 to 192.168.100.248:1812 length 336
2022-10-24T07:34:47.626280+07:00 FACMHP radiusd[1181]: (169) Service-Type = Framed-User
2022-10-24T07:34:47.626296+07:00 FACMHP radiusd[1181]: (169) Framed-MTU = 1400
2022-10-24T07:34:47.626311+07:00 FACMHP radiusd[1181]: (169) User-Name = "misniru"
2022-10-24T07:34:47.626326+07:00 FACMHP radiusd[1181]: (169) State = 0x7200e2957407fb35c4fcb4c1472470b0
2022-10-24T07:34:47.626340+07:00 FACMHP radiusd[1181]: (169) NAS-Port-Id = "wlan1"
2022-10-24T07:34:47.626354+07:00 FACMHP radiusd[1181]: (169) NAS-Port-Type = Wireless-802.11
2022-10-24T07:34:47.626368+07:00 FACMHP radiusd[1181]: (169) Acct-Session-Id = "8270000d"
2022-10-24T07:34:47.626386+07:00 FACMHP radiusd[1181]: (169) Acct-Multi-Session-Id = "C4-AD-34-B4-7B-03-60-57-18-64-B6-6C-82-70-00-00-00-00-00-0D"
2022-10-24T07:34:47.626401+07:00 FACMHP radiusd[1181]: (169) Calling-Station-Id = "60-57-18-64-B6-6C"
2022-10-24T07:34:47.626427+07:00 FACMHP radiusd[1181]: (169) Called-Station-Id = "C4-AD-34-B4-7B-03:TEST PEAP FORTIAUTH"
2022-10-24T07:34:47.626449+07:00 FACMHP radiusd[1181]: (169) EAP-Message = 0x020700611900170303005600000000000000022b673a02275079016a656a4866c70df304faf29ccc234e35593e4ab7479ce21d33cb51e5bd1620ed1409112ae43f0f688801ceec4740d607b35ceb91a037856713a0af548d125fcfecd59e760266
2022-10-24T07:34:47.626463+07:00 FACMHP radiusd[1181]: (169) Message-Authenticator = 0x42ca6767d838d5730579116a811f39b4
2022-10-24T07:34:47.626477+07:00 FACMHP radiusd[1181]: (169) NAS-Identifier = "TESTRADIUS"
2022-10-24T07:34:47.626492+07:00 FACMHP radiusd[1181]: (169) NAS-IP-Address = 192.168.100.229
2022-10-24T07:34:47.626519+07:00 FACMHP radiusd[1181]: (169) # Executing section authorize from file /usr/etc/raddb/sites-enabled/default
2022-10-24T07:34:47.626575+07:00 FACMHP radiusd[1181]: (169) # Executing group from file /usr/etc/raddb/sites-enabled/default
2022-10-24T07:34:47.626600+07:00 FACMHP radiusd[1181]: (169) eap: Expiring EAP session with state 0xd038f1c3d03feb8e
2022-10-24T07:34:47.626619+07:00 FACMHP radiusd[1181]: (169) eap: Finished EAP session with state 0x7200e2957407fb35
2022-10-24T07:34:47.626638+07:00 FACMHP radiusd[1181]: (169) eap: Previous EAP request found for state 0x7200e2957407fb35, released from the list
2022-10-24T07:34:47.626737+07:00 FACMHP radiusd[1181]: (169) Virtual server inner-tunnel received request
2022-10-24T07:34:47.626763+07:00 FACMHP radiusd[1181]: (169) EAP-Message = 0x020700421a0207003d313fa34afb3e1b8d8f9df0312ba2a995ed000000000000000045f17e0bd4a1314a129d2f1caac4bf27bb1d6baa8e53dc3e006d69736e697275
2022-10-24T07:34:47.626779+07:00 FACMHP radiusd[1181]: (169) FreeRADIUS-Proxied-To = 127.0.0.1
2022-10-24T07:34:47.626792+07:00 FACMHP radiusd[1181]: (169) User-Name = "misniru"
2022-10-24T07:34:47.626807+07:00 FACMHP radiusd[1181]: (169) State = 0xd038f1c3d03feb8ece8f4c9faf23e7b7
2022-10-24T07:34:47.626821+07:00 FACMHP radiusd[1181]: (169) Service-Type = Framed-User
2022-10-24T07:34:47.626836+07:00 FACMHP radiusd[1181]: (169) Framed-MTU = 1400
2022-10-24T07:34:47.626911+07:00 FACMHP radiusd[1181]: (169) NAS-Port-Id = "wlan1"
2022-10-24T07:34:47.626927+07:00 FACMHP radiusd[1181]: (169) NAS-Port-Type = Wireless-802.11
2022-10-24T07:34:47.626941+07:00 FACMHP radiusd[1181]: (169) Acct-Session-Id = "8270000d"
2022-10-24T07:34:47.626959+07:00 FACMHP radiusd[1181]: (169) Acct-Multi-Session-Id = "C4-AD-34-B4-7B-03-60-57-18-64-B6-6C-82-70-00-00-00-00-00-0D"
2022-10-24T07:34:47.626974+07:00 FACMHP radiusd[1181]: (169) Calling-Station-Id = "60-57-18-64-B6-6C"
2022-10-24T07:34:47.626990+07:00 FACMHP radiusd[1181]: (169) Called-Station-Id = "C4-AD-34-B4-7B-03:TEST PEAP FORTIAUTH"
2022-10-24T07:34:47.627003+07:00 FACMHP radiusd[1181]: (169) NAS-Identifier = "TESTRADIUS"
2022-10-24T07:34:47.627019+07:00 FACMHP radiusd[1181]: (169) NAS-IP-Address = 192.168.100.229
2022-10-24T07:34:47.627036+07:00 FACMHP radiusd[1181]: (169) Event-Timestamp = "Oct 24 2022 07:34:47 ICT"
2022-10-24T07:34:47.627053+07:00 FACMHP radiusd[1181]: (169) WARNING: Outer and inner identities are the same. User privacy is compromised.
2022-10-24T07:34:47.627067+07:00 FACMHP radiusd[1181]: (169) server inner-tunnel {
2022-10-24T07:34:47.627088+07:00 FACMHP radiusd[1181]: (169) # Executing section authorize from file /usr/etc/raddb/sites-enabled/inner-tunnel
2022-10-24T07:34:47.627131+07:00 FACMHP radiusd[1181]: (169) &Proxy-To-Realm := LOCAL
2022-10-24T07:34:47.627197+07:00 FACMHP radiusd[1181]: (169) facauth: ===>NAS IP:192.168.100.229
2022-10-24T07:34:47.627218+07:00 FACMHP radiusd[1181]: (169) facauth: ===>Username:misniru
2022-10-24T07:34:47.627238+07:00 FACMHP radiusd[1181]: (169) facauth: WARNING: client 192.168.100.229, id=169, cannot get request arrival time.
2022-10-24T07:34:47.627280+07:00 FACMHP radiusd[1181]: (169) facauth: Found authclient from preloaded authclients list for 192.168.100.229: Mikrotik (192.168.100.229)
2022-10-24T07:34:47.630828+07:00 FACMHP radiusd[1181]: (169) facauth: Found authpolicy 'FG-MIS' for client '192.168.100.229'
2022-10-24T07:34:47.632458+07:00 FACMHP radiusd[1181]: (169) facauth: Found authclient from preloaded authclients list for 192.168.100.229: Mikrotik (192.168.100.229)
2022-10-24T07:34:47.635169+07:00 FACMHP radiusd[1181]: (169) facauth: Found authpolicy 'FG-MIS' for client '192.168.100.229'
2022-10-24T07:34:47.636763+07:00 FACMHP radiusd[1181]: (169) facauth: Client type: 0 (subtype: 0)
2022-10-24T07:34:47.636854+07:00 FACMHP radiusd[1181]: (169) facauth: Input Realm: (null) (default realm id: 2) username: misniru
2022-10-24T07:34:47.638047+07:00 FACMHP radiusd[1181]: (169) facauth: Realm not specified, default goes to Windows AD, id: 1
2022-10-24T07:34:47.638137+07:00 FACMHP radiusd[1181]: (169) facauth: FAC local user overrides, try searching local user first
2022-10-24T07:34:47.640229+07:00 FACMHP radiusd[1181]: (169) facauth: Local user not found, try searching remote user
2022-10-24T07:34:47.644987+07:00 FACMHP radiusd[1181]: (169) # Executing group from file /usr/etc/raddb/sites-enabled/inner-tunnel
2022-10-24T07:34:47.645081+07:00 FACMHP radiusd[1181]: (169) eap: Expiring EAP session with state 0xd038f1c3d03feb8e
2022-10-24T07:34:47.645102+07:00 FACMHP radiusd[1181]: (169) eap: Finished EAP session with state 0xd038f1c3d03feb8e
2022-10-24T07:34:47.645122+07:00 FACMHP radiusd[1181]: (169) eap: Previous EAP request found for state 0xd038f1c3d03feb8e, released from the list
2022-10-24T07:34:47.645163+07:00 FACMHP radiusd[1181]: (169) eap_mschapv2: PEAP: Setting 'Auth-Type := FACAUTH'
2022-10-24T07:34:47.645187+07:00 FACMHP radiusd[1181]: (169) eap_mschapv2: # Executing group from file /usr/etc/raddb/sites-enabled/inner-tunnel
2022-10-24T07:34:47.645235+07:00 FACMHP radiusd[1181]: (169) facauth: Found authclient from preloaded authclients list for 192.168.100.229: Mikrotik (192.168.100.229)
2022-10-24T07:34:47.647910+07:00 FACMHP radiusd[1181]: (169) facauth: Found authpolicy 'FG-MIS' for client '192.168.100.229'
2022-10-24T07:34:47.649560+07:00 FACMHP radiusd[1181]: (169) facauth: Client type: 0 (subtype: 0)
2022-10-24T07:34:47.649653+07:00 FACMHP radiusd[1181]: (169) facauth: Input Realm: (null) (default realm id: 2) username: misniru
2022-10-24T07:34:47.650847+07:00 FACMHP radiusd[1181]: (169) facauth: Realm not specified, default goes to Windows AD, id: 1
2022-10-24T07:34:47.650938+07:00 FACMHP radiusd[1181]: (169) facauth: FAC local user overrides, try searching local user first
2022-10-24T07:34:47.652671+07:00 FACMHP radiusd[1181]: (169) facauth: Local user not found, try searching remote user
2022-10-24T07:34:47.657902+07:00 FACMHP radiusd[1181]: (169) facauth: LDAP user found: misniru
2022-10-24T07:34:47.659177+07:00 FACMHP radiusd[1181]: (169) facauth: # Executing group from file /usr/etc/raddb/sites-enabled/inner-tunnel
2022-10-24T07:34:47.930204+07:00 FACMHP radiusd[1181]: (169) Ignoring duplicate packet from client Mikrotik port 56131 - ID: 181 due to unfinished request in component authenticate module eap_peap
2022-10-24T07:34:47.930299+07:00 FACMHP radiusd[1181]: Waking up in 0.2 seconds.
2022-10-24T07:34:48.239477+07:00 FACMHP radiusd[1181]: (169) Ignoring duplicate packet from client Mikrotik port 56131 - ID: 181 due to unfinished request in component authenticate module eap_peap
2022-10-24T07:34:48.303430+07:00 FACMHP radiusd[1181]: Waking up in 0.9 seconds.
2022-10-24T07:34:49.313335+07:00 FACMHP radiusd[1181]: Waking up in 1.4 seconds.
2022-10-24T07:34:50.006677+07:00 FACMHP radiusd[1181]: (169) facauth: Remote Windows AD user authenticated
2022-10-24T07:34:50.019922+07:00 FACMHP radiusd[1181]: (169) facauth: Authentication OK
2022-10-24T07:34:50.020005+07:00 FACMHP radiusd[1181]: (169) facauth: Setting 'Post-Auth-Type := FACAUTH'
2022-10-24T07:34:50.022121+07:00 FACMHP radiusd[1181]: (169) facauth: Updated auth log 'misniru': Windows AD user authentication(mschap) with no token successful
2022-10-24T07:34:50.022662+07:00 FACMHP radiusd[1181]: (169) eap: EAP session adding &reply:State = 0xd038f1c3d130eb8e
2022-10-24T07:34:50.022751+07:00 FACMHP radiusd[1181]: (169) } # server inner-tunnel
2022-10-24T07:34:50.022766+07:00 FACMHP radiusd[1181]: (169) Virtual server sending reply
2022-10-24T07:34:50.022788+07:00 FACMHP radiusd[1181]: (169) EAP-Message = 0x010800331a0307002e533d39463235383841414236354236444536443643373945303530314236333233323534463430353644
2022-10-24T07:34:50.022803+07:00 FACMHP radiusd[1181]: (169) Message-Authenticator = 0x00000000000000000000000000000000
2022-10-24T07:34:50.022817+07:00 FACMHP radiusd[1181]: (169) State = 0xd038f1c3d130eb8ece8f4c9faf23e7b7
2022-10-24T07:34:50.023047+07:00 FACMHP radiusd[1181]: (169) eap: EAP session adding &reply:State = 0x7200e2957508fb35
2022-10-24T07:34:50.023143+07:00 FACMHP radiusd[1181]: (169) # Executing group from file /usr/etc/raddb/sites-enabled/default
2022-10-24T07:34:50.023164+07:00 FACMHP radiusd[1181]: (169) TLS-Session-Cipher-Suite = "ECDHE-RSA-AES256-GCM-SHA384"
2022-10-24T07:34:50.023179+07:00 FACMHP radiusd[1181]: (169) TLS-Session-Version = "TLS 1.2"
2022-10-24T07:34:50.023225+07:00 FACMHP radiusd[1181]: (169) Sent Access-Challenge Id 181 from 192.168.100.248:1812 to 192.168.100.229:56131 length 0
2022-10-24T07:34:50.023246+07:00 FACMHP radiusd[1181]: (169) EAP-Message = 0x010800521900170303004775dfc65f74643a47f127bd1ad8e0c95eb858edd33cd3f8606a063cd5f3cb261b8c69027f34b8dae838ef47c86612e6586ba6527c46328b5f99df3f5e8ca52aa2be419671d4016f
2022-10-24T07:34:50.023260+07:00 FACMHP radiusd[1181]: (169) Message-Authenticator = 0x00000000000000000000000000000000
2022-10-24T07:34:50.023275+07:00 FACMHP radiusd[1181]: (169) State = 0x7200e2957508fb35c4fcb4c1472470b0
2022-10-24T07:34:50.818851+07:00 FACMHP radiusd[1181]: Waking up in 25.3 seconds.

Please let me know, if there are still missing steps

Regards,

Heri

[heriherwanto]

Dear all

Here is the video login using mschap-2

https://www.dropbox.com/s/2ye2uf3jo6bu1mk/TES%20PEAP%20FORTIAUTH.mp4?dl=0

Regards,

Heri

[Markus_M]

Hi Heri,

the video cannot be viewed without login.

From the debugs:

2022-10-24T07:34:50.022121+07:00 FACMHP radiusd[1181]: (169) facauth: Updated auth log 'misniru': Windows AD user authentication(mschap) with no token successful

It looks good but I don't know this is the same flow as in the beginning. The timestamps divert a bit more (3seconds) that it would be normal.

Best regards,

Markus

[heriherwanto]

Hi Markus

The video to show, when we success login, then back to login form again.

in the log, yes success. but always back to login dialog again.

Is there any solution

Best Regards,

Heri

[Markus_M · Accepted solution]

Hi Heri,

There is a solution, but it needs to be found.

When you login and the login is successful according to the logs, then why the SSID is asking again for a login?

From what it looks like, the Mikrotik is sending multiple access-requests via RADIUS, should get one answered and apparently gets another of the duplicated answered.

Authentication is usually serial, going one by one. Clients asks to somewhere, response comes back. No magic:

1) Windows asks the AP

2) AP asks to FAC

3) FortiAuthenticator asks to LDAP

4) LDAP sends OK

5) FAC sends OK

6) AP sends OK

7) client receives OK.

Your flow seems distorted such that the AP may not understand the OK or the Mikrotik is asking multiple times for an unknown reason.

2022-10-24T07:34:47.930204+07:00 FACMHP radiusd[1181]: (169) Ignoring duplicate packet from client Mikrotik port 56131 - ID: 181 due to unfinished request in component authenticate module eap_peap

2022-10-24T07:34:48.239477+07:00 FACMHP radiusd[1181]: (169) Ignoring duplicate packet from client Mikrotik port 56131 - ID: 181 due to unfinished request in component authenticate module eap_peap

The time it takes for FAC to authenticate the user, makes it looks like the LDAP server is taking 3 seconds to respond.

Or your FortiAuthenticator is incredibly slow:

2022-10-24T07:34:47.657902+07:00 FACMHP radiusd[1181]: (169) facauth: LDAP user found: misniru

2022-10-24T07:34:50.006677+07:00 FACMHP radiusd[1181]: (169) facauth: Remote Windows AD user authenticated

So check either of these:

- is FAC maybe out of RAM/CPU

- is your LDAP server slow

- why Mikrotik is making multiple duplicate requests

Best regards,

Markus

[heriherwanto · Accepted solution]

Dear Markus

Thank you for your suggestion.

The Problems is:

1. The user from AC is not set to "Disable change password" (After check, there is no "Null Password again"

2. The Mikrotik send multiple request (When I try using other product, then we can login to FortiAuthenticator)

Thank you for your help.

Best Regards,

Heri