Hello, I'll try to make Mac Authentication with MySQL backend. But I always rejected. Mac Authentication only works if I add like the following lines into the /etc/raddb/users.
90:4 C: E5: 6C: 7E: B6 Auth-Type: = Accept I use OpenBSD 4.6, FreeRadius 2.1.3 and MySQL 5.0.83. What should I do, to make it work with MySQL ? mysql> use radius; Database changed mysql> select * from radcheck; +----+-------------------+-----------+----+---------+ | id | username | attribute | op | value | +----+-------------------+-----------+----+---------+ | 2 | 90:4C:E5:6C:7E:B6 | Password | == | testpwd | +----+-------------------+-----------+----+---------+ 1 row in set (0.00 sec) mysql> select * from radusergroup; +-------------------+-----------+----------+ | username | groupname | priority | +-------------------+-----------+----------+ | 90:4C:E5:6C:7E:B6 | xs4all | 1 | +-------------------+-----------+----------+ 1 row in set (0.00 sec) mysql> select * from radgroupreply; +----+-----------+-----------+----+--------+ | id | groupname | attribute | op | value | +----+-----------+-----------+----+--------+ | 3 | xs4all | Auth-Type | := | Accept | +----+-----------+-----------+----+--------+ 1 row in set (0.00 sec) radiusd -X -xx Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_files, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_files Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating files Tue Mar 16 00:38:10 2010 : Debug: files { Tue Mar 16 00:38:10 2010 : Debug: usersfile = "/etc/raddb/users" Tue Mar 16 00:38:10 2010 : Debug: acctusersfile = "/etc/raddb/acct_users" Tue Mar 16 00:38:10 2010 : Debug: preproxy_usersfile = "/etc/raddb/preproxy_users" Tue Mar 16 00:38:10 2010 : Debug: compat = "no" Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_sql, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_sql Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating sql Tue Mar 16 00:38:10 2010 : Debug: sql { Tue Mar 16 00:38:10 2010 : Debug: driver = "rlm_sql_mysql" Tue Mar 16 00:38:10 2010 : Debug: server = "localhost" Tue Mar 16 00:38:10 2010 : Debug: port = "" Tue Mar 16 00:38:10 2010 : Debug: login = "radius" Tue Mar 16 00:38:10 2010 : Debug: password = "passwordradius" Tue Mar 16 00:38:10 2010 : Debug: radius_db = "radius" Tue Mar 16 00:38:10 2010 : Debug: read_groups = yes Tue Mar 16 00:38:10 2010 : Debug: sqltrace = no Tue Mar 16 00:38:10 2010 : Debug: sqltracefile = "/var/log/radius/sqltrace.sql" Tue Mar 16 00:38:10 2010 : Debug: readclients = yes Tue Mar 16 00:38:10 2010 : Debug: deletestalesessions = yes Tue Mar 16 00:38:10 2010 : Debug: num_sql_socks = 5 Tue Mar 16 00:38:10 2010 : Debug: sql_user_name = "%{User-Name}" Tue Mar 16 00:38:10 2010 : Debug: default_user_profile = "" Tue Mar 16 00:38:10 2010 : Debug: nas_query = "SELECT id, nasname, shortname, type, secret FROM nas" Tue Mar 16 00:38:10 2010 : Debug: authorize_check_query = "SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id" Tue Mar 16 00:38:10 2010 : Debug: authorize_reply_query = "SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id" Tue Mar 16 00:38:10 2010 : Debug: authorize_group_check_query = "SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Mar 16 00:38:10 2010 : Debug: authorize_group_reply_query = "SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id" Tue Mar 16 00:38:10 2010 : Debug: 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'" Tue Mar 16 00:38:10 2010 : Debug: 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}'" Tue Mar 16 00:38:10 2010 : Debug: 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}')" Tue Mar 16 00:38:10 2010 : Debug: 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}')" Tue Mar 16 00:38:10 2010 : Debug: 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}'" Tue Mar 16 00:38:10 2010 : Debug: 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}'" Tue Mar 16 00:38:10 2010 : Debug: 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}')" Tue Mar 16 00:38:10 2010 : Debug: group_membership_query = "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" Tue Mar 16 00:38:10 2010 : Debug: connect_failure_retry_delay = 60 Tue Mar 16 00:38:10 2010 : Debug: simul_count_query = "" Tue Mar 16 00:38:10 2010 : Debug: simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" Tue Mar 16 00:38:10 2010 : Debug: postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" Tue Mar 16 00:38:10 2010 : Debug: safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Info: rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked Tue Mar 16 00:38:10 2010 : Info: rlm_sql (sql): Attempting to connect to rad...@localhost:/radius Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): starting 0 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 Tue Mar 16 00:38:10 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #0 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Connected new DB handle, #0 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): starting 1 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 Tue Mar 16 00:38:10 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #1 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Connected new DB handle, #1 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): starting 2 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 Tue Mar 16 00:38:10 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #2 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Connected new DB handle, #2 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): starting 3 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 Tue Mar 16 00:38:10 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #3 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Connected new DB handle, #3 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): starting 4 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 Tue Mar 16 00:38:10 2010 : Info: rlm_sql_mysql: Starting connect to MySQL server for #4 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Connected new DB handle, #4 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Processing generate_sql_clients Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql) in generate_sql_clients: query is SELECT id, nasname, shortname, type, secret FROM nas Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Reserving sql socket id: 4 Tue Mar 16 00:38:10 2010 : Debug: rlm_sql (sql): Released sql socket id: 4 Tue Mar 16 00:38:10 2010 : Debug: Module: Checking session {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_radutmp, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_radutmp Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating radutmp Tue Mar 16 00:38:10 2010 : Debug: radutmp { Tue Mar 16 00:38:10 2010 : Debug: filename = "/var/log/radius/radutmp" Tue Mar 16 00:38:10 2010 : Debug: username = "%{User-Name}" Tue Mar 16 00:38:10 2010 : Debug: case_sensitive = yes Tue Mar 16 00:38:10 2010 : Debug: check_with_nas = yes Tue Mar 16 00:38:10 2010 : Debug: perm = 384 Tue Mar 16 00:38:10 2010 : Debug: callerid = yes Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Checking post-auth {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_attr_filter, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_attr_filter Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating attr_filter.access_reject Tue Mar 16 00:38:10 2010 : Debug: attr_filter attr_filter.access_reject { Tue Mar 16 00:38:10 2010 : Debug: attrsfile = "/etc/raddb/attrs.access_reject" Tue Mar 16 00:38:10 2010 : Debug: key = "%{User-Name}" Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: modules { Tue Mar 16 00:38:10 2010 : Debug: Module: Checking authenticate {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_always, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_always Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating ok Tue Mar 16 00:38:10 2010 : Debug: always ok { Tue Mar 16 00:38:10 2010 : Debug: rcode = "ok" Tue Mar 16 00:38:10 2010 : Debug: simulcount = 0 Tue Mar 16 00:38:10 2010 : Debug: mpp = no Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Checking authorize {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_preprocess, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_preprocess Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating preprocess Tue Mar 16 00:38:10 2010 : Debug: preprocess { Tue Mar 16 00:38:10 2010 : Debug: huntgroups = "/etc/raddb/huntgroups" Tue Mar 16 00:38:10 2010 : Debug: hints = "/etc/raddb/hints" Tue Mar 16 00:38:10 2010 : Debug: with_ascend_hack = no Tue Mar 16 00:38:10 2010 : Debug: ascend_channels_per_line = 23 Tue Mar 16 00:38:10 2010 : Debug: with_ntdomain_hack = no Tue Mar 16 00:38:10 2010 : Debug: with_specialix_jetstream_hack = no Tue Mar 16 00:38:10 2010 : Debug: with_cisco_vsa_hack = no Tue Mar 16 00:38:10 2010 : Debug: with_alvarion_vsa_hack = no Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Checking preacct {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_acct_unique, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_acct_unique Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating acct_unique Tue Mar 16 00:38:10 2010 : Debug: acct_unique { Tue Mar 16 00:38:10 2010 : Debug: key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Checking accounting {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: (Loaded rlm_detail, checking if it's valid) Tue Mar 16 00:38:10 2010 : Debug: Module: Linked to module rlm_detail Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating detail Tue Mar 16 00:38:10 2010 : Debug: detail { Tue Mar 16 00:38:10 2010 : Debug: detailfile = "/var/log/radius/radacct/%{Client-IP-Address}/detail-%Y%m%d" Tue Mar 16 00:38:10 2010 : Debug: header = "%t" Tue Mar 16 00:38:10 2010 : Debug: detailperm = 384 Tue Mar 16 00:38:10 2010 : Debug: dirperm = 493 Tue Mar 16 00:38:10 2010 : Debug: locking = no Tue Mar 16 00:38:10 2010 : Debug: log_packet_header = no Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating attr_filter.accounting_response Tue Mar 16 00:38:10 2010 : Debug: attr_filter attr_filter.accounting_response { Tue Mar 16 00:38:10 2010 : Debug: attrsfile = "/etc/raddb/attrs.accounting_response" Tue Mar 16 00:38:10 2010 : Debug: key = "%{User-Name}" Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Checking session {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: Module: Checking post-auth {...} for more modules to load Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating authorized_macs Tue Mar 16 00:38:10 2010 : Debug: files authorized_macs { Tue Mar 16 00:38:10 2010 : Debug: usersfile = "/etc/raddb/authorized_macs" Tue Mar 16 00:38:10 2010 : Debug: compat = "no" Tue Mar 16 00:38:10 2010 : Debug: key = "%{Calling-Station-ID}" Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Module: Instantiating reject Tue Mar 16 00:38:10 2010 : Debug: always reject { Tue Mar 16 00:38:10 2010 : Debug: rcode = "reject" Tue Mar 16 00:38:10 2010 : Debug: simulcount = 0 Tue Mar 16 00:38:10 2010 : Debug: mpp = no Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: radiusd: #### Opening IP addresses and Ports #### Tue Mar 16 00:38:10 2010 : Debug: listen { Tue Mar 16 00:38:10 2010 : Debug: type = "auth" Tue Mar 16 00:38:10 2010 : Debug: ipaddr = * Tue Mar 16 00:38:10 2010 : Debug: port = 0 Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: listen { Tue Mar 16 00:38:10 2010 : Debug: type = "acct" Tue Mar 16 00:38:10 2010 : Debug: ipaddr = * Tue Mar 16 00:38:10 2010 : Debug: port = 0 Tue Mar 16 00:38:10 2010 : Debug: } Tue Mar 16 00:38:10 2010 : Debug: Listening on authentication address * port 1812 Tue Mar 16 00:38:10 2010 : Debug: Listening on accounting address * port 1813 Tue Mar 16 00:38:10 2010 : Debug: Ready to process requests. rad_recv: Access-Request packet from host 192.168.0.1 port 47168, id=20, length=136 Service-Type = Framed-User NAS-Port-Id = "wireless" User-Name = "90:4C:E5:6C:7E:B6" Calling-Station-Id = "90-4C-E5-6C-7E-B6" Called-Station-Id = "00-0C-42-61-4A-99:wireless" User-Password = "" NAS-Identifier = "wireless" NAS-IP-Address = 192.168.0.1 Tue Mar 16 00:40:41 2010 : Info: +- entering group authorize {...} Tue Mar 16 00:40:41 2010 : Info: ++[preprocess] returns ok Tue Mar 16 00:40:41 2010 : Info: ++? if ((Service-Type == 'Call-Check') || (User-Name =~ /^%{Calling-Station-ID}$/i)) Tue Mar 16 00:40:41 2010 : Info: ?? Evaluating (Service-Type == 'Call-Check') -> FALSE Tue Mar 16 00:40:41 2010 : Info: expand: ^%{Calling-Station-ID}$ -> ^90-4C-E5-6C-7E-B6$ Tue Mar 16 00:40:41 2010 : Info: ?? Evaluating (User-Name =~ /^%{Calling-Station-ID}$/i) -> FALSE Tue Mar 16 00:40:41 2010 : Info: ++? if ((Service-Type == 'Call-Check') || (User-Name =~ /^%{Calling-Station-ID}$/i)) -> FALSE Tue Mar 16 00:40:41 2010 : Info: ++[chap] returns noop Tue Mar 16 00:40:41 2010 : Info: ++[mschap] returns noop Tue Mar 16 00:40:41 2010 : Info: [suffix] No '@' in User-Name = "90:4C:E5:6C:7E:B6", looking up realm NULL Tue Mar 16 00:40:41 2010 : Info: [suffix] No such realm "NULL" Tue Mar 16 00:40:41 2010 : Info: ++[suffix] returns noop Tue Mar 16 00:40:41 2010 : Info: ++[unix] returns notfound Tue Mar 16 00:40:41 2010 : Info: ++[files] returns noop Tue Mar 16 00:40:41 2010 : Info: [sql] expand: %{User-Name} -> 90:4C:E5:6C:7E:B6 Tue Mar 16 00:40:41 2010 : Info: [sql] sql_set_user escaped user --> '90:4C:E5:6C:7E:B6' Tue Mar 16 00:40:41 2010 : Debug: rlm_sql (sql): Reserving sql socket id: 3 Tue Mar 16 00:40:41 2010 : Info: [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 = '90:4C:E5:6C:7E:B6' ORDER BY id Tue Mar 16 00:40:41 2010 : Debug: WARNING: Found User-Password == "...". Tue Mar 16 00:40:41 2010 : Debug: WARNING: Are you sure you don't mean Cleartext-Password? Tue Mar 16 00:40:41 2010 : Debug: WARNING: See "man rlm_pap" for more information. Tue Mar 16 00:40:41 2010 : Info: [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = '90:4C:E5:6C:7E:B6' ORDER BY priority Tue Mar 16 00:40:41 2010 : Info: [sql] expand: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'xs4all' ORDER BY id Tue Mar 16 00:40:41 2010 : Info: [sql] User found in group xs4all Tue Mar 16 00:40:41 2010 : Info: [sql] expand: SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id -> SELECT id, groupname, attribute, value, op FROM radgroupreply WHERE groupname = 'xs4all' ORDER BY id Tue Mar 16 00:40:41 2010 : Debug: rlm_sql (sql): Released sql socket id: 3 Tue Mar 16 00:40:41 2010 : Info: ++[sql] returns ok Tue Mar 16 00:40:41 2010 : Info: ++[expiration] returns noop Tue Mar 16 00:40:41 2010 : Info: ++[logintime] returns noop Tue Mar 16 00:40:41 2010 : Info: No authenticate method (Auth-Type) configuration found for the request: Rejecting the user Tue Mar 16 00:40:41 2010 : Info: Failed to authenticate the user. Tue Mar 16 00:40:41 2010 : Info: Using Post-Auth-Type Reject Tue Mar 16 00:40:41 2010 : Info: +- entering group REJECT {...} Tue Mar 16 00:40:41 2010 : Info: [attr_filter.access_reject] expand: %{User-Name} -> 90:4C:E5:6C:7E:B6 Tue Mar 16 00:40:41 2010 : Debug: attr_filter: Matched entry DEFAULT at line 11 Tue Mar 16 00:40:41 2010 : Info: ++[attr_filter.access_reject] returns updated Tue Mar 16 00:40:41 2010 : Info: Delaying reject of request 0 for 1 seconds Tue Mar 16 00:40:41 2010 : Debug: Going to the next request Tue Mar 16 00:40:41 2010 : Debug: Waking up in 0.9 seconds. rad_recv: Access-Request packet from host 192.168.0.1 port 47168, id=20, length=136 Tue Mar 16 00:40:42 2010 : Info: Waiting to send Access-Reject to client 0.0.0.0/0 port 47168 - ID: 20 Tue Mar 16 00:40:42 2010 : Debug: Waking up in 0.7 seconds. rad_recv: Access-Request packet from host 192.168.0.1 port 47168, id=20, length=136 Tue Mar 16 00:40:42 2010 : Info: Waiting to send Access-Reject to client 0.0.0.0/0 port 47168 - ID: 20 Tue Mar 16 00:40:42 2010 : Debug: Waking up in 0.3 seconds. Tue Mar 16 00:40:42 2010 : Info: Sending delayed reject for request 0 Sending Access-Reject of id 20 to 192.168.0.1 port 47168 Tue Mar 16 00:40:42 2010 : Debug: Waking up in 4.9 seconds. Tue Mar 16 00:40:47 2010 : Info: Cleaning up request 0 ID 20 with timestamp +151 Tue Mar 16 00:40:47 2010 : Debug: Ready to process requests. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html