Current-time: Mar 17 00:51:07 PST (UTC -0800) H323-conf-id: 3F727C4E 4A45440A 714B9C9A 21E4AF86 SIP Call-ID: 91.121.205.108-1300351623.84 Requests: 5 REQUEST-- Mar 17 00:47:04: 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 = '3F727C4E 4A45440A 714B9C9A 21E4AF86' call-id = '91.121.205.108-1300351623.84' Digest-Attributes = 'User-Name = "41215500336"' Digest-Attributes = 'Realm = "switzernet"' Digest-Attributes = 'Nonce = "69089117"' Digest-Attributes = 'URI = "sip:0033612000123@astrad9.switzernet.com"' Digest-Attributes = 'Method = "INVITE"' Digest-Attributes = 'Algorithm = "MD5"' Digest-Response = 'a114c5caac125294c1a312209721d2dc' h323-ivr-out = 'PortaBilling_Routing:SIP' Mar 17 00:47:04: h323-conf-id=3F727C4E 4A45440A 714B9C9A 21E4AF86/1, call-id=91.121.205.108-1300351623.84/1 Mar 17 00:47:04: H323/SIP call, use h323-conf-id, but remember call-id Mar 17 00:47:04: Checking if this call comes through a VoIP from vendor connection Mar 17 00:47:04: No VoIP from vendor connections were found Mar 17 00:47:04: PrepareNexecute 'AccountAuth' Mar 17 00:47:04: SQL query 'AccountAuth' executed in 0.001936 seconds Mar 17 00:47:04: Found Account: 41215500336[63813,credit,balance=0.34000,limit=none] of customer Swiss offices[16165,balance=1324.44000,limit=2220.00000] Mar 17 00:47:04: PrepareNexecute 'GetSessions' Mar 17 00:47:04: SQL query 'GetSessions' executed in 0.00077 seconds Mar 17 00:47:04: Account 41215500336 is not logged in yet Mar 17 00:47:04: Verification of password using method 'digest_response': success Mar 17 00:47:04: Applying customer dialing translation rule on CLD ... Mar 17 00:47:04: Translation 'local_to_e164($_,{cc=>'41',dp=>'0',ip=>'00'});#% cc=41 dp=0 ip=00' applied: '0033612000123' -> '33612000123' Mar 17 00:47:04: PrepareNexecute 'AccountAuth' Mar 17 00:47:04: SQL query 'AccountAuth' executed in 0.001421 seconds Mar 17 00:47:04: CLD '33612000123' is an off-net number Mar 17 00:47:04: Setting up a new charge with tariff 'business' ... Mar 17 00:47:04: Using peak rate, since no off-peak is defined Mar 17 00:47:04: PrepareNexecute 'GetPricePerDestination*' Mar 17 00:47:04: SQL query 'GetPricePerDestination*' executed in 0.001809 seconds Mar 17 00:47:04: Compute maximum call duration for leg Account 41215500336 to destination with funds 895.56 (customer funds 895.56) Mar 17 00:47:04: Maximum call duration: 214934 announced as 214934 (+1x1x0.25+214933x1x0.25) by rate 2481515 using 57799 as seed Mar 17 00:47:04: Remote termination 'PortaSIP': Calculating routing for 33612000123 Mar 17 00:47:04: RTP Proxy with origination preference 'Undetermined', Calling party NOT behind NAT. Mar 17 00:47:04: Looking up routes to '33612000123' using '' routing plan Mar 17 00:47:04: PrepareNexecute 'GetRoutingPerDestination*' Mar 17 00:47:04: SQL query 'GetRoutingPerDestination*' executed in 0.015404 seconds Mar 17 00:47:04: Checked 2011-03-17 09:47:04 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 00:47:04: Start of call is peak level 0 Mar 17 00:47:04: Checked 2011-03-17 09:47:04 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 00:47:04: Start of call is peak level 0 Mar 17 00:47:04: Checked 2011-03-17 09:47:04 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 00:47:04: Start of call is peak level 0 Mar 17 00:47:04: Checked 2011-03-17 09:47:04 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 00:47:04: Start of call is peak level 0 Mar 17 00:47:04: Using peak rate, since no off-peak is defined Mar 17 00:47:04: Applying route outgoing CLD translation on '33612000123' ... Mar 17 00:47:04: Translation 's/^(\d)/00$1/;' applied: '33612000123' -> '0033612000123' Mar 17 00:47:04: Applying route outgoing CLD translation on '33612000123' ... Mar 17 00:47:04: Translation 's/^(\d)/\+$1/;' applied: '33612000123' -> '+33612000123' Mar 17 00:47:04: Applying route outgoing CLD translation on '33612000123' ... Mar 17 00:47:04: Translation 's/^(\d)/\+$1/;' applied: '33612000123' -> '+33612000123' Mar 17 00:47:04: Applying route outgoing CLD translation on '33612000123' ... Mar 17 00:47:04: Translation 's/^(\d)/00$1/;' applied: '33612000123' -> '0033612000123' Mar 17 00:47:04: Applying route outgoing CLI translation on '41215500336' ... Mar 17 00:47:04: Translation 's/^(\d)/00$1/;' applied: '41215500336' -> '0041215500336' Mar 17 00:47:04: Applying route outgoing CLI translation on '41215500336' ... Mar 17 00:47:04: Translation 's/^(\d)/\+$1/;' applied: '41215500336' -> '+41215500336' Mar 17 00:47:04: Applying route outgoing CLI translation on '41215500336' ... Mar 17 00:47:04: Translation 's/^(\d)/\+$1/;' applied: '41215500336' -> '+41215500336' Mar 17 00:47:04: Applying route outgoing CLI translation on '41215500336' ... Mar 17 00:47:04: Translation 's/^(\d)/00$1/;' applied: '41215500336' -> '0041215500336' Mar 17 00:47:04: Result routes to destination '33612000123': 0033612000123@217.168.45.4, prio = 6, cost = 0.06749, 'Asterisk SS7' - to remote GW +33612000123@212.249.15.9, prio = 5, cost = 0.05035, 'OpenSER 9' - to remote GW +33612000123@212.249.15.4, prio = 5, cost = 0.05035, 'OpenSER 3' - 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 00:47:04: Logging in account '41215500336'(63813) to '3F727C4E 4A45440A 714B9C9A 21E4AF86' Mar 17 00:47:04: PrepareNexecute 'AddSession' Mar 17 00:47:04: SQL query 'AddSession' executed in 0.002288 seconds Mar 17 00:47:04: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: @;g-hunt=skip;expires=300;credit-time=214934;patience=20 h323-ivr-in = PortaBilling_Routing: 0033612000123@217.168.45.4;cli=0041215500336;rtpp=1 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@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:214934 h323-return-code = 0 h323-currency = CHF h323-credit-time = 214934 h323-preferred-lang = en Mar 17 00:47:04: ...Done Authorize/INVITE in 0.063406 seconds, 0.023628 spent in SQL queries. --REQUEST REQUEST-- Mar 17 00:47:06: 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 = 'originate' h323-call-type = 'VoIP' h323-setup-time = '08:47:05 GMT Thu Mar 17 2011' h323-conf-id = '3F727C4E 4A45440A 714B9C9A 21E4AF86' call-id = '91.121.205.108-1300351623.84' session-protocol = 'sipv2' h323-remote-address = '217.168.45.4' Exec-Program-Log = 'porta-billing.pl' Mar 17 00:47:06: fixup: Using value '08:47:05 GMT Thu Mar 17 2011' to supply missing h323-connect-time attribute in Start accounting Mar 17 00:47:06: h323-conf-id=3F727C4E 4A45440A 714B9C9A 21E4AF86/1, call-id=91.121.205.108-1300351623.84/1 Mar 17 00:47:06: Found a call in cache with such id Mar 17 00:47:06: Copied account: 41215500336[63813,credit,balance=0.34000,limit=none] of customer Swiss offices[16165,balance=1324.44000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 00:47:06: Fixing time with duration 0 seconds from connect time Mar 17 00:47:06: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 00:47:06: SQL query 'GetActiveLegIdByAcct' executed in 0.001222 seconds Mar 17 00:47:06: Looking up vendor/connection Mar 17 00:47:06: Trying to match connection for call Mar 17 00:47:06: Looking for a connection VoIP/originate Mar 17 00:47:06: Outgoing VoIP, matching by the remote IP address '217.168.45.4' (env 1) Mar 17 00:47:06: Found connection 214 'Asterisk SS7' to vendor 'Colt' Mar 17 00:47:06: Found vendor/connection Mar 17 00:47:06: PrepareNexecute 'InsertActiveLeg' Mar 17 00:47:06: SQL query 'InsertActiveLeg' executed in 0.001174 seconds Mar 17 00:47:06: Accounting response Mar 17 00:47:06: ...Done Accounting/Start/originate/VoIP in 0.008365 seconds, 0.002396 spent in SQL queries. --REQUEST REQUEST-- Mar 17 00:47:06: 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 = '08:47:03 GMT Thu Mar 17 2011' h323-conf-id = '3F727C4E 4A45440A 714B9C9A 21E4AF86' call-id = '91.121.205.108-1300351623.84' session-protocol = 'sipv2' h323-remote-address = '91.121.205.108' Exec-Program-Log = 'porta-billing.pl' Mar 17 00:47:06: fixup: Using value '08:47:03 GMT Thu Mar 17 2011' to supply missing h323-connect-time attribute in Start accounting Mar 17 00:47:06: h323-conf-id=3F727C4E 4A45440A 714B9C9A 21E4AF86/1, call-id=91.121.205.108-1300351623.84/1 Mar 17 00:47:06: Found a call in cache with such id Mar 17 00:47:06: Copied account: 41215500336[63813,credit,balance=0.34000,limit=none] of customer Swiss offices[16165,balance=1324.44000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 00:47:06: Fixing time with duration 0 seconds from connect time Mar 17 00:47:06: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 00:47:06: SQL query 'GetActiveLegIdByAcct' executed in 0.001013 seconds Mar 17 00:47:06: Looking up vendor/connection Mar 17 00:47:06: Trying to match connection for call Mar 17 00:47:06: Looking for a connection VoIP/answer Mar 17 00:47:06: VoIP, matching by the node IP '91.121.205.108' and User-Name '41215500336' Mar 17 00:47:06: No VoIP from vendor connections were found Mar 17 00:47:06: Connection to vendor not found Mar 17 00:47:06: PrepareNexecute 'InsertActiveLeg' Mar 17 00:47:06: SQL query 'InsertActiveLeg' executed in 0.001197 seconds Mar 17 00:47:06: Accounting response Mar 17 00:47:06: ...Done Accounting/Start/answer/VoIP in 0.007822 seconds, 0.002210 spent in SQL queries. --REQUEST REQUEST-- Mar 17 00:47:09: 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 = 'originate' h323-call-type = 'VoIP' h323-setup-time = '08:47:05 GMT Thu Mar 17 2011' h323-connect-time = '08:47:06 GMT Thu Mar 17 2011' h323-disconnect-time = '08:47:09 GMT Thu Mar 17 2011' h323-disconnect-cause = '10' h323-conf-id = '3F727C4E 4A45440A 714B9C9A 21E4AF86' call-id = '91.121.205.108-1300351623.84' Acct-Session-Time = '3' session-protocol = 'sipv2' h323-remote-address = '217.168.45.4' Exec-Program-Log = 'porta-billing.pl' Mar 17 00:47:09: h323-conf-id=3F727C4E 4A45440A 714B9C9A 21E4AF86/1, call-id=91.121.205.108-1300351623.84/1 Mar 17 00:47:09: Found a call in cache with such id Mar 17 00:47:09: Copied account: 41215500336[63813,credit,balance=0.34000,limit=none] of customer Swiss offices[16165,balance=1324.44000,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 00:47:09: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 00:47:09: SQL query 'GetActiveLegIdByAcct' executed in 0.001195 seconds Mar 17 00:47:09: PrepareNexecute 'DeleteActiveLeg' Mar 17 00:47:09: SQL query 'DeleteActiveLeg' executed in 0.001151 seconds Mar 17 00:47:09: End of the outgoing call for logged in account. Waiting another outgoing call or hang up Mar 17 00:47:09: Set lifetime with 15s to Thu Mar 17 00:47:24 2011 Mar 17 00:47:09: Looking up vendor/connection Mar 17 00:47:09: Trying to match connection for call Mar 17 00:47:09: Looking for a connection VoIP/originate Mar 17 00:47:09: Outgoing VoIP, matching by the remote IP address '217.168.45.4' (env 1) Mar 17 00:47:09: Found connection 214 'Asterisk SS7' to vendor 'Colt' Mar 17 00:47:09: Found vendor/connection Mar 17 00:47:09: Applying connection translation rule on CLD ... Mar 17 00:47:09: Translation 's/^00//;' applied: '0033612000123' -> '33612000123' Mar 17 00:47:09: Charging call ... Mar 17 00:47:09: Using peak rate, since no off-peak is defined Mar 17 00:47:09: Can reuse the already initialized charge. Mar 17 00:47:09: Calculating account's charge by tariff 'business' Mar 17 00:47:09: Call to '33612000123' with duration 3 seconds will be charged for 3 seconds and cost is 0.02 (1x1x0.25+2x1x0.25^2) by rate 2481515 using 57799 as seed Mar 17 00:47:09: Setting up a new charge with tariff 'colt' ... Mar 17 00:47:09: Checked 2011-03-17 09:47:06 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 00:47:09: Checked 2011-03-17 09:47:09 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 00:47:09: Start of call is peak level 0 Mar 17 00:47:09: End of call is peak level 0 Mar 17 00:47:09: PrepareNexecute 'GetPricePerDestination*' Mar 17 00:47:09: SQL query 'GetPricePerDestination*' executed in 0.001886 seconds Mar 17 00:47:09: Calculating vendor's charge by tariff 'colt' Mar 17 00:47:09: Call to '33612000123' with duration 3 seconds will be charged for 3 seconds and cost is 0.00309 (1x1x0.0618+2x1x0.0618) by rate 9318016 using 57799 as seed Mar 17 00:47:09: Charging account for the call Mar 17 00:47:09: Inserting CDR Mar 17 00:47:09: PrepareNexecute 'InsertAccountCDR' Mar 17 00:47:09: SQL query 'InsertAccountCDR' executed in 0.001151 seconds Mar 17 00:47:09: Charging credit account 41215500336 0.02 Mar 17 00:47:09: PrepareNexecute 'UpdateAccountBalance' Mar 17 00:47:09: SQL query 'UpdateAccountBalance' executed in 0.000872 seconds Mar 17 00:47:09: Charging account's owner for the call Mar 17 00:47:09: Charging customer 16165 'Swiss offices' 0.02 Mar 17 00:47:09: PrepareNexecute 'UpdateCustomerBalance' Mar 17 00:47:09: SQL query 'UpdateCustomerBalance' executed in 0.000824 seconds Mar 17 00:47:09: Charging vendor for the call Mar 17 00:47:09: Charging vendor 62 'Colt' 0.00309 Mar 17 00:47:09: Inserting CDR Mar 17 00:47:09: PrepareNexecute 'InsertVendorCDR' Mar 17 00:47:09: SQL query 'InsertVendorCDR' executed in 0.001096 seconds Mar 17 00:47:09: PrepareNexecute 'UpdateVendorBalance' Mar 17 00:47:09: SQL query 'UpdateVendorBalance' executed in 0.000803 seconds Mar 17 00:47:09: Accounting response Mar 17 00:47:09: ...Done Accounting/Stop/originate/VoIP in 0.026254 seconds, 0.008978 spent in SQL queries. --REQUEST REQUEST-- Mar 17 00:47:09: 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 = '08:47:03 GMT Thu Mar 17 2011' h323-connect-time = '08:47:06 GMT Thu Mar 17 2011' h323-disconnect-time = '08:47:09 GMT Thu Mar 17 2011' h323-disconnect-cause = '10' h323-conf-id = '3F727C4E 4A45440A 714B9C9A 21E4AF86' call-id = '91.121.205.108-1300351623.84' Acct-Session-Time = '3' session-protocol = 'sipv2' h323-remote-address = '91.121.205.108' Exec-Program-Log = 'porta-billing.pl' Mar 17 00:47:09: h323-conf-id=3F727C4E 4A45440A 714B9C9A 21E4AF86/1, call-id=91.121.205.108-1300351623.84/1 Mar 17 00:47:09: Found a call in cache with such id Mar 17 00:47:09: Copied account: 41215500336[63813,credit,balance=0.36,limit=none] of customer Swiss offices[16165,balance=1324.46,limit=2220.00000] from '91.121.205.108' into the current request Mar 17 00:47:09: PrepareNexecute 'GetActiveLegIdByAcct' Mar 17 00:47:09: SQL query 'GetActiveLegIdByAcct' executed in 0.001245 seconds Mar 17 00:47:09: PrepareNexecute 'DeleteActiveLeg' Mar 17 00:47:09: SQL query 'DeleteActiveLeg' executed in 0.001114 seconds Mar 17 00:47:09: End of call on incoming call leg from access NAS Mar 17 00:47:09: Scheduling 41215500336 for logout, call lifetime reduced to 15 Mar 17 00:47:09: PrepareNexecute 'GetSessions' Mar 17 00:47:09: SQL query 'GetSessions' executed in 0.000522 seconds Mar 17 00:47:09: Logging out account '41215500336'(63813) from '3F727C4E 4A45440A 714B9C9A 21E4AF86' Mar 17 00:47:09: PrepareNexecute 'RemoveSession' Mar 17 00:47:09: SQL query 'RemoveSession' executed in 0.002209 seconds Mar 17 00:47:09: Set lifetime with 15s to Thu Mar 17 00:47:24 2011 Mar 17 00:47:09: Looking up vendor/connection Mar 17 00:47:09: Trying to match connection for call Mar 17 00:47:09: Looking for a connection VoIP/answer Mar 17 00:47:09: VoIP, matching by the node IP '91.121.205.108' and User-Name '41215500336' Mar 17 00:47:09: No VoIP from vendor connections were found Mar 17 00:47:09: Connection to vendor not found Mar 17 00:47:09: No connection from vendor Mar 17 00:47:09: Accounting response Mar 17 00:47:09: ...Done Accounting/Stop/answer/VoIP in 0.012391 seconds, 0.005090 spent in SQL queries. --REQUEST CALL-- Mar 17 00:47:44: Removing call 3F727C4E 4A45440A 714B9C9A 21E4AF86/1 Mar 17 00:47:44: Scheduling 41215500336 for logout, call lifetime reduced to 15 Mar 17 00:47:44: PrepareNexecute 'GetSessions' Mar 17 00:47:44: SQL query 'GetSessions' executed in 0.000535 seconds Mar 17 00:47:44: Cleaning up the call Mar 17 00:47:44: Usernames in all accounting requests are ok Mar 17 00:47:44: Processing answer/VoIP call leg Mar 17 00:47:44: Skipping Start accounting Mar 17 00:47:44: Processing originate/VoIP call leg Mar 17 00:47:44: Processing originate/VoIP call leg Mar 17 00:47:44: Skipping Start accounting Mar 17 00:47:44: Processing answer/VoIP call leg Mar 17 00:47:44: There are no unsaved CDRs for this call left Mar 17 00:47:44: Call '3F727C4E 4A45440A 714B9C9A 21E4AF86/1' deleted from the cache Mar 17 00:47:44: Call 3F727C4E 4A45440A 714B9C9A 21E4AF86/1 removed --CALL