This continues questions related to group processing not always working as expected, in particluar why group replies are not sent when the users are members of groups for which there are replies in radgroupreply.
I should mention that Alan's response to my previous post a couple weeks ago was simply to run the server in debug and look at the queries...this is what I've done here (I hope). The queries printed out when starting the server in debug show the correct authorize_group_reply_query, but it never gets run during an auth request. I began with 2.1.8 on CentOS 5.8 - and have now moved to a clean 2.1.12 (stock) on CentOS 6.0. All are using a MySQL backend built from the schema by Mike Machado. The only change to the tables is the addition of two fields to some tables, 'notes' and 'expires'; none of the FreeRADIUS queries have been altered. Any help with how to get this working? Thank you - Andrew Long Here are the queries for the user's auth request: [sql] sql_set_user escaped user --> 'memwg150412' rlm_sql (sql): Reserving sql socket id: 1 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'memwg150412' ORDER BY id rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'memwg150412' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'memwg150412' ORDER BY id rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'memwg150412' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'memwg150412' ORDER BY priority rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'memwg150412' ORDER BY priority [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 = 'wolfchase-guest-group' ORDER BY id rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'wolfchase-guest-group' ORDER BY id rlm_sql (sql): Released sql socket id: 1 and here is the reply sent: Sending Access-Accept of id 215 to 192.168.245.1 port 58639 Nomadix-Bw-Down := 768 Nomadix-Bw-Up := 256 Finished request 0. The problem is that these attributes are from radreply based on the username, and processing is not continuing to radgroupreply. When I manually run: 'SELECT groupname FROM radusergroup WHERE username = 'memwg150412' ORDER BY priority;' MySQL returns: "wolfchase-guest-group" and processing should continue to radgroupreply (where there are reply attributes), but never does. In sql.conf, we have "read_groups = yes" So the question: why are goups not being processed and how can I fix this? ### Below is a complete debug from this session: ### FreeRADIUS Version 2.1.12, for host i686-redhat-linux-gnu, built on Feb 22 2012 at 15:07:38 Copyright (C) 1999-2009 The FreeRADIUS server project and contributors. There is NO warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. You may redistribute copies of FreeRADIUS under the terms of the GNU General Public License v2. Starting - reading configuration files ... including configuration file /etc/raddb/radiusd.conf including configuration file /etc/raddb/clients.conf including files in directory /etc/raddb/modules/ including configuration file /etc/raddb/modules/smbpasswd including configuration file /etc/raddb/modules/smsotp including configuration file /etc/raddb/modules/ntlm_auth including configuration file /etc/raddb/modules/acct_unique including configuration file /etc/raddb/modules/sqlcounter_expire_on_login including configuration file /etc/raddb/modules/cui including configuration file /etc/raddb/modules/soh including configuration file /etc/raddb/modules/exec including configuration file /etc/raddb/modules/sradutmp including configuration file /etc/raddb/modules/attr_filter including configuration file /etc/raddb/modules/pam including configuration file /etc/raddb/modules/preprocess including configuration file /etc/raddb/modules/mschap including configuration file /etc/raddb/modules/mac2ip including configuration file /etc/raddb/modules/realm including configuration file /etc/raddb/modules/logintime including configuration file /etc/raddb/modules/always including configuration file /etc/raddb/modules/rediswho including configuration file /etc/raddb/modules/inner-eap including configuration file /etc/raddb/modules/policy including configuration file /etc/raddb/modules/attr_rewrite including configuration file /etc/raddb/modules/passwd including configuration file /etc/raddb/modules/mac2vlan including configuration file /etc/raddb/modules/detail including configuration file /etc/raddb/modules/dynamic_clients including configuration file /etc/raddb/modules/redis including configuration file /etc/raddb/modules/files including configuration file /etc/raddb/modules/digest including configuration file /etc/raddb/modules/detail.example.com including configuration file /etc/raddb/modules/detail.log including configuration file /etc/raddb/modules/wimax including configuration file /etc/raddb/modules/otp including configuration file /etc/raddb/modules/etc_group including configuration file /etc/raddb/modules/replicate including configuration file /etc/raddb/modules/echo including configuration file /etc/raddb/modules/ippool including configuration file /etc/raddb/modules/perl including configuration file /etc/raddb/modules/radutmp including configuration file /etc/raddb/modules/expr including configuration file /etc/raddb/modules/opendirectory including configuration file /etc/raddb/modules/unix including configuration file /etc/raddb/modules/chap including configuration file /etc/raddb/modules/checkval including configuration file /etc/raddb/modules/expiration including configuration file /etc/raddb/modules/counter including configuration file /etc/raddb/modules/sql_log including configuration file /etc/raddb/modules/linelog including configuration file /etc/raddb/modules/pap including configuration file /etc/raddb/eap.conf including configuration file /etc/raddb/sql.conf including configuration file /etc/raddb/sql/mysql/dialup.conf including configuration file /etc/raddb/sqlcounter.conf including configuration file /etc/raddb/policy.conf including files in directory /etc/raddb/sites-enabled/ including configuration file /etc/raddb/sites-enabled/default including configuration file /etc/raddb/sites-enabled/control-socket including configuration file /etc/raddb/sites-enabled/inner-tunnel main { user = "radiusd" group = "radiusd" allow_core_dumps = no } including dictionary file /etc/raddb/dictionary main { name = "radiusd" prefix = "/usr" localstatedir = "/var" sbindir = "/usr/sbin" logdir = "/var/log/radius" run_dir = "/var/run/radiusd" libdir = "/usr/lib/freeradius" radacctdir = "/var/log/radius/radacct" hostname_lookups = no max_request_time = 30 cleanup_delay = 5 max_requests = 1024 pidfile = "/var/run/radiusd/radiusd.pid" checkrad = "/usr/sbin/checkrad" debug_level = 0 proxy_requests = no log { stripped_names = no auth = yes auth_badpass = yes auth_goodpass = no } security { max_attributes = 200 reject_delay = 1 status_server = yes } } radiusd: #### Loading Realms and Home Servers #### radiusd: #### Loading Clients #### ...snip... client 192.168.245.0/24 { require_message_authenticator = no secret = "xxx" shortname = "vmHost" nastype = "other" } ...snip... radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating module "exec" from file /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 /etc/raddb/modules/expr Module: Linked to module rlm_expiration Module: Instantiating module "expiration" from file /etc/raddb/modules/expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating module "logintime" from file /etc/raddb/modules/logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { # from file /etc/raddb/radiusd.conf modules { Module: Creating Post-Auth-Type = REJECT Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating module "pap" from file /etc/raddb/modules/pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating module "chap" from file /etc/raddb/modules/chap Module: Linked to module rlm_mschap Module: Instantiating module "mschap" from file /etc/raddb/modules/mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no allow_retry = yes } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating module "preprocess" from file /etc/raddb/modules/preprocess preprocess { huntgroups = "/etc/raddb/huntgroups" hints = "/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_digest Module: Instantiating module "digest" from file /etc/raddb/modules/digest Module: Linked to module rlm_realm Module: Instantiating module "suffix" from file /etc/raddb/modules/realm realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_sql Module: Instantiating module "sql" from file /etc/raddb/sql.conf sql { driver = "rlm_sql_mysql" server = "localhost" port = "3306" login = "radxxxxxx" password = "radxxxxxx" radius_db = "radius" read_groups = yes sqltrace = yes sqltracefile = "/var/log/radius/sqltrace.sql" readclients = no deletestalesessions = yes num_sql_socks = 5 lifetime = 0 max_queries = 0 sql_user_name = "%{User-Name}" default_user_profile = "" nas_query = "SELECT id, nasname, shortname, type, secret, 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" connect_failure_retry_delay = 60 simul_count_query = "" simul_verify_query = "SELECT radacctid, acctsessionid, username, nasipaddress, nasportid, framedipaddress, callingstationid, framedprotocol FROM radacct WHERE username = '%{SQL-User-Name}' AND acctstoptime IS NULL" postauth_query = "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sql (sql): Driver rlm_sql_mysql (module rlm_sql_mysql) loaded and linked rlm_sql (sql): Attempting to connect to radiusd@localhost:3306/radius2 rlm_sql (sql): starting 0 rlm_sql (sql): Attempting to connect rlm_sql_mysql #0 rlm_sql_mysql: Starting connect to MySQL server for #0 rlm_sql (sql): Connected new DB handle, #0 rlm_sql (sql): starting 1 rlm_sql (sql): Attempting to connect rlm_sql_mysql #1 rlm_sql_mysql: Starting connect to MySQL server for #1 rlm_sql (sql): Connected new DB handle, #1 rlm_sql (sql): starting 2 rlm_sql (sql): Attempting to connect rlm_sql_mysql #2 rlm_sql_mysql: Starting connect to MySQL server for #2 rlm_sql (sql): Connected new DB handle, #2 rlm_sql (sql): starting 3 rlm_sql (sql): Attempting to connect rlm_sql_mysql #3 rlm_sql_mysql: Starting connect to MySQL server for #3 rlm_sql (sql): Connected new DB handle, #3 rlm_sql (sql): starting 4 rlm_sql (sql): Attempting to connect rlm_sql_mysql #4 rlm_sql_mysql: Starting connect to MySQL server for #4 rlm_sql (sql): Connected new DB handle, #4 Module: Linked to module rlm_sqlcounter Module: Instantiating module "noresetcounter" from file /etc/raddb/sqlcounter.conf sqlcounter noresetcounter { counter-name = "Max-All-Session-Time" check-name = "Max-All-Session" key = "User-Name" sqlmod-inst = "sql" query = "SELECT SUM(AcctSessionTime) FROM radacct WHERE UserName='%{%k}'" reset = "never" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sqlcounter: Reply attribute set to Session-Timeout. rlm_sqlcounter: Counter attribute Max-All-Session-Time is number 11273 rlm_sqlcounter: Check attribute Max-All-Session is number 11274 rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Next reset 0 [2012-04-14 11:00:00] rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Prev reset 0 [2012-04-14 11:00:00] Module: Instantiating module "dailycounter" from file /etc/raddb/sqlcounter.conf sqlcounter dailycounter { counter-name = "Daily-Session-Time" check-name = "Max-Daily-Session" key = "User-Name" sqlmod-inst = "sql" query = "SELECT SUM(AcctSessionTime - GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0)) FROM radacct WHERE UserName='%{%k}' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'" reset = "daily" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sqlcounter: Reply attribute set to Session-Timeout. rlm_sqlcounter: Counter attribute Daily-Session-Time is number 11275 rlm_sqlcounter: Check attribute Max-Daily-Session is number 11276 rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Next reset 1334462400 [2012-04-15 00:00:00] rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Prev reset 1334376000 [2012-04-14 00:00:00] Module: Instantiating module "monthlycounter" from file /etc/raddb/sqlcounter.conf sqlcounter monthlycounter { counter-name = "Monthly-Session-Time" check-name = "Max-Monthly-Session" key = "User-Name" sqlmod-inst = "sqlcca3" query = "SELECT SUM(AcctSessionTime - GREATEST((%b - UNIX_TIMESTAMP(AcctStartTime)), 0)) FROM radacct WHERE UserName='%{%k}' AND UNIX_TIMESTAMP(AcctStartTime) + AcctSessionTime > '%b'" reset = "monthly" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sqlcounter: Reply attribute set to Session-Timeout. rlm_sqlcounter: Counter attribute Monthly-Session-Time is number 11277 rlm_sqlcounter: Check attribute Max-Monthly-Session is number 11278 rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Next reset 1335844800 [2012-05-01 00:00:00] rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Prev reset 1333252800 [2012-04-01 00:00:00] Module: Instantiating module "daypasscounter" from file /etc/raddb/sqlcounter.conf sqlcounter daypasscounter { counter-name = "Day-Term-Code" check-name = "Check-Login-Day" key = "User-Name" sqlmod-inst = "sql" query = "SELECT UNIX_TIMESTAMP(now()) - UNIX_TIMESTAMP(min(AcctStartTime)) FROM radacct WHERE UserName='%{%k}' LIMIT 1" reset = "never" safe-characters = "@abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789.-_: /" } rlm_sqlcounter: Reply attribute set to Session-Timeout. rlm_sqlcounter: Counter attribute Day-Term-Code is number 11279 rlm_sqlcounter: Check attribute Check-Login-Day is number 11280 rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Next reset 0 [2012-04-14 11:00:00] rlm_sqlcounter: Current Time: 1334416365 [2012-04-14 11:12:45], Prev reset 0 [2012-04-14 11:00:00] Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating module "acct_unique" from file /etc/raddb/modules/acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } Module: Linked to module rlm_files Module: Instantiating module "files" from file /etc/raddb/modules/files files { usersfile = "/etc/raddb/users" acctusersfile = "/etc/raddb/acct_users" preproxy_usersfile = "/etc/raddb/preproxy_users" compat = "no" } Module: Checking accounting {...} for more modules to load Module: Linked to module rlm_detail Module: Instantiating module "detail" from file /etc/raddb/modules/detail detail { detailfile = "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" header = "%t" detailperm = 384 dirperm = 493 locking = no log_packet_header = no } Module: Linked to module rlm_radutmp Module: Instantiating module "radutmp" from file /etc/raddb/modules/radutmp radutmp { filename = "/var/log/radius/radutmp" username = "%{User-Name}" case_sensitive = yes check_with_nas = yes perm = 384 callerid = yes } Module: Linked to module rlm_attr_filter Module: Instantiating module "attr_filter.accounting_response" from file /etc/raddb/modules/attr_filter attr_filter attr_filter.accounting_response { attrsfile = "/etc/raddb/attrs.accounting_response" key = "%{User-Name}" relaxed = no } Module: Checking session {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Instantiating module "attr_filter.access_reject" from file /etc/raddb/modules/attr_filter attr_filter attr_filter.access_reject { attrsfile = "/etc/raddb/attrs.access_reject" key = "%{User-Name}" relaxed = no } } # modules } # server server inner-tunnel { # from file /etc/raddb/sites-enabled/inner-tunnel modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_unix Module: Instantiating module "unix" from file /etc/raddb/modules/unix unix { radwtmp = "/var/log/radius/radwtmp" } Module: Linked to module rlm_eap Module: Instantiating module "eap" from file /etc/raddb/eap.conf eap { default_eap_type = "md5" timer_expire = 60 ignore_unknown_eap_types = no cisco_accounting_username_bug = no max_sessions = 4096 } Module: Linked to sub-module rlm_eap_md5 Module: Instantiating eap-md5 Module: Linked to sub-module rlm_eap_leap Module: Instantiating eap-leap Module: Linked to sub-module rlm_eap_gtc Module: Instantiating eap-gtc gtc { challenge = "Password: " auth_type = "PAP" } Module: Linked to sub-module rlm_eap_tls Module: Instantiating eap-tls tls { rsa_key_exchange = no dh_key_exchange = yes rsa_key_length = 512 dh_key_length = 512 verify_depth = 0 CA_path = "/etc/raddb/certs" pem_file_type = yes private_key_file = "/etc/raddb/certs/server.pem" certificate_file = "/etc/raddb/certs/server.pem" CA_file = "/etc/raddb/certs/ca.pem" private_key_password = "whatever" dh_file = "/etc/raddb/certs/dh" random_file = "/etc/raddb/certs/random" fragment_size = 1024 include_length = yes check_crl = no cipher_list = "DEFAULT" cache { enable = no lifetime = 24 max_entries = 255 } verify { } ocsp { enable = no override_cert_url = yes url = "http://127.0.0.1/ocsp/" } } Module: Linked to sub-module rlm_eap_ttls Module: Instantiating eap-ttls ttls { default_eap_type = "md5" copy_request_to_tunnel = no use_tunneled_reply = no virtual_server = "inner-tunnel" include_length = yes } Module: Linked to sub-module rlm_eap_peap Module: Instantiating eap-peap peap { default_eap_type = "mschapv2" copy_request_to_tunnel = no use_tunneled_reply = no proxy_tunneled_request_as_eap = yes virtual_server = "inner-tunnel" soh = no } 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: 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 = 1812 } listen { type = "acct" ipaddr = * port = 1813 } listen { type = "control" listen { socket = "/var/run/radiusd/radiusd.sock" } } listen { type = "auth" ipaddr = 127.0.0.1 port = 18120 } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /var/run/radiusd/radiusd.sock Listening on authentication address 127.0.0.1 port 18120 as server inner-tunnel Ready to process requests. rad_recv: Access-Request packet from host 192.168.245.1 port 58639, id=215, length=51 User-Password = "wolfchase-guest" User-Name = "memwg150412" # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "memwg150412", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [sql] expand: %{User-Name} -> memwg150412 [sql] sql_set_user escaped user --> 'memwg150412' rlm_sql (sql): Reserving sql socket id: 4 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'memwg150412' ORDER BY id rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'memwg150412' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'memwg150412' ORDER BY id rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'memwg150412' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'memwg150412' ORDER BY priority rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'memwg150412' ORDER BY priority [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 = 'wolfchase-guest-group' ORDER BY id rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'wolfchase-guest-group' ORDER BY id rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[noresetcounter] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[dailycounter] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[monthlycounter] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[daypasscounter] returns noop ++[pap] returns updated Found Auth-Type = PAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group PAP {...} [pap] login attempt with password "wolfchase-guest" [pap] Using clear text password "wolfchase-guest" [pap] User authenticated successfully ++[pap] returns ok Login OK: [memwg150412] (from client vmHost port 0) # Executing section post-auth from file /etc/raddb/sites-enabled/default +- entering group post-auth {...} [sql] expand: %{User-Name} -> memwg150412 [sql] sql_set_user escaped user --> 'memwg150412' [sql] expand: %{User-Password} -> wolfchase-guest [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'memwg150412', 'wolfchase-guest', 'Access-Accept', '2012-04-14 11:12:53') [sql] expand: /var/log/radius/sqltrace.sql -> /var/log/radius/sqltrace.sql rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'memwg150412', 'wolfchase-guest', 'Access-Accept', '2012-04-14 11:12:53') rlm_sql (sql): Reserving sql socket id: 3 rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'memwg150412', 'wolfchase-guest', 'Access-Accept', '2012-04-14 11:12:53') rlm_sql (sql): Released sql socket id: 3 ++[sql] returns ok ++[exec] returns noop Sending Access-Accept of id 215 to 192.168.245.1 port 58639 Nomadix-Bw-Down := 768 Nomadix-Bw-Up := 256 Finished request 0. Going to the next request Waking up in 4.9 seconds. Cleaning up request 0 ID 215 with timestamp +8 Ready to process requests. rad_recv: Access-Request packet from host 192.168.245.1 port 65287, id=120, length=49 User-Name = "ithce0412" User-Password = "hiit_pass" # Executing section authorize from file /etc/raddb/sites-enabled/default +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop ++[digest] returns noop [suffix] No '@' in User-Name = "ithce0412", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [sql] expand: %{User-Name} -> ithce0412 [sql] sql_set_user escaped user --> 'ithce0412' rlm_sql (sql): Reserving sql socket id: 2 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ithce0412' ORDER BY id rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'ithce0412' ORDER BY id [sql] User found in radcheck table [sql] expand: SELECT id, username, attribute, value, op FROM radreply WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ithce0412' ORDER BY id rlm_sql_mysql: query: SELECT id, username, attribute, value, op FROM radreply WHERE username = 'ithce0412' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'ithce0412' ORDER BY priority rlm_sql_mysql: query: SELECT groupname FROM radusergroup WHERE username = 'ithce0412' ORDER BY priority [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 = 'ithce-guest-group' ORDER BY id rlm_sql_mysql: query: SELECT id, groupname, attribute, Value, op FROM radgroupcheck WHERE groupname = 'ithce-guest-group' ORDER BY id rlm_sql (sql): Released sql socket id: 2 ++[sql] returns ok ++[expiration] returns noop ++[logintime] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[noresetcounter] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[dailycounter] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[monthlycounter] returns noop rlm_sqlcounter: Entering module authorize code rlm_sqlcounter: Could not find Check item value pair ++[daypasscounter] returns noop ++[pap] returns updated Found Auth-Type = PAP # Executing group from file /etc/raddb/sites-enabled/default +- entering group PAP {...} [pap] login attempt with password "hiit_pass" [pap] Using clear text password "hiit_pass" [pap] User authenticated successfully ++[pap] returns ok Login OK: [ithce0412] (from client vmHost port 0) # Executing section post-auth from file /etc/raddb/sites-enabled/default +- entering group post-auth {...} [sql] expand: %{User-Name} -> ithce0412 [sql] sql_set_user escaped user --> 'ithce0412' [sql] expand: %{User-Password} -> hiit_pass [sql] expand: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S') -> INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ithce0412', 'hiit_pass', 'Access-Accept', '2012-04-14 11:14:42') [sql] expand: /var/log/radius/sqltrace.sql -> /var/log/radius/sqltrace.sql rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ithce0412', 'hiit_pass', 'Access-Accept', '2012-04-14 11:14:42') rlm_sql (sql): Reserving sql socket id: 1 rlm_sql_mysql: query: INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'ithce0412', 'hiit_pass', 'Access-Accept', '2012-04-14 11:14:42') rlm_sql (sql): Released sql socket id: 1 ++[sql] returns ok ++[exec] returns noop Sending Access-Accept of id 120 to 192.168.245.1 port 65287 Finished request 1. Going to the next request Waking up in 4.9 seconds. Cleaning up request 1 ID 120 with timestamp +117 Ready to process requests. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html