mssql-freetds interim-update problem
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@selcuklu (5) sql: SQL-User-Name set to 'b48@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@orbit (3) sql: SQL-User-Name set to 'test@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@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@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.
On Mar 8, 2020, at 10:01 AM, Ali Arslan via Freeradius-Users <freeradius-users@lists.freeradius.org> wrote:
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.
New rows are inserted when there is no pre-existing rows.
The debug output parts for interim update are as follows:
The debug output shows the SQL queries which are being executed.
(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@orbit (3) sql: SQL-User-Name set to 'test@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 **********************
Because no row was updated.
Why it inserts a new row in interim-update after updating record?
Because there's no pre-existing row. Read ALL of the debug output for one user. Does the server get an accounting "start" packet? If so, what's in it? What is inserted into the database? How does that information differ from an "update" packet? FreeRADIUS depends on the NAS to send the same information in each packet. If the NAS sends *different* information in the start and update packets... well, FreeRADIUS can't do much about that. Alan DeKok.
participants (2)
-
Alan DeKok -
Ali Arslan