FR3.0/Policy.D

ultaman khoo ultaman.khoo at gmail.com
Thu Aug 15 09:52:17 CEST 2013


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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeradius.org/pipermail/freeradius-users/attachments/20130815/e35690d0/attachment-0001.html>


More information about the Freeradius-Users mailing list