Current-time: Mar 17 05:56:49 PST (UTC -0800) H323-conf-id: 70899920 23798964 60F00D54 2C95DCC4 SIP Call-ID: 91.121.205.108-1300369287.313 Requests: 3 REQUEST-- Mar 17 05:41:28: Processing request (BE ver1.245.2.11,pid45919): NAS-IP-Address = '91.121.205.108' NAS-Port-Name = 'SIP/41215500336-017254c0' User-Name = '41215500336' Called-Station-Id = '0033612000123' Calling-Station-Id = '41215500336' h323-conf-id = '70899920 23798964 60F00D54 2C95DCC4' call-id = '91.121.205.108-1300369287.313' Digest-Attributes = 'User-Name = "41215500336"' Digest-Attributes = 'Realm = "switzernet"' Digest-Attributes = 'Nonce = "6faec1a5"' Digest-Attributes = 'URI = "sip:0033612000123@astrad9.switzernet.com"' Digest-Attributes = 'Method = "INVITE"' Digest-Attributes = 'Algorithm = "MD5"' Digest-Response = 'e11e5c2b530d5f8884c32de77539961e' h323-ivr-out = 'PortaBilling_Routing:SIP' Mar 17 05:41:28: h323-conf-id=70899920 23798964 60F00D54 2C95DCC4/1, call-id=91.121.205.108-1300369287.313/1 Mar 17 05:41:28: H323/SIP call, use h323-conf-id, but remember call-id Mar 17 05:41:28: Checking if this call comes through a VoIP from vendor connection Mar 17 05:41:28: No VoIP from vendor connections were found Mar 17 05:41:28: PrepareNexecute 'AccountAuth' Mar 17 05:41:28: SQL query 'AccountAuth' executed in 0.001927 seconds Mar 17 05:41:28: Found Account: 41215500336[63813,credit,balance=0.48000,limit=none] of customer Swiss offices[16165,balance=1325.30000,limit=2220.00000] Mar 17 05:41:28: PrepareNexecute 'GetSessions' Mar 17 05:41:28: SQL query 'GetSessions' executed in 0.000582 seconds Mar 17 05:41:28: Account 41215500336 is not logged in yet Mar 17 05:41:28: Verification of password using method 'digest_response': success Mar 17 05:41:28: Applying customer dialing translation rule on CLD ... Mar 17 05:41:28: Translation 'local_to_e164($_,{cc=>'41',dp=>'0',ip=>'00'});#% cc=41 dp=0 ip=00' applied: '0033612000123' -> '33612000123' Mar 17 05:41:28: PrepareNexecute 'AccountAuth' Mar 17 05:41:28: SQL query 'AccountAuth' executed in 0.001997 seconds Mar 17 05:41:28: CLD '33612000123' is an off-net number Mar 17 05:41:28: Setting up a new charge with tariff 'business' ... Mar 17 05:41:28: Using peak rate, since no off-peak is defined Mar 17 05:41:28: PrepareNexecute 'GetPricePerDestination*' Mar 17 05:41:28: SQL query 'GetPricePerDestination*' executed in 0.016305 seconds Mar 17 05:41:28: Compute maximum call duration for leg Account 41215500336 to destination with funds 894.7 (customer funds 894.7) Mar 17 05:41:28: Maximum call duration: 214728 announced as 214728 (+1x1x0.25+214727x1x0.25) by rate 2481515 using 22790 as seed Mar 17 05:41:28: Remote termination 'PortaSIP': Calculating routing for 33612000123 Mar 17 05:41:28: RTP Proxy with origination preference 'Undetermined', Calling party NOT behind NAT. Mar 17 05:41:28: Looking up routes to '33612000123' using '' routing plan Mar 17 05:41:28: PrepareNexecute 'GetRoutingPerDestination*' Mar 17 05:41:28: SQL query 'GetRoutingPerDestination*' executed in 0.015588 seconds Mar 17 05:41:28: Using peak rate, since no off-peak is defined Mar 17 05:41:28: Checked 2011-03-17 14:41:28 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}': 0 Mar 17 05:41:28: Start of call is peak level 0 Mar 17 05:41:28: Checked 2011-03-17 14:41:28 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}': 0 Mar 17 05:41:28: Start of call is peak level 0 Mar 17 05:41:28: Checked 2011-03-17 14:41:28 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}': 0 Mar 17 05:41:28: Start of call is peak level 0 Mar 17 05:41:28: Checked 2011-03-17 14:41:28 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}': 0 Mar 17 05:41:28: Start of call is peak level 0 Mar 17 05:41:28: Applying route outgoing CLD translation on '33612000123' ... Mar 17 05:41:28: Translation 's/^(\d)/\+$1/;' applied: '33612000123' -> '+33612000123' Mar 17 05:41:28: Applying route outgoing CLD translation on '33612000123' ... Mar 17 05:41:28: Translation 's/^(\d)/\+$1/;' applied: '33612000123' -> '+33612000123' Mar 17 05:41:28: Applying route outgoing CLD translation on '33612000123' ... Mar 17 05:41:28: Translation 's/^(\d)/00$1/;' applied: '33612000123' -> '0033612000123' Mar 17 05:41:28: Applying route outgoing CLD translation on '33612000123' ... Mar 17 05:41:28: Translation 's/^(\d)/00$1/;' applied: '33612000123' -> '0033612000123' Mar 17 05:41:28: Applying route outgoing CLI translation on '41215500336' ... Mar 17 05:41:28: Translation 's/^(\d)/\+$1/;' applied: '41215500336' -> '+41215500336' Mar 17 05:41:28: Applying route outgoing CLI translation on '41215500336' ... Mar 17 05:41:28: Translation 's/^(\d)/\+$1/;' applied: '41215500336' -> '+41215500336' Mar 17 05:41:28: Applying route outgoing CLI translation on '41215500336' ... Mar 17 05:41:28: Translation 's/^(\d)/00$1/;' applied: '41215500336' -> '0041215500336' Mar 17 05:41:28: Applying route outgoing CLI translation on '41215500336' ... Mar 17 05:41:28: Translation 's/^(\d)/00$1/;' applied: '41215500336' -> '0041215500336' Mar 17 05:41:28: Result routes to destination '33612000123': 33612000123@80.77.12.195, prio = 8, cost = 0.00000, 'reliance UK' - to remote GW +33612000123@212.249.15.4, prio = 7, cost = 0.00000, 'OpenSER 3' - to remote GW +33612000123@212.249.15.9, prio = 7, cost = 0.00000, 'OpenSER 9' - to remote GW 0033612000123@217.168.45.4, prio = 6, cost = 0.06749, 'Asterisk SS7' - to remote GW 0033612000123@212.249.15.5, prio = 4, cost = 0.05035, 'AstSS7 Swi' - to remote GW Mar 17 05:41:28: Logging in account '41215500336'(63813) to '70899920 23798964 60F00D54 2C95DCC4' Mar 17 05:41:28: PrepareNexecute 'AddSession' Mar 17 05:41:28: SQL query 'AddSession' executed in 0.007571 seconds Mar 17 05:41:28: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: @;g-hunt=skip;expires=300;credit-time=214728;patience=20 h323-ivr-in = PortaBilling_Routing: 33612000123@80.77.12.195 h323-ivr-in = PortaBilling_Routing: +33612000123@212.249.15.4;cli=+41215500336 h323-ivr-in = PortaBilling_Routing: +33612000123@212.249.15.9;cli=+41215500336 h323-ivr-in = PortaBilling_Routing: 0033612000123@217.168.45.4;cli=0041215500336;rtpp=1 h323-ivr-in = PortaBilling_Routing: 0033612000123@212.249.15.5;cli=0041215500336 h323-billing-model = 0 h323-ivr-in = Tariff:business h323-ivr-in = PortaBilling_CLI:41215500336 h323-ivr-in = MOH:1 h323-ivr-in = PortaBilling_CompleteNumber:33612000123 h323-ivr-in = PortaBilling_Auth_CLD:33612000123 h323-ivr-in = PortaBilling_Auth_Reseller_CLD:33612000123 h323-ivr-in = DURATION:214728 h323-return-code = 0 h323-currency = CHF h323-credit-time = 214728 h323-preferred-lang = en Mar 17 05:41:28: ...Done Authorize/INVITE in 0.085217 seconds, 0.043970 spent in SQL queries. --REQUEST REQUEST-- Mar 17 05:41:29: Processing request (BE ver1.245.2.11,pid45919): NAS-IP-Address = '91.121.205.108' User-Name = '41215500336' Called-Station-Id = '33612000123' Calling-Station-Id = '41215500336' Acct-Status-Type = 'Stop' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '13:41:29 GMT Thu Mar 17 2011' h323-connect-time = '13:41:29 GMT Thu Mar 17 2011' h323-disconnect-time = '13:41:29 GMT Thu Mar 17 2011' h323-disconnect-cause = '0' h323-conf-id = '70899920 23798964 60F00D54 2C95DCC4' call-id = '91.121.205.108-1300369287.313' Acct-Session-Time = '0' session-protocol = 'sipv2' h323-remote-address = '80.77.12.195' Exec-Program-Log = 'porta-billing.pl' Mar 17 05:41:29: h323-conf-id=70899920 23798964 60F00D54 2C95DCC4/1, call-id=91.121.205.108-1300369287.313/1 Mar 17 05:41:29: Found a call in cache with such id Mar 17 05:41:29: Copied account: 41215500336[63813,credit,balance=0.48000,limit=none] of customer Swiss offices[16165,balance=1325.30000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 05:41:29: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 05:41:29: SQL query 'GetActiveLegIdByAcct' executed in 0.001774 seconds Mar 17 05:41:29: End of the outgoing failed call for logged in account. Waiting another outgoing call or hang up Mar 17 05:41:29: Looking up vendor/connection Mar 17 05:41:29: Trying to match connection for call Mar 17 05:41:29: Looking for a connection VoIP/originate Mar 17 05:41:29: Outgoing VoIP, matching by the remote IP address '80.77.12.195' (env 1) Mar 17 05:41:29: Found connection 224 'reliance UK' to vendor 'Reliance' Mar 17 05:41:29: Found vendor/connection Mar 17 05:41:29: Charging call ... Mar 17 05:41:29: Zero duration call Mar 17 05:41:29: Using peak rate, since no off-peak is defined Mar 17 05:41:29: Can reuse the already initialized charge. Mar 17 05:41:29: Calculating account's charge by tariff 'business' Mar 17 05:41:29: Call to '33612000123' with duration 0 seconds will be charged for 0 seconds and cost is 0 (0s<1s) by rate 2481515 using 22790 as seed Mar 17 05:41:29: Setting up a new charge with tariff 'reliance' ... Mar 17 05:41:29: Using peak rate, since no off-peak is defined Mar 17 05:41:29: PrepareNexecute 'GetPricePerDestination*' Mar 17 05:41:29: SQL query 'GetPricePerDestination*' executed in 0.002666 seconds Mar 17 05:41:29: Calculating vendor's charge by tariff 'reliance' Mar 17 05:41:29: Call to '33612000123' with duration 0 seconds will be charged for 0 seconds and cost is 0 (0s<1s) by rate 9357129 using 22790 as seed Mar 17 05:41:29: Updating account usage of '41215500336' with 'Thu Mar 17 05:41:29 2011' Mar 17 05:41:29: PrepareNexecute 'UpdateAccountUsage' Mar 17 05:41:29: SQL query 'UpdateAccountUsage' executed in 0.000922 seconds Mar 17 05:41:29: Charging vendor for the call Mar 17 05:41:29: Inserting fail CDR Mar 17 05:41:29: PrepareNexecute 'InsertVendorCDRFail' Mar 17 05:41:29: SQL query 'InsertVendorCDRFail' executed in 0.001034 seconds Mar 17 05:41:29: Accounting response Mar 17 05:41:29: ...Done Accounting/Stop/originate/VoIP in 0.017147 seconds, 0.006396 spent in SQL queries. --REQUEST REQUEST-- Mar 17 05:41:34: Processing request (BE ver1.245.2.11,pid45919): NAS-IP-Address = '91.121.205.108' User-Name = '41215500336' Called-Station-Id = '0033612000123' Calling-Station-Id = '41215500336' Acct-Status-Type = 'Stop' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '13:41:27 GMT Thu Mar 17 2011' h323-connect-time = '13:41:27 GMT Thu Mar 17 2011' h323-disconnect-time = '13:41:27 GMT Thu Mar 17 2011' h323-disconnect-cause = '0' h323-conf-id = '70899920 23798964 60F00D54 2C95DCC4' call-id = '91.121.205.108-1300369287.313' Acct-Session-Time = '0' session-protocol = 'sipv2' h323-remote-address = '91.121.205.108' Exec-Program-Log = 'porta-billing.pl' Mar 17 05:41:34: h323-conf-id=70899920 23798964 60F00D54 2C95DCC4/1, call-id=91.121.205.108-1300369287.313/1 Mar 17 05:41:34: Found a call in cache with such id Mar 17 05:41:34: Copied account: 41215500336[63813,credit,balance=0.48000,limit=none] of customer Swiss offices[16165,balance=1325.30000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 05:41:34: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 05:41:34: SQL query 'GetActiveLegIdByAcct' executed in 0.001479 seconds Mar 17 05:41:34: End of call on incoming call leg from access NAS Mar 17 05:41:34: Scheduling 41215500336 for logout, call lifetime reduced to 15 Mar 17 05:41:34: PrepareNexecute 'GetSessions' Mar 17 05:41:34: SQL query 'GetSessions' executed in 0.000556 seconds Mar 17 05:41:34: Logging out account '41215500336'(63813) from '70899920 23798964 60F00D54 2C95DCC4' Mar 17 05:41:34: PrepareNexecute 'RemoveSession' Mar 17 05:41:34: SQL query 'RemoveSession' executed in 0.002445 seconds Mar 17 05:41:34: Set lifetime with 15s to Thu Mar 17 05:41:49 2011 Mar 17 05:41:34: Looking up vendor/connection Mar 17 05:41:34: Trying to match connection for call Mar 17 05:41:34: Looking for a connection VoIP/answer Mar 17 05:41:34: VoIP, matching by the node IP '91.121.205.108' and User-Name '41215500336' Mar 17 05:41:34: No VoIP from vendor connections were found Mar 17 05:41:34: Connection to vendor not found Mar 17 05:41:34: No connection from vendor Mar 17 05:41:34: Accounting response Mar 17 05:41:34: ...Done Accounting/Stop/answer/VoIP in 0.011358 seconds, 0.004480 spent in SQL queries. --REQUEST CALL-- Mar 17 05:41:50: Removing call 70899920 23798964 60F00D54 2C95DCC4/1 Mar 17 05:41:50: Scheduling 41215500336 for logout, call lifetime reduced to 15 Mar 17 05:41:50: PrepareNexecute 'GetSessions' Mar 17 05:41:50: SQL query 'GetSessions' executed in 0.000476 seconds Mar 17 05:41:50: Cleaning up the call Mar 17 05:41:50: Usernames in all accounting requests are ok Mar 17 05:41:50: Processing originate/VoIP call leg Mar 17 05:41:50: Charging call ... Mar 17 05:41:50: Zero duration call Mar 17 05:41:50: Using peak rate, since no off-peak is defined Mar 17 05:41:50: Can reuse the already initialized charge. Mar 17 05:41:50: Calculating account's charge by tariff 'business' Mar 17 05:41:50: Call to '33612000123' with duration 0 seconds will be charged for 0 seconds and cost is 0 (0s<1s) by rate 2481515 using 22790 as seed Mar 17 05:41:50: Reusing existing vendor charge Mar 17 05:41:50: Updating account usage of '41215500336' with 'Thu Mar 17 05:41:50 2011' Mar 17 05:41:50: PrepareNexecute 'UpdateAccountUsage' Mar 17 05:41:50: SQL query 'UpdateAccountUsage' executed in 0.001024 seconds Mar 17 05:41:50: Found call leg with connection, increasing setup time Mar 17 05:41:50: Processing answer/VoIP call leg Mar 17 05:41:50: Inserting fail CDR for the account/customer Mar 17 05:41:50: Charging call ... Mar 17 05:41:50: Zero duration call Mar 17 05:41:50: Using peak rate, since no off-peak is defined Mar 17 05:41:50: Can reuse the already initialized charge. Mar 17 05:41:50: Calculating account's charge by tariff 'business' Mar 17 05:41:50: Call to '33612000123' with duration 0 seconds will be charged for 0 seconds and cost is 0 (0s<1s) by rate 2481515 using 22790 as seed Mar 17 05:41:50: Reusing existing vendor charge Mar 17 05:41:50: Charging account for the call Mar 17 05:41:50: Inserting fail CDR Mar 17 05:41:50: PrepareNexecute 'InsertAccountCDRFail' Mar 17 05:41:50: SQL query 'InsertAccountCDRFail' executed in 0.008182 seconds Mar 17 05:41:50: Charging account's owner for the call Mar 17 05:41:50: Call '70899920 23798964 60F00D54 2C95DCC4/1' deleted from the cache Mar 17 05:41:50: Call 70899920 23798964 60F00D54 2C95DCC4/1 removed --CALL