mssql-freetds interim-update problem

Ali Arslan e066377 at yahoo.com
Sun Mar 8 15:01:13 CET 2020 

Hello all,

I am using freeradius 3.0.16 on 2 ubuntu 18.04 servers. One is using mysql the other mssql server as backends. The radius server using mysql is working properly but the one that is using mssql with freetds inserts new rows in radacct table for interim updates. The debug output parts for interim update are as follows:

radius server 1 (using mysql):
---------------------------------------

(5) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(5) sql:    --> type.interim-update.query
(5) sql: Using query template 'query'
rlm_sql (sql): Reserved connection (7)
(5) sql: EXPAND %{User-Name}
(5) sql:    --> b48 at selcuklu
(5) sql: SQL-User-Name set to 'b48 at selcuklu'
(5) sql: EXPAND UPDATE radacct SET acctupdatetime  = (@acctupdatetime_old:=acctupdatetime), acctupdatetime  = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval    = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), acctstoptime = NULL, framedipaddress = '%{Framed-IP-Address}', ipinternalport = %{%{IP-Port-Int-Port}:-NULL}, internalipaddress = %{%{IP-Port-Int-IPv4-Addr}:-NULL}, ipexternalport = %{%{IP-Port-Ext-Port}:-NULL}, externalipaddress = %{%{IP-Port-Ext-IPv4-Addr}:-NULL}, acctsessiontime = %{%{Acct-Session-Time}:-NULL}, acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'
(5) sql:    --> UPDATE radacct SET acctupdatetime  = (@acctupdatetime_old:=acctupdatetime), acctupdatetime  = FROM_UNIXTIME(1583672931), acctinterval    = 1583672931 - UNIX_TIMESTAMP(@acctupdatetime_old), acctstoptime = NULL, framedipaddress = '192.168.12.251', ipinternalport = NULL, internalipaddress = NULL, ipexternalport = NULL, externalipaddress = NULL, acctsessiontime = 198600, acctinputoctets = '0' << 32 | '214152128', acctoutputoctets = '0' << 32 | '418687860' WHERE AcctUniqueId = '5d7426d2c93ad7b53a9ff6801d14f201'
(5) sql: Executing query: UPDATE radacct SET acctupdatetime  = (@acctupdatetime_old:=acctupdatetime), acctupdatetime  = FROM_UNIXTIME(1583672931), acctinterval    = 1583672931 - UNIX_TIMESTAMP(@acctupdatetime_old), acctstoptime = NULL, framedipaddress = '192.168.12.251', ipinternalport = NULL, internalipaddress = NULL, ipexternalport = NULL, externalipaddress = NULL, acctsessiontime = 198600, acctinputoctets = '0' << 32 | '214152128', acctoutputoctets = '0' << 32 | '418687860' WHERE AcctUniqueId = '5d7426d2c93ad7b53a9ff6801d14f201'
rlm_sql_mysql: Rows matched: 1  Changed: 1  Warnings: 1
(5) sql: SQL query returned: success
(5) sql: 1 record(s) updated
rlm_sql (sql): Released connection (7)
Need 1 more connections to reach 10 spares
----------------------------------------------------------------------------------------------------------------------------------------


radius server 2 (using mssql):
----------------------------------------

(3) sql: EXPAND %{tolower:type.%{Acct-Status-Type}.query}
(3) sql:    --> type.interim-update.query
(3) sql: Using query template 'query'
rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 120 seconds
rlm_sql_freetds: socket destructor called, closing socket
rlm_sql (sql): Reserved connection (1)
(3) sql: EXPAND %{User-Name}
(3) sql:    --> test at orbit
(3) sql: SQL-User-Name set to 'test at orbit'
(3) sql: EXPAND UPDATE radacct SET AcctUpdateTime  = '%S', AcctStopTime = NULL, FramedIPAddress = '%{Framed-IP-Address}', FramedIPv6Address = '%{Framed-IPv6-Address}', FramedIPv6Prefix = '%{Framed-IPv6-Prefix}', FramedInterfaceId = '%{Framed-Interface-Id}', DelegatedIPv6Prefix = '%{Delegated-IPv6-Prefix}', AcctSessionTime = %{%{Acct-Session-Time}:-NULL}, AcctInputOctets = convert(bigint, '%{%{Acct-Input-Gigawords}:-0}' * POWER(2.0, 32)) | '%{%{Acct-Input-Octets}:-0}', AcctOutputOctets = convert(bigint, '%{%{Acct-Output-Gigawords}:-0}' * POWER(2.0, 32)) | '%{%{Acct-Output-Octets}:-0}' WHERE AcctUniqueId = '%{Acct-Unique-Session-Id}'
(3) sql:    --> UPDATE radacct SET AcctUpdateTime  = '2020-03-08 16:07:09', AcctStopTime = NULL, FramedIPAddress = '192.168.10.255', FramedIPv6Address = '', FramedIPv6Prefix = '', FramedInterfaceId = '', DelegatedIPv6Prefix = '', AcctSessionTime = 600, AcctInputOctets = convert(bigint, '0' * POWER(2.0, 32)) | '407068', AcctOutputOctets = convert(bigint, '0' * POWER(2.0, 32)) | '687067' WHERE AcctUniqueId = '72029846d9c951718be3d5e42432e88f'
(3) sql: Executing query: UPDATE radacct SET AcctUpdateTime  = '2020-03-08 16:07:09', AcctStopTime = NULL, FramedIPAddress = '192.168.10.255', FramedIPv6Address = '', FramedIPv6Prefix = '', FramedInterfaceId = '', DelegatedIPv6Prefix = '', AcctSessionTime = 600, AcctInputOctets = convert(bigint, '0' * POWER(2.0, 32)) | '407068', AcctOutputOctets = convert(bigint, '0' * POWER(2.0, 32)) | '687067' WHERE AcctUniqueId = '72029846d9c951718be3d5e42432e88f'
(3) sql: SQL query returned: success
(3) sql: -1 record(s) updated

