peap + freeradius093 + Windows XP : module "eap" returns handled

[Wilfried QUET]

Hello,

I've installed freeradius093 compiled with this option :
./configure --prefix=/usr/local/radius093 --disable-shared 
--with-openssl-includes=/usr/local/openssl/include 
--with-openssl-libraries=/usr/local/openssl/lib

The version of openssl is 097b
Every seems to be OK but the client is not authenticated and it loops on 
the windows NT logon and i got the following message :

Someboby can tell me what's wrong .
Thanks
Starting - reading configuration files ...
reread_config:  reading radiusd.conf
Config:   including file: /usr/local/radius093/etc/raddb/proxy.conf
Config:   including file: /usr/local/radius093/etc/raddb/clients.conf
Config:   including file: /usr/local/radius093/etc/raddb/snmp.conf
Config:   including file: /usr/local/radius093/etc/raddb/sql.conf
 main: prefix = "/usr/local/radius093"
 main: localstatedir = "/usr/local/radius093/var"
 main: logdir = "/usr/local/radius093/var/log/radius"
 main: libdir = "/usr/local/radius093/lib"
 main: radacctdir = "/usr/local/radius093/var/log/radius/radacct"
 main: hostname_lookups = no
 main: snmp = no
 main: max_request_time = 30
 main: cleanup_delay = 5
 main: max_requests = 1024
 main: delete_blocked_requests = 0
 main: port = 1912
 main: allow_core_dumps = no
 main: log_stripped_names = no
 main: log_file = "/usr/local/radius093/var/log/radius/radius.log"
 main: log_auth = no
 main: log_auth_badpass = no
 main: log_auth_goodpass = no
 main: pidfile = "/usr/local/radius093/var/run/radiusd/radiusd.pid"
 main: user = "(null)"
 main: group = "(null)"
 main: usercollide = no
 main: lower_user = "no"
 main: lower_pass = "no"
 main: nospace_user = "no"
 main: nospace_pass = "no"
 main: checkrad = "/usr/local/radius093/sbin/checkrad"
 main: proxy_requests = yes
 proxy: retry_delay = 5
 proxy: retry_count = 3
 proxy: synchronous = no
 proxy: default_fallback = yes
 proxy: dead_time = 120
 proxy: post_proxy_authorize = yes
 proxy: wake_all_if_all_dead = no
 security: max_attributes = 200
 security: reject_delay = 1
 security: status_server = no
 main: debug_level = 0
read_config_files:  reading dictionary
read_config_files:  reading naslist
Using deprecated naslist file.  Support for this will go away soon.
read_config_files:  reading clients
Using deprecated clients file.  Support for this will go away soon.
read_config_files:  reading realms
Using deprecated realms file.  Support for this will go away soon.
radiusd:  entering modules setup
Module: Library search path is /usr/local/radius093/lib
Module: Loaded exec
 exec: wait = yes
 exec: program = "(null)"
 exec: input_pairs = "request"
 exec: output_pairs = "(null)"
 exec: packet_type = "(null)"
rlm_exec: Wait=yes but no output defined. Did you mean output=none?
Module: Instantiated exec (exec)
Module: Loaded expr
Module: Instantiated expr (expr)
Module: Loaded PAP
 pap: encryption_scheme = "crypt"
Module: Instantiated pap (pap)
Module: Loaded CHAP
Module: Instantiated chap (chap)
Module: Loaded MS-CHAP
 mschap: use_mppe = yes
 mschap: require_encryption = no
 mschap: require_strong = no
 mschap: with_ntdomain_hack = no
 mschap: passwd = "(null)"
 mschap: authtype = "MS-CHAP"
Module: Instantiated mschap (mschap)
Module: Loaded System
 unix: cache = no
 unix: passwd = "(null)"
 unix: shadow = "(null)"
 unix: group = "(null)"
 unix: radwtmp = "/usr/local/radius093/var/log/radius/radwtmp"
 unix: usegroup = no
 unix: cache_reload = 600
Module: Instantiated unix (unix)
Module: Loaded eap
 eap: default_eap_type = "mschapv2"
 eap: timer_expire = 60
 eap: ignore_unknown_eap_types = no
rlm_eap: Loaded and initialized type md5
rlm_eap: Loaded and initialized type leap
 tls: rsa_key_exchange = no
 tls: dh_key_exchange = yes
 tls: rsa_key_length = 512
 tls: dh_key_length = 512
 tls: verify_depth = 0
 tls: CA_path = "(null)"
 tls: pem_file_type = yes
 tls: private_key_file = "/usr/local/radius/etc/cert-srv.pem"
 tls: certificate_file = "/usr/local/radius/etc/cert-srv.pem"
 tls: CA_file = "/usr/local/radius/etc/root.pem"
 tls: private_key_password = "xxxxxx"
 tls: dh_file = "/usr/local/radius/etc/DH"
 tls: random_file = "/usr/local/radius/etc/random"
 tls: fragment_size = 1024
 tls: include_length = yes
 tls: check_crl = yes
