Logins against AD failing in *most* cases. Can see why, but don't *understand* why.

Meyers, Dan d.meyers at lancaster.ac.uk
Tue Dec 1 17:23:11 CET 2009


Still trying to get our FreeRADIUS system working nicely after the AD
upgrade to server 2008. Compiling Samba to version 3.4.3 from source
fixed our ntlm_auth issue, but most users were still unable to connect.
I have 2 examples here, one of a user who failed to connect, one of a
user who succeeded (you may wish to skip to the end of the mail for some
things i've noted, and only then look back at all the debug output ;) ).

Firstly, the last packet of my auth attempt after the EAP negotiation
has been done, where my MSCHAPv2 password gets authenticated against the
domain (sorry for the wall of text):

rad_recv: Access-Request packet from host 148.88.249.136 port 32770,
id=107, length=325
  User-Name = "user1 at lancaster.ac.uk"
  Calling-Station-Id = "00-19-D2-7A-32-37"
  Called-Station-Id = "00-22-55-EF-12-70:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
  EAP-Message =
0x0209007b19001703010070617a586349258a547c06634d0fddf4595a1335caed798858
583e7abb666d98687d584b69e92570c58f855442a0e4cfbee722a8e408ec1c952f97b3ef
286ed3b611ff5799f587048f82e762c79a90e9b20c01e5a1ed175726e2db392b9e7b5a4a
bf57e82a3fd0caf93f164fc3d14b547f
  State = 0x358f4053338659fabf419b83279b13d2
  Message-Authenticator = 0x57a488c36caaca604135f6e50b03a561
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] Looking up realm "lancaster.ac.uk" for User-Name =
"user1 at lancaster.ac.uk"
[suffix] Found realm "lancaster.ac.uk"
[suffix] Adding Stripped-User-Name = "user1"
[suffix] Adding Realm = "lancaster.ac.uk"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> user1 at lancaster.ac.uk
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> FALSE
[eap] EAP packet type response id 9 length 123
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] EAP type mschapv2
[peap] Got tunneled request
  EAP-Message =
