Hi All, I have faced an issue with NAS IP Changes causes radius accouting insert instead of update, this has causes an issue with the reporting wenever the NAS IP changes, for example the usage of the users will be duplicate if you sum up the usage for 1 day for example. i have tested the FR3.0RC0 with the policy.d in place, below is the issue i encounter during the testing in lab.
From Debug Log: Radius accouting start - OK rad_recv: Accounting-Request packet from host 10.69.1.35 port 62260, id=11, length=39 User-Name = 'cskhoo' Acct-Status-Type = Start Acct-Session-Id = '900' (0) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (0) group preacct { (0) - entering group preacct {...} (0) [preprocess] = ok (0) policy acct_unique { (0) - entering policy acct_unique {...} (0) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (0) expand: "%{string:Class}" -> '' (0) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (0) else else { (0) - entering else else {...} (0) update request { (0) expand: "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" -> 'c2141489ad2dd37607b19fd75af8623f' (0) Acct-Unique-Session-Id := "c2141489ad2dd37607b19fd75af8623f" (0) } # update request = ok (0) - else else returns ok (0) - policy acct_unique returns ok (0) suffix : No '@' in User-Name = "cskhoo", looking up realm NULL (0) suffix : No such realm "NULL" (0) [suffix] = noop (0) [files] = noop (0) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (0) group accounting { (0) - entering group accounting {...} (0) detail : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/10.69.1.35/detail-20130815' (0) 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/10.69.1.35/detail-20130815 (0) detail : expand: "%t" -> 'Thu Aug 15 02:53:59 2013' (0) [detail] = ok (0) [unix] = noop (0) sql : expand: "%{tolower:type.%{Acct-Status-Type}.query}" -> 'type.start.query' (0) sql : Using query template 'query' rlm_sql (sql): Reserved connection (4) (0) sql : expand: "%{User-Name}" -> 'cskhoo' (0) sql : SQL-User-Name updated (0) 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 ('900', 'c2141489ad2dd37607b19fd75af8623f', 'cskhoo', '', '10.69.1.35', '', '', FROM_UNIXTIME(1376506439), FROM_UNIXTIME(1376506439), NULL, '0', '', '', '', '0', '0', '', '', '', '', '', '')' 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 ('900', 'c2141489ad2dd37607b19fd75af8623f', 'cskhoo', '', '10.69.1.35', '', '', FROM_UNIXTIME(1376506439), FROM_UNIXTIME(1376506439), NULL, '0', '', '', '', '0', '0', '', '', '', '', '', '')' 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) [exec] = noop (0) attr_filter.accounting_response : expand: "%{User-Name}" -> 'cskhoo' (0) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (0) [attr_filter.accounting_response] = updated Sending Accounting-Response of id 11 from 0.0.0.0 port 1813 to 10.69.1.35 port 62260 (0) Finished request 0. Waking up in 0.2 seconds. (0) Cleaning up request packet ID 11 with timestamp +10 Ready to process requests.
Radius Acct Update - OK rad_recv: Accounting-Request packet from host 10.69.1.35 port 62261, id=12, length=39 User-Name = 'cskhoo' Acct-Status-Type = Interim-Update Acct-Session-Id = '900' (1) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (1) group preacct { (1) - entering group preacct {...} (1) [preprocess] = ok (1) policy acct_unique { (1) - entering policy 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) - entering else else {...} (1) update request { (1) expand: "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" -> 'c2141489ad2dd37607b19fd75af8623f' (1) Acct-Unique-Session-Id := "c2141489ad2dd37607b19fd75af8623f" (1) } # update request = ok (1) - else else returns ok (1) - policy acct_unique returns ok (1) suffix : No '@' in User-Name = "cskhoo", looking up realm NULL (1) suffix : No such realm "NULL" (1) [suffix] = noop (1) [files] = noop (1) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (1) group accounting { (1) - entering group accounting {...} (1) detail : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/10.69.1.35/detail-20130815' (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/10.69.1.35/detail-20130815 (1) detail : expand: "%t" -> 'Thu Aug 15 02:54:31 2013' (1) [detail] = ok (1) [unix] = noop (1) sql : expand: "%{tolower:type.%{Acct-Status-Type}.query}" -> 'type.interim-update.query' (1) sql : Using query template 'query' rlm_sql (sql): Reserved connection (4) (1) sql : expand: "%{User-Name}" -> 'cskhoo' (1) sql : SQL-User-Name updated (1) sql : expand: "UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" -> 'UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(1376506471), acctinterval = 1376506471 - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '', acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '900' AND username = 'cskhoo' AND nasipaddress = '10.69.1.35'' rlm_sql (sql): Executing query: 'UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(1376506471), acctinterval = 1376506471 - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '', acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '900' AND username = 'cskhoo' AND nasipaddress = '10.69.1.35'' 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) [-sql] = ok (1) [exec] = noop (1) attr_filter.accounting_response : expand: "%{User-Name}" -> 'cskhoo' (1) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (1) [attr_filter.accounting_response] = updated Sending Accounting-Response of id 12 from 0.0.0.0 port 1813 to 10.69.1.35 port 62261 (1) Finished request 1. Waking up in 0.2 seconds. (1) Cleaning up request packet ID 12 with timestamp +42 Ready to process requests. Radius Update when NAS IP Changes - Error as below rad_recv: Accounting-Request packet from host 10.69.1.31 port 65146, id=13, length=39 User-Name = 'cskhoo' Acct-Status-Type = Interim-Update Acct-Session-Id = '900' (2) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (2) group preacct { (2) - entering group preacct {...} (2) [preprocess] = ok (2) policy acct_unique { (2) - entering policy 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) - entering else else {...} (2) update request { (2) expand: "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" -> '47fe864f0f34504bea1670f9b8e542e4' (2) Acct-Unique-Session-Id := "47fe864f0f34504bea1670f9b8e542e4" (2) } # update request = ok (2) - else else returns ok (2) - policy acct_unique returns ok (2) suffix : No '@' in User-Name = "cskhoo", looking up realm NULL (2) suffix : No such realm "NULL" (2) [suffix] = noop (2) [files] = noop (2) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (2) group accounting { (2) - entering group accounting {...} (2) detail : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/10.69.1.31/detail-20130815' (2) 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/10.69.1.31/detail-20130815 (2) detail : expand: "%t" -> 'Thu Aug 15 02:55:53 2013' (2) [detail] = ok (2) [unix] = noop (2) sql : expand: "%{tolower:type.%{Acct-Status-Type}.query}" -> 'type.interim-update.query' (2) sql : Using query template 'query' rlm_sql (sql): Reserved connection (4) (2) sql : expand: "%{User-Name}" -> 'cskhoo' (2) sql : SQL-User-Name updated (2) sql : expand: "UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(%{integer:Event-Timestamp}), acctinterval = %{integer:Event-Timestamp} - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '%{Framed-IP-Address}', acctsessiontime = '%{Acct-Session-Time}', acctinputoctets = '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', acctoutputoctets = '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}' WHERE acctsessionid = '%{Acct-Session-Id}' AND username = '%{SQL-User-Name}' AND nasipaddress = '%{NAS-IP-Address}'" -> 'UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(1376506553), acctinterval = 1376506553 - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '', acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '900' AND username = 'cskhoo' AND nasipaddress = '10.69.1.31'' rlm_sql (sql): Executing query: 'UPDATE radacct SET acctupdatetime = (@acctupdatetime_old:=acctupdatetime), acctupdatetime = FROM_UNIXTIME(1376506553), acctinterval = 1376506553 - UNIX_TIMESTAMP(@acctupdatetime_old), framedipaddress = '', acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0' WHERE acctsessionid = '900' AND username = 'cskhoo' AND nasipaddress = '10.69.1.31'' (2) sql : No records updated (2) sql : Trying next query... (2) 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} - %{%{Acct-Session-Time}:-0}), FROM_UNIXTIME(%{integer:Event-Timestamp}), NULL, '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-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 ('900', '47fe864f0f34504bea1670f9b8e542e4', 'cskhoo', '', '10.69.1.31', '', '', FROM_UNIXTIME(1376506553 - 0), FROM_UNIXTIME(1376506553), NULL, '', '', '', '0' << 32 | '0', '0' << 32 | '0', '', '', '', '', '')' 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 ('900', '47fe864f0f34504bea1670f9b8e542e4', 'cskhoo', '', '10.69.1.31', '', '', FROM_UNIXTIME(1376506553 - 0), FROM_UNIXTIME(1376506553), NULL, '', '', '', '0' << 32 | '0', '0' << 32 | '0', '', '', '', '', '')' rlm_sql_mysql: MYSQL check_error: 1136 received rlm_sql (sql): Database query error: Column count doesn't match value count at row 1 rlm_sql_mysql: MYSQL check_error: 1136 received rlm_sql_mysql: Cannot store result rlm_sql_mysql: MySQL error 'Column count doesn't match value count at row 1' (2) sql : No additional queries configured rlm_sql (sql): Released connection (4) rlm_sql (sql): Closing connection (3): Hit idle_timeout, was idle for 124 seconds rlm_sql (sql): You probably need to lower "min" rlm_sql_mysql: Socket destructor called, closing socket rlm_sql (sql): Closing connection (2): Hit idle_timeout, was idle for 124 seconds rlm_sql_mysql: Socket destructor called, closing socket (2) [-sql] = noop (2) [exec] = noop (2) attr_filter.accounting_response : expand: "%{User-Name}" -> 'cskhoo' (2) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (2) [attr_filter.accounting_response] = updated Sending Accounting-Response of id 13 from 0.0.0.0 port 1813 to 10.69.1.31 port 65146 (2) Finished request 2. Waking up in 0.3 seconds. (2) Cleaning up request packet ID 13 with timestamp +124 Ready to process requests. Radius Acct Stop after NAS IP Changes - another record with stop time was added into mysql DB, the previous record will not have stop time. rad_recv: Accounting-Request packet from host 10.69.1.31 port 53956, id=14, length=39 User-Name = 'cskhoo' Acct-Status-Type = Stop Acct-Session-Id = '900' (3) # Executing section preacct from file /usr/local/etc/raddb/sites-enabled/default (3) group preacct { (3) - entering group preacct {...} (3) [preprocess] = ok (3) policy acct_unique { (3) - entering policy acct_unique {...} (3) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) (3) expand: "%{string:Class}" -> '' (3) ? if ("%{string:Class}" =~ /ai:([0-9a-f]{32})/i) -> FALSE (3) else else { (3) - entering else else {...} (3) update request { (3) expand: "%{md5:%{User-Name},%{Acct-Session-ID},%{NAS-IP-Address},%{NAS-Identifier},%{NAS-Port-ID},%{NAS-Port}}" -> '47fe864f0f34504bea1670f9b8e542e4' (3) Acct-Unique-Session-Id := "47fe864f0f34504bea1670f9b8e542e4" (3) } # update request = ok (3) - else else returns ok (3) - policy acct_unique returns ok (3) suffix : No '@' in User-Name = "cskhoo", looking up realm NULL (3) suffix : No such realm "NULL" (3) [suffix] = noop (3) [files] = noop (3) # Executing section accounting from file /usr/local/etc/raddb/sites-enabled/default (3) group accounting { (3) - entering group accounting {...} (3) detail : expand: "/usr/local/var/log/radius/radacct/%{%{Packet-Src-IP-Address}:-%{Packet-Src-IPv6-Address}}/detail-%Y%m%d" -> '/usr/local/var/log/radius/radacct/10.69.1.31/detail-20130815' (3) 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/10.69.1.31/detail-20130815 (3) detail : expand: "%t" -> 'Thu Aug 15 02:56:37 2013' (3) [detail] = ok (3) [unix] = noop (3) sql : expand: "%{tolower:type.%{Acct-Status-Type}.query}" -> 'type.stop.query' (3) sql : Using query template 'query' rlm_sql (sql): Reserved connection (4) (3) sql : expand: "%{User-Name}" -> 'cskhoo' (3) sql : SQL-User-Name updated (3) 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(1376506597), acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0', acctterminatecause = '', connectinfo_stop = '' WHERE acctsessionid = '900' AND username = 'cskhoo' AND nasipaddress = '10.69.1.31'' rlm_sql (sql): Executing query: 'UPDATE radacct SET acctstoptime = FROM_UNIXTIME(1376506597), acctsessiontime = '', acctinputoctets = '0' << 32 | '0', acctoutputoctets = '0' << 32 | '0', acctterminatecause = '', connectinfo_stop = '' WHERE acctsessionid = '900' AND username = 'cskhoo' AND nasipaddress = '10.69.1.31'' (3) sql : No records updated (3) sql : Trying next query... (3) 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} - %{%{Acct-Session-Time}:-0}), FROM_UNIXTIME(%{integer:Event-Timestamp}), FROM_UNIXTIME(%{integer:Event-Timestamp}), '%{Acct-Session-Time}', '%{Acct-Authentic}', '', '%{Connect-Info}', '%{%{Acct-Input-Gigawords}:-0}' << 32 | '%{%{Acct-Input-Octets}:-0}', '%{%{Acct-Output-Gigawords}:-0}' << 32 | '%{%{Acct-Output-Octets}:-0}', '%{Called-Station-Id}', '%{Calling-Station-Id}', '%{Acct-Terminate-Cause}', '%{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 ('900', '47fe864f0f34504bea1670f9b8e542e4', 'cskhoo', '', '10.69.1.31', '', '', FROM_UNIXTIME(1376506597 - 0), FROM_UNIXTIME(1376506597), FROM_UNIXTIME(1376506597), '', '', '', '', '0' << 32 | '0', '0' << 32 | '0', '', '', '', '', '', '')' 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 ('900', '47fe864f0f34504bea1670f9b8e542e4', 'cskhoo', '', '10.69.1.31', '', '', FROM_UNIXTIME(1376506597 - 0), FROM_UNIXTIME(1376506597), FROM_UNIXTIME(1376506597), '', '', '', '', '0' << 32 | '0', '0' << 32 | '0', '', '', '', '', '', '')' rlm_sql (sql): Released connection (4) rlm_sql (sql): Opening additional connection (5) rlm_sql_mysql: Starting connect to MySQL server (3) [-sql] = ok (3) [exec] = noop (3) attr_filter.accounting_response : expand: "%{User-Name}" -> 'cskhoo' (3) attr_filter.accounting_response : Matched entry DEFAULT at line 12 (3) [attr_filter.accounting_response] = updated Sending Accounting-Response of id 14 from 0.0.0.0 port 1813 to 10.69.1.31 port 53956 (3) Finished request 3. Waking up in 0.2 seconds. (3) Cleaning up request packet ID 14 with timestamp +168 Ready to process requests. Regards, Ultaman