rlm_eap: Loaded and initialized type tls
 ttls: default_eap_type = "md5"
 ttls: copy_request_to_tunnel = no
 ttls: use_tunneled_reply = no
rlm_eap: Loaded and initialized type ttls
 peap: default_eap_type = "mschapv2"
 peap: copy_request_to_tunnel = yes
 peap: use_tunneled_reply = yes
rlm_eap: Loaded and initialized type peap
rlm_eap: Loaded and initialized type mschapv2
Module: Instantiated eap (eap)
Module: Loaded preprocess
 preprocess: huntgroups = "/usr/local/radius093/etc/raddb/huntgroups"
 preprocess: hints = "/usr/local/radius093/etc/raddb/hints"
 preprocess: with_ascend_hack = no
 preprocess: ascend_channels_per_line = 23
 preprocess: with_ntdomain_hack = no
 preprocess: with_specialix_jetstream_hack = no
 preprocess: with_cisco_vsa_hack = no
Module: Instantiated preprocess (preprocess)
Module: Loaded realm
 realm: format = "suffix"
 realm: delimiter = "@"
Module: Instantiated realm (suffix)
Module: Loaded files
 files: usersfile = "/usr/local/radius093/etc/raddb/users"
 files: acctusersfile = "/usr/local/radius093/etc/raddb/acct_users"
 files: preproxy_usersfile = 
"/usr/local/radius093/etc/raddb/preproxy_users"
 files: compat = "no"
Module: Instantiated files (files)
Module: Loaded Acct-Unique-Session-Id
 acct_unique: key = "User-Name, Acct-Session-Id, NAS-IP-Address, 
Client-IP-Address, NAS-Port"
Module: Instantiated acct_unique (acct_unique)
Module: Loaded detail
 detail: detailfile = 
"/usr/local/radius093/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d"
 detail: detailperm = 384
 detail: dirperm = 493
 detail: locking = no
Module: Instantiated detail (detail)
Module: Loaded radutmp
 radutmp: filename = "/usr/local/radius093/var/log/radius/radutmp"
 radutmp: username = "%{User-Name}"
 radutmp: case_sensitive = yes
 radutmp: check_with_nas = yes
 radutmp: perm = 384
 radutmp: callerid = yes
Module: Instantiated radutmp (radutmp)
Listening on IP address *, ports 1912/udp and 1913/udp, with proxy on 
1914/udp.
Ready to process requests.
rad_recv: Access-Request packet from host 10.2.5.6:1645, id=0, length=135
        User-Name = "toto"
        Framed-MTU = 1400
        Called-Station-Id = "000c.ceff.4fe5"
        Calling-Station-Id = "0004.2372.d636"
        Message-Authenticator = 0xd65357a03084e4de010b0580988c106b
        EAP-Message = 0x0202000d017175657477696c66
        NAS-Port-Type = Virtual
        NAS-Port = 276
        NAS-IP-Address = 10.2.5.6
        NAS-Identifier = "borne-aironet"
modcall: entering group authorize for request 0
  modcall[authorize]: module "preprocess" returns ok for request 0
  modcall[authorize]: module "chap" returns noop for request 0
  modcall[authorize]: module "mschap" returns noop for request 0
    rlm_realm: No '@' in User-Name = "toto", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 0
  rlm_eap: EAP packet type response id 2 length 13
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 0
    users: Matched DEFAULT at 152
    users: Matched toto at 217
  modcall[authorize]: module "files" returns ok for request 0
modcall: group authorize returns updated for request 0
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
modcall: entering group authenticate for request 0
  rlm_eap: EAP Identity
  rlm_eap: processing type mschapv2
rlm_eap_mschapv2: Issuing Challenge
  modcall[authenticate]: module "eap" returns handled for request 0
modcall: group authenticate returns handled for request 0
Sending Access-Challenge of id 0 to 10.2.5.6:1645
        Reply-Message = " YYYYYEEEESSSSSSSSSS, %u"
        EAP-Message = 