0x020900521a0209004d31edbf49d61deaee3bc54da173c7fa87f3000000000000000088
ad0f8484b8ba14e9d5a5f87ebbd0dc0995dcfacd4c8947006d657965727364406c616e63
61737465722e61632e756b
server  {
  PEAP: Setting User-Name to user1 at lancaster.ac.uk
Sending tunneled request
  EAP-Message =
0x020900521a0209004d31edbf49d61deaee3bc54da173c7fa87f3000000000000000088
ad0f8484b8ba14e9d5a5f87ebbd0dc0995dcfacd4c8947006d657965727364406c616e63
61737465722e61632e756b
  FreeRADIUS-Proxied-To = 127.0.0.1
  User-Name = "user1 at lancaster.ac.uk"
  State = 0x87479817874e82241c779ef3ac5e3935
  Calling-Station-Id = "00-19-D2-7A-32-37"
  Called-Station-Id = "00-22-55-EF-12-70:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
server inner-tunnel {
+- entering group authorize {...}
++[mschap] returns noop
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> user1 at lancaster.ac.uk
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(.*)\@(.*)$/)
  expand: %{User-Name} -> user1 at lancaster.ac.uk
? Evaluating ("%{User-Name}" =~ /^(.*)\@(.*)$/) -> TRUE
++? if ("%{User-Name}" =~ /^(.*)\@(.*)$/) -> TRUE
++- entering if ("%{User-Name}" =~ /^(.*)\@(.*)$/) {...}
  expand: %{1} -> user1
  expand: %{2} -> lancaster.ac.uk
+++[request] returns noop
++- if ("%{User-Name}" =~ /^(.*)\@(.*)$/) returns noop
[eap] EAP packet type response id 9 length 82
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{Stripped-User-Name} -> user1
[sql]   expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-none}} -> user1
[sql] sql_set_user escaped user --> 'user1'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, UserName, Attribute, Value, Op   FROM
radcheck   WHERE Username = '%{SQL-User-Name}'   ORDER BY id -> SELECT
id, UserName, Attribute, Value, Op   FROM radcheck   WHERE Username =
'user1'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 5
[sql]   expand: SELECT GroupName FROM radusergroup WHERE
UserName='%{SQL-User-Name}' -> SELECT GroupName FROM radusergroup WHERE
UserName='user1'
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 1
[sql]   expand: SELECT id, GroupName, Attribute, Value, op   FROM
radgroupcheck   WHERE GroupName = '%{Sql-Group}'   ORDER BY id -> SELECT
id, GroupName, Attribute, Value, op   FROM radgroupcheck   WHERE
GroupName = 'ISS-Networking'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 5
[sql] User found in group ISS-Networking
[sql]   expand: SELECT id, GroupName, Attribute, Value, op   FROM
radgroupreply   WHERE GroupName = '%{Sql-Group}'   ORDER BY id -> SELECT
id, GroupName, Attribute, Value, op   FROM radgroupreply   WHERE
GroupName = 'ISS-Networking'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 4 , fields = 5
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] +- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured.  Cannot create LM-Password.
[mschap] No Cleartext-Password configured.  Cannot create NT-Password.
[mschap] Told to do MS-CHAPv2 for user1 at lancaster.ac.uk with NT-Password
[mschap] WARNING: Deprecated conditional expansion ":-".  See "man
unlang" for details
[mschap]  expand: --username=%{Stripped-User-Name:-%{mschap:User-Name}}
-> --username=user1
[mschap]  mschap2: e5
[mschap]  expand: --challenge=%{mschap:Challenge:-00} ->
--challenge=ca93a4a6d7ac3f9d
[mschap]  expand: --nt-response=%{mschap:NT-Response:-00} ->
--nt-response=88ad0f8484b8ba14e9d5a5f87ebbd0dc099537ac2d95fe1b
Exec-Program output: NT_KEY: 9EF58004B6228C9E7E779AB6572FE8AC
Exec-Program-Wait: plaintext: NT_KEY: 9EF58004B6228C9E7E779AB6572FE8AC
Exec-Program: returned: 0
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  EAP-Message =
0x010a00331a0309002e533d463034323630444131373738334245363735373245423537
30443231353043464136363633463533
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0x87479817864d82241c779ef3ac5e3935
[peap] Got tunneled reply RADIUS code 11
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  EAP-Message =
0x010a00331a0309002e533d463034323630444131373738334245363735373245423537
30443231353043464136363633463533
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0x87479817864d82241c779ef3ac5e3935
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 107 to 148.88.249.136 port 32770
  EAP-Message =
0x010a005b19001703010050d87da9543e146acad57c1956c44cb8cdbed378259e40ad29
ce2d903b0afb4f16124050b10c3c9a78eeeaaf00d61ced25488db9196a9c8c91a1bc7cf4
a7ac1fbbe71266009749655783ba673171e80abb
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0x358f4053328559fabf419b83279b13d2
Finished request 416.

That's all I ever get for my user account in the logs. The full auth
attempt went from Access-Request id 100 through to Access-Request id
107. The server never seems to get a response to the ending
Access-Challenge id 107. Conversely, my colleague who has a working
account, gets the following (again, from the beginning of the packet
where his MSCHAPv2 password is actually authenticated against the
domain):

rad_recv: Access-Request packet from host 148.88.249.136 port 32770,
id=132, length=337
  User-Name = "lancs\\user2"
  Calling-Station-Id = "00-1C-BF-C7-FB-4C"
  Called-Station-Id = "00-22-90-B3-F9-50:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
  EAP-Message =
