MariaDB [radius]> select * from radcheck;
+----+----------+--------------------+----+-------+
| id | username | attribute | op | value |
+----+----------+--------------------+----+-------+
| 1 | test | Cleartext-Password | := | pass |
+----+----------+--------------------+----+-------+
4 rows in set (0.00 sec)
MariaDB [radius]> select * from radusergroup;
+----------+-----------+----------+
| username | groupname | priority |
+----------+-----------+----------+
| test | 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)
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.