0x010300221a0103001d10cb5be8187f9f273a76221a78a726cf747175657477696c66
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x474bc9eb5f9886550d504dd5b6203709
Finished request 0
Going to the next request
--- Walking the entire request list ---
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.2.5.6:1645, id=1, length=146
        User-Name = "toto"
        Framed-MTU = 1400
        Called-Station-Id = "000c.ceff.4fe5"
        Calling-Station-Id = "0004.2372.d636"
        Message-Authenticator = 0x594c46150c53c44c14058afb63423408
        EAP-Message = 0x020300060319
        NAS-Port-Type = Virtual
        NAS-Port = 276
        State = 0x474bc9eb5f9886550d504dd5b6203709
        NAS-IP-Address = 10.2.5.6
        NAS-Identifier = "borne-aironet"
modcall: entering group authorize for request 1
  modcall[authorize]: module "preprocess" returns ok for request 1
  modcall[authorize]: module "chap" returns noop for request 1
  modcall[authorize]: module "mschap" returns noop for request 1
    rlm_realm: No '@' in User-Name = "toto", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 1
  rlm_eap: EAP packet type response id 3 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 1
    users: Matched DEFAULT at 152
    users: Matched toto at 217
  modcall[authorize]: module "files" returns ok for request 1
modcall: group authorize returns updated for request 1
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
modcall: entering group authenticate for request 1
  rlm_eap: Request found, released from the list
  rlm_eap: EAP NAK
 rlm_eap: EAP-NAK asked for EAP-Type/peap
  rlm_eap: processing type tls
  rlm_eap_tls: Initiate
  rlm_eap_tls: Start returned 1
  modcall[authenticate]: module "eap" returns handled for request 1
modcall: group authenticate returns handled for request 1
Sending Access-Challenge of id 1 to 10.2.5.6:1645
        Reply-Message = " YYYYYEEEESSSSSSSSSS, %u"
        EAP-Message = 0x010400061920
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x3e314e3711dd5d61142ff60cf61942e2
Finished request 1
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.2.5.6:1645, id=2, length=220
        User-Name = "toto"
        Framed-MTU = 1400
        Called-Station-Id = "000c.ceff.4fe5"
        Calling-Station-Id = "0004.2372.d636"
        Message-Authenticator = 0x24933fb0913f72887c2eb385a20df005
        EAP-Message = 
0x0204005019800000004616030100410100003d0301404497931db5b75968df033cac299050d005275a9e4ad7eef4329c467697a99900001600040005000a000900640062000300060013001200630100
        NAS-Port-Type = Virtual
        NAS-Port = 276
        State = 0x3e314e3711dd5d61142ff60cf61942e2
        NAS-IP-Address = 10.2.5.6
        NAS-Identifier = "borne-aironet"
modcall: entering group authorize for request 2
  modcall[authorize]: module "preprocess" returns ok for request 2
  modcall[authorize]: module "chap" returns noop for request 2
  modcall[authorize]: module "mschap" returns noop for request 2
    rlm_realm: No '@' in User-Name = "toto", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 2
  rlm_eap: EAP packet type response id 4 length 80
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 2
    users: Matched DEFAULT at 152
    users: Matched toto at 217
  modcall[authorize]: module "files" returns ok for request 2
modcall: group authorize returns updated for request 2
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
modcall: entering group authenticate for request 2
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls:  Length Included
  eaptls_verify returned 11
    (other): before/accept initialization
    TLS_accept: before/accept initialization
  rlm_eap_tls: <<< TLS 1.0 Handshake [length 0041], ClientHello
    TLS_accept: SSLv3 read client hello A
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 004a], ServerHello
    TLS_accept: SSLv3 write server hello A
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0679], Certificate
    TLS_accept: SSLv3 write certificate A
  rlm_eap_tls: >>> TLS 1.0 Handshake [length 0004], ServerHelloDone
    TLS_accept: SSLv3 write server done A
    TLS_accept: SSLv3 flush data
    TLS_accept:error in SSLv3 read client certificate A
In SSL Handshake Phase
In SSL Accept mode
  eaptls_process returned 13
  rlm_eap_peap: EAPTLS_HANDLED
  modcall[authenticate]: module "eap" returns handled for request 2
modcall: group authenticate returns handled for request 2
Sending Access-Challenge of id 2 to 10.2.5.6:1645
        Reply-Message = " YYYYYEEEESSSSSSSSSS, %u"
        EAP-Message = 
0x0105040a19c0000006d6160301004a02000046030140449791c62cff2c53fa3ef1f45606bf324e0a79142f30a815747c7928df40722019d65c9b569f7962b498f523a3d20a8c3f31dfc3dbdc5a5ee6dd5cabef6cf74f00040016030106790b0006750006720002bb308202b730820220a003020102020104300d06092a864886f70d010104050030819c310b30090603550406130246523111300f0603550408130850696361726469653112301006035504071309436f6d706965676e65310c300a060355040a1303555443311d301b060355040b13145365727669636520496e666f726d617469717565311d301b0603550403131453657276696365
        EAP-Message = 