0x02090090190017030100207b2d004369d3679747d1848f1660014fee49cc8b6c1b77b7
8ff1e89dc59f00681703010060a88555a1f6dec5ee9ec73123bd768ab4f8bf917ca647c3
78c18aae92ac6fb8de80e1d9992b20c9dfff91eb20600a758748ae792f80c314ebfe2abc
29b5961652b1a5d0b14578e0484c87db03d36d0c11cf8b6a620cebc5ac6aa8e7d744dff1
79
  State = 0x7623a625712abf8ef354537bc6756aba
  Message-Authenticator = 0x39f424f4c84dcd7991a423af3ca3f18c
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "lancs\user2", looking up realm NULL
[suffix] Found realm "NULL"
[suffix] Adding Stripped-User-Name = "lancs\user2"
[suffix] Adding Realm = "NULL"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++- entering if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) {...}
  expand: %{2} -> user2
  expand: %{1} -> lancs
+++[request] returns ok
++- if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) returns ok
[eap] EAP packet type response id 9 length 144
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] EAP type mschapv2
[peap] Got tunneled request
  EAP-Message =
0x020900491a02090044313384674726b9231d92d1b16ae3381616000000000000000059
e5bb803ee23f3f68530828759579c6cfb2d0b92eb4a1ed006c616e63735c686f66666d61
6e6e
server  {
  PEAP: Setting User-Name to lancs\user2
Sending tunneled request
  EAP-Message =
0x020900491a02090044313384674726b9231d92d1b16ae3381616000000000000000059
e5bb803ee23f3f68530828759579c6cfb2d0b92eb4a1ed006c616e63735c686f66666d61
6e6e
  FreeRADIUS-Proxied-To = 127.0.0.1
  User-Name = "lancs\\user2"
  State = 0xfb1c3a72fb152075c4ee252347450ff8
  Calling-Station-Id = "00-1C-BF-C7-FB-4C"
  Called-Station-Id = "00-22-90-B3-F9-50:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
server inner-tunnel {
+- entering group authorize {...}
++[mschap] returns noop
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++- entering if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) {...}
  expand: %{2} -> user2
  expand: %{1} -> lancs
+++[request] returns noop
++- if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) returns noop
++? if ("%{User-Name}" =~ /^(.*)\@(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\@(.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(.*)\@(.*)$/) -> FALSE
[eap] EAP packet type response id 9 length 73
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{Stripped-User-Name} -> user2
[sql]   expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-none}} -> user2
[sql] sql_set_user escaped user --> 'user2'
rlm_sql (sql): Reserving sql socket id: 4
[sql]   expand: SELECT id, UserName, Attribute, Value, Op   FROM
radcheck   WHERE Username = '%{SQL-User-Name}'   ORDER BY id -> SELECT
id, UserName, Attribute, Value, Op   FROM radcheck   WHERE Username =
'user2'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 5
[sql]   expand: SELECT GroupName FROM radusergroup WHERE
UserName='%{SQL-User-Name}' -> SELECT GroupName FROM radusergroup WHERE
UserName='user2'
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 1
[sql]   expand: SELECT id, GroupName, Attribute, Value, op   FROM
radgroupcheck   WHERE GroupName = '%{Sql-Group}'   ORDER BY id -> SELECT
id, GroupName, Attribute, Value, op   FROM radgroupcheck   WHERE
GroupName = 'ISS-Networking'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 5
[sql] User found in group ISS-Networking
[sql]   expand: SELECT id, GroupName, Attribute, Value, op   FROM
radgroupreply   WHERE GroupName = '%{Sql-Group}'   ORDER BY id -> SELECT
id, GroupName, Attribute, Value, op   FROM radgroupreply   WHERE
GroupName = 'ISS-Networking'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 4 , fields = 5
rlm_sql (sql): Released sql socket id: 4
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[mschapv2] +- entering group MS-CHAP {...}
[mschap] No Cleartext-Password configured.  Cannot create LM-Password.
[mschap] No Cleartext-Password configured.  Cannot create NT-Password.
[mschap] Told to do MS-CHAPv2 for user2 with NT-Password
[mschap] WARNING: Deprecated conditional expansion ":-".  See "man
unlang" for details
[mschap]  expand: --username=%{Stripped-User-Name:-%{mschap:User-Name}}
-> --username=user2
[mschap]  mschap2: 44
[mschap]  expand: --challenge=%{mschap:Challenge:-00} ->
--challenge=95f65d33af4ba23c4
[mschap]  expand: --nt-response=%{mschap:NT-Response:-00} ->
--nt-response=59e5bb803ee23f3f68530828759579c6cfb2d0b968a5cb2e
Exec-Program output: NT_KEY: 52B7AEF2B433075AF22CAD4C4D25A39C
Exec-Program-Wait: plaintext: NT_KEY: 52B7AEF2B433075AF22CAD4C4D25A39C
Exec-Program: returned: 0
[mschap] adding MS-CHAPv2 MPPE keys
++[mschap] returns ok
MSCHAP Success
++[eap] returns handled
} # server inner-tunnel
[peap] Got tunneled reply code 11
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  EAP-Message =
0x010a00331a0309002e533d303842374531424436333542394339323836383235463439
46323742463341314230364541303738
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0xfb1c3a72fa162075c4ee252347450ff8
[peap] Got tunneled reply RADIUS code 11
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  EAP-Message =
0x010a00331a0309002e533d303842374531424436333542394339323836383235463439
46323742463341314230364541303738
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0xfb1c3a72fa162075c4ee252347450ff8
[peap] Got tunneled Access-Challenge
++[eap] returns handled
Sending Access-Challenge of id 132 to 148.88.249.136 port 32770
  EAP-Message =
