Current-time: Dec 30 01:11:55 PST (UTC -0800) H323-conf-id: 1DFE3A01 16E2034A 63018886 1F3163CC SIP Call-ID: 91.121.117.76-1325236294.68518 SIP Call-ID: 378efdf01d4f270016e14b142c379d94@91.121.117.76 Requests: 10 REQUEST-- Dec 30 01:11:35: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '91.121.117.76' NAS-Port-Name = 'SIP/212.249.15.6-e0578f70' User-Name = '212.249.15.6' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '91.121.117.76-1325236294.68518' Password = 'cisco' h323-remote-address = '212.249.15.6' h323-ivr-out = 'PortaBilling_Routing:SIP' Dec 30 01:11:35: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=91.121.117.76-1325236294.68518/1 Dec 30 01:11:35: H323/SIP call, use h323-conf-id, but remember call-id Dec 30 01:11:35: Checking if this call comes through a VoIP from vendor connection Dec 30 01:11:35: No VoIP from vendor connections were found Dec 30 01:11:35: PrepareNexecute 'AccountAuth' Dec 30 01:11:35: SQL query 'AccountAuth' executed in 0.004695 seconds Dec 30 01:11:35: Found Account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] Dec 30 01:11:35: PrepareNexecute 'GetSessions' Dec 30 01:11:35: SQL query 'GetSessions' executed in 0.000563 seconds Dec 30 01:11:35: Account 212.249.15.6 is already logged in, other session with call ID=6F8C45C3 83E1C8E0 EB07C212 AB369094 Dec 30 01:11:35: Account has an empty password, skip the password check Dec 30 01:11:35: Applying node translation rule on CLD ... Dec 30 01:11:35: Translation 's/^000//; s/^0//; s/^011//; s/^9950011//; s/^99501/1/; s/^3450011//; s/^3950011//; s/^3542011//;' applied: '412X55XXXXX' unchanged Dec 30 01:11:35: PrepareNexecute 'AccountAuth' Dec 30 01:11:35: SQL query 'AccountAuth' executed in 0.002258 seconds Dec 30 01:11:35: CLD '412X55XXXXX' matching our account Dec 30 01:11:35: Setting up a new charge with tariff 'Inbound Verizon' ... Dec 30 01:11:35: Using peak rate, since no off-peak is defined Dec 30 01:11:35: PrepareNexecute 'GetPricePerDestination*' Dec 30 01:11:35: SQL query 'GetPricePerDestination*' executed in 0.001571 seconds Dec 30 01:11:35: Compute maximum call duration for leg Account 212.249.15.6 to destination with funds unlimited (account funds unlimited) Dec 30 01:11:35: No credit limit, unlimited call duration Dec 30 01:11:35: Local termination 'PortaSIP': Checking follow-me for 412X55XXXXX ... Dec 30 01:11:35: PrepareNexecute 'GetAccountFollowMe' Dec 30 01:11:35: SQL query 'GetAccountFollowMe' executed in 0.000835 seconds Dec 30 01:11:35: Local termination 'PortaSIP': ... follow-me result list for 412X55XXXXX: |412X55XXXXX(acct);unlimited Dec 30 01:11:35: PrepareNexecute 'GetSipServerAddress' Dec 30 01:11:35: SQL query 'GetSipServerAddress' executed in 0.002065 seconds Dec 30 01:11:35: CLD '412X55XXXXX' found registered on 82.103.128.3. Dec 30 01:11:35: Don't use RTP Proxy according to policy 'Undetermined' => 'On Nat': ? Dec 30 01:11:35: Enhance lifetime with 1800s to Fri Dec 30 01:41:35 2011 Dec 30 01:11:35: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: 412X55XXXXX@82.103.128.3;expires=300;credit-time=-1;forward-on-fail=yes;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:11:35: ...Done Authorize in 0.027932 seconds, 0.011987 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:35: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '82.103.128.3' User-Name = '91.121.117.76' Called-Station-Id = '412X55XXXXX' Calling-Station-Id = '412X566YYYY' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' 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' h323-ivr-out = 'PortaBilling_Notify:rtpp_level=3' h323-ivr-out = 'PortaBilling_Seed:2152843298' NAS-Port = '5060' Dec 30 01:11:35: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=378efdf01d4f270016e14b142c379d94@91.121.117.76/1 Dec 30 01:11:35: Found a call in cache with such id Dec 30 01:11:35: Authorization of the trusted node Dec 30 01:11:35: IP based authorization, force 'plaintext' password verification Dec 30 01:11:35: Verification of password using method 'plaintext': success Dec 30 01:11:35: '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:11:35: PrepareNexecute 'AccountAuth' Dec 30 01:11:35: SQL query 'AccountAuth' executed in 0.002564 seconds Dec 30 01:11:35: CLD '412X55XXXXX' matching our account Dec 30 01:11:35: Local termination 'PortaSIP', after previous hop from PortaSIP node Dec 30 01:11:35: PrepareNexecute 'GetSipServerAddress' Dec 30 01:11:35: SQL query 'GetSipServerAddress' executed in 0.001173 seconds Dec 30 01:11:35: CLD '412X55XXXXX' found registered on 82.103.128.3. Dec 30 01:11:35: Don't use RTP Proxy, local policy not applied. Dec 30 01:11:35: Authentication acknowledge response h323-ivr-in = PortaBilling_Routing:@;g-hunt=seq h323-ivr-in = PortaBilling_Routing: 412X55XXXXX@82.103.128.3;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:11:35: ...Done Authorize/INVITE in 0.011354 seconds, 0.003737 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:38: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '82.103.128.3' 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:11:35.611 GMT Fri Dec 30 2011' h323-connect-time = '09:11:38.583 GMT Fri Dec 30 2011' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Session-Id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' 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' h323-ivr-out = 'PortaBilling_Seed:2152843298' alert-timepoint = '09:11:35.851 GMT Fri Dec 30 2011' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:38: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=378efdf01d4f270016e14b142c379d94@91.121.117.76/1 Dec 30 01:11:38: Found a call in cache with such id Dec 30 01:11:38: Copying randomization seed '2152843298' into request's PortaBilling_Seed attribute Dec 30 01:11:38: Copying originator authorized CLD '412X55XXXXX' into current request Dec 30 01:11:38: Copying reseller authorized CLD '412X55XXXXX' into current request Dec 30 01:11:38: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:11:38: Copied account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:38: Fixing time with duration 0 seconds from connect time Dec 30 01:11:38: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:38: SQL query 'GetActiveLegIdByAcct' executed in 0.001934 seconds Dec 30 01:11:38: Looking up vendor/connection Dec 30 01:11:38: Trying to match connection for call Dec 30 01:11:38: Looking for a connection VoIP/originate Dec 30 01:11:38: Outgoing VoIP, matching by the remote IP address 'SIP-UA' (env 1) Dec 30 01:11:38: Found connection 154 'SIP UA <-> SIP UA' to vendor 'Switzernet' Dec 30 01:11:38: Found vendor/connection Dec 30 01:11:38: PrepareNexecute 'InsertActiveLeg' Dec 30 01:11:38: SQL query 'InsertActiveLeg' executed in 0.003115 seconds Dec 30 01:11:38: Accounting response Dec 30 01:11:38: ...Done Accounting/Start/originate/VoIP in 0.012296 seconds, 0.005049 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:38: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '82.103.128.3' 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:11:35.505 GMT Fri Dec 30 2011' h323-connect-time = '09:11:38.585 GMT Fri Dec 30 2011' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Session-Id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' h323-remote-address = '91.121.117.76' h323-ivr-out = 'PortaBilling_Seed:2152843298' alert-timepoint = '09:11:38.585 GMT Fri Dec 30 2011' NAS-Port = '5060' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:38: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=378efdf01d4f270016e14b142c379d94@91.121.117.76/1 Dec 30 01:11:38: Found a call in cache with such id Dec 30 01:11:38: Copying randomization seed '2152843298' into request's PortaBilling_Seed attribute Dec 30 01:11:38: Copying originator authorized CLD '412X55XXXXX' into current request Dec 30 01:11:38: Copying reseller authorized CLD '412X55XXXXX' into current request Dec 30 01:11:38: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:11:38: Copied account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:38: Fixing time with duration 0 seconds from connect time Dec 30 01:11:38: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:38: SQL query 'GetActiveLegIdByAcct' executed in 0.001605 seconds Dec 30 01:11:38: Looking up vendor/connection Dec 30 01:11:38: Trying to match connection for call Dec 30 01:11:38: Looking for a connection VoIP/answer Dec 30 01:11:38: VoIP, matching by the node IP '82.103.128.3' and User-Name '91.121.117.76' Dec 30 01:11:38: No VoIP from vendor connections were found Dec 30 01:11:38: Connection to vendor not found Dec 30 01:11:38: PrepareNexecute 'InsertActiveLeg' Dec 30 01:11:38: SQL query 'InsertActiveLeg' executed in 0.001458 seconds Dec 30 01:11:38: Accounting response Dec 30 01:11:38: ...Done Accounting/Start/answer/VoIP in 0.009846 seconds, 0.003063 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:38: 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:11:35 GMT Fri Dec 30 2011' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '91.121.117.76-1325236294.68518' session-protocol = 'sipv2' h323-remote-address = '82.103.128.3' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:38: fixup: Using value '09:11:35 GMT Fri Dec 30 2011' to supply missing h323-connect-time attribute in Start accounting Dec 30 01:11:38: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=91.121.117.76-1325236294.68518/1 Dec 30 01:11:38: Found a call in cache with such id Dec 30 01:11:38: Copied account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:38: Fixing time with duration 0 seconds from connect time Dec 30 01:11:38: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:38: SQL query 'GetActiveLegIdByAcct' executed in 0.000884 seconds Dec 30 01:11:38: Looking up vendor/connection Dec 30 01:11:38: Trying to match connection for call Dec 30 01:11:38: Looking for a connection VoIP/originate Dec 30 01:11:38: Outgoing VoIP, matching by the remote IP address '82.103.128.3' (env 1) Dec 30 01:11:38: Call goes to our trusted node dk1.youroute.net, on net leg Dec 30 01:11:38: Connection to vendor not found Dec 30 01:11:38: PrepareNexecute 'InsertActiveLeg' Dec 30 01:11:38: SQL query 'InsertActiveLeg' executed in 0.001433 seconds Dec 30 01:11:38: Accounting response Dec 30 01:11:38: ...Done Accounting/Start/originate/VoIP in 0.008078 seconds, 0.002317 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:38: 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:11:34 GMT Fri Dec 30 2011' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '91.121.117.76-1325236294.68518' session-protocol = 'sipv2' h323-remote-address = '212.249.15.6' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:38: fixup: Using value '09:11:34 GMT Fri Dec 30 2011' to supply missing h323-connect-time attribute in Start accounting Dec 30 01:11:38: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=91.121.117.76-1325236294.68518/1 Dec 30 01:11:38: Found a call in cache with such id Dec 30 01:11:38: Copied account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:38: Fixing time with duration 0 seconds from connect time Dec 30 01:11:38: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:38: SQL query 'GetActiveLegIdByAcct' executed in 0.001571 seconds Dec 30 01:11:38: Looking up vendor/connection Dec 30 01:11:38: Trying to match connection for call Dec 30 01:11:38: Looking for a connection VoIP/answer Dec 30 01:11:38: VoIP, matching by the node IP '91.121.117.76' and User-Name '212.249.15.6' Dec 30 01:11:38: No VoIP from vendor connections were found Dec 30 01:11:38: Connection to vendor not found Dec 30 01:11:38: PrepareNexecute 'InsertActiveLeg' Dec 30 01:11:38: SQL query 'InsertActiveLeg' executed in 0.001769 seconds Dec 30 01:11:38: Accounting response Dec 30 01:11:38: ...Done Accounting/Start/answer/VoIP in 0.009112 seconds, 0.003340 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:49: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '82.103.128.3' 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:11:35.505 GMT Fri Dec 30 2011' h323-connect-time = '09:11:38.505 GMT Fri Dec 30 2011' h323-disconnect-time = '09:11:49.505 GMT Fri Dec 30 2011' h323-disconnect-cause = '0' h323-voice-quality = '0' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Session-Id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Session-Time = '11' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' h323-remote-address = '91.121.117.76' h323-ivr-out = 'PortaBilling_Seed:2152843298' Acct-Terminate-Cause = 'User-Request' h323-ivr-out = 'PortaBilling_Session:unlock' alert-timepoint = '09:11:38.585 GMT Fri Dec 30 2011' NAS-Port = '5060' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:49: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=378efdf01d4f270016e14b142c379d94@91.121.117.76/1 Dec 30 01:11:49: Found a call in cache with such id Dec 30 01:11:49: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:11:49: Copied account: 212.249.15.6[56344,credit,balance=163223.80886,limit=none] of customer Inbound Verizon[6336,balance=163050.75696,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:49: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:49: SQL query 'GetActiveLegIdByAcct' executed in 0.001496 seconds Dec 30 01:11:49: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:11:49: SQL query 'DeleteActiveLeg' executed in 0.001573 seconds Dec 30 01:11:49: Force unlock requested by NAS Dec 30 01:11:49: There have been authentication requests from more than one NAS Dec 30 01:11:49: No logged in accounts, call lifetime reduced to 15 Dec 30 01:11:49: Set lifetime with 15s to Fri Dec 30 01:12:04 2011 Dec 30 01:11:49: Looking up vendor/connection Dec 30 01:11:49: Trying to match connection for call Dec 30 01:11:49: Looking for a connection VoIP/answer Dec 30 01:11:49: VoIP, matching by the node IP '82.103.128.3' and User-Name '91.121.117.76' Dec 30 01:11:49: No VoIP from vendor connections were found Dec 30 01:11:49: Connection to vendor not found Dec 30 01:11:49: No connection from vendor Dec 30 01:11:49: Accounting response Dec 30 01:11:49: ...Done Accounting/Stop/answer/VoIP in 0.010303 seconds, 0.003069 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:49: 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:11:34 GMT Fri Dec 30 2011' h323-connect-time = '09:11:38 GMT Fri Dec 30 2011' h323-disconnect-time = '09:11:49 GMT Fri Dec 30 2011' h323-disconnect-cause = '10' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '91.121.117.76-1325236294.68518' Acct-Session-Time = '11' session-protocol = 'sipv2' h323-remote-address = '212.249.15.6' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:49: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=91.121.117.76-1325236294.68518/1 Dec 30 01:11:49: Found a call in cache with such id Dec 30 01:11:49: Copied account: 212.249.15.6[56344,credit,balance=163223.80886,limit=none] of customer Inbound Verizon[6336,balance=163050.75696,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:49: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:49: SQL query 'GetActiveLegIdByAcct' executed in 0.003062 seconds Dec 30 01:11:49: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:11:49: SQL query 'DeleteActiveLeg' executed in 0.001388 seconds Dec 30 01:11:49: End of call on incoming call leg from access NAS Dec 30 01:11:49: There have been authentication requests from more than one NAS Dec 30 01:11:49: Scheduling 212.249.15.6 for logout, call lifetime reduced to 15 Dec 30 01:11:49: PrepareNexecute 'GetSessions' Dec 30 01:11:49: SQL query 'GetSessions' executed in 0.000501 seconds Dec 30 01:11:49: Logging out account '212.249.15.6'(56344) from '1DFE3A01 16E2034A 63018886 1F3163CC' Dec 30 01:11:49: PrepareNexecute 'RemoveSession' Dec 30 01:11:49: SQL query 'RemoveSession' executed in 0.000769 seconds Dec 30 01:11:49: Set lifetime with 15s to Fri Dec 30 01:12:04 2011 Dec 30 01:11:49: Looking up vendor/connection Dec 30 01:11:49: Trying to match connection for call Dec 30 01:11:49: Looking for a connection VoIP/answer Dec 30 01:11:49: VoIP, matching by the node IP '91.121.117.76' and User-Name '212.249.15.6' Dec 30 01:11:49: No VoIP from vendor connections were found Dec 30 01:11:49: Connection to vendor not found Dec 30 01:11:49: No connection from vendor Dec 30 01:11:49: Accounting response Dec 30 01:11:49: ...Done Accounting/Stop/answer/VoIP in 0.037163 seconds, 0.005720 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:49: 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:11:35 GMT Fri Dec 30 2011' h323-connect-time = '09:11:38 GMT Fri Dec 30 2011' h323-disconnect-time = '09:11:49 GMT Fri Dec 30 2011' h323-disconnect-cause = '10' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '91.121.117.76-1325236294.68518' Acct-Session-Time = '11' session-protocol = 'sipv2' h323-remote-address = '82.103.128.3' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:49: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=91.121.117.76-1325236294.68518/1 Dec 30 01:11:49: Found a call in cache with such id Dec 30 01:11:49: Copied account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:49: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:49: SQL query 'GetActiveLegIdByAcct' executed in 0.00184 seconds Dec 30 01:11:49: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:11:49: SQL query 'DeleteActiveLeg' executed in 0.001889 seconds Dec 30 01:11:49: End of the outgoing call for account, which appears as never logged-in Dec 30 01:11:49: Set lifetime with 15s to Fri Dec 30 01:12:04 2011 Dec 30 01:11:49: Looking up vendor/connection Dec 30 01:11:49: Trying to match connection for call Dec 30 01:11:49: Looking for a connection VoIP/originate Dec 30 01:11:49: Outgoing VoIP, matching by the remote IP address '82.103.128.3' (env 1) Dec 30 01:11:49: Call goes to our trusted node dk1.youroute.net, on net leg Dec 30 01:11:49: Connection to vendor not found Dec 30 01:11:49: No connection to vendor - on-net call leg Dec 30 01:11:49: Accounting response Dec 30 01:11:49: ...Done Accounting/Stop/originate/VoIP in 0.009762 seconds, 0.003729 spent in SQL queries. --REQUEST REQUEST-- Dec 30 01:11:49: Processing request (BE ver1.245.2.11,pid20219): NAS-IP-Address = '82.103.128.3' 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:11:35.611 GMT Fri Dec 30 2011' h323-connect-time = '09:11:37.611 GMT Fri Dec 30 2011' h323-disconnect-time = '09:11:48.611 GMT Fri Dec 30 2011' h323-disconnect-cause = '0' h323-voice-quality = '0' h323-conf-id = '1DFE3A01 16E2034A 63018886 1F3163CC' call-id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Session-Id = '378efdf01d4f270016e14b142c379d94@91.121.117.76' Acct-Session-Time = '11' Acct-Delay-Time = '0' h323-session-protocol = 'sipv2' h323-remote-address = 'sip-ua' h323-ivr-out = 'DURATION:7200' h323-ivr-out = 'PortaBilling_Auth_CLD:412X55XXXXX' h323-ivr-out = 'PortaBilling_Seed:2152843298' Acct-Terminate-Cause = 'User-Request' alert-timepoint = '09:11:35.851 GMT Fri Dec 30 2011' NAS-Port = '5060' Exec-Program-Log = 'porta-billing.pl' Dec 30 01:11:49: h323-conf-id=1DFE3A01 16E2034A 63018886 1F3163CC/1, call-id=378efdf01d4f270016e14b142c379d94@91.121.117.76/1 Dec 30 01:11:49: Found a call in cache with such id Dec 30 01:11:49: Replacing username '91.121.117.76' with the real username '212.249.15.6' Dec 30 01:11:49: Copied account: 212.249.15.6[56344,credit,balance=163223.80794,limit=none] of customer Inbound Verizon[6336,balance=163050.75604,limit=none] from '91.121.117.76' into the current request Dec 30 01:11:49: PrepareNexecute 'GetActiveLegIdByAcct' Dec 30 01:11:49: SQL query 'GetActiveLegIdByAcct' executed in 0.002267 seconds Dec 30 01:11:49: PrepareNexecute 'DeleteActiveLeg' Dec 30 01:11:49: SQL query 'DeleteActiveLeg' executed in 0.002431 seconds Dec 30 01:11:49: End of the outgoing call for account, which appears as never logged-in Dec 30 01:11:49: Set lifetime with 15s to Fri Dec 30 01:12:04 2011 Dec 30 01:11:49: Looking up vendor/connection Dec 30 01:11:49: Trying to match connection for call Dec 30 01:11:49: Looking for a connection VoIP/originate Dec 30 01:11:49: Outgoing VoIP, matching by the remote IP address 'SIP-UA' (env 1) Dec 30 01:11:49: Found connection 154 'SIP UA <-> SIP UA' to vendor 'Switzernet' Dec 30 01:11:49: Found vendor/connection Dec 30 01:11:49: Applying connection translation rule on CLD ... Dec 30 01:11:49: Translation 's/^00//; s/^0/41/;' applied: '412X55XXXXX' unchanged Dec 30 01:11:49: Charging call ... Dec 30 01:11:49: Initialize new charge clone with tariff 'Inbound Verizon' as this one is already initialized with incompatible parameters Dec 30 01:11:49: Setting up a new charge with tariff 'Inbound Verizon' ... Dec 30 01:11:49: Using peak rate, since no off-peak is defined Dec 30 01:11:49: PrepareNexecute 'GetPricePerDestination*' Dec 30 01:11:49: SQL query 'GetPricePerDestination*' executed in 0.001558 seconds Dec 30 01:11:49: Calculating account's charge by tariff 'Inbound Verizon' Dec 30 01:11:49: Call to '412X55XXXXX' with duration 11 seconds will be charged for 11 seconds and cost is 0.00092 (1x1x0.005+10x1x0.005) by rate 2144849 using -2142090518 as seed Dec 30 01:11:49: Setting up a new charge with tariff 'SIP Termination' ... Dec 30 01:11:49: Using peak rate, since no off-peak is defined Dec 30 01:11:49: PrepareNexecute 'GetPricePerDestination*' Dec 30 01:11:49: SQL query 'GetPricePerDestination*' executed in 0.001904 seconds Dec 30 01:11:49: Calculating vendor's charge by tariff 'SIP Termination' Dec 30 01:11:49: Call to '412X55XXXXX' with duration 11 seconds will be charged for 11 seconds and cost is 0 (1x1x0+10x1x0) by rate 2144843 using -2142090518 as seed Dec 30 01:11:49: Charging account for the call Dec 30 01:11:49: Inserting CDR Dec 30 01:11:49: PrepareNexecute 'InsertAccountCDR' Dec 30 01:11:49: SQL query 'InsertAccountCDR' executed in 0.00157 seconds Dec 30 01:11:49: Charging credit account 212.249.15.6 0.00092 Dec 30 01:11:49: PrepareNexecute 'UpdateAccountBalance' Dec 30 01:11:49: SQL query 'UpdateAccountBalance' executed in 0.000865 seconds Dec 30 01:11:49: Charging account's owner for the call Dec 30 01:11:49: Charging customer 6336 'Inbound Verizon' 0.00092 Dec 30 01:11:49: PrepareNexecute 'UpdateCustomerBalance' Dec 30 01:11:49: SQL query 'UpdateCustomerBalance' executed in 0.00083 seconds Dec 30 01:11:49: Charging vendor for the call Dec 30 01:11:49: Charging vendor 32 'Switzernet' 0 Dec 30 01:11:49: Inserting CDR Dec 30 01:11:49: PrepareNexecute 'InsertVendorCDR' Dec 30 01:11:49: SQL query 'InsertVendorCDR' executed in 0.001058 seconds Dec 30 01:11:49: PrepareNexecute 'UpdateVendorBalance' Dec 30 01:11:49: SQL query 'UpdateVendorBalance' executed in 0.001962 seconds Dec 30 01:11:49: Accounting response Dec 30 01:11:49: ...Done Accounting/Stop/originate/VoIP in 0.031663 seconds, 0.014445 spent in SQL queries. --REQUEST