no wait exec scripts end up as defunct zombie process
Sajeewa Warnakulasuriya
sajeewaw at ispone.com.au
Wed Feb 10 03:43:27 CET 2010
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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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 at 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
>
More information about the Freeradius-Users
mailing list