I have a new server giving me fits and I cannot figure out what the heck I did wrong: FreeRADIUS Version 3.0.0, for host x86_64-unknown-linux-gnu, built on Jul 27 2012 at 08:55:21 Copyright (C) 1999-2012 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/ippool including configuration file /usr/local/etc/raddb/modules/mac2ip including configuration file /usr/local/etc/raddb/modules/sqlippool including configuration file /usr/local/etc/raddb/sql/postgresql/ippool.conf including configuration file /usr/local/etc/raddb/modules/counter including configuration file /usr/local/etc/raddb/modules/policy including configuration file /usr/local/etc/raddb/modules/eap including configuration file /usr/local/etc/raddb/modules/ldap including configuration file /usr/local/etc/raddb/modules/sql including configuration file /usr/local/etc/raddb/sql/mysql/dialup.conf including configuration file /usr/local/etc/raddb/modules/pap including configuration file /usr/local/etc/raddb/modules/acct_unique including configuration file /usr/local/etc/raddb/modules/passwd including configuration file /usr/local/etc/raddb/modules/mschap including configuration file /usr/local/etc/raddb/modules/detail.example.com including configuration file /usr/local/etc/raddb/modules/otp including configuration file /usr/local/etc/raddb/modules/detail including configuration file /usr/local/etc/raddb/modules/ntlm_auth including configuration file /usr/local/etc/raddb/modules/pam including configuration file /usr/local/etc/raddb/modules/realm including configuration file /usr/local/etc/raddb/modules/exec including configuration file /usr/local/etc/raddb/modules/smsotp including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login including configuration file /usr/local/etc/raddb/modules/linelog including configuration file /usr/local/etc/raddb/modules/mac2vlan including configuration file /usr/local/etc/raddb/modules/wimax including configuration file /usr/local/etc/raddb/modules/logintime including configuration file /usr/local/etc/raddb/modules/rediswho including configuration file /usr/local/etc/raddb/modules/always including configuration file /usr/local/etc/raddb/modules/krb5 including configuration file /usr/local/etc/raddb/modules/redis including configuration file /usr/local/etc/raddb/modules/detail.log including configuration file /usr/local/etc/raddb/modules/radutmp including configuration file /usr/local/etc/raddb/modules/inner-eap including configuration file /usr/local/etc/raddb/modules/unix including configuration file /usr/local/etc/raddb/modules/preprocess including configuration file /usr/local/etc/raddb/modules/dynamic_clients including configuration file /usr/local/etc/raddb/modules/sradutmp including configuration file /usr/local/etc/raddb/modules/attr_rewrite including configuration file /usr/local/etc/raddb/modules/sql_log including configuration file /usr/local/etc/raddb/modules/etc_group including configuration file /usr/local/etc/raddb/modules/echo including configuration file /usr/local/etc/raddb/modules/perl including configuration file /usr/local/etc/raddb/modules/soh including configuration file /usr/local/etc/raddb/modules/chap including configuration file /usr/local/etc/raddb/modules/expr including configuration file /usr/local/etc/raddb/modules/opendirectory including configuration file /usr/local/etc/raddb/modules/digest 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/expiration including configuration file /usr/local/etc/raddb/modules/smbpasswd including configuration file /usr/local/etc/raddb/modules/checkval including configuration file /usr/local/etc/raddb/modules/files 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/control-socket including configuration file /usr/local/etc/raddb/sites-enabled/default including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel main { security { allow_core_dumps = no } } including dictionary file /usr/local/etc/raddb/dictionary main { name = "radiusd" prefix = "/usr/local" localstatedir = "/usr/local/var" sbindir = "/usr/local/sbin" logdir = "/usr/local/var/log/radius" run_dir = "/usr/local/var/run/radiusd" libdir = "/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 #### realm cueband.com { } radiusd: #### Loading Clients #### client localhost { ipaddr = 127.0.0.1 require_message_authenticator = no secret = "testing123" nastype = "other" proto = "*" } radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { # from file /usr/local/etc/raddb/radiusd.conf modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no allow_retry = yes } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /usr/local/etc/raddb/modules/eap eap { default_eap_type = "mschapv2" 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_pwd Module: Instantiating eap-pwd pwd { group = 19 fragment_size = 1020 server_id = "theserver@example.com" virtual_server = "inner-tunnel" } 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 { tls = "tls-common" } tls-config tls-common { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 CA_path = "/usr/local/etc/raddb/certs" 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" ecdh_curve = "prime256v1" cache { enable = yes lifetime = 24 max_entries = 255 } verify { } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" use_nonce = yes timeout = 0 softfail = yes } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = yes use_tunneled_reply = yes virtual_server = "inner-tunnel" include_length = yes } debug: Using cached TLS configuration from previous invocation Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { tls = "tls-common" default_eap_type = "mschapv2" copy_request_to_tunnel = yes use_tunneled_reply = yes proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no } debug: Using cached TLS configuration from previous invocation Module: Linked to sub-module rlm_eap_mschapv2 Module: Instantiating eap-mschapv2 mschapv2 { with_ntdomain_hack = no send_error = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/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_wimax Module: Instantiating module "wimax" from file /usr/local/etc/raddb/modules/wimax wimax { delete_mppe_keys = yes } Module: Linked to module rlm_sql Module: Instantiating module "sql" from file /usr/local/etc/raddb/modules/sql sql { driver = "rlm_sql_mysql" server = "10.50.0.10" port = "" login = "root" password = "unl0ck" radius_db = "radius" read_groups = yes sqltrace = no sqltracefile = "/usr/local/var/log/radius/sqltrace.sql" readclients = yes deletestalesessions = yes sql_user_name = "%{User-Name}" default_user_profile = "" nas_query = "SELECT id, nasname, shortname, type, secret, server 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" 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')" 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@10.50.0.10:/radius rlm_sql (sql): Initialising connection pool rlm_sql (sql): Processing generate_sql_clients rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret, server FROM nas rlm_sql (sql): Opening additional connection (0) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Reserved connection (0) rlm_sql (sql): Executing query rlm_sql (sql): Read entry nasname=10.50.4.2,shortname=Geauga AZ0,secret=unl0ck rlm_sql (sql): Adding client 10.50.4.2 (Geauga AZ0, server=<none>) to clients list rlm_sql (sql): Read entry nasname=10.50.3.2,shortname=Geauga AZ120,secret=unl0ck rlm_sql (sql): Adding client 10.50.3.2 (Geauga AZ120, server=<none>) to clients list rlm_sql (sql): Read entry nasname=10.50.2.2,shortname=Geauga AZ240,secret=unl0ck rlm_sql (sql): Adding client 10.50.2.2 (Geauga AZ240, server=<none>) to clients list rlm_sql (sql): Released connection (0) rlm_sql (sql): Closing idle connection (0): Too many free connections (1 > 0) rlm_sql (sql): Closing connection (0) Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/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 module "detail" from file /usr/local/etc/raddb/modules/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 module "unix" from file /usr/local/etc/raddb/modules/unix unix { radwtmp = "/usr/local/var/log/radius/radwtmp" } Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp radutmp { filename = "/usr/local/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Linked to module rlm_sql_log Module: Instantiating module "sql_log" from file /usr/local/etc/raddb/modules/sql_log sql_log { path = "/usr/local/var/log/radius/radacct/sql-relay" Post-Auth = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ('%{User-Name}', '%{User-Password:-Chap-Password}', '%{reply:Packet-Type}', '%S');" sql_user_name = "%{%{User-Name}:-DEFAULT}" utf8 = no safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" key = "%{User-Name}" relaxed = no } 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 Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/usr/local/etc/raddb/attrs.access_reject" key = "%{User-Name}" relaxed = no } } # modules } # server server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap Module: Checking authorize {...} for more modules to load 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 max_pps = 0 } listen { type = "acct" ipaddr = * port = 0 max_pps = 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 Opening new proxy address * port 1814 Listening on proxy address * port 1814 Ready to process requests. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=10, length=274 User-Name = "{am=1}{sm=1}396139FCA3777664EE26C1EC0FFFBFF2@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x0201003d017b616d3d317d7b736d3d317d3339363133394643413337373736363445453236 4331454330464646424646324063756562616e642e636f6d Message-Authenticator = 0xd3e9283d07c41fc0d964b697a06bcbd0 (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (0) group authorize { (0) - entering group authorize {...} (0) [preprocess] = ok (0) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (0) [wimax] = ok (0) eap : EAP packet type response id 1 length 61 (0) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (0) [eap] = ok (0) Found Auth-Type = EAP (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (0) group authenticate { (0) - entering group authenticate {...} (0) eap : EAP Identity (0) eap : processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge (0) [eap] = handled Sending Access-Challenge of id 10 to 10.50.4.2 port 49154 EAP-Message = 0x010200521a0102004d10e477a9dde07ba9f3550c4c7c181cd79d7b616d3d317d7b736d3d31 7d33393631333946434133373737363634454532364331454330464646424646324063756562 616e642e636f6d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x534198ee534382198a827a734ef513ce (0) Finished request 0. Waking up in 0.3 seconds. Waking up in 4.6 seconds. (0) Cleaning up request packet ID 10 with timestamp +4 Ready to process requests. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=11, length=274 User-Name = "{am=1}{sm=1}FACFD4B7EBA428D1FA794025E47CA4F5@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x0201003d017b616d3d317d7b736d3d317d4641434644344237454241343238443146413739 3430323545343743413446354063756562616e642e636f6d Message-Authenticator = 0x8822db580daa6714b72a1b28a3d08079 (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (1) group authorize { (1) - entering group authorize {...} (1) [preprocess] = ok (1) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (1) [wimax] = ok (1) eap : EAP packet type response id 1 length 61 (1) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (1) [eap] = ok (1) Found Auth-Type = EAP (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (1) group authenticate { (1) - entering group authenticate {...} (1) eap : EAP Identity (1) eap : processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge (1) [eap] = handled Sending Access-Challenge of id 11 to 10.50.4.2 port 49154 EAP-Message = 0x010200521a0102004d1022f39aa355b7811088ab8a1bc0b211007b616d3d317d7b736d3d31 7d46414346443442374542413432384431464137393430323545343743413446354063756562 616e642e636f6d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x03a9feba03abe4620c7aa45ec6c0be35 (1) Finished request 1. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=12, length=237 User-Name = "{am=1}{sm=1}FACFD4B7EBA428D1FA794025E47CA4F5@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x03a9feba03abe4620c7aa45ec6c0be35 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x020200060315 Message-Authenticator = 0x88fbeb571ec0612d6935910202c5f3cd (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (2) group authorize { (2) - entering group authorize {...} (2) [preprocess] = ok (2) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (2) [wimax] = ok (2) eap : EAP packet type response id 2 length 6 (2) eap : No EAP Start, assuming it's an on-going EAP conversation (2) [eap] = updated (2) sql : expand: %{User-Name} -> {am=1}{sm=1}FACFD4B7EBA428D1FA794025E47CA4F5@cueband.com (2) sql : sql_set_user escaped user --> '{am=1}{sm=1}FACFD4B7EBA428D1FA794025E47CA4F5@cueband.com' rlm_sql (sql): Opening additional connection (1) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Reserved connection (1) (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 = '=7Bam=3D1=7D=7Bsm=3D1=7DFACFD4B7EBA428D1FA794025E47CA4F5@cueband.com' ORDER BY id rlm_sql (sql): Executing query (2) sql : expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '=7Bam=3D1=7D=7Bsm=3D1=7DFACFD4B7EBA428D1FA794025E47CA4F5@cueband.com' ORDER BY priority rlm_sql (sql): Executing query rlm_sql (sql): Released connection (1) rlm_sql (sql): Closing idle connection (1): Too many free connections (1 > 0) rlm_sql (sql): Closing connection (1) (2) sql : User {am=1}{sm=1}FACFD4B7EBA428D1FA794025E47CA4F5@cueband.com not found (2) [sql] = notfound (2) [expiration] = noop (2) [logintime] = noop (2) Found Auth-Type = EAP (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (2) group authenticate { (2) - entering group authenticate {...} (2) eap : Request found, released from the list (2) eap : EAP NAK (2) eap : EAP-NAK asked for EAP-Type/ttls (2) eap : processing type ttls (2) ttls : Flushing SSL sessions (of #0) (2) ttls : Initiate (2) ttls : Start returned 1 (2) [eap] = handled Sending Access-Challenge of id 12 to 10.50.4.2 port 49154 EAP-Message = 0x010300061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x03a9feba02aaeb620c7aa45ec6c0be35 (2) Finished request 2. Waking up in 0.2 seconds. Waking up in 4.5 seconds. (1) Cleaning up request packet ID 11 with timestamp +19 (2) Cleaning up request packet ID 12 with timestamp +19 WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! WARNING: !! EAP session for state 0x03a9feba02aaeb62 did not finish! WARNING: !! Please read http://wiki.freeradius.org/Certificate_Compatibility WARNING: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! Ready to process requests. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=13, length=274 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x0201003d017b616d3d317d7b736d3d317d3934413433353634334330303244413345353446 3344393737394331464537304063756562616e642e636f6d Message-Authenticator = 0x3ddf39952f63cae6374be72419a86f1e (3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (3) group authorize { (3) - entering group authorize {...} (3) [preprocess] = ok (3) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (3) [wimax] = ok (3) eap : EAP packet type response id 1 length 61 (3) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize (3) [eap] = ok (3) Found Auth-Type = EAP (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (3) group authenticate { (3) - entering group authenticate {...} (3) eap : EAP Identity (3) eap : processing type mschapv2 rlm_eap_mschapv2: Issuing Challenge (3) [eap] = handled Sending Access-Challenge of id 13 to 10.50.4.2 port 49154 EAP-Message = 0x010200521a0102004d10bb0df969f618f1ce068b882685a6b16f7b616d3d317d7b736d3d31 7d39344134333536343343303032444133453534463344393737394331464537304063756562 616e642e636f6d Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1952930c19508927ccef9d983eb1b684 (3) Finished request 3. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=14, length=237 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x1952930c19508927ccef9d983eb1b684 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x020200060315 Message-Authenticator = 0xdf93d27137571334ab88b524c3a48c2e (4) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (4) group authorize { (4) - entering group authorize {...} (4) [preprocess] = ok (4) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (4) [wimax] = ok (4) eap : EAP packet type response id 2 length 6 (4) eap : No EAP Start, assuming it's an on-going EAP conversation (4) [eap] = updated (4) sql : expand: %{User-Name} -> {am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com (4) sql : sql_set_user escaped user --> '{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com' rlm_sql (sql): Opening additional connection (2) rlm_sql_mysql: Starting connect to MySQL server rlm_sql (sql): Reserved connection (2) (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 = '=7Bam=3D1=7D=7Bsm=3D1=7D94A435643C002DA3E54F3D9779C1FE70@cueband.com' ORDER BY id rlm_sql (sql): Executing query (4) sql : expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '=7Bam=3D1=7D=7Bsm=3D1=7D94A435643C002DA3E54F3D9779C1FE70@cueband.com' ORDER BY priority rlm_sql (sql): Executing query rlm_sql (sql): Released connection (2) rlm_sql (sql): Closing idle connection (2): Too many free connections (1 > 0) rlm_sql (sql): Closing connection (2) (4) sql : User {am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com not found (4) [sql] = notfound (4) [expiration] = noop (4) [logintime] = noop (4) Found Auth-Type = EAP (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (4) group authenticate { (4) - entering group authenticate {...} (4) eap : Request found, released from the list (4) eap : EAP NAK (4) eap : EAP-NAK asked for EAP-Type/ttls (4) eap : processing type ttls (4) ttls : Initiate (4) ttls : Start returned 1 (4) [eap] = handled Sending Access-Challenge of id 14 to 10.50.4.2 port 49154 EAP-Message = 0x010300061520 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1952930c18518627ccef9d983eb1b684 (4) Finished request 4. Waking up in 0.2 seconds. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=15, length=319 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x1952930c18518627ccef9d983eb1b684 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x0203005815800000004e16030100490100004503014e4a68271cb3efd28c7ffd6cb2d5a69e 02c7835c4f6293c615d9eced05ab3a1700001e00390038003500160013000a00330032002f00 15001200090014001100080100 Message-Authenticator = 0x94c9d5d50fa8ae9231510126cdcbd0a8 (5) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (5) group authorize { (5) - entering group authorize {...} (5) [preprocess] = ok (5) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (5) [wimax] = ok (5) eap : EAP packet type response id 3 length 88 (5) eap : Continuing tunnel setup. (5) [eap] = ok (5) Found Auth-Type = EAP (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (5) group authenticate { (5) - entering group authenticate {...} (5) eap : Request found, released from the list (5) eap : EAP/ttls (5) eap : processing type ttls (5) ttls : Authenticate (5) ttls : processing EAP-TLS TLS Length 78 (5) ttls : Length Included (5) ttls : eaptls_verify returned 11 (5) ttls : (other): before/accept initialization (5) ttls : TLS_accept: before/accept initialization (5) ttls : <<< TLS 1.0 Handshake [length 0049], ClientHello (5) ttls : TLS_accept: SSLv3 read client hello A (5) ttls : >>> TLS 1.0 Handshake [length 004a], ServerHello (5) ttls : TLS_accept: SSLv3 write server hello A (5) ttls : >>> TLS 1.0 Handshake [length 085e], Certificate (5) ttls : TLS_accept: SSLv3 write certificate A (5) ttls : >>> TLS 1.0 Handshake [length 020d], ServerKeyExchange (5) ttls : TLS_accept: SSLv3 write key exchange A (5) ttls : >>> TLS 1.0 Handshake [length 0004], ServerHelloDone (5) ttls : TLS_accept: SSLv3 write server done A (5) ttls : TLS_accept: SSLv3 flush data (5) ttls : TLS_accept: Need to read more data: SSLv3 read client certificate A In SSL Handshake Phase In SSL Accept mode (5) ttls : eaptls_process returned 13 (5) [eap] = handled Sending Access-Challenge of id 15 to 10.50.4.2 port 49154 EAP-Message = 0x010403ec15c000000acd160301004a0200004603015012ea53cce022a5de5d29899ab62086 5e0b6e626f469622254c0e50eb26ce08204cf09e9c9f327a21bd3f49610525905b42346e067b 3d1f254b14331103397e81003900160301085e0b00085a0008570003a6308203a23082028aa0 03020102020101300d06092a864886f70d0101050500308193310b3009060355040613024652 310f300d060355040813065261646975733112301006035504071309536f6d65776865726531 153013060355040a130c4578616d706c6520496e632e3120301e06092a864886f70d01090116 1161646d696e406578616d706c652e636f6d3126302406035504 EAP-Message = 0x03131d4578616d706c6520436572746966696361746520417574686f72697479301e170d31 32303732373132353731395a170d3133303732373132353731395a307c310b30090603550406 13024652310f300d0603550408130652616469757331153013060355040a130c4578616d706c 6520496e632e312330210603550403131a4578616d706c652053657276657220436572746966 69636174653120301e06092a864886f70d010901161161646d696e406578616d706c652e636f 6d30820122300d06092a864886f70d01010105000382010f003082010a0282010100be15f401 8757bc2f4b8f997f0a1e9d1ca5dc41fcfd0eb2b787eee7a3ebe5 EAP-Message = 0x21573525464944eab09b4ffe0337dcbd756fb653290d7665b5fd49130292b9398948b72fc7 10eda687e3fefb84f601a95504c4da1b4b905e13d942af2a415422bf2a7c08ce134b099cd075 bdb85739fbc3e8133fef94631116eb03a78c6b658adf2a244e40e371a74dfd5bcade5f98d0c2 f85e44c1084e012e7ad72a1344aa7600f22c9fe2a90a14d5c52623bd4397bdbfa7a383dfb8f0 23de8e0ccb25c81eabed2d5a8ea3853b9a3afbd538bf3c7fbd2cf48962bef7e3da3924b11892 c7b0c422647fb1a11ca55df5634be49c74b581869d1d9dfb28c982ad07613d51194075d6e502 03010001a317301530130603551d25040c300a06082b06010505 EAP-Message = 0x070301300d06092a864886f70d010105050003820101007f104aa64a39f7411fcc53af2182 ad8801983e5ce15768e9a4adc9fae77d3eb5c37b601ee0481abb014cfaf2c660a1d0711b81b5 0d325fdd1de77e7bea774a879fbbd4127019ce73a86d729f38e75fedbc09f96dfcbf49b824c5 2e7b3d5652a78421afc9caf2c197d0e6c9cd653c5828a12a87d9cc131871b941f8cda86a594b 8e1d08a16d2fa0f8912199d936fb59ac2bf50e0cd8a0390279aac75d04e9619ce5cfd35f6301 f89691b32f904b48a73714e48fe9ac157cd3540167ae31786cd2eb9a598f4941e499ce798c42 748c445ff91c88c423cba1d29ce7f3062ca1 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1952930c1b568627ccef9d983eb1b684 (5) Finished request 5. Waking up in 0.1 seconds. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=16, length=237 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x1952930c1b568627ccef9d983eb1b684 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x020400061500 Message-Authenticator = 0x50bbf63701339da3751b0969f39e75ff (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (6) group authorize { (6) - entering group authorize {...} (6) [preprocess] = ok (6) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (6) [wimax] = ok (6) eap : EAP packet type response id 4 length 6 (6) eap : Continuing tunnel setup. (6) [eap] = ok (6) Found Auth-Type = EAP (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (6) group authenticate { (6) - entering group authenticate {...} (6) eap : Request found, released from the list (6) eap : EAP/ttls (6) eap : processing type ttls (6) ttls : Authenticate (6) ttls : processing EAP-TLS (6) ttls : Received TLS ACK (6) ttls : Received TLS ACK (6) ttls : ACK handshake fragment handler (6) ttls : eaptls_verify returned 1 (6) ttls : eaptls_process returned 13 (6) [eap] = handled Sending Access-Challenge of id 16 to 10.50.4.2 port 49154 EAP-Message = 0x010503ec15c000000acdb86f4a892e7341ac83b4d73f079f9b7bc84f5bf9b2b36de758714f dd1128197b5a840004ab308204a73082038fa0030201020209009f2d7ada256cb590300d0609 2a864886f70d0101050500308193310b3009060355040613024652310f300d06035504081306 5261646975733112301006035504071309536f6d65776865726531153013060355040a130c45 78616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d 706c652e636f6d312630240603550403131d4578616d706c6520436572746966696361746520 417574686f72697479301e170d3132303732373132353731395a EAP-Message = 0x170d3133303732373132353731395a308193310b3009060355040613024652310f300d0603 55040813065261646975733112301006035504071309536f6d65776865726531153013060355 040a130c4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e 406578616d706c652e636f6d312630240603550403131d4578616d706c652043657274696669 6361746520417574686f7269747930820122300d06092a864886f70d01010105000382010f00 3082010a0282010100cfac03ee20e4ce9bdc0bd0a8138dcf8f6dd0a6cc7223212941e9637389 97c7804c8285dc1c6e118a8110d859c9115ac7632a3bf6ce899b EAP-Message = 0xdd5c0ecd12235a8bd509535b9d5a84728637c6e034ceff030ddf41d755fc87ad1573d20de7 9706f928cb3991f3f000c309b268d63517a7152351ddcdb0374c4d425b7dc79aaa54e04b824a e46c96debf4c67eb4f7644dfdd8d1b5f69e4abb512f60ac79b56687c096553bfb607384a82f0 40d00438e4448115ae8000f53994076a1a009b8c39961f200dd05fe6e89c8c694c8989d46e1b 393598a21f2c470b5f73b143730a631b2772402c6081b54f9725963cc2bef9642030ce9b1848 0ba7ef13a68535469f94f5370203010001a381fb3081f8301d0603551d0e041604144eb70ed6 4e9941f34a7066a80dccbede358df58f3081c80603551d230481 EAP-Message = 0xc03081bd80144eb70ed64e9941f34a7066a80dccbede358df58fa18199a48196308193310b 3009060355040613024652310f300d0603550408130652616469757331123010060355040713 09536f6d65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06 092a864886f70d010901161161646d696e406578616d706c652e636f6d312630240603550403 131d4578616d706c6520436572746966696361746520417574686f726974798209009f2d7ada 256cb590300c0603551d13040530030101ff300d06092a864886f70d01010505000382010100 35808c266c4978a7eb629101e5d27c6dbb11 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1952930c1a578627ccef9d983eb1b684 (6) Finished request 6. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=17, length=237 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x1952930c1a578627ccef9d983eb1b684 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x020500061500 Message-Authenticator = 0xfa070be428a7e0f31c1fb4c68760b4cf (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (7) group authorize { (7) - entering group authorize {...} (7) [preprocess] = ok (7) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (7) [wimax] = ok (7) eap : EAP packet type response id 5 length 6 (7) eap : Continuing tunnel setup. (7) [eap] = ok (7) Found Auth-Type = EAP (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (7) group authenticate { (7) - entering group authenticate {...} (7) eap : Request found, released from the list (7) eap : EAP/ttls (7) eap : processing type ttls (7) ttls : Authenticate (7) ttls : processing EAP-TLS (7) ttls : Received TLS ACK (7) ttls : Received TLS ACK (7) ttls : ACK handshake fragment handler (7) ttls : eaptls_verify returned 1 (7) ttls : eaptls_process returned 13 (7) [eap] = handled Sending Access-Challenge of id 17 to 10.50.4.2 port 49154 EAP-Message = 0x01060313158000000acd58f51ec582b80339e1b6e4840c26464b17b59fd9be0f60822d0d5a ae008d36d7088a20489e421786f0359fd2e268ceafa3bf9c07bbf1c2e9267fdb99690d3d2f13 3235d56cf9583252b353b79cca2c57dbe3ca644f175bb48df9389d3575979cef123841f22597 956732f89380db12983f038ae0d7b7d4cbe8adac83af314936a2c318ea702c17cf0749d916d0 750a5af92a40a8419f9444ba0da4604878fd7094eaddf055aedcf748443c1f293bacd4e4d297 c6f5c6bf09039fdd9f6f570a24532a162a2688be5e16ad62f6050d4091be7d0a5c933c653802 3ac87145d6a53bf81dbb0246e3f745dca39b773e5b160301020d EAP-Message = 0x0c0002090080937241455120e5f86723331c043ae3551d357c209fb557cb58312d1b1583a9 1e018e4955d2f2891568f6490d44dab517976062592a362a6857f2578ef2d1865e469f97f7dc 2b8b1fa0a1fed25aac2ccee0160f3369a80a73d70958c736f3eb6a0d59a74e8414372a5b2963 8a7e74e2875188d3f4280aa8633ac3ecac606c8abb00010200800198b440f8e9d92975289bc5 b020fe363603f57a4d9edf3e3627b137e0c60ba81756694410d0b588f253221c1b09b34d32a8 402a77d2b83eea0fc6551c1ef056f4d7b0db870f4a4fb6fc4a6e140dd6faaca5d1948255fa0f 1dbc352adfa2eb6585b5a2c0ae3dc2a738aa4ee53950dfe1bd40 EAP-Message = 0x368f69b0b921b6e14f7be84725b60100193202fd650f77df635b926ddebc6b0acf680a5ff5 454f8560c920e0ed1437ede5982e783fc5c1ab38cec26a2379ff7595fef27e4db5aee82b9523 31fd604d86daf606276006464defb8b06ff3e76ca02800f4a3401b803dca6ae97459add32448 d59fbd344f8dc8bb6622a97cf8cabfb6f6827eb10c8df775e5ffe8752747eff36249120770dd 48d2c885d7f93caff347d9baad490b640e45240629fc317a4cfae657cec634ac2809f214c984 fff2e9d6d8fff9ca019bf88aa997fd0cdaa3d726c3efa983167f925e3c40be1eeb9a2121b465 605dea0d6371adecf2d270321a2b30d427c848e94a37a00fbeef EAP-Message = 0xab2f2f04cb1feffc067e581402bb2bf5913ea116030100040e000000 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1952930c1d548627ccef9d983eb1b684 (7) Finished request 7. Waking up in 4.3 seconds. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=18, length=439 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x1952930c1d548627ccef9d983eb1b684 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x020600d01580000000c616030100861000008200804601ed4cea7a4fbf3ea936bb190447aa 79e902f76bd9ca26bf56b5002c860bb7514513debe0262889773db19e9fde0637c596e9f8e95 c758e5572d94b816837ff33624babf64a1e49b10391c78c7d0429098de0483b093fdc72b16e8 efe20271ceb0c635de78bf1d6676197e9132e558accb96c43accde388dc47be89ee22b401403 0100010116030100308113e5ba633d23953215f260177dec8b25a61b3db96c29b3986c88e2c4 ed89e87c5f2bdc224e78ade7702668167ba5a6 Message-Authenticator = 0xf1cb9dcb23d2730fdd71275b451e332d (8) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (8) group authorize { (8) - entering group authorize {...} (8) [preprocess] = ok (8) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (8) [wimax] = ok (8) eap : EAP packet type response id 6 length 208 (8) eap : Continuing tunnel setup. (8) [eap] = ok (8) Found Auth-Type = EAP (8) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (8) group authenticate { (8) - entering group authenticate {...} (8) eap : Request found, released from the list (8) eap : EAP/ttls (8) eap : processing type ttls (8) ttls : Authenticate (8) ttls : processing EAP-TLS TLS Length 198 (8) ttls : Length Included (8) ttls : eaptls_verify returned 11 (8) ttls : <<< TLS 1.0 Handshake [length 0086], ClientKeyExchange (8) ttls : TLS_accept: SSLv3 read client key exchange A (8) ttls : <<< TLS 1.0 ChangeCipherSpec [length 0001] (8) ttls : <<< TLS 1.0 Handshake [length 0010], Finished (8) ttls : TLS_accept: SSLv3 read finished A (8) ttls : >>> TLS 1.0 ChangeCipherSpec [length 0001] (8) ttls : TLS_accept: SSLv3 write change cipher spec A (8) ttls : >>> TLS 1.0 Handshake [length 0010], Finished (8) ttls : TLS_accept: SSLv3 write finished A (8) ttls : TLS_accept: SSLv3 flush data SSL: adding session 4cf09e9c9f327a21bd3f49610525905b42346e067b3d1f254b14331103397e81 to cache (8) ttls : (other): SSL negotiation finished successfully SSL Connection Established (8) ttls : eaptls_process returned 13 (8) [eap] = handled Sending Access-Challenge of id 18 to 10.50.4.2 port 49154 EAP-Message = 0x0107004515800000003b1403010001011603010030570f9a8f3128c5efe3ab40fedb710a6a 98b4a758734a6f041228fc595846a4271cd9fab4385458fcc226338fb0b91a15 Message-Authenticator = 0x00000000000000000000000000000000 State = 0x1952930c1c558627ccef9d983eb1b684 (8) Finished request 8. Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 10.50.4.2 port 49154, id=19, length=423 User-Name = "{am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com" NAS-IP-Address = 10.50.4.2 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\254\201\022\027\217\352" NAS-Identifier = "010010010000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x1952930c1c558627ccef9d983eb1b684 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303130303130303130303030303332303030 EAP-Message = 0x020700c015001703010020b101f024e95005e369d9c5d192382a8d453c5e51c9af2d15d2a8 b755743b33d3170301009021437256763846c6c051ca099d0357cea3821edb948ba156193791 20f1b97521bb987a775214f1564df6ffbb3f01fd4476a5319bbe7ce4fd1dd8a93abd57cb28b6 b8aed2f37753ede1783589002e0404d1a4247525b941b14d6708f0988df41511758749c51d52 9423167e100ab43bab6991c786266a10f5dd03324930afb09ae3020edcc6a9ac7a77eed51b44 0c88a8 Message-Authenticator = 0xbfaf7a1a3a19e84106b8191119a83fcc (9) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default (9) group authorize { (9) - entering group authorize {...} (9) [preprocess] = ok (9) [mschap] = noop rlm_wimax: Fixing WiMAX binary Calling-Station-Id to ac-81-12-17-8f-ea (9) [wimax] = ok (9) eap : EAP packet type response id 7 length 192 (9) eap : Continuing tunnel setup. (9) [eap] = ok (9) Found Auth-Type = EAP (9) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (9) group authenticate { (9) - entering group authenticate {...} (9) eap : Request found, released from the list (9) eap : EAP/ttls (9) eap : processing type ttls (9) ttls : Authenticate (9) ttls : processing EAP-TLS (9) ttls : eaptls_verify returned 7 (9) ttls : Done initial handshake (9) ttls : eaptls_process returned 7 (9) ttls : Session established. Proceeding to decode tunneled attributes. (9) ttls : Tunneled attribute 1 is too short (1 < 12) to contain anything useful. SSL: Removing session 4cf09e9c9f327a21bd3f49610525905b42346e067b3d1f254b14331103397e81 from the cache (9) eap : Handler failed in EAP/ttls (9) eap : Failed in EAP select (9) [eap] = invalid (9) Failed to authenticate the user. (9) Using Post-Auth-Type Reject (9) # Executing group from file /usr/local/etc/raddb/sites-enabled/default (9) group REJECT { (9) - entering group REJECT {...} (9) attr_filter.access_reject : expand: %{User-Name} -> {am=1}{sm=1}94A435643C002DA3E54F3D9779C1FE70@cueband.com (9) attr_filter.access_reject : Matched entry DEFAULT at line 11 (9) [attr_filter.access_reject] = updated (9) Finished request 9. Waking up in 0.2 seconds. Waking up in 0.1 seconds. Waking up in 0.6 seconds. (9) Sending delayed reject Sending Access-Reject of id 19 to 10.50.4.2 port 49154 EAP-Message = 0x04070004 Message-Authenticator = 0x00000000000000000000000000000000 Waking up in 2.3 seconds. (3) Cleaning up request packet ID 13 with timestamp +35 (4) Cleaning up request packet ID 14 with timestamp +35 (5) Cleaning up request packet ID 15 with timestamp +36
David Peterson wrote:
I have a new server giving me fits and I cannot figure out what the heck I did wrong:
Nothing.
(9) ttls : Session established. Proceeding to decode tunneled attributes. (9) ttls : Tunneled attribute 1 is too short (1 < 12) to contain anything useful.
Which supplicant are you using? It's not encoding the inner-tunnel data correctly. I'll also note you're running the bleeding edge "master" branch. There might be a compatibility change needed, as the TTLS verification code changed recently. Alan DeKok.
I came up with that conclusion as well. I am going to use my known good source. David -----Original Message----- From: Alan DeKok [mailto:aland@deployingradius.com] Sent: Friday, July 27, 2012 4:54 PM To: David Peterson-WirelessConnections; FreeRadius users mailing list Subject: Re: EAP problem David Peterson wrote:
I have a new server giving me fits and I cannot figure out what the heck I did wrong:
Nothing.
(9) ttls : Session established. Proceeding to decode tunneled attributes. (9) ttls : Tunneled attribute 1 is too short (1 < 12) to contain anything useful.
Which supplicant are you using? It's not encoding the inner-tunnel data correctly. I'll also note you're running the bleeding edge "master" branch. There might be a compatibility change needed, as the TTLS verification code changed recently. Alan DeKok.
On 27 Jul 2012, at 22:24, Alan DeKok <aland@DEPLOYINGRADIUS.COM> wrote:
David Peterson wrote:
I came up with that conclusion as well. I am going to use my known good source.
Please also say which supplicant you're using. Knowing *which* software is broken is useful.
Or even just posting the full debug with -Xxx so we get the hex output from the inner tunnel. -Arran
I will send a full debug prior to recompiling tomorrow. David -----Original Message----- From: Arran Cudbard-Bell [mailto:a.cudbardb@freeradius.org] Sent: Friday, July 27, 2012 6:05 PM To: FreeRadius users mailing list Cc: David Peterson-WirelessConnections Subject: Re: EAP problem On 27 Jul 2012, at 22:24, Alan DeKok <aland@DEPLOYINGRADIUS.COM> wrote:
David Peterson wrote:
I came up with that conclusion as well. I am going to use my known good source.
Please also say which supplicant you're using. Knowing *which* software is broken is useful.
Or even just posting the full debug with -Xxx so we get the hex output from the inner tunnel. -Arran
I am using an Alvarion WiMax CPE. The CPE works on my other radius server just not the new one. David -----Original Message----- From: Alan DeKok [mailto:aland@deployingradius.com] Sent: Friday, July 27, 2012 5:24 PM To: David Peterson-WirelessConnections; FreeRadius users mailing list Subject: Re: EAP problem David Peterson wrote:
I came up with that conclusion as well. I am going to use my known good source.
Please also say which supplicant you're using. Knowing *which* software is broken is useful. Alan DeKok.
David Peterson wrote:
I am using an Alvarion WiMax CPE. The CPE works on my other radius server just not the new one.
I should have known. Can you at least run "radiusd -Xx" with the recent git "master" ? That will let us know exactly what is going on inside of the TTLS tunnel. That will allow us to fix the problem, too. Alan DeKok.
hi list! i think we found same issue as david: something fails in eap-ttls. my supplicant is a huawei wimax cpe [that obviously works great on my other radius server but not the new one...]. we noticed some commit about ttls so we built master branch from git in the afternoon but still we have this problem; are we wrong about new eap-ttls configuration section? you can find my "radiusd -Xxx" as attachment. thanks folks, marco Il 28/07/12 23.25, Alan DeKok ha scritto:
David Peterson wrote:
I am using an Alvarion WiMax CPE. The CPE works on my other radius server just not the new one.
I should have known.
Can you at least run "radiusd -Xx" with the recent git "master" ? That will let us know exactly what is going on inside of the TTLS tunnel.
That will allow us to fix the problem, too.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
marco perugini wrote:
hi list! i think we found same issue as david: something fails in eap-ttls. my supplicant is a huawei wimax cpe [that obviously works great on my other radius server but not the new one...]. we noticed some commit about ttls so we built master branch from git in the afternoon but still we have this problem; are we wrong about new eap-ttls configuration section? you can find my "radiusd -Xxx" as attachment.
Could you grab the latest version from "master"? I added a patch to print out the contents of the tunnel. This lets me know *what* is in the tunnel, so I know how to fix it. Thanks. Alan DeKok.
i'm sorry, i though it was the right one.. Il 01/08/12 17.59, Alan DeKok ha scritto:
marco perugini wrote:
hi list! i think we found same issue as david: something fails in eap-ttls. my supplicant is a huawei wimax cpe [that obviously works great on my other radius server but not the new one...]. we noticed some commit about ttls so we built master branch from git in the afternoon but still we have this problem; are we wrong about new eap-ttls configuration section? you can find my "radiusd -Xxx" as attachment.
Could you grab the latest version from "master"? I added a patch to print out the contents of the tunnel. This lets me know *what* is in the tunnel, so I know how to fix it.
Thanks.
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
Alan, Let me know if this debug is the latest master. It should be but I don't have personal verification. The EAP issue is persisting as of this version: rad@radserv:~$ sudo radiusd -Xxx Thu Aug 2 12:28:36 2012 : Info: FreeRADIUS Version 3.0.0, for host i686-pc-linux-gnu, built on Aug 1 2012 at 16:18:04 Thu Aug 2 12:28:36 2012 : Info: Copyright (C) 1999-2012 The FreeRADIUS server project and contributors. Thu Aug 2 12:28:36 2012 : Info: There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A Thu Aug 2 12:28:36 2012 : Info: PARTICULAR PURPOSE. Thu Aug 2 12:28:36 2012 : Info: You may redistribute copies of FreeRADIUS under the terms of the Thu Aug 2 12:28:36 2012 : Info: GNU General Public License v2. Thu Aug 2 12:28:36 2012 : Info: Thu Aug 2 12:28:36 2012 : Info: Starting - reading configuration files ... Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/radiusd.conf Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/proxy.conf Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/clients.conf Thu Aug 2 12:28:36 2012 : Debug: including files in directory /usr/local/etc/raddb/modules/ Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/expiration Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/dynamic_clients Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/preprocess Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/radutmp Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/files Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_filter Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/realm Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/perl Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/sql_log Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/mschap Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/replicate Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/pam Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/detail Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/sradutmp Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/cui Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/echo Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/sqlcounter_expire_on_login Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2ip Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/inner-eap Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/opendirectory Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.example.com Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/checkval Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/etc_group Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/wimax Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/passwd Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/chap Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/detail.log Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/digest Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/attr_rewrite Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/linelog Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/pap Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/smbpasswd Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/ntlm_auth Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/otp Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/unix Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/rediswho Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/ippool Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/counter Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/acct_unique Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/krb5 Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/redis Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/mac2vlan Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/expr Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/exec Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/logintime Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/policy Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/soh Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/ldap Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/smsotp Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/modules/always Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/eap.conf Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/policy.conf Thu Aug 2 12:28:36 2012 : Debug: including files in directory /usr/local/etc/raddb/sites-enabled/ Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/control-socket Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:28:36 2012 : Debug: including configuration file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Aug 2 12:28:36 2012 : Debug: main { Thu Aug 2 12:28:36 2012 : Debug: security { Thu Aug 2 12:28:36 2012 : Debug: allow_core_dumps = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Error: /usr/local/etc/raddb/radiusd.conf[0]: "allow_core_dumps" is deprecated. Please replace it with the up-to-date configuration Thu Aug 2 12:28:36 2012 : Debug: allow_core_dumps = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: including dictionary file /usr/local/etc/raddb/dictionary Thu Aug 2 12:28:36 2012 : Debug: main { Thu Aug 2 12:28:36 2012 : Debug: name = "radiusd" Thu Aug 2 12:28:36 2012 : Debug: prefix = "/usr/local" Thu Aug 2 12:28:36 2012 : Debug: localstatedir = "/usr/local/var" Thu Aug 2 12:28:36 2012 : Debug: sbindir = "/usr/local/sbin" Thu Aug 2 12:28:36 2012 : Debug: logdir = "/usr/local/var/log/radius" Thu Aug 2 12:28:36 2012 : Debug: run_dir = "/usr/local/var/run/radiusd" Thu Aug 2 12:28:36 2012 : Debug: libdir = "/usr/local/lib:/usr/local/lib" Thu Aug 2 12:28:36 2012 : Debug: radacctdir = "/usr/local/var/log/radius/radacct" Thu Aug 2 12:28:36 2012 : Debug: hostname_lookups = no Thu Aug 2 12:28:36 2012 : Debug: max_request_time = 30 Thu Aug 2 12:28:36 2012 : Debug: cleanup_delay = 5 Thu Aug 2 12:28:36 2012 : Debug: max_requests = 1024 Thu Aug 2 12:28:36 2012 : Debug: pidfile = "/usr/local/var/run/radiusd/radiusd.pid" Thu Aug 2 12:28:36 2012 : Debug: checkrad = "/usr/local/sbin/checkrad" Thu Aug 2 12:28:36 2012 : Debug: debug_level = 0 Thu Aug 2 12:28:36 2012 : Debug: proxy_requests = yes Thu Aug 2 12:28:36 2012 : Debug: log { Thu Aug 2 12:28:36 2012 : Debug: stripped_names = no Thu Aug 2 12:28:36 2012 : Debug: auth = no Thu Aug 2 12:28:36 2012 : Debug: auth_badpass = no Thu Aug 2 12:28:36 2012 : Debug: auth_goodpass = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: security { Thu Aug 2 12:28:36 2012 : Debug: max_attributes = 200 Thu Aug 2 12:28:36 2012 : Debug: reject_delay = 1 Thu Aug 2 12:28:36 2012 : Debug: status_server = yes Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: radiusd: #### Loading Realms and Home Servers #### Thu Aug 2 12:28:36 2012 : Debug: proxy server { Thu Aug 2 12:28:36 2012 : Debug: retry_delay = 5 Thu Aug 2 12:28:36 2012 : Debug: retry_count = 3 Thu Aug 2 12:28:36 2012 : Debug: default_fallback = no Thu Aug 2 12:28:36 2012 : Debug: dead_time = 120 Thu Aug 2 12:28:36 2012 : Debug: wake_all_if_all_dead = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: home_server localhost { Thu Aug 2 12:28:36 2012 : Debug: ipaddr = 127.0.0.1 Thu Aug 2 12:28:36 2012 : Debug: port = 1812 Thu Aug 2 12:28:36 2012 : Debug: type = "auth" Thu Aug 2 12:28:36 2012 : Debug: secret = "testing123" Thu Aug 2 12:28:36 2012 : Debug: response_window = 20 Thu Aug 2 12:28:36 2012 : Debug: max_outstanding = 65536 Thu Aug 2 12:28:36 2012 : Debug: require_message_authenticator = yes Thu Aug 2 12:28:36 2012 : Debug: zombie_period = 40 Thu Aug 2 12:28:36 2012 : Debug: status_check = "status-server" Thu Aug 2 12:28:36 2012 : Debug: ping_interval = 30 Thu Aug 2 12:28:36 2012 : Debug: check_interval = 30 Thu Aug 2 12:28:36 2012 : Debug: num_answers_to_alive = 3 Thu Aug 2 12:28:36 2012 : Debug: num_pings_to_alive = 3 Thu Aug 2 12:28:36 2012 : Debug: revive_interval = 120 Thu Aug 2 12:28:36 2012 : Debug: status_check_timeout = 4 Thu Aug 2 12:28:36 2012 : Debug: coa { Thu Aug 2 12:28:36 2012 : Debug: irt = 2 Thu Aug 2 12:28:36 2012 : Debug: mrt = 16 Thu Aug 2 12:28:36 2012 : Debug: mrc = 5 Thu Aug 2 12:28:36 2012 : Debug: mrd = 30 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: home_server_pool my_auth_failover { Thu Aug 2 12:28:36 2012 : Debug: type = fail-over Thu Aug 2 12:28:36 2012 : Debug: home_server = localhost Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: realm example.com { Thu Aug 2 12:28:36 2012 : Debug: auth_pool = my_auth_failover Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: realm LOCAL { Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: radiusd: #### Loading Clients #### Thu Aug 2 12:28:36 2012 : Debug: client localhost { Thu Aug 2 12:28:36 2012 : Debug: ipaddr = 127.0.0.1 Thu Aug 2 12:28:36 2012 : Debug: require_message_authenticator = no Thu Aug 2 12:28:36 2012 : Debug: secret = "testing123" Thu Aug 2 12:28:36 2012 : Debug: nastype = "other" Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: client 1.1.1.23 { Thu Aug 2 12:28:36 2012 : Debug: require_message_authenticator = no Thu Aug 2 12:28:36 2012 : Debug: secret = "test" Thu Aug 2 12:28:36 2012 : Debug: shortname = "RadiusServer" Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: radiusd: #### Instantiating modules #### Thu Aug 2 12:28:36 2012 : Debug: instantiate { Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_exec, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_exec Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "exec" from file /usr/local/etc/raddb/modules/exec Thu Aug 2 12:28:36 2012 : Debug: exec { Thu Aug 2 12:28:36 2012 : Debug: wait = no Thu Aug 2 12:28:36 2012 : Debug: input_pairs = "request" Thu Aug 2 12:28:36 2012 : Debug: shell_escape = yes Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_expr, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_expr Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "expr" from file /usr/local/etc/raddb/modules/expr Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_expiration, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_expiration Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "expiration" from file /usr/local/etc/raddb/modules/expiration Thu Aug 2 12:28:36 2012 : Debug: expiration { Thu Aug 2 12:28:36 2012 : Debug: reply-message = "Password Has Expired " Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_logintime, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_logintime Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "logintime" from file /usr/local/etc/raddb/modules/logintime Thu Aug 2 12:28:36 2012 : Debug: logintime { Thu Aug 2 12:28:36 2012 : Debug: reply-message = "You are calling outside your allowed timespan " Thu Aug 2 12:28:36 2012 : Debug: minimum-timeout = 60 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: radiusd: #### Loading Virtual Servers #### Thu Aug 2 12:28:36 2012 : Debug: server { # from file /usr/local/etc/raddb/radiusd.conf Thu Aug 2 12:28:36 2012 : Debug: modules { Thu Aug 2 12:28:36 2012 : Debug: Module: Creating Auth-Type = digest Thu Aug 2 12:28:36 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_eap, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_eap Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "eap" from file /usr/local/etc/raddb/eap.conf Thu Aug 2 12:28:36 2012 : Debug: eap { Thu Aug 2 12:28:36 2012 : Debug: default_eap_type = "ttls" Thu Aug 2 12:28:36 2012 : Debug: timer_expire = 60 Thu Aug 2 12:28:36 2012 : Debug: ignore_unknown_eap_types = no Thu Aug 2 12:28:36 2012 : Debug: cisco_accounting_username_bug = no Thu Aug 2 12:28:36 2012 : Debug: max_sessions = 4096 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to sub-module rlm_eap_tls Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating eap-tls Thu Aug 2 12:28:36 2012 : Debug: tls { Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Info: debug: 'tls' option missing, trying to use legacy configuration Thu Aug 2 12:28:36 2012 : Debug: tls { Thu Aug 2 12:28:36 2012 : Debug: rsa_key_exchange = no Thu Aug 2 12:28:36 2012 : Debug: dh_key_exchange = yes Thu Aug 2 12:28:36 2012 : Debug: rsa_key_length = 512 Thu Aug 2 12:28:36 2012 : Debug: dh_key_length = 512 Thu Aug 2 12:28:36 2012 : Debug: verify_depth = 0 Thu Aug 2 12:28:36 2012 : Debug: CA_path = "/usr/local/etc/raddb/certs" Thu Aug 2 12:28:36 2012 : Debug: pem_file_type = yes Thu Aug 2 12:28:36 2012 : Debug: private_key_file = "/usr/local/etc/raddb/certs/server.pem" Thu Aug 2 12:28:36 2012 : Debug: certificate_file = "/usr/local/etc/raddb/certs/server.pem" Thu Aug 2 12:28:36 2012 : Debug: CA_file = "/usr/local/etc/raddb/certs/ca.pem" Thu Aug 2 12:28:36 2012 : Debug: private_key_password = "whatever" Thu Aug 2 12:28:36 2012 : Debug: dh_file = "/usr/local/etc/raddb/certs/dh" Thu Aug 2 12:28:36 2012 : Debug: random_file = "/usr/local/etc/raddb/certs/random" Thu Aug 2 12:28:36 2012 : Debug: fragment_size = 1024 Thu Aug 2 12:28:36 2012 : Debug: include_length = yes Thu Aug 2 12:28:36 2012 : Debug: check_crl = no Thu Aug 2 12:28:36 2012 : Debug: cipher_list = "DEFAULT" Thu Aug 2 12:28:36 2012 : Debug: make_cert_command = "/usr/local/etc/raddb/certs/bootstrap" Thu Aug 2 12:28:36 2012 : Debug: ecdh_curve = "prime256v1" Thu Aug 2 12:28:36 2012 : Debug: cache { Thu Aug 2 12:28:36 2012 : Debug: enable = no Thu Aug 2 12:28:36 2012 : Debug: lifetime = 24 Thu Aug 2 12:28:36 2012 : Debug: max_entries = 255 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: verify { Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: ocsp { Thu Aug 2 12:28:36 2012 : Debug: enable = no Thu Aug 2 12:28:36 2012 : Debug: override_cert_url = yes Thu Aug 2 12:28:36 2012 : Debug: url = "http://127.0.0.1/ocsp/" Thu Aug 2 12:28:36 2012 : Debug: use_nonce = yes Thu Aug 2 12:28:36 2012 : Debug: timeout = 0 Thu Aug 2 12:28:36 2012 : Debug: softfail = yes Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to sub-module rlm_eap_ttls Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating eap-ttls Thu Aug 2 12:28:36 2012 : Debug: ttls { Thu Aug 2 12:28:36 2012 : Debug: default_eap_type = "md5" Thu Aug 2 12:28:36 2012 : Debug: copy_request_to_tunnel = no Thu Aug 2 12:28:36 2012 : Debug: use_tunneled_reply = yes Thu Aug 2 12:28:36 2012 : Debug: virtual_server = "inner-tunnel" Thu Aug 2 12:28:36 2012 : Debug: include_length = yes Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Info: debug: 'tls' option missing, trying to use legacy configuration Thu Aug 2 12:28:36 2012 : Debug: debug: Using cached TLS configuration from previous invocation Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to sub-module rlm_eap_mschapv2 Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating eap-mschapv2 Thu Aug 2 12:28:36 2012 : Debug: mschapv2 { Thu Aug 2 12:28:36 2012 : Debug: with_ntdomain_hack = no Thu Aug 2 12:28:36 2012 : Debug: send_error = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_pap, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_pap Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "pap" from file /usr/local/etc/raddb/modules/pap Thu Aug 2 12:28:36 2012 : Debug: pap { Thu Aug 2 12:28:36 2012 : Debug: encryption_scheme = "auto" Thu Aug 2 12:28:36 2012 : Debug: auto_header = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_chap, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_chap Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "chap" from file /usr/local/etc/raddb/modules/chap Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_mschap, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_mschap Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "mschap" from file /usr/local/etc/raddb/modules/mschap Thu Aug 2 12:28:36 2012 : Debug: mschap { Thu Aug 2 12:28:36 2012 : Debug: use_mppe = yes Thu Aug 2 12:28:36 2012 : Debug: require_encryption = no Thu Aug 2 12:28:36 2012 : Debug: require_strong = no Thu Aug 2 12:28:36 2012 : Debug: with_ntdomain_hack = no Thu Aug 2 12:28:36 2012 : Debug: allow_retry = yes Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_digest, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_digest Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "digest" from file /usr/local/etc/raddb/modules/digest Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_unix, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_unix Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "unix" from file /usr/local/etc/raddb/modules/unix Thu Aug 2 12:28:36 2012 : Debug: unix { Thu Aug 2 12:28:36 2012 : Debug: radwtmp = "/usr/local/var/log/radius/radwtmp" Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_preprocess, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_preprocess Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "preprocess" from file /usr/local/etc/raddb/modules/preprocess Thu Aug 2 12:28:36 2012 : Debug: preprocess { Thu Aug 2 12:28:36 2012 : Debug: huntgroups = "/usr/local/etc/raddb/huntgroups" Thu Aug 2 12:28:36 2012 : Debug: hints = "/usr/local/etc/raddb/hints" Thu Aug 2 12:28:36 2012 : Debug: with_ascend_hack = no Thu Aug 2 12:28:36 2012 : Debug: ascend_channels_per_line = 23 Thu Aug 2 12:28:36 2012 : Debug: with_ntdomain_hack = no Thu Aug 2 12:28:36 2012 : Debug: with_specialix_jetstream_hack = no Thu Aug 2 12:28:36 2012 : Debug: with_cisco_vsa_hack = no Thu Aug 2 12:28:36 2012 : Debug: with_alvarion_vsa_hack = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_realm, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_realm Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "suffix" from file /usr/local/etc/raddb/modules/realm Thu Aug 2 12:28:36 2012 : Debug: realm suffix { Thu Aug 2 12:28:36 2012 : Debug: format = "suffix" Thu Aug 2 12:28:36 2012 : Debug: delimiter = "@" Thu Aug 2 12:28:36 2012 : Debug: ignore_default = no Thu Aug 2 12:28:36 2012 : Debug: ignore_null = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_files, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_files Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "files" from file /usr/local/etc/raddb/modules/files Thu Aug 2 12:28:36 2012 : Debug: files { Thu Aug 2 12:28:36 2012 : Debug: usersfile = "/usr/local/etc/raddb/users" Thu Aug 2 12:28:36 2012 : Debug: acctusersfile = "/usr/local/etc/raddb/acct_users" Thu Aug 2 12:28:36 2012 : Debug: preproxy_usersfile = "/usr/local/etc/raddb/preproxy_users" Thu Aug 2 12:28:36 2012 : Debug: compat = "no" Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Module: Checking preacct {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_acct_unique Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "acct_unique" from file /usr/local/etc/raddb/modules/acct_unique Thu Aug 2 12:28:36 2012 : Debug: acct_unique { Thu Aug 2 12:28:36 2012 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Module: Checking accounting {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_detail, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_detail Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "detail" from file /usr/local/etc/raddb/modules/detail Thu Aug 2 12:28:36 2012 : Debug: detail { Thu Aug 2 12:28:36 2012 : Debug: detailfile = "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src- IPv6-Address}}/detail-%Y%m%d" Thu Aug 2 12:28:36 2012 : Debug: header = "%t" Thu Aug 2 12:28:36 2012 : Debug: detailperm = 384 Thu Aug 2 12:28:36 2012 : Debug: dirperm = 493 Thu Aug 2 12:28:36 2012 : Debug: locking = no Thu Aug 2 12:28:36 2012 : Debug: log_packet_header = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_radutmp, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_radutmp Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "radutmp" from file /usr/local/etc/raddb/modules/radutmp Thu Aug 2 12:28:36 2012 : Debug: radutmp { Thu Aug 2 12:28:36 2012 : Debug: filename = "/usr/local/var/log/radius/radutmp" Thu Aug 2 12:28:36 2012 : Debug: username = "%{User-Name}" Thu Aug 2 12:28:36 2012 : Debug: case_sensitive = yes Thu Aug 2 12:28:36 2012 : Debug: check_with_nas = yes Thu Aug 2 12:28:36 2012 : Debug: perm = 384 Thu Aug 2 12:28:36 2012 : Debug: callerid = yes Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_attr_filter Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "attr_filter.accounting_response" from file /usr/local/etc/raddb/modules/attr_filter Thu Aug 2 12:28:36 2012 : Debug: attr_filter attr_filter.accounting_response { Thu Aug 2 12:28:36 2012 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.accounting_response" Thu Aug 2 12:28:36 2012 : Debug: key = "%{User-Name}" Thu Aug 2 12:28:36 2012 : Debug: relaxed = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Module: Checking session {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "attr_filter.access_reject" from file /usr/local/etc/raddb/modules/attr_filter Thu Aug 2 12:28:36 2012 : Debug: attr_filter attr_filter.access_reject { Thu Aug 2 12:28:36 2012 : Debug: attrsfile = "/usr/local/etc/raddb/attrs.access_reject" Thu Aug 2 12:28:36 2012 : Debug: key = "%{User-Name}" Thu Aug 2 12:28:36 2012 : Debug: relaxed = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } # modules Thu Aug 2 12:28:36 2012 : Debug: } # server Thu Aug 2 12:28:36 2012 : Debug: server inner-tunnel { # from file /usr/local/etc/raddb/sites-enabled/inner-tunnel Thu Aug 2 12:28:36 2012 : Debug: modules { Thu Aug 2 12:28:36 2012 : Debug: Module: Checking authenticate {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Checking authorize {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Checking session {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Checking post-proxy {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: Module: Checking post-auth {...} for more modules to load Thu Aug 2 12:28:36 2012 : Debug: (Loaded rlm_wimax, checking if it's valid) Thu Aug 2 12:28:36 2012 : Debug: Module: Linked to module rlm_wimax Thu Aug 2 12:28:36 2012 : Debug: Module: Instantiating module "wimax" from file /usr/local/etc/raddb/modules/wimax Thu Aug 2 12:28:36 2012 : Debug: wimax { Thu Aug 2 12:28:36 2012 : Debug: delete_mppe_keys = no Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } # modules Thu Aug 2 12:28:36 2012 : Debug: } # server Thu Aug 2 12:28:36 2012 : Debug: radiusd: #### Opening IP addresses and Ports #### Thu Aug 2 12:28:36 2012 : Debug: listen { Thu Aug 2 12:28:36 2012 : Debug: type = "auth" Thu Aug 2 12:28:36 2012 : Debug: ipaddr = * Thu Aug 2 12:28:36 2012 : Debug: port = 0 Thu Aug 2 12:28:36 2012 : Debug: max_pps = 0 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: listen { Thu Aug 2 12:28:36 2012 : Debug: type = "acct" Thu Aug 2 12:28:36 2012 : Debug: ipaddr = * Thu Aug 2 12:28:36 2012 : Debug: port = 0 Thu Aug 2 12:28:36 2012 : Debug: max_pps = 0 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: listen { Thu Aug 2 12:28:36 2012 : Debug: type = "control" Thu Aug 2 12:28:36 2012 : Debug: listen { Thu Aug 2 12:28:36 2012 : Debug: socket = "/usr/local/var/run/radiusd/radiusd.sock" Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: listen { Thu Aug 2 12:28:36 2012 : Debug: type = "auth" Thu Aug 2 12:28:36 2012 : Debug: ipaddr = 127.0.0.1 Thu Aug 2 12:28:36 2012 : Debug: port = 18120 Thu Aug 2 12:28:36 2012 : Debug: max_pps = 0 Thu Aug 2 12:28:36 2012 : Debug: } Thu Aug 2 12:28:36 2012 : Debug: Listening on authentication address * port 1812 Thu Aug 2 12:28:36 2012 : Debug: Listening on accounting address * port 1813 Thu Aug 2 12:28:36 2012 : Debug: Listening on command file /usr/local/var/run/radiusd/radiusd.sock Thu Aug 2 12:28:36 2012 : Debug: Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Thu Aug 2 12:28:36 2012 : Debug: Opening new proxy address * port 1814 Thu Aug 2 12:28:36 2012 : Debug: Listening on proxy address * port 1814 Thu Aug 2 12:28:36 2012 : Debug: No trigger subsection: ignoring trigger server.start Thu Aug 2 12:28:36 2012 : Info: Ready to process requests. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=171, length=181 Code: 1 Id: 171 Length: 181 Vector: 5a2da5bf874c5a6058e5d3712a536f1a Data: 01 1e 4b 65 65 70 41 6c 69 76 65 55 73 65 72 4e 61 6d 65 41 6e 64 50 61 73 73 77 6f 72 64 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 00 1f 08 00 00 00 00 00 00 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 50 12 0c 76 2e 2d d3 c7 1e c5 c4 01 6e af ac bd 4f d0 2c 14 4b 65 65 70 41 6c 69 76 65 53 65 73 73 69 6f 6e 49 64 02 22 f0 77 59 ff 2e 5c 61 15 8b 95 24 ec b5 51 60 75 3f 60 bd 90 60 01 80 e0 3d 82 d7 3d c2 b8 64 3f User-Name = "KeepAliveUserNameAndPassword" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 0 Calling-Station-Id = "\000\000\000\000\000" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Message-Authenticator = 0x0c762e2dd3c71ec5c4016eafacbd4fd0 Acct-Session-Id = "KeepAliveSessionId" User-Password = "KeepAliveUserNameAndPassword" Thu Aug 2 12:28:59 2012 : Info: (0) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:28:59 2012 : Info: (0) group authorize { Thu Aug 2 12:28:59 2012 : Info: (0) - entering group authorize {...} Thu Aug 2 12:28:59 2012 : Info: (0) [preprocess] = ok Thu Aug 2 12:28:59 2012 : Info: (0) eap : No EAP-Message, not doing EAP Thu Aug 2 12:28:59 2012 : Info: (0) [eap] = noop Thu Aug 2 12:28:59 2012 : Info: (0) [chap] = noop Thu Aug 2 12:28:59 2012 : Info: (0) [mschap] = noop Thu Aug 2 12:28:59 2012 : Info: (0) [digest] = noop Thu Aug 2 12:28:59 2012 : Info: (0) suffix : No '@' in User-Name = "KeepAliveUserNameAndPassword", looking up realm NULL Thu Aug 2 12:28:59 2012 : Info: (0) suffix : No such realm "NULL" Thu Aug 2 12:28:59 2012 : Info: (0) [suffix] = noop Thu Aug 2 12:28:59 2012 : Info: (0) eap : No EAP-Message, not doing EAP Thu Aug 2 12:28:59 2012 : Info: (0) [eap] = noop Thu Aug 2 12:28:59 2012 : Info: (0) [files] = noop Thu Aug 2 12:28:59 2012 : Info: (0) [expiration] = noop Thu Aug 2 12:28:59 2012 : Info: (0) [logintime] = noop Thu Aug 2 12:28:59 2012 : Info: (0) pap : WARNING! No "known good" password found for the user. Authentication may fail because of this. Thu Aug 2 12:28:59 2012 : Info: (0) [pap] = noop Thu Aug 2 12:28:59 2012 : Info: (0) ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user Thu Aug 2 12:28:59 2012 : Info: (0) Failed to authenticate the user. Thu Aug 2 12:28:59 2012 : Info: (0) Using Post-Auth-Type Reject Thu Aug 2 12:28:59 2012 : Info: (0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:28:59 2012 : Info: (0) group REJECT { Thu Aug 2 12:28:59 2012 : Info: (0) - entering group REJECT {...} Thu Aug 2 12:28:59 2012 : Info: (0) attr_filter.access_reject : expand: %{User-Name} -> KeepAliveUserNameAndPassword Thu Aug 2 12:28:59 2012 : Info: (0) attr_filter.access_reject : Matched entry DEFAULT at line 11 Thu Aug 2 12:28:59 2012 : Info: (0) [attr_filter.access_reject] = updated Thu Aug 2 12:28:59 2012 : Info: (0) Finished request 0. Thu Aug 2 12:28:59 2012 : Debug: Waking up in 0.3 seconds. Thu Aug 2 12:28:59 2012 : Debug: Waking up in 0.6 seconds. Thu Aug 2 12:29:00 2012 : Info: (0) Sending delayed reject Sending Access-Reject of id 171 to 1.1.1.23 port 49154 Code: 3 Id: 171 Length: 20 Vector: 4e76ef4ee3b98653d02ba15da31dc6d1 Thu Aug 2 12:29:00 2012 : Debug: Waking up in 4.9 seconds. Thu Aug 2 12:29:05 2012 : Info: (0) Cleaning up request packet ID 171 with timestamp +23 Thu Aug 2 12:29:05 2012 : Info: Ready to process requests. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=172, length=258 Code: 1 Id: 172 Length: 258 Vector: 494b492dae5e07a5dd0cfd3d4e94ae7f Data: 01 32 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 01 1f 08 00 10 e7 61 0e 46 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 0c 06 00 00 05 d2 06 06 00 00 00 02 1a 11 000060b5 (24757) 01 0b 00 01 05 31 2e 30 02 03 01 1a 1b 000060b5 (24757) 2e 15 00 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 4f 37 02 01 00 35 01 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 50 12 e4 94 d6 6b 0e 8e 9b 7f 5a 24 50 b6 12 b5 31 5b User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\000\020\347a\016F" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303031303031303031303030303332303030 EAP-Message = 0x02010035017b616d3d317d3732653939323933343363666665613933663338623363303238 3062346138314057694d61782e636f6d Message-Authenticator = 0xe494d66b0e8e9b7f5a2450b612b5315b Thu Aug 2 12:29:16 2012 : Info: (1) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:16 2012 : Info: (1) group authorize { Thu Aug 2 12:29:16 2012 : Info: (1) - entering group authorize {...} Thu Aug 2 12:29:16 2012 : Info: (1) [preprocess] = ok Thu Aug 2 12:29:16 2012 : Info: (1) eap : EAP packet type response id 1 length 53 Thu Aug 2 12:29:16 2012 : Info: (1) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Thu Aug 2 12:29:16 2012 : Info: (1) [eap] = ok Thu Aug 2 12:29:16 2012 : Info: (1) [chap] = noop Thu Aug 2 12:29:16 2012 : Info: (1) [mschap] = noop Thu Aug 2 12:29:16 2012 : Info: (1) [digest] = noop Thu Aug 2 12:29:16 2012 : Info: (1) suffix : Looking up realm "WiMax.com" for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" Thu Aug 2 12:29:16 2012 : Info: (1) suffix : No such realm "WiMax.com" Thu Aug 2 12:29:16 2012 : Info: (1) [suffix] = noop Thu Aug 2 12:29:16 2012 : Info: (1) eap : EAP packet type response id 1 length 53 Thu Aug 2 12:29:16 2012 : Info: (1) eap : EAP-Identity reply, returning 'ok' so we can short-circuit the rest of authorize Thu Aug 2 12:29:16 2012 : Info: (1) [eap] = ok Thu Aug 2 12:29:16 2012 : Info: (1) Found Auth-Type = EAP Thu Aug 2 12:29:16 2012 : Info: (1) Found Auth-Type = EAP Thu Aug 2 12:29:16 2012 : Error: (1) Warning: Found 2 auth-types on request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com' Thu Aug 2 12:29:16 2012 : Info: (1) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:16 2012 : Info: (1) group authenticate { Thu Aug 2 12:29:16 2012 : Info: (1) - entering group authenticate {...} Thu Aug 2 12:29:16 2012 : Info: (1) eap : EAP Identity Thu Aug 2 12:29:16 2012 : Info: (1) eap : processing type ttls Thu Aug 2 12:29:16 2012 : Info: (1) ttls : Initiate Thu Aug 2 12:29:16 2012 : Info: (1) ttls : Start returned 1 Thu Aug 2 12:29:16 2012 : Info: (1) [eap] = handled Sending Access-Challenge of id 172 to 1.1.1.23 port 49154 EAP-Message = 0x010200061520 4f 08 01 02 00 06 15 20 Message-Authenticator = 0x00000000000000000000000000000000 50 12 ... State = 0x70e4843670e691af7954d6edd228f499 18 12 70 e4 84 36 70 e6 91 af 79 54 d6 ed d2 28 f4 99 Code: 11 Id: 172 Length: 64 Vector: f7c21b63bc52e2d2dc556561df03df96 Data: 4f 08 01 02 00 06 15 20 50 12 17 45 52 de 5d 0e fe d8 51 54 2b 21 80 c6 61 3c 18 12 70 e4 84 36 70 e6 91 af 79 54 d6 ed d2 28 f4 99 Thu Aug 2 12:29:16 2012 : Info: (1) Finished request 1. Thu Aug 2 12:29:16 2012 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=173, length=285 Code: 1 Id: 173 Length: 285 Vector: 6f6f3cf16e46f0891c1ea4402a89a17c Data: 01 32 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 01 1f 08 00 10 e7 61 0e 46 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 0c 06 00 00 05 d2 06 06 00 00 00 02 18 12 70 e4 84 36 70 e6 91 af 79 54 d6 ed d2 28 f4 99 1a 11 000060b5 (24757) 01 0b 00 01 05 31 2e 30 02 03 01 1a 1b 000060b5 (24757) 2e 15 00 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 4f 40 02 02 00 3e 15 00 16 03 01 00 33 01 00 00 2f 03 01 00 00 01 15 6d c0 ed 3c 1f 1a 26 c1 d4 ac f7 d6 49 a5 2c a5 5e 51 36 61 8a 47 71 5a fc 3a 11 b2 00 00 08 00 2f 00 0a 00 05 00 04 01 00 50 12 b9 23 7b 86 d0 bf 80 f4 47 72 7b fd fb bb 09 4a User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\000\020\347a\016F" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x70e4843670e691af7954d6edd228f499 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303031303031303031303030303332303030 EAP-Message = 0x0202003e150016030100330100002f0301000001156dc0ed3c1f1a26c1d4acf7d649a52ca5 5e5136618a47715afc3a11b2000008002f000a000500040100 Message-Authenticator = 0xb9237b86d0bf80f447727bfdfbbb094a Thu Aug 2 12:29:17 2012 : Info: (2) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (2) group authorize { Thu Aug 2 12:29:17 2012 : Info: (2) - entering group authorize {...} Thu Aug 2 12:29:17 2012 : Info: (2) [preprocess] = ok Thu Aug 2 12:29:17 2012 : Info: (2) eap : EAP packet type response id 2 length 62 Thu Aug 2 12:29:17 2012 : Info: (2) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (2) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (2) [chap] = noop Thu Aug 2 12:29:17 2012 : Info: (2) [mschap] = noop Thu Aug 2 12:29:17 2012 : Info: (2) [digest] = noop Thu Aug 2 12:29:17 2012 : Info: (2) suffix : Looking up realm "WiMax.com" for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (2) suffix : No such realm "WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (2) [suffix] = noop Thu Aug 2 12:29:17 2012 : Info: (2) eap : EAP packet type response id 2 length 62 Thu Aug 2 12:29:17 2012 : Info: (2) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (2) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (2) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Info: (2) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Error: (2) Warning: Found 2 auth-types on request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com' Thu Aug 2 12:29:17 2012 : Info: (2) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (2) group authenticate { Thu Aug 2 12:29:17 2012 : Info: (2) - entering group authenticate {...} Thu Aug 2 12:29:17 2012 : Info: (2) eap : Request found, released from the list Thu Aug 2 12:29:17 2012 : Info: (2) eap : EAP/ttls Thu Aug 2 12:29:17 2012 : Info: (2) eap : processing type ttls Thu Aug 2 12:29:17 2012 : Info: (2) ttls : Authenticate Thu Aug 2 12:29:17 2012 : Info: (2) ttls : processing EAP-TLS Thu Aug 2 12:29:17 2012 : Info: (2) ttls : eaptls_verify returned 7 Thu Aug 2 12:29:17 2012 : Info: (2) ttls : Done initial handshake Thu Aug 2 12:29:17 2012 : Info: (2) ttls : (other): before/accept initialization Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: before/accept initialization Thu Aug 2 12:29:17 2012 : Info: (2) ttls : <<< TLS 1.0 Handshake [length 0033], ClientHello Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: SSLv3 read client hello A Thu Aug 2 12:29:17 2012 : Info: (2) ttls : >>> TLS 1.0 Handshake [length 002a], ServerHello Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: SSLv3 write server hello A Thu Aug 2 12:29:17 2012 : Info: (2) ttls : >>> TLS 1.0 Handshake [length 085e], Certificate Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: SSLv3 write certificate A Thu Aug 2 12:29:17 2012 : Info: (2) ttls : >>> TLS 1.0 Handshake [length 0004], ServerHelloDone Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: SSLv3 write server done A Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: SSLv3 flush data Thu Aug 2 12:29:17 2012 : Info: (2) ttls : TLS_accept: Need to read more data: SSLv3 read client certificate A Thu Aug 2 12:29:17 2012 : Debug: In SSL Handshake Phase Thu Aug 2 12:29:17 2012 : Debug: In SSL Accept mode Thu Aug 2 12:29:17 2012 : Info: (2) ttls : eaptls_process returned 13 Thu Aug 2 12:29:17 2012 : Info: (2) [eap] = handled Sending Access-Challenge of id 173 to 1.1.1.23 port 49154 EAP-Message = 0x010303f615c00000089b160301002a020000260301501aaaddbe1c6131fd8d227e7b6a571a 9f6033b1ead17f1ec7e5d5bf828a052d00002f00160301085e0b00085a0008570003a6308203 a23082028aa003020102020101300d06092a864886f70d0101040500308193310b3009060355 040613024652310f300d060355040813065261646975733112301006035504071309536f6d65 776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a864886 f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d457861 6d706c6520436572746966696361746520417574686f72697479 4f ff 01 03 03 f6 15 c0 00 00 08 9b 16 03 01 00 2a 02 00 00 26 03 01 50 1a aa dd be 1c 61 31 fd 8d 22 7e 7b 6a 57 1a 9f 60 33 b1 ea d1 7f 1e c7 e5 d5 bf 82 8a 05 2d 00 00 2f 00 16 03 01 08 5e 0b 00 08 5a 00 08 57 00 03 a6 30 82 03 a2 30 82 02 8a a0 03 02 01 02 02 01 01 30 0d 06 09 2a 86 48 86 f7 0d 01 01 04 05 00 30 81 93 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 EAP-Message = 0x301e170d3132303830313230323230385a170d3133303830313230323230385a307c310b30 09060355040613024652310f300d0603550408130652616469757331153013060355040a130c 4578616d706c6520496e632e312330210603550403131a4578616d706c652053657276657220 43657274696669636174653120301e06092a864886f70d010901161161646d696e406578616d 706c652e636f6d30820122300d06092a864886f70d01010105000382010f003082010a028201 0100de0bf920a502100daec1e015143e02a445842403aa8e7cdcf1a4a80687f770e9ddc5e424 2d0bf7e59c85bfa3b6ae9c0c0ec038a8db5f990352281e855f16 4f ff 30 1e 17 0d 31 32 30 38 30 31 32 30 32 32 30 38 5a 17 0d 31 33 30 38 30 31 32 30 32 32 30 38 5a 30 7c 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 23 30 21 06 03 55 04 03 13 1a 45 78 61 6d 70 6c 65 20 53 65 72 76 65 72 20 43 65 72 74 69 66 69 63 61 74 65 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 30 82 01 22 30 0d 06 09 2a 86 48 86 f7 0d 01 01 01 05 00 03 82 01 0f 00 30 82 01 0a 02 82 01 01 00 de 0b f9 20 a5 02 10 0d ae c1 e0 15 14 3e 02 a4 45 84 24 03 aa 8e 7c dc f1 a4 a8 06 87 f7 70 e9 dd c5 e4 24 2d 0b f7 e5 9c 85 bf a3 b6 ae 9c 0c 0e c0 38 a8 db 5f 99 03 52 28 1e 85 5f 16 EAP-Message = 0x01589cdf68659ee0166aa92a64f5a8779e3f301007668b0d1e0490054b7979dc6ccef24e11 4fa9554e2908d7919d3f92d41dda67fe63fc1a789349b6ef7b0012939e6f36815750dcb6668d 9e4f3eca7fdc978517c0fd5edba70aab9564e4705d8cf28594b62c7e6809b8e88f39781c0348 8d08c536c7b6ddb538cc62920c9b5d975a79dfd361efc550161719d97ed3c4daf98fb67eed7e 914e956d125a6ec7bf02dfd112863d026c3b74ec84ff506e57586e8a4f821616514f6aec29c9 62593ab9510203010001a317301530130603551d25040c300a06082b06010505070301300d06 092a864886f70d0101040500038201010007b6a418336f5c5482 4f ff 01 58 9c df 68 65 9e e0 16 6a a9 2a 64 f5 a8 77 9e 3f 30 10 07 66 8b 0d 1e 04 90 05 4b 79 79 dc 6c ce f2 4e 11 4f a9 55 4e 29 08 d7 91 9d 3f 92 d4 1d da 67 fe 63 fc 1a 78 93 49 b6 ef 7b 00 12 93 9e 6f 36 81 57 50 dc b6 66 8d 9e 4f 3e ca 7f dc 97 85 17 c0 fd 5e db a7 0a ab 95 64 e4 70 5d 8c f2 85 94 b6 2c 7e 68 09 b8 e8 8f 39 78 1c 03 48 8d 08 c5 36 c7 b6 dd b5 38 cc 62 92 0c 9b 5d 97 5a 79 df d3 61 ef c5 50 16 17 19 d9 7e d3 c4 da f9 8f b6 7e ed 7e 91 4e 95 6d 12 5a 6e c7 bf 02 df d1 12 86 3d 02 6c 3b 74 ec 84 ff 50 6e 57 58 6e 8a 4f 82 16 16 51 4f 6a ec 29 c9 62 59 3a b9 51 02 03 01 00 01 a3 17 30 15 30 13 06 03 55 1d 25 04 0c 30 0a 06 08 2b 06 01 05 05 07 03 01 30 0d 06 09 2a 86 48 86 f7 0d 01 01 04 05 00 03 82 01 01 00 07 b6 a4 18 33 6f 5c 54 82 EAP-Message = 0xf6266fe22bca35d6b7564ab695480fa8b837c81ada436935ac4ba28fb57fcc2cb007aeb8ec 14ab7373fa4a37b3c2c5f1dafc2b76332935d35af145caf72d952dd9d37e41377d467a376cb3 c8763cff128f98b0fbfc51f6ee919371bdcd4b4d3629d59e4ae6755ca9c63e6d15b480cbb58a b15ef3666572ab45b926cee83d3db9a5cbfdd2c5bfcbeb5227fcff493b324c83da3288df7705 ded4e9fe144fcab708fa3852071320c803323585fb7a86c2062f7ad64bc23bc692c6a4197058 1833a0f342dcd91c97ce878610ea59ab34863f55f8d835dea77c3b2d5962a1672fc233c2eac7 7a58fa624dcc12ec38fc8f343233fbfdf24789750004ab308204 4f ff f6 26 6f e2 2b ca 35 d6 b7 56 4a b6 95 48 0f a8 b8 37 c8 1a da 43 69 35 ac 4b a2 8f b5 7f cc 2c b0 07 ae b8 ec 14 ab 73 73 fa 4a 37 b3 c2 c5 f1 da fc 2b 76 33 29 35 d3 5a f1 45 ca f7 2d 95 2d d9 d3 7e 41 37 7d 46 7a 37 6c b3 c8 76 3c ff 12 8f 98 b0 fb fc 51 f6 ee 91 93 71 bd cd 4b 4d 36 29 d5 9e 4a e6 75 5c a9 c6 3e 6d 15 b4 80 cb b5 8a b1 5e f3 66 65 72 ab 45 b9 26 ce e8 3d 3d b9 a5 cb fd d2 c5 bf cb eb 52 27 fc ff 49 3b 32 4c 83 da 32 88 df 77 05 de d4 e9 fe 14 4f ca b7 08 fa 38 52 07 13 20 c8 03 32 35 85 fb 7a 86 c2 06 2f 7a d6 4b c2 3b c6 92 c6 a4 19 70 58 18 33 a0 f3 42 dc d9 1c 97 ce 87 86 10 ea 59 ab 34 86 3f 55 f8 d8 35 de a7 7c 3b 2d 59 62 a1 67 2f c2 33 c2 ea c7 7a 58 fa 62 4d cc 12 ec 38 fc 8f 34 32 33 fb fd f2 47 89 75 00 04 ab 30 82 04 EAP-Message = 0xa730 4f 04 a7 30 Message-Authenticator = 0x00000000000000000000000000000000 50 12 ... State = 0x70e4843671e791af7954d6edd228f499 18 12 70 e4 84 36 71 e7 91 af 79 54 d6 ed d2 28 f4 99 Code: 11 Id: 173 Length: 1080 Vector: faccd8f2a1be3142843b1f6d47a36e2d Data: 4f ff 01 03 03 f6 15 c0 00 00 08 9b 16 03 01 00 2a 02 00 00 26 03 01 50 1a aa dd be 1c 61 31 fd 8d 22 7e 7b 6a 57 1a 9f 60 33 b1 ea d1 7f 1e c7 e5 d5 bf 82 8a 05 2d 00 00 2f 00 16 03 01 08 5e 0b 00 08 5a 00 08 57 00 03 a6 30 82 03 a2 30 82 02 8a a0 03 02 01 02 02 01 01 30 0d 06 09 2a 86 48 86 f7 0d 01 01 04 05 00 30 81 93 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 4f ff 30 1e 17 0d 31 32 30 38 30 31 32 30 32 32 30 38 5a 17 0d 31 33 30 38 30 31 32 30 32 32 30 38 5a 30 7c 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 23 30 21 06 03 55 04 03 13 1a 45 78 61 6d 70 6c 65 20 53 65 72 76 65 72 20 43 65 72 74 69 66 69 63 61 74 65 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 30 82 01 22 30 0d 06 09 2a 86 48 86 f7 0d 01 01 01 05 00 03 82 01 0f 00 30 82 01 0a 02 82 01 01 00 de 0b f9 20 a5 02 10 0d ae c1 e0 15 14 3e 02 a4 45 84 24 03 aa 8e 7c dc f1 a4 a8 06 87 f7 70 e9 dd c5 e4 24 2d 0b f7 e5 9c 85 bf a3 b6 ae 9c 0c 0e c0 38 a8 db 5f 99 03 52 28 1e 85 5f 16 4f ff 01 58 9c df 68 65 9e e0 16 6a a9 2a 64 f5 a8 77 9e 3f 30 10 07 66 8b 0d 1e 04 90 05 4b 79 79 dc 6c ce f2 4e 11 4f a9 55 4e 29 08 d7 91 9d 3f 92 d4 1d da 67 fe 63 fc 1a 78 93 49 b6 ef 7b 00 12 93 9e 6f 36 81 57 50 dc b6 66 8d 9e 4f 3e ca 7f dc 97 85 17 c0 fd 5e db a7 0a ab 95 64 e4 70 5d 8c f2 85 94 b6 2c 7e 68 09 b8 e8 8f 39 78 1c 03 48 8d 08 c5 36 c7 b6 dd b5 38 cc 62 92 0c 9b 5d 97 5a 79 df d3 61 ef c5 50 16 17 19 d9 7e d3 c4 da f9 8f b6 7e ed 7e 91 4e 95 6d 12 5a 6e c7 bf 02 df d1 12 86 3d 02 6c 3b 74 ec 84 ff 50 6e 57 58 6e 8a 4f 82 16 16 51 4f 6a ec 29 c9 62 59 3a b9 51 02 03 01 00 01 a3 17 30 15 30 13 06 03 55 1d 25 04 0c 30 0a 06 08 2b 06 01 05 05 07 03 01 30 0d 06 09 2a 86 48 86 f7 0d 01 01 04 05 00 03 82 01 01 00 07 b6 a4 18 33 6f 5c 54 82 4f ff f6 26 6f e2 2b ca 35 d6 b7 56 4a b6 95 48 0f a8 b8 37 c8 1a da 43 69 35 ac 4b a2 8f b5 7f cc 2c b0 07 ae b8 ec 14 ab 73 73 fa 4a 37 b3 c2 c5 f1 da fc 2b 76 33 29 35 d3 5a f1 45 ca f7 2d 95 2d d9 d3 7e 41 37 7d 46 7a 37 6c b3 c8 76 3c ff 12 8f 98 b0 fb fc 51 f6 ee 91 93 71 bd cd 4b 4d 36 29 d5 9e 4a e6 75 5c a9 c6 3e 6d 15 b4 80 cb b5 8a b1 5e f3 66 65 72 ab 45 b9 26 ce e8 3d 3d b9 a5 cb fd d2 c5 bf cb eb 52 27 fc ff 49 3b 32 4c 83 da 32 88 df 77 05 de d4 e9 fe 14 4f ca b7 08 fa 38 52 07 13 20 c8 03 32 35 85 fb 7a 86 c2 06 2f 7a d6 4b c2 3b c6 92 c6 a4 19 70 58 18 33 a0 f3 42 dc d9 1c 97 ce 87 86 10 ea 59 ab 34 86 3f 55 f8 d8 35 de a7 7c 3b 2d 59 62 a1 67 2f c2 33 c2 ea c7 7a 58 fa 62 4d cc 12 ec 38 fc 8f 34 32 33 fb fd f2 47 89 75 00 04 ab 30 82 04 4f 04 a7 30 50 12 ce b9 f2 7b 61 8f 83 ce 3f 78 31 0a 03 02 23 e9 18 12 70 e4 84 36 71 e7 91 af 79 54 d6 ed d2 28 f4 99 Thu Aug 2 12:29:17 2012 : Info: (2) Finished request 2. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=174, length=229 Code: 1 Id: 174 Length: 229 Vector: 596f86dcff924f82458193daf60083c2 Data: 01 32 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 01 1f 08 00 10 e7 61 0e 46 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 0c 06 00 00 05 d2 06 06 00 00 00 02 18 12 70 e4 84 36 71 e7 91 af 79 54 d6 ed d2 28 f4 99 1a 11 000060b5 (24757) 01 0b 00 01 05 31 2e 30 02 03 01 1a 1b 000060b5 (24757) 2e 15 00 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 4f 08 02 03 00 06 15 00 50 12 ff 32 50 8e 14 a8 86 1f 81 62 12 8c c8 95 8a 51 User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\000\020\347a\016F" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x70e4843671e791af7954d6edd228f499 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303031303031303031303030303332303030 EAP-Message = 0x020300061500 Message-Authenticator = 0xff32508e14a8861f8162128cc8958a51 Thu Aug 2 12:29:17 2012 : Info: (3) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (3) group authorize { Thu Aug 2 12:29:17 2012 : Info: (3) - entering group authorize {...} Thu Aug 2 12:29:17 2012 : Info: (3) [preprocess] = ok Thu Aug 2 12:29:17 2012 : Info: (3) eap : EAP packet type response id 3 length 6 Thu Aug 2 12:29:17 2012 : Info: (3) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (3) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (3) [chap] = noop Thu Aug 2 12:29:17 2012 : Info: (3) [mschap] = noop Thu Aug 2 12:29:17 2012 : Info: (3) [digest] = noop Thu Aug 2 12:29:17 2012 : Info: (3) suffix : Looking up realm "WiMax.com" for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (3) suffix : No such realm "WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (3) [suffix] = noop Thu Aug 2 12:29:17 2012 : Info: (3) eap : EAP packet type response id 3 length 6 Thu Aug 2 12:29:17 2012 : Info: (3) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (3) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (3) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Info: (3) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Error: (3) Warning: Found 2 auth-types on request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com' Thu Aug 2 12:29:17 2012 : Info: (3) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (3) group authenticate { Thu Aug 2 12:29:17 2012 : Info: (3) - entering group authenticate {...} Thu Aug 2 12:29:17 2012 : Info: (3) eap : Request found, released from the list Thu Aug 2 12:29:17 2012 : Info: (3) eap : EAP/ttls Thu Aug 2 12:29:17 2012 : Info: (3) eap : processing type ttls Thu Aug 2 12:29:17 2012 : Info: (3) ttls : Authenticate Thu Aug 2 12:29:17 2012 : Info: (3) ttls : processing EAP-TLS Thu Aug 2 12:29:17 2012 : Info: (3) ttls : Received TLS ACK Thu Aug 2 12:29:17 2012 : Info: (3) ttls : Received TLS ACK Thu Aug 2 12:29:17 2012 : Info: (3) ttls : ACK handshake fragment handler Thu Aug 2 12:29:17 2012 : Info: (3) ttls : eaptls_verify returned 1 Thu Aug 2 12:29:17 2012 : Info: (3) ttls : eaptls_process returned 13 Thu Aug 2 12:29:17 2012 : Info: (3) [eap] = handled Sending Access-Challenge of id 174 to 1.1.1.23 port 49154 EAP-Message = 0x010403f615c00000089b82038fa0030201020209008b3ae4d24b0d8074300d06092a864886 f70d0101050500308193310b3009060355040613024652310f300d0603550408130652616469 75733112301006035504071309536f6d65776865726531153013060355040a130c4578616d70 6c6520496e632e3120301e06092a864886f70d010901161161646d696e406578616d706c652e 636f6d312630240603550403131d4578616d706c652043657274696669636174652041757468 6f72697479301e170d3132303830313230323230385a170d3133303830313230323230385a30 8193310b3009060355040613024652310f300d06035504081306 4f ff 01 04 03 f6 15 c0 00 00 08 9b 82 03 8f a0 03 02 01 02 02 09 00 8b 3a e4 d2 4b 0d 80 74 30 0d 06 09 2a 86 48 86 f7 0d 01 01 05 05 00 30 81 93 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 30 1e 17 0d 31 32 30 38 30 31 32 30 32 32 30 38 5a 17 0d 31 33 30 38 30 31 32 30 32 32 30 38 5a 30 81 93 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 EAP-Message = 0x5261646975733112301006035504071309536f6d65776865726531153013060355040a130c 4578616d706c6520496e632e3120301e06092a864886f70d010901161161646d696e40657861 6d706c652e636f6d312630240603550403131d4578616d706c65204365727469666963617465 20417574686f7269747930820122300d06092a864886f70d01010105000382010f003082010a 0282010100c36abc7f1f7fab4f42bccc205eda320e1aac97851162a59ff4a233bd684d6c898a 8de8b1977a54cebd25142c5231b85b9abf4dda8802f68e9ca90578ded2717a7119f5c380e09c eff603a2c3aaa7defdc7a2a81f1de5d542377274df33c057e680 4f ff 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 30 82 01 22 30 0d 06 09 2a 86 48 86 f7 0d 01 01 01 05 00 03 82 01 0f 00 30 82 01 0a 02 82 01 01 00 c3 6a bc 7f 1f 7f ab 4f 42 bc cc 20 5e da 32 0e 1a ac 97 85 11 62 a5 9f f4 a2 33 bd 68 4d 6c 89 8a 8d e8 b1 97 7a 54 ce bd 25 14 2c 52 31 b8 5b 9a bf 4d da 88 02 f6 8e 9c a9 05 78 de d2 71 7a 71 19 f5 c3 80 e0 9c ef f6 03 a2 c3 aa a7 de fd c7 a2 a8 1f 1d e5 d5 42 37 72 74 df 33 c0 57 e6 80 EAP-Message = 0x5c8c7753a3df62de87c009399a7751c1ffae25ae1bf357835db0ceeae188a093ea0249293d dc62a620666e64cf3d6f53fc51bba0f73bea03496cd0113555b1d87f05837f8ce1067e4f936e 6e4b025fb4ab50e23462b003e94984d2910781fd566c77348e4f48fa15a4ca7c8e24f2228e56 d6a55d64c94d9181d30a823e5aa88b26d29b4f6500aacdba4791c98f34a968275d8dcaaeaf87 bd0f14f7411774350203010001a381fb3081f8301d0603551d0e0416041435b8ba9717c526ff 332deed9f3736708c70d27d43081c80603551d230481c03081bd801435b8ba9717c526ff332d eed9f3736708c70d27d4a18199a48196308193310b3009060355 4f ff 5c 8c 77 53 a3 df 62 de 87 c0 09 39 9a 77 51 c1 ff ae 25 ae 1b f3 57 83 5d b0 ce ea e1 88 a0 93 ea 02 49 29 3d dc 62 a6 20 66 6e 64 cf 3d 6f 53 fc 51 bb a0 f7 3b ea 03 49 6c d0 11 35 55 b1 d8 7f 05 83 7f 8c e1 06 7e 4f 93 6e 6e 4b 02 5f b4 ab 50 e2 34 62 b0 03 e9 49 84 d2 91 07 81 fd 56 6c 77 34 8e 4f 48 fa 15 a4 ca 7c 8e 24 f2 22 8e 56 d6 a5 5d 64 c9 4d 91 81 d3 0a 82 3e 5a a8 8b 26 d2 9b 4f 65 00 aa cd ba 47 91 c9 8f 34 a9 68 27 5d 8d ca ae af 87 bd 0f 14 f7 41 17 74 35 02 03 01 00 01 a3 81 fb 30 81 f8 30 1d 06 03 55 1d 0e 04 16 04 14 35 b8 ba 97 17 c5 26 ff 33 2d ee d9 f3 73 67 08 c7 0d 27 d4 30 81 c8 06 03 55 1d 23 04 81 c0 30 81 bd 80 14 35 b8 ba 97 17 c5 26 ff 33 2d ee d9 f3 73 67 08 c7 0d 27 d4 a1 81 99 a4 81 96 30 81 93 31 0b 30 09 06 03 55 EAP-Message = 0x040613024652310f300d060355040813065261646975733112301006035504071309536f6d 65776865726531153013060355040a130c4578616d706c6520496e632e3120301e06092a8648 86f70d010901161161646d696e406578616d706c652e636f6d312630240603550403131d4578 616d706c6520436572746966696361746520417574686f726974798209008b3ae4d24b0d8074 300c0603551d13040530030101ff300d06092a864886f70d010105050003820101006d4d67c0 893fe75e0ebd115e29d05dc12ffc3999cbb4ffaf025190077c68cfc7a7ec9cca671cf4534106 6957c347aa5cb3943fc2c46439989b290a76ff2559ba5e0a7b1c 4f ff 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 82 09 00 8b 3a e4 d2 4b 0d 80 74 30 0c 06 03 55 1d 13 04 05 30 03 01 01 ff 30 0d 06 09 2a 86 48 86 f7 0d 01 01 05 05 00 03 82 01 01 00 6d 4d 67 c0 89 3f e7 5e 0e bd 11 5e 29 d0 5d c1 2f fc 39 99 cb b4 ff af 02 51 90 07 7c 68 cf c7 a7 ec 9c ca 67 1c f4 53 41 06 69 57 c3 47 aa 5c b3 94 3f c2 c4 64 39 98 9b 29 0a 76 ff 25 59 ba 5e 0a 7b 1c EAP-Message = 0xe142 4f 04 e1 42 Message-Authenticator = 0x00000000000000000000000000000000 50 12 ... State = 0x70e4843672e091af7954d6edd228f499 18 12 70 e4 84 36 72 e0 91 af 79 54 d6 ed d2 28 f4 99 Code: 11 Id: 174 Length: 1080 Vector: 2d1d93905ba1e947b6eb8e1e53da285a Data: 4f ff 01 04 03 f6 15 c0 00 00 08 9b 82 03 8f a0 03 02 01 02 02 09 00 8b 3a e4 d2 4b 0d 80 74 30 0d 06 09 2a 86 48 86 f7 0d 01 01 05 05 00 30 81 93 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 30 1e 17 0d 31 32 30 38 30 31 32 30 32 32 30 38 5a 17 0d 31 33 30 38 30 31 32 30 32 32 30 38 5a 30 81 93 31 0b 30 09 06 03 55 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 4f ff 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 30 82 01 22 30 0d 06 09 2a 86 48 86 f7 0d 01 01 01 05 00 03 82 01 0f 00 30 82 01 0a 02 82 01 01 00 c3 6a bc 7f 1f 7f ab 4f 42 bc cc 20 5e da 32 0e 1a ac 97 85 11 62 a5 9f f4 a2 33 bd 68 4d 6c 89 8a 8d e8 b1 97 7a 54 ce bd 25 14 2c 52 31 b8 5b 9a bf 4d da 88 02 f6 8e 9c a9 05 78 de d2 71 7a 71 19 f5 c3 80 e0 9c ef f6 03 a2 c3 aa a7 de fd c7 a2 a8 1f 1d e5 d5 42 37 72 74 df 33 c0 57 e6 80 4f ff 5c 8c 77 53 a3 df 62 de 87 c0 09 39 9a 77 51 c1 ff ae 25 ae 1b f3 57 83 5d b0 ce ea e1 88 a0 93 ea 02 49 29 3d dc 62 a6 20 66 6e 64 cf 3d 6f 53 fc 51 bb a0 f7 3b ea 03 49 6c d0 11 35 55 b1 d8 7f 05 83 7f 8c e1 06 7e 4f 93 6e 6e 4b 02 5f b4 ab 50 e2 34 62 b0 03 e9 49 84 d2 91 07 81 fd 56 6c 77 34 8e 4f 48 fa 15 a4 ca 7c 8e 24 f2 22 8e 56 d6 a5 5d 64 c9 4d 91 81 d3 0a 82 3e 5a a8 8b 26 d2 9b 4f 65 00 aa cd ba 47 91 c9 8f 34 a9 68 27 5d 8d ca ae af 87 bd 0f 14 f7 41 17 74 35 02 03 01 00 01 a3 81 fb 30 81 f8 30 1d 06 03 55 1d 0e 04 16 04 14 35 b8 ba 97 17 c5 26 ff 33 2d ee d9 f3 73 67 08 c7 0d 27 d4 30 81 c8 06 03 55 1d 23 04 81 c0 30 81 bd 80 14 35 b8 ba 97 17 c5 26 ff 33 2d ee d9 f3 73 67 08 c7 0d 27 d4 a1 81 99 a4 81 96 30 81 93 31 0b 30 09 06 03 55 4f ff 04 06 13 02 46 52 31 0f 30 0d 06 03 55 04 08 13 06 52 61 64 69 75 73 31 12 30 10 06 03 55 04 07 13 09 53 6f 6d 65 77 68 65 72 65 31 15 30 13 06 03 55 04 0a 13 0c 45 78 61 6d 70 6c 65 20 49 6e 63 2e 31 20 30 1e 06 09 2a 86 48 86 f7 0d 01 09 01 16 11 61 64 6d 69 6e 40 65 78 61 6d 70 6c 65 2e 63 6f 6d 31 26 30 24 06 03 55 04 03 13 1d 45 78 61 6d 70 6c 65 20 43 65 72 74 69 66 69 63 61 74 65 20 41 75 74 68 6f 72 69 74 79 82 09 00 8b 3a e4 d2 4b 0d 80 74 30 0c 06 03 55 1d 13 04 05 30 03 01 01 ff 30 0d 06 09 2a 86 48 86 f7 0d 01 01 05 05 00 03 82 01 01 00 6d 4d 67 c0 89 3f e7 5e 0e bd 11 5e 29 d0 5d c1 2f fc 39 99 cb b4 ff af 02 51 90 07 7c 68 cf c7 a7 ec 9c ca 67 1c f4 53 41 06 69 57 c3 47 aa 5c b3 94 3f c2 c4 64 39 98 9b 29 0a 76 ff 25 59 ba 5e 0a 7b 1c 4f 04 e1 42 50 12 df b5 f1 bd 7a 51 d4 a5 d3 58 be 77 ac 02 b0 17 18 12 70 e4 84 36 72 e0 91 af 79 54 d6 ed d2 28 f4 99 Thu Aug 2 12:29:17 2012 : Info: (3) Finished request 3. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=175, length=229 Code: 1 Id: 175 Length: 229 Vector: f0f4171ca8b272d64760ccee915518e7 Data: 01 32 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 01 1f 08 00 10 e7 61 0e 46 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 0c 06 00 00 05 d2 06 06 00 00 00 02 18 12 70 e4 84 36 72 e0 91 af 79 54 d6 ed d2 28 f4 99 1a 11 000060b5 (24757) 01 0b 00 01 05 31 2e 30 02 03 01 1a 1b 000060b5 (24757) 2e 15 00 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 4f 08 02 04 00 06 15 00 50 12 b1 c1 2f 42 50 e8 69 88 bf 90 f7 39 75 d6 ec 16 User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\000\020\347a\016F" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x70e4843672e091af7954d6edd228f499 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303031303031303031303030303332303030 EAP-Message = 0x020400061500 Message-Authenticator = 0xb1c12f4250e86988bf90f73975d6ec16 Thu Aug 2 12:29:17 2012 : Info: (4) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (4) group authorize { Thu Aug 2 12:29:17 2012 : Info: (4) - entering group authorize {...} Thu Aug 2 12:29:17 2012 : Info: (4) [preprocess] = ok Thu Aug 2 12:29:17 2012 : Info: (4) eap : EAP packet type response id 4 length 6 Thu Aug 2 12:29:17 2012 : Info: (4) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (4) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (4) [chap] = noop Thu Aug 2 12:29:17 2012 : Info: (4) [mschap] = noop Thu Aug 2 12:29:17 2012 : Info: (4) [digest] = noop Thu Aug 2 12:29:17 2012 : Info: (4) suffix : Looking up realm "WiMax.com" for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (4) suffix : No such realm "WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (4) [suffix] = noop Thu Aug 2 12:29:17 2012 : Info: (4) eap : EAP packet type response id 4 length 6 Thu Aug 2 12:29:17 2012 : Info: (4) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (4) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (4) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Info: (4) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Error: (4) Warning: Found 2 auth-types on request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com' Thu Aug 2 12:29:17 2012 : Info: (4) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (4) group authenticate { Thu Aug 2 12:29:17 2012 : Info: (4) - entering group authenticate {...} Thu Aug 2 12:29:17 2012 : Info: (4) eap : Request found, released from the list Thu Aug 2 12:29:17 2012 : Info: (4) eap : EAP/ttls Thu Aug 2 12:29:17 2012 : Info: (4) eap : processing type ttls Thu Aug 2 12:29:17 2012 : Info: (4) ttls : Authenticate Thu Aug 2 12:29:17 2012 : Info: (4) ttls : processing EAP-TLS Thu Aug 2 12:29:17 2012 : Info: (4) ttls : Received TLS ACK Thu Aug 2 12:29:17 2012 : Info: (4) ttls : Received TLS ACK Thu Aug 2 12:29:17 2012 : Info: (4) ttls : ACK handshake fragment handler Thu Aug 2 12:29:17 2012 : Info: (4) ttls : eaptls_verify returned 1 Thu Aug 2 12:29:17 2012 : Info: (4) ttls : eaptls_process returned 13 Thu Aug 2 12:29:17 2012 : Info: (4) [eap] = handled Sending Access-Challenge of id 175 to 1.1.1.23 port 49154 EAP-Message = 0x010500cd15800000089b8e2c29c529afee1893f22707e590467c7f212dc4857e1d83de9431 23f37fb0bcbde5cbc2724a695917e090cbce71bba8bba9c3d0559cfc0d5c8c94c00d9ab8389a 1885a38e4bb9f8763f86919c4ec24822384416b628838022578c034341be186092afabaaf40e fb44d8f6f3b07e7b1a8743c5535d4b0e3b35d32d32d0caaae6d978ed996884fb92a0c84f0960 f32e79d8fc531918e8fe7988e3064cdafb741d03a2e2aecd10bc62552d6f1a0b1871567a1101 99f574aa4ebfe316030100040e000000 4f cf 01 05 00 cd 15 80 00 00 08 9b 8e 2c 29 c5 29 af ee 18 93 f2 27 07 e5 90 46 7c 7f 21 2d c4 85 7e 1d 83 de 94 31 23 f3 7f b0 bc bd e5 cb c2 72 4a 69 59 17 e0 90 cb ce 71 bb a8 bb a9 c3 d0 55 9c fc 0d 5c 8c 94 c0 0d 9a b8 38 9a 18 85 a3 8e 4b b9 f8 76 3f 86 91 9c 4e c2 48 22 38 44 16 b6 28 83 80 22 57 8c 03 43 41 be 18 60 92 af ab aa f4 0e fb 44 d8 f6 f3 b0 7e 7b 1a 87 43 c5 53 5d 4b 0e 3b 35 d3 2d 32 d0 ca aa e6 d9 78 ed 99 68 84 fb 92 a0 c8 4f 09 60 f3 2e 79 d8 fc 53 19 18 e8 fe 79 88 e3 06 4c da fb 74 1d 03 a2 e2 ae cd 10 bc 62 55 2d 6f 1a 0b 18 71 56 7a 11 01 99 f5 74 aa 4e bf e3 16 03 01 00 04 0e 00 00 00 Message-Authenticator = 0x00000000000000000000000000000000 50 12 ... State = 0x70e4843673e191af7954d6edd228f499 18 12 70 e4 84 36 73 e1 91 af 79 54 d6 ed d2 28 f4 99 Code: 11 Id: 175 Length: 263 Vector: 4ea588aa6bfd47fea96d500d07bc45e5 Data: 4f cf 01 05 00 cd 15 80 00 00 08 9b 8e 2c 29 c5 29 af ee 18 93 f2 27 07 e5 90 46 7c 7f 21 2d c4 85 7e 1d 83 de 94 31 23 f3 7f b0 bc bd e5 cb c2 72 4a 69 59 17 e0 90 cb ce 71 bb a8 bb a9 c3 d0 55 9c fc 0d 5c 8c 94 c0 0d 9a b8 38 9a 18 85 a3 8e 4b b9 f8 76 3f 86 91 9c 4e c2 48 22 38 44 16 b6 28 83 80 22 57 8c 03 43 41 be 18 60 92 af ab aa f4 0e fb 44 d8 f6 f3 b0 7e 7b 1a 87 43 c5 53 5d 4b 0e 3b 35 d3 2d 32 d0 ca aa e6 d9 78 ed 99 68 84 fb 92 a0 c8 4f 09 60 f3 2e 79 d8 fc 53 19 18 e8 fe 79 88 e3 06 4c da fb 74 1d 03 a2 e2 ae cd 10 bc 62 55 2d 6f 1a 0b 18 71 56 7a 11 01 99 f5 74 aa 4e bf e3 16 03 01 00 04 0e 00 00 00 50 12 95 ea dc 03 4c 6e 80 7e 67 6f 10 83 9f f1 dc 51 18 12 70 e4 84 36 73 e1 91 af 79 54 d6 ed d2 28 f4 99 Thu Aug 2 12:29:17 2012 : Info: (4) Finished request 4. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 4.1 seconds. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=176, length=557 Code: 1 Id: 176 Length: 557 Vector: 1a6cad37bcb8f543399498dab26ed07b Data: 01 32 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 01 1f 08 00 10 e7 61 0e 46 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 0c 06 00 00 05 d2 06 06 00 00 00 02 18 12 70 e4 84 36 73 e1 91 af 79 54 d6 ed d2 28 f4 99 1a 11 000060b5 (24757) 01 0b 00 01 05 31 2e 30 02 03 01 1a 1b 000060b5 (24757) 2e 15 00 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 4f ff 02 05 01 4c 15 00 16 03 01 01 06 10 00 01 02 01 00 1d 15 6d 23 92 5e 99 3d d6 c9 09 f5 d0 c0 13 12 0a 4e 3a e4 1a 0b fc ac be 55 e2 66 ea f0 22 9e 5d 80 d1 21 c0 aa a9 89 c0 5a b9 f0 a3 51 53 71 32 4b 71 54 9e da 9f 28 e5 75 f4 10 76 71 63 d7 36 1b 91 f4 f4 07 b0 8d 28 68 3e 73 1b c4 c4 ca ad 00 06 0a e9 f2 5f e3 f6 b1 8c 09 7b 08 f4 f3 fd 9f 12 a1 cd 3a 00 f3 dc f4 69 55 57 98 4d 34 1d 2c dd 54 bc 4f 57 fd 99 59 42 f5 59 b7 08 a1 5e ed d4 66 85 a9 8f 24 94 84 ec 5c 03 62 1f 58 c4 f4 6a a3 25 db 2c 71 ce 5c a6 a3 de 75 f7 a7 56 0e 23 8f 21 8d af 2a 99 25 04 e8 0b a5 f6 e0 15 56 28 21 41 1b 7d ae 52 71 d5 ef f2 6e d8 c0 b9 09 42 dd 3d 2a 78 2a bc 20 5a 92 5b 82 0f da 14 16 9c ad c9 75 18 c8 c6 37 c5 3d ca 29 63 aa 38 83 07 d5 3e c2 8d ae 9a 6c 85 d1 4f 51 77 59 d9 4a d8 9f d9 7a af 68 f7 1f b9 66 6b fd 9e 66 28 f6 14 03 01 00 01 01 16 03 01 00 30 fc 64 74 e6 a0 ec 55 29 14 e2 cb ad eb 93 18 00 2a f5 8d 46 9a 27 43 f8 6e 65 90 8d ec b9 51 0f 10 16 37 e9 ae dd d0 e6 b4 0a 65 78 c3 c8 3c 5b 50 12 cd 68 25 7e 3d 6b 57 b8 6b 87 dd e4 8b f1 27 bc User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\000\020\347a\016F" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x70e4843673e191af7954d6edd228f499 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303031303031303031303030303332303030 EAP-Message = 0x0205014c150016030101061000010201001d156d23925e993dd6c909f5d0c013120a4e3ae4 1a0bfcacbe55e266eaf0229e5d80d121c0aaa989c05ab9f0a3515371324b71549eda9f28e575 f410767163d7361b91f4f407b08d28683e731bc4c4caad00060ae9f25fe3f6b18c097b08f4f3 fd9f12a1cd3a00f3dcf4695557984d341d2cdd54bc4f57fd995942f559b708a15eedd46685a9 8f249484ec5c03621f58c4f46aa325db2c71ce5ca6a3de75f7a7560e238f218daf2a992504e8 0ba5f6e015562821411b7dae5271d5eff26ed8c0b90942dd3d2a782abc205a925b820fda1416 9cadc97518c8c637c53dca2963aa388307d53ec28dae9a6c85d1 EAP-Message = 0x7759d94ad89fd97aaf68f71fb9666bfd9e6628f61403010001011603010030fc6474e6a0ec 552914e2cbadeb9318002af58d469a2743f86e65908decb9510f101637e9aeddd0e6b40a6578 c3c83c5b Message-Authenticator = 0xcd68257e3d6b57b86b87dde48bf127bc Thu Aug 2 12:29:17 2012 : Info: (5) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (5) group authorize { Thu Aug 2 12:29:17 2012 : Info: (5) - entering group authorize {...} Thu Aug 2 12:29:17 2012 : Info: (5) [preprocess] = ok Thu Aug 2 12:29:17 2012 : Info: (5) eap : EAP packet type response id 5 length 253 Thu Aug 2 12:29:17 2012 : Info: (5) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (5) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (5) [chap] = noop Thu Aug 2 12:29:17 2012 : Info: (5) [mschap] = noop Thu Aug 2 12:29:17 2012 : Info: (5) [digest] = noop Thu Aug 2 12:29:17 2012 : Info: (5) suffix : Looking up realm "WiMax.com" for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (5) suffix : No such realm "WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (5) [suffix] = noop Thu Aug 2 12:29:17 2012 : Info: (5) eap : EAP packet type response id 5 length 253 Thu Aug 2 12:29:17 2012 : Info: (5) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (5) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (5) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Info: (5) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Error: (5) Warning: Found 2 auth-types on request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com' Thu Aug 2 12:29:17 2012 : Info: (5) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (5) group authenticate { Thu Aug 2 12:29:17 2012 : Info: (5) - entering group authenticate {...} Thu Aug 2 12:29:17 2012 : Info: (5) eap : Request found, released from the list Thu Aug 2 12:29:17 2012 : Info: (5) eap : EAP/ttls Thu Aug 2 12:29:17 2012 : Info: (5) eap : processing type ttls Thu Aug 2 12:29:17 2012 : Info: (5) ttls : Authenticate Thu Aug 2 12:29:17 2012 : Info: (5) ttls : processing EAP-TLS Thu Aug 2 12:29:17 2012 : Info: (5) ttls : eaptls_verify returned 7 Thu Aug 2 12:29:17 2012 : Info: (5) ttls : Done initial handshake Thu Aug 2 12:29:17 2012 : Info: (5) ttls : <<< TLS 1.0 Handshake [length 0106], ClientKeyExchange Thu Aug 2 12:29:17 2012 : Info: (5) ttls : TLS_accept: SSLv3 read client key exchange A Thu Aug 2 12:29:17 2012 : Info: (5) ttls : <<< TLS 1.0 ChangeCipherSpec [length 0001] Thu Aug 2 12:29:17 2012 : Info: (5) ttls : <<< TLS 1.0 Handshake [length 0010], Finished Thu Aug 2 12:29:17 2012 : Info: (5) ttls : TLS_accept: SSLv3 read finished A Thu Aug 2 12:29:17 2012 : Info: (5) ttls : >>> TLS 1.0 ChangeCipherSpec [length 0001] Thu Aug 2 12:29:17 2012 : Info: (5) ttls : TLS_accept: SSLv3 write change cipher spec A Thu Aug 2 12:29:17 2012 : Info: (5) ttls : >>> TLS 1.0 Handshake [length 0010], Finished Thu Aug 2 12:29:17 2012 : Info: (5) ttls : TLS_accept: SSLv3 write finished A Thu Aug 2 12:29:17 2012 : Info: (5) ttls : TLS_accept: SSLv3 flush data Thu Aug 2 12:29:17 2012 : Info: (5) ttls : (other): SSL negotiation finished successfully Thu Aug 2 12:29:17 2012 : Debug: SSL Connection Established Thu Aug 2 12:29:17 2012 : Info: (5) ttls : eaptls_process returned 13 Thu Aug 2 12:29:17 2012 : Info: (5) [eap] = handled Sending Access-Challenge of id 176 to 1.1.1.23 port 49154 EAP-Message = 0x0106004515800000003b140301000101160301003078867353a3e23b0d6503baf380805acb af23c2e5571baaf434c40742575994f889a63d740f43bd60b0df81bda4452aa7 4f 47 01 06 00 45 15 80 00 00 00 3b 14 03 01 00 01 01 16 03 01 00 30 78 86 73 53 a3 e2 3b 0d 65 03 ba f3 80 80 5a cb af 23 c2 e5 57 1b aa f4 34 c4 07 42 57 59 94 f8 89 a6 3d 74 0f 43 bd 60 b0 df 81 bd a4 45 2a a7 Message-Authenticator = 0x00000000000000000000000000000000 50 12 ... State = 0x70e4843674e291af7954d6edd228f499 18 12 70 e4 84 36 74 e2 91 af 79 54 d6 ed d2 28 f4 99 Code: 11 Id: 176 Length: 127 Vector: 632aea85d7e8bc609e929d9df6432b88 Data: 4f 47 01 06 00 45 15 80 00 00 00 3b 14 03 01 00 01 01 16 03 01 00 30 78 86 73 53 a3 e2 3b 0d 65 03 ba f3 80 80 5a cb af 23 c2 e5 57 1b aa f4 34 c4 07 42 57 59 94 f8 89 a6 3d 74 0f 43 bd 60 b0 df 81 bd a4 45 2a a7 50 12 59 56 90 75 a5 4d b0 10 66 a5 a5 9b f8 5b b9 e7 18 12 70 e4 84 36 74 e2 91 af 79 54 d6 ed d2 28 f4 99 Thu Aug 2 12:29:17 2012 : Info: (5) Finished request 5. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.3 seconds. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=177, length=394 Code: 1 Id: 177 Length: 394 Vector: 174e53706e00aeb0a3518f99dd483600 Data: 01 32 7b 61 6d 3d 31 7d 37 32 65 39 39 32 39 33 34 33 63 66 66 65 61 39 33 66 33 38 62 33 63 30 32 38 30 62 34 61 38 31 40 57 69 4d 61 78 2e 63 6f 6d 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 01 1f 08 00 10 e7 61 0e 46 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 0c 06 00 00 05 d2 06 06 00 00 00 02 18 12 70 e4 84 36 74 e2 91 af 79 54 d6 ed d2 28 f4 99 1a 11 000060b5 (24757) 01 0b 00 01 05 31 2e 30 02 03 01 1a 1b 000060b5 (24757) 2e 15 00 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 4f ad 02 06 00 ab 15 00 17 03 01 00 a0 8e bd 16 77 8e 63 28 f0 2f f0 94 8d d1 d4 37 0e f0 2c 0b 83 35 10 f0 4a 04 8a 09 5b 03 7c fd bb b7 48 24 a2 ec 3b 44 d8 fd a1 41 26 37 a0 a2 2b 77 05 71 fe e2 e4 b0 d1 5b 67 86 dd 0a 48 6a 06 96 4a 71 58 75 61 e9 fe 64 d2 a7 9a 24 a6 61 fe 74 97 3d b1 06 da 80 2f fd 3b eb 5f 44 16 ab ea 6e 17 a0 9b 8f 8d 72 84 8e ee b6 76 eb b4 86 1b 0a 4b b0 0b 2e 5f 18 2a f3 49 ba 0d 7e 7f 7a 74 01 82 b4 c0 d5 74 2d bf 84 b0 77 5a 58 4f ad 34 4e f4 f7 86 76 47 85 81 7a 1c bf 4f 3b 57 ef 5b 50 12 80 61 e0 ea 35 44 c5 6d 74 28 8f 86 e0 36 30 ae User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 1 Calling-Station-Id = "\000\020\347a\016F" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Framed-MTU = 1490 Service-Type = Framed-User State = 0x70e4843674e291af7954d6edd228f499 WiMAX-Release = "1.0" WiMAX-Accounting-Capabilities = IP-Session-Based WiMAX-BS-Id = 0x303031303031303031303030303332303030 EAP-Message = 0x020600ab150017030100a08ebd16778e6328f02ff0948dd1d4370ef02c0b833510f04a048a 095b037cfdbbb74824a2ec3b44d8fda1412637a0a22b770571fee2e4b0d15b6786dd0a486a06 964a71587561e9fe64d2a79a24a661fe74973db106da802ffd3beb5f4416abea6e17a09b8f8d 72848eeeb676ebb4861b0a4bb00b2e5f182af349ba0d7e7f7a740182b4c0d5742dbf84b0775a 584fad344ef4f786764785817a1cbf4f3b57ef5b Message-Authenticator = 0x8061e0ea3544c56d74288f86e03630ae Thu Aug 2 12:29:17 2012 : Info: (6) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (6) group authorize { Thu Aug 2 12:29:17 2012 : Info: (6) - entering group authorize {...} Thu Aug 2 12:29:17 2012 : Info: (6) [preprocess] = ok Thu Aug 2 12:29:17 2012 : Info: (6) eap : EAP packet type response id 6 length 171 Thu Aug 2 12:29:17 2012 : Info: (6) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (6) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (6) [chap] = noop Thu Aug 2 12:29:17 2012 : Info: (6) [mschap] = noop Thu Aug 2 12:29:17 2012 : Info: (6) [digest] = noop Thu Aug 2 12:29:17 2012 : Info: (6) suffix : Looking up realm "WiMax.com" for User-Name = "{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (6) suffix : No such realm "WiMax.com" Thu Aug 2 12:29:17 2012 : Info: (6) [suffix] = noop Thu Aug 2 12:29:17 2012 : Info: (6) eap : EAP packet type response id 6 length 171 Thu Aug 2 12:29:17 2012 : Info: (6) eap : Continuing tunnel setup. Thu Aug 2 12:29:17 2012 : Info: (6) [eap] = ok Thu Aug 2 12:29:17 2012 : Info: (6) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Info: (6) Found Auth-Type = EAP Thu Aug 2 12:29:17 2012 : Error: (6) Warning: Found 2 auth-types on request for user '{am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com' Thu Aug 2 12:29:17 2012 : Info: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (6) group authenticate { Thu Aug 2 12:29:17 2012 : Info: (6) - entering group authenticate {...} Thu Aug 2 12:29:17 2012 : Info: (6) eap : Request found, released from the list Thu Aug 2 12:29:17 2012 : Info: (6) eap : EAP/ttls Thu Aug 2 12:29:17 2012 : Info: (6) eap : processing type ttls Thu Aug 2 12:29:17 2012 : Info: (6) ttls : Authenticate Thu Aug 2 12:29:17 2012 : Info: (6) ttls : processing EAP-TLS Thu Aug 2 12:29:17 2012 : Info: (6) ttls : eaptls_verify returned 7 Thu Aug 2 12:29:17 2012 : Info: (6) ttls : Done initial handshake Thu Aug 2 12:29:17 2012 : Info: (6) ttls : eaptls_process returned 7 Thu Aug 2 12:29:17 2012 : Info: (6) ttls : Session established. Proceeding to decode tunneled attributes. TTLS tunnel data in 0000: 00 00 00 01 40 00 00 1e 30 30 31 30 45 37 36 31 TTLS tunnel data in 0010: 30 45 34 35 40 57 69 4d 61 78 2e 63 6f 6d 00 00 TTLS tunnel data in 0020: 00 00 00 0b c0 00 00 1c 00 00 01 37 e2 6f cf da TTLS tunnel data in 0030: c9 64 3f 44 48 52 2f ac 31 79 98 a1 00 00 00 19 TTLS tunnel data in 0040: c0 00 00 3e 00 00 01 37 0e 00 75 79 89 be 55 26 TTLS tunnel data in 0050: f3 c1 06 49 c8 94 ef ca 5e 5e 00 00 00 00 00 00 TTLS tunnel data in 0060: 00 00 f3 1c d9 98 b7 cd e6 df 22 9b b5 08 9d b8 TTLS tunnel data in 0070: ff 67 15 31 3c 62 68 c7 e8 9c 00 00 Thu Aug 2 12:29:17 2012 : Info: (6) ttls : Tunneled attribute 1 is too short (1 < 12) to contain anything useful. Thu Aug 2 12:29:17 2012 : Info: (6) eap : Handler failed in EAP/ttls Thu Aug 2 12:29:17 2012 : Info: (6) eap : Failed in EAP select Thu Aug 2 12:29:17 2012 : Info: (6) [eap] = invalid Thu Aug 2 12:29:17 2012 : Info: (6) Failed to authenticate the user. Thu Aug 2 12:29:17 2012 : Info: (6) Using Post-Auth-Type Reject Thu Aug 2 12:29:17 2012 : Info: (6) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:29:17 2012 : Info: (6) group REJECT { Thu Aug 2 12:29:17 2012 : Info: (6) - entering group REJECT {...} Thu Aug 2 12:29:17 2012 : Info: (6) attr_filter.access_reject : expand: %{User-Name} -> {am=1}72e9929343cffea93f38b3c0280b4a81@WiMax.com Thu Aug 2 12:29:17 2012 : Info: (6) attr_filter.access_reject : Matched entry DEFAULT at line 11 Thu Aug 2 12:29:17 2012 : Info: (6) [attr_filter.access_reject] = updated Thu Aug 2 12:29:17 2012 : Info: (6) Finished request 6. Thu Aug 2 12:29:17 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:18 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:18 2012 : Debug: Waking up in 0.6 seconds. Thu Aug 2 12:29:18 2012 : Info: (6) Sending delayed reject Sending Access-Reject of id 177 to 1.1.1.23 port 49154 EAP-Message = 0x04060004 4f 06 04 06 00 04 Message-Authenticator = 0x00000000000000000000000000000000 50 12 ... Code: 3 Id: 177 Length: 44 Vector: 2acbbf58b3f1495a359f3feaaab30f99 Data: 4f 06 04 06 00 04 50 12 f7 d3 49 74 25 76 14 38 35 de 60 31 c0 8a c7 8e Thu Aug 2 12:29:18 2012 : Debug: Waking up in 2.9 seconds. Thu Aug 2 12:29:21 2012 : Info: (1) Cleaning up request packet ID 172 with timestamp +40 Thu Aug 2 12:29:21 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:22 2012 : Info: (2) Cleaning up request packet ID 173 with timestamp +41 Thu Aug 2 12:29:22 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:22 2012 : Info: (3) Cleaning up request packet ID 174 with timestamp +41 Thu Aug 2 12:29:22 2012 : Debug: Waking up in 0.1 seconds. Thu Aug 2 12:29:22 2012 : Info: (4) Cleaning up request packet ID 175 with timestamp +41 Thu Aug 2 12:29:22 2012 : Debug: Waking up in 0.3 seconds. Thu Aug 2 12:29:22 2012 : Info: (5) Cleaning up request packet ID 176 with timestamp +41 Thu Aug 2 12:29:22 2012 : Debug: Waking up in 1.1 seconds. Thu Aug 2 12:29:23 2012 : Info: (6) Cleaning up request packet ID 177 with timestamp +41 Thu Aug 2 12:29:23 2012 : Info: Ready to process requests. rad_recv: Access-Request packet from host 1.1.1.23 port 49154, id=178, length=181 Code: 1 Id: 178 Length: 181 Vector: 610a3a428887dc445ff90c63281da6a0 Data: 01 1e 4b 65 65 70 41 6c 69 76 65 55 73 65 72 4e 61 6d 65 41 6e 64 50 61 73 73 77 6f 72 64 04 06 01 01 01 17 3d 06 00 00 00 1b 05 06 00 00 00 00 1f 08 00 00 00 00 00 00 20 14 30 30 31 30 30 31 30 30 31 30 30 30 30 33 32 30 30 30 1a 0d 000060b5 (24757) 03 07 00 00 00 00 00 50 12 a0 3a 1d 62 f0 42 df 89 67 b9 a8 d3 2c 66 fc ad 2c 14 4b 65 65 70 41 6c 69 76 65 53 65 73 73 69 6f 6e 49 64 02 22 9f 61 f5 36 12 e1 5d 38 cf 6b 68 14 d6 69 2a 91 ce a6 8e 76 02 58 56 9a 0c 47 35 39 6c bb 5f 19 User-Name = "KeepAliveUserNameAndPassword" NAS-IP-Address = 1.1.1.23 NAS-Port-Type = Wireless-802.16 NAS-Port = 0 Calling-Station-Id = "\000\000\000\000\000" NAS-Identifier = "001001001000032000" WiMAX-GMT-Timezone-offset = 0 Message-Authenticator = 0xa03a1d62f042df8967b9a8d32c66fcad Acct-Session-Id = "KeepAliveSessionId" User-Password = "KeepAliveUserNameAndPassword" Thu Aug 2 12:30:00 2012 : Info: (7) # Executing section authorize from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:30:00 2012 : Info: (7) group authorize { Thu Aug 2 12:30:00 2012 : Info: (7) - entering group authorize {...} Thu Aug 2 12:30:00 2012 : Info: (7) [preprocess] = ok Thu Aug 2 12:30:00 2012 : Info: (7) eap : No EAP-Message, not doing EAP Thu Aug 2 12:30:00 2012 : Info: (7) [eap] = noop Thu Aug 2 12:30:00 2012 : Info: (7) [chap] = noop Thu Aug 2 12:30:00 2012 : Info: (7) [mschap] = noop Thu Aug 2 12:30:00 2012 : Info: (7) [digest] = noop Thu Aug 2 12:30:00 2012 : Info: (7) suffix : No '@' in User-Name = "KeepAliveUserNameAndPassword", looking up realm NULL Thu Aug 2 12:30:00 2012 : Info: (7) suffix : No such realm "NULL" Thu Aug 2 12:30:00 2012 : Info: (7) [suffix] = noop Thu Aug 2 12:30:00 2012 : Info: (7) eap : No EAP-Message, not doing EAP Thu Aug 2 12:30:00 2012 : Info: (7) [eap] = noop Thu Aug 2 12:30:00 2012 : Info: (7) [files] = noop Thu Aug 2 12:30:00 2012 : Info: (7) [expiration] = noop Thu Aug 2 12:30:00 2012 : Info: (7) [logintime] = noop Thu Aug 2 12:30:00 2012 : Info: (7) pap : WARNING! No "known good" password found for the user. Authentication may fail because of this. Thu Aug 2 12:30:00 2012 : Info: (7) [pap] = noop Thu Aug 2 12:30:00 2012 : Info: (7) ERROR: No authenticate method (Auth-Type) found for the request: Rejecting the user Thu Aug 2 12:30:00 2012 : Info: (7) Failed to authenticate the user. Thu Aug 2 12:30:00 2012 : Info: (7) Using Post-Auth-Type Reject Thu Aug 2 12:30:00 2012 : Info: (7) # Executing group from file /usr/local/etc/raddb/sites-enabled/default Thu Aug 2 12:30:00 2012 : Info: (7) group REJECT { Thu Aug 2 12:30:00 2012 : Info: (7) - entering group REJECT {...} Thu Aug 2 12:30:00 2012 : Info: (7) attr_filter.access_reject : expand: %{User-Name} -> KeepAliveUserNameAndPassword Thu Aug 2 12:30:00 2012 : Info: (7) attr_filter.access_reject : Matched entry DEFAULT at line 11 Thu Aug 2 12:30:00 2012 : Info: (7) [attr_filter.access_reject] = updated Thu Aug 2 12:30:00 2012 : Info: (7) Finished request 7. Thu Aug 2 12:30:00 2012 : Debug: Waking up in 0.3 seconds. Thu Aug 2 12:30:01 2012 : Debug: Waking up in 0.6 seconds. Thu Aug 2 12:30:01 2012 : Info: (7) Sending delayed reject Sending Access-Reject of id 178 to 1.1.1.23 port 49154 Code: 3 Id: 178 Length: 20 Vector: a15722909dd087c3543477518d0fe639 Thu Aug 2 12:30:01 2012 : Debug: Waking up in 4.9 seconds. Thu Aug 2 12:30:06 2012 : Info: (7) Cleaning up request packet ID 178 with timestamp +84 Thu Aug 2 12:30:06 2012 : Info: Ready to process requests. ^Crad@radserv:~$ -----Original Message----- From: freeradius-users-bounces+david.peterson=acc-corp.net@lists.freeradius.org [mailto:freeradius-users-bounces+david.peterson=acc-corp.net@lists.freeradiu s.org] On Behalf Of Alan DeKok Sent: Wednesday, August 1, 2012 12:00 PM To: FreeRadius users mailing list Subject: Re: EAP problem marco perugini wrote:
hi list! i think we found same issue as david: something fails in eap-ttls. my supplicant is a huawei wimax cpe [that obviously works great on my other radius server but not the new one...]. we noticed some commit about ttls so we built master branch from git in the afternoon but still we have this problem; are we wrong about new eap-ttls configuration section? you can find my "radiusd -Xxx" as attachment.
Could you grab the latest version from "master"? I added a patch to print out the contents of the tunnel. This lets me know *what* is in the tunnel, so I know how to fix it. Thanks. Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
participants (4)
-
Alan DeKok -
Arran Cudbard-Bell -
David Peterson -
marco perugini