Current-time: Mar 17 01:30:12 PST (UTC -0800) H323-conf-id: 183D3BF1 50364BFA 3DF228B6 2AED8839 SIP Call-ID: 91.121.205.108-1300353537.86 Requests: 5 REQUEST-- Mar 17 01:18:58: Processing request (BE ver1.245.2.11,pid45919): NAS-IP-Address = '91.121.205.108' NAS-Port-Name = 'SIP/41215500336-016e6b70' User-Name = '41215500336' Called-Station-Id = '0033612000123' Calling-Station-Id = '41215500336' h323-conf-id = '183D3BF1 50364BFA 3DF228B6 2AED8839' call-id = '91.121.205.108-1300353537.86' Digest-Attributes = 'User-Name = "41215500336"' Digest-Attributes = 'Realm = "switzernet"' Digest-Attributes = 'Nonce = "56e477dc"' Digest-Attributes = 'URI = "sip:0033612000123@astrad9.switzernet.com"' Digest-Attributes = 'Method = "INVITE"' Digest-Attributes = 'Algorithm = "MD5"' Digest-Response = '05ae9d2c59b92e49ca78462225c45943' h323-ivr-out = 'PortaBilling_Routing:SIP' Mar 17 01:18:58: h323-conf-id=183D3BF1 50364BFA 3DF228B6 2AED8839/1, call-id=91.121.205.108-1300353537.86/1 Mar 17 01:18:58: H323/SIP call, use h323-conf-id, but remember call-id Mar 17 01:18:58: Checking if this call comes through a VoIP from vendor connection Mar 17 01:18:58: No VoIP from vendor connections were found Mar 17 01:18:58: PrepareNexecute 'AccountAuth' Mar 17 01:18:58: SQL query 'AccountAuth' executed in 0.00195 seconds Mar 17 01:18:58: Found Account: 41215500336[63813,credit,balance=0.36000,limit=none] of customer Swiss offices[16165,balance=1324.57000,limit=2220.00000] Mar 17 01:18:58: PrepareNexecute 'GetSessions' Mar 17 01:18:58: SQL query 'GetSessions' executed in 0.001426 seconds Mar 17 01:18:58: Account 41215500336 is not logged in yet Mar 17 01:18:58: Verification of password using method 'digest_response': success Mar 17 01:18:58: Applying customer dialing translation rule on CLD ... Mar 17 01:18:58: Translation 'local_to_e164($_,{cc=>'41',dp=>'0',ip=>'00'});#% cc=41 dp=0 ip=00' applied: '0033612000123' -> '33612000123' Mar 17 01:18:58: PrepareNexecute 'AccountAuth' Mar 17 01:18:58: SQL query 'AccountAuth' executed in 0.001385 seconds Mar 17 01:18:58: CLD '33612000123' is an off-net number Mar 17 01:18:58: Setting up a new charge with tariff 'business' ... Mar 17 01:18:58: Using peak rate, since no off-peak is defined Mar 17 01:18:58: PrepareNexecute 'GetPricePerDestination*' Mar 17 01:18:58: SQL query 'GetPricePerDestination*' executed in 0.002307 seconds Mar 17 01:18:58: Compute maximum call duration for leg Account 41215500336 to destination with funds 895.43 (customer funds 895.43 reduced to 895.43) Mar 17 01:18:58: Maximum call duration: 214903 announced as 214903 (+1x1x0.25+214902x1x0.25) by rate 2481515 using 27244 as seed Mar 17 01:18:58: Remote termination 'PortaSIP': Calculating routing for 33612000123 Mar 17 01:18:58: RTP Proxy with origination preference 'Undetermined', Calling party NOT behind NAT. Mar 17 01:18:58: Looking up routes to '33612000123' using '' routing plan Mar 17 01:18:58: PrepareNexecute 'GetRoutingPerDestination*' Mar 17 01:18:59: SQL query 'GetRoutingPerDestination*' executed in 0.017144 seconds Mar 17 01:18:59: Checked 2011-03-17 10:18:59 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 01:18:59: Start of call is peak level 0 Mar 17 01:18:59: Checked 2011-03-17 10:18:59 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 01:18:59: Start of call is peak level 0 Mar 17 01:18:59: Checked 2011-03-17 10:18:59 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 01:18:59: Start of call is peak level 0 Mar 17 01:18:59: Checked 2011-03-17 10:18:59 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 01:18:59: Start of call is peak level 0 Mar 17 01:18:59: Using peak rate, since no off-peak is defined Mar 17 01:18:59: Applying route outgoing CLD translation on '33612000123' ... Mar 17 01:18:59: Translation 's/^(\d)/\+$1/;' applied: '33612000123' -> '+33612000123' Mar 17 01:18:59: Applying route outgoing CLD translation on '33612000123' ... Mar 17 01:18:59: Translation 's/^(\d)/\+$1/;' applied: '33612000123' -> '+33612000123' Mar 17 01:18:59: Applying route outgoing CLD translation on '33612000123' ... Mar 17 01:18:59: Translation 's/^(\d)/00$1/;' applied: '33612000123' -> '0033612000123' Mar 17 01:18:59: Applying route outgoing CLD translation on '33612000123' ... Mar 17 01:18:59: Translation 's/^(\d)/00$1/;' applied: '33612000123' -> '0033612000123' Mar 17 01:18:59: Applying route outgoing CLI translation on '41215500336' ... Mar 17 01:18:59: Translation 's/^(\d)/\+$1/;' applied: '41215500336' -> '+41215500336' Mar 17 01:18:59: Applying route outgoing CLI translation on '41215500336' ... Mar 17 01:18:59: Translation 's/^(\d)/\+$1/;' applied: '41215500336' -> '+41215500336' Mar 17 01:18:59: Applying route outgoing CLI translation on '41215500336' ... Mar 17 01:18:59: Translation 's/^(\d)/00$1/;' applied: '41215500336' -> '0041215500336' Mar 17 01:18:59: Applying route outgoing CLI translation on '41215500336' ... Mar 17 01:18:59: Translation 's/^(\d)/00$1/;' applied: '41215500336' -> '0041215500336' Mar 17 01:18:59: Result routes to destination '33612000123': +33612000123@212.249.15.9, prio = 7, cost = 0.00000, 'OpenSER 9' - to remote GW +33612000123@212.249.15.4, prio = 7, cost = 0.00000, 'OpenSER 3' - 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 33612000123@80.77.12.195, prio = 4, cost = 0.08000, 'reliance UK' - to remote GW Mar 17 01:18:59: Logging in account '41215500336'(63813) to '183D3BF1 50364BFA 3DF228B6 2AED8839' Mar 17 01:18:59: PrepareNexecute 'AddSession' Mar 17 01:18:59: SQL query 'AddSession' executed in 0.002531 seconds Mar 17 01:18:59: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: @;g-hunt=skip;expires=300;credit-time=214903;patience=20 h323-ivr-in = PortaBilling_Routing: +33612000123@212.249.15.9;cli=+41215500336 h323-ivr-in = PortaBilling_Routing: +33612000123@212.249.15.4;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-ivr-in = PortaBilling_Routing: 33612000123@80.77.12.195 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:214903 h323-return-code = 0 h323-currency = CHF h323-credit-time = 214903 h323-preferred-lang = en Mar 17 01:18:59: ...Done Authorize/INVITE in 0.066792 seconds, 0.026743 spent in SQL queries. --REQUEST REQUEST-- Mar 17 01:19:02: 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 = 'Start' h323-call-origin = 'originate' h323-call-type = 'VoIP' h323-setup-time = '09:18:59 GMT Thu Mar 17 2011' h323-conf-id = '183D3BF1 50364BFA 3DF228B6 2AED8839' call-id = '91.121.205.108-1300353537.86' session-protocol = 'sipv2' h323-remote-address = '212.249.15.9' Exec-Program-Log = 'porta-billing.pl' Mar 17 01:19:02: fixup: Using value '09:18:59 GMT Thu Mar 17 2011' to supply missing h323-connect-time attribute in Start accounting Mar 17 01:19:02: h323-conf-id=183D3BF1 50364BFA 3DF228B6 2AED8839/1, call-id=91.121.205.108-1300353537.86/1 Mar 17 01:19:02: Found a call in cache with such id Mar 17 01:19:02: Copied account: 41215500336[63813,credit,balance=0.36000,limit=none] of customer Swiss offices[16165,balance=1324.57000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 01:19:02: Fixing time with duration 0 seconds from connect time Mar 17 01:19:02: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 01:19:02: SQL query 'GetActiveLegIdByAcct' executed in 0.001776 seconds Mar 17 01:19:02: Looking up vendor/connection Mar 17 01:19:02: Trying to match connection for call Mar 17 01:19:02: Looking for a connection VoIP/originate Mar 17 01:19:02: Outgoing VoIP, matching by the remote IP address '212.249.15.9' (env 1) Mar 17 01:19:02: Found connection 217 'OpenSER 9' to vendor 'Verizon' Mar 17 01:19:02: Found vendor/connection Mar 17 01:19:02: PrepareNexecute 'InsertActiveLeg' Mar 17 01:19:02: SQL query 'InsertActiveLeg' executed in 0.001528 seconds Mar 17 01:19:02: Accounting response Mar 17 01:19:02: ...Done Accounting/Start/originate/VoIP in 0.009269 seconds, 0.003304 spent in SQL queries. --REQUEST REQUEST-- Mar 17 01:19:02: 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 = 'Start' h323-call-origin = 'answer' h323-call-type = 'VoIP' h323-setup-time = '09:18:58 GMT Thu Mar 17 2011' h323-conf-id = '183D3BF1 50364BFA 3DF228B6 2AED8839' call-id = '91.121.205.108-1300353537.86' session-protocol = 'sipv2' h323-remote-address = '91.121.205.108' Exec-Program-Log = 'porta-billing.pl' Mar 17 01:19:02: fixup: Using value '09:18:58 GMT Thu Mar 17 2011' to supply missing h323-connect-time attribute in Start accounting Mar 17 01:19:02: h323-conf-id=183D3BF1 50364BFA 3DF228B6 2AED8839/1, call-id=91.121.205.108-1300353537.86/1 Mar 17 01:19:02: Found a call in cache with such id Mar 17 01:19:02: Copied account: 41215500336[63813,credit,balance=0.36000,limit=none] of customer Swiss offices[16165,balance=1324.57000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 01:19:02: Fixing time with duration 0 seconds from connect time Mar 17 01:19:02: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 01:19:02: SQL query 'GetActiveLegIdByAcct' executed in 0.002462 seconds Mar 17 01:19:02: Looking up vendor/connection Mar 17 01:19:02: Trying to match connection for call Mar 17 01:19:02: Looking for a connection VoIP/answer Mar 17 01:19:02: VoIP, matching by the node IP '91.121.205.108' and User-Name '41215500336' Mar 17 01:19:02: No VoIP from vendor connections were found Mar 17 01:19:02: Connection to vendor not found Mar 17 01:19:02: PrepareNexecute 'InsertActiveLeg' Mar 17 01:19:02: SQL query 'InsertActiveLeg' executed in 0.001479 seconds Mar 17 01:19:02: Accounting response Mar 17 01:19:02: ...Done Accounting/Start/answer/VoIP in 0.009768 seconds, 0.003941 spent in SQL queries. --REQUEST REQUEST-- Mar 17 01:19:05: 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 = '09:18:59 GMT Thu Mar 17 2011' h323-connect-time = '09:19:01 GMT Thu Mar 17 2011' h323-disconnect-time = '09:19:05 GMT Thu Mar 17 2011' h323-disconnect-cause = '10' h323-conf-id = '183D3BF1 50364BFA 3DF228B6 2AED8839' call-id = '91.121.205.108-1300353537.86' Acct-Session-Time = '4' session-protocol = 'sipv2' h323-remote-address = '212.249.15.9' Exec-Program-Log = 'porta-billing.pl' Mar 17 01:19:05: h323-conf-id=183D3BF1 50364BFA 3DF228B6 2AED8839/1, call-id=91.121.205.108-1300353537.86/1 Mar 17 01:19:05: Found a call in cache with such id Mar 17 01:19:05: Copied account: 41215500336[63813,credit,balance=0.36000,limit=none] of customer Swiss offices[16165,balance=1324.57000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 01:19:05: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 01:19:05: SQL query 'GetActiveLegIdByAcct' executed in 0.001767 seconds Mar 17 01:19:05: PrepareNexecute 'DeleteActiveLeg' Mar 17 01:19:05: SQL query 'DeleteActiveLeg' executed in 0.001485 seconds Mar 17 01:19:05: End of the outgoing call for logged in account. Waiting another outgoing call or hang up Mar 17 01:19:05: Set lifetime with 15s to Thu Mar 17 01:19:20 2011 Mar 17 01:19:05: Looking up vendor/connection Mar 17 01:19:05: Trying to match connection for call Mar 17 01:19:05: Looking for a connection VoIP/originate Mar 17 01:19:05: Outgoing VoIP, matching by the remote IP address '212.249.15.9' (env 1) Mar 17 01:19:05: Found connection 217 'OpenSER 9' to vendor 'Verizon' Mar 17 01:19:05: Found vendor/connection Mar 17 01:19:05: Applying connection translation rule on CLD ... Mar 17 01:19:05: Translation 's/^\+//;' applied: '+33612000123' -> '33612000123' Mar 17 01:19:05: Charging call ... Mar 17 01:19:05: Using peak rate, since no off-peak is defined Mar 17 01:19:05: Can reuse the already initialized charge. Mar 17 01:19:05: Calculating account's charge by tariff 'business' Mar 17 01:19:05: Call to '33612000123' with duration 4 seconds will be charged for 4 seconds and cost is 0.02 (1x1x0.25+3x1x0.25^2) by rate 2481515 using 27244 as seed Mar 17 01:19:05: Setting up a new charge with tariff 'verizon-PRE' ... Mar 17 01:19:05: Checked 2011-03-17 10:19:01 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 01:19:05: Checked 2011-03-17 10:19:05 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 01:19:05: Start of call is peak level 0 Mar 17 01:19:05: End of call is peak level 0 Mar 17 01:19:05: PrepareNexecute 'GetPricePerDestination*' Mar 17 01:19:05: SQL query 'GetPricePerDestination*' executed in 0.002253 seconds Mar 17 01:19:05: Calculating vendor's charge by tariff 'verizon-PRE' Mar 17 01:19:05: Call to '33612000123' with duration 4 seconds will be charged for 4 seconds and cost is 0 (1x1x0+3x1x0) by rate 9318017 using 27244 as seed Mar 17 01:19:05: Charging account for the call Mar 17 01:19:05: Inserting CDR Mar 17 01:19:05: PrepareNexecute 'InsertAccountCDR' Mar 17 01:19:05: SQL query 'InsertAccountCDR' executed in 0.001929 seconds Mar 17 01:19:05: Charging credit account 41215500336 0.02 Mar 17 01:19:05: PrepareNexecute 'UpdateAccountBalance' Mar 17 01:19:05: SQL query 'UpdateAccountBalance' executed in 0.000984 seconds Mar 17 01:19:05: Charging account's owner for the call Mar 17 01:19:05: Charging customer 16165 'Swiss offices' 0.02 Mar 17 01:19:05: PrepareNexecute 'UpdateCustomerBalance' Mar 17 01:19:05: SQL query 'UpdateCustomerBalance' executed in 0.000938 seconds Mar 17 01:19:05: Charging vendor for the call Mar 17 01:19:05: Charging vendor 55 'Verizon' 0 Mar 17 01:19:05: Inserting CDR Mar 17 01:19:05: PrepareNexecute 'InsertVendorCDR' Mar 17 01:19:05: SQL query 'InsertVendorCDR' executed in 0.001185 seconds Mar 17 01:19:05: PrepareNexecute 'UpdateVendorBalance' Mar 17 01:19:05: SQL query 'UpdateVendorBalance' executed in 0.000499 seconds Mar 17 01:19:05: Accounting response Mar 17 01:19:05: ...Done Accounting/Stop/originate/VoIP in 0.028397 seconds, 0.011040 spent in SQL queries. --REQUEST REQUEST-- Mar 17 01:19:05: 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 = '09:18:58 GMT Thu Mar 17 2011' h323-connect-time = '09:19:01 GMT Thu Mar 17 2011' h323-disconnect-time = '09:19:05 GMT Thu Mar 17 2011' h323-disconnect-cause = '10' h323-conf-id = '183D3BF1 50364BFA 3DF228B6 2AED8839' call-id = '91.121.205.108-1300353537.86' Acct-Session-Time = '4' session-protocol = 'sipv2' h323-remote-address = '91.121.205.108' Exec-Program-Log = 'porta-billing.pl' Mar 17 01:19:05: h323-conf-id=183D3BF1 50364BFA 3DF228B6 2AED8839/1, call-id=91.121.205.108-1300353537.86/1 Mar 17 01:19:05: Found a call in cache with such id Mar 17 01:19:05: Copied account: 41215500336[63813,credit,balance=0.38,limit=none] of customer Swiss offices[16165,balance=1324.59,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 01:19:05: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 01:19:05: SQL query 'GetActiveLegIdByAcct' executed in 0.00182 seconds Mar 17 01:19:05: PrepareNexecute 'DeleteActiveLeg' Mar 17 01:19:05: SQL query 'DeleteActiveLeg' executed in 0.001456 seconds Mar 17 01:19:05: End of call on incoming call leg from access NAS Mar 17 01:19:05: Scheduling 41215500336 for logout, call lifetime reduced to 15 Mar 17 01:19:05: PrepareNexecute 'GetSessions' Mar 17 01:19:05: SQL query 'GetSessions' executed in 0.000634 seconds Mar 17 01:19:05: Logging out account '41215500336'(63813) from '183D3BF1 50364BFA 3DF228B6 2AED8839' Mar 17 01:19:05: PrepareNexecute 'RemoveSession' Mar 17 01:19:05: SQL query 'RemoveSession' executed in 0.004523 seconds Mar 17 01:19:05: Set lifetime with 15s to Thu Mar 17 01:19:20 2011 Mar 17 01:19:05: Looking up vendor/connection Mar 17 01:19:05: Trying to match connection for call Mar 17 01:19:05: Looking for a connection VoIP/answer Mar 17 01:19:05: VoIP, matching by the node IP '91.121.205.108' and User-Name '41215500336' Mar 17 01:19:05: No VoIP from vendor connections were found Mar 17 01:19:05: Connection to vendor not found Mar 17 01:19:05: No connection from vendor Mar 17 01:19:05: Accounting response Mar 17 01:19:05: ...Done Accounting/Stop/answer/VoIP in 0.015663 seconds, 0.008433 spent in SQL queries. --REQUEST CALL-- Mar 17 01:19:50: Removing call 183D3BF1 50364BFA 3DF228B6 2AED8839/1 Mar 17 01:19:50: Scheduling 41215500336 for logout, call lifetime reduced to 15 Mar 17 01:19:50: PrepareNexecute 'GetSessions' Mar 17 01:19:50: SQL query 'GetSessions' executed in 0.000557 seconds Mar 17 01:19:50: Cleaning up the call Mar 17 01:19:50: Usernames in all accounting requests are ok Mar 17 01:19:50: Processing answer/VoIP call leg Mar 17 01:19:50: Processing originate/VoIP call leg Mar 17 01:19:50: Skipping Start accounting Mar 17 01:19:50: Processing answer/VoIP call leg Mar 17 01:19:50: Skipping Start accounting Mar 17 01:19:50: Processing originate/VoIP call leg Mar 17 01:19:50: There are no unsaved CDRs for this call left Mar 17 01:19:50: Call '183D3BF1 50364BFA 3DF228B6 2AED8839/1' deleted from the cache Mar 17 01:19:50: Call 183D3BF1 50364BFA 3DF228B6 2AED8839/1 removed --CALL