Current-time: Dec 30 01:07:51 PST (UTC -0800) H323-conf-id: 33E90990 59AA1A98 56148713 6C504A74 SIP Call-ID: 91.121.122.64-1325236035.337 SIP Call-ID: 91.121.117.76-1325236034.68506 Requests: 10 REQUEST-- Dec 30 01:07:14: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.117.76' NAS-Port-Name = 'SIP/212.249.15.6-00ee6370' User-Name = '212.249.15.6' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.117.76-1325236034.68506' Password = 'cisco' h323-remote-address = '212.249.15.6' h323-ivr-out = 'PortaBilling_Routing:SIP' Dec 30 01:07:14: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.117.76-1325236034.68506/1 Dec 30 01:07:14: H323/SIP call, use h323-conf-id, but remember call-id Dec 30 01:07:14: Checking if this call comes through a VoIP from vendor connection Dec 30 01:07:14: No VoIP from vendor connections were found Dec 30 01:07:14: PrepareNexecute 'AccountAuth' Dec 30 01:07:14: SQL query 'AccountAuth' executed in 0.002627 seconds Dec 30 01:07:14: Found Account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] Dec 30 01:07:14: PrepareNexecute 'GetSessions' Dec 30 01:07:14: SQL query 'GetSessions' executed in 0.000589 seconds Dec 30 01:07:14: Account 212.249.15.6 is already logged in, other session with call ID=6F8C45C3 83E1C8E0 EB07C212 AB369094 Dec 30 01:07:14: Account has an empty password, skip the password check Dec 30 01:07:14: Applying node translation rule on CLD ... Dec 30 01:07:14: Translation 's/^000//; s/^0//; s/^011//; s/^9950011//; s/^99501/1/; s/^3450011//; s/^3950011//; s/^3542011//;' applied: '412X55XXXXX' unchanged Dec 30 01:07:14: PrepareNexecute 'AccountAuth' Dec 30 01:07:14: SQL query 'AccountAuth' executed in 0.00197 seconds Dec 30 01:07:14: CLD '412X55XXXXX' matching our account Dec 30 01:07:14: Setting up a new charge with tariff 'Inbound Verizon' ... Dec 30 01:07:14: Using peak rate, since no off-peak is defined Dec 30 01:07:14: PrepareNexecute 'GetPricePerDestination*' Dec 30 01:07:14: SQL query 'GetPricePerDestination*' executed in 0.002139 seconds Dec 30 01:07:14: Compute maximum call duration for leg Account 212.249.15.6 to destination with funds unlimited (account funds unlimited) Dec 30 01:07:14: No credit limit, unlimited call duration Dec 30 01:07:14: Local termination 'PortaSIP': Checking follow-me for 412X55XXXXX ... Dec 30 01:07:14: PrepareNexecute 'GetAccountFollowMe' Dec 30 01:07:14: SQL query 'GetAccountFollowMe' executed in 0.001155 seconds Dec 30 01:07:14: Local termination 'PortaSIP': ... follow-me result list for 412X55XXXXX: |412X55XXXXX(acct);unlimited Dec 30 01:07:14: PrepareNexecute 'GetSipServerAddress' Dec 30 01:07:14: SQL query 'GetSipServerAddress' executed in 0.001178 seconds Dec 30 01:07:14: CLD '412X55XXXXX' found registered on 91.121.122.64. Dec 30 01:07:14: Use RTP Proxy according to policy 'Undetermined' => 'On Nat': Calling party NOT behind NAT, called party behind NAT Dec 30 01:07:14: Enhance lifetime with 1800s to Fri Dec 30 01:37:14 2011 Dec 30 01:07:14: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: 412X55XXXXX@91.121.122.64;expires=300;credit-time=-1;forward-on-fail=yes;rtpp=3;moh=1;patience=20 h323-billing-model = 0 h323-ivr-in = Tariff:Inbound Verizon h323-ivr-in = PortaBilling_CLI:412X566YYYY h323-ivr-in = MOH:1 h323-ivr-in = PortaBilling_Account:YES h323-ivr-in = PortaBilling_CompleteNumber:412X55XXXXX h323-ivr-in = PortaBilling_Auth_CLD:412X55XXXXX h323-ivr-in = PortaBilling_Auth_Reseller_CLD:412X55XXXXX h323-return-code = 13 h323-currency = CHF h323-preferred-lang = en Dec 30 01:07:14: ...Done Authorize in 0.025765 seconds, 0.009658 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:15: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.122.64' NAS-Port-Name = 'SIP/91.121.117.76-00000151' User-Name = '91.121.117.76' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.122.64-1325236035.337' Password = 'cisco' h323-remote-address = '91.121.117.76' h323-ivr-out = 'PortaBilling_Routing:SIP' h323-session-protocol = 'sipv2' h323-ivr-out = 'PortaBilling_AuthMethod:INVITE' Dec 30 01:07:15: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.122.64-1325236035.337/1 Dec 30 01:07:15: Found a call in cache with such id Dec 30 01:07:15: Authorization of the trusted node Dec 30 01:07:15: IP based authorization, force 'plaintext' password verification Dec 30 01:07:15: Verification of password using method 'plaintext': success Dec 30 01:07:15: '91.121.117.76' is a trusted node's ID or IP, unable to use it as an account ID. Correct account ID should be available on the other call legs Dec 30 01:07:15: PrepareNexecute 'AccountAuth' Dec 30 01:07:15: SQL query 'AccountAuth' executed in 0.003798 seconds Dec 30 01:07:15: CLD '412X55XXXXX' matching our account Dec 30 01:07:15: Local termination 'PortaSIP', after previous hop from PortaSIP node Dec 30 01:07:15: PrepareNexecute 'GetSipServerAddress' Dec 30 01:07:15: SQL query 'GetSipServerAddress' executed in 0.002198 seconds Dec 30 01:07:15: CLD '412X55XXXXX' found registered on 91.121.122.64. Dec 30 01:07:15: Don't use RTP Proxy, local policy not applied. Dec 30 01:07:15: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: 412X55XXXXX@91.121.122.64;expires=300;credit-time=-1;patience=20 h323-ivr-in = PortaBilling_CacheExpiration:Never h323-ivr-in = PortaBilling_CLI:412X566YYYY h323-ivr-in = PortaBilling_Account:YES h323-ivr-in = PortaBilling_CompleteNumber:412X55XXXXX h323-ivr-in = PortaBilling_Auth_CLD:412X55XXXXX h323-ivr-in = PortaBilling_Auth_Reseller_CLD:412X55XXXXX h323-return-code = 0 Dec 30 01:07:15: ...Done Authorize/INVITE in 0.041281 seconds, 0.005996 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:16: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.122.64' User-Name = '91.121.117.76' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Start' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '09:07:15 GMT Fri Dec 30 2011' h323-connect-time = '09:07:16 GMT Fri Dec 30 2011' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.122.64-1325236035.337' Acct-Session-Id = '91.121.122.64-1325236035.337' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' NAS-Port = '5060' h323-ivr-out = 'PortaBilling_Auth_CLD:412X55XXXXX' h323-ivr-out = 'DURATION:7200' h323-remote-address = 'sip-ua' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:16: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.122.64-1325236035.337/1 Dec 30 01:07:16: Found a call in cache with such id Dec 30 01:07:16: Copying randomization seed '16747' into request's PortaBilling_Seed attribute Dec 30 01:07:16: Copying originator authorized CLD '412X55XXXXX' into current request Dec 30 01:07:16: Copying reseller authorized CLD '412X55XXXXX' into current request Dec 30 01:07:16: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:07:16: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:16: Fixing time with duration 0 seconds from connect time Dec 30 01:07:16: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:18: SQL query 'GetActiveLegIdByAcct' executed in 1.576249 seconds! Dec 30 01:07:18: Looking up vendor/connection Dec 30 01:07:18: Trying to match connection for call Dec 30 01:07:18: Looking for a connection VoIP/originate Dec 30 01:07:18: Outgoing VoIP, matching by the remote IP address 'SIP-UA' (env 1) Dec 30 01:07:18: Found connection 154 'SIP UA <-> SIP UA' to vendor 'Switzernet' Dec 30 01:07:18: Found vendor/connection Dec 30 01:07:18: PrepareNexecute 'InsertActiveLeg' Dec 30 01:07:18: SQL query 'InsertActiveLeg' executed in 0.001457 seconds Dec 30 01:07:18: Accounting response Dec 30 01:07:18: ...Done Accounting/Start/originate/VoIP in 1.584785 seconds, 1.577706 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:18: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.117.76' User-Name = '212.249.15.6' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Start' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '09:07:15 GMT Fri Dec 30 2011' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.117.76-1325236034.68506' session-protocol = 'sipv2' h323-remote-address = '91.121.122.64' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:18: fixup: Using value '09:07:15 GMT Fri Dec 30 2011' to supply missing h323-connect-time attribute in Start accounting Dec 30 01:07:18: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.117.76-1325236034.68506/1 Dec 30 01:07:18: Found a call in cache with such id Dec 30 01:07:18: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:18: Fixing time with duration 0 seconds from connect time Dec 30 01:07:18: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:18: SQL query 'GetActiveLegIdByAcct' executed in 0.019307 seconds Dec 30 01:07:18: Looking up vendor/connection Dec 30 01:07:18: Trying to match connection for call Dec 30 01:07:18: Looking for a connection VoIP/originate Dec 30 01:07:18: Outgoing VoIP, matching by the remote IP address '91.121.122.64' (env 1) Dec 30 01:07:18: Call goes to our trusted node astrad.switzernet.com, on net leg Dec 30 01:07:18: Connection to vendor not found Dec 30 01:07:18: PrepareNexecute 'InsertActiveLeg' Dec 30 01:07:18: SQL query 'InsertActiveLeg' executed in 0.019839 seconds Dec 30 01:07:18: Accounting response Dec 30 01:07:18: ...Done Accounting/Start/originate/VoIP in 0.045036 seconds, 0.039146 spent in SQL queries. --REQUEST REQUEST-- c 30 01:07:18: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.122.64' User-Name = '91.121.117.76' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Start' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '09:07:15 GMT Fri Dec 30 2011' h323-connect-time = '09:07:18 GMT Fri Dec 30 2011' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.122.64-1325236035.337' Acct-Session-Id = '91.121.122.64-1325236035.337' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' NAS-Port = '5060' alert-timepoint = '09:07:18 GMT Fri Dec 30 2011' h323-remote-address = '91.121.117.76' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:18: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.122.64-1325236035.337/1 Dec 30 01:07:18: Found a call in cache with such id Dec 30 01:07:18: Copying randomization seed '16747' into request's PortaBilling_Seed attribute Dec 30 01:07:18: Copying originator authorized CLD '412X55XXXXX' into current request Dec 30 01:07:18: Copying reseller authorized CLD '412X55XXXXX' into current request Dec 30 01:07:18: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:07:18: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:18: Fixing time with duration 0 seconds from connect time Dec 30 01:07:18: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:18: SQL query 'GetActiveLegIdByAcct' executed in 0.000973 seconds Dec 30 01:07:18: Looking up vendor/connection Dec 30 01:07:18: Trying to match connection for call Dec 30 01:07:18: Looking for a connection VoIP/answer Dec 30 01:07:18: VoIP, matching by the node IP '91.121.122.64' and User-Name '91.121.117.76' Dec 30 01:07:18: No VoIP from vendor connections were found Dec 30 01:07:18: Connection to vendor not found Dec 30 01:07:18: PrepareNexecute 'InsertActiveLeg' Dec 30 01:07:18: SQL query 'InsertActiveLeg' executed in 0.003324 seconds Dec 30 01:07:18: Accounting response Dec 30 01:07:18: ...Done Accounting/Start/answer/VoIP in 0.010964 seconds, 0.004297 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:18: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.117.76' User-Name = '212.249.15.6' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Start' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '09:07:14 GMT Fri Dec 30 2011' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.117.76-1325236034.68506' session-protocol = 'sipv2' h323-remote-address = '212.249.15.6' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:18: fixup: Using value '09:07:14 GMT Fri Dec 30 2011' to supply missing h323-connect-time attribute in Start accounting Dec 30 01:07:18: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.117.76-1325236034.68506/1 Dec 30 01:07:18: Found a call in cache with such id Dec 30 01:07:18: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:18: Fixing time with duration 0 seconds from connect time Dec 30 01:07:18: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:18: SQL query 'GetActiveLegIdByAcct' executed in 0.001088 seconds Dec 30 01:07:18: Looking up vendor/connection Dec 30 01:07:18: Trying to match connection for call Dec 30 01:07:18: Looking for a connection VoIP/answer Dec 30 01:07:18: VoIP, matching by the node IP '91.121.117.76' and User-Name '212.249.15.6' Dec 30 01:07:18: No VoIP from vendor connections were found Dec 30 01:07:18: Connection to vendor not found Dec 30 01:07:18: PrepareNexecute 'InsertActiveLeg' Dec 30 01:07:18: SQL query 'InsertActiveLeg' executed in 0.001542 seconds Dec 30 01:07:18: Accounting response Dec 30 01:07:18: ...Done Accounting/Start/answer/VoIP in 0.008619 seconds, 0.002630 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:26: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.122.64' User-Name = '91.121.117.76' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Stop' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '09:07:15 GMT Fri Dec 30 2011' h323-connect-time = '09:07:18 GMT Fri Dec 30 2011' h323-disconnect-time = '09:07:26 GMT Fri Dec 30 2011' h323-disconnect-cause = '10' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.122.64-1325236035.337' Acct-Session-Id = '91.121.122.64-1325236035.337' Acct-Session-Time = '8' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' NAS-Port = '5060' h323-ivr-out = 'PortaBilling_Session:unlock' alert-timepoint = '09:07:18 GMT Fri Dec 30 2011' h323-remote-address = '91.121.117.76' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:26: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.122.64-1325236035.337/1 Dec 30 01:07:26: Found a call in cache with such id Dec 30 01:07:26: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:07:26: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:26: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:26: SQL query 'GetActiveLegIdByAcct' executed in 0.000954 seconds Dec 30 01:07:26: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:07:26: SQL query 'DeleteActiveLeg' executed in 0.001308 seconds Dec 30 01:07:26: Force unlock requested by NAS Dec 30 01:07:26: There have been authentication requests from more than one NAS Dec 30 01:07:26: No logged in accounts, call lifetime reduced to 15 Dec 30 01:07:26: Set lifetime with 15s to Fri Dec 30 01:07:41 2011 Dec 30 01:07:26: Looking up vendor/connection Dec 30 01:07:26: Trying to match connection for call Dec 30 01:07:26: Looking for a connection VoIP/answer Dec 30 01:07:26: VoIP, matching by the node IP '91.121.122.64' and User-Name '91.121.117.76' Dec 30 01:07:26: No VoIP from vendor connections were found Dec 30 01:07:26: Connection to vendor not found Dec 30 01:07:26: No connection from vendor Dec 30 01:07:26: Accounting response Dec 30 01:07:26: ...Done Accounting/Stop/answer/VoIP in 0.009019 seconds, 0.002262 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:26: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.117.76' User-Name = '212.249.15.6' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Stop' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '09:07:15 GMT Fri Dec 30 2011' h323-connect-time = '09:07:18 GMT Fri Dec 30 2011' h323-disconnect-time = '09:07:26 GMT Fri Dec 30 2011' h323-disconnect-cause = '10' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.117.76-1325236034.68506' Acct-Session-Time = '8' session-protocol = 'sipv2' h323-remote-address = '91.121.122.64' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:26: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.117.76-1325236034.68506/1 Dec 30 01:07:26: Found a call in cache with such id Dec 30 01:07:26: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:26: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:26: SQL query 'GetActiveLegIdByAcct' executed in 0.002016 seconds Dec 30 01:07:26: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:07:26: SQL query 'DeleteActiveLeg' executed in 0.001325 seconds Dec 30 01:07:26: End of the outgoing call for account, which appears as never logged-in Dec 30 01:07:26: Set lifetime with 15s to Fri Dec 30 01:07:41 2011 Dec 30 01:07:26: Looking up vendor/connection Dec 30 01:07:26: Trying to match connection for call Dec 30 01:07:26: Looking for a connection VoIP/originate Dec 30 01:07:26: Outgoing VoIP, matching by the remote IP address '91.121.122.64' (env 1) Dec 30 01:07:26: Call goes to our trusted node astrad.switzernet.com, on net leg Dec 30 01:07:26: Connection to vendor not found Dec 30 01:07:26: No connection to vendor - on-net call leg Dec 30 01:07:26: Accounting response Dec 30 01:07:26: ...Done Accounting/Stop/originate/VoIP in 0.009647 seconds, 0.003341 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:26: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.117.76' User-Name = '212.249.15.6' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Stop' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '09:07:14 GMT Fri Dec 30 2011' h323-connect-time = '09:07:18 GMT Fri Dec 30 2011' h323-disconnect-time = '09:07:26 GMT Fri Dec 30 2011' h323-disconnect-cause = '10' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.117.76-1325236034.68506' Acct-Session-Time = '8' session-protocol = 'sipv2' h323-remote-address = '212.249.15.6' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:26: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.117.76-1325236034.68506/1 Dec 30 01:07:26: Found a call in cache with such id Dec 30 01:07:26: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:26: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:26: SQL query 'GetActiveLegIdByAcct' executed in 0.001898 seconds Dec 30 01:07:26: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:07:26: SQL query 'DeleteActiveLeg' executed in 0.001349 seconds Dec 30 01:07:26: End of call on incoming call leg from access NAS Dec 30 01:07:26: There have been authentication requests from more than one NAS Dec 30 01:07:26: Scheduling 212.249.15.6 for logout, call lifetime reduced to 15 Dec 30 01:07:26: PrepareNexecute 'GetSessions' Dec 30 01:07:26: SQL query 'GetSessions' executed in 0.000532 seconds Dec 30 01:07:26: Logging out account '212.249.15.6'(56344) from '33E90990 59AA1A98 56148713 6C504A74' Dec 30 01:07:26: PrepareNexecute 'RemoveSession' Dec 30 01:07:26: SQL query 'RemoveSession' executed in 0.000972 seconds Dec 30 01:07:26: Set lifetime with 15s to Fri Dec 30 01:07:41 2011 Dec 30 01:07:26: Looking up vendor/connection Dec 30 01:07:26: Trying to match connection for call Dec 30 01:07:26: Looking for a connection VoIP/answer Dec 30 01:07:26: VoIP, matching by the node IP '91.121.117.76' and User-Name '212.249.15.6' Dec 30 01:07:26: No VoIP from vendor connections were found Dec 30 01:07:26: Connection to vendor not found Dec 30 01:07:26: No connection from vendor Dec 30 01:07:26: Accounting response Dec 30 01:07:26: ...Done Accounting/Stop/answer/VoIP in 0.024921 seconds, 0.004751 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:07:26: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.122.64' User-Name = '91.121.117.76' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' Acct-Status-Type = 'Stop' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '09:07:15 GMT Fri Dec 30 2011' h323-connect-time = '09:07:16 GMT Fri Dec 30 2011' h323-disconnect-time = '09:07:26 GMT Fri Dec 30 2011' h323-disconnect-cause = '10' h323-conf-id = '33E90990 59AA1A98 56148713 6C504A74' call-id = '91.121.122.64-1325236035.337' Acct-Session-Id = '91.121.122.64-1325236035.337' Acct-Session-Time = '8' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' NAS-Port = '5060' h323-ivr-out = 'PortaBilling_Auth_CLD:412X55XXXXX' h323-ivr-out = 'DURATION:7200' h323-remote-address = 'sip-ua' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:07:26: h323-conf-id=33E90990 59AA1A98 56148713 6C504A74/1, call-id=91.121.122.64-1325236035.337/1 Dec 30 01:07:26: Found a call in cache with such id Dec 30 01:07:26: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:07:26: Copied account: 212.249.15.6[56344,credit,balance=163223.52724,limit=none] of customer Inbound Verizon[6336,balance=163050.47534,limit=none] from '91.121.117.76' into the current request Dec 30 01:07:26: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:07:26: SQL query 'GetActiveLegIdByAcct' executed in 0.000925 seconds Dec 30 01:07:26: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:07:26: SQL query 'DeleteActiveLeg' executed in 0.001428 seconds Dec 30 01:07:26: End of the outgoing call for account, which appears as never logged-in Dec 30 01:07:26: Set lifetime with 15s to Fri Dec 30 01:07:41 2011 Dec 30 01:07:26: Looking up vendor/connection Dec 30 01:07:26: Trying to match connection for call Dec 30 01:07:26: Looking for a connection VoIP/originate Dec 30 01:07:26: Outgoing VoIP, matching by the remote IP address 'SIP-UA' (env 1) Dec 30 01:07:26: Found connection 154 'SIP UA <-> SIP UA' to vendor 'Switzernet' Dec 30 01:07:26: Found vendor/connection Dec 30 01:07:26: Applying connection translation rule on CLD ... Dec 30 01:07:26: Translation 's/^00//; s/^0/41/;' applied: '412X55XXXXX' unchanged Dec 30 01:07:26: Charging call ... Dec 30 01:07:26: Using peak rate, since no off-peak is defined Dec 30 01:07:26: Can reuse the already initialized charge. Dec 30 01:07:26: Calculating account's charge by tariff 'Inbound Verizon' Dec 30 01:07:26: Call to '412X55XXXXX' with duration 10 seconds will be charged for 10 seconds and cost is 0.00084 (1x1x0.005+9x1x0.005) by rate 2144849 using 50227 as seed Dec 30 01:07:26: Setting up a new charge with tariff 'SIP Termination' ... Dec 30 01:07:26: Using peak rate, since no off-peak is defined Dec 30 01:07:26: PrepareNexecute 'GetPricePerDestination*' Dec 30 01:07:26: SQL query 'GetPricePerDestination*' executed in 0.002214 seconds Dec 30 01:07:26: Calculating vendor's charge by tariff 'SIP Termination' Dec 30 01:07:26: Call to '412X55XXXXX' with duration 10 seconds will be charged for 10 seconds and cost is 0 (1x1x0+9x1x0) by rate 2144843 using 50227 as seed Dec 30 01:07:26: Charging account for the call Dec 30 01:07:26: Inserting CDR Dec 30 01:07:26: PrepareNexecute 'InsertAccountCDR' Dec 30 01:07:26: SQL query 'InsertAccountCDR' executed in 0.001611 seconds Dec 30 01:07:26: Charging credit account 212.249.15.6 0.00084 Dec 30 01:07:26: PrepareNexecute 'UpdateAccountBalance' Dec 30 01:07:26: SQL query 'UpdateAccountBalance' executed in 0.000854 seconds Dec 30 01:07:26: Charging account's owner for the call Dec 30 01:07:26: Charging customer 6336 'Inbound Verizon' 0.00084 Dec 30 01:07:26: PrepareNexecute 'UpdateCustomerBalance' Dec 30 01:07:26: SQL query 'UpdateCustomerBalance' executed in 0.000857 seconds Dec 30 01:07:26: Charging vendor for the call Dec 30 01:07:26: Charging vendor 32 'Switzernet' 0 Dec 30 01:07:26: Inserting CDR Dec 30 01:07:26: PrepareNexecute 'InsertVendorCDR' Dec 30 01:07:26: SQL query 'InsertVendorCDR' executed in 0.001881 seconds Dec 30 01:07:26: PrepareNexecute 'UpdateVendorBalance' Dec 30 01:07:26: SQL query 'UpdateVendorBalance' executed in 0.000431 seconds Dec 30 01:07:26: Accounting response Dec 30 01:07:26: ...Done Accounting/Stop/originate/VoIP in 0.025605 seconds, 0.010201 spent in SQL queries. --REQUEST