802.1x Strange active directory with MSCHAP issue

31 Oct 2009

      Hello List,

I'm trying to set up freeradius for users to authenticate against Active
Directory. The problem is that it seems to be that the client tries and
somehow succeeds but then it sends Access-Challenge again.

ntlm_auth from commandline works fine. If someone could pls take a look at
it, and point me to the problem source.

# freeradius -Xx
[snip]
rad_recv: Access-Request packet from host 10.X.X.X port 1645, id=170,
length=272
        User-Name = "DOMAIN\\USER_NAME"
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "00-17-0E-18-6F-02"
        Calling-Station-Id = "00-22-68-10-E9-9D"
        EAP-Message =
0x0209006219001703010057dbed00fdb2ac2eebb7a9749b351455a9e261b8101109c397d32e7feda500fe9ab5be56aa8f0f553b050009e48c8201f1ead322025b3b996d9e78b3906eddcbef18660af56ffb77a3d66552c6bdf6b8a4acadb1e68ff4d0
        Message-Authenticator = 0x060bb882f3abde473de477df5ec50d83
        NAS-Port-Type = Ethernet
        NAS-Port = 50203
        NAS-Port-Id = "FastEthernet2/3"
        Called-Station-Id = "00170E186F0"
        State = 0x651daded6314b44b23e510c28ece2035
        NAS-IP-Address = 10.X.X.X
Thu Oct 29 10:08:14 2009 : Info: +- entering group authorize {...}
Thu Oct 29 10:08:14 2009 : Info: ++[preprocess] returns ok
Thu Oct 29 10:08:14 2009 : Info: [auth_log]     expand:
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d ->
/var/log/freeradius/radacct/10.X.X.X/auth-detail-20091029
Thu Oct 29 10:08:14 2009 : Info: [auth_log]
/var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands
to /var/log/freeradius/radacct/10.X.X.X/auth-detail-20091029
Thu Oct 29 10:08:14 2009 : Info: [auth_log]     expand: %t -> Thu Oct 29
10:08:14 2009
Thu Oct 29 10:08:14 2009 : Info: ++[auth_log] returns ok
Thu Oct 29 10:08:14 2009 : Info: ++[mschap] returns noop
Thu Oct 29 10:08:14 2009 : Info: [IPASS] No '/' in User-Name =
"DOMAIN\USER_NAME", looking up realm NULL
Thu Oct 29 10:08:14 2009 : Info: [IPASS] No such realm "NULL"
Thu Oct 29 10:08:14 2009 : Info: ++[IPASS] returns noop
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Looking up realm "DOMAIN" for
User-Name = "DOMAIN\USER_NAME"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Found realm "DOMAIN"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Adding Stripped-User-Name =
"USER_NAME"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Adding Realm = "DOMAIN"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Authentication realm is LOCAL.
Thu Oct 29 10:08:14 2009 : Info: ++[ntdomain] returns ok
Thu Oct 29 10:08:14 2009 : Info: [eap] EAP packet type response id 9 length
98
Thu Oct 29 10:08:14 2009 : Info: [eap] Continuing tunnel setup.
Thu Oct 29 10:08:14 2009 : Info: ++[eap] returns ok
Thu Oct 29 10:08:14 2009 : Info: Found Auth-Type = EAP
Thu Oct 29 10:08:14 2009 : Info: +- entering group authenticate {...}
Thu Oct 29 10:08:14 2009 : Info: [eap] Request found, released from the list
Thu Oct 29 10:08:14 2009 : Info: [eap] EAP/peap
Thu Oct 29 10:08:14 2009 : Info: [eap] processing type peap
Thu Oct 29 10:08:14 2009 : Info: [peap] processing EAP-TLS
Thu Oct 29 10:08:14 2009 : Info: [peap] eaptls_verify returned 7
Thu Oct 29 10:08:14 2009 : Info: [peap] Done initial handshake
Thu Oct 29 10:08:14 2009 : Info: [peap] eaptls_process returned 7
Thu Oct 29 10:08:14 2009 : Info: [peap] EAPTLS_OK
Thu Oct 29 10:08:14 2009 : Info: [peap] Session established.  Decoding
tunneled attributes.
  PEAP tunnel data in 0000: 1a 02 09 00 46 31 ed 83 a9 6d bc 8a 55 45 16 3f
  PEAP tunnel data in 0010: 41 13 c8 eb 17 08 00 00 00 00 00 00 00 00 2a 0f
  PEAP tunnel data in 0020: 3a 33 97 72 a7 f0 09 9e 9d 13 00 64 df f8 d0 13
  PEAP tunnel data in 0030: f5 0c 46 d8 94 0d 00 49 42 4d 45 4d 45 41 5c 68
  PEAP tunnel data in 0040: 75 65 34 39 31 62 7a