0x20496e666f726d617469717565311a301806092a864886f70d010901160b35303030407574632e6672301e170d3033303733303135343031385a170d3034303732393135343031385a30818c310b30090603550406130246523111300f0603550408130850696361726469653112301006035504071309436f6d706965676e65310c300a060355040a13035554433121301f060355040b13185365727669636520496e666f726d617469717565205554433110300e060355040313076e657074756e653113301106092a864886f70d0109011604726f6f7430819f300d06092a864886f70d010101050003818d0030818902818100aba119aa90e2cea6
        EAP-Message = 
0x167daf2d7d15bf2d535bf5d603208ab0c53d05f5ea80e2b3a6e60af95f5b35c9250a98b099d65fd4f14fd04ffe6c6015d2a9b79e7a1642adf9fa84c60e2acb678837fb557f4d1d60fd8ac49269bec31e3868f383d8bc845fa840fd31bec2fe7a0a8aa6df18a5c1dc23af41a90b66394efffaaff4bb08f8c10203010001a317301530130603551d25040c300a06082b06010505070301300d06092a864886f70d0101040500038181002aaeca046c6c6ab50ae19bf7a18ce7b399ea023d8f5eca3c6011680823e8921274a8d78abe36e326433bf5a8a33cfb821725a9637c769281eba00ad2f938550e89a151870bd1d079cc32b6a2aeb70d273801e8ab
        EAP-Message = 
0xdb43031c5d4e8410fb3ae4aa4b6da009082893b76e3f1ab3f06e154d9543bc56517ed1ca08c031853a94928e0003b1308203ad30820316a003020102020100300d06092a864886f70d010104050030819c310b30090603550406130246523111300f0603550408130850696361726469653112301006035504071309436f6d706965676e65310c300a060355040a1303555443311d301b060355040b13145365727669636520496e666f726d617469717565311d301b060355040313145365727669636520496e666f726d617469717565311a301806092a864886f70d010901160b35303030407574632e6672301e170d303330373330313235363331
        EAP-Message = 0x5a170d3035303732393132353633315a30819c310b30
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x688468bf2995a798a3d3744bfe62e953
Finished request 2
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.2.5.6:1645, id=3, length=146
        User-Name = "toto"
        Framed-MTU = 1400
        Called-Station-Id = "000c.ceff.4fe5"
        Calling-Station-Id = "0004.2372.d636"
        Message-Authenticator = 0x409e5834dd6a0f8a3b431ed40bad1303
        EAP-Message = 0x020500061900
        NAS-Port-Type = Virtual
        NAS-Port = 276
        State = 0x688468bf2995a798a3d3744bfe62e953
        NAS-IP-Address = 10.2.5.6
        NAS-Identifier = "borne-aironet"
modcall: entering group authorize for request 3
  modcall[authorize]: module "preprocess" returns ok for request 3
  modcall[authorize]: module "chap" returns noop for request 3
  modcall[authorize]: module "mschap" returns noop for request 3
    rlm_realm: No '@' in User-Name = "toto", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 3
  rlm_eap: EAP packet type response id 5 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 3
    users: Matched DEFAULT at 152
    users: Matched toto at 217
  modcall[authorize]: module "files" returns ok for request 3
modcall: group authorize returns updated for request 3
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
modcall: entering group authenticate for request 3
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  rlm_eap_tls: ack handshake fragment handler
  eaptls_verify returned 1
  eaptls_process returned 13
  rlm_eap_peap: EAPTLS_HANDLED
  modcall[authenticate]: module "eap" returns handled for request 3
modcall: group authenticate returns handled for request 3
Sending Access-Challenge of id 3 to 10.2.5.6:1645
        Reply-Message = " YYYYYEEEESSSSSSSSSS, %u"
        EAP-Message = 
0x010602dc1900090603550406130246523111300f0603550408130850696361726469653112301006035504071309436f6d706965676e65310c300a060355040a1303555443311d301b060355040b13145365727669636520496e666f726d617469717565311d301b060355040313145365727669636520496e666f726d617469717565311a301806092a864886f70d010901160b35303030407574632e667230819f300d06092a864886f70d010101050003818d0030818902818100a0e039bd6e168e6af07fa3a81037e06828b45cbb06d1c662ba345c17aca9de95cbe84c4cb6667defe5890951ead10a11f69e605fd9a6fc4870813b547099a4d644
        EAP-Message = 
