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.
dvmp wrote:
mschap validation occur with success but wireless client can't authenticate.
So... read the entire debug log.
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.
I'm not sure what that means.
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
I don't think that matters.
EAP isn't happening ?
No idea. You posted the logs when it works. That doesn't help.
Follow, all the radiusd -X when start:
That doesn't help, either. You need to post the FULL LOGS from WHEN IT FAILS. I have no idea why this is a difficult concept. Alan DeKok.
Follow, all the radiusd -X when start: That doesn't help, either. You need to post the FULL LOGS from WHEN IT FAILS. I have no idea why this is a difficult concept.
Hello Alan, follow the FULL LOGS from WHEN IT FAILS: Ready to process requests. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=167, length=167 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xbe734e6d92fd8666df3d4be010ee9302 EAP-Message = 0x020200190153554d4f4c434f4d50414c5c5343313031383536 NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 2 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> DOMAIN\userADaccount [sql] sql_set_user escaped user --> 'DOMAIN\userADaccount' rlm_sql (sql): Reserving sql socket id: 0 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY priority rlm_sql (sql): Released sql socket id: 0 [sql] User DOMAIN\userADaccount not found ++[sql] returns notfound ++? if (ok) ? Evaluating (ok) -> FALSE ++? if (ok) -> FALSE 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 167 to ip_AP_cisco port 1645 EAP-Message = 0x010300061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2be8d2392b8b84ab35544cf2 Finished request 380. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=168, length=265 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xe9675777fbc46a829f9242cb4a9c570e EAP-Message = 0x0203006919800000005f160301005a01000056030150917f3c269f39337bdde42e0cd4e09c 18a51faeeeaf74407f2fb85e72af0d9d000018002f00350005000ac013c014c009c00a003200 380013000401000015ff01000100000a0006000400170018000b00020100 NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" State = 0x2bebcbfd2be8d2392b8b84ab35544cf2 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 3 length 105 [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 TLS Length 95 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 005a], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 0791], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 168 to ip_AP_cisco port 1645 EAP-Message = 0x0104040019c0000007ce160301002a02000026030150917f59f69fe716f4b49831fcd5e0cb 1b23a89dddb6dfc21ecf9c6f0d68f98300002f0016030107910b00078d00078a00030f308203 0b308201f3a003020102020101300d06092a864886f70d0101040500308181310b3009060355 040613025054310f300d060355040813064c6973626f613112301006035504071309416c6672 616769646531143012060355040a130b53756d6f6c436f6d70616c3121301f06092a864886f7 0d01090116126473694073756d6f6c636f6d70616c2e7074311430120603550403130b53756d 6f6c436f6d70616c301e170d3130303530333138303030375a17 EAP-Message = 0x0d3133303530323138303030375a307b310b3009060355040613025054310f300d06035504 0813064c6973626f6131143012060355040a130b53756d6f6c436f6d70616c310c300a060355 040b1303647369311430120603550403130b53756d6f6c436f6d70616c3121301f06092a8648 86f70d01090116126473694073756d6f6c636f6d70616c2e707430819f300d06092a864886f7 0d010101050003818d0030818902818100f8957c8923b7bbefa910f557ab74f5f950f50b7211 be83d0ac53630430edf40257c6b4f7f4cbb584e3ae97b48f66ac31cb8ac302f064d9c8967654 128a9288297ff276e3c2dd91669b90d1ba52215990ad7a6a07e5 EAP-Message = 0x655f09ef328a16f80604e9df43c40d4b197981fe41bc0d3dc5950b56b1eb846226d3bcbca0 5be2c5de6faf0203010001a317301530130603551d25040c300a06082b06010505070301300d 06092a864886f70d0101040500038201010051142c0e7e03b78e59ae31d321302ff36b0f12d6 e289a38234d7ede583e3b668d33ff6f3ed2b02d19d6b0e56d7dd6626c085141fc9817327db0c cfadba32432eff943b646b8ddc71a022eef73e4dc78db61b754a088f68924f8ca6f4c6be87b5 e18340a9f7bf38e2818c593004289d08b47897da3ef342f58a4fe7af887635d90a7032e70cd5 bcc7345c6eaf2192930b30af56e55704799517a87adc6e9a630f EAP-Message = 0x5ed60b0ec2127ac4bbd28a605825c91d0f2d6f566e72e16e28baa9b6a9053176f3067465f1 3c92ac05deaba34a6a93ba1e35ac0bbd6eb1fd2def51f8d60cddde7d591e29d0f320a7cf5141 8c818b6fce6cadef076ef1614d1d26804377d7bb620004753082047130820359a00302010202 0900f17af5bcd5a336d4300d06092a864886f70d0101050500308181310b3009060355040613 025054310f300d060355040813064c6973626f613112301006035504071309416c6672616769 646531143012060355040a130b53756d6f6c436f6d70616c3121301f06092a864886f70d0109 0116126473694073756d6f6c636f6d70616c2e70743114301206 EAP-Message = 0x03550403130b53756d6f6c43 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2aefd2392b8b84ab35544cf2 Finished request 381. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=169, length=166 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xe9ee7fe2259ec0eb41eca800cfefc9b3 EAP-Message = 0x020400061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" State = 0x2bebcbfd2aefd2392b8b84ab35544cf2 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 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/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 169 to ip_AP_cisco port 1645 EAP-Message = 0x010503de19006f6d70616c301e170d3130303530333138303030375a170d31333035303231 38303030375a308181310b3009060355040613025054310f300d060355040813064c6973626f 613112301006035504071309416c6672616769646531143012060355040a130b53756d6f6c43 6f6d70616c3121301f06092a864886f70d01090116126473694073756d6f6c636f6d70616c2e 7074311430120603550403130b53756d6f6c436f6d70616c30820122300d06092a864886f70d 01010105000382010f003082010a0282010100c22f4331e11c8a97823dd2e22b09bb25d14519 b49edca72e81123bbd4bbdfdad77a968c8e3f8d46a8bd657a636 EAP-Message = 0x1544b1e58ac3589d701ee275a5d386a892def7dd0d90edb7adf46793d1bc90044e770f801e 90156b02162ef932142d4c6f26db1faf5000bf1a910fd5427e4e25ca904ef164e30983841e5a f2acfbf082eb4dbaabea870699ca7319d857dcfaaa3483097d0afea7286265f2a85df491c222 508c15e21bec0eaaeb13822ba9c0d67818db0bf0b37f6660e35d0f95383bb780c8adb6791086 cdc90cba8efa705b051a660d16c13bbfd9a56188e6deb6a044f12d2ff81efcc141608ad42310 9b52cce64543a2c9b3927e3101f1b8b6ca60a3e043810203010001a381e93081e6301d060355 1d0e041604143f6ba9f9a46015e19021e778c73e34281fe547cd EAP-Message = 0x3081b60603551d230481ae3081ab80143f6ba9f9a46015e19021e778c73e34281fe547cda1 8187a48184308181310b3009060355040613025054310f300d060355040813064c6973626f61 3112301006035504071309416c6672616769646531143012060355040a130b53756d6f6c436f 6d70616c3121301f06092a864886f70d01090116126473694073756d6f6c636f6d70616c2e70 74311430120603550403130b53756d6f6c436f6d70616c820900f17af5bcd5a336d4300c0603 551d13040530030101ff300d06092a864886f70d0101050500038201010071e8ab8308a34ac0 b8a083c5a6d85025b9e17a677db2c2f68d7cb42c906e9f3032e3 EAP-Message = 0x82bd876717c5f62932ca6a52145bb0050aec8af14c318eaef68b4c659b2b21f515ab29276d 06deb095cab322c3b3de511edfae55fa290d84e4038a2b1aabb45f0dca3e5875fab8cf241fb4 646f04e9e02c41ae9c1db6c9a23b1a63f9e9d7b708c62cafdc0274f7083fd81ce4e15287e938 ec06824545373b911cfe58a37bf41c72869947dc217fed008884a7b6c8dad73616637691dde2 b76addcbf184832b97e9466ca7c05ef33eb16104f0c81f094daa4f6e9367ce79c1a05cfed53c 494c64dffbfca5d1268e63bd4233a722499d893d774287bb2bc6729a28f906f5281603010004 0e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd29eed2392b8b84ab35544cf2 Finished request 382. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=170, length=368 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0x51c7051a6df98542134d7a4cad9364c4 EAP-Message = 0x020500d01980000000c6160301008610000082008091af4c6faa831c1fc81bb03e5ff94cf2 3e731941943dea2dfcd35b81a308a7c067baa9e9aa2957c246de00432cba628cd7539865ae4d 372b66f4fa0933bd45a5bb8714024a62af0dbc76093ab5f21462a4ca1a591749ef832ae95a34 da7324b770200ff87137821260203bae545c6420fe45a1182f2b15b6be59d3a0c4843ae91403 010001011603010030bde7b5b5b80bee6457a448f8b308cecaedcfafa9d9bae2b308a8f981bb dd6f3282870b56282593d4f354cef83cd99d77 NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" State = 0x2bebcbfd29eed2392b8b84ab35544cf2 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 5 length 208 [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 TLS Length 198 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0086], 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 Sending Access-Challenge of id 170 to ip_AP_cisco port 1645 EAP-Message = 0x01060041190014030100010116030100305ec9a3d4315420edbdc6c028395219fd94158e26 a45115351bf193c7038c04f670986dabb7b1c41f8ce9144e68757914 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd28edd2392b8b84ab35544cf2 Finished request 383. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=171, length=166 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xfe8482b3d38145735b0f520c17cc1691 EAP-Message = 0x020600061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" State = 0x2bebcbfd28edd2392b8b84ab35544cf2 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 6 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/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 ++[eap] returns handled Sending Access-Challenge of id 171 to ip_AP_cisco port 1645 EAP-Message = 0x0107002b1900170301002061a42fd36d3a766b798f27c976cddafc206068a3c819ff6eb651 d15eed5b0f3f Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2fecd2392b8b84ab35544cf2 Finished request 384. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=172, length=219 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xe3de5f32cf757439798596452a62f220 EAP-Message = 0x0207003b19001703010030c6a7e446886971749bd33a49dce1a8c66f7dc40acf7ea5e96ae5 3ef63b52e0839fc9ddde75f6e7db43fb5973b885005e NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" State = 0x2bebcbfd2fecd2392b8b84ab35544cf2 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 7 length 59 [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] Identity - DOMAIN\userADaccount [peap] Got tunneled request EAP-Message = 0x020700190153554d4f4c434f4d50414c5c5343313031383536 server { PEAP: Got tunneled identity of DOMAIN\userADaccount PEAP: Setting default EAP type for tunneled EAP session. PEAP: Setting User-Name to DOMAIN\userADaccount Sending tunneled request EAP-Message = 0x020700190153554d4f4c434f4d50414c5c5343313031383536 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "DOMAIN\\userADaccount" 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 7 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> DOMAIN\userADaccount [sql] sql_set_user escaped user --> 'DOMAIN\userADaccount' rlm_sql (sql): Reserving sql socket id: 4 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY priority rlm_sql (sql): Released sql socket id: 4 [sql] User DOMAIN\userADaccount not found ++[sql] returns notfound ++? if (ok) ? Evaluating (ok) -> FALSE ++? if (ok) -> FALSE Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x0108002e1a0108002910fcadce522673bc246f119f7426a0a16e53554d4f4c434f4d50414c 5c5343313031383536 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc282d9b6c28ac325c2d75d655a3b20bb [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0108002e1a0108002910fcadce522673bc246f119f7426a0a16e53554d4f4c434f4d50414c 5c5343313031383536 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc282d9b6c28ac325c2d75d655a3b20bb [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 172 to ip_AP_cisco port 1645 EAP-Message = 0x0108004b190017030100406d42040665bd9d04f2b78a1eb2be3610727e48b2e3516c0299bd b36241946ef288f565f1b18c6368b4028478ffdd39bc74f57de8d3f9b201b5b1064f0b198bf5 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2ee3d2392b8b84ab35544cf2 Finished request 385. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=173, length=267 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xd311903f2735fc06f2d6884aee5b1656 EAP-Message = 0x0208006b19001703010060989c617a4d75a71675d49b93798de03e0f756947618713174213 b3d5adace82bdd184ba506f1973dd881a8940bf0b36a33d406da7324fc84e71a3240d8773e16 c053b7ff734d9b1946a89cd876010c8a5f318d55f08536fe1bdb185df7f013e6 NAS-Port-Type = Wireless-802.11 NAS-Port = 33391 NAS-Port-Id = "33391" State = 0x2bebcbfd2ee3d2392b8b84ab35544cf2 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 8 length 107 [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 = 0x0208004f1a0208004a319afcbf0d90146863dcce62e55cbf6b2600000000000000003213a6 67f5405fe084a9e7291e326e0f0c68ce28482c998a0053554d4f4c434f4d50414c5c53433130 31383536 server { PEAP: Setting User-Name to DOMAIN\userADaccount Sending tunneled request EAP-Message = 0x0208004f1a0208004a319afcbf0d90146863dcce62e55cbf6b2600000000000000003213a6 67f5405fe084a9e7291e326e0f0c68ce28482c998a0053554d4f4c434f4d50414c5c53433130 31383536 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "DOMAIN\\userADaccount" State = 0xc282d9b6c28ac325c2d75d655a3b20bb 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 8 length 79 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> DOMAIN\userADaccount [sql] sql_set_user escaped user --> 'DOMAIN\userADaccount' rlm_sql (sql): Reserving sql socket id: 3 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY priority rlm_sql (sql): Released sql socket id: 3 [sql] User DOMAIN\userADaccount not found ++[sql] returns notfound ++? if (ok) ? Evaluating (ok) -> FALSE ++? if (ok) -> FALSE Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] +- entering group MS-CHAP {...} [mschap] Told to do MS-CHAPv2 for userADaccount with NT-Password [mschap] expand: %{mschap:NT-Domain} -> DOMAIN [mschap] expand: --domain=%{%{mschap:NT-Domain}:-DOMAIN} -> --domain=DOMAIN [mschap] expand: %{Stripped-User-Name} -> [mschap] ... expanding second conditional [mschap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [mschap] expand: %{User-Name:-None} -> DOMAIN\userADaccount [mschap] expand: --username=%{%{Stripped-User-Name}:-%{User-Name:-None}} -> --username=DOMAIN\userADaccount [mschap] mschap2: fc [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=6aa1a18a77be8437 [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=3213a667f5405fe084a9e7291e326e0f0c68ce28482c998a Exec-Program output: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program-Wait: plaintext: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x010900331a0308002e533d4436464245433343433334343334373542443835343334333432 3745313831384243414639333030 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc282d9b6c38bc325c2d75d655a3b20bb [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x010900331a0308002e533d4436464245433343433334343334373542443835343334333432 3745313831384243414639333030 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc282d9b6c38bc325c2d75d655a3b20bb [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 173 to ip_AP_cisco port 1645 EAP-Message = 0x0109005b190017030100505317a8177c77666155012c3211bf6b1c09ef17d29e1bb1fdcf91 ae82bf7dc5baae0e670350b67151aefb6bc5e1f18861cd55c6cdb04a829d8d59349be4ae0f68 a1ccd3f6714ea7a663b7c98ff3904cf9 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2de2d2392b8b84ab35544cf2 Finished request 386. Going to the next request Waking up in 4.9 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=174, length=167 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xbfbafd91f0c8db0b664454958ff46920 EAP-Message = 0x020200190153554d4f4c434f4d50414c5c5343313031383536 NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 2 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> DOMAIN\userADaccount [sql] sql_set_user escaped user --> 'DOMAIN\userADaccount' rlm_sql (sql): Reserving sql socket id: 2 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY priority rlm_sql (sql): Released sql socket id: 2 [sql] User DOMAIN\userADaccount not found ++[sql] returns notfound ++? if (ok) ? Evaluating (ok) -> FALSE ++? if (ok) -> FALSE 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 174 to ip_AP_cisco port 1645 EAP-Message = 0x010300061920 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cf924268144e0f611590a6390 Finished request 387. Going to the next request Waking up in 2.5 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=175, length=265 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0x654642a79ad18d4f9b0b43b0b5ff6b49 EAP-Message = 0x0203006919800000005f160301005a01000056030150917f3e21eb8628177ee842a7970a30 5073e5097d4247271e936867232502aa000018002f00350005000ac013c014c009c00a003200 380013000401000015ff01000100000a0006000400170018000b00020100 NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" State = 0xf9273f5cf924268144e0f611590a6390 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 3 length 105 [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 TLS Length 95 [peap] Length Included [peap] eaptls_verify returned 11 [peap] (other): before/accept initialization [peap] TLS_accept: before/accept initialization [peap] <<< TLS 1.0 Handshake [length 005a], ClientHello [peap] TLS_accept: SSLv3 read client hello A [peap] >>> TLS 1.0 Handshake [length 002a], ServerHello [peap] TLS_accept: SSLv3 write server hello A [peap] >>> TLS 1.0 Handshake [length 0791], Certificate [peap] TLS_accept: SSLv3 write certificate A [peap] >>> TLS 1.0 Handshake [length 0004], ServerHelloDone [peap] TLS_accept: SSLv3 write server done A [peap] TLS_accept: SSLv3 flush data [peap] TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 175 to ip_AP_cisco port 1645 EAP-Message = 0x0104040019c0000007ce160301002a02000026030150917f5b99dba76efa6994d17c05dfc4 c4c0d6a083078cb567fa7b772806479700002f0016030107910b00078d00078a00030f308203 0b308201f3a003020102020101300d06092a864886f70d0101040500308181310b3009060355 040613025054310f300d060355040813064c6973626f613112301006035504071309416c6672 616769646531143012060355040a130b53756d6f6c436f6d70616c3121301f06092a864886f7 0d01090116126473694073756d6f6c636f6d70616c2e7074311430120603550403130b53756d 6f6c436f6d70616c301e170d3130303530333138303030375a17 EAP-Message = 0x0d3133303530323138303030375a307b310b3009060355040613025054310f300d06035504 0813064c6973626f6131143012060355040a130b53756d6f6c436f6d70616c310c300a060355 040b1303647369311430120603550403130b53756d6f6c436f6d70616c3121301f06092a8648 86f70d01090116126473694073756d6f6c636f6d70616c2e707430819f300d06092a864886f7 0d010101050003818d0030818902818100f8957c8923b7bbefa910f557ab74f5f950f50b7211 be83d0ac53630430edf40257c6b4f7f4cbb584e3ae97b48f66ac31cb8ac302f064d9c8967654 128a9288297ff276e3c2dd91669b90d1ba52215990ad7a6a07e5 EAP-Message = 0x655f09ef328a16f80604e9df43c40d4b197981fe41bc0d3dc5950b56b1eb846226d3bcbca0 5be2c5de6faf0203010001a317301530130603551d25040c300a06082b06010505070301300d 06092a864886f70d0101040500038201010051142c0e7e03b78e59ae31d321302ff36b0f12d6 e289a38234d7ede583e3b668d33ff6f3ed2b02d19d6b0e56d7dd6626c085141fc9817327db0c cfadba32432eff943b646b8ddc71a022eef73e4dc78db61b754a088f68924f8ca6f4c6be87b5 e18340a9f7bf38e2818c593004289d08b47897da3ef342f58a4fe7af887635d90a7032e70cd5 bcc7345c6eaf2192930b30af56e55704799517a87adc6e9a630f EAP-Message = 0x5ed60b0ec2127ac4bbd28a605825c91d0f2d6f566e72e16e28baa9b6a9053176f3067465f1 3c92ac05deaba34a6a93ba1e35ac0bbd6eb1fd2def51f8d60cddde7d591e29d0f320a7cf5141 8c818b6fce6cadef076ef1614d1d26804377d7bb620004753082047130820359a00302010202 0900f17af5bcd5a336d4300d06092a864886f70d0101050500308181310b3009060355040613 025054310f300d060355040813064c6973626f613112301006035504071309416c6672616769 646531143012060355040a130b53756d6f6c436f6d70616c3121301f06092a864886f70d0109 0116126473694073756d6f6c636f6d70616c2e70743114301206 EAP-Message = 0x03550403130b53756d6f6c43 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cf823268144e0f611590a6390 Finished request 388. Going to the next request Waking up in 2.5 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=176, length=166 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xb9efc78ddc56b5697c3c806970efcccb EAP-Message = 0x020400061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" State = 0xf9273f5cf823268144e0f611590a6390 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 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/peap [eap] processing type peap [peap] processing EAP-TLS [peap] Received TLS ACK [peap] ACK handshake fragment handler [peap] eaptls_verify returned 1 [peap] eaptls_process returned 13 [peap] EAPTLS_HANDLED ++[eap] returns handled Sending Access-Challenge of id 176 to ip_AP_cisco port 1645 EAP-Message = 0x010503de19006f6d70616c301e170d3130303530333138303030375a170d31333035303231 38303030375a308181310b3009060355040613025054310f300d060355040813064c6973626f 613112301006035504071309416c6672616769646531143012060355040a130b53756d6f6c43 6f6d70616c3121301f06092a864886f70d01090116126473694073756d6f6c636f6d70616c2e 7074311430120603550403130b53756d6f6c436f6d70616c30820122300d06092a864886f70d 01010105000382010f003082010a0282010100c22f4331e11c8a97823dd2e22b09bb25d14519 b49edca72e81123bbd4bbdfdad77a968c8e3f8d46a8bd657a636 EAP-Message = 0x1544b1e58ac3589d701ee275a5d386a892def7dd0d90edb7adf46793d1bc90044e770f801e 90156b02162ef932142d4c6f26db1faf5000bf1a910fd5427e4e25ca904ef164e30983841e5a f2acfbf082eb4dbaabea870699ca7319d857dcfaaa3483097d0afea7286265f2a85df491c222 508c15e21bec0eaaeb13822ba9c0d67818db0bf0b37f6660e35d0f95383bb780c8adb6791086 cdc90cba8efa705b051a660d16c13bbfd9a56188e6deb6a044f12d2ff81efcc141608ad42310 9b52cce64543a2c9b3927e3101f1b8b6ca60a3e043810203010001a381e93081e6301d060355 1d0e041604143f6ba9f9a46015e19021e778c73e34281fe547cd EAP-Message = 0x3081b60603551d230481ae3081ab80143f6ba9f9a46015e19021e778c73e34281fe547cda1 8187a48184308181310b3009060355040613025054310f300d060355040813064c6973626f61 3112301006035504071309416c6672616769646531143012060355040a130b53756d6f6c436f 6d70616c3121301f06092a864886f70d01090116126473694073756d6f6c636f6d70616c2e70 74311430120603550403130b53756d6f6c436f6d70616c820900f17af5bcd5a336d4300c0603 551d13040530030101ff300d06092a864886f70d0101050500038201010071e8ab8308a34ac0 b8a083c5a6d85025b9e17a677db2c2f68d7cb42c906e9f3032e3 EAP-Message = 0x82bd876717c5f62932ca6a52145bb0050aec8af14c318eaef68b4c659b2b21f515ab29276d 06deb095cab322c3b3de511edfae55fa290d84e4038a2b1aabb45f0dca3e5875fab8cf241fb4 646f04e9e02c41ae9c1db6c9a23b1a63f9e9d7b708c62cafdc0274f7083fd81ce4e15287e938 ec06824545373b911cfe58a37bf41c72869947dc217fed008884a7b6c8dad73616637691dde2 b76addcbf184832b97e9466ca7c05ef33eb16104f0c81f094daa4f6e9367ce79c1a05cfed53c 494c64dffbfca5d1268e63bd4233a722499d893d774287bb2bc6729a28f906f5281603010004 0e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cfb22268144e0f611590a6390 Finished request 389. Going to the next request Waking up in 2.4 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=177, length=368 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0x4f560baf11832d1a5d0d5b2d35375199 EAP-Message = 0x020500d01980000000c61603010086100000820080b4e23df0bfeb70abedd7ab35ccce316b e7924e118e44403bd076df506ee79eb284639660b5c1f3cd7e2479b45d18944c79b70a193e43 98b7b92c9803e4f8366694528dbe1bd1ed59effdc1d8af7b5edc532b98c024389f4b6fb8ff82 813d9ef41b720cf9fb01d5a1705a0b0e325f312637d6c0bfec72db4a5c315fbff59da6ee1403 010001011603010030015784c05b51b9b8accc4f80602a9c32259b10e88c619b7c51cd2aec2d 91f49457fe314e35831d3affa91bd3a6dd41a7 NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" State = 0xf9273f5cfb22268144e0f611590a6390 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 5 length 208 [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 TLS Length 198 [peap] Length Included [peap] eaptls_verify returned 11 [peap] <<< TLS 1.0 Handshake [length 0086], 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 Sending Access-Challenge of id 177 to ip_AP_cisco port 1645 EAP-Message = 0x01060041190014030100010116030100304e5b08197c4a7a7d3f8147d32c699a0f3b58be1f 122a2bc4a7b19a429ee64b0e97c279728180cbb966bc73523c1a22cf Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cfa21268144e0f611590a6390 Finished request 390. Going to the next request Waking up in 2.4 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=178, length=166 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xd32f574e1096954528e1958f06a538be EAP-Message = 0x020600061900 NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" State = 0xf9273f5cfa21268144e0f611590a6390 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 6 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/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 ++[eap] returns handled Sending Access-Challenge of id 178 to ip_AP_cisco port 1645 EAP-Message = 0x0107002b1900170301002016e05c3a7c54b262bc4ef127d51d1bd9fb01a1da703100ee3f2a 12d8a22be1f6 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cfd20268144e0f611590a6390 Finished request 391. Going to the next request Waking up in 2.4 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=179, length=219 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xc7634ddb6b0a8e14ee1cb9b14b5148b9 EAP-Message = 0x0207003b19001703010030c84fb828e6fd4d888488a6e21767c8671bc5e7d560156e18bafc 2f455241ed32b713ce0cceb5c8db4a67fa407f094b26 NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" State = 0xf9273f5cfd20268144e0f611590a6390 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 7 length 59 [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] Identity - DOMAIN\userADaccount [peap] Got tunneled request EAP-Message = 0x020700190153554d4f4c434f4d50414c5c5343313031383536 server { PEAP: Got tunneled identity of DOMAIN\userADaccount PEAP: Setting default EAP type for tunneled EAP session. PEAP: Setting User-Name to DOMAIN\userADaccount Sending tunneled request EAP-Message = 0x020700190153554d4f4c434f4d50414c5c5343313031383536 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "DOMAIN\\userADaccount" 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 7 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> DOMAIN\userADaccount [sql] sql_set_user escaped user --> 'DOMAIN\userADaccount' rlm_sql (sql): Reserving sql socket id: 1 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY priority rlm_sql (sql): Released sql socket id: 1 [sql] User DOMAIN\userADaccount not found ++[sql] returns notfound ++? if (ok) ? Evaluating (ok) -> FALSE ++? if (ok) -> FALSE Found Auth-Type = EAP +- entering group authenticate {...} [eap] EAP Identity [eap] processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x0108002e1a01080029103e012c895c707cfdb101ee68490e0bc753554d4f4c434f4d50414c 5c5343313031383536 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf27c6434f2747e5953b4425059470cef [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x0108002e1a01080029103e012c895c707cfdb101ee68490e0bc753554d4f4c434f4d50414c 5c5343313031383536 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf27c6434f2747e5953b4425059470cef [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 179 to ip_AP_cisco port 1645 EAP-Message = 0x0108004b1900170301004057de040d203c3cc762a15223cbb44c524ae68b650240d40c5b0a a5577592f5d13d774a67022677016666a1fd8e4f6e667e2b0170e76de2a0321999d3965a323d Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cfc2f268144e0f611590a6390 Finished request 392. Going to the next request Waking up in 2.4 seconds. rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=180, length=267 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0x2310c60f37236cf885df903d9e417627 EAP-Message = 0x0208006b19001703010060fe540af30166803c2194908bec8c0f99f59304e2cc130549ce9c 284f30df439a93ed9c024feae41899750f970fc23047e637b25c81a7c6fef32537b0d3a6e8ee 7e279294982d2caede51bd341db026c2090297cf56845d8fcf7ef1bb8388951b NAS-Port-Type = Wireless-802.11 NAS-Port = 33392 NAS-Port-Id = "33392" State = 0xf9273f5cfc2f268144e0f611590a6390 NAS-IP-Address = ip_AP_cisco NAS-Identifier = "SC_APSI01" +- 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 8 length 107 [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 = 0x0208004f1a0208004a3159b3a0b6d49a89138f04f52abeb1f362000000000000000084a503 90b18fcd9f48bfdfd54cac709dc182cbc0937830e80053554d4f4c434f4d50414c5c53433130 31383536 server { PEAP: Setting User-Name to DOMAIN\userADaccount Sending tunneled request EAP-Message = 0x0208004f1a0208004a3159b3a0b6d49a89138f04f52abeb1f362000000000000000084a503 90b18fcd9f48bfdfd54cac709dc182cbc0937830e80053554d4f4c434f4d50414c5c53433130 31383536 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "DOMAIN\\userADaccount" State = 0xf27c6434f2747e5953b4425059470cef 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 8 length 79 [eap] No EAP Start, assuming it's an on-going EAP conversation ++[eap] returns updated ++[files] returns noop [sql] expand: %{User-Name} -> DOMAIN\userADaccount [sql] sql_set_user escaped user --> 'DOMAIN\userADaccount' rlm_sql (sql): Reserving sql socket id: 0 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'DOMAIN=5CuserADaccount' ORDER BY priority rlm_sql (sql): Released sql socket id: 0 [sql] User DOMAIN\userADaccount not found ++[sql] returns notfound ++? if (ok) ? Evaluating (ok) -> FALSE ++? if (ok) -> FALSE Found Auth-Type = EAP +- entering group authenticate {...} [eap] Request found, released from the list [eap] EAP/mschapv2 [eap] processing type mschapv2 [mschapv2] +- entering group MS-CHAP {...} [mschap] Told to do MS-CHAPv2 for userADaccount with NT-Password [mschap] expand: %{mschap:NT-Domain} -> DOMAIN [mschap] expand: --domain=%{%{mschap:NT-Domain}:-DOMAIN} -> --domain=DOMAIN [mschap] expand: %{Stripped-User-Name} -> [mschap] ... expanding second conditional [mschap] WARNING: Deprecated conditional expansion ":-". See "man unlang" for details [mschap] expand: %{User-Name:-None} -> DOMAIN\userADaccount [mschap] expand: --username=%{%{Stripped-User-Name}:-%{User-Name:-None}} -> --username=DOMAIN\userADaccount [mschap] mschap2: 3e [mschap] expand: --challenge=%{mschap:Challenge:-00} -> --challenge=b439b68a07408f48 [mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=84a50390b18fcd9f48bfdfd54cac709dc182cbc0937830e8 Exec-Program output: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program-Wait: plaintext: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled } # server inner-tunnel [peap] Got tunneled reply code 11 EAP-Message = 0x010900331a0308002e533d3732364234443430444634413838334346394336374342353743 4431414437373839303931373839 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf27c6434f3757e5953b4425059470cef [peap] Got tunneled reply RADIUS code 11 EAP-Message = 0x010900331a0308002e533d3732364234443430444634413838334346394336374342353743 4431414437373839303931373839 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf27c6434f3757e5953b4425059470cef [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 180 to ip_AP_cisco port 1645 EAP-Message = 0x0109005b190017030100502f79f75d930239412dc6c2abfbbed6c6930ef8ed21bedee2d972 9a2a1c987a285ddfd23ef4379fa1e6bf44ffa1eb1d08f8a24c50606ba462b9cbdf8c68923e52 72a032112af4c2f1af939b470d00b30b Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cff2e268144e0f611590a6390 Finished request 393. Going to the next request Waking up in 2.4 seconds.
On Tue, Nov 06, 2012 at 10:59:45PM -0000, dvmp wrote:
[mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=3213a667f5405fe084a9e7291e326e0f0c68ce28482c998a Exec-Program output: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program-Wait: plaintext: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled
OK, mschap seems to succeed.
} # server inner-tunnel [peap] Got tunneled reply code 11 ... [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 173 to ip_AP_cisco port 1645 EAP-Message = 0x0109005b190017030100505317a8177c77666155012c3211bf6b1c09ef17d29e1bb1fdcf91 ae82bf7dc5baae0e670350b67151aefb6bc5e1f18861cd55c6cdb04a829d8d59349be4ae0f68 a1ccd3f6714ea7a663b7c98ff3904cf9 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2de2d2392b8b84ab35544cf2 Finished request 386. Going to the next request Waking up in 4.9 seconds.
Client is sent the access challenge for the user's device with the mschap success.
rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=174, length=167 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xbfbafd91f0c8db0b664454958ff46920 EAP-Message = 0x020200190153554d4f4c434f4d50414c5c5343313031383536
User's device sends back an EAP Identity
[eap] EAP packet type response id 2 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation
Which is why this isn't picked up as part of the previous PEAP conversation, so the client isn't sent an Access-Accept ...
Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled } # server inner-tunnel ... ++[eap] returns handled Sending Access-Challenge of id 180 to ip_AP_cisco port 1645 EAP-Message = 0x0109005b190017030100502f79f75d930239412dc6c2abfbbed6c6930ef8ed21bedee2d972 9a2a1c987a285ddfd23ef4379fa1e6bf44ffa1eb1d08f8a24c50606ba462b9cbdf8c68923e52 72a032112af4c2f1af939b470d00b30b Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cff2e268144e0f611590a6390 Finished request 393. Going to the next request Waking up in 2.4 seconds.
... repeat of last time. The client has given up (that much is certain), so check EAP logs on the client. If it's Windows, you probably don't stand much of a chance of getting much useful (easy to read) logs. Check things like certificates expiring (but it doesn't sound like this). But first I'd restart winbind and see if it all works again. Then check your domain join (net ads testjoin or similar). I've seen similar before when everything individually worked OK, but the clients didn't like something that was sent back. [0] I think something has broken with the domain join, or winbind - it isn't at all obvious, but the client doesn't like it. You could also try re-joining the server to the domain. Oh, and you want to upgrade FreeRADIUS to 2.2.0; there's a security vulnerability in anything older. Cheers Matthew [0] http://notes.asd.me.uk/2011/01/11/freeradius-and-ntlm_auth-reminder-from-a-s... -- Matthew Newton, Ph.D. <mcn4@le.ac.uk> Systems Architect (UNIX and Networks), Network Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk>
Maybe is that Samba bug? The one that makes it apparently work:
[mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success but the client refuses to go on?
I can't search the archive right now, but I think it would be useful to know the Samba version. 2012/11/7 Matthew Newton <mcn4@leicester.ac.uk>
On Tue, Nov 06, 2012 at 10:59:45PM -0000, dvmp wrote:
[mschap] expand: --nt-response=%{mschap:NT-Response:-00} -> --nt-response=3213a667f5405fe084a9e7291e326e0f0c68ce28482c998a Exec-Program output: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program-Wait: plaintext: NT_KEY: 56F8FF72C1E6DB98E25A86F7E98A3C53 Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled
OK, mschap seems to succeed.
} # server inner-tunnel [peap] Got tunneled reply code 11 ... [peap] Got tunneled Access-Challenge ++[eap] returns handled Sending Access-Challenge of id 173 to ip_AP_cisco port 1645 EAP-Message =
0x0109005b190017030100505317a8177c77666155012c3211bf6b1c09ef17d29e1bb1fdcf91
ae82bf7dc5baae0e670350b67151aefb6bc5e1f18861cd55c6cdb04a829d8d59349be4ae0f68
a1ccd3f6714ea7a663b7c98ff3904cf9 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x2bebcbfd2de2d2392b8b84ab35544cf2 Finished request 386. Going to the next request Waking up in 4.9 seconds.
Client is sent the access challenge for the user's device with the mschap success.
rad_recv: Access-Request packet from host ip_AP_cisco port 1645, id=174, length=167 User-Name = "DOMAIN\\userADaccount" Framed-MTU = 1400 Called-Station-Id = "003a.994b.fd40" Calling-Station-Id = "e02a.8255.86ba" Service-Type = Login-User Message-Authenticator = 0xbfbafd91f0c8db0b664454958ff46920 EAP-Message = 0x020200190153554d4f4c434f4d50414c5c5343313031383536
User's device sends back an EAP Identity
[eap] EAP packet type response id 2 length 25 [eap] No EAP Start, assuming it's an on-going EAP conversation
Which is why this isn't picked up as part of the previous PEAP conversation, so the client isn't sent an Access-Accept
...
Exec-Program: returned: 0 [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success ++[eap] returns handled } # server inner-tunnel ... ++[eap] returns handled Sending Access-Challenge of id 180 to ip_AP_cisco port 1645 EAP-Message =
0x0109005b190017030100502f79f75d930239412dc6c2abfbbed6c6930ef8ed21bedee2d972
9a2a1c987a285ddfd23ef4379fa1e6bf44ffa1eb1d08f8a24c50606ba462b9cbdf8c68923e52
72a032112af4c2f1af939b470d00b30b Message-Authenticator = 0x00000000000000000000000000000000 State = 0xf9273f5cff2e268144e0f611590a6390 Finished request 393. Going to the next request Waking up in 2.4 seconds.
... repeat of last time.
The client has given up (that much is certain), so check EAP logs on the client. If it's Windows, you probably don't stand much of a chance of getting much useful (easy to read) logs. Check things like certificates expiring (but it doesn't sound like this).
But first I'd restart winbind and see if it all works again. Then check your domain join (net ads testjoin or similar). I've seen similar before when everything individually worked OK, but the clients didn't like something that was sent back. [0] I think something has broken with the domain join, or winbind - it isn't at all obvious, but the client doesn't like it. You could also try re-joining the server to the domain.
Oh, and you want to upgrade FreeRADIUS to 2.2.0; there's a security vulnerability in anything older.
Cheers
Matthew
[0] http://notes.asd.me.uk/2011/01/11/freeradius-and-ntlm_auth-reminder-from-a-s...
-- Matthew Newton, Ph.D. <mcn4@le.ac.uk>
Systems Architect (UNIX and Networks), Network Services, I.T. Services, University of Leicester, Leicester LE1 7RH, United Kingdom
For IT help contact helpdesk extn. 2253, <ithelp@le.ac.uk> - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- Alberto Martínez Setién Servicio Informático Universidad de Deusto Avda. de las Universidades, 24 48007 - Bilbao (SPAIN) Phone: +34 - 94 413 90 00 Ext 2684 Fax: +34 - 94 413 91 01
Maybe is that Samba bug?
The one that makes it apparently work:
[mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success but the client refuses to go on?
I can't search the archive right now, but I think it would be useful to know the Samba version.
Hello Alberto #smbd -V Version 3.4.0
I had just the same trouble as you. Here is my thread: http://www.mail-archive.com/freeradius-users@lists.freeradius.org/msg73649.h... And another here: http://www.mail-archive.com/freeradius-users@lists.freeradius.org/msg78218.h... Both make reference to this bug: https://bugzilla.samba.org/show_bug.cgi?id=6563 The bug is known to be solved in 3.5.16 onwards, so upgrade it. 2012/11/8 dvmp <dvmpbox@gmail.com>
Maybe is that Samba bug?
The one that makes it apparently work:
[mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok MSCHAP Success but the client refuses to go on?
I can't search the archive right now, but I think it would be useful to know the Samba version.****
Hello Alberto****
#smbd -V****
Version 3.4.0****
** **
- List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
-- Alberto Martínez Setién Servicio Informático Universidad de Deusto Avda. de las Universidades, 24 48007 - Bilbao (SPAIN) Phone: +34 - 94 413 90 00 Ext 2684 Fax: +34 - 94 413 91 01
Sending tunneled request EAP-Message = 0x0208004f1a0208004a319afcbf0d90146863dcce62e55cbf6b2600000000000000003213a6 67f5405fe084a9e7291e326e0f0c68ce28482c998a0053554d4f4c434f4d50414c5c53433130 31383536 FreeRADIUS-Proxied-To = 127.0.0.1 User-Name = "DOMAIN\\userADaccount" State = 0xc282d9b6c28ac325c2d75d655a3b20bb
EAP-Message parsed: 02 Code = 2 (EAP-Response) 08 Identifier = 8 00 4f Length = 79 1a Type = 26 (EAP-MSCHAPv2) 02 Opcode = 2 (Response) 08 MS-CHAP-v2-Id = 8 00 4a MS-Length = 74 31 Value-Size = 49 9a fc bf 0d 90 14 Peer-Challenge 68 63 dc ce 62 e5 5c bf 6b 26 00 00 00 00 00 00 Reserved 00 00 32 13 a6 67 f5 40 5f e0 84 a9 e7 29 1e 32 NT-Response 6e 0f 0c 68 ce 28 48 2c 99 8a 00 Flags = 0 53 55 4d 4f 4c 43 4f 4d 50 41 4c 5c 53 43 31 30 31 38 35 36 Name = SUMOLCOMPAL\SC101856
[peap] Got tunneled reply code 11 EAP-Message = 0x010900331a0308002e533d4436464245433343433334343334373542443835343334333432 3745313831384243414639333030 Message-Authenticator = 0x00000000000000000000000000000000 State = 0xc282d9b6c38bc325c2d75d655a3b20bb
EAP-Message parsed: 01 Code = 1 (EAP-Request) 09 Identifier = 9 00 33 Length = 51 1a Type = 26 (EAP-MSCHAPv2) 03 Opcode = 2 (Succes) 08 MS-CHAP-v2-Id = 8 00 2e MS-Length = 46 53 3d 44 36 46 42 45 43 33 43 43 33 34 34 33 34 37 35 42 44 38 35 34 33 34 33 34 32 37 45 31 38 31 38 42 43 41 46 39 33 30 30 Message = S=D6FBEC3CC3443475BD854343427E1818BCAF9300 MSCHAPv2 is a mutual authentication protocol. Supplicant has interrupted authentication process just after it receive EAP-MSCHAPv2 Success request packet. It means that Success request packet was not calculated using proper user password. In other words user password available at supplicant and at authentication server does not match.
participants (5)
-
Alan DeKok -
Alberto Martínez -
dvmp -
Iliya Peregoudov -
Matthew Newton