******************** here it tries next query and inserts new row  **********************
(3) sql: Trying next query...
(3) sql: EXPAND INSERT INTO radacct (AcctSessionId,             AcctUniqueId,           UserName, Realm,                                                               NASIPAddress,            NASPortId, NASPortType,         AcctStartTime,          AcctUpdateTime, AcctStopTime,          AcctSessionTime,                                AcctAuthentic, ConnectInfoStart, ConnectInfoStop,        AcctInputOctets, AcctOutputOctets,      CalledStationId,       CallingStationId, AcctTerminateCause,           ServiceType,             FramedProtocol, FramedIPAddress,        FramedIPv6Address,      FramedIPv6Prefix, FramedInterfaceId,                                           DelegatedIPv6Prefix) VALUES ('%{Acct-Session-Id}', '%{Acct-Unique-Session-Id}', '%{SQL-User-Name}', '%{Realm}', '%{NAS-IP-Address}', '%{%{NAS-Port-Id}:-%{NAS-Port}}', '%{NAS-Port-Type}', DATEADD(second, -1 * (%{%{Acct-Session-Time}:-0}),'%S'), '%S', NULL, %{%{Acct-Session-Time}:-NULL}, '%{Acct-Authentic}', '%{Connect-Info}', '', convert(bigint, '%{%{Acct-Input-Gigawords}:-0}' * POWER(2.0, 32)) | '%{%{Acct-Input-Octets}:-0}', convert(bigint, '%{%{Acct-Output-Gigawords}:-0}' * POWER(2.0, 32)) | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '', '%{Service-Type}', '%{Framed-Protocol}', '%{Framed-IP-Address}', '%{Framed-IPv6-Address}', '%{Framed-IPv6-Prefix}', '%{Framed-Interface-Id}', '%{Delegated-IPv6-Prefix}')
(3) sql:    --> INSERT INTO radacct (AcctSessionId,             AcctUniqueId,           UserName, Realm,                                                               NASIPAddress,            NASPortId, NASPortType,         AcctStartTime,          AcctUpdateTime, AcctStopTime,          AcctSessionTime,                                AcctAuthentic, ConnectInfoStart, ConnectInfoStop,        AcctInputOctets, AcctOutputOctets,      CalledStationId,       CallingStationId, AcctTerminateCause,           ServiceType,             FramedProtocol, FramedIPAddress,        FramedIPv6Address,      FramedIPv6Prefix, FramedInterfaceId,                                           DelegatedIPv6Prefix) VALUES ('81a00005', '72029846d9c951718be3d5e42432e88f', 'test at orbit', '', '192.168.1.200', 'LAN', 'Ethernet', DATEADD(second, -1 * (600),'2020-03-08 16:07:09'), '2020-03-08 16:07:09', NULL, 600, 'RADIUS', '', '', convert(bigint, '0' * POWER(2.0, 32)) | '407068', convert(bigint, '0' * POWER(2.0, 32)) | '687067', 'PPPoE', 'D8:C4:97:15:C1:F8', '', 'Framed-User', 'PPP', '192.168.10.255', '', '', '', '')
(3) sql: Executing query: INSERT INTO radacct (AcctSessionId,           AcctUniqueId,           UserName, Realm,
NASIPAddress,           NASPortId, NASPortType,         AcctStartTime,          AcctUpdateTime, AcctStopTime,          AcctSessionTime,                                AcctAuthentic, ConnectInfoStart, ConnectInfoStop,        AcctInputOctets, AcctOutputOctets,      CalledStationId,       CallingStationId, AcctTerminateCause,           ServiceType,             FramedProtocol, FramedIPAddress,        FramedIPv6Address,      FramedIPv6Prefix, FramedInterfaceId,                                           DelegatedIPv6Prefix) VALUES ('81a00005', '72029846d9c951718be3d5e42432e88f', 'test at orbit', '', '192.168.1.200', 'LAN', 'Ethernet', DATEADD(second, -1 * (600),'2020-03-08 16:07:09'), '2020-03-08 16:07:09', NULL, 600, 'RADIUS', '', '', convert(bigint, '0' * POWER(2.0, 32)) | '407068', convert(bigint, '0' * POWER(2.0, 32)) | '687067', 'PPPoE', 'D8:C4:97:15:C1:F8', '', 'Framed-User', 'PPP', '192.168.10.255', '', '', '', '')
(3) sql: SQL query returned: success
(3) sql: -1 record(s) updated
(3) sql: No additional queries configured
rlm_sql (sql): Released connection (1)


The attached file shows mssql queries.conf file accounting section.


sql configuration for mssql is as follows:

sql {
    driver = "rlm_sql_freetds"
    dialect = "mssql"
    server = "SQLServer"  # configured in  /etc/freetds/freetds.conf file
    port = 1433
    login = *****
    password = ******
    radius_db = "database_name"

    *** table mappings ***
    
     pool {
        """" default ****
    }

    delete_stale_sessions = yes
    read_clients = yes
    client_table = "nas"

    ...
}


Why it inserts a new row in interim-update after updating record?

Thanks.
-------------- next part --------------
An embedded and charset-unspecified text was scrubbed...
Name: mssql.queries.txt
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20200308/21b33d36/attachment.txt>

More information about the Freeradius-Users mailing list