Failure to Process radgroupreply
Platfrom: CentOS 5.8 FreeRADIUS: 2.1.8 Backend: MySQL I am unable to get FreeRadius to reply with attributes assigned in the radgroupreply table for some groups. When the same attributes are assigned in radreply, the server sends them as expected. Adding a Fall-Through entry for the user in radreply makes no difference (the server defaults to Fall-Through from the config). I can see no difference in the structure of the user/groups between working and non-working accounts. I've spent most of the night combing the web, wiki, and other resources, but I find nothing quite like this. For instance: # radcheck testuser1 Cleartext-Password := password # radreply (WORKS) testuser1 Nomadix-Bw-Down := 768 # radusergroup testuser1 test-group 1 # radgroupreply (DOES NOT WORK) testuser1 Nomadix-Bw-Down := 768 Here is debug output from an auth request for this account (when the pairs are only in radgroupreply). You'll notice there is no processing of the radgroupreply table. rad_recv: Access-Request packet from host xx.xx.xx.xx port 29817, id=170, length=49 User-Name = "testuser1" User-Password = "password" +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop ++[mschap] returns noop [suffix] No '@' in User-Name = "testuser1", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [sql] expand: %{User-Name} -> testuser1 [sql] sql_set_user escaped user --> 'testuser1' rlm_sql (sql): Reserving sql socket id: 0 [sql] expand: SELECT id, username, attribute, value, op FROM radcheck WHERE username = '%{SQL-User-Name}' ORDER BY id -> SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'testuser1' 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 = 'testuser1' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'testuser1' 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 = 'test-group' ORDER BY id rlm_sql (sql): Released sql socket id: 0 ++[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 +- entering group PAP {...} [pap] login attempt with password "password" [pap] Using clear text password "password" [pap] User authenticated successfully ++[pap] returns ok Login OK: [testuser1] (from client wolfchase-gateway port 0) +- entering group post-auth {...} [sql] expand: %{User-Name} -> testuser1 [sql] sql_set_user escaped user --> 'testuser1' [sql] expand: %{User-Password} -> password [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 ( 'testuser1', 'password', 'Access-Accept', '2012-04-05 06:58:06') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'testuser1', 'password', 'Access-Accept', '2012-04-05 06:58:06') rlm_sql (sql): Reserving sql socket id: 4 rlm_sql (sql): Released sql socket id: 4 ++[sql] returns ok ++[exec] returns noop Sending Access-Accept of id 170 to xx.xx.xx.xx port 29817 Finished request 166. Going to the next request Waking up in 3.0 seconds. Thank you for any help.
For reference, here is a debug from another account's auth request which successfully processes radgroupreply and sends the pairs from that table. The attributes are different here because the NAS is different and I don't want to confuse it by assigning another vendor's attributes. I did accidentally have the Nomadix-Bw-Up/Down in this account's radgrouprely table, and they were also passed correctly here, though I don't have that debug. rad_recv: Access-Request packet from host xx.xx.xx.xx port 32772, id=71, length=244 Acct-Session-Id = "645dcb12" NAS-Port = 10 NAS-Port-Type = Wireless-802.11 User-Name = "tup140412" Calling-Station-Id = "3C-8B-FE-D8-66-6E" Called-Station-Id = "3C-D9-2B-7B-97-37" Framed-IP-Address = 192.168.25.92 MS-CHAP2-Response = 0x4700c5c9e5b0d32cef356ea40cef22e904a400000000000000008ab1f953dbb0a3b342fbdf00518cda391b29bf13efeffd84 MS-CHAP-Challenge = 0x20a511804f668694117f916ee1ef6a46 NAS-Identifier = "TW126LK026" NAS-IP-Address = xx.xx.xx.xx Framed-MTU = 1496 Connect-Info = "HTTPS" Service-Type = Framed-User Colubris-AVPair = "vsc-name=HP ProCurve" +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] returns ok [suffix] No '@' in User-Name = "tup140412", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [sql] expand: %{User-Name} -> tup140412 [sql] sql_set_user escaped user --> 'tup140412' 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 = 'tup140412' 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 = 'tup140412' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'tup140412' 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 = 'hieTUPELO-guest-group' ORDER BY id [sql] User found in group hieTUPELO-guest-group [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 = 'hieTUPELO-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] Found existing Auth-Type, not changing it. ++[pap] returns noop Found Auth-Type = MSCHAP +- entering group MS-CHAP {...} [mschap] Told to do MS-CHAPv2 for tup140412 with NT-Password [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok Login OK: [tup140412] (from client xxx-gateway port 10 cli 3C-8B-FE-D8-66-6E) +- entering group post-auth {...} [sql] expand: %{User-Name} -> tup140412 [sql] sql_set_user escaped user --> 'tup140412' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [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 ( 'tup140412', '', 'Access-Accept', '2012-04-05 08:01:35') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'tup140412', '', 'Access-Accept', '2012-04-05 08:01:35') rlm_sql (sql): Reserving sql socket id: 1 rlm_sql (sql): Released sql socket id: 1 ++[sql] returns ok ++[exec] returns noop Sending Access-Accept of id 71 to xx.xx.xx.xx port 32772 Idle-Timeout := 3600 [from radgroupreply] Colubris-AVPair += "one-to-one-nat=1" [from radgroupreply] Colubris-AVPair += "smtp-redirect=xx.xx.xx.xx" [from radgroupreply] MS-CHAP2-Success = 0x47533d46453336353138333746413938383539443430424143443130383539364131454434363631384642 MS-MPPE-Recv-Key = 0x200ce521f54129a00b8ddbfa0d38a1df MS-MPPE-Send-Key = 0x64debbade6a03f53df884e7ef78a7645 MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006
Andrew Long wrote:
I am unable to get FreeRadius to reply with attributes assigned in the radgroupreply table for some groups. When the same attributes are assigned in radreply, the server sends them as expected. Adding a Fall-Through entry for the user in radreply makes no difference (the server defaults to Fall-Through from the config). I can see no difference in the structure of the user/groups between working and non-working accounts.
Did you set "read_groups = yes" in sql.conf? What about the comments just above that configuration? Alan DeKok.
Did you set "read_groups = yes" in sql.conf?
What about the comments just above that configuration?
Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html
It was commented out! Given the comments, though, do you have any idea why it would still have failed when I tested with Fall-Through enabled? I did it like this: # radreply account-to-test Fall-Through = yes So, I removed the comment and restarted radiusd, but I get the same results. Here is the radgroupreply: 4 xxx-guest-group Nomadix-Bw-Down := 768 85 xxx-guest-group Nomadix-Bw-Up := 256 My packet capture shows none of the group items being returned. This test was done sending the request from RadTest; I'm going to check again in a moment with an actual Win7 client behind the Nomadix and will let you know... There is also the oddity that even though the line was commented previously, groups were being processed as I would see in the reply packets pairs that existed only in radgroupreply. Thank you, Alan.
I should have said... There is also the oddity that even though the line was commented previously, groups were being processed as I would see in the reply packets pairs that existed only in radgroupreply. JUST NOT THE ONES I WANT.
OK, the test from an actual client behind the Nomadix fails even after un-commenting read_groups = yes and restarting, still no group attributes passed in reply. This debug is rather lengthy as I thought you might want to see some of the earlier loading (though I snipped some). What should I try next? <snip> radiusd: #### Instantiating modules #### instantiate { Module: Linked to module rlm_exec Module: Instantiating exec exec { wait = no input_pairs = "request" shell_escape = yes } Module: Linked to module rlm_expr Module: Instantiating expr Module: Linked to module rlm_expiration Module: Instantiating expiration expiration { reply-message = "Password Has Expired " } Module: Linked to module rlm_logintime Module: Instantiating logintime logintime { reply-message = "You are calling outside your allowed timespan " minimum-timeout = 60 } } radiusd: #### Loading Virtual Servers #### server { modules { Module: Checking authenticate {...} for more modules to load Module: Linked to module rlm_pap Module: Instantiating pap pap { encryption_scheme = "auto" auto_header = no } Module: Linked to module rlm_chap Module: Instantiating chap Module: Linked to module rlm_mschap Module: Instantiating mschap mschap { use_mppe = yes require_encryption = no require_strong = no with_ntdomain_hack = no } Module: Checking authorize {...} for more modules to load Module: Linked to module rlm_preprocess Module: Instantiating 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_realm Module: Instantiating suffix realm suffix { format = "suffix" delimiter = "@" ignore_default = no ignore_null = no } Module: Linked to module rlm_sql Module: Instantiating sql sql { driver = "rlm_sql_mysql" server = "localhost" port = "" login = "radiusd" password = "radiusd" radius_db = "radius2" read_groups = yes sqltrace = no 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 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:/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 noresetcounter 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: 1333638543 [2012-04-05 11:09:03], Next reset 0 [2012-04-05 11:00:00] rlm_sqlcounter: Current Time: 1333638543 [2012-04-05 11:09:03], Prev reset 0 [2012-04-05 11:00:00] Module: Instantiating dailycounter 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: 1333638543 [2012-04-05 11:09:03], Next reset 1333684800 [2012-04-06 00:00:00] rlm_sqlcounter: Current Time: 1333638543 [2012-04-05 11:09:03], Prev reset 1333598400 [2012-04-05 00:00:00] Module: Instantiating monthlycounter 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: 1333638543 [2012-04-05 11:09:03], Next reset 1335844800 [2012-05-01 00:00:00] rlm_sqlcounter: Current Time: 1333638543 [2012-04-05 11:09:03], Prev reset 1333252800 [2012-04-01 00:00:00] Module: Instantiating daypasscounter 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: 1333638543 [2012-04-05 11:09:03], Next reset 0 [2012-04-05 11:00:00] rlm_sqlcounter: Current Time: 1333638543 [2012-04-05 11:09:03], Prev reset 0 [2012-04-05 11:00:00] Module: Checking preacct {...} for more modules to load Module: Linked to module rlm_acct_unique Module: Instantiating acct_unique acct_unique { key = "User-Name, Acct-Session-Id, NAS-IP-Address, Client-IP-Address, NAS-Port" } Module: Linked to module rlm_files Module: Instantiating 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 detail detail { detailfile = "/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_radutmp Module: Instantiating 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 attr_filter.accounting_response attr_filter attr_filter.accounting_response { attrsfile = "/etc/raddb/attrs.accounting_response" key = "%{User-Name}" } Module: Checking session {...} for more modules to load Module: Checking post-auth {...} for more modules to load Module: Instantiating attr_filter.access_reject attr_filter attr_filter.access_reject { attrsfile = "/etc/raddb/attrs.access_reject" key = "%{User-Name}" } } # 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" } } Listening on authentication address * port 1812 Listening on accounting address * port 1813 Listening on command file /var/run/radiusd/radiusd.sock Ready to process requests. <snip> rad_recv: Access-Request packet from host xx.xx.xx.xx port 1031, id=26, length=260 User-Name = "memwg140412" NAS-IP-Address = xx.xx.xx.xx NAS-Port = 0 Service-Type = Login-User Acct-Session-Id = "0F00008E" Called-Station-Id = "00-50-E8-03-13-0D" Calling-Station-Id = "00-1F-3C-83-3C-E4" Nomadix-Logoff-URL = "http://1.1.1.1" WISPr-Location-ID = "isocc=840,cc=011,ac=901,network=Holiday Inn" Framed-IP-Address = 192.168.1.52 MS-CHAP-Challenge = 0xb03f0000a3090000056d00007d520000 MS-CHAP2-Response = 0xbc000c3c0000700100001c640000f967000000000000000000007e96645fb3fad2e732972a2672cf55e17f24a48e753ea09f +- entering group authorize {...} ++[preprocess] returns ok ++[chap] returns noop [mschap] Found MS-CHAP attributes. Setting 'Auth-Type = mschap' ++[mschap] returns ok [suffix] No '@' in User-Name = "memwg140412", looking up realm NULL [suffix] No such realm "NULL" ++[suffix] returns noop [sql] expand: %{User-Name} -> memwg140412 [sql] sql_set_user escaped user --> 'memwg140412' 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 = 'memwg140412' 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 = 'memwg140412' ORDER BY id [sql] expand: SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority -> SELECT groupname FROM radusergroup WHERE username = 'memwg140412' 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 (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] Found existing Auth-Type, not changing it. ++[pap] returns noop Found Auth-Type = MSCHAP +- entering group MS-CHAP {...} [mschap] Told to do MS-CHAPv2 for memwg140412 with NT-Password [mschap] adding MS-CHAPv2 MPPE keys ++[mschap] returns ok Login OK: [memwg140412] (from client xxx-gateway port 0 cli 00-1F-3C-83-3C-E4) +- entering group post-auth {...} [sql] expand: %{User-Name} -> memwg140412 [sql] sql_set_user escaped user --> 'memwg140412' [sql] expand: %{User-Password} -> [sql] ... expanding second conditional [sql] expand: %{Chap-Password} -> [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 ( 'memwg140412', '', 'Access-Accept', '2012-04-05 11:09:17') rlm_sql (sql) in sql_postauth: query is INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'memwg140412', '', 'Access-Accept', '2012-04-05 11:09:17') rlm_sql (sql): Reserving sql socket id: 1 rlm_sql (sql): Released sql socket id: 1 ++[sql] returns ok ++[exec] returns noop Sending Access-Accept of id 26 to xx.xx.xx.xx port 1031 MS-CHAP2-Success = 0xbc533d43323337463532313532393933423839464445453446374145384342433643383235343231313037 MS-MPPE-Recv-Key = 0xa9df6d6d7c6e4c8c4956f26197314f4d MS-MPPE-Send-Key = 0x7bc8f7efdf37c3d17a107b73dc7fedcb MS-MPPE-Encryption-Policy = 0x00000001 MS-MPPE-Encryption-Types = 0x00000006 Finished request 1.
Andrew Long wrote:
It was commented out! Given the comments, though, do you have any idea why it would still have failed when I tested with Fall-Through enabled? I did it like this: # radreply account-to-test Fall-Through = yes
It should work.
So, I removed the comment and restarted radiusd, but I get the same results. Here is the radgroupreply: 4 xxx-guest-group Nomadix-Bw-Down := 768 85 xxx-guest-group Nomadix-Bw-Up := 256
Again...
My packet capture shows none of the group items being returned.
And debug mode will tell you what's going on.
This test was done sending the request from RadTest; I'm going to check again in a moment with an actual Win7 client behind the Nomadix and will let you know...
Why? Use radtest or radclient. RADIUS isn't magic. It doesn't require the "right" magic client software. Everything is in the packet. So... if you reproduce the packet, you reproduce the tests.
There is also the oddity that even though the line was commented previously, groups were being processed as I would see in the reply packets pairs that existed only in radgroupreply.
No idea. It works for me when I test it. Alan DeKok.
In case you missed it, the debug from latest test is a couple messages previous (our messages crossed). I have looked through it and with my limited knowledge see nothing exceptional except that processing stops with radgroupcheck and never moves to radgroupreply. Have you any ideas? - Andrew
On Thu, Apr 5, 2012 at 12:04 PM, Andrew Long <fursink@gmail.com> wrote:
In case you missed it, the debug from latest test is a couple messages previous (our messages crossed). I have looked through it and with my limited knowledge see nothing exceptional except that processing stops with radgroupcheck and never moves to radgroupreply. Have you any ideas?
- Andrew
I apologize if this is "off-topic", but if someone wishes to take this on as contractual work, please send email with brief references to <along[AT]escapewire[DOT]com>. The job would simply be to find/fix the problem with group processing. Thank you. - Andrew Long
Andrew Long wrote:
In case you missed it, the debug from latest test is a couple messages previous (our messages crossed). I have looked through it and with my limited knowledge see nothing exceptional except that processing stops with radgroupcheck and never moves to radgroupreply. Have you any ideas?
Run the queries manually, and try to sort it out. Alan DeKok.
Run the queries manually, and try to sort it out.
Alan DeKok.
Thank you. Just in case, I tested a build of 2.1.12 now avail through the stock repos on a CentOS 5.8 VM. It's working correctly, so I'm confident I can get there (an upgrade, to boot) without much too difficulty. - Andrew
participants (2)
-
Alan DeKok -
Andrew Long