| alexandergravitz |
11-04-2014 03:28 AM |
Freeradius authentication problem
Hello,
For my internship I have been given the difficult task to setup eduroam as a service provider (which works perfectly now) and as an identity provider using an LDAP server.
Authenticating with LDAP works when I do radtest but somehow it rejects the user when I try to connect externally.
Linux version: 3.2.0-4-amd64 #1 SMP Debian 3.2.60-1+deb7u3 x86_64 GNU/Linux
FreeRADIUS Version 2.1.12
Freeradius -X shows:
Code:
rad_recv: Access-Request packet from host 10.10.3.145 port 21650, id=137, length=364
User-Name = "testuser@jflifggr.be"
Framed-MTU = 1400
Called-Station-Id = "0013.1a08.73b0"
Calling-Station-Id = "0008.2250.074f"
Cisco-AVPair = "ssid=eduroam"
WISPr-Location-ID = "isocc=PT,cc=351,ac=21 ,network=eduroam"
Service-Type = Login-User
Message-Authenticator = 0xbce82d9c1777b1b1ac82616d91efbb06
EAP-Message = 0x020400901980000000861603010046100000424104fa3db75393ded88070fec0a2c41917bbec597e22ffd24dfb12fc326f088e77b2b727e89874b396a3c9fc1956544066a4bf8eafa8f092e71983de4a37f290773814030100010116030100309814b057cb8f3ad6d07ed6f49d70e91a4dbfff08f92edfbc5bf23c25121e7d7cb1bf3ce0a0bf181660d03c505734aa3a
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "1068"
NAS-Port = 1068
State = 0x2633ccae2437d58f08575ce9852c2e53
NAS-IP-Address = 10.10.3.145
server eduroam {
# Executing section authorize from file /etc/freeradius/sites-enabled/eduroam
+- entering group authorize {...}
++[request] returns notfound
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] expand: %t -> Tue Nov 4 09:55:32 2014
++[auth_log] returns ok
[suffix] Looking up realm "jflifggr.be" for User-Name = "testuser@jflifggr.be"
[suffix] Found realm "jflifggr.be"
[suffix] Adding Realm = "jflifggr.be"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 4 length 144
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/eduroam
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
TLS Length 134
[peap] Length Included
[peap] eaptls_verify returned 11
[peap] <<< TLS 1.0 Handshake [length 0046], ClientKeyExchange
[peap] TLS_accept: SSLv3 read client key exchange A
[peap] <<< TLS 1.0 ChangeCipherSpec [length 0001]
[peap] <<< TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 read finished A
[peap] >>> TLS 1.0 ChangeCipherSpec [length 0001]
[peap] TLS_accept: SSLv3 write change cipher spec A
[peap] >>> TLS 1.0 Handshake [length 0010], Finished
[peap] TLS_accept: SSLv3 write finished A
[peap] TLS_accept: SSLv3 flush data
[peap] (other): SSL negotiation finished successfully
SSL Connection Established
[peap] eaptls_process returned 13
[peap] EAPTLS_HANDLED
++[eap] returns handled
} # server eduroam
Sending Access-Challenge of id 137 to 10.10.3.145 port 21650
EAP-Message = 0x0105004119001403010001011603010030a1ae63dcf69f96eb0cdfcaa98f873b39ec5ac1477d248c408a9036b0459249e4f67a67688253dbb4c86a2bd3372b9a22
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x2633ccae2536d58f08575ce9852c2e53
Finished request 3.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.3.145 port 21650, id=138, length=226
User-Name = "testuser@jflifggr.be"
Framed-MTU = 1400
Called-Station-Id = "0013.1a08.73b0"
Calling-Station-Id = "0008.2250.074f"
Cisco-AVPair = "ssid=eduroam"
WISPr-Location-ID = "isocc=PT,cc=351,ac=21 ,network=eduroam"
Service-Type = Login-User
Message-Authenticator = 0x3b5a9cea9218bbc0a7a0ce608c2f2dd0
EAP-Message = 0x020500061900
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "1068"
NAS-Port = 1068
State = 0x2633ccae2536d58f08575ce9852c2e53
NAS-IP-Address = 10.10.3.145
server eduroam {
# Executing section authorize from file /etc/freeradius/sites-enabled/eduroam
+- entering group authorize {...}
++[request] returns notfound
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] expand: %t -> Tue Nov 4 09:55:32 2014
++[auth_log] returns ok
[suffix] Looking up realm "jflifggr.be" for User-Name = "testuser@jflifggr.be"
[suffix] Found realm "jflifggr.be"
[suffix] Adding Realm = "jflifggr.be"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 5 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/eduroam
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/peap
[eap] processing type peap
[peap] processing EAP-TLS
[peap] Received TLS ACK
[peap] ACK handshake is finished
[peap] eaptls_verify returned 3
[peap] eaptls_process returned 3
[peap] EAPTLS_SUCCESS
[peap] Session established. Decoding tunneled attributes.
[peap] Peap state TUNNEL ESTABLISHED
++[eap] returns handled
} # server eduroam
Sending Access-Challenge of id 138 to 10.10.3.145 port 21650
EAP-Message = 0x0106002b190017030100200d47e3c9e926ef0e1d15bef89242f70c8fdfe7e55dc110c6a09b08039d8be2f3
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x2633ccae2235d58f08575ce9852c2e53
Finished request 4.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.3.145 port 21650, id=139, length=316
User-Name = "testuser@jflifggr.be"
Framed-MTU = 1400
Called-Station-Id = "0013.1a08.73b0"
Calling-Station-Id = "0008.2250.074f"
Cisco-AVPair = "ssid=eduroam"
WISPr-Location-ID = "isocc=PT,cc=351,ac=21 ,network=eduroam"
Service-Type = Login-User
Message-Authenticator = 0xc565289a7753e824adfac8bc47d15752
EAP-Message = 0x0206006019001703010020d891b611a3730981580bbc13c7fbacd3168c3f2c3f93fb474982848a16e7ce18170301003047daed54e40e1bfd3e3c8ed2fe4587986a7760350dbb54ab358bd8e9d8ffb69ffdd52f51b6d5c852925c3e18409ad8e6
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "1068"
NAS-Port = 1068
State = 0x2633ccae2235d58f08575ce9852c2e53
NAS-IP-Address = 10.10.3.145
server eduroam {
# Executing section authorize from file /etc/freeradius/sites-enabled/eduroam
+- entering group authorize {...}
++[request] returns notfound
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] expand: %t -> Tue Nov 4 09:55:32 2014
++[auth_log] returns ok
[suffix] Looking up realm "jflifggr.be" for User-Name = "testuser@jflifggr.be"
[suffix] Found realm "jflifggr.be"
[suffix] Adding Realm = "jflifggr.be"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 6 length 96
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/eduroam
+- 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] Peap state WAITING FOR INNER IDENTITY
[peap] Identity - testuser@jflifggr.be
[peap] Got inner identity 'testuser@jflifggr.be'
[peap] Setting default EAP type for tunneled EAP session.
[peap] Got tunneled request
EAP-Message = 0x0206001901627665726d65756c656e40696d696e64732e6265
server eduroam {
[peap] Setting User-Name to testuser@jflifggr.be
Sending tunneled request
EAP-Message = 0x0206001901627665726d65756c656e40696d696e64732e6265
FreeRADIUS-Proxied-To = 127.0.0.1
User-Name = "testuser@jflifggr.be"
Framed-MTU = 1400
Called-Station-Id = "0013.1a08.73b0"
Calling-Station-Id = "0008.2250.074f"
Cisco-AVPair = "ssid=eduroam"
WISPr-Location-ID = "isocc=PT,cc=351,ac=21 ,network=eduroam"
Service-Type = Login-User
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "1068"
NAS-Port = 1068
NAS-IP-Address = 10.10.3.145
Operator-Name = "1jflifggr.be"
server eduroam-inner-tunnel {
# Executing section authorize from file /etc/freeradius/sites-enabled/eduroam-inner-tunnel
+- entering group authorize {...}
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] expand: %t -> Tue Nov 4 09:55:32 2014
++[auth_log] returns ok
++[files] returns noop
[ldap] performing user authorization for testuser@jflifggr.be
[ldap] expand: (uid=%u) -> (uid=testuser@jflifggr.be)
[ldap] expand: ou=users,dc=jflifggr,dc=be -> ou=users,dc=jflifggr,dc=be
[ldap] ldap_get_conn: Checking Id: 0
[ldap] ldap_get_conn: Got Id: 0
[ldap] attempting LDAP reconnection
[ldap] (re)connect to 10.10.3.146:389, authentication 0
[ldap] bind as cn=admin,dc=jflifggr,dc=be/pAsSwOrD to 10.10.3.146:389
[ldap] waiting for bind result ...
[ldap] Bind was successful
[ldap] performing search in ou=users,dc=jflifggr,dc=be, with filter (uid=testuser@jflifggr.be)
[ldap] checking if remote access for testuser@jflifggr.be is allowed by uid
[ldap] No default NMAS login sequence
[ldap] looking for check items in directory...
[ldap] userPassword -> User-Password == "{MD5}fhg+bs/87YV0dMl0mpHNrA=="
[ldap] userPassword -> Password-With-Header == "{MD5}fhg+bs/87YV0dMl0mpHNrA=="
[ldap] looking for reply items in directory...
[ldap] user testuser@jflifggr.be authorized to use remote access
[ldap] ldap_release_conn: Release Id: 0
++[ldap] returns ok
++[mschap] returns noop
[pap] No clear-text password in the request. Not performing PAP.
++[pap] returns noop
ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user
Failed to authenticate the user.
Login incorrect: [testuser@jflifggr.be/<no User-Password attribute>] (from client eduroam-ap-v4 port 1068 cli 0008.2250.074f via TLS tunnel)
} # server eduroam-inner-tunnel
[peap] Got tunneled reply code 3
[peap] Got tunneled reply RADIUS code 3
[peap] Tunneled authentication was rejected.
[peap] FAILURE
++[eap] returns handled
} # server eduroam
Sending Access-Challenge of id 139 to 10.10.3.145 port 21650
EAP-Message = 0x0107002b19001703010020f7b99c3506c2eb626de00897c600e21cd24b6c1c6f32e2874d4a8a576001c375
Message-Authenticator = 0x00000000000000000000000000000000
State = 0x2633ccae2334d58f08575ce9852c2e53
Finished request 5.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 10.10.3.145 port 21650, id=140, length=300
User-Name = "testuser@jflifggr.be"
Framed-MTU = 1400
Called-Station-Id = "0013.1a08.73b0"
Calling-Station-Id = "0008.2250.074f"
Cisco-AVPair = "ssid=eduroam"
WISPr-Location-ID = "isocc=PT,cc=351,ac=21 ,network=eduroam"
Service-Type = Login-User
Message-Authenticator = 0x50629148d6122e1a24f6f5097e7d1732
EAP-Message = 0x0207005019001703010020855c55a57d1ac780ea1c12a2d09c1152fe60a933e8d3544824849675eea12d581703010020aed9d9a6e861ae2d24efd27c5ea62ab5a7139c4ace6069c46e48334ca10a73c5
NAS-Port-Type = Wireless-802.11
Cisco-NAS-Port = "1068"
NAS-Port = 1068
State = 0x2633ccae2334d58f08575ce9852c2e53
NAS-IP-Address = 10.10.3.145
server eduroam {
# Executing section authorize from file /etc/freeradius/sites-enabled/eduroam
+- entering group authorize {...}
++[request] returns notfound
[auth_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] /var/log/freeradius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.3.145/auth-detail-20141104
[auth_log] expand: %t -> Tue Nov 4 09:55:32 2014
++[auth_log] returns ok
[suffix] Looking up realm "jflifggr.be" for User-Name = "testuser@jflifggr.be"
[suffix] Found realm "jflifggr.be"
[suffix] Adding Realm = "jflifggr.be"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 7 length 80
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
# Executing group from file /etc/freeradius/sites-enabled/eduroam
+- 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] Peap state send tlv failure
[peap] Received EAP-TLV response.
[peap] The users session was previously rejected: returning reject (again.)
[peap] *** This means you need to read the PREVIOUS messages in the debug output
[peap] *** to find out the reason why the user was rejected.
[peap] *** Look for "reject" or "fail". Those earlier messages will tell you.
[peap] *** what went wrong, and how to fix the problem.
[eap] Handler failed in EAP/peap
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Login incorrect: [testuser@jflifggr.be/<via Auth-Type = EAP>] (from client eduroam-ap-v4 port 1068 cli 0008.2250.074f)
} # server eduroam
Using Post-Auth-Type Reject
# Executing group from file /etc/freeradius/sites-enabled/eduroam
+- entering group REJECT {...}
[reply_log] expand: /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d -> /var/log/freeradius/radacct/10.10.3.145/reply-detail-20141104
[reply_log] /var/log/freeradius/radacct/%{Client-IP-Address}/reply-detail-%Y%m%d expands to /var/log/freeradius/radacct/10.10.3.145/reply-detail-20141104
[reply_log] expand: %t -> Tue Nov 4 09:55:32 2014
++[reply_log] returns ok
Delaying reject of request 6 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 6
Sending Access-Reject of id 140 to 10.10.3.145 port 21650
EAP-Message = 0x04070004
Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.9 seconds.
Cleaning up request 0 ID 134 with timestamp +23
Cleaning up request 1 ID 135 with timestamp +23
Cleaning up request 2 ID 136 with timestamp +23
Cleaning up request 3 ID 137 with timestamp +23
Cleaning up request 4 ID 138 with timestamp +23
Cleaning up request 5 ID 139 with timestamp +23
Waking up in 1.0 seconds.
Thanks in advance for helping me out.
Regards,
Alexander |