0x010a005b19001703010050fcdf518ed3fcffd6407e0186e7062c0c1669cc92a93a01da
4285a7093a143d7956dc6bc4bfdf05b3b756a3194099fc8322dbf08d460087a414c96fa8
5fd8ee6f1ba96b29ce477d4885827c0e61427b52
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0x7623a6257e29bf8ef354537bc6756aba
Finished request 686.

Going to the next request
Waking up in 2.3 seconds.
rad_recv: Access-Request packet from host 148.88.249.136 port 32770,
id=133, length=273
  User-Name = "lancs\\user2"
  Calling-Station-Id = "00-1C-BF-C7-FB-4C"
  Called-Station-Id = "00-22-90-B3-F9-50:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
  EAP-Message =
0x020a005019001703010020563086272f8d270b6fba82ba179ca5635f5aae98fd72dade
74902244e8c87d0e170301002002a746be3302e56dee560cc2928a262b5d1560060e33fa
7647245e97023981d4
  State = 0x7623a6257e29bf8ef354537bc6756aba
  Message-Authenticator = 0x58cb28942c70c52b0eec7f08340d6f9e
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "lancs\user2", looking up realm NULL
[suffix] Found realm "NULL"
[suffix] Adding Stripped-User-Name = "lancs\user2"
[suffix] Adding Realm = "NULL"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++- entering if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) {...}
  expand: %{2} -> user2
  expand: %{1} -> lancs
+++[request] returns ok
++- if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) returns ok
[eap] EAP packet type response id 10 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] EAP type mschapv2
[peap] Got tunneled request
  EAP-Message = 0x020a00061a03
