Logging mschap error when send_error=yes
Currently I'm configuring new servers for an eventual 3.0.x migration, and decided to take a look at password-change. I have not got that far yet, just as far as playing around with the server behavior when EAP-MCHAPv2 is set to send_error = yes, which is a prerequisite for that. As soon as this is turned on we seem to lose the ability to log the exact error code returned by ntlm_auth, and this is actually one of the more critical log messages we need to detect locked accounts. With send_error=yes the flow out of the inner tunnel after a bad ntlm auth is as follows: (8) : ERROR: upn_mschap: Program returned code (1) and output 'Logon failure (0xc000006d)' (8) : Debug: upn_mschap: External script failed (8) : ERROR: upn_mschap: External script says: Logon failure (0xc000006d) (8) : ERROR: upn_mschap: MS-CHAP2-Response is incorrect (8) : Debug: modsingle[authenticate]: returned from upn_mschap (rlm_mschap) for request 8 (8) : Debug: [upn_mschap] = reject (8) : Debug: } # Auth-Type MS-CHAP = reject (8) : Debug: MSCHAP-Error:E=691 R=0 C=792471a3e2e250631e1353c26afb0b8f V=3 M=Authentication failed (8) : Debug: Found new challenge from MS-CHAP-Error: err=691 retry=0 challenge=792471a3e2e250631e1353c26afb0b8f (8) : ERROR: MSCHAP Failure (8) : Debug: eap: Sending EAP Request (code 1) ID 9 length 81 (8) : Debug: eap: EAP session adding &reply:State = 0xb5db88f6b4d292e4 (8) : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 8 (8) : Debug: [eap] = handled (8) : Debug: } # Auth-Type EAP = handled (8) : Debug: } # server eduroam_idpi_inner ... and there seems to be pretty much no toehold by which to get an unlang statement into that to store or log MSCHAP-Error or Module-Failure-Message. I haven't tried use_tunneled_reply as it is marked as deprecated in favor of the new state handling, but I've tried just about everything else I can think of. With send_error=no, default internal logging would normally log the ntlm_auth result, or we could catch it in the inner tunnel's post-auth Reject section: (8) : ERROR: upn_mschap: Program returned code (1) and output 'Logon failure (0xc000006d)' (8) : Debug: upn_mschap: External script failed (8) : ERROR: upn_mschap: External script says: Logon failure (0xc000006d) (8) : ERROR: upn_mschap: MS-CHAP2-Response is incorrect (8) : Debug: modsingle[authenticate]: returned from upn_mschap (rlm_mschap) for request 8 (8) : Debug: [upn_mschap] = reject (8) : Debug: } # Auth-Type MS-CHAP = reject (8) : Debug: eap: Sending EAP Failure (code 4) ID 8 length 4 (8) : Debug: eap: Freeing handler (8) : Debug: modsingle[authenticate]: returned from eap (rlm_eap) for request 8 (8) : Debug: [eap] = reject (8) : Debug: } # Auth-Type EAP = reject (8) : Debug: Failed to authenticate the user (8) : Debug: Using Post-Auth-Type Reject (8) : Debug: # Executing group from file /etc/raddb/eduroam_idpi.conf (8) : Debug: Post-Auth-Type REJECT { So my first question is, am I missing a trick that would allow me to log the ntlm_auth result? The second thing is that, since the failure seems to promulgate down to the EAP layer in a different fashion (a new challenge seems to always be issued and the failure delayed until later packets, even when retries are not allowed) the normal logs get filled with the usual "The users session was previously rejected" stanza, which in this particular case is not very helpful since there's not much to read above them (and it's a lot of syslog bulk for a common logon failure.) No real question there, just an observation. The third thing is, while looking further into this I noticed the current code for dealing with locked accounts appears to be entirely based off SMB-Account-CTRL, which does not seem to exist when authing against an actual AD server rather than a local Samba setup. For password changes there is code to use the text returned from ntlm_auth instead, but locked or disabled accounts just end up sending 691/"Authentication failed" instead of the actual error. So I quick-hacked the C code to pass on the code/message for locks and disables. Second question: is there any particular reason why the code is the way it is, or is it just a not-implemented-yet situation?
On Nov 2, 2015, at 1:12 PM, Brian Julin <BJulin@clarku.edu> wrote:
Currently I'm configuring new servers for an eventual 3.0.x migration, and decided to take a look at password-change. I have not got that far yet, just as far as playing around with the server behavior when EAP-MCHAPv2 is set to send_error = yes, which is a prerequisite for that. As soon as this is turned on we seem to lose the ability to log the exact error code returned by ntlm_auth, and this is actually one of the more critical log messages we need to detect locked accounts.
With send_error=yes the flow out of the inner tunnel after a bad ntlm auth is as follows: ... ... and there seems to be pretty much no toehold by which to get an unlang statement into that to store or log MSCHAP-Error or Module-Failure-Message.
Just put a statement into the eduroam_idpi_inner virtual server. You will need to to catch the "handled" return code from the EAP module. That code says to stop processing the section, and retune. So.. server eduroam_idpi_inner { ... authenticate { ... Auth-Type EAP { eap { handled = 1 # don't return right away } if (reply:MS-CHAP-Error) { # do logging of MS-CHAP-Error } handled # which is what EAP tried to return above. } }
The second thing is that, since the failure seems to promulgate down to the EAP layer in a different fashion (a new challenge seems to always be issued and the failure delayed until later packets, even when retries are not allowed) the normal logs get filled with the usual "The users session was previously rejected" stanza, which in this particular case is not very helpful since there's not much to read above them (and it's a lot of syslog bulk for a common logon failure.)
That message was changed to be a debug-only message. It's available now in the v3.0.x branch in git, or wait for 3.0.1..
The third thing is, while looking further into this I noticed the current code for dealing with locked accounts appears to be entirely based off SMB-Account-CTRL, which does not seem to exist when authing against an actual AD server rather than a local Samba setup.
OK.
For password changes there is code to use the text returned from ntlm_auth instead, but locked or disabled accounts just end up sending 691/"Authentication failed" instead of the actual error. So I quick-hacked the C code to pass on the code/message for locks and disables.
Do you have a patch?
Second question: is there any particular reason why the code is the way it is, or is it just a not-implemented-yet situation?
Not done yet. As always, patches are welcome. Alan DeKok.
Alan DeKok wrote:
Just put a statement into the eduroam_idpi_inner virtual server. You will need to to catch the "handled" return code from the EAP module. That code says to stop processing the section, and retune.
So..
server eduroam_idpi_inner { ... authenticate { ...
Auth-Type EAP { eap { handled = 1 # don't return right away }
if (reply:MS-CHAP-Error) { # do logging of MS-CHAP-Error }
handled # which is what EAP tried to return above. }
}
That worked splendidly, thank you. Though it turned out the attribute populated was request:Module-Failure-Message.
For password changes there is code to use the text returned from ntlm_auth instead, but locked or disabled accounts just end up sending 691/"Authentication failed" instead of the actual error. So I quick-hacked the C code to pass on the code/message for locks and disables.
Do you have a patch?
The next time I do a pull I'll try to clean what I have up into something presentable. Thanks again.
participants (2)
-
Alan DeKok -
Brian Julin