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;

+----+----------+--------------------+----+-------+

+----+----------+--------------------+----+-------+

+----+----------+--------------------+----+-------+

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;

+----+-----------+--------------+----+-------+

+----+-----------+--------------+----+-------+

+----+-----------+--------------+----+-------+

2 rows in set (0.01 sec)

MariaDB [radius]> select * from radippool;

+----+-----------+-----------------+--------------+-----------------+------------------+---------------------+----------+----------+

+----+-----------+-----------------+--------------+-----------------+------------------+---------------------+----------+----------+

| 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 = ok

Sending 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] = ok

rlm_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 = updated

Sending 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 +14

Waking up in 2.7 seconds.

(0) Cleaning up request packet ID 53 with timestamp +12

Ready 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] = ok

rlm_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 = updated

Sending 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 +17

Ready to process requests.