Hi, I am having some trouble with freeradius and the SQL module. The issue i have is the radgroupcheck and radgroupreply tables never get read by freeradius. I cannot find a reason why the group tables aren't being used, they meet the requirements according the the wiki. Specifically my Pool-Name is not being pulled and assigned to the user from the groupcheck. If i set the pool name in radcheck and not radgroupcheck it works and the user is assigned an IP from the pool. In the sql.conf i have checked "read_groups = yes" is set The sqlippool and sql modules are enabled in the default sites setup hence it works when set in radcheck. This problem is because the groups are not being read. I would really like some help as to why my groups aren't working Here is my config and a debug out of radiusd -X MariaDB [radius]> select * from radcheck;+----+----------+--------------------+----+-------+| id | username | attribute | op | value |+----+----------+--------------------+----+-------+| 1 | user | Cleartext-Password | := | pass |+----+----------+--------------------+----+-------+4 rows in set (0.00 sec) MariaDB [radius]> select * from radusergroup;+----------+-----------+----------+| username | groupname | priority |+----------+-----------+----------+| user | vpngroup | 1 |+----------+-----------+----------+1 row in set (0.00 sec) MariaDB [radius]> select * from radgroupcheck;+----+-----------+--------------+----+-------+| id | groupname | attribute | op | value |+----+-----------+--------------+----+-------+| 3 | vpngroup | Pool-Name | := | pool1 |+----+-----------+--------------+----+-------+2 rows in set (0.01 sec) MariaDB [radius]> select * from radippool;+----+-----------+-----------------+--------------+-----------------+------------------+---------------------+----------+----------+| id | pool_name | framedipaddress | nasipaddress | calledstationid | callingstationid | expiry_time | username | pool_key |+----+-----------+-----------------+--------------+-----------------+------------------+---------------------+----------+----------+| 1 | pool1 | 172.16.15.1 | | | | NULL | | 0 || 2 | pool1 | 172.16.15.2 | | | | NULL | | || 3 | pool1 | 172.16.15.3 | | | | NULL | | |+----+-----------+-----------------+--------------+-----------------+------------------+---------------------+----------+----------+3 rows in set (0.00 sec)
From the above it meets the requirements set out in the wiki - http://wiki.freeradius.org/modules/Rlm_sql
"The user IS found in radcheck, the check items DO match AND the read_groups directive is set to 'yes' "
From the debug out you can see it doesn't check the groups then moves on and says " (0) sqlippool : No Pool-Name defined." I have also checked the file /etc/raddb/mods-config/sql/main/mysql/queries.conf and i see the queries for the groupcheck its just not doing it
Ready to process requests.rad_recv: Access-Request packet from host 192.168.1.109 port 55758, id=53, length=146 Service-Type = Framed-User Framed-Protocol = PPP User-Name = 'test' MS-CHAP-Challenge = 0x7098b7e479b88ea6ea646493435c771e MS-CHAP2-Response = 0x7a002c2ae80d2311583f5e38117753a3dc7a0000000000000000eef14310bcc325e0edb4908298df6014328fc042ddaf2360 Calling-Station-Id = '192.168.1.70' NAS-IP-Address = 127.0.0.1 NAS-Port = 0(0) # Executing section authorize from file /etc/raddb/sites-enabled/default(0) authorize {(0) filter_username filter_username {(0) ? if (User-Name != "%{tolower:%{User-Name}}") (0) expand: "%{tolower:%{User-Name}}" -> 'test'(0) ? if (User-Name != "%{tolower:%{User-Name}}") -> FALSE(0) ? if (User-Name =~ / /) (0) ? if (User-Name =~ / /) -> FALSE(0) ? if (User-Name =~ /@.*@/ ) (0) ? if (User-Name =~ /@.*@/ ) -> FALSE(0) ? if (User-Name =~ /\\.\\./ ) (0) ? if (User-Name =~ /\\.\\./ ) -> FALSE(0) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) (0) ? if ((User-Name =~ /@/) && (User-Name !~ /@(.+)\\.(.+)$/)) -> FALSE(0) ? if (User-Name =~ /\\.$/) (0) ? if (User-Name =~ /\\.$/) -> FALSE(0) ? if (User-Name =~ /@\\./) (0) ? if (User-Name =~ /@\\./) -> FALSE(0) } # filter_username filter_username = notfound(0) [preprocess] = ok(0) auth_log : expand: "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d" -> '/var/log/radius/radacct/192.168.1.109/auth-detail-20140926'(0) auth_log : /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.109/auth-detail-20140926(0) auth_log : expand: "%t" -> 'Fri Sep 26 06:51:18 2014'(0) [auth_log] = ok(0) [chap] = noop(0) mschap : Found MS-CHAP attributes. Setting 'Auth-Type = mschap'(0) [mschap] = ok(0) [digest] = noop(0) suffix : No '@' in User-Name = "test", looking up realm NULL(0) suffix : No such realm "NULL"(0) [suffix] = noop(0) eap : No EAP-Message, not doing EAP(0) [eap] = noop(0) files : users: Matched entry DEFAULT at line 181(0) [files] = ok(0) sql : expand: "%{User-Name}" -> 'test'(0) sql : SQL-User-Name set to 'test'rlm_sql (sql): Reserved connection (4)(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 = 'test' ORDER BY id'rlm_sql (sql): Executing query: 'SELECT id, username, attribute, value, op FROM radcheck WHERE username = 'test' ORDER BY id'(0) sql : User found in radcheck table(0) sql : Check items matched(0) 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 = 'test' ORDER BY id'rlm_sql (sql): Executing query: 'SELECT id, username, attribute, value, op FROM radreply WHERE username = 'test' ORDER BY id'(0) sql : expand: "SELECT groupname FROM radusergroup WHERE username = '%{SQL-User-Name}' ORDER BY priority" -> 'SELECT groupname FROM radusergroup WHERE username = 'test' ORDER BY priority'rlm_sql (sql): Executing query: 'SELECT groupname FROM radusergroup WHERE username = 'test' ORDER BY priority'rlm_sql (sql): Released connection (4)rlm_sql (sql): Closing connection (0): Too many free connections (5 > 3)rlm_sql_mysql: Socket destructor called, closing socket(0) [sql] = ok(0) [expiration] = noop(0) [logintime] = noop(0) WARNING: pap : Auth-Type already set. Not setting to PAP(0) [pap] = noop(0) } # authorize = ok(0) Found Auth-Type = MSCHAP(0) # Executing group from file /etc/raddb/sites-enabled/default(0) Auth-Type MS-CHAP {(0) mschap : Found Cleartext-Password, hashing to create LM-Password(0) mschap : Found Cleartext-Password, hashing to create NT-Password(0) mschap : Creating challenge hash with username: test(0) mschap : Client is using MS-CHAPv2 for test, we need NT-Password(0) mschap : adding MS-CHAPv2 MPPE keys(0) [mschap] = ok(0) } # Auth-Type MS-CHAP = ok(0) Login OK: [test/<via Auth-Type = MSCHAP>] (from client 192.168.1.109 port 0 cli 192.168.1.70)(0) # Executing section post-auth from file /etc/raddb/sites-enabled/default(0) post-auth {(0) sql : expand: ".query" -> '.query'(0) sql : Using query template 'query'rlm_sql (sql): Reserved connection (4)(0) sql : expand: "%{User-Name}" -> 'test'(0) sql : SQL-User-Name set to 'test'(0) sql : expand: "INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}', '%{reply:Packet-Type}', '%S')" -> 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'test', '', 'Access-Accept', '2014-09-26 06:51:18')'rlm_sql (sql): Executing query: 'INSERT INTO radpostauth (username, pass, reply, authdate) VALUES ( 'test', '', 'Access-Accept', '2014-09-26 06:51:18')'rlm_sql (sql): Released connection (4)(0) [sql] = ok(0) sqlippool : No Pool-Name defined.(0) sqlippool : expand: "No Pool-Name defined (did %{Called-Station-Id} cli %{Calling-Station-Id} port %{NAS-Port} user %{User-Name})" -> 'No Pool-Name defined (did cli 192.168.1.70 port 0 user test)'(0) [sqlippool] = noop(0) [exec] = noop(0) remove_reply_message_if_eap remove_reply_message_if_eap {(0) ? if (reply:EAP-Message && reply:Reply-Message) (0) ? if (reply:EAP-Message && reply:Reply-Message) -> FALSE(0) else else {(0) [noop] = noop(0) } # else else = noop(0) } # remove_reply_message_if_eap remove_reply_message_if_eap = noop(0) } # post-auth = okSending Access-Accept of id 53 from 192.168.1.67 port 1812 to 192.168.1.109 port 55758 Framed-Protocol = PPP Framed-Compression = Van-Jacobson-TCP-IP MS-CHAP2-Success = 0x7a533d30383134394335414641303837374636373833433934413034313938373737363341344231433632 MS-MPPE-Recv-Key = 0xa2232b07eab47e9464305946464fdd13 MS-MPPE-Send-Key = 0xf1ab397d79c4eb450b5dde7dad811f1d MS-MPPE-Encryption-Policy = Encryption-Required MS-MPPE-Encryption-Types = 4(0) Finished request 0.Waking up in 0.2 seconds.Waking up in 4.7 seconds.rad_recv: Accounting-Request packet from host 192.168.1.109 port 35133, id=54, length=110 Acct-Session-Id = '5425A63435B300' User-Name = 'test' Acct-Status-Type = Start Service-Type = Framed-User Framed-Protocol = PPP Calling-Station-Id = '192.168.1.70' Acct-Authentic = RADIUS NAS-Port-Type = Async Framed-IP-Address = 192.168.1.1 NAS-IP-Address = 127.0.0.1 NAS-Port = 0 Acct-Delay-Time = 0(1) # Executing section preacct from file /etc/raddb/sites-enabled/default(1) preacct {(1) [preprocess] = ok(1) acct_unique acct_unique {(1) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (1) expand: "%{string:Class}" -> ''(1) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE(1) else else {(1) update request {(1) expand: "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" -> '84b95fb1219c04cd5fd1f53d294840aa'(1) Acct-Unique-Session-Id := "84b95fb1219c04cd5fd1f53d294840aa"(1) } # update request = noop(1) } # else else = noop(1) } # acct_unique acct_unique = noop(1) suffix : No '@' in User-Name = "test", looking up realm NULL(1) suffix : No such realm "NULL"(1) [suffix] = noop(1) [files] = noop(1) } # preacct = ok(1) # Executing section accounting from file /etc/raddb/sites-enabled/default(1) accounting {(1) detail : expand: "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/var/log/radius/radacct/192.168.1.109/detail-20140926'(1) detail : /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.109/detail-20140926(1) detail : expand: "%t" -> 'Fri Sep 26 06:51:20 2014'(1) [detail] = ok(1) [unix] = okrlm_sql (sql): Reserved connection (4)(1) sqlippool : expand: "%{User-Name}" -> 'test'(1) sqlippool : SQL-User-Name set to 'test'(1) sqlippool : expand: "START TRANSACTION" -> 'START TRANSACTION'rlm_sql (sql): Executing query: 'START TRANSACTION'(1) sqlippool : expand: "UPDATE radippool SET expiry_time = NOW() + INTERVAL 3600 SECOND WHERE nasipaddress = '%{NAS-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" -> 'UPDATE radippool SET expiry_time = NOW() + INTERVAL 3600 SECOND WHERE nasipaddress = '127.0.0.1' AND pool_key = '0' AND username = 'test' AND callingstationid = '192.168.1.70' AND framedipaddress = '192.168.1.1''rlm_sql (sql): Executing query: 'UPDATE radippool SET expiry_time = NOW() + INTERVAL 3600 SECOND WHERE nasipaddress = '127.0.0.1' AND pool_key = '0' AND username = 'test' AND callingstationid = '192.168.1.70' AND framedipaddress = '192.168.1.1''(1) sqlippool : expand: "COMMIT" -> 'COMMIT'rlm_sql (sql): Executing query: 'COMMIT'rlm_sql (sql): Released connection (4)rlm_sql (sql): Closing connection (1): Too many free connections (4 > 3)rlm_sql_mysql: Socket destructor called, closing socket(1) [sqlippool] = ok(1) sql : expand: "%{tolower:type.%{Acct-Status-Type}.query}" -> 'type.start.query'(1) sql : Using query template 'query'rlm_sql (sql): Reserved connection (4)(1) sql : expand: "%{User-Name}" -> 'test'(1) sql : SQL-User-Name set to 'test'(1) sql : expand: "INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{NAS-Port}', '%{NAS-Port-Type}', FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '0', '%{Acct-Authentic}', '%{Connect-Info}', '', '0', '0', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}')" -> 'INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype, acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('5425A63435B300', '84b95fb1219c04cd5fd1f53d294840aa', 'test', '', '127.0.0.1', '0', 'Async', FROM_UNIXTIME(1411710680), FROM_UNIXTIME(1411710680), NULL, '0', 'RADIUS', '', '', '0', '0', '', '192.168.1.70', '', 'Framed-User', 'PPP', '192.168.1.1')'rlm_sql (sql): Executing query: 'INSERT INTO radacct (acctsessionid, acctuniqueid, username, realm, nasipaddress, nasportid, nasporttype,acctstarttime, acctupdatetime, acctstoptime, acctsessiontime, acctauthentic, connectinfo_start, connectinfo_stop, acctinputoctets, acctoutputoctets, calledstationid, callingstationid, acctterminatecause, servicetype, framedprotocol, framedipaddress) VALUES ('5425A63435B300', '84b95fb1219c04cd5fd1f53d294840aa', 'test', '', '127.0.0.1', '0', 'Async', FROM_UNIXTIME(1411710680), FROM_UNIXTIME(1411710680), NULL, '0', 'RADIUS', '', '', '0', '0', '', '192.168.1.70', '', 'Framed-User', 'PPP', '192.168.1.1')'rlm_sql (sql): Released connection (4)(1) [sql] = ok(1) [exec] = noop(1) attr_filter.accounting_response : expand: "%{User-Name}" -> 'test'(1) attr_filter.accounting_response : Matched entry DEFAULT at line 12(1) [attr_filter.accounting_response] = updated(1) } # accounting = updatedSending Accounting-Response of id 54 from 192.168.1.67 port 1813 to 192.168.1.109 port 35133(1) Finished request 1.Waking up in 0.2 seconds.(1) Cleaning up request packet ID 54 with timestamp +14Waking up in 2.7 seconds.(0) Cleaning up request packet ID 53 with timestamp +12Ready to process requests.rad_recv: Accounting-Request packet from host 192.168.1.109 port 59458, id=55, length=146 Acct-Session-Id = '5425A63435B300' User-Name = 'test' Acct-Status-Type = Stop Service-Type = Framed-User Framed-Protocol = PPP Acct-Authentic = RADIUS Acct-Session-Time = 4 Acct-Output-Octets = 0 Acct-Input-Octets = 2804 Acct-Output-Packets = 0 Acct-Input-Packets = 36 Calling-Station-Id = '192.168.1.70' NAS-Port-Type = Async Acct-Terminate-Cause = User-Request Framed-IP-Address = 192.168.1.1 NAS-IP-Address = 127.0.0.1 NAS-Port = 0 Acct-Delay-Time = 0(2) # Executing section preacct from file /etc/raddb/sites-enabled/default(2) preacct {(2) [preprocess] = ok(2) acct_unique acct_unique {(2) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (2) expand: "%{string:Class}" -> ''(2) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE(2) else else {(2) update request {(2) expand: "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" -> '84b95fb1219c04cd5fd1f53d294840aa'(2) Acct-Unique-Session-Id := "84b95fb1219c04cd5fd1f53d294840aa"(2) } # update request = noop(2) } # else else = noop(2) } # acct_unique acct_unique = noop(2) suffix : No '@' in User-Name = "test", looking up realm NULL(2) suffix : No such realm "NULL"(2) [suffix] = noop(2) [files] = noop(2) } # preacct = ok(2) # Executing section accounting from file /etc/raddb/sites-enabled/default(2) accounting {(2) detail : expand: "/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/var/log/radius/radacct/192.168.1.109/detail-20140926'(2) detail : /var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d expands to /var/log/radius/radacct/192.168.1.109/detail-20140926(2) detail : expand: "%t" -> 'Fri Sep 26 06:51:23 2014'(2) [detail] = ok(2) [unix] = okrlm_sql (sql): Reserved connection (4)(2) sqlippool : expand: "%{User-Name}" -> 'test'(2) sqlippool : SQL-User-Name set to 'test'(2) sqlippool : expand: "START TRANSACTION" -> 'START TRANSACTION'rlm_sql (sql): Executing query: 'START TRANSACTION'(2) sqlippool : expand: "UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '%{Nas-IP-Address}' AND pool_key = '%{NAS-Port}' AND username = '%{User-Name}' AND callingstationid = '%{Calling-Station-Id}' AND framedipaddress = '%{Framed-IP-Address}'" -> 'UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '127.0.0.1' AND pool_key = '0' AND username = 'test' AND callingstationid = '192.168.1.70' AND framedipaddress = '192.168.1.1''rlm_sql (sql): Executing query: 'UPDATE radippool SET nasipaddress = '', pool_key = 0, callingstationid = '', username = '', expiry_time = NULL WHERE nasipaddress = '127.0.0.1' AND pool_key = '0' AND username = 'test' AND callingstationid = '192.168.1.70' AND framedipaddress = '192.168.1.1''(2) sqlippool : expand: "COMMIT" -> 'COMMIT'rlm_sql (sql): Executing query: 'COMMIT'(2) sqlippool : expand: "Released IP %{Framed-IP-Address} (did %{Called-Station-Id} cli %{Calling-Station-Id} user %{User-Name})" -> 'Released IP 192.168.1.1 (did cli 192.168.1.70 user test)'rlm_sql (sql): Released connection (4)(2) [sqlippool] = ok(2) sql : expand: "%{tolower:type.%{Acct-Status-Type}.query}" -> 'type.stop.query'(2) sql : Using query template 'query'rlm_sql (sql): Reserved connection (4)(2) sql : expand: "%{User-Name}" -> 'test'(2) sql : SQL-User-Name set to 'test'(2) sql : expand: "UPDATE radacct SET acctstoptime = FROM_UNIXTIME(%{integer:Event-Timestamp}), 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}', connectinfo_stop = '%{Connect-Info}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" -> 'UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1411710683), acctsessiontime = '4', acctinputoctets = '0' << 32 | '2804', acctoutputoctets = '0' << 32 | '0', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid = '5425A63435B300' AND username = 'test' AND nasipaddress = '127.0.0.1''rlm_sql (sql): Executing query: 'UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1411710683), acctsessiontime = '4', acctinputoctets = '0' << 32 | '2804', acctoutputoctets = '0' << 32 | '0', acctterminatecause = 'User-Request', connectinfo_stop = '' WHERE acctsessionid = '5425A63435B300' AND username = 'test' AND nasipaddress = '127.0.0.1''rlm_sql (sql): Released connection (4)(2) [sql] = ok(2) [exec] = noop(2) attr_filter.accounting_response : expand: "%{User-Name}" -> 'test'(2) attr_filter.accounting_response : Matched entry DEFAULT at line 12(2) [attr_filter.accounting_response] = updated(2) } # accounting = updatedSending Accounting-Response of id 55 from 192.168.1.67 port 1813 to 192.168.1.109 port 59458(2) Finished request 2.Waking up in 0.3 seconds.(2) Cleaning up request packet ID 55 with timestamp +17Ready to process requests.