Is there anything else I can do check why the no wait exec scripts end up as zombies? I have run the scripts manually and no errors are produced, so I can confirm it is not the script that is causing the issue. Here is a debug output. The zombies are created under debug mode as well. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=21, length=272 Acct-Session-Id = "0000E0B9" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E0A0" Framed-IP-Address = 112.213.137.216 User-Name = "asrtest5@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7006 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4493 NAS-Port-Id = "Uniq-Sess-ID4493" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "5523DFCA" Event-Timestamp = "Feb 10 2010 13:39:41 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest5@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest5@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NUPLOAD',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 49 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 49 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest5@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0B9" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E0A0" Framed-IP-Address = 112.213.137.216 User-Name = "asrtest5@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7006 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4493 NAS-Port-Id = "Uniq-Sess-ID4493" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "5523DFCA" Event-Timestamp = "Feb 10 2010 13:39:41 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:41'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7006', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0B9' AND USERNAME = 'asrtest5@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP

= UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 48 rlm_sql (bb_acct_usage): Released sql socket id: 48 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 49 rlm_sql (bb_acct_online): Released sql socket id: 49 ++[bb_acct_online] returns ok Sending Accounting-Response of id 21 to 112.213.128.3 port 1646 Finished request 0. Cleaning up request 0 ID 21 with timestamp +0 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=22, length=271 Acct-Session-Id = "0000E0BA" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E09F" Framed-IP-Address = 112.213.137.211 User-Name = "asrtest6@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;536" Acct-Input-Packets = 0 Acct-Output-Packets = 11 Acct-Input-Octets = 0 Acct-Output-Octets = 536 Acct-Session-Time = 7007 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4096 NAS-Port-Id = "Uniq-Sess-ID4096" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "6D98C5AF" Event-Timestamp = "Feb 10 2010 13:39:42 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest6@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest6@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NWWW',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 47 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 47 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 1 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++- entering if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) {...} [bb_quota_update] expand: %{User-Name} -> asrtest6@isp1.net.au [bb_quota_update] expand: %{Cisco-Service-Info} -> NWWW [bb_quota_update] expand: %{Acct-Output-Octets} -> 536 [bb_quota_update] expand: %{%{Acct-Output-Octets}:-0} -> 536 [bb_quota_update] expand: %{Acct-Input-Octets} -> 0 [bb_quota_update] expand: %{%{Acct-Input-Octets}:-0} -> 0 [bb_quota_update] expand: %{Framed-IP-Address} -> 112.213.137.211 [bb_quota_update] expand: %{NAS-IP-Address} -> 112.213.128.3 [bb_quota_update] expand: %{Acct-Status-Type} -> Interim-Update [bb_quota_update] expand: %{Acct-Output-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Output-Gigawords}:-0} -> 0 [bb_quota_update] expand: %{Acct-Input-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Input-Gigawords}:-0} -> 0 +++[bb_quota_update] returns ok ++- if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) returns ok [proxy_bb_realms] expand: %u -> asrtest6@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0BA" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E09F" Framed-IP-Address = 112.213.137.211 User-Name = "asrtest6@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;536" Acct-Input-Packets = 0 Acct-Output-Packets = 11 Acct-Input-Octets = 0 Acct-Output-Octets = 536 Acct-Session-Time = 7007 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4096 NAS-Port-Id = "Uniq-Sess-ID4096" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "6D98C5AF" Event-Timestamp = "Feb 10 2010 13:39:42 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 536 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:42'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7007', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '536', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0BA' AND USERNAME = 'asrtest6@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STA rlm_sql (bb_acct_usage): Reserving sql socket id: 46 rlm_sql (bb_acct_usage): Released sql socket id: 46 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 48 rlm_sql (bb_acct_online): Released sql socket id: 48 ++[bb_acct_online] returns ok Sending Accounting-Response of id 22 to 112.213.128.3 port 1646 Finished request 1. Cleaning up request 1 ID 22 with timestamp +1 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=23, length=272 Acct-Session-Id = "0000E0AD" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E09D" Framed-IP-Address = 112.213.137.210 User-Name = "asrtest8@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;1052" Acct-Input-Packets = 0 Acct-Output-Packets = 13 Acct-Input-Octets = 0 Acct-Output-Octets = 1052 Acct-Session-Time = 7009 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 3289 NAS-Port-Id = "Uniq-Sess-ID3289" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "3E3A5625" Event-Timestamp = "Feb 10 2010 13:39:44 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest8@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest8@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NWWW',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 45 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 45 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 1 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++- entering if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) {...} [bb_quota_update] expand: %{User-Name} -> asrtest8@isp1.net.au [bb_quota_update] expand: %{Cisco-Service-Info} -> NWWW [bb_quota_update] expand: %{Acct-Output-Octets} -> 1052 [bb_quota_update] expand: %{%{Acct-Output-Octets}:-0} -> 1052 [bb_quota_update] expand: %{Acct-Input-Octets} -> 0 [bb_quota_update] expand: %{%{Acct-Input-Octets}:-0} -> 0 [bb_quota_update] expand: %{Framed-IP-Address} -> 112.213.137.210 [bb_quota_update] expand: %{NAS-IP-Address} -> 112.213.128.3 [bb_quota_update] expand: %{Acct-Status-Type} -> Interim-Update [bb_quota_update] expand: %{Acct-Output-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Output-Gigawords}:-0} -> 0 [bb_quota_update] expand: %{Acct-Input-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Input-Gigawords}:-0} -> 0 +++[bb_quota_update] returns ok ++- if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) returns ok [proxy_bb_realms] expand: %u -> asrtest8@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0AD" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E09D" Framed-IP-Address = 112.213.137.210 User-Name = "asrtest8@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;1052" Acct-Input-Packets = 0 Acct-Output-Packets = 13 Acct-Input-Octets = 0 Acct-Output-Octets = 1052 Acct-Session-Time = 7009 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 3289 NAS-Port-Id = "Uniq-Sess-ID3289" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "3E3A5625" Event-Timestamp = "Feb 10 2010 13:39:44 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 1052 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:44'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7009', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '1052', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0AD' AND USERNAME = 'asrtest8@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_ST rlm_sql (bb_acct_usage): Reserving sql socket id: 44 rlm_sql (bb_acct_usage): Released sql socket id: 44 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 47 rlm_sql (bb_acct_online): Released sql socket id: 47 ++[bb_acct_online] returns ok Sending Accounting-Response of id 23 to 112.213.128.3 port 1646 Finished request 2. Cleaning up request 2 ID 23 with timestamp +3 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=24, length=271 Acct-Session-Id = "0000E0B2" Framed-Protocol = PPP Cisco-Service-Info = "NLOCAL" Cisco-AVPair = "parent-session-id=0000E0A1" Framed-IP-Address = 112.213.137.215 User-Name = "asrtest4@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7002 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 3589 NAS-Port-Id = "Uniq-Sess-ID3589" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "D3792764" Event-Timestamp = "Feb 10 2010 13:39:37 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 8 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest4@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest4@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NLOCAL',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 43 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 43 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest4@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0B2" Framed-Protocol = PPP Cisco-Service-Info = "NLOCAL" Cisco-AVPair = "parent-session-id=0000E0A1" Framed-IP-Address = 112.213.137.215 User-Name = "asrtest4@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7002 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 3589 NAS-Port-Id = "Uniq-Sess-ID3589" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "D3792764" Event-Timestamp = "Feb 10 2010 13:39:37 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 8 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:46'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7002', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0B2' AND USERNAME = 'asrtest4@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 42 rlm_sql (bb_acct_usage): Released sql socket id: 42 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 46 rlm_sql (bb_acct_online): Released sql socket id: 46 ++[bb_acct_online] returns ok Sending Accounting-Response of id 24 to 112.213.128.3 port 1646 Finished request 3. Cleaning up request 3 ID 24 with timestamp +5 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=25, length=270 Acct-Session-Id = "0000E0AC" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E09E" Framed-IP-Address = 112.213.137.209 User-Name = "asrtest7@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;584" Acct-Input-Packets = 0 Acct-Output-Packets = 12 Acct-Input-Octets = 0 Acct-Output-Octets = 584 Acct-Session-Time = 7011 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 108 NAS-Port-Id = "Uniq-Sess-ID108" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "1422ADB4" Event-Timestamp = "Feb 10 2010 13:39:46 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest7@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest7@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NWWW',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 41 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 41 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 1 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++- entering if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) {...} [bb_quota_update] expand: %{User-Name} -> asrtest7@isp1.net.au [bb_quota_update] expand: %{Cisco-Service-Info} -> NWWW [bb_quota_update] expand: %{Acct-Output-Octets} -> 584 [bb_quota_update] expand: %{%{Acct-Output-Octets}:-0} -> 584 [bb_quota_update] expand: %{Acct-Input-Octets} -> 0 [bb_quota_update] expand: %{%{Acct-Input-Octets}:-0} -> 0 [bb_quota_update] expand: %{Framed-IP-Address} -> 112.213.137.209 [bb_quota_update] expand: %{NAS-IP-Address} -> 112.213.128.3 [bb_quota_update] expand: %{Acct-Status-Type} -> Interim-Update [bb_quota_update] expand: %{Acct-Output-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Output-Gigawords}:-0} -> 0 [bb_quota_update] expand: %{Acct-Input-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Input-Gigawords}:-0} -> 0 +++[bb_quota_update] returns ok ++- if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) returns ok [proxy_bb_realms] expand: %u -> asrtest7@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0AC" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E09E" Framed-IP-Address = 112.213.137.209 User-Name = "asrtest7@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;584" Acct-Input-Packets = 0 Acct-Output-Packets = 12 Acct-Input-Octets = 0 Acct-Output-Octets = 584 Acct-Session-Time = 7011 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 108 NAS-Port-Id = "Uniq-Sess-ID108" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "1422ADB4" Event-Timestamp = "Feb 10 2010 13:39:46 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 584 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:46'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7011', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '584', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0AC' AND USERNAME = 'asrtest7@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STA rlm_sql (bb_acct_usage): Reserving sql socket id: 40 rlm_sql (bb_acct_usage): Released sql socket id: 40 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 45 rlm_sql (bb_acct_online): Released sql socket id: 45 ++[bb_acct_online] returns ok Sending Accounting-Response of id 25 to 112.213.128.3 port 1646 Finished request 4. Cleaning up request 4 ID 25 with timestamp +5 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=26, length=273 Acct-Session-Id = "0000E06E" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E061" User-Name = "asrtest@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;15683" Acct-Input-Packets = 0 Acct-Output-Packets = 160 Acct-Input-Octets = 0 Acct-Output-Octets = 15683 Acct-Session-Time = 7952 Acct-Status-Type = Interim-Update Framed-IP-Address = 112.213.137.207 Connect-Info = "149760000" NAS-Port-Type = Virtual NAS-Port = 4063 NAS-Port-Id = "Uniq-Sess-ID4063" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "0C676AD7" Event-Timestamp = "Feb 10 2010 13:39:47 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NWWW',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 39 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 39 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 1 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> TRUE ++- entering if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) {...} [bb_quota_update] expand: %{User-Name} -> asrtest@isp1.net.au [bb_quota_update] expand: %{Cisco-Service-Info} -> NWWW [bb_quota_update] expand: %{Acct-Output-Octets} -> 15683 [bb_quota_update] expand: %{%{Acct-Output-Octets}:-0} -> 15683 [bb_quota_update] expand: %{Acct-Input-Octets} -> 0 [bb_quota_update] expand: %{%{Acct-Input-Octets}:-0} -> 0 [bb_quota_update] expand: %{Framed-IP-Address} -> 112.213.137.207 [bb_quota_update] expand: %{NAS-IP-Address} -> 112.213.128.3 [bb_quota_update] expand: %{Acct-Status-Type} -> Interim-Update [bb_quota_update] expand: %{Acct-Output-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Output-Gigawords}:-0} -> 0 [bb_quota_update] expand: %{Acct-Input-Gigawords} -> [bb_quota_update] ... expanding second conditional [bb_quota_update] expand: %{%{Acct-Input-Gigawords}:-0} -> 0 +++[bb_quota_update] returns ok ++- if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) returns ok [proxy_bb_realms] expand: %u -> asrtest@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E06E" Framed-Protocol = PPP Cisco-Service-Info = "NWWW" Cisco-AVPair = "parent-session-id=0000E061" User-Name = "asrtest@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;15683" Acct-Input-Packets = 0 Acct-Output-Packets = 160 Acct-Input-Octets = 0 Acct-Output-Octets = 15683 Acct-Session-Time = 7952 Acct-Status-Type = Interim-Update Framed-IP-Address = 112.213.137.207 Connect-Info = "149760000" NAS-Port-Type = Virtual NAS-Port = 4063 NAS-Port-Id = "Uniq-Sess-ID4063" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "0C676AD7" Event-Timestamp = "Feb 10 2010 13:39:47 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 15683 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:46'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7952', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '15683', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E06E' AND USERNAME = 'asrtest@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_ST rlm_sql (bb_acct_usage): Reserving sql socket id: 38 rlm_sql (bb_acct_usage): Released sql socket id: 38 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 44 rlm_sql (bb_acct_online): Released sql socket id: 44 ++[bb_acct_online] returns ok Sending Accounting-Response of id 26 to 112.213.128.3 port 1646 Finished request 5. Cleaning up request 5 ID 26 with timestamp +5 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=27, length=271 Acct-Session-Id = "0000E0B3" Framed-Protocol = PPP Cisco-Service-Info = "NLOCAL" Cisco-AVPair = "parent-session-id=0000E0A0" Framed-IP-Address = 112.213.137.216 User-Name = "asrtest5@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7003 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4493 NAS-Port-Id = "Uniq-Sess-ID4493" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "5523DFCA" Event-Timestamp = "Feb 10 2010 13:39:38 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 9 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest5@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest5@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NLOCAL',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 37 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 37 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest5@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0B3" Framed-Protocol = PPP Cisco-Service-Info = "NLOCAL" Cisco-AVPair = "parent-session-id=0000E0A0" Framed-IP-Address = 112.213.137.216 User-Name = "asrtest5@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7003 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4493 NAS-Port-Id = "Uniq-Sess-ID4493" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "5523DFCA" Event-Timestamp = "Feb 10 2010 13:39:38 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 9 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:47'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7003', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0B3' AND USERNAME = 'asrtest5@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 36 rlm_sql (bb_acct_usage): Released sql socket id: 36 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 43 rlm_sql (bb_acct_online): Released sql socket id: 43 ++[bb_acct_online] returns ok Sending Accounting-Response of id 27 to 112.213.128.3 port 1646 Finished request 6. Cleaning up request 6 ID 27 with timestamp +6 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=28, length=272 Acct-Session-Id = "0000E0A8" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E09C" Framed-IP-Address = 112.213.137.208 User-Name = "asrtest9@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7012 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 2731 NAS-Port-Id = "Uniq-Sess-ID2731" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "66BAAC8A" Event-Timestamp = "Feb 10 2010 13:39:47 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest9@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest9@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NUPLOAD',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 35 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 35 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest9@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0A8" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E09C" Framed-IP-Address = 112.213.137.208 User-Name = "asrtest9@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7012 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 2731 NAS-Port-Id = "Uniq-Sess-ID2731" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "66BAAC8A" Event-Timestamp = "Feb 10 2010 13:39:47 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:47'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7012', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0A8' AND USERNAME = 'asrtest9@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 34 rlm_sql (bb_acct_usage): Released sql socket id: 34 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 42 rlm_sql (bb_acct_online): Released sql socket id: 42 ++[bb_acct_online] returns ok Sending Accounting-Response of id 28 to 112.213.128.3 port 1646 Finished request 7. Cleaning up request 7 ID 28 with timestamp +6 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=29, length=272 Acct-Session-Id = "0000E0B5" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E0A3" Framed-IP-Address = 112.213.137.212 User-Name = "asrtest2@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7003 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4669 NAS-Port-Id = "Uniq-Sess-ID4669" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "3ABAF5E2" Event-Timestamp = "Feb 10 2010 13:39:38 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 9 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest2@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest2@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NUPLOAD',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 33 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 33 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest2@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0B5" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E0A3" Framed-IP-Address = 112.213.137.212 User-Name = "asrtest2@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7003 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4669 NAS-Port-Id = "Uniq-Sess-ID4669" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "3ABAF5E2" Event-Timestamp = "Feb 10 2010 13:39:38 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 9 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:47'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7003', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0B5' AND USERNAME = 'asrtest2@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 32 rlm_sql (bb_acct_usage): Released sql socket id: 32 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 41 rlm_sql (bb_acct_online): Released sql socket id: 41 ++[bb_acct_online] returns ok Sending Accounting-Response of id 29 to 112.213.128.3 port 1646 Finished request 8. Cleaning up request 8 ID 29 with timestamp +6 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=30, length=271 Acct-Session-Id = "0000E0A9" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E09E" Framed-IP-Address = 112.213.137.209 User-Name = "asrtest7@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7017 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 108 NAS-Port-Id = "Uniq-Sess-ID108" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "1422ADB4" Event-Timestamp = "Feb 10 2010 13:39:52 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest7@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest7@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NUPLOAD',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 31 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 31 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest7@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0A9" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E09E" Framed-IP-Address = 112.213.137.209 User-Name = "asrtest7@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7017 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 108 NAS-Port-Id = "Uniq-Sess-ID108" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "1422ADB4" Event-Timestamp = "Feb 10 2010 13:39:52 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:52'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7017', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0A9' AND USERNAME = 'asrtest7@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 30 rlm_sql (bb_acct_usage): Released sql socket id: 30 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 40 rlm_sql (bb_acct_online): Released sql socket id: 40 ++[bb_acct_online] returns ok Sending Accounting-Response of id 30 to 112.213.128.3 port 1646 Finished request 9. Cleaning up request 9 ID 30 with timestamp +11 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=31, length=271 Acct-Session-Id = "0000E0AE" Framed-Protocol = PPP Cisco-Service-Info = "NLOCAL" Cisco-AVPair = "parent-session-id=0000E09F" Framed-IP-Address = 112.213.137.211 User-Name = "asrtest6@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7017 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4096 NAS-Port-Id = "Uniq-Sess-ID4096" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "6D98C5AF" Event-Timestamp = "Feb 10 2010 13:39:52 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest6@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest6@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NLOCAL',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 29 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 29 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest6@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0AE" Framed-Protocol = PPP Cisco-Service-Info = "NLOCAL" Cisco-AVPair = "parent-session-id=0000E09F" Framed-IP-Address = 112.213.137.211 User-Name = "asrtest6@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7017 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 4096 NAS-Port-Id = "Uniq-Sess-ID4096" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "6D98C5AF" Event-Timestamp = "Feb 10 2010 13:39:52 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:52'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7017', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0AE' AND USERNAME = 'asrtest6@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 28 rlm_sql (bb_acct_usage): Released sql socket id: 28 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 39 rlm_sql (bb_acct_online): Released sql socket id: 39 ++[bb_acct_online] returns ok Sending Accounting-Response of id 31 to 112.213.128.3 port 1646 Finished request 10. Cleaning up request 10 ID 31 with timestamp +11 Going to the next request Ready to process requests. rad_recv: Accounting-Request packet from host 112.213.128.3 port 1646, id=32, length=272 Acct-Session-Id = "0000E0AA" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E09D" Framed-IP-Address = 112.213.137.210 User-Name = "asrtest8@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7018 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 3289 NAS-Port-Id = "Uniq-Sess-ID3289" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "3E3A5625" Event-Timestamp = "Feb 10 2010 13:39:53 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 +- entering group preacct {...} ++[preprocess] returns ok [suffix] Looking up realm "isp1.net.au" for User-Name = "asrtest8@isp1.net.au" [suffix] No such realm "isp1.net.au" ++[suffix] returns noop +- entering group accounting {...} ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) sql_xlat expand: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','') -> SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = 'asrtest8@isp1.net.au' AND SERVICENAME = REPLACE(SUBSTRING('NUPLOAD',2),'_PENAL','') rlm_sql (bb_acct_usage): Reserving sql socket id: 27 sql_xlat finished rlm_sql (bb_acct_usage): Released sql socket id: 27 expand: %{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')} -> 0 ? Evaluating ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE ++? if ("%{bb_acct_usage: SELECT COUNT(USERNAME) FROM SERVICEREMAINQUOTA WHERE USERNAME = '%{User-Name}' AND SERVICENAME = REPLACE(SUBSTRING('%{Cisco-Service-Info}',2),'_PENAL','')}" > 0) -> FALSE [proxy_bb_realms] expand: %u -> asrtest8@isp1.net.au [proxy_bb_realms] expand: %Z -> Acct-Session-Id = "0000E0AA" Framed-Protocol = PPP Cisco-Service-Info = "NUPLOAD" Cisco-AVPair = "parent-session-id=0000E09D" Framed-IP-Address = 112.213.137.210 User-Name = "asrtest8@isp1.net.au" Cisco-Control-Info = "I0;0" Cisco-Control-Info = "O0;0" Acct-Input-Packets = 0 Acct-Output-Packets = 0 Acct-Input-Octets = 0 Acct-Output-Octets = 0 Acct-Session-Time = 7018 Acct-Status-Type = Interim-Update Connect-Info = "10000000" NAS-Port-Type = Virtual NAS-Port = 3289 NAS-Port-Id = "Uniq-Sess-ID3289" Service-Type = Framed-User NAS-IP-Address = 112.213.128.3 X-Ascend-Session-Svr-Key = "3E3A5625" Event-Timestamp = "Feb 10 2010 13:39:53 EST" NAS-Identifier = "mel-lns01.ispone.net.au" Acct-Delay-Time = 0 ++[proxy_bb_realms] returns ok [bb_acct_usage] expand: %{Acct-Input-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Input-Octets} -> 0 [bb_acct_usage] expand: %{Acct-Output-Gigawords} -> [bb_acct_usage] ... expanding second conditional [bb_acct_usage] expand: %{Acct-Output-Octets} -> 0 [bb_acct_usage] expand: UPDATE SRVUSAGE_%Y%m SET TIME_STAMP = UNIX_TIMESTAMP('%S'), ACCTSTATUSTYPE = '3', 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}' WHERE ACCTSESSIONID = '%{Acct-Session-Id}' AND USERNAME = '%{User-Name}' AND NASIDENTIFIER = '%{NAS-IP-Address}' AND TIME_STAMP >= UNIX_TIMESTAMP('%Y-%m-%d 00:00:00') AND TIME_STAMP <= UNIX_TIMESTAMP('%Y-%m-%d 23:59:59') AND ACCTSTATUSTYPE = '3' -> UPDATE SRVUSAGE_201002 SET TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 13:39:53'), ACCTSTATUSTYPE = '3', ACCTSESSIONTIME = '7018', ACCTINPUTOCTETS = '0' << 32 | '0', ACCTOUTPUTOCTETS = '0' << 32 | '0', ACCTTERMINATECAUSE = '' WHERE ACCTSESSIONID = '0000E0AA' AND USERNAME = 'asrtest8@isp1.net.au' AND NASIDENTIFIER = '112.213.128.3' AND TIME_STAMP = UNIX_TIMESTAMP('2010-02-10 00:00:00') AND TIME_STAMP rlm_sql (bb_acct_usage): Reserving sql socket id: 26 rlm_sql (bb_acct_usage): Released sql socket id: 26 ++[bb_acct_usage] returns ok [bb_acct_online] expand: -> rlm_sql (bb_acct_online): Reserving sql socket id: 38 rlm_sql (bb_acct_online): Released sql socket id: 38 ++[bb_acct_online] returns ok Sending Accounting-Response of id 32 to 112.213.128.3 port 1646 Finished request 11. Cleaning up request 11 ID 32 with timestamp +12 Going to the next request Ready to process requests.