server  {
  PEAP: Setting User-Name to lancs\user2
Sending tunneled request
  EAP-Message = 0x020a00061a03
  FreeRADIUS-Proxied-To = 127.0.0.1
  User-Name = "lancs\\user2"
  State = 0xfb1c3a72fa162075c4ee252347450ff8
  Calling-Station-Id = "00-1C-BF-C7-FB-4C"
  Called-Station-Id = "00-22-90-B3-F9-50:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
server inner-tunnel {
+- entering group authorize {...}
++[mschap] returns noop
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++- entering if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) {...}
  expand: %{2} -> user2
  expand: %{1} -> lancs
+++[request] returns noop
++- if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) returns noop
++? if ("%{User-Name}" =~ /^(.*)\@(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\@(.*)$/) -> FALSE
++? if ("%{User-Name}" =~ /^(.*)\@(.*)$/) -> FALSE
[eap] EAP packet type response id 10 length 6
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[files] returns noop
[sql]   expand: %{Stripped-User-Name} -> user2
[sql]   expand: %{%{Stripped-User-Name}:-%{%{User-Name}:-none}} -> user2
[sql] sql_set_user escaped user --> 'user2'
rlm_sql (sql): Reserving sql socket id: 3
[sql]   expand: SELECT id, UserName, Attribute, Value, Op   FROM
radcheck   WHERE Username = '%{SQL-User-Name}'   ORDER BY id -> SELECT
id, UserName, Attribute, Value, Op   FROM radcheck   WHERE Username =
'user2'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 5
[sql]   expand: SELECT GroupName FROM radusergroup WHERE
UserName='%{SQL-User-Name}' -> SELECT GroupName FROM radusergroup WHERE
UserName='user2'
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 1 , fields = 1
[sql]   expand: SELECT id, GroupName, Attribute, Value, op   FROM
radgroupcheck   WHERE GroupName = '%{Sql-Group}'   ORDER BY id -> SELECT
id, GroupName, Attribute, Value, op   FROM radgroupcheck   WHERE
GroupName = 'ISS-Networking'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 0 , fields = 5
[sql] User found in group ISS-Networking
[sql]   expand: SELECT id, GroupName, Attribute, Value, op   FROM
radgroupreply   WHERE GroupName = '%{Sql-Group}'   ORDER BY id -> SELECT
id, GroupName, Attribute, Value, op   FROM radgroupreply   WHERE
GroupName = 'ISS-Networking'   ORDER BY id
rlm_sql_postgresql: Status: PGRES_TUPLES_OK
rlm_sql_postgresql: query affected rows = 4 , fields = 5
rlm_sql (sql): Released sql socket id: 3
++[sql] returns ok
++[expiration] returns noop
++[logintime] returns noop
[pap] WARNING! No "known good" password found for the user.
Authentication may fail because of this.
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/mschapv2
[eap] processing type mschapv2
[eap] Freeing handler
++[eap] returns ok
Login OK: [lancs\\user2] (from client LWAPP port 29 cli
00-1C-BF-C7-FB-4C via TLS tunnel)
+- entering group post-auth {...}
  expand: %{request:User-Name} -> lancs\user2
++[outer.reply] returns noop
} # server inner-tunnel
[peap] Got tunneled reply code 2
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  EAP-Message = 0x030a0004
  Message-Authenticator = 0x00000000000000000000000000000000
  User-Name = "user2"
[peap] Got tunneled reply RADIUS code 2
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  EAP-Message = 0x030a0004
  Message-Authenticator = 0x00000000000000000000000000000000
  User-Name = "user2"
[peap] Tunneled authentication was successful.
[peap] SUCCESS
[peap] Saving tunneled attributes for later
++[eap] returns handled
Sending Access-Challenge of id 133 to 148.88.249.136 port 32770
  User-Name = "lancs\\user2"
  EAP-Message =
0x010b002b190017030100202b2fb168f98ef8c49538a4b92b3b133a369a842a51af704a
9ec1e5bb55ef1edd
  Message-Authenticator = 0x00000000000000000000000000000000
  State = 0x7623a6257f28bf8ef354537bc6756aba
Finished request 687.

Going to the next request
Waking up in 2.2 seconds.
rad_recv: Access-Request packet from host 148.88.249.136 port 32770,
id=134, length=273
  User-Name = "lancs\\user2"
  Calling-Station-Id = "00-1C-BF-C7-FB-4C"
  Called-Station-Id = "00-22-90-B3-F9-50:eduroam"
  NAS-Port = 29
  NAS-IP-Address = 148.88.249.136
  NAS-Identifier = "open-lwapp03"
  Airespace-Wlan-Id = 2
  Service-Type = Framed-User
  Framed-MTU = 1300
  NAS-Port-Type = Wireless-802.11
  Tunnel-Type:0 = VLAN
  Tunnel-Medium-Type:0 = IEEE-802
  Tunnel-Private-Group-Id:0 = "431"
  EAP-Message =
