No EAP Start, assuming it's an on-going EAP conversation

Hello all, I'm using FreeRADIUS Version 2.1.8 with Active Directory Integration for authenticate wireless clients. mschap validation occur with success but wireless client can't authenticate. On several tests when run radiusd -X and force join to Active Directory, during the next 2 ou 3 minutes clients can authenticate with success. Difference between logs: Not Authenticate: [eap] EAP packet type response id 2 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated Authenticate: [eap] EAP packet type response id 9 length 43 [eap] Continuing tunnel setup. ++[eap] returns ok Found Auth-Type = EAP +- 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] EAP type mschapv2 [peap] Got tunneled request EAP-Message = 0x020900061a03 server { PEAP: Setting User-Name to DOMAIN\userADaccount Sending tunneled request EAP-Message = 0x020900061a03 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "DOMAIN\\userADaccount" State = 0xe5148887e41d92371b84644b616ede77 server inner-tunnel { +- entering group authorize {...} ++[preprocess] returns ok ++[mschap] returns noop [suffix] No '@' in User-Name = "DOMAIN\userADaccount", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [eap] EAP packet type response id 9 length 6 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated EAP isn't happening ? Follow, all the radiusd -X when start: FreeRADIUS Version 2.1.8, for host i686-pc-linux-gnu, built on Apr 28 2010 at 12:00:46 Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License v2. Starting - reading configuration files ... including configuration file /usr/local/etc/raddb/radiusd.conf including configuration file /usr/local/etc/raddb/proxy.conf including configuration file /usr/local/etc/raddb/clients.conf including files in directory /usr/local/etc/raddb/modules/ including configuration file /usr/local/etc/raddb/modules/expiration including configuration file /usr/local/etc/raddb/modules/detail.log including configuration file /usr/local/etc/raddb/modules/linelog including configuration file /usr/local/etc/raddb/modules/perl including configuration file /usr/local/etc/raddb/modules/passwd including configuration file /usr/local/etc/raddb/modules/mac2ip including configuration file /usr/local/etc/raddb/modules/attr_filter including configuration file /usr/local/etc/raddb/modules/cui including configuration file /usr/local/etc/raddb/modules/always including configuration file /usr/local/etc/raddb/modules/etc_group including configuration file /usr/local/etc/raddb/modules/exec including configuration file /usr/local/etc/raddb/modules/counter including configuration file /usr/local/etc/raddb/modules/ntlm_auth including configuration file /usr/local/etc/raddb/modules/expr including configuration file /usr/local/etc/raddb/modules/mac2vlan including configuration file /usr/local/etc/raddb/modules/policy including configuration file /usr/local/etc/raddb/modules/ippool including configuration file /usr/local/etc/raddb/modules/realm including configuration file /usr/local/etc/raddb/modules/echo including configuration file /usr/local/etc/raddb/modules/sql_log including configuration file /usr/local/etc/raddb/modules/attr_rewrite including configuration file /usr/local/etc/raddb/modules/pam including configuration file /usr/local/etc/raddb/modules/smbpasswd including configuration file /usr/local/etc/raddb/modules/chap including configuration file /usr/local/etc/raddb/modules/preprocess including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login including configuration file /usr/local/etc/raddb/modules/digest including configuration file /usr/local/etc/raddb/modules/acct_unique including configuration file /usr/local/etc/raddb/modules/pap including configuration file /usr/local/etc/raddb/modules/sradutmp including configuration file /usr/local/etc/raddb/modules/logintime including configuration file /usr/local/etc/raddb/modules/unix including configuration file /usr/local/etc/raddb/modules/otp including configuration file /usr/local/etc/raddb/modules/smsotp including configuration file /usr/local/etc/raddb/modules/checkval including configuration file /usr/local/etc/raddb/modules/inner-eap including configuration file /usr/local/etc/raddb/modules/ldap including configuration file /usr/local/etc/raddb/modules/files including configuration file /usr/local/etc/raddb/modules/detail.example.com including configuration file /usr/local/etc/raddb/modules/mschap including configuration file /usr/local/etc/raddb/modules/radutmp including configuration file /usr/local/etc/raddb/modules/wimax including configuration file /usr/local/etc/raddb/modules/krb5 including configuration file /usr/local/etc/raddb/modules/detail including configuration file /usr/local/etc/raddb/eap.conf including configuration file /usr/local/etc/raddb/sql.conf including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf including configuration file /usr/local/etc/raddb/policy.conf including files in directory /usr/local/etc/raddb/sites-enabled/ including configuration file /usr/local/etc/raddb/sites-enabled/default including configuration file /usr/local/etc/raddb/sites-enabled/control-socket including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel main { allow_core_dumps = no } including dictionary file /usr/local/etc/raddb/dictionary main { prefix = "/usr/local" localstatedir = "/usr/local/var" logdir = "/usr/local/var/log/radius" libdir = "/usr/local/lib:/usr/lib/freeradius:/usr/local/lib" radacctdir = "/usr/local/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 pidfile = "/usr/local/var/run/radiusd/radiusd.pid" checkrad = "/usr/local/sbin/checkrad" debug_level = 0 proxy_requests = yes log { stripped_names = no auth = no auth_badpass = no auth_goodpass = no } security { max_attributes = 200 reject_delay = 1 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### proxy server { retry_delay = 5 retry_count = 3 default_fallback = no dead_time = 120 wake_all_if_all_dead = no } home_server localhost { ipaddr = 127.0.0.1 port = 1812 type = "auth" secret = "testing123" response_window = 20 max_outstanding = 65536 require_message_authenticator = no zombie_period = 40 status_check = "status-server" ping_interval = 30 check_interval = 30 num_answers_to_alive = 3 num_pings_to_alive = 3 revive_interval = 120 status_check_timeout = 4 irt = 2 mrt = 16 mrc = 5 mrd = 30 } home_server_pool my_auth_failover { type = fail-over home_server = localhost } realm example.com { auth_pool = my_auth_failover } realm LOCAL { } radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "testing123" nastype = "other" } client ip_server_freeradius { require_message_authenticator = no secret = "sharedkey2010" shortname = "AP" nastype = "cisco" } client ip_AP1_cisco { require_message_authenticator = no secret = "sharedkey2010" shortname = "AP" nastype = "cisco" } client ip_AP2_cisco { require_message_authenticator = no secret = "sharedkey2010" shortname = "AP" nastype = "cisco" } } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_mschap Module: Instantiating mschap mschap { use_mppe = yes require_encryption = yes require_strong = yes with_ntdomain_hack = yes ntlm_auth = "/usr/bin/ntlm_auth --request-nt-key --domain=%{%{mschap:NT-Domain}:-DOMAIN} --username=%{%{Stripped-User-Name}:-%{User-Name:-None}} --challenge=%{mschap:Challenge:-00} --nt-response=%{mschap:NT-Response:-00}" } Module: Linked to module rlm_exec Module: Instantiating exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating expr Module: Linked to module rlm_expiration Module: Instantiating expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server inner-tunnel { modules { Module: Checking authenticate {...} for more modules to load Module: Instantiating ntlm_auth exec ntlm_auth { wait = yes program = "/usr/bin/ntlm_auth --request-nt-key --domain=DOMAIN --username=%{mschap:User-Name} --password=%{User-Password}" input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_eap Module: Instantiating eap eap { default_eap_type = "peap" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 4096 } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_leap Module: Instantiating eap-leap Module: Linked to sub-module rlm_eap_gtc Module: Instantiating eap-gtc gtc { challenge = "Password: " auth_type = "PAP" } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 pem_file_type = yes private_key_file = "/usr/local/etc/raddb/certs/server.pem" certificate_file = "/usr/local/etc/raddb/certs/server.pem" CA_file = "/usr/local/etc/raddb/certs/ca.pem" private_key_password = "whatever" dh_file = "/usr/local/etc/raddb/certs/dh" random_file = "/usr/local/etc/raddb/certs/random" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" make_cert_command = "/usr/local/etc/raddb/certs/bootstrap" cache { enable = no lifetime = 24 max_entries = 255 } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" } Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating preprocess preprocess { huntgroups = "/usr/local/etc/raddb/huntgroups" hints = "/usr/local/etc/raddb/hints" with_ascend_hack = no ascend_channels_per_line = 23 with_ntdomain_hack = no with_specialix_jetstream_hack = no with_cisco_vsa_hack = no with_alvarion_vsa_hack = no } Module: Linked to module rlm_realm Module: Instantiating suffix realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_files Module: Instantiating files files { usersfile = "/usr/local/etc/raddb/users" acctusersfile = "/usr/local/etc/raddb/acct_users" preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" compat = "no" } Module: Linked to module rlm_sql Module: Instantiating sql sql { driver = "rlm_sql_mysql" server = "localhost" port = "" login = "root" password = "sc123" radius_db = "radius_db" read_groups = yes sqltrace = no sqltracefile = "/usr/local/var/log/radius/sqltrace.sql" readclients = no deletestalesessions = yes num_sql_socks = 5 lifetime = 0 max_queries = 0 sql_user_name = "%{User-Name}" default_user_profile = "" nas_query = "SELECT id, nasname, shortname, type, secret FROM nas" authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" accounting_onoff_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = unix_timestamp('%S') - unix_timestamp(acctstarttime), acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = %{%{Acct-Delay-Time}:-0} WHERE acctstoptime IS NULL AND nasipaddress = '%{NAS-IP-Address}' AND acctstarttime <= '%S'" accounting_update_query = " UPDATE radacct SET framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_update_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctsessiontime, acctauthentic, connectinfo_start, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, servicetype, framedprotocol, framedipaddress, acctstartdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{X-Ascend-Session-Svr-Key}')" accounting_start_query = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay, xascendsessionsvrkey) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', '%S', NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{%{Acct-Delay-Time}:-0}', '0', '%{X-Ascend-Session-Svr-Key}')" accounting_start_query_alt = " UPDATE radacct SET acctstarttime = '%S', acctstartdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_start = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_stop_query = " UPDATE radacct SET acctstoptime = '%S', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', acctterminatecause = '%{Acct-Terminate-Cause}', acctstopdelay = '%{%{Acct-Delay-Time}:-0}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" accounting_stop_query_alt = " INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress, acctstartdelay, acctstopdelay) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', DATE_SUB('%S', INTERVAL (%{%{Acct-Session-Time}:-0} + %{%{Acct-Delay-Time}:-0}) SECOND), '%S', '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '0', '%{%{Acct-Delay-Time}:-0}')" group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" connect_failure_retry_delay = 60 simul_count_query = "" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') <mailto:%22%0d%20%20%20%20%20%20%20%20safe-characters%20=%20%22@abcdefghijkl mnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_> " <mailto:%22%0d%20%20%20%20%20%20%20%20safe-characters%20=%20%22@abcdefghijkl mnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_> safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to root@localhost:/radius_db rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 Module: Checking session {...} for more modules to load Module: Linked to module rlm_radutmp Module: Instantiating radutmp radutmp { filename = "/usr/local/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Linked to module rlm_attr_filter Module: Instantiating attr_filter.access_reject attr_filter attr_filter.access_reject { attrsfile = "/usr/local/etc/raddb/attrs.access_reject" key = "%{User-Name}" } } # modules } # server server { modules { Module: Checking authenticate {...} for more modules to load Module: Checking authorize {...} for more modules to load Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating detail detail { detailfile = "/usr/local/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Linked to module rlm_unix Module: Instantiating unix unix { radwtmp = "/usr/local/var/log/radius/radwtmp" } Module: Instantiating attr_filter.accounting_response attr_filter attr_filter.accounting_response { attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" key = "%{User-Name}" } Module: Checking session {...} for more modules to load Module: Checking post-proxy {...} for more modules to load Module: Checking post-auth {...} for more modules to load } # modules } # server radiusd: #### Opening IP addresses and Ports #### listen { type = "auth" ipaddr = * port = 0 } listen { type = "acct" ipaddr = * port = 0 } listen { type = "control" listen { socket = "/usr/local/var/run/radiusd/radiusd.sock" } } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /usr/local/var/run/radiusd/radiusd.sock Listening on proxy address * port 1814 Ready to process requests.