Thu Oct 29 10:08:14 2009 : Info: [peap] EAP type mschapv2
Thu Oct 29 10:08:14 2009 : Info: [peap] Got tunneled request
        EAP-Message =
0x0209004b1a0209004631ed83a96dbc8a5545163f4113c8eb170800000000000000002a0f3a339772a7f0099e9d130064dff8d013f50c46d8940d0049424d454d45415c687565343931627a
server  {
Thu Oct 29 10:08:14 2009 : Debug:   PEAP: Setting User-Name to
DOMAIN\USER_NAME
Sending tunneled request
        EAP-Message =
0x0209004b1a0209004631ed83a96dbc8a5545163f4113c8eb170800000000000000002a0f3a339772a7f0099e9d130064dff8d013f50c46d8940d0049424d454d45415c687565343931627a
        FreeRADIUS-Proxied-To = 127.0.0.1
        User-Name = "DOMAIN\\USER_NAME"
        State = 0xd4de0819d4d7123b2e87e4d75e5d8f2c
        Service-Type = Framed-User
        Framed-MTU = 1500
        Called-Station-Id = "00-17-0E-18-6F-02"
        Called-Station-Id = "00170E186F0"
        Calling-Station-Id = "00-22-68-10-E9-9D"
        NAS-Port-Type = Ethernet
        NAS-Port = 50203
        NAS-Port-Id = "FastEthernet2/3"
        NAS-IP-Address = 10.X.X.X
server inner-tunnel {
Thu Oct 29 10:08:14 2009 : Info: +- entering group authorize {...}
Thu Oct 29 10:08:14 2009 : Info: ++[mschap] returns noop
Thu Oct 29 10:08:14 2009 : Info: [IPASS] No '/' in User-Name =
"DOMAIN\USER_NAME", looking up realm NULL
Thu Oct 29 10:08:14 2009 : Info: [IPASS] No such realm "NULL"
Thu Oct 29 10:08:14 2009 : Info: ++[IPASS] returns noop
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Looking up realm "DOMAIN" for
User-Name = "DOMAIN\USER_NAME"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Found realm "DOMAIN"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Adding Stripped-User-Name =
"USER_NAME"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Adding Realm = "DOMAIN"
Thu Oct 29 10:08:14 2009 : Info: [ntdomain] Authentication realm is LOCAL.
Thu Oct 29 10:08:14 2009 : Info: ++[ntdomain] returns ok
Thu Oct 29 10:08:14 2009 : Info: [eap] EAP packet type response id 9 length
75
Thu Oct 29 10:08:14 2009 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Thu Oct 29 10:08:14 2009 : Info: ++[eap] returns updated
Thu Oct 29 10:08:14 2009 : Info: ++[files] returns noop
Thu Oct 29 10:08:14 2009 : Info: ++[expiration] returns noop
Thu Oct 29 10:08:14 2009 : Info: ++[logintime] returns noop
Thu Oct 29 10:08:14 2009 : Info: Found Auth-Type = EAP
Thu Oct 29 10:08:14 2009 : Info: +- entering group authenticate {...}
Thu Oct 29 10:08:14 2009 : Info: [eap] Request found, released from the list
Thu Oct 29 10:08:14 2009 : Info: [eap] EAP/mschapv2
Thu Oct 29 10:08:14 2009 : Info: [eap] processing type mschapv2
Thu Oct 29 10:08:14 2009 : Info: [mschapv2] +- entering group MS-CHAP {...}
Thu Oct 29 10:08:14 2009 : Info: [mschap] Told to do MS-CHAPv2 for USER_NAME
with NT-Password
Thu Oct 29 10:08:14 2009 : Info: [mschap]       expand:
--username=%{mschap:User-Name:-None} -> --username=USER_NAME
Thu Oct 29 10:08:14 2009 : Info: [mschap]       expand:
--domain=%{mschap:NT-Domain:-SOMETHING.DOMAIN.NET} -> --domain=DOMAIN
Thu Oct 29 10:08:14 2009 : Info: [mschap]  mschap2: 7e
Thu Oct 29 10:08:14 2009 : Info: [mschap]       expand:
--challenge=%{mschap:Challenge:-00} -> --challenge=713fa3f8ce6f4b85
Thu Oct 29 10:08:14 2009 : Info: [mschap]       expand:
--nt-response=%{mschap:NT-Response:-00} ->
--nt-response=2a0f3a339772a7f0099e9d130064dff8d013f50c46d8940d
Thu Oct 29 10:08:14 2009 : Debug: Exec-Program output: NT_KEY:
D3EF67E4795483D8C8ECCD398929BD83
Thu Oct 29 10:08:14 2009 : Debug: Exec-Program-Wait: plaintext: NT_KEY:
D3EF67E4795483D8C8ECCD398929BD83
Thu Oct 29 10:08:14 2009 : Debug: Exec-Program: returned: 0
Thu Oct 29 10:08:14 2009 : Info: ++[mschap] returns ok
Thu Oct 29 10:08:14 2009 : Debug: MSCHAP Success
Thu Oct 29 10:08:14 2009 : Info: ++[eap] returns handled
} # server inner-tunnel
Thu Oct 29 10:08:14 2009 : Info: [peap] Got tunneled reply code 11
        EAP-Message =
0x010a00331a0309002e533d30354537393244373946463135444637443039333735354230303941433932373038353432363132
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xd4de0819d5d4123b2e87e4d75e5d8f2c
Thu Oct 29 10:08:14 2009 : Info: [peap] Got tunneled reply RADIUS code 11
        EAP-Message =
0x010a00331a0309002e533d30354537393244373946463135444637443039333735354230303941433932373038353432363132
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xd4de0819d5d4123b2e87e4d75e5d8f2c
Thu Oct 29 10:08:14 2009 : Info: [peap] Got tunneled Access-Challenge
  PEAP tunnel data out 0000: 1a 03 09 00 2e 53 3d 30 35 45 37 39 32 44 37 39
  PEAP tunnel data out 0010: 46 46 31 35 44 46 37 44 30 39 33 37 35 35 42 30
  PEAP tunnel data out 0020: 30 39 41 43 39 32 37 30 38 35 34 32 36 31 32
Thu Oct 29 10:08:14 2009 : Info: ++[eap] returns handled
Sending Access-Challenge of id 170 to 10.X.X.X port 1645
        EAP-Message =
0x010a004a1900170301003f7a8338c8443aab925281cc99d62063e56bce7edc3a0fe618ef8cae86ffa7bdb310d88c30c000f2402e10963c02a43374f9b12818980ce2821a51182b132654
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x651daded6217b44b23e510c28ece2035
Thu Oct 29 10:08:14 2009 : Info: Finished request 8.

[snip]

Thanks in advance,
cU

802.1x Strange active directory with MSCHAP issue

sea you