0x020b005019001703010020c4ebc0c571cb9874782be1f3eee5ec17592737a4ce0d5271
831d72e629f620cc17030100203b27019cda8f0086564d29017a26ed5dd0c4427f27908a
b67ebc45cc075d782e
  State = 0x7623a6257f28bf8ef354537bc6756aba
  Message-Authenticator = 0x0c959b9ceeb3e2bd3fad22181c785443
+- entering group authorize {...}
++[preprocess] returns ok
[suffix] No '@' in User-Name = "lancs\user2", looking up realm NULL
[suffix] Found realm "NULL"
[suffix] Adding Stripped-User-Name = "lancs\user2"
[suffix] Adding Realm = "NULL"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/)
  expand: %{User-Name} -> lancs\user2
? Evaluating ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++? if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) -> TRUE
++- entering if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) {...}
  expand: %{2} -> user2
  expand: %{1} -> lancs
+++[request] returns ok
++- if ("%{User-Name}" =~ /^(.*)\\\\(.*)$/) returns ok
[eap] EAP packet type response id 11 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] eaptls_verify returned 7
[peap] Done initial handshake
[peap] eaptls_process returned 7
[peap] EAPTLS_OK
[peap] Session established.  Decoding tunneled attributes.
[peap] Received EAP-TLV response.
[peap] Success
[peap] Using saved attributes from the original Access-Accept
[eap] Freeing handler
++[eap] returns ok
Login OK: [lancs\\user2] (from client LWAPP port 29 cli
00-1C-BF-C7-FB-4C)
+- entering group post-auth {...}
++[exec] returns noop
Sending Access-Accept of id 134 to 148.88.249.136 port 32770
  Tunnel-Type:0 := VLAN
  Tunnel-Medium-Type:0 := 802
  Tunnel-Private-Group-Id:0 := "432"
  Reply-Message := "ISS-Networking Role"
  User-Name = "user2"
  MS-MPPE-Recv-Key =
0xfaf2a2f2ef1fca4b0be9e1fd2e2d0e695d6a40d286b33bf57dcbd66b0a2520f1
  MS-MPPE-Send-Key =
0xef9dbb374b16caa2ac7e194ba6acbb3318af5e7afa7e0ca9c9f53f895a0c1155
  EAP-Message = 0x030b0004
  Message-Authenticator = 0x00000000000000000000000000000000
Finished request 688.

Now I can see a number of differences here. First is that he is authing
against lancs//username, and i'm doing username at lancaster.ac.uk. However
I have tried using lancs//username on my machine, and still get no joy.
Both should work, as we have configuration for both on the radius server
and they both worked before the upgrade to server 2008 on the AD.

Secondly, my colleague's machine actually responds to the
Access-Challenge sent at the end of the packet where the ntlm_auth is
done, whereas my machine does not. This is the crucial point I think.
Without this final response the Access-Accept is never sent back. My
colleague is using Windows XP with the Intel Pro/Set Wireless drivers
and supplicant. If he changes to using the XP inbuilt supplicant,
everything stops working. I am on Windows 7 using the inbuilt
supplicant. As best we can tell, this is the problematic difference. The
Intel supplicant is presumably getting and responding to the
Access-Challenge where the windows inbuilt supplicant is not, but I
don't know why or what could be causing it. My machine also doesn't
respond to the Access-Challenge under Ubuntu 9.10, using the Gnome
inbuilt supplicant.

Given that the call to ntlm_auth does a --request-nt-key, which is then
used in further communication with the client, the best I can come up
with is that in some way the key returned by the server has changed from
2003 to 2008. The clients are then for some reason rejecting this
change. I am at a bit of a loss, however, as to what exactly this change
is and how I go about rectifying it. I was hoping somebody else might
have had similar experiences and be able to point me in the right
direction. At this point I don't actually know if the issue is with my
radius config somewhere, and a simple 1 line option will make things
work, or if I need to get our Windows admins to look at settings on the
AD, which I know absolutely nothing about.

Thanks in advance.

--
Dan Meyers
Network Specialist, Lancaster University
E-Mail: d.meyers at lancaster.ac.uk






More information about the Freeradius-Users mailing list