0x8f97c12b55d39b7304a1afd23892213c5deeb3e1f8cd9d73a941e25c7f3c454b44524aadc26d9544139c2b9ea21aa611615b64a4e1052cf99963209e2ba0130203010001a381fc3081f9301d0603551d0e0416041424ed06fe443bdaaaa6271a93597b6abb83079a9e3081c90603551d230481c13081be801424ed06fe443bdaaaa6271a93597b6abb83079a9ea181a2a4819f30819c310b30090603550406130246523111300f0603550408130850696361726469653112301006035504071309436f6d706965676e65310c300a060355040a1303555443311d301b060355040b13145365727669636520496e666f726d617469717565311d301b0603
        EAP-Message = 
0x55040313145365727669636520496e666f726d617469717565311a301806092a864886f70d010901160b35303030407574632e6672820100300c0603551d13040530030101ff300d06092a864886f70d0101040500038181006d2ed3009e5643647ccddcbd6f6000db488f37290f4e6fbff44d9cc2e22104b93e0db3ca860937f9c872f6d8a086f6e3ee4acef2e89bf94825f39e78e250cffc32093b723ac224dbc5b1e028c87015f26333940a4ad8ba953a309449d1ce3c5e9ff821bc41ad2a209da92742227f87c238a465f98d326449aa1cba2af390363716030100040e000000
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0xf472fa125effef7991d2920547e59b63
Finished request 3
Going to the next request
Waking up in 6 seconds...
rad_recv: Access-Request packet from host 10.2.5.6:1645, id=4, length=146
        User-Name = "toto"
        Framed-MTU = 1400
        Called-Station-Id = "000c.ceff.4fe5"
        Calling-Station-Id = "0004.2372.d636"
        Message-Authenticator = 0xb85d975559fc0b54ba218313ae94cb44
        EAP-Message = 0x020600061900
        NAS-Port-Type = Virtual
        NAS-Port = 276
        State = 0xf472fa125effef7991d2920547e59b63
        NAS-IP-Address = 10.2.5.6
        NAS-Identifier = "borne-aironet"
modcall: entering group authorize for request 4
  modcall[authorize]: module "preprocess" returns ok for request 4
  modcall[authorize]: module "chap" returns noop for request 4
  modcall[authorize]: module "mschap" returns noop for request 4
    rlm_realm: No '@' in User-Name = "toto", looking up realm NULL
    rlm_realm: No such realm "NULL"
  modcall[authorize]: module "suffix" returns noop for request 4
  rlm_eap: EAP packet type response id 6 length 6
  rlm_eap: No EAP Start, assuming it's an on-going EAP conversation
  modcall[authorize]: module "eap" returns updated for request 4
    users: Matched DEFAULT at 152
    users: Matched toto at 217
  modcall[authorize]: module "files" returns ok for request 4
modcall: group authorize returns updated for request 4
  rad_check_password:  Found Auth-Type EAP
auth: type "EAP"
modcall: entering group authenticate for request 4
  rlm_eap: Request found, released from the list
  rlm_eap: EAP/peap
  rlm_eap: processing type peap
  rlm_eap_peap: Authenticate
  rlm_eap_tls: processing TLS
rlm_eap_tls: Received EAP-TLS ACK message
  eaptls_verify returned 3
  eaptls_process returned 3
    TLS_accept:error in SSLv3 read client certificate A
  rlm_eap_peap: EAPTLS_SUCCESS
  modcall[authenticate]: module "eap" returns handled for request 4
modcall: group authenticate returns handled for request 4
Sending Access-Challenge of id 4 to 10.2.5.6:1645
        Reply-Message = " YYYYYEEEESSSSSSSSSS, %u"
        EAP-Message = 0x010700061900
        Message-Authenticator = 0x00000000000000000000000000000000
        State = 0x3a70f7cca5b1aaeaae771d619c4946c6
Finished request 4
Going to the next request
Waking up in 6 seconds...
--- Walking the entire request list ---
Cleaning up request 0 ID 0 with timestamp 40449791
Cleaning up request 1 ID 1 with timestamp 40449791
Cleaning up request 2 ID 2 with timestamp 40449791
Cleaning up request 3 ID 3 with timestamp 40449791
Cleaning up request 4 ID 4 with timestamp 40449791
Nothing to do.  Sleeping until we see a request.
--
------------------------------------------
- Wilfried QUET                          -
- Universit� de Technologie de Compi�gne -
- Service Informatique                   -
- t�l. :  03 44 23 49 90                 -
- port.:  06 22 20 59 83                 -
- fax  :  03 44 23 46 77                 -
- mail :  [EMAIL PROTECTED]                   -
------------------------------------------

-
List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html