EAP-MD5 testing with radeapclient and eapol_test

6 Sep 2010

      Hi All,

I have a proxy setup ( proxy server 192.168.6.134) where users are proxied
to home server (192.168.7.40).
Host IP address = 192.168.6.181
FreeRADIUS  version 2.1.9

User authentication using radclient works fine when I issue following
command

echo "User-Name=raduser@mytest.com,Password=pass123" | radclient
192.168.6.134 auth testing123

I get following response on my proxy server

rad_recv: Access-Accept packet from host 192.168.7.40 port 1812, id=104,
length=68
Proxy-State = 0x3737
Framed-Protocol = PPP
Service-Type = Framed-User
Class = 0x52a505b1000001370001c0a8072801cb4d87ddbf246a0000000000000016

I try the same test to work out with EAP using following command:

echo "User-Name=raduser@mytest.com
,Password=pass123,EAP-Code=Response,EAP-Id=210,EAP-Type-Identity=
raduser@mytest.com" | radeapclient -x 192.168.6.134 auth testing123

I see following output on proxy server:

rad_recv: Access-Request packet from host 192.168.6.181 port 32771, id=108,
length=107
User-Name = "raduser@mytest.com"
User-Password = "pass123"
EAP-Message = 0x02d2001a0172616475736572406e65766973746573742e636f6d
Message-Authenticator = 0xe61561c7667d60c2fbc37709b16e8193
Mon Sep 6 06:48:30 2010 : Info: +- entering group authorize {...}
Mon Sep 6 06:48:30 2010 : Info: ++[preprocess] returns ok
Mon Sep 6 06:48:30 2010 : Info: ++[chap] returns noop
Mon Sep 6 06:48:30 2010 : Info: ++[mschap] returns noop
Mon Sep 6 06:48:30 2010 : Info: [suffix] Looking up realm "mytest.com" for
User-Name = "raduser@mytest.com"
Mon Sep 6 06:48:30 2010 : Info: [suffix] Found realm "mytest.com"
Mon Sep 6 06:48:30 2010 : Info: [suffix] Adding Stripped-User-Name =
"raduser"
Mon Sep 6 06:48:30 2010 : Info: [suffix] Adding Realm = "mytest.com"
Mon Sep 6 06:48:30 2010 : Info: [suffix] Proxying request from user raduser
to realm mytest.com
Mon Sep 6 06:48:30 2010 : Info: [suffix] Preparing to proxy authentication
request to realm "mytest.com"
Mon Sep 6 06:48:30 2010 : Info: ++[suffix] returns updated
Mon Sep 6 06:48:30 2010 : Info: [eap] Request is supposed to be proxied to
Realm mytest.com. Not doing EAP.
Mon Sep 6 06:48:30 2010 : Info: ++[eap] returns noop
Mon Sep 6 06:48:30 2010 : Info: ++[unix] returns notfound
Mon Sep 6 06:48:30 2010 : Info: [files] users: Matched entry DEFAULT at line
195
Mon Sep 6 06:48:30 2010 : Info: [files] expand: %{User-Name} ->
raduser@mytest.com
Mon Sep 6 06:48:30 2010 : Info: ++[files] returns ok
Mon Sep 6 06:48:30 2010 : Info: ++[expiration] returns noop
Mon Sep 6 06:48:30 2010 : Info: ++[logintime] returns noop
Mon Sep 6 06:48:30 2010 : Info: ++[pap] returns noop
Mon Sep 6 06:48:30 2010 : Info: WARNING: Empty pre-proxy section. Using
default return values.

Mon Sep 6 06:48:30 2010 : Info: Proxying request 0 to home server
192.168.7.40 port 1812
Sending Access-Request of id 40 to 192.168.7.40 port 1812
User-Name = "raduser"
User-Password = "pass123"
EAP-Message = 0x02d2001a0172616475736572406e65766973746573742e636f6d
Message-Authenticator = 0x00000000000000000000000000000000
NAS-IP-Address = 192.168.6.181
Proxy-State = 0x313038
Mon Sep 6 06:48:30 2010 : Debug: Going to the next request
Mon Sep 6 06:48:30 2010 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Accept packet from host 192.168.7.40 port 1812, id=40,
length=69
Proxy-State = 0x313038
Framed-Protocol = PPP
Service-Type = Framed-User
Class = 0x52a605b2000001370001c0a8072801cb4d87ddbf246a0000000000000017
Mon Sep 6 06:48:30 2010 : Info: +- entering group post-proxy {...}
Mon Sep 6 06:48:30 2010 : Info: [force_username] expand: %{User-Name} ->
raduser@mytest.com
Mon Sep 6 06:48:30 2010 : Debug: force_username: Added attribute User-Name
with value 'raduser@mytest.com'
Mon Sep 6 06:48:30 2010 : Info: ++[force_username] returns ok
Mon Sep 6 06:48:30 2010 : Info: [eap] No pre-existing handler found
Mon Sep 6 06:48:30 2010 : Info: ++[eap] returns noop
Mon Sep 6 06:48:30 2010 : Info: Found Auth-Type = Accept
Mon Sep 6 06:48:30 2010 : Info: Auth-Type = Accept, accepting the user
Mon Sep 6 06:48:30 2010 : Info: +- entering group post-auth {...}
Mon Sep 6 06:48:30 2010 : Info: ++[exec] returns noop
Sending Access-Accept of id 108 to 192.168.6.181 port 32771
Framed-Protocol = PPP
Service-Type = Framed-User
Class = 0x52a605b2000001370001c0a8072801cb4d87ddbf246a0000000000000017
User-Name = "raduser@mytest.com"

