problem migrating to freeradius2 with LDAP/krb5 Authorization/Authentication

Fri Jun 18 11:31:55 CEST 2010

Hello,
i moved my old freeradius 1.x server to freeradius 2 I am on CentOS5.5

freeradius2-utils-2.1.7-7.el5
freeradius2-mysql-2.1.7-7.el5
freeradius2-2.1.7-7.el5
freeradius2-postgresql-2.1.7-7.el5
freeradius2-python-2.1.7-7.el5
freeradius2-unixODBC-2.1.7-7.el5
freeradius2-krb5-2.1.7-7.el5
freeradius2-perl-2.1.7-7.el5
freeradius2-ldap-2.1.7-7.el5

What I would like to do is to have the same service with LDAP 
authorization plus Kerberos V authentication,
and users using EAP-TTLS client (SecureW2).
But it does not work to me, Kerberos authentication is not even entered 
by the radius server because of missconfiguration
and I am trying to guess where is my error.

Basic Cleartext password in users file with EAP authentication works.
I am not able to make KErberos authentication work with EAP.

I Setup the radius server,  I added principal in the kerberos server and 
I have the proper krb5.keytab file setup

here is my configuration, might you check please where I get wrong in my 
configuration ?
Following is my configuration and at the end is the radius log,
thank you very much

# users
DEFAULT         Auth-Type := eap

DEFAULT        Auth-Type := Kerberos
        Fall-Through = 1

# modules/krb5

krb5 {
    keytab = /etc/krb5.keytab
    #service_principal = name_of_principle
}

# modules/ldap

ldap {
    server = "ldap-m.mydomain.com"
    basedn = "ou=people,o=myorg o=myorg,c=it"
    filter = "(uid=%{%{Stripped-User-Name}:-%{User-Name}})"

    ldap_connections_number = 5

    timeout = 4

    timelimit = 3

    net_timeout = 1

    tls {
        start_tls = no
    }

    dictionary_mapping = ${confdir}/ldap.attrmap

    edir_account_policy_check = no
}

#sites-avaliable/default

authorize {
    preprocess

    auth_log

    chap

    mschap

    suffix

    eap {
        ok = return
    }

    unix

    files

    ldap

    expiration
    logintime

    pap

}

authenticate {
    Auth-Type PAP {
        pap
    }

    Auth-Type CHAP {
        chap
    }

    Auth-Type MS-CHAP {
        mschap
    }

    Auth-Type Kerberos {
        krb5
    }

    unix

    eap

    Auth-Type eap {
        eap {
            handled = 1 
        }
    }
}

preacct {
    preprocess

    acct_unique

    suffix

    files
}

accounting {
    detail

    unix

    radutmp

    attr_filter.accounting_response

}

session {
    radutmp

}

post-auth {

    exec

    Post-Auth-Type REJECT {
        attr_filter.access_reject
    }
}

pre-proxy {

}

post-proxy {

    eap

}

#sites-avaliable/inner-tunnel