Regards, Sajeewa Warnakulasuriya Systems Development Manager ispONE is a wholesale ISP built to help internet access resellers and independent ISPs to compete in the Australian marketplace through ONE Brand, ONE Provider, ONE Solution. Level 14 520 Collins Street Melbourne 3000 VIC Phone: 1300 663 400 Fax: 1300 665 400 E-Mail: sajeewaw@ispone.com.au Web: http://www.ispone.com.au/ On Fri, 5 Feb 2010, Alan DeKok wrote:

Sajeewa Warnakulasuriya wrote:

...

Hi all,

I know the issue no wait exec scripts end up as defunct zombie process was covered previously and appears to have been resolved after version 1.1(?) but the issue still appears to happening in the latest freeradius.

Has anybody else noticed this?

Nope. It does a waitpid() every time it processes a packet.

The only situation where it takes a bit of time to do a waitpid() is if ALL of the child threads are blocked for many seconds.

Alan DeKok. - List info/subscribe/unsubscribe? See http://www.freeradius.org/list/users.html

Sajeewa Warnakulasuriya wrote:

Also I found the below snippet of code in exec.c ... When does freeradius close the child?

See src/main/threads.c Which OS are you using? Did you build FreeRADIUS yourself from source? Alan DeKok.

Sajeewa Warnakulasuriya wrote:

Also after further testing I found the issue is caused when running two no wait exec modules at the same time.

Hmm.... OK.

If you look at my previous posts the module names proxy_bb_realms and bb_quota_update

We solved it by removing the proxy bb realms module and using radrelay equivalent in Freeradius server.

That's probably a good solution. Alan DeKok.