When I use eapol_test client to using following command:
eapol_test -c /tmp/eapol.conf -a 192.168.6.134 -p 1812 -s testing123 -r 1

eapol.conf is as follows
network={
key_mgmt=NONE
eap=MD5
identity="raduser@mytest.com"
password="pass123"
}

I see following output on my proxy server:

Mon Sep 6 06:53:49 2010 : Info: Proxying request 0 to home server
192.168.7.40 port 1812
Sending Access-Request of id 166 to 192.168.7.40 port 1812
User-Name = "raduser"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0200001a0172616475736572406e65766973746573742e636f6d
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x30
Mon Sep 6 06:53:49 2010 : Debug: Going to the next request
Mon Sep 6 06:53:49 2010 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Challenge packet from host 192.168.7.40 port 1812, id=166,
length=109
Proxy-State = 0x30
Session-Timeout = 6
EAP-Message =
0x0101002304101f3bc497bfe2cfaf507a66218e4dcb01524f4f54544553544c41424144
State = 0x1a2902ae000001370001c0a8072800000003235c233800
Message-Authenticator = 0x467eeb430357cbddf194719353853d80
Mon Sep 6 06:53:49 2010 : Info: +- entering group post-proxy {...}
Mon Sep 6 06:53:49 2010 : Info: [force_username] expand: %{User-Name} ->
raduser@mytest.com
Mon Sep 6 06:53:49 2010 : Debug: force_username: Added attribute User-Name
with value 'raduser@mytest.com'
Mon Sep 6 06:53:49 2010 : Info: ++[force_username] returns ok
Mon Sep 6 06:53:49 2010 : Info: [eap] No pre-existing handler found
Mon Sep 6 06:53:49 2010 : Info: ++[eap] returns noop
Sending Access-Challenge of id 0 to 192.168.6.181 port 32771
Session-Timeout = 6
EAP-Message =
0x0101002304101f3bc497bfe2cfaf507a66218e4dcb01524f4f54544553544c41424144
State = 0x1a2902ae000001370001c0a8072800000003235c233800
Message-Authenticator = 0x00000000000000000000000000000000
User-Name = "raduser@mytest.com"
Mon Sep 6 06:53:49 2010 : Info: Finished request 0.
Mon Sep 6 06:53:49 2010 : Debug: Going to the next request
Mon Sep 6 06:53:49 2010 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.6.181 port 32771, id=1,
length=171
User-Name = "raduser@mytest.com"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0201001604100ff84736f21760abada91fdb828e888c
State = 0x1a2902ae000001370001c0a8072800000003235c233800
Message-Authenticator = 0xe1da93d7d4f4d4b68cf9ef4333a1f8eb
Mon Sep 6 06:53:49 2010 : Info: +- entering group authorize {...}
Mon Sep 6 06:53:49 2010 : Info: ++[preprocess] returns ok
Mon Sep 6 06:53:49 2010 : Info: ++[chap] returns noop
Mon Sep 6 06:53:49 2010 : Info: ++[mschap] returns noop
Mon Sep 6 06:53:49 2010 : Info: [suffix] Looking up realm "mytest.com" for
User-Name = "raduser@mytest.com"
Mon Sep 6 06:53:49 2010 : Info: [suffix] Found realm "mytest.com"
Mon Sep 6 06:53:49 2010 : Info: [suffix] Adding Stripped-User-Name =
"raduser"
Mon Sep 6 06:53:49 2010 : Info: [suffix] Adding Realm = "mytest.com"
Mon Sep 6 06:53:49 2010 : Info: [suffix] Proxying request from user raduser
to realm mytest.com
Mon Sep 6 06:53:49 2010 : Info: [suffix] Preparing to proxy authentication
request to realm "mytest.com"
Mon Sep 6 06:53:49 2010 : Info: ++[suffix] returns updated
Mon Sep 6 06:53:49 2010 : Info: [eap] Request is supposed to be proxied to
Realm mytest.com. Not doing EAP.
Mon Sep 6 06:53:49 2010 : Info: ++[eap] returns noop
Mon Sep 6 06:53:49 2010 : Info: ++[unix] returns notfound
Mon Sep 6 06:53:49 2010 : Info: [files] users: Matched entry DEFAULT at line
195
Mon Sep 6 06:53:49 2010 : Info: [files] expand: %{User-Name} ->
raduser@mytest.com
Mon Sep 6 06:53:49 2010 : Info: ++[files] returns ok
Mon Sep 6 06:53:49 2010 : Info: ++[expiration] returns noop
Mon Sep 6 06:53:49 2010 : Info: ++[logintime] returns noop
Mon Sep 6 06:53:49 2010 : Info: ++[pap] returns noop
Mon Sep 6 06:53:49 2010 : Info: WARNING: Empty pre-proxy section. Using
default return values.
Sending Access-Request of id 177 to 192.168.7.40 port 1812
User-Name = "raduser"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0201001604100ff84736f21760abada91fdb828e888c
State = 0x1a2902ae000001370001c0a8072800000003235c233800
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x31
Mon Sep 6 06:53:49 2010 : Info: Proxying request 1 to home server
192.168.7.40 port 1812
Sending Access-Request of id 177 to 192.168.7.40 port 1812
User-Name = "raduser"
NAS-IP-Address = 127.0.0.1
Calling-Station-Id = "02-00-00-00-00-01"
Framed-MTU = 1400
NAS-Port-Type = Wireless-802.11
Connect-Info = "CONNECT 11Mbps 802.11b"
EAP-Message = 0x0201001604100ff84736f21760abada91fdb828e888c
State = 0x1a2902ae000001370001c0a8072800000003235c233800
Message-Authenticator = 0x00000000000000000000000000000000
Proxy-State = 0x31
Mon Sep 6 06:53:49 2010 : Debug: Going to the next request
Mon Sep 6 06:53:49 2010 : Debug: Waking up in 0.9 seconds.
rad_recv: Access-Reject packet from host 192.168.7.40 port 1812, id=177,
length=47
Proxy-State = 0x31
EAP-Message = 0x04010004
Message-Authenticator = 0x9ce0e5c3b355540c348cbff29f5f40f2
Mon Sep 6 06:53:49 2010 : Info: +- entering group post-proxy {...}
Mon Sep 6 06:53:49 2010 : Info: [force_username] expand: %{User-Name} ->
raduser@mytest.com
Mon Sep 6 06:53:49 2010 : Debug: force_username: Added attribute User-Name
with value 'raduser@mytest.com'
Mon Sep 6 06:53:49 2010 : Info: ++[force_username] returns ok
Mon Sep 6 06:53:49 2010 : Info: [eap] No pre-existing handler found
Mon Sep 6 06:53:49 2010 : Info: ++[eap] returns noop
Mon Sep 6 06:53:49 2010 : Info: Using Post-Auth-Type Reject
Mon Sep 6 06:53:49 2010 : Info: +- entering group REJECT {...}
Mon Sep 6 06:53:49 2010 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> raduser@mytest.com
Mon Sep 6 06:53:49 2010 : Debug: attr_filter: Matched entry DEFAULT at line
11
Mon Sep 6 06:53:49 2010 : Info: ++[attr_filter.access_reject] returns
updated
Mon Sep 6 06:53:49 2010 : Info: Delaying reject of request 1 for 1 seconds
Mon Sep 6 06:53:49 2010 : Debug: Going to the next request
Mon Sep 6 06:53:49 2010 : Debug: Waking up in 0.9 seconds.
Mon Sep 6 06:53:50 2010 : Info: Sending delayed reject for request 1
Sending Access-Reject of id 1 to 192.168.6.181 port 32771
EAP-Message = 0x04010004
Message-Authenticator = 0x00000000000000000000000000000000
Mon Sep 6 06:53:50 2010 : Debug: Waking up in 3.9 seconds.
Mon Sep 6 06:53:54 2010 : Info: Cleaning up request 0 ID 0 with timestamp
+48
Mon Sep 6 06:53:54 2010 : Debug: Waking up in 0.9 seconds.
Mon Sep 6 06:53:55 2010 : Info: Cleaning up request 1 ID 1 with timestamp
+48
Mon Sep 6 06:53:55 2010 : Info: Ready to process requests.

I have never succedded with eapol_test. I doubt on NAS-IP-Address attribute
in Access=Request which is 127.0.0.1.
Can some body point me where am I going wrong?

-- 
Chidanand Gangur
Pune.