server inner-tunnel {

authorize {
    chap

    mschap

    unix

    suffix

    update control {
           Proxy-To-Realm := LOCAL
    }

    eap {
        ok = return
    }

    files

    ldap

    expiration
    logintime

    pap
}

authenticate {
    Auth-Type PAP {
        pap
    }

    Auth-Type CHAP {
        chap
    }

    Auth-Type MS-CHAP {
        mschap
    }
    Auth-Type Kerberos {
        krb5
    }

    unix

    eap
}

session {
    radutmp

}

post-auth {

    Post-Auth-Type REJECT {
        attr_filter.access_reject
    }

}

pre-proxy {

}

post-proxy {

    eap

}

radiusd -X

rad_recv: Access-Request packet from host 192.168.252.17 port 1645, 
id=55, length=157
    User-Name = "username at myrealm.com"
    Framed-MTU = 1400
    Called-Station-Id = "0012.438a.e8f0"
    Calling-Station-Id = "0022.5f08.a887"
    Service-Type = Login-User
    Message-Authenticator = 0xf4d6a67552977fb729b374eba35a1ff4
    EAP-Message = 0x0202001b016775697a7a756e746940636e61662e696e666e2e6974
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 331
    NAS-IP-Address = 192.168.252.17
    NAS-Identifier = "ap"
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]     expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> 
/var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log]     expand: %t -> Fri Jun 18 11:11:43 2010
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] Looking up realm "myrealm.com" for User-Name = 
"username at myrealm.com"
[suffix] Found realm "myrealm.com"
[suffix] Adding Stripped-User-Name = "username"
[suffix] Adding Realm = "myrealm.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 2 length 27
[eap] No EAP Start, assuming it's an on-going EAP conversation
++[eap] returns updated
++[unix] returns notfound
[files] users: Matched entry DEFAULT at line 6
++[files] returns ok
[ldap] performing user authorization for username
[ldap]     expand: %{Stripped-User-Name} -> username
[ldap]     expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> 
(uid=username)
[ldap]     expand: ou=people,o=myorg,o=myorg,c=it -> 
ou=people,o=myorg,o=myorg,c=it
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: attempting LDAP reconnection
rlm_ldap: (re)connect to ldap-m.cr.myrealm.com:389, authentication 0
rlm_ldap: bind as / to ldap-m.cr.myrealm.com:389
rlm_ldap: waiting for bind result ...
rlm_ldap: Bind was successful
rlm_ldap: performing search in ou=people,o=myorg,o=myorg,c=it, with 
filter (uid=username)
[ldap] looking for check items in directory...
[ldap] looking for reply items in directory...
WARNING: No "known good" password was found in LDAP.  Are you sure that 
the user is configured correctly?
[ldap] user username authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
++[ldap] 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] EAP Identity
[eap] processing type tls
[tls] Initiate
[tls] Start returned 1
++[eap] returns handled
Sending Access-Challenge of id 55 to 192.168.252.17 port 1645
    EAP-Message = 0x010300061520
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x5753d13e5750c4ac9fc5b5a8b7c8a781
Finished request 0.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.252.17 port 1645, 
id=56, length=208
    User-Name = "username at myrealm.com"
    Framed-MTU = 1400
    Called-Station-Id = "0012.438a.e8f0"
    Calling-Station-Id = "0022.5f08.a887"
    Service-Type = Login-User
    Message-Authenticator = 0x98a6abafe23ad54ef0b53c22e50538aa
    EAP-Message = 
0x0203003c158000000032160301002d0100002903010975d1c7f4c77c95b90742f17d51e0e098c8018d2ca1e685239b82b7f1f94398000002000a0100
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 331
    State = 0x5753d13e5750c4ac9fc5b5a8b7c8a781
    NAS-IP-Address = 192.168.252.17
    NAS-Identifier = "ap"
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]     expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> 
/var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log]     expand: %t -> Fri Jun 18 11:11:43 2010
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] Looking up realm "myrealm.com" for User-Name = 
"username at myrealm.com"
[suffix] Found realm "myrealm.com"
[suffix] Adding Stripped-User-Name = "username"
[suffix] Adding Realm = "myrealm.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 3 length 60
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 50
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls]     (other): before/accept initialization
[ttls]     TLS_accept: before/accept initialization
[ttls] <<< TLS 1.0 Handshake [length 002d], ClientHello 
[ttls]     TLS_accept: SSLv3 read client hello A
[ttls] >>> TLS 1.0 Handshake [length 002a], ServerHello 
[ttls]     TLS_accept: SSLv3 write server hello A
[ttls] >>> TLS 1.0 Handshake [length 0771], Certificate 
[ttls]     TLS_accept: SSLv3 write certificate A
[ttls] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone 
[ttls]     TLS_accept: SSLv3 write server done A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     TLS_accept: Need to read more data: SSLv3 read client 
certificate A
In SSL Handshake Phase
In SSL Accept mode 
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 56 to 192.168.252.17 port 1645
    EAP-Message = 
