[strongSwan] Strongswan with freeradius on Debian server
Sabrina Louison-francois
sabrina.louison-francois at ens-cachan.fr
Thu Apr 25 10:03:11 CEST 2013
Le 25/04/2013 09:11, Noel Kuntze a écrit :
> Hello,
> You might want to enable file logging with diverse parameters then. It
> always gives a clue on what goes wrong.
>
> Regards,
> Noel
The important here is my Radius Server log. Whatever I have in my
ipsec.secrets on my client configuration the password crypt stay the
same: [ldap] userPassword -> Password-With-Header == "{crypt}ZO0YOg0GnG1eA"
So I think that there is no password send to the radius server.
* Server Strongswan
Apr 25 09:12:59 serv-vpn charon: 01[NET] received packet: from
192.168.110.65[500] to 192.168.10.8[500] (708 bytes)
Apr 25 09:12:59 serv-vpn charon: 01[ENC] parsed IKE_SA_INIT request 0 [
SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
Apr 25 09:12:59 serv-vpn charon: 01[IKE] 192.168.110.65 is initiating an
IKE_SA
Apr 25 09:12:59 serv-vpn charon: 01[ENC] generating IKE_SA_INIT response
0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) N(MULT_AUTH) ]
Apr 25 09:12:59 serv-vpn charon: 01[NET] sending packet: from
192.168.10.8[500] to 192.168.110.65[500] (440 bytes)
Apr 25 09:12:59 serv-vpn charon: 09[NET] received packet: from
192.168.110.65[4500] to 192.168.10.8[4500] (380bytes)
Apr 25 09:12:59 serv-vpn charon: 09[ENC] parsed IKE_AUTH request 1 [ IDi
N(INIT_CONTACT) CERTREQ SA TSi TSr N(MOBIKE_SUP) N(NO_ADD_ADDR)
N(MULT_AUTH) N(EAP_ONLY) ]
Apr 25 09:12:59 serv-vpn charon: 09[IKE] received cert request for "C=AT"
Apr 25 09:12:59 serv-vpn charon: 09[CFG] looking for peer configs
matching 192.168.10.8[%any]...192.168.110.65[ 192.168.110.65]
Apr 25 09:12:59 serv-vpn charon: 09[CFG] selected peer config 'road'
Apr 25 09:12:59 serv-vpn charon: 09[IKE] initiating EAP_IDENTITY method
(id 0x00)
Apr 25 09:12:59 serv-vpn charon: 09[IKE] peer supports MOBIKE
Apr 25 09:12:59 serv-vpn charon: 09[IKE] authentication of 'C=AT,
ST='.', O='.', OU='.', CN=Serveur-de-VPN' (myself) with RSA signature
successful
Apr 25 09:12:59 serv-vpn charon: 09[IKE] sending end entity cert "C=AT,
ST='.', O='.', OU='.', CN=Serveur-de-VPN"
Apr 25 09:12:59 serv-vpn charon: 09[ENC] generating IKE_AUTH response 1
[ IDr CERT AUTH EAP/REQ/ID ]
Apr 25 09:12:59 serv-vpn charon: 09[NET] sending packet: from
192.168.10.8[4500] to 192.168.110.65[4500] (1036 bytes)
Apr 25 09:12:59 serv-vpn charon: 16[NET] received packet: from
192.168.110.65[4500] to 192.168.10.8[4500] (92 bytes)
Apr 25 09:12:59 serv-vpn charon: 16[ENC] parsed IKE_AUTH request 2 [
EAP/RES/ID ]
Apr 25 09:12:59 serv-vpn charon: 16[IKE] received EAP identity 'slouison'
Apr 25 09:12:59 serv-vpn charon: 16[CFG] sending RADIUS Access-Request
to server 'primary'
Apr 25 09:12:59 serv-vpn charon: 16[CFG] received RADIUS
Access-Challenge from server 'primary'
Apr 25 09:12:59 serv-vpn charon: 16[IKE] initiating EAP_PEAP method (id
0x01)
Apr 25 09:12:59 serv-vpn charon: 16[ENC] generating IKE_AUTH response 2
[ EAP/REQ/PEAP ]
Apr 25 09:12:59 serv-vpn charon: 16[NET] sending packet: from
192.168.10.8[4500] to 192.168.110.65[4500] (76 bytes)
Apr 25 09:12:59 serv-vpn charon: 10[NET] received packet: from
192.168.110.65[4500] to 192.168.10.8[4500] (76 bytes)
Apr 25 09:12:59 serv-vpn charon: 10[ENC] parsed IKE_AUTH request 3 [
EAP/RES/NAK ]
Apr 25 09:12:59 serv-vpn charon: 10[CFG] sending RADIUS Access-Request
to server 'primary'
Apr 25 09:13:00 serv-vpn charon: 10[CFG] received RADIUS Access-Reject
from server 'primary'
Apr 25 09:13:00 serv-vpn charon: 10[IKE] RADIUS authentication of
'slouison' failed
Apr 25 09:13:00 serv-vpn charon: 10[IKE] EAP method EAP_PEAP failed for
peer 192.168.110.65
Apr 25 09:13:00 serv-vpn charon: 10[ENC] generating IKE_AUTH response 3
[ EAP/FAIL ]
Apr 25 09:13:00 serv-vpn charon: 10[NET] sending packet: from
192.168.10.8[4500] to 192.168.110.65[4500] (76 bytes)
* Client
initiating IKE_SA home[3] to 192.168.10.8
generating IKE_SA_INIT request 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP) ]
sending packet: from 192.168.110.65[500] to 192.168.10.8[500] (708 bytes)
received packet: from 192.168.10.8[500] to 192.168.110.65[500] (440 bytes)
parsed IKE_SA_INIT response 0 [ SA KE No N(NATD_S_IP) N(NATD_D_IP)
N(MULT_AUTH) ]
sending cert request for "C=AT"
no IDi configured, fall back on IP address
establishing CHILD_SA home
generating IKE_AUTH request 1 [ IDi N(INIT_CONTACT) CERTREQ SA TSi TSr
N(MOBIKE_SUP) N(NO_ADD_ADDR) N(MULT_AUTH) N(EAP_ONLY) ]
sending packet: from 192.168.110.65[4500] to 192.168.10.8[4500] (380 bytes)
received packet: from 192.168.10.8[4500] to 192.168.110.65[4500] (1036
bytes)
parsed IKE_AUTH response 1 [ IDr CERT AUTH EAP/REQ/ID ]
received end entity cert "C=AT, ST='.', O='.', OU='.', CN=Serveur-de-VPN"
using certificate "C=AT, ST='.', O='.', OU='.', CN=Serveur-de-VPN"
using trusted ca certificate "C=AT"
checking certificate status of "C=AT, ST='.', O='.', OU='.',
CN=Serveur-de-VPN"
certificate status is not available
reached self-signed root ca with a path length of 0
authentication of 'C=AT, ST='.', O='.', OU='.', CN=Serveur-de-VPN' with
RSA signature successful
server requested EAP_IDENTITY (id 0x00), sending 'slouison'
generating IKE_AUTH request 2 [ EAP/RES/ID ]
sending packet: from 192.168.110.65[4500] to 192.168.10.8[4500] (92 bytes)
received packet: from 192.168.10.8[4500] to 192.168.110.65[4500] (76 bytes)
parsed IKE_AUTH response 2 [ EAP/REQ/PEAP ]
server requested EAP_PEAP authentication (id 0x01)
requesting EAP_RADIUS authentication, sending EAP_NAK
generating IKE_AUTH request 3 [ EAP/RES/NAK ]
sending packet: from 192.168.110.65[4500] to 192.168.10.8[4500] (76 bytes)
received packet: from 192.168.10.8[4500] to 192.168.110.65[4500] (76 bytes)
parsed IKE_AUTH response 3 [ EAP/FAIL ]
received EAP_FAILURE, EAP authentication failed
establishing connection 'home' failed
*Radius server
rad_recv: Access-Request packet from host 192.168.10.8 port 45584,
id=42, length=147
User-Name = "login"
NAS-Port-Type = Virtual
Service-Type = Framed-User
NAS-Port = 8
NAS-Port-Id = "road"
NAS-IP-Address = 192.168.10.8
Called-Station-Id = "192.168.10.8[4500]"
Calling-Station-Id = "192.168.110.65[4500]"
EAP-Message = 0x0200000d01736c6f7569736f6e
NAS-Identifier = "serv-tests"
Message-Authenticator = 0x7fbf79cddc3461ead95e2067042a02a0
Thu Apr 25 09:24:09 2013 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Thu Apr 25 09:24:09 2013 : Info: +- entering group authorize {...}
Thu Apr 25 09:24:09 2013 : Info: ++[preprocess] returns ok
Thu Apr 25 09:24:09 2013 : Info: ++[chap] returns noop
Thu Apr 25 09:24:09 2013 : Info: ++[mschap] returns noop
Thu Apr 25 09:24:09 2013 : Info: ++[digest] returns noop
Thu Apr 25 09:24:09 2013 : Info: [suffix] No '@' in User-Name = "login",
looking up realm NULL
Thu Apr 25 09:24:09 2013 : Info: [suffix] Found realm "NULL"
Thu Apr 25 09:24:09 2013 : Info: [suffix] Adding Stripped-User-Name =
"login"
Thu Apr 25 09:24:09 2013 : Info: [suffix] Adding Realm = "NULL"
Thu Apr 25 09:24:09 2013 : Info: [suffix] Authentication realm is LOCAL.
Thu Apr 25 09:24:09 2013 : Info: ++[suffix] returns ok
Thu Apr 25 09:24:09 2013 : Info: [eap] EAP packet type response id 0
length 13
Thu Apr 25 09:24:09 2013 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 25 09:24:09 2013 : Info: ++[eap] returns updated
Thu Apr 25 09:24:09 2013 : Info: ++[unix] returns updated
Thu Apr 25 09:24:09 2013 : Info: ++[files] returns noop
Thu Apr 25 09:24:09 2013 : Info: [ldap] performing user authorization
for login
Thu Apr 25 09:24:09 2013 : Info: [ldap] WARNING: Deprecated conditional
expansion ":-". See "man unlang" for details
Thu Apr 25 09:24:09 2013 : Info: [ldap] expand:
(uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=login)
Thu Apr 25 09:24:09 2013 : Info: [ldap] expand:
ou=people,dc=mydomain,dc=fr -> ou=people,dc=mydomain,dc=fr
Thu Apr 25 09:24:09 2013 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Thu Apr 25 09:24:09 2013 : Debug: [ldap] ldap_get_conn: Got Id: 0
Thu Apr 25 09:24:09 2013 : Debug: [ldap] attempting LDAP reconnection
Thu Apr 25 09:24:09 2013 : Debug: [ldap] (re)connect to
ldaps://ldap1.mydomain.fr, authentication 0
Thu Apr 25 09:24:09 2013 : Debug: [ldap] bind as
cn=admin,dc=mydomain,dc=fr/ to ldaps://ldap1.mydomain.fr
Thu Apr 25 09:24:09 2013 : Debug: [ldap] waiting for bind result ...
Thu Apr 25 09:24:09 2013 : Debug: [ldap] Bind was successful
Thu Apr 25 09:24:09 2013 : Debug: [ldap] performing search in
ou=people,dc=mydomain,dc=fr, with filter (uid=login)
Thu Apr 25 09:24:09 2013 : Info: [ldap] Added User-Password =
{crypt}ZO0YOg0GnG1eA in check items
Thu Apr 25 09:24:09 2013 : Info: [ldap] No default NMAS login sequence
Thu Apr 25 09:24:09 2013 : Info: [ldap] looking for check items in
directory...
Thu Apr 25 09:24:09 2013 : Debug: [ldap] userPassword ->
Password-With-Header == "{crypt}ZO0YOg0GnG1eA"
Thu Apr 25 09:24:09 2013 : Debug: [ldap] sambaNtPassword ->
NT-Password ==
0x3835383934413934413530413536363844314233383831454133434642353836
Thu Apr 25 09:24:09 2013 : Debug: [ldap] sambaLmPassword ->
LM-Password ==
0x4241463435344446414333384642374142364130344241424335373135384537
Thu Apr 25 09:24:09 2013 : Info: [ldap] looking for reply items in
directory...
Thu Apr 25 09:24:09 2013 : Info: [ldap] user login authorized to use
remote access
Thu Apr 25 09:24:09 2013 : Debug: [ldap] ldap_release_conn: Release Id: 0
Thu Apr 25 09:24:09 2013 : Info: ++[ldap] returns ok
Thu Apr 25 09:24:09 2013 : Info: ++[expiration] returns noop
Thu Apr 25 09:24:09 2013 : Info: ++[logintime] returns noop
Thu Apr 25 09:24:09 2013 : Info: [pap] Normalizing NT-Password from hex
encoding
Thu Apr 25 09:24:09 2013 : Info: [pap] Normalizing LM-Password from hex
encoding
Thu Apr 25 09:24:09 2013 : Info: [pap] WARNING: Auth-Type already set.
Not setting to PAP
Thu Apr 25 09:24:09 2013 : Info: ++[pap] returns noop
Thu Apr 25 09:24:09 2013 : Info: Found Auth-Type = EAP
Thu Apr 25 09:24:09 2013 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Thu Apr 25 09:24:09 2013 : Info: +- entering group authenticate {...}
Thu Apr 25 09:24:09 2013 : Info: [eap] EAP Identity
Thu Apr 25 09:24:09 2013 : Info: [eap] processing type tls
Thu Apr 25 09:24:09 2013 : Info: [tls] Initiate
Thu Apr 25 09:24:09 2013 : Info: [tls] Start returned 1
Thu Apr 25 09:24:09 2013 : Info: ++[eap] returns handled
Sending Access-Challenge of id 42 to 192.168.10.8 port 45584
EAP-Message = 0x010100061920
Message-Authenticator = 0x00000000000000000000000000000000
State = 0xa1a80d97a1a9146202c287478acea4bd
Thu Apr 25 09:24:09 2013 : Info: Finished request 0.
Thu Apr 25 09:24:09 2013 : Debug: Going to the next request
Thu Apr 25 09:24:09 2013 : Debug: Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.10.8 port 45584,
id=43, length=158
User-Name = "login"
NAS-Port-Type = Virtual
Service-Type = Framed-User
NAS-Port = 8
NAS-Port-Id = "road"
NAS-IP-Address = 192.168.10.8
Called-Station-Id = "192.168.10.8[4500]"
Calling-Station-Id = "192.168.110.65[4500]"
EAP-Message = 0x020100060300
NAS-Identifier = "serv-tests"
State = 0xa1a80d97a1a9146202c287478acea4bd
Message-Authenticator = 0xb5d2ecfeed4e4e854e638c22fb0058ae
Thu Apr 25 09:24:09 2013 : Info: # Executing section authorize from file
/etc/freeradius/sites-enabled/default
Thu Apr 25 09:24:09 2013 : Info: +- entering group authorize {...}
Thu Apr 25 09:24:09 2013 : Info: ++[preprocess] returns ok
Thu Apr 25 09:24:09 2013 : Info: ++[chap] returns noop
Thu Apr 25 09:24:09 2013 : Info: ++[mschap] returns noop
Thu Apr 25 09:24:09 2013 : Info: ++[digest] returns noop
Thu Apr 25 09:24:09 2013 : Info: [suffix] No '@' in User-Name = "login",
looking up realm NULL
Thu Apr 25 09:24:09 2013 : Info: [suffix] Found realm "NULL"
Thu Apr 25 09:24:09 2013 : Info: [suffix] Adding Stripped-User-Name =
"login"
Thu Apr 25 09:24:09 2013 : Info: [suffix] Adding Realm = "NULL"
Thu Apr 25 09:24:09 2013 : Info: [suffix] Authentication realm is LOCAL.
Thu Apr 25 09:24:09 2013 : Info: ++[suffix] returns ok
Thu Apr 25 09:24:09 2013 : Info: [eap] EAP packet type response id 1
length 6
Thu Apr 25 09:24:09 2013 : Info: [eap] No EAP Start, assuming it's an
on-going EAP conversation
Thu Apr 25 09:24:09 2013 : Info: ++[eap] returns updated
Thu Apr 25 09:24:09 2013 : Info: ++[unix] returns updated
Thu Apr 25 09:24:09 2013 : Info: ++[files] returns noop
Thu Apr 25 09:24:09 2013 : Info: [ldap] performing user authorization
for login
Thu Apr 25 09:24:09 2013 : Info: [ldap] WARNING: Deprecated conditional
expansion ":-". See "man unlang" for details
Thu Apr 25 09:24:09 2013 : Info: [ldap] expand:
(uid=%{Stripped-User-Name:-%{User-Name}}) -> (uid=login)
Thu Apr 25 09:24:09 2013 : Info: [ldap] expand:
ou=people,dc=mydomain,dc=fr -> ou=people,dc=mydomain,dc=fr
Thu Apr 25 09:24:09 2013 : Debug: [ldap] ldap_get_conn: Checking Id: 0
Thu Apr 25 09:24:09 2013 : Debug: [ldap] ldap_get_conn: Got Id: 0
Thu Apr 25 09:24:09 2013 : Debug: [ldap] performing search in
ou=people,dc=mydomain,dc=fr, with filter (uid=login)
Thu Apr 25 09:24:09 2013 : Info: [ldap] Added User-Password =
{crypt}ZO0YOg0GnG1eA in check items
Thu Apr 25 09:24:09 2013 : Info: [ldap] No default NMAS login sequence
Thu Apr 25 09:24:09 2013 : Info: [ldap] looking for check items in
directory...
Thu Apr 25 09:24:09 2013 : Debug: [ldap] userPassword ->
Password-With-Header == "{crypt}ZO0YOg0GnG1eA"
Thu Apr 25 09:24:09 2013 : Debug: [ldap] sambaNtPassword ->
NT-Password ==
0x3835383934413934413530413536363844314233383831454133434642353836
Thu Apr 25 09:24:09 2013 : Debug: [ldap] sambaLmPassword ->
LM-Password ==
0x4241463435344446414333384642374142364130344241424335373135384537
Thu Apr 25 09:24:09 2013 : Info: [ldap] looking for reply items in
directory...
Thu Apr 25 09:24:09 2013 : Info: [ldap] user login authorized to use
remote access
Thu Apr 25 09:24:09 2013 : Debug: [ldap] ldap_release_conn: Release Id: 0
Thu Apr 25 09:24:09 2013 : Info: ++[ldap] returns ok
Thu Apr 25 09:24:09 2013 : Info: ++[expiration] returns noop
Thu Apr 25 09:24:09 2013 : Info: ++[logintime] returns noop
Thu Apr 25 09:24:09 2013 : Info: [pap] Normalizing NT-Password from hex
encoding
Thu Apr 25 09:24:09 2013 : Info: [pap] Normalizing LM-Password from hex
encoding
Thu Apr 25 09:24:09 2013 : Info: [pap] WARNING: Auth-Type already set.
Not setting to PAP
Thu Apr 25 09:24:09 2013 : Info: ++[pap] returns noop
Thu Apr 25 09:24:09 2013 : Info: Found Auth-Type = EAP
Thu Apr 25 09:24:09 2013 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Thu Apr 25 09:24:09 2013 : Info: +- entering group authenticate {...}
Thu Apr 25 09:24:09 2013 : Info: [eap] Request found, released from the list
Thu Apr 25 09:24:09 2013 : Info: [eap] EAP NAK
Thu Apr 25 09:24:09 2013 : Info: [eap] NAK asked for bad type 0
Thu Apr 25 09:24:09 2013 : Info: [eap] Failed in EAP select
Thu Apr 25 09:24:09 2013 : Info: ++[eap] returns invalid
Thu Apr 25 09:24:09 2013 : Info: Failed to authenticate the user.
Thu Apr 25 09:24:09 2013 : Auth: Login incorrect: [login] (from client
serv-tests port 8 cli 192.168.110.65[4500])
Thu Apr 25 09:24:09 2013 : Info: Using Post-Auth-Type Reject
Thu Apr 25 09:24:09 2013 : Info: # Executing group from file
/etc/freeradius/sites-enabled/default
Thu Apr 25 09:24:09 2013 : Info: +- entering group REJECT {...}
Thu Apr 25 09:24:09 2013 : Info: [attr_filter.access_reject] expand:
%{User-Name} -> login
Thu Apr 25 09:24:09 2013 : Debug: attr_filter: Matched entry DEFAULT at
line 11
Thu Apr 25 09:24:09 2013 : Info: ++[attr_filter.access_reject] returns
updated
Thu Apr 25 09:24:09 2013 : Info: Delaying reject of request 1 for 1 seconds
Thu Apr 25 09:24:09 2013 : Debug: Going to the next request
Thu Apr 25 09:24:09 2013 : Debug: Waking up in 0.9 seconds.
Thu Apr 25 09:24:10 2013 : Info: Sending delayed reject for request 1
Sending Access-Reject of id 43 to 192.168.10.8 port 45584
EAP-Message = 0x04010004
Message-Authenticator = 0x00000000000000000000000000000000
Thu Apr 25 09:24:10 2013 : Debug: Waking up in 3.9 seconds.
--
Sabrina
More information about the Users
mailing list