Current-time: Jan 29 10:21:19 PST (UTC -0800) H323-conf-id: 3B02A6D9 36A57AAF 288B9E7C 1A26DDE0 SIP Call-ID: 94.23.225.212-1264789030.2 SIP Call-ID: 94.23.242.200-1264789029.114 Requests: 4 REQUEST-- Jan 29 10:18:33: Processing request (BE ver1.245.2.11,pid15598): NAS-IP-Address = '94.23.242.200' User-Name = '41215500329' Called-Station-Id = '+41216912818' Calling-Station-Id = '41215500329' Acct-Status-Type = 'Stop' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '18:17:10 GMT Fri Jan 29 2010' h323-connect-time = '18:17:15 GMT Fri Jan 29 2010' h323-disconnect-time = '18:17:33 GMT Fri Jan 29 2010' h323-disconnect-cause = '10' h323-conf-id = '3B02A6D9 36A57AAF 288B9E7C 1A26DDE0' call-id = '94.23.242.200-1264789029.114' Acct-Session-Time = '18' session-protocol = 'sipv2' h323-remote-address = '94.23.225.212' Exec-Program-Log = 'porta-billing.pl' Jan 29 10:18:33: h323-conf-id=3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1, call-id=94.23.242.200-1264789029.114/1 Jan 29 10:18:33: H323/SIP call, use h323-conf-id, but remember call-id Jan 29 10:18:33: PrepareNexecute 'GetActiveLegIdByAcct' Jan 29 10:18:33: SQL query 'GetActiveLegIdByAcct' executed in 0.001285 seconds Jan 29 10:18:33: PrepareNexecute 'AccountAccounting' Jan 29 10:18:33: SQL query 'AccountAccounting' executed in 0.001764 seconds Jan 29 10:18:33: Found Account: 41215500329[58048,credit,balance=0.21000,limit=none] of customer Swiss offices[16165,balance=633.49000,limit=700.00000] Jan 29 10:18:33: End of the outgoing call for account, which appears as never logged-in Jan 29 10:18:33: Set lifetime with 15s to Fri Jan 29 10:18:48 2010 Jan 29 10:18:33: Looking up vendor/connection Jan 29 10:18:33: Trying to match connection for call Jan 29 10:18:33: Looking for a connection VoIP/originate Jan 29 10:18:33: Outgoing VoIP, matching by the remote IP address '94.23.225.212' (env 1) Jan 29 10:18:33: Call goes to our trusted node astrad.switzernet.com, on net leg Jan 29 10:18:33: Connection to vendor not found Jan 29 10:18:33: No connection to vendor - on-net call leg Jan 29 10:18:33: Accounting response Jan 29 10:18:33: ...Done Accounting/Stop/originate/VoIP in 0.010132 seconds, 0.003049 spent in SQL queries. --REQUEST REQUEST-- Jan 29 10:18:33: Processing request (BE ver1.245.2.11,pid15598): NAS-IP-Address = '94.23.225.212' User-Name = '94.23.242.200' Called-Station-Id = '+41216912818' Calling-Station-Id = '41215500329' Acct-Status-Type = 'Stop' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '18:17:10 GMT Fri Jan 29 2010' h323-connect-time = '18:17:15 GMT Fri Jan 29 2010' h323-disconnect-time = '18:17:33 GMT Fri Jan 29 2010' h323-disconnect-cause = '10' h323-conf-id = '3B02A6D9 36A57AAF 288B9E7C 1A26DDE0' call-id = '94.23.225.212-1264789030.2' Acct-Session-Time = '18' session-protocol = 'sipv2' h323-remote-address = '212.249.15.9' Exec-Program-Log = 'porta-billing.pl' Jan 29 10:18:33: h323-conf-id=3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1, call-id=94.23.225.212-1264789030.2/1 Jan 29 10:18:33: Found a call in cache with such id Jan 29 10:18:33: Replacing username '94.23.242.200' with the real username '41215500329' Jan 29 10:18:33: Copied account: 41215500329[58048,credit,balance=0.21000,limit=none] of customer Swiss offices[16165,balance=633.49000,limit=700.00000] from '94.23.242.200' into the current request Jan 29 10:18:33: PrepareNexecute 'GetActiveLegIdByAcct' Jan 29 10:18:33: SQL query 'GetActiveLegIdByAcct' executed in 0.001308 seconds Jan 29 10:18:33: End of the outgoing call for account, which appears as never logged-in Jan 29 10:18:33: Set lifetime with 15s to Fri Jan 29 10:18:48 2010 Jan 29 10:18:33: Looking up vendor/connection Jan 29 10:18:33: Trying to match connection for call Jan 29 10:18:33: Looking for a connection VoIP/originate Jan 29 10:18:33: Outgoing VoIP, matching by the remote IP address '212.249.15.9' (env 1) Jan 29 10:18:33: Found connection 217 'OpenSER 9' to vendor 'Verizon' Jan 29 10:18:33: Found vendor/connection Jan 29 10:18:33: Applying connection translation rule on CLD ... Jan 29 10:18:33: Translation 's/^\+//;' applied: '+41216912818' -> '41216912818' Jan 29 10:18:33: Charging call ... Jan 29 10:18:33: Setting up a new charge with tariff 'business' ... Jan 29 10:18:33: Using peak rate, since no off-peak is defined Jan 29 10:18:33: PrepareNexecute 'GetPricePerDestination*' Jan 29 10:18:33: SQL query 'GetPricePerDestination*' executed in 0.002386 seconds Jan 29 10:18:33: Calculating account's charge by tariff 'business' Jan 29 10:18:33: Call to '41216912818' with duration 18 seconds will be charged for 18 seconds and cost is 0.01 (1x1x0.02+17x1x0.02^2) by rate 2487323 using 49082 as seed Jan 29 10:18:33: Setting up a new charge with tariff 'verizon-PRE' ... Jan 29 10:18:33: Checked 2010-01-29 19:17:15 Europe/Zurich against 'hr{17-7} wd{mo-fr }, wd{sa su }, md{25} mo{dec}, md{26} mo{dec}, md{1} mo{jan}, md{2} mo{jan}, md{10} mo{apr}, md{13} mo{apr}, md{1} mo{may}, md{1} mo{jun}, md{1} mo{aug}': 1 Jan 29 10:18:33: Checked 2010-01-29 19:17:33 Europe/Zurich against 'hr{17-7} wd{mo-fr }, wd{sa su }, md{25} mo{dec}, md{26} mo{dec}, md{1} mo{jan}, md{2} mo{jan}, md{10} mo{apr}, md{13} mo{apr}, md{1} mo{may}, md{1} mo{jun}, md{1} mo{aug}': 1 Jan 29 10:18:33: Start of call is peak level 1 Jan 29 10:18:33: End of call is peak level 1 Jan 29 10:18:33: PrepareNexecute 'GetPricePerDestination*' Jan 29 10:18:33: SQL query 'GetPricePerDestination*' executed in 0.001696 seconds Jan 29 10:18:33: Calculating vendor's charge by tariff 'verizon-PRE' Jan 29 10:18:33: Call to '41216912818' with duration 18 seconds will be charged for 18 seconds and cost is 0.00647 (1x1x0.2709+17x1x0.0069) by rate 3530937 using 49082 as seed Jan 29 10:18:33: Charging account for the call Jan 29 10:18:33: Inserting CDR Jan 29 10:18:33: PrepareNexecute 'InsertAccountCDR' Jan 29 10:18:33: SQL query 'InsertAccountCDR' executed in 0.001242 seconds Jan 29 10:18:33: Charging credit account 41215500329 0.01 Jan 29 10:18:33: PrepareNexecute 'UpdateAccountBalance' Jan 29 10:18:33: SQL query 'UpdateAccountBalance' executed in 0.000889 seconds Jan 29 10:18:33: Charging account's owner for the call Jan 29 10:18:33: Charging customer 16165 'Swiss offices' 0.01 Jan 29 10:18:33: PrepareNexecute 'UpdateCustomerBalance' Jan 29 10:18:33: SQL query 'UpdateCustomerBalance' executed in 0.000853 seconds Jan 29 10:18:33: Charging vendor for the call Jan 29 10:18:33: Charging vendor 55 'Verizon' 0.00647 Jan 29 10:18:33: Inserting CDR Jan 29 10:18:33: PrepareNexecute 'InsertVendorCDR' Jan 29 10:18:33: SQL query 'InsertVendorCDR' executed in 0.001105 seconds Jan 29 10:18:33: PrepareNexecute 'UpdateVendorBalance' Jan 29 10:18:33: SQL query 'UpdateVendorBalance' executed in 0.0008 seconds Jan 29 10:18:33: Accounting response Jan 29 10:18:33: ...Done Accounting/Stop/originate/VoIP in 0.026638 seconds, 0.010279 spent in SQL queries. --REQUEST CALL-- Jan 29 10:19:00: Removing call 3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1 Jan 29 10:19:00: No logged in accounts, call lifetime reduced to 15 Jan 29 10:19:00: Cleaning up the call Jan 29 10:19:00: Usernames in all accounting requests are ok Jan 29 10:19:00: Processing originate/VoIP call leg Jan 29 10:19:00: Processing originate/VoIP call leg Jan 29 10:19:00: There are no unsaved CDRs for this call left Jan 29 10:19:00: Call '3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1' deleted from the cache Jan 29 10:19:00: Call 3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1 removed --CALL REQUEST-- Jan 29 10:19:33: Processing request (BE ver1.245.2.11,pid15598): NAS-IP-Address = '94.23.242.200' User-Name = '41215500329' Called-Station-Id = '0216912818' Calling-Station-Id = '41215500329' Acct-Status-Type = 'Stop' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '18:17:09 GMT Fri Jan 29 2010' h323-connect-time = '18:17:15 GMT Fri Jan 29 2010' h323-disconnect-time = '18:17:33 GMT Fri Jan 29 2010' h323-disconnect-cause = '10' h323-conf-id = '3B02A6D9 36A57AAF 288B9E7C 1A26DDE0' call-id = '94.23.242.200-1264789029.114' Acct-Session-Time = '18' session-protocol = 'sipv2' h323-remote-address = '94.23.242.200' Exec-Program-Log = 'porta-billing.pl' Jan 29 10:19:33: h323-conf-id=3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1, call-id=94.23.242.200-1264789029.114/1 Jan 29 10:19:33: H323/SIP call, use h323-conf-id, but remember call-id Jan 29 10:19:33: PrepareNexecute 'GetActiveLegIdByAcct' Jan 29 10:19:33: SQL query 'GetActiveLegIdByAcct' executed in 0.001389 seconds Jan 29 10:19:33: End of call on incoming call leg from access NAS Jan 29 10:19:33: No logged in accounts, call lifetime reduced to 15 Jan 29 10:19:33: Set lifetime with 15s to Fri Jan 29 10:19:48 2010 Jan 29 10:19:33: Looking up vendor/connection Jan 29 10:19:33: Trying to match connection for call Jan 29 10:19:33: Looking for a connection VoIP/answer Jan 29 10:19:33: VoIP, matching by the node IP '94.23.242.200' and User-Name '41215500329' Jan 29 10:19:33: No VoIP from vendor connections were found Jan 29 10:19:33: Connection to vendor not found Jan 29 10:19:33: No connection from vendor Jan 29 10:19:33: Accounting response Jan 29 10:19:33: ...Done Accounting/Stop/answer/VoIP in 0.006614 seconds, 0.001389 spent in SQL queries. --REQUEST REQUEST-- Jan 29 10:19:33: Processing request (BE ver1.245.2.11,pid15598): NAS-IP-Address = '94.23.225.212' User-Name = '94.23.242.200' Called-Station-Id = '41216912818' Calling-Station-Id = '41215500329' Acct-Status-Type = 'Stop' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '18:17:10 GMT Fri Jan 29 2010' h323-connect-time = '18:17:15 GMT Fri Jan 29 2010' h323-disconnect-time = '18:17:33 GMT Fri Jan 29 2010' h323-disconnect-cause = '10' h323-conf-id = '3B02A6D9 36A57AAF 288B9E7C 1A26DDE0' call-id = '94.23.225.212-1264789030.2' Acct-Session-Time = '18' session-protocol = 'sipv2' h323-remote-address = '94.23.242.200' Exec-Program-Log = 'porta-billing.pl' Jan 29 10:19:33: h323-conf-id=3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1, call-id=94.23.225.212-1264789030.2/1 Jan 29 10:19:33: Found a call in cache with such id Jan 29 10:19:33: PrepareNexecute 'GetActiveLegIdByAcct' Jan 29 10:19:33: SQL query 'GetActiveLegIdByAcct' executed in 0.001383 seconds Jan 29 10:19:33: User-Name needs correction. Postponing. Jan 29 10:19:33: Accounting response Jan 29 10:19:33: ...Done Accounting/Stop/answer/VoIP in 0.005714 seconds, 0.001383 spent in SQL queries. --REQUEST CALL-- Jan 29 10:20:02: Removing call 3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1 Jan 29 10:20:02: No logged in accounts, call lifetime reduced to 15 Jan 29 10:20:02: Cleaning up the call Jan 29 10:20:02: No originate call legs to replace username on, probably junk incoming call Jan 29 10:20:02: Processing answer/VoIP call leg Jan 29 10:20:02: Found not billed accounting request with the duration more than zero - bill it now Jan 29 10:20:02: Looking up vendor/connection Jan 29 10:20:02: Trying to match connection for call Jan 29 10:20:02: Looking for a connection VoIP/answer Jan 29 10:20:02: VoIP, matching by the node IP '94.23.225.212' and User-Name '94.23.242.200' Jan 29 10:20:02: No VoIP from vendor connections were found Jan 29 10:20:02: Connection to vendor not found Jan 29 10:20:02: Charging call ... Jan 29 10:20:02: This is incoming call, bill only vendor Jan 29 10:20:02: Vendor is undefined (on-net call?), call is not billed Jan 29 10:20:02: Processing answer/VoIP call leg Jan 29 10:20:02: No outgoing connections to vendor, on-net call Jan 29 10:20:02: No originate call legs, junk incoming call Jan 29 10:20:02: Call '3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1' deleted from the cache Jan 29 10:20:02: Call 3B02A6D9 36A57AAF 288B9E7C 1A26DDE0/1 removed --CALL