0x0104040015c0000007ae160301002a0200002603014c1b384f09835579da8b5456f480d5c4f5e6adc766d3db6e528ce79ffaf48eed00000a0016030107710b00076d00076a0003ed308203e9308202d1a003020102020243e8300d06092a864886f70d0101050500302e310b3009060355040613024954310d300b060355040a1304494e464e3110300e06035504031307494e464e204341301e170d3130303631313133333433385a170d3131303631313133333433385a3058310b3009060355040613024954310d300b060355040a1304494e464e310d300b060355040b1304486f7374310d300b06035504071304434e4146311c301a0603550403
    EAP-Message = 
0x13137261646975732e636e61662e696e666e2e697430819f300d06092a864886f70d010101050003818d0030818902818100e52a70b55fcf6cff98debcc333b2250d5bf311550dff5048a3da3436752fcc35fa65da8eeac6ac7661aa05162cfa43a3a9c02b528d01390647ee270d8710bd5a2a91dd0d178afdc7b8720807169ff02b337b4609df026e74b2b67a0c39da43b38b7202bb588f96d28b6ae5da739f19c09579552ef5826cd1868c48bafc29ca870203010001a382016930820165300c0603551d130101ff04023000300e0603551d0f0101ff0404030205a030340603551d25042d302b06082b0601050507030106082b0601050507030206
    EAP-Message = 
0x0a2b0601040182370a030306096086480186f8420401303d0603551d1f043630343032a030a02e862c687474703a2f2f73656375726974792e66692e696e666e2e69742f43412f494e464e43415f63726c2e64657230250603551d20041e301c300c060a2b06010401d1230a0107300c060a2a864886f74c05020201301d0603551d0e041604143e48fa5b450e5dba99497d2aedda7254d4c70e0030560603551d23044f304d8014d162f3b37772c82efbf2791a6f374e279f13d520a132a430302e310b3009060355040613024954310d300b060355040a1304494e464e3110300e06035504031307494e464e20434182010030320603551d11042b30
    EAP-Message = 
0x2982137261646975732e636e61662e696e666e2e697481127379736f7040636e61662e696e666e2e6974300d06092a864886f70d0101050500038201010008d0f5e2826b7d1c556096cc4feed46b101a4ec00272fd0d942b554c396c7886e33487362615a313c9dcfdfdb8ab64203ecee766344bf3912a2518e10e2aac98b37ca8c4d4159427c592adda8afc63b25a841583daba3c9922b65784c6bf5810f5581a0e3f4ca7155f323ec784a222ddec9cb96f334699374670f16bee4e7dda4d65796feb99b7cef70801676714813a3dc8575d3803f6bacda7ea4724bf2f441216fcc0b285029a8efcf9aa95d820b88239fe2738e3a283f529b60a656e62
    EAP-Message = 0xc960ed2032f034653f28879f
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x5753d13e5657c4ac9fc5b5a8b7c8a781
Finished request 1.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.252.17 port 1645, 
id=57, length=154
    User-Name = "username at myrealm.com"
    Framed-MTU = 1400
    Called-Station-Id = "0012.438a.e8f0"
    Calling-Station-Id = "0022.5f08.a887"
    Service-Type = Login-User
    Message-Authenticator = 0x908d086ab2287026379e7037b0d5c711
    EAP-Message = 0x020400061500
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 331
    State = 0x5753d13e5657c4ac9fc5b5a8b7c8a781
    NAS-IP-Address = 192.168.252.17
    NAS-Identifier = "ap"
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]     expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> 
/var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log]     expand: %t -> Fri Jun 18 11:11:43 2010
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] Looking up realm "myrealm.com" for User-Name = 
"username at myrealm.com"
[suffix] Found realm "myrealm.com"
[suffix] Adding Stripped-User-Name = "username"
[suffix] Adding Realm = "myrealm.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 4 length 6
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
[ttls] Received TLS ACK
[ttls] ACK handshake fragment handler
[ttls] eaptls_verify returned 1
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 57 to 192.168.252.17 port 1645
    EAP-Message = 
0x010503c21580000007aef89beeea09cd7cba4cc6815861d1765a5f2cb89b735aa8fbc1bfbdf4d4e8d5001689aab6d4161f788f4e6bd9176dae3836bc5bf626000377308203733082025ba003020102020100300d06092a864886f70d0101050500302e310b3009060355040613024954310d300b060355040a1304494e464e3110300e06035504031307494e464e204341301e170d3036313030333134313634375a170d3136313030333134313634375a302e310b3009060355040613024954310d300b060355040a1304494e464e3110300e06035504031307494e464e20434130820122300d06092a864886f70d01010105000382010f003082010a
    EAP-Message = 
0x0282010100ce958e0e83959d42a9ca2923cab763f90a49ba825e2a4a85e1f6dde8baea7902f476a02296e551f03e32fd3d8caafb1d1ff7e0d2cdc46195034198a6700982dda9a64d7deba973b3df81962c6a57a170265152963cd149a3aac0130870dd28da6bc9848cc89913f262807379448f0aead68ab632ff8c4e1751364e19bbe52ac44ec7324f33a6cee0625d60efaa84af44e47b1b57af7d0d8cae9017d407a0a1b43e860db71d3ca50ac217a78b98f4bfab2616388111bdd5420e0efae0564c730fd75e8bf643d8f88ee88f35cbb9ac8c4ddfba4d7cee9d1df7fafea1f00b4b0a171046de2f8fba06fec7138377929c5b2aa043b80f8205f6fe
    EAP-Message = 
0x3cd46249c20e7c2f0203010001a3819b308198300f0603551d130101ff040530030101ff300e0603551d0f0101ff040403020106301d0603551d0e04160414d162f3b37772c82efbf2791a6f374e279f13d52030560603551d23044f304d8014d162f3b37772c82efbf2791a6f374e279f13d520a132a430302e310b3009060355040613024954310d300b060355040a1304494e464e3110300e06035504031307494e464e204341820100300d06092a864886f70d0101050500038201010078d7d33fb73f72724062012396805ce4b736e0c47f431da822c5206b178edbc89b690348c48640e839b999c92d3021693fa05f978d90377386eb891205b5
    EAP-Message = 
0x14f183cb621feb3803e13e04b12e7413e2f905334e1bbf14cc5e07f4318195bae40fc544ba0f51a711aeb12c1e1869673ba093fd4d536f75d8e598c8accb9b874f54c268caf671087b7bc244f2270246e66a6b5e7b3a4a3aa0b92a78f4669a94f829d692ec989e3b255f57bd3b995bba92d3a7934ea99442167d628938e9a0d79f82a2c4dec1de7606f63f5bd2f253be1088519d681f37da801d2aa443e64e6f121f3c915d725baef1dfcab57b0590a9a616e1077744ab629061f5908b0e0ab6c7d616030100040e000000
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x5753d13e5556c4ac9fc5b5a8b7c8a781
Finished request 2.
Going to the next request
Waking up in 4.9 seconds.
rad_recv: Access-Request packet from host 192.168.252.17 port 1645, 
id=58, length=348
    User-Name = "username at myrealm.com"
    Framed-MTU = 1400
    Called-Station-Id = "0012.438a.e8f0"
    Calling-Station-Id = "0022.5f08.a887"
    Service-Type = Login-User
    Message-Authenticator = 0xb9b0cb0f79cce7dbac3e6580be35fee8
    EAP-Message = 
0x020500c81580000000be16030100861000008200805bff51c22c6177f2bb156dc96f1443d0af3f20350edd0b28d8b9e4844b86129d463fde980cabf5fce46c7024645276c3586d28b6ac4581ee187e28a940c0e0475c644cd561d0f22ac52a838e25273d454f11f9614a463646c931f9bac9f87b9af09ca01a7fa78ceea056ba56007a7a41e5853e3283b33bc2aa691cede3ac53bf1403010001011603010028a98916d48662eef747eaca2bb451650dcc22fae50e9dc86965dbb3e82a01f0770c31958f10da6dfd
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 331
    State = 0x5753d13e5556c4ac9fc5b5a8b7c8a781
    NAS-IP-Address = 192.168.252.17
    NAS-Identifier = "ap"
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]     expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> 
/var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log]     expand: %t -> Fri Jun 18 11:11:43 2010
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] Looking up realm "myrealm.com" for User-Name = 
"username at myrealm.com"
[suffix] Found realm "myrealm.com"
[suffix] Adding Stripped-User-Name = "username"
[suffix] Adding Realm = "myrealm.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 5 length 200
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 190
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls] <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange 
[ttls]     TLS_accept: SSLv3 read client key exchange A
[ttls] <<< TLS 1.0 ChangeCipherSpec [length 0001] 
[ttls] <<< TLS 1.0 Handshake [length 0010], Finished 
[ttls]     TLS_accept: SSLv3 read finished A
[ttls] >>> TLS 1.0 ChangeCipherSpec [length 0001] 
[ttls]     TLS_accept: SSLv3 write change cipher spec A
[ttls] >>> TLS 1.0 Handshake [length 0010], Finished 
[ttls]     TLS_accept: SSLv3 write finished A
[ttls]     TLS_accept: SSLv3 flush data
[ttls]     (other): SSL negotiation finished successfully
SSL Connection Established
[ttls] eaptls_process returned 13
++[eap] returns handled
Sending Access-Challenge of id 58 to 192.168.252.17 port 1645
    EAP-Message = 
0x0106003d158000000033140301000101160301002843ccdc295b6dbd1d720d5e9087e94f173b3f2cd83798f8012aaca2f7b61d21b38e51a91262b8a64f
    Message-Authenticator = 0x00000000000000000000000000000000
    State = 0x5753d13e5455c4ac9fc5b5a8b7c8a781
Finished request 3.
Going to the next request
Waking up in 4.7 seconds.
rad_recv: Access-Request packet from host 192.168.252.17 port 1645, 
id=59, length=243
    User-Name = "username at myrealm.com"
    Framed-MTU = 1400
    Called-Station-Id = "0012.438a.e8f0"
    Calling-Station-Id = "0022.5f08.a887"
    Service-Type = Login-User
    Message-Authenticator = 0x23d67a33d7bfb5afdb680d317b5e5280
    EAP-Message = 
0x0206005f1580000000551703010050c032907ee2ba0e63bbcc36909c482b61c8d18de52649368384225179d61b86e908bb354bf43d401d75df8bf4e1c07ffc68e07640501742f4a3bf7abe6b99ae0060fc058eade22ce7a088faee0a6a7243
    NAS-Port-Type = Wireless-802.11
    NAS-Port = 331
    State = 0x5753d13e5455c4ac9fc5b5a8b7c8a781
    NAS-IP-Address = 192.168.252.17
    NAS-Identifier = "ap"
+- entering group authorize {...}
++[preprocess] returns ok
[auth_log]     expand: 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d -> 
/var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log] 
/var/log/radius/radacct/%{Client-IP-Address}/auth-detail-%Y%m%d expands 
to /var/log/radius/radacct/192.168.252.17/auth-detail-20100618
[auth_log]     expand: %t -> Fri Jun 18 11:11:43 2010
++[auth_log] returns ok
++[chap] returns noop
++[mschap] returns noop
[suffix] Looking up realm "myrealm.com" for User-Name = 
"username at myrealm.com"
[suffix] Found realm "myrealm.com"
[suffix] Adding Stripped-User-Name = "username"
[suffix] Adding Realm = "myrealm.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
[eap] EAP packet type response id 6 length 95
[eap] Continuing tunnel setup.
++[eap] returns ok
Found Auth-Type = EAP
+- entering group authenticate {...}
[eap] Request found, released from the list
[eap] EAP/ttls
[eap] processing type ttls
[ttls] Authenticate
[ttls] processing EAP-TLS
  TLS Length 85
[ttls] Length Included
[ttls] eaptls_verify returned 11
[ttls] eaptls_process returned 7
[ttls] Session established.  Proceeding to decode tunneled attributes.
[ttls] Got tunneled request
    User-Name = "username at myrealm.com"
    User-Password = "mypassword"
    FreeRADIUS-Proxied-To = 127.0.0.1
[ttls] Sending tunneled request
    User-Name = "username at myrealm.com"
    User-Password = "mypassword"
    FreeRADIUS-Proxied-To = 127.0.0.1
server inner-tunnel {
+- entering group authorize {...}
++[chap] returns noop
++[mschap] returns noop
++[unix] returns notfound
[suffix] Looking up realm "myrealm.com" for User-Name = 
"username at myrealm.com"
[suffix] Found realm "myrealm.com"
[suffix] Adding Stripped-User-Name = "username"
[suffix] Adding Realm = "myrealm.com"
[suffix] Authentication realm is LOCAL.
++[suffix] returns ok
++[control] returns ok
[eap] No EAP-Message, not doing EAP
++[eap] returns noop
[files] users: Matched entry DEFAULT at line 6
++[files] returns ok
[ldap] performing user authorization for username
[ldap]     expand: %{Stripped-User-Name} -> username
[ldap]     expand: (uid=%{%{Stripped-User-Name}:-%{User-Name}}) -> 
(uid=username)
[ldap]     expand: ou=people,o=myorg,o=myorg,c=it -> 
ou=people,o=myorg,o=myorg,c=it
rlm_ldap: ldap_get_conn: Checking Id: 0
rlm_ldap: ldap_get_conn: Got Id: 0
rlm_ldap: performing search in ou=people,o=myorg,o=myorg,c=it, with 
filter (uid=username)
[ldap] looking for check items in directory...
[ldap] looking for reply items in directory...
WARNING: No "known good" password was found in LDAP.  Are you sure that 
the user is configured correctly?
[ldap] user username authorized to use remote access
rlm_ldap: ldap_release_conn: Release Id: 0
++[ldap] returns ok
++[expiration] returns noop
++[logintime] returns noop
++[pap] returns noop
Found Auth-Type = EAP
+- entering group authenticate {...}
rlm_eap: EAP-Message not found
[eap] Malformed EAP Message
++[eap] returns fail
Failed to authenticate the user.
} # server inner-tunnel
[ttls] Got tunneled reply code 3
[ttls] Got tunneled Access-Reject
[eap] Handler failed in EAP/ttls
[eap] Failed in EAP select
++[eap] returns invalid
Failed to authenticate the user.
Using Post-Auth-Type Reject
+- entering group REJECT {...}
[attr_filter.access_reject]     expand: %{User-Name} -> username at myrealm.com
 attr_filter: Matched entry DEFAULT at line 11
++[attr_filter.access_reject] returns updated
Delaying reject of request 4 for 1 seconds
Going to the next request
Waking up in 0.9 seconds.
Sending delayed reject for request 4
Sending Access-Reject of id 59 to 192.168.252.17 port 1645
    EAP-Message = 0x04060004
    Message-Authenticator = 0x00000000000000000000000000000000
Waking up in 3.7 seconds.
Cleaning up request 0 ID 55 with timestamp +7
Cleaning up request 1 ID 56 with timestamp +7
Cleaning up request 2 ID 57 with timestamp +7
Waking up in 0.2 seconds.
Cleaning up request 3 ID 58 with timestamp +7
Waking up in 1.0 seconds.
Cleaning up request 4 ID 59 with timestamp +7
Ready to process requests.