Reg radgroupreply table attribute is not sending to mikrotik in freeradius 3.0.8
J@g@dee5h
djfueese at gmail.com
Thu Jul 2 07:59:50 CEST 2015
Hi,
I am using the freeradius 3.0.8, mysql and mikrotik. While access request
from mikrotik, freeradius is not sending the radgroupreply table
attributes. I have tested with radtest command also.
Here is the radtest output and debug log.
--------------
radtest randeeps xxx 192.168.1.182 0 xxxx
Sending Access-Request of id 204 to 192.168.1.182 port 1812
User-Name = "randeeps"
User-Password = "xxx"
NAS-IP-Address = 192.168.1.182
NAS-Port = 0
Message-Authenticator = 0x00000000000000000000000000000000
rad_recv: Access-Accept packet from host 192.168.1.182 port 1812, id=204,
length=20
--------------
----------------
(0) Received Access-Request Id 37 from 192.168.1.1:58640 to
192.168.1.182:1812 length 195
(0) NAS-Port-Type = Ethernet
(0) Calling-Station-Id = '38:63:BB:AA:23:C8'
(0) Called-Station-Id = 'server1'
(0) NAS-Port-Id = 'LAN'
(0) User-Name = 'randeeps'
(0) NAS-Port = 2161115148
(0) Acct-Session-Id = '80d0000c'
(0) Framed-IP-Address = 192.168.1.178
(0) Mikrotik-Host-IP = 192.168.1.178
(0) CHAP-Challenge = 0x204416f8f4dffa7c6e61d242008309e8
(0) CHAP-Password = 0x16c3e52824bccf28b038ada822e4700776
(0) Service-Type = Login-User
(0) WISPr-Logoff-URL = 'http://192.168.1.1/logout'
(0) NAS-Identifier = 'MikroTik'
(0) NAS-IP-Address = 192.168.1.1
(0) # Executing section authorize from file
/usr/local/etc/raddb/sites-enabled/default
(0) authorize {
(0) [preprocess] = ok
(0) auth_log: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
(0) auth_log: --> /usr/local/var/log/radius/radacct/
192.168.1.1/auth-detail-20150702
(0) auth_log:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/auth-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/
192.168.1.1/auth-detail-20150702
(0) auth_log: EXPAND %t
(0) auth_log: --> Thu Jul 2 01:53:01 2015
(0) [auth_log] = ok
(0) chap: &control:Auth-Type := CHAP
(0) [chap] = ok
(0) [mschap] = noop
(0) suffix: Checking for suffix after "@"
(0) suffix: No '@' in User-Name = "randeeps", 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] = noop
(0) sql: EXPAND %{User-Name}
(0) sql: --> randeeps
(0) sql: SQL-User-Name set to 'randeeps'
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
(0) sql: --> SELECT id, username, attribute, value, op FROM radcheck
WHERE username = 'randeeps' ORDER BY id
(0) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radcheck WHERE username = 'randeeps' ORDER BY id
(0) sql: User found in radcheck table
(0) sql: Conditional check items matched, merging assignment check items
(0) sql: Cleartext-Password := 'randeeps'
(0) sql: EXPAND SELECT id, username, attribute, value, op FROM radreply
WHERE username = '%{SQL-User-Name}' ORDER BY id
(0) sql: --> SELECT id, username, attribute, value, op FROM radreply
WHERE username = 'randeeps' ORDER BY id
(0) sql: Executing select query: SELECT id, username, attribute, value, op
FROM radreply WHERE username = 'randeeps' ORDER BY id
(0) sql: EXPAND SELECT groupname FROM radusergroup WHERE username =
'%{SQL-User-Name}' ORDER BY priority
(0) sql: --> SELECT groupname FROM radusergroup WHERE username =
'randeeps' ORDER BY priority
(0) sql: Executing select query: SELECT groupname FROM radusergroup WHERE
username = 'randeeps' ORDER BY priority
(0) sql: User found in the group table
(0) sql: EXPAND SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = '%{Sql-Group}' ORDER BY id
(0) sql: --> SELECT id, groupname, attribute, Value, op FROM
radgroupcheck WHERE groupname = 'starter' ORDER BY id
(0) sql: Executing select query: SELECT id, groupname, attribute, Value, op
FROM radgroupcheck WHERE groupname = 'starter' ORDER BY id
(0) sql: Group "starter": Conditional check items matched
(0) sql: Group "starter": Merging assignment check items
(0) sql: Max-Data := 2147483648
(0) sql: Mikrotik-Rate-Limit := '512k/512k'
(0) sql: EXPAND SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = '%{Sql-Group}' ORDER BY id
(0) sql: --> SELECT id, groupname, attribute, value, op FROM
radgroupreply WHERE groupname = 'starter' ORDER BY id
(0) sql: Executing select query: SELECT id, groupname, attribute, value, op
FROM radgroupreply WHERE groupname = 'starter' ORDER BY id
(0) sql: Group "starter": Merging reply items
(0) sql: Framed-Protocol == PPP
(0) sql: Framed-MTU == 1500
(0) sql: Framed-Routing == Broadcast-Listen
(0) sql: Framed-Compression == Van-Jacobson-TCP-IP
(0) sql: Service-Type == Framed-User
(0) sql: Idle-Timeout == 300
(0) sql: Acct-Interim-Interval == 60
(0) sql: Mikrotik-Rate-Limit == '4096k/4096k'
rlm_sql (sql): Released connection (4)
(0) [sql] = ok
(0) [expiration] = noop
(0) [logintime] = noop
(0) pap: WARNING: Auth-Type already set. Not setting to PAP
(0) [pap] = noop
(0) } # authorize = ok
(0) Found Auth-Type = CHAP
(0) # Executing group from file /usr/local/etc/raddb/sites-enabled/default
(0) Auth-Type CHAP {
(0) chap: Comparing with "known good" Cleartext-Password
(0) chap: CHAP user "randeeps" authenticated successfully
(0) [chap] = ok
(0) } # Auth-Type CHAP = ok
(0) # Executing section post-auth from file
/usr/local/etc/raddb/sites-enabled/default
(0) post-auth {
(0) update {
(0) No attributes updated
(0) } # update = noop
(0) reply_log: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
(0) reply_log: --> /usr/local/var/log/radius/radacct/
192.168.1.1/reply-detail-20150702
(0) reply_log:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/reply-detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/
192.168.1.1/reply-detail-20150702
(0) reply_log: EXPAND %t
(0) reply_log: --> Thu Jul 2 01:53:01 2015
(0) [reply_log] = ok
(0) sql: EXPAND .query
(0) sql: --> .query
(0) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (4)
(0) sql: EXPAND %{User-Name}
(0) sql: --> randeeps
(0) sql: SQL-User-Name set to 'randeeps'
(0) sql: EXPAND INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES ( '%{SQL-User-Name}', '%{%{User-Password}:-%{Chap-Password}}',
'%{reply:Packet-Type}', '%S')
(0) sql: --> INSERT INTO radpostauth (username, pass, reply, authdate)
VALUES ( 'randeeps', '0x16c3e52824bccf28b038ada822e4700776',
'Access-Accept', '2015-07-02 01:53:01')
(0) sql: Executing query: INSERT INTO radpostauth (username, pass, reply,
authdate) VALUES ( 'randeeps', '0x16c3e52824bccf28b038ada822e4700776',
'Access-Accept', '2015-07-02 01:53:01')
(0) sql: SQL query returned: success
(0) sql: 1 record(s) updated
rlm_sql (sql): Released connection (4)
(0) [sql] = ok
(0) [exec] = noop
(0) policy remove_reply_message_if_eap {
(0) if (&reply:EAP-Message && &reply:Reply-Message) {
(0) if (&reply:EAP-Message && &reply:Reply-Message) -> FALSE
(0) else {
(0) [noop] = noop
(0) } # else = noop
(0) } # policy remove_reply_message_if_eap = noop
(0) } # post-auth = ok
(0) Sent Access-Accept Id 37 from 192.168.1.182:1812 to 192.168.1.1:58640
length 0
(0) Finished request
Waking up in 4.9 seconds.
(1) Received Accounting-Request Id 38 from 192.168.1.1:55815 to
192.168.1.182:1813 length 137
(1) Acct-Status-Type = Start
(1) NAS-Port-Type = Ethernet
(1) Calling-Station-Id = '38:63:BB:AA:23:C8'
(1) Called-Station-Id = 'server1'
(1) NAS-Port-Id = 'LAN'
(1) User-Name = 'randeeps'
(1) NAS-Port = 2161115148
(1) Acct-Session-Id = '80d0000c'
(1) Framed-IP-Address = 192.168.1.178
(1) Mikrotik-Host-IP = 192.168.1.178
(1) Event-Timestamp = 'Jan 1 1970 21:37:55 EST'
(1) NAS-Identifier = 'MikroTik'
(1) Acct-Delay-Time = 0
(1) NAS-IP-Address = 192.168.1.1
(1) # Executing section preacct from file
/usr/local/etc/raddb/sites-enabled/default
(1) preacct {
(1) [preprocess] = ok
(1) update request {
(1) EXPAND %{expr: %l - %{%{Acct-Session-Time}:-0} -
%{%{Acct-Delay-Time}:-0}}
(1) --> 1435816381
(1) FreeRADIUS-Acct-Session-Start-Time = Jul 2 2015 01:53:01 EDT
(1) } # update request = noop
(1) policy acct_unique {
(1) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) {
(1) EXPAND %{string:Class}
(1) -->
(1) if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE
(1) else {
(1) update request {
(1) EXPAND
%{md5:%{User-Name},%{Acct-Session-ID},%{%{NAS-IPv6-Address}:-%{NAS-IP-Address}},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}
(1) --> ea4d3903abb8c9b3982209738a5c2915
(1) &Acct-Unique-Session-Id := ea4d3903abb8c9b3982209738a5c2915
(1) } # update request = noop
(1) } # else = noop
(1) } # policy acct_unique = noop
(1) suffix: Checking for suffix after "@"
(1) suffix: No '@' in User-Name = "randeeps", 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
/usr/local/etc/raddb/sites-enabled/default
(1) accounting {
(1) detail: EXPAND
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
(1) detail: --> /usr/local/var/log/radius/radacct/
192.168.1.1/detail-20150702
(1) detail:
/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d
expands to /usr/local/var/log/radius/radacct/192.168.1.1/detail-20150702
(1) detail: EXPAND %t
(1) detail: --> Thu Jul 2 01:53:01 2015
(1) [detail] = ok
(1) [unix] = ok
(1) radutmp: EXPAND /usr/local/var/log/radius/radutmp
(1) radutmp: --> /usr/local/var/log/radius/radutmp
(1) radutmp: EXPAND %{User-Name}
(1) radutmp: --> randeeps
(1) [radutmp] = ok
(1) sradutmp: EXPAND /usr/local/var/log/radius/sradutmp
(1) sradutmp: --> /usr/local/var/log/radius/sradutmp
(1) sradutmp: EXPAND %{User-Name}
(1) sradutmp: --> randeeps
(1) [sradutmp] = ok
(1) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(1) sql: --> type.start.query
(1) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (4)
(1) sql: EXPAND %{User-Name}
(1) sql: --> randeeps
(1) sql: SQL-User-Name set to 'randeeps'
(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}')
(1) sql: --> 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
('80d0000c', 'ea4d3903abb8c9b3982209738a5c2915', 'randeeps', '',
'192.168.1.1', '2161115148', 'Ethernet', FROM_UNIXTIME(95875),
FROM_UNIXTIME(95875), NULL, '0', '', '', '', '0', '0', 'server1',
'38:63:BB:AA:23:C8', '', '', '', '192.168.1.178')
(1) 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
('80d0000c', 'ea4d3903abb8c9b3982209738a5c2915', 'randeeps', '',
'192.168.1.1', '2161115148', 'Ethernet', FROM_UNIXTIME(95875),
FROM_UNIXTIME(95875), NULL, '0', '', '', '', '0', '0', 'server1',
'38:63:BB:AA:23:C8', '', '', '', '192.168.1.178')
(1) sql: SQL query returned: success
(1) sql: 1 record(s) updated
rlm_sql (sql): Released connection (4)
(1) [sql] = ok
(1) update control {
(1) EXPAND %{User-Name}
(1) --> randeeps
(1) SQL-User-Name set to 'randeeps'
rlm_sql (sql): Reserved connection (4)
(1) Executing select query: SELECT
(SUM(acctinputoctets)+SUM(acctoutputoctets)) AS Total FROM radacct where
(acctstarttime between DATE_FORMAT(NOW() ,'2015-07-01') AND NOW() AND
acctstoptime between DATE_FORMAT(NOW() ,'2015-07-01') AND NOW()) AND
radacct.username='randeeps'
(1) NULL value in first column of result
rlm_sql (sql): Released connection (4)
(1) EXPAND %{sql:SELECT (SUM(acctinputoctets)+SUM(acctoutputoctets))
AS Total FROM radacct where (acctstarttime between DATE_FORMAT(NOW()
,'%Y-%m-01') AND NOW() AND acctstoptime between DATE_FORMAT(NOW()
,'%Y-%m-01') AND NOW()) AND radacct.username='%{User-Name}'}
(1) -->
(1) Tmp-Integer-0 := 0
(1) EXPAND %{User-Name}
(1) --> randeeps
(1) SQL-User-Name set to 'randeeps'
rlm_sql (sql): Reserved connection (4)
(1) Executing select query: SELECT radgroupcheck.value FROM
radusergroup INNER JOIN radgroupcheck ON radusergroup.groupname =
radgroupcheck.groupname WHERE radusergroup.username='randeeps' AND
radgroupcheck.attribute='Max-Data'
rlm_sql (sql): Released connection (4)
(1) EXPAND %{sql: SELECT radgroupcheck.value FROM radusergroup INNER
JOIN radgroupcheck ON radusergroup.groupname = radgroupcheck.groupname
WHERE radusergroup.username='%{User-Name}' AND
radgroupcheck.attribute='Max-Data'}
(1) --> 32212254720
(1) Tmp-Integer-1 := 2147483648
(1) EXPAND %{User-Name}
(1) --> randeeps
(1) SQL-User-Name set to 'randeeps'
rlm_sql (sql): Reserved connection (4)
(1) Executing select query: SELECT radgroupcheck.value FROM
radusergroup INNER JOIN radgroupcheck ON radusergroup.groupname =
radgroupcheck.groupname WHERE radusergroup.username='randeeps' AND
radgroupcheck.attribute='Mikrotik-Rate-Limit'
rlm_sql (sql): Released connection (4)
(1) EXPAND %{sql: SELECT radgroupcheck.value FROM radusergroup INNER
JOIN radgroupcheck ON radusergroup.groupname = radgroupcheck.groupname
WHERE radusergroup.username='%{User-Name}' AND
radgroupcheck.attribute='Mikrotik-Rate-Limit'}
(1) --> 512k/512k
(1) Tmp-String-1 := 512k/512k
(1) } # update control = noop
(1) if ("%{control:Tmp-Integer-0}" > "%{control:Tmp-Integer-1}") {
(1) EXPAND %{control:Tmp-Integer-0}
(1) --> 0
(1) EXPAND %{control:Tmp-Integer-1}
(1) --> 2147483648
(1) if ("%{control:Tmp-Integer-0}" > "%{control:Tmp-Integer-1}") ->
FALSE
(1) [exec] = noop
(1) attr_filter.accounting_response: EXPAND %{User-Name}
(1) attr_filter.accounting_response: --> randeeps
(1) attr_filter.accounting_response: Matched entry DEFAULT at line 15
(1) [attr_filter.accounting_response] = updated
(1) } # accounting = updated
(1) Sent Accounting-Response Id 38 from 192.168.1.182:1813 to
192.168.1.1:55815 length 0
(1) Finished request
(1) <done>: Cleaning up request packet ID 38 with timestamp +5
Waking up in 4.9 seconds.
-------------
Please help me to resolve this issue.
Thanks.
More information about the Freeradius-Users
mailing list