FreeSWITCH Pastebin

Untitled

From Bulky Parakeet, 5 Years ago, written in FreeSWITCH.
- view diff
URL https://pastebin.freeswitch.org/view/c28060a3
Embed
Download Paste or View Raw
  1. 2018-10-31 23:05:56.414881 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'internal' for [PHU001@nec.convergedgroup.co.za] from ip 154.118.252.35
  2. 2018-10-31 23:05:59.094892 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/27104760604@sbc.brightnetworks.co.za [145c3b64-b3d5-4d4d-acc9-9edffa54b8aa]
  3. 2018-10-31 23:05:59.094892 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_NEW (Cur 9 Tot 3729050)
  4. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:9873 sofia/internal/27104760604@sbc.brightnetworks.co.za receiving invite from 154.118.252.35:5060 version: 1.6.20 -37-987c9b9 64bit
  5. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:9999 1 acls to check for proxy
  6. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:10004 checking 154.118.252.35 against acl proxies
  7. 2018-10-31 23:05:59.094892 [INFO] sofia.c:10006 154.118.252.35 is a proxy according to the proxies acl
  8. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:10016 network ip is a proxy
  9. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [154.118.252.248]
  10. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:10044 IP 154.118.252.35 Rejected by acl "domains". Falling back to Digest auth.
  11. 2018-10-31 23:05:59.094892 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [0112340142@sbc.brightnetworks.co.za] from ip 154.118.252.35
  12. 2018-10-31 23:05:59.094892 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State NEW
  13. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:2334 detaching session 145c3b64-b3d5-4d4d-acc9-9edffa54b8aa
  14. 2018-10-31 23:05:59.094892 [DEBUG] sofia.c:2442 Re-attaching to session 145c3b64-b3d5-4d4d-acc9-9edffa54b8aa
  15. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:9873 sofia/internal/27104760604@sbc.brightnetworks.co.za receiving invite from 154.118.252.35:5060 version: 1.6.20 -37-987c9b9 64bit
  16. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:9999 1 acls to check for proxy
  17. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:10004 checking 154.118.252.35 against acl proxies
  18. 2018-10-31 23:05:59.114878 [INFO] sofia.c:10006 154.118.252.35 is a proxy according to the proxies acl
  19. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:10016 network ip is a proxy
  20. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [154.118.252.248]
  21. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:10044 IP 154.118.252.35 Rejected by acl "domains". Falling back to Digest auth.
  22. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:7084 Channel sofia/internal/27104760604@sbc.brightnetworks.co.za entering state [received][100]
  23. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:7094 Remote SDP:
  24. v=0
  25. o=Z 0 0 IN IP4 154.118.252.248
  26. s=Z
  27. c=IN IP4 154.118.252.248
  28. t=0 0
  29. m=audio 8000 RTP/AVP 8 101
  30. a=rtpmap:101 telephone-event/8000
  31. a=fmtp:101 0-16
  32.  
  33. 2018-10-31 23:05:59.114878 [DEBUG] sofia.c:7486 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State Change CS_NEW -> CS_INIT
  34. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_INIT (Cur 9 Tot 3729050)
  35. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State INIT
  36. 2018-10-31 23:05:59.114878 [DEBUG] mod_sofia.c:90 sofia/internal/27104760604@sbc.brightnetworks.co.za SOFIA INIT
  37. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:40 sofia/internal/27104760604@sbc.brightnetworks.co.za Standard INIT
  38. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State Change CS_INIT -> CS_ROUTING
  39. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State INIT going to sleep
  40. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_ROUTING (Cur 9 Tot 3729050)
  41. 2018-10-31 23:05:59.114878 [DEBUG] switch_channel.c:2249 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Callstate Change DOWN -> RINGING
  42. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State ROUTING
  43. 2018-10-31 23:05:59.114878 [DEBUG] mod_sofia.c:143 sofia/internal/27104760604@sbc.brightnetworks.co.za SOFIA ROUTING
  44. 2018-10-31 23:05:59.114878 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  45. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='a6e32d84-0d4c-476a-a0a8-1f4b229027f6']
  46. 2018-10-31 23:05:59.114878 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account a6e32d84-0d4c-476a-a0a8-1f4b229027f6 (balance = -1098.533355)
  47. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:236 sofia/internal/27104760604@sbc.brightnetworks.co.za Standard ROUTING
  48. 2018-10-31 23:05:59.114878 [INFO] mod_dialplan_xml.c:637 Processing 27104760604 <27104760604>->0112340142 in context cgrtbilling
  49. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za parsing [cgrtbilling->unloop] continue=false
  50. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  51. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  52. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za parsing [cgrtbilling->call_debug] continue=true
  53. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  54. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za parsing [cgrtbilling->block_account] continue=false
  55. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (FAIL) [block_account] destination_number(0112340142) =~ /^(block_account)$/ break=on-false
  56. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za parsing [cgrtbilling->check_auth] continue=true
  57. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (PASS) [check_auth] ${sip_authorized}(true) =~ /^true$/ break=never
  58. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za parsing [cgrtbilling->calls_from_converged] continue=true
  59. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (FAIL) [calls_from_converged] ${sip_req_host}(sbc.brightnetworks.co.za) =~ /^sbc.convergedgroup.co.za$/ break=on-false
  60. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za parsing [cgrtbilling->calls_from_tenants] continue=true
  61. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Regex (PASS) [calls_from_tenants] destination_number(0112340142) =~ /^(.*)$/ break=on-false
  62. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Action translate(${destination_number} sbc.convergedgroup.co.za-za)
  63. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Action set(destination_number=${translated})
  64. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Action set(outside_call=true)
  65. Dialplan: sofia/internal/27104760604@sbc.brightnetworks.co.za Action lua(cgrtbilling/cgrtbilling_v2.luac)
  66. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State Change CS_ROUTING -> CS_EXECUTE
  67. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State ROUTING going to sleep
  68. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_EXECUTE (Cur 9 Tot 3729050)
  69. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State EXECUTE
  70. 2018-10-31 23:05:59.114878 [DEBUG] mod_sofia.c:198 sofia/internal/27104760604@sbc.brightnetworks.co.za SOFIA EXECUTE
  71. 2018-10-31 23:05:59.114878 [DEBUG] switch_core_state_machine.c:328 sofia/internal/27104760604@sbc.brightnetworks.co.za Standard EXECUTE
  72. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za translate(0112340142 sbc.convergedgroup.co.za-za)
  73. 2018-10-31 23:05:59.114878 [DEBUG] mod_translate.c:128 translating [0112340142] against [sbc.convergedgroup.co.za-za] profile
  74. 2018-10-31 23:05:59.114878 [DEBUG] mod_translate.c:137 0112340142 =~ /^\+(\d+)$/
  75. 2018-10-31 23:05:59.114878 [DEBUG] mod_translate.c:137 0112340142 =~ /^(00\d{9,17})$/
  76. 2018-10-31 23:05:59.114878 [DEBUG] mod_translate.c:137 0112340142 =~ /^0(\d+)$/
  77. 2018-10-31 23:05:59.114878 [NOTICE] mod_translate.c:249 Translated: 27112340142
  78. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za set(destination_number=27112340142)
  79. 2018-10-31 23:05:59.114878 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27104760604@sbc.brightnetworks.co.za [destination_number]=[27112340142]
  80. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za set(outside_call=true)
  81. 2018-10-31 23:05:59.114878 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27104760604@sbc.brightnetworks.co.za [outside_call]=[true]
  82. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za lua(cgrtbilling/cgrtbilling_v2.luac)
  83. 2018-10-31 23:05:59.114878 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  84. 2018-10-31 23:05:59.114878 [INFO] switch_cpp.cpp:1365 Destination_number: 27112340142<-----------
  85.  
  86. 2018-10-31 23:05:59.114878 [NOTICE] switch_cpp.cpp:1365 SELECT mc.id, mc.name, mc.account_type, mc.account_code, b.balance_uuid, b.value as balance, t.name as tenant,
  87.     mc.origination, mc.orig_credit_limit, mc.max_per_minute_rate as max_rate, mc.max_daily_spend, mc.play_audio_messages as play_msgs,
  88.     mc.orig_max_channels as max_channels, mc.orig_max_cps as max_cps, tc.max_call_length as max_duration, mc.enable_calls, mc.enabled
  89.     FROM management_client mc
  90.     INNER JOIN management_tenant t ON t.id = mc.tenant_id
  91.     INNER JOIN management_tenantconfiguration tc ON ( t.id = tc.tenant_id )
  92.     INNER JOIN management_clientbalances b ON mc.id = b.client_id
  93.     WHERE mc.account_code = '0823913044' AND b.balance_type = '*monetary' AND weight = '10'
  94. 2018-10-31 23:05:59.114878 [WARNING] switch_cpp.cpp:1365 <------- Getting Account Info for Client: Bright Office with account_code: 0823913044 ------->
  95.  
  96. 2018-10-31 23:05:59.114878 [NOTICE] switch_cpp.cpp:1365 SELECT mc.account_code, s.username, s.password, s.ip_address, s.caller_id_name as cid_name, s.caller_id_number as cid_number,
  97.     s.bypass_media as bymedia, s.pass_thru_caller_id, s.custom_sip_headers, c1.description as c1, c2.description as c2,
  98.     c3.description as c3, c4.description as c4, s.enabled
  99.     FROM management_sipaccount s
  100.     INNER JOIN management_client mc ON s.client_id = mc.id
  101.     LEFT OUTER JOIN configuration_codecpreference c1 ON s.codec1_id = c1.id
  102.     LEFT OUTER JOIN configuration_codecpreference c2 ON s.codec2_id = c2.id
  103.     LEFT OUTER JOIN configuration_codecpreference c3 ON s.codec3_id = c3.id
  104.     LEFT OUTER JOIN configuration_codecpreference c4 ON s.codec4_id = c4.id
  105.     WHERE  mc.id = '5473851498396115' AND s.username = '27104760604'AND s.enabled = 't'
  106. 2018-10-31 23:05:59.134860 [WARNING] switch_cpp.cpp:1365 elapsed time: 0.003138
  107.  
  108. 2018-10-31 23:05:59.134860 [WARNING] switch_cpp.cpp:1365 -------------> Geting Client Tariff Plan info ------------->
  109.  
  110. 2018-10-31 23:05:59.134860 [NOTICE] switch_cpp.cpp:1365 SELECT mt.tech_prefix, mt.tpb_id, t.name as tpb_name, mt.routing_plan_id, r.routing_type, r.allow_negative_profit
  111.       FROM management_tpballocation mt
  112.       INNER JOIN management_client mc ON mt.client_id = mc.id
  113.       INNER JOIN routing_routingplan r ON mt.routing_plan_id = r.id
  114.       INNER JOIN tariff_plans_tpb t ON t.id = mt.tpb_id
  115.       WHERE mc.account_code = '0823913044'
  116. 2018-10-31 23:05:59.134860 [INFO] switch_cpp.cpp:1365 <----------------------------------------------------->
  117. 2018-10-31 23:05:59.134860 [INFO] switch_cpp.cpp:1365 Trying without tech prefix
  118. 2018-10-31 23:05:59.134860 [INFO] switch_cpp.cpp:1365 Dialed number : 27112340142
  119. 2018-10-31 23:05:59.134860 [INFO] switch_cpp.cpp:1365 Tariff Plan Name : BRONZE
  120. 2018-10-31 23:05:59.134860 [INFO] switch_cpp.cpp:1365 <----------------------------------------------------->
  121.  
  122. 2018-10-31 23:05:59.134860 [WARNING] switch_cpp.cpp:1365 ------------  Getting Call cost for client  ------------
  123.  
  124. 2018-10-31 23:05:59.134860 [NOTICE] switch_cpp.cpp:1365 SELECT tp.code, tp.destination_name, tp.connect_fee, tp.rate, tp.rate_minimum, tp.rate_increment, tp.effective_date, tp.expiry_date, tp.enabled
  125.     FROM tariff_plans_rates tp
  126.     WHERE code @> '27112340142' AND tpb_id = '5465386174008112' AND tp.effective_date <= tp.expiry_date AND tp.expiry_date >= now()
  127.     ORDER BY CODE ASC LIMIT 1
  128. 2018-10-31 23:05:59.134860 [NOTICE] switch_cpp.cpp:1365 Code: 2711
  129. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(execute_on_answer=nibblebill adjust -0)
  130. 2018-10-31 23:05:59.134860 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [execute_on_answer]=[nibblebill adjust -0]
  131. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('connect_fee', '0')
  132. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_rate', '0.4')
  133. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_minimum', '0.0066666666666667')
  134. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_increment', '1')
  135. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_account', 'A6E32D84-0D4C-476A-A0A8-1F4B229027F6')
  136. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_account', '0823913044')
  137. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('client_id', '5473851498396115')
  138. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_tenant', 'sbc.brightnetworks.co.za')
  139. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nobal_amt', '-5000')
  140. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za nibblebill(heartbeat 60)
  141. 2018-10-31 23:05:59.134860 [WARNING] switch_core_session.c:1605 sofia/internal/27104760604@sbc.brightnetworks.co.za using scheduler due to bypass media or media is not established.
  142. 2018-10-31 23:05:59.134860 [DEBUG] switch_scheduler.c:249 Added task 8876726 switch_core_session_sched_heartbeat (145c3b64-b3d5-4d4d-acc9-9edffa54b8aa) to run at 1541020019
  143. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_dept', ' ')
  144. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_site', ' ')
  145. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_extension', ' ')
  146. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_custom', ' ')
  147. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_subject', ' ')
  148. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_supplier', ' ')
  149. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_reqtype', 'POSTPAID')
  150. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_category', 'BRONZE')
  151. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('prefix', '2711')
  152. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('destination_name', 'SA National_2711')
  153. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('destination_number', '27112340142')
  154. 2018-10-31 23:05:59.134860 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('tor', '*voice')
  155. 2018-10-31 23:05:59.134860 [WARNING] switch_cpp.cpp:1365 -------------> Removing unwanted SIP Headers ------------->
  156.  
  157. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za unset(sip_h_X-accountcode)
  158. 2018-10-31 23:05:59.134860 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-accountcode]
  159. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za unset(sip_h_X-username)
  160. 2018-10-31 23:05:59.134860 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-username]
  161. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za unset(sip_h_X-extension)
  162. 2018-10-31 23:05:59.134860 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-extension]
  163. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za unset(sip_h_X-dept)
  164. 2018-10-31 23:05:59.134860 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-dept]
  165. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za unset(sip_h_X-site)
  166. 2018-10-31 23:05:59.134860 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-site]
  167. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za unset(sip_h_X-custom)
  168. 2018-10-31 23:05:59.134860 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-custom]
  169. 2018-10-31 23:05:59.134860 [NOTICE] switch_cpp.cpp:1365 Checking if 27112340142 is a DID <-------------
  170. 2018-10-31 23:05:59.134860 [NOTICE] switch_cpp.cpp:1365 SELECT status from management_did where did_number = '27112340142' and status != 'ported_out'
  171. 2018-10-31 23:05:59.134860 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  172. 2018-10-31 23:05:59.134860 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  173. 2018-10-31 23:05:59.134860 [WARNING] switch_cpp.cpp:1365 ------------  Getting LCR info  ------------
  174.  
  175. 2018-10-31 23:05:59.134860 [NOTICE] switch_cpp.cpp:1365 SELECT *
  176.     FROM (SELECT DISTINCT ON (t.name) t.name as tariff_plan, rt.id AS rt_id, r.code, r.destination_name, r.connect_fee, r.rate, r.rate_minimum, r.rate_increment,
  177.     t.prefix, t.suffix, t.quality, t.reliability, t.client_id AS carrier_id, r.effective_date, r.expiry_date, t.gw1_id, t.gw2_id, t.gw3_id, r.enabled
  178.     FROM tariff_plans_rates r
  179.     INNER JOIN tariff_plans_tpb t ON r.tpb_id = t.id
  180.     INNER JOIN routing_routingplantariff rt ON rt.tariff_plan_id = t.id
  181.     WHERE rt.routing_plan_id = '5465431039104489' AND code @> '27112340142' AND enabled = 't' AND (CURRENT_TIMESTAMP BETWEEN r.effective_date AND r.expiry_date)
  182.     ORDER BY t.name, code ASC, "effective_date" DESC) n
  183.     ORDER BY rate ASC, quality DESC, reliability DESC
  184. 2018-10-31 23:05:59.154864 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  185. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ------------------  No of routes found: 1  ------------------
  186. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ------->                   lcr_profile: lc
  187. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ------->     lcr_allow_negative_profit: 1.00
  188.  
  189. 2018-10-31 23:05:59.154864 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  190. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 SELECT lead_strip, tail_strip, add_prefix, add_suffix, terminator_id
  191.         FROM routing_providernumbertranslation
  192.         WHERE routing_providernumbertranslation.terminator_id = '5465400089730286' AND substring('27112340142',1,length(lead_strip)) = lead_strip
  193. 2018-10-31 23:05:59.154864 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  194. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 -----------------------  Route [1 of 1 ] -----------------------
  195. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->             lcr_code[1]: 2711
  196. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 -------> lcr_destination_name[1]: SA National_2711
  197. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_connect_fee[1]: 0.00000
  198. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->             lcr_rate[1]: 0.16000
  199. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->     lcr_rate_minimum[1]: 1
  200. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->   lcr_rate_increment[1]: 1
  201. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->           lcr_prefix[1]:  
  202. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_tariff_plan[1]: PROVIDER_CONVERGED
  203. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->       lcr_carrier_id[1]: 5465400089730286
  204. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->   lcr_effective_date[1]: 2018-10-19 02:03:38
  205. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_expiry_date[1]: 2028-10-19 02:03:38
  206. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 ------->          lcr_enabled[1]: 1
  207. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ------------------------------------------------------------------  
  208.  
  209. 2018-10-31 23:05:59.154864 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('sip_h_X-cid', 'VKIb38GZLc1WMqeQtT0RwA..')
  210. 2018-10-31 23:05:59.154864 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: sip_h_X-cid VKIb38GZLc1WMqeQtT0RwA..<-------------
  211. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ----------> Call progressing through the diaplan <----------
  212.  
  213. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 --------------------- Customer rate: 0.4
  214. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ----------- Negative profit allowed: 1.00%
  215. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 ---- Maximum provider rate for call: 0.404
  216.  
  217. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za limit(hash sbc.brightnetworks.co.za 27104760604 20 5/1 !CLIENT_LIMIT_EXCEEDED)
  218. 2018-10-31 23:05:59.154864 [DEBUG] switch_limit.c:126 incr called: sbc.brightnetworks.co.za_27104760604 max:20, interval:0
  219. 2018-10-31 23:05:59.154864 [DEBUG] mod_hash.c:196 Usage for sbc.brightnetworks.co.za_27104760604 is now 1/20
  220. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 Limit for this client: 27104760604 is 20 Concurrent and 5 CPS <-----------
  221.  
  222. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 -------------> Provider_1 rate: 0.16000 <-----------
  223. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 <-------------------------------------------------->
  224. 2018-10-31 23:05:59.154864 [NOTICE] switch_cpp.cpp:1365 SELECT mc.account_code, mc.account_type, mc.orig_credit_limit, mb.balance_uuid
  225.             FROM management_client mc
  226.             INNER JOIN management_clientbalances mb ON mc.id = mb.client_id
  227.             WHERE mb.client_id = '5465400089730286' AND mb.balance_type = '*monetary' AND mb.weight=10 AND mb.enabled = 't'
  228.  
  229. 2018-10-31 23:05:59.154864 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  230. 2018-10-31 23:05:59.154864 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  231. 2018-10-31 23:05:59.154864 [INFO] switch_cpp.cpp:1365 -----------------> Trying LCR Route = 1 of 1 <-----------------
  232.  
  233. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(execute_on_answer=nibblebill adjust -0)
  234. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [execute_on_answer]=[nibblebill adjust -0]
  235. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:connect_fee=0.00000)
  236. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [connect_fee]=[0.00000]
  237. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:nibble_rate=0.16000)
  238. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [nibble_rate]=[0.16000]
  239. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:nibble_minimum=0.0026666666666667)
  240. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [nibble_minimum]=[0.0026666666666667]
  241. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:nibble_increment=1)
  242. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [nibble_increment]=[1]
  243. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:nibble_account=CCE9A0C3-B568-424A-A254-90474CED1E60)
  244. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [nibble_account]=[CCE9A0C3-B568-424A-A254-90474CED1E60]
  245. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_account=5428397474)
  246. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_account]=[5428397474]
  247. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_tenant=sbc.brightnetworks.co.za)
  248. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_tenant]=[sbc.brightnetworks.co.za]
  249. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_dept= )
  250. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_dept]=[ ]
  251. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_site= )
  252. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_site]=[ ]
  253. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_extension= )
  254. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_extension]=[ ]
  255. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_custom= )
  256. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_custom]=[ ]
  257. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_subject= )
  258. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_subject]=[ ]
  259. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_supplier= )
  260. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_supplier]=[ ]
  261. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_reqtype=POSTPAID)
  262. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_reqtype]=[POSTPAID]
  263. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:o_category=PROVIDER_CONVERGED)
  264. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [o_category]=[PROVIDER_CONVERGED]
  265. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:prefix=2711)
  266. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [prefix]=[2711]
  267. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:destination_name=SA National_2711)
  268. 2018-10-31 23:05:59.154864 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [destination_name]=[SA National_2711]
  269. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:destination_number=27112340142)
  270. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [destination_number]=[27112340142]
  271. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:tor=*voice)
  272. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [tor]=[*voice]
  273. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:nobal_amt=-30000)
  274. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [nobal_amt]=[-30000]
  275. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za nibblebill(heartbeat 60)
  276. 2018-10-31 23:05:59.174861 [WARNING] switch_core_session.c:1605 sofia/internal/27104760604@sbc.brightnetworks.co.za using scheduler due to bypass media or media is not established.
  277. 2018-10-31 23:05:59.174861 [DEBUG] switch_scheduler.c:249 Added task 8876727 switch_core_session_sched_heartbeat (145c3b64-b3d5-4d4d-acc9-9edffa54b8aa) to run at 1541020019
  278. 2018-10-31 23:05:59.174861 [DEBUG] switch_scheduler.c:144 Deleting task 8876726 switch_core_session_sched_heartbeat (145c3b64-b3d5-4d4d-acc9-9edffa54b8aa)
  279. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('execute_on_answer', 'sched_hangup +7200 allotted_timeout')
  280. 2018-10-31 23:05:59.174861 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: execute_on_answer sched_hangup +7200 allotted_timeout<-------------
  281. 2018-10-31 23:05:59.174861 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  282. 2018-10-31 23:05:59.174861 [NOTICE] switch_cpp.cpp:1365 SELECT name AS g_name, proxy, sip_cid_type, ignore_early_media, leg_timeout, channels, enabled
  283.     FROM management_providergateway g
  284.     WHERE id = '5465413257484362' AND enabled = 't'
  285. 2018-10-31 23:05:59.174861 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  286. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za limit(hash sbc.brightnetworks.co.za Bright-Converged 100!BEARERCAPABILITY_NOTAVAIL)
  287. 2018-10-31 23:05:59.174861 [DEBUG] switch_limit.c:126 incr called: sbc.brightnetworks.co.za_Bright-Converged max:100, interval:0
  288. 2018-10-31 23:05:59.174861 [DEBUG] mod_hash.c:196 Usage for sbc.brightnetworks.co.za_Bright-Converged is now 1/100
  289. 2018-10-31 23:05:59.174861 [INFO] switch_cpp.cpp:1365 Maximum concurrent calls for Gateway 1: Bright-Converged = 100 <-----------
  290.  
  291. 2018-10-31 23:05:59.174861 [INFO] switch_cpp.cpp:1365 Now Bridging the call to ...[originate_continue_on_timeout=true,sip_cid_type=pid,ignore_early_media=false][leg_progress_timeout=20]sofia/gateway/Bright-Converged/27112340142 <-----------
  292.  
  293. 2018-10-31 23:05:59.174861 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  294. 2018-10-31 23:05:59.174861 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  295. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('effective_caller_id_name', '27104760604')
  296. 2018-10-31 23:05:59.174861 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: effective_caller_id_name 27104760604<-------------
  297. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('effective_caller_id_number', '27104760604')
  298. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('call_direction', 'outbound')
  299. 2018-10-31 23:05:59.174861 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: call_direction outbound<-------------
  300. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('continue_on_fail', 'true')
  301. 2018-10-31 23:05:59.174861 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: continue_on_fail true<-------------
  302. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('hangup_after_bridge', 'true')
  303. 2018-10-31 23:05:59.174861 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: hangup_after_bridge true<-------------
  304. 2018-10-31 23:05:59.174861 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('ignore_display_updates', 'true')
  305. 2018-10-31 23:05:59.174861 [WARNING] switch_cpp.cpp:1365 ------->145c3b64-b3d5-4d4d-acc9-9edffa54b8aa - WS CALL Set value :.....: ignore_display_updates true<-------------
  306. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(codec_string=G729,PCMA)
  307. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [codec_string]=[G729,PCMA]
  308. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(nolocal:absolute_codec_string=G729,PCMA)
  309. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[G729,PCMA]
  310. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(fax_enable_t38_request=true)
  311. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [fax_enable_t38_request]=[true]
  312. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za export(fax_enable_t38=true)
  313. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [fax_enable_t38]=[true]
  314. EXECUTE sofia/internal/27104760604@sbc.brightnetworks.co.za bridge([originate_continue_on_timeout=true,sip_cid_type=pid,ignore_early_media=false][leg_progress_timeout=20]sofia/gateway/Bright-Converged/27112340142)
  315. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [execute_on_answer]=[sched_hangup +7200 allotted_timeout] to event
  316. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [execute_on_answer]=[sched_hangup +7200 allotted_timeout] to event
  317. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [connect_fee]=[0.00000] to event
  318. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [nibble_rate]=[0.16000] to event
  319. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [nibble_minimum]=[0.0026666666666667] to event
  320. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [nibble_increment]=[1] to event
  321. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [nibble_account]=[CCE9A0C3-B568-424A-A254-90474CED1E60] to event
  322. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_account]=[5428397474] to event
  323. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_tenant]=[sbc.brightnetworks.co.za] to event
  324. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_dept]=[ ] to event
  325. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_site]=[ ] to event
  326. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_extension]=[ ] to event
  327. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_custom]=[ ] to event
  328. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_subject]=[ ] to event
  329. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_supplier]=[ ] to event
  330. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_reqtype]=[POSTPAID] to event
  331. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [o_category]=[PROVIDER_CONVERGED] to event
  332. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [prefix]=[2711] to event
  333. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [destination_name]=[SA National_2711] to event
  334. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [destination_number]=[27112340142] to event
  335. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [tor]=[*voice] to event
  336. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [nobal_amt]=[-30000] to event
  337. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [codec_string]=[G729,PCMA] to event
  338. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [absolute_codec_string]=[G729,PCMA] to event
  339. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [fax_enable_t38_request]=[true] to event
  340. 2018-10-31 23:05:59.174861 [DEBUG] switch_channel.c:1250 sofia/internal/27104760604@sbc.brightnetworks.co.za EXPORTING[export_vars] [fax_enable_t38]=[true] to event
  341. 2018-10-31 23:05:59.174861 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  342. 2018-10-31 23:05:59.174861 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
  343. 2018-10-31 23:05:59.174861 [NOTICE] switch_channel.c:1104 New Channel sofia/external/27112340142 [7734e05b-cb41-4986-bb14-15db1f8f000b]
  344. 2018-10-31 23:05:59.174861 [DEBUG] mod_sofia.c:4819 (sofia/external/27112340142) State Change CS_NEW -> CS_INIT
  345. 2018-10-31 23:05:59.174861 [DEBUG] switch_ivr_originate.c:2972 sofia/external/27112340142 Setting leg progress timeout to 20
  346. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:584 (sofia/external/27112340142) Running State Change CS_INIT (Cur 10 Tot 3729051)
  347. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:627 (sofia/external/27112340142) State INIT
  348. 2018-10-31 23:05:59.174861 [DEBUG] mod_sofia.c:90 sofia/external/27112340142 SOFIA INIT
  349. 2018-10-31 23:05:59.174861 [DEBUG] sofia_glue.c:1295 sofia/external/27112340142 sending invite version: 1.6.20 -37-987c9b9 64bit
  350. Local SDP:
  351. v=0
  352. o=cgrtbilling 1540999701 1540999702 IN IP4 154.118.252.36
  353. s=cgrtbilling
  354. c=IN IP4 154.118.252.36
  355. t=0 0
  356. m=audio 20258 RTP/AVP 18 8 101
  357. a=rtpmap:18 G729/8000
  358. a=fmtp:18 annexb=no
  359. a=rtpmap:8 PCMA/8000
  360. a=rtpmap:101 telephone-event/8000
  361. a=fmtp:101 0-16
  362. a=silenceSupp:off - - - -
  363. a=ptime:20
  364. a=sendrecv
  365.  
  366. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:40 sofia/external/27112340142 Standard INIT
  367. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:48 (sofia/external/27112340142) State Change CS_INIT -> CS_ROUTING
  368. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:627 (sofia/external/27112340142) State INIT going to sleep
  369. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:584 (sofia/external/27112340142) Running State Change CS_ROUTING (Cur 10 Tot 3729051)
  370. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:7084 Channel sofia/external/27112340142 entering state [calling][0]
  371. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:643 (sofia/external/27112340142) State ROUTING
  372. 2018-10-31 23:05:59.174861 [DEBUG] mod_sofia.c:143 sofia/external/27112340142 SOFIA ROUTING
  373. 2018-10-31 23:05:59.174861 [DEBUG] switch_ivr_originate.c:67 (sofia/external/27112340142) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  374. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.16000 per minute to account CCE9A0C3-B568-424A-A254-90474CED1E60
  375. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:518 Not billing CCE9A0C3-B568-424A-A254-90474CED1E60 - call is not in answered state
  376. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  377. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='CCE9A0C3-B568-424A-A254-90474CED1E60']
  378. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account CCE9A0C3-B568-424A-A254-90474CED1E60 (balance = -774.072176)
  379. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:523 Comparing -774.072176 to hangup balance of -30000.000000, taking into account minimum charge of 0.002667
  380. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  381. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='CCE9A0C3-B568-424A-A254-90474CED1E60']
  382. 2018-10-31 23:05:59.174861 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/27104760604@sbc.convergedgroup.co.za [f892355f-e010-46db-a054-dee5a15cf95f]
  383. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_NEW (Cur 11 Tot 3729052)
  384. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:9873 sofia/internal/27104760604@sbc.convergedgroup.co.za receiving invite from 154.118.252.35:5060 version: 1.6.20 -37-987c9b9 64bit
  385. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:9999 1 acls to check for proxy
  386. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:10004 checking 154.118.252.35 against acl proxies
  387. 2018-10-31 23:05:59.174861 [INFO] sofia.c:10006 154.118.252.35 is a proxy according to the proxies acl
  388. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:10016 network ip is a proxy
  389. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [154.118.252.248]
  390. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [154.118.252.35]
  391. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:10044 IP 154.118.252.35 Rejected by acl "domains". Falling back to Digest auth.
  392. 2018-10-31 23:05:59.174861 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [27112340142@sbc.convergedgroup.co.za] from ip 154.118.252.35
  393. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State NEW
  394. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account CCE9A0C3-B568-424A-A254-90474CED1E60 (balance = -774.072176)
  395. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:643 (sofia/external/27112340142) State ROUTING going to sleep
  396. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:2334 detaching session f892355f-e010-46db-a054-dee5a15cf95f
  397. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:584 (sofia/external/27112340142) Running State Change CS_CONSUME_MEDIA (Cur 11 Tot 3729052)
  398. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:662 (sofia/external/27112340142) State CONSUME_MEDIA
  399. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.16000 per minute to account CCE9A0C3-B568-424A-A254-90474CED1E60
  400. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:518 Not billing CCE9A0C3-B568-424A-A254-90474CED1E60 - call is not in answered state
  401. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  402. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='CCE9A0C3-B568-424A-A254-90474CED1E60']
  403. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account CCE9A0C3-B568-424A-A254-90474CED1E60 (balance = -774.072176)
  404. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:523 Comparing -774.072176 to hangup balance of -30000.000000, taking into account minimum charge of 0.002667
  405. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  406. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='CCE9A0C3-B568-424A-A254-90474CED1E60']
  407. 2018-10-31 23:05:59.174861 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account CCE9A0C3-B568-424A-A254-90474CED1E60 (balance = -774.072176)
  408. 2018-10-31 23:05:59.174861 [WARNING] switch_core_session.c:1605 sofia/external/27112340142 using scheduler due to bypass media or media is not established.
  409. 2018-10-31 23:05:59.174861 [DEBUG] switch_scheduler.c:249 Added task 8876728 switch_core_session_sched_heartbeat (7734e05b-cb41-4986-bb14-15db1f8f000b) to run at 1541019989
  410. 2018-10-31 23:05:59.174861 [DEBUG] switch_core_state_machine.c:662 (sofia/external/27112340142) State CONSUME_MEDIA going to sleep
  411. 2018-10-31 23:05:59.174861 [DEBUG] sofia.c:7084 Channel sofia/external/27112340142 entering state [calling][0]
  412. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:2442 Re-attaching to session f892355f-e010-46db-a054-dee5a15cf95f
  413. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:9873 sofia/internal/27104760604@sbc.convergedgroup.co.za receiving invite from 154.118.252.35:5060 version: 1.6.20 -37-987c9b9 64bit
  414. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:9999 1 acls to check for proxy
  415. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:10004 checking 154.118.252.35 against acl proxies
  416. 2018-10-31 23:05:59.194860 [INFO] sofia.c:10006 154.118.252.35 is a proxy according to the proxies acl
  417. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:10016 network ip is a proxy
  418. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [154.118.252.248]
  419. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [154.118.252.35]
  420. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:10044 IP 154.118.252.35 Rejected by acl "domains". Falling back to Digest auth.
  421. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:7084 Channel sofia/internal/27104760604@sbc.convergedgroup.co.za entering state [received][100]
  422. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:7094 Remote SDP:
  423. v=0
  424. o=cgrtbilling 1540999701 1540999702 IN IP4 154.118.252.36
  425. s=cgrtbilling
  426. c=IN IP4 154.118.252.36
  427. t=0 0
  428. m=audio 20258 RTP/AVP 18 8 101
  429. a=rtpmap:18 G729/8000
  430. a=fmtp:18 annexb=no
  431. a=rtpmap:8 PCMA/8000
  432. a=rtpmap:101 telephone-event/8000
  433. a=fmtp:101 0-16
  434. a=silenceSupp:off - - - -
  435. a=ptime:20
  436.  
  437. 2018-10-31 23:05:59.194860 [DEBUG] sofia.c:7486 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State Change CS_NEW -> CS_INIT
  438. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_INIT (Cur 11 Tot 3729052)
  439. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State INIT
  440. 2018-10-31 23:05:59.194860 [DEBUG] mod_sofia.c:90 sofia/internal/27104760604@sbc.convergedgroup.co.za SOFIA INIT
  441. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:40 sofia/internal/27104760604@sbc.convergedgroup.co.za Standard INIT
  442. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State Change CS_INIT -> CS_ROUTING
  443. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State INIT going to sleep
  444. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_ROUTING (Cur 11 Tot 3729052)
  445. 2018-10-31 23:05:59.194860 [DEBUG] switch_channel.c:2249 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Callstate Change DOWN -> RINGING
  446. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State ROUTING
  447. 2018-10-31 23:05:59.194860 [DEBUG] mod_sofia.c:143 sofia/internal/27104760604@sbc.convergedgroup.co.za SOFIA ROUTING
  448. 2018-10-31 23:05:59.194860 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  449. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='8c261155-c5ff-449f-8b4d-382c0c916647']
  450. 2018-10-31 23:05:59.194860 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account 8c261155-c5ff-449f-8b4d-382c0c916647 (balance = -196.236180)
  451. 2018-10-31 23:05:59.194860 [DEBUG] switch_core_state_machine.c:236 sofia/internal/27104760604@sbc.convergedgroup.co.za Standard ROUTING
  452. 2018-10-31 23:05:59.194860 [INFO] mod_dialplan_xml.c:637 Processing 27104760604 <27104760604>->27112340142 in context cgrtbilling
  453. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za parsing [cgrtbilling->unloop] continue=false
  454. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
  455. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
  456. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za parsing [cgrtbilling->call_debug] continue=true
  457. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
  458. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za parsing [cgrtbilling->block_account] continue=false
  459. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (FAIL) [block_account] destination_number(27112340142) =~ /^(block_account)$/ break=on-false
  460. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za parsing [cgrtbilling->check_auth] continue=true
  461. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (PASS) [check_auth] ${sip_authorized}(true) =~ /^true$/ break=never
  462. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za parsing [cgrtbilling->calls_from_converged] continue=true
  463. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (PASS) [calls_from_converged] ${sip_req_host}(sbc.convergedgroup.co.za) =~ /^sbc.convergedgroup.co.za$/ break=on-false
  464. |--- Dialplan: Processing recursive conditions level:1 [calls_from_converged_recur_1] require-nested=TRUE
  465. |--- Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (PASS) [calls_from_converged_recur_1] destination_number(27112340142) =~ /^(.*)$/ break=on-false
  466. |--- Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action translate(${destination_number} sbc.convergedgroup.co.za-za)
  467. |--- Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action set(destination_number=${translated})
  468. |--- Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action set(outside_call=true)
  469. |--- Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action set(lnp_dest_num=${lua(cgrtbilling/sa_lnp_lookup.lua ${destination_number})})
  470. |--- Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action lua(cgrtbilling/cgrtbilling_v2.luac)
  471. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za parsing [cgrtbilling->calls_from_tenants] continue=true
  472. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Regex (PASS) [calls_from_tenants] destination_number(27112340142) =~ /^(.*)$/ break=on-false
  473. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action translate(${destination_number} sbc.convergedgroup.co.za-za)
  474. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action set(destination_number=${translated})
  475. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action set(outside_call=true)
  476. Dialplan: sofia/internal/27104760604@sbc.convergedgroup.co.za Action lua(cgrtbilling/cgrtbilling_v2.luac)
  477. 2018-10-31 23:05:59.214860 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State Change CS_ROUTING -> CS_EXECUTE
  478. 2018-10-31 23:05:59.214860 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State ROUTING going to sleep
  479. 2018-10-31 23:05:59.214860 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_EXECUTE (Cur 11 Tot 3729052)
  480. 2018-10-31 23:05:59.214860 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State EXECUTE
  481. 2018-10-31 23:05:59.214860 [DEBUG] mod_sofia.c:198 sofia/internal/27104760604@sbc.convergedgroup.co.za SOFIA EXECUTE
  482. 2018-10-31 23:05:59.214860 [DEBUG] switch_core_state_machine.c:328 sofia/internal/27104760604@sbc.convergedgroup.co.za Standard EXECUTE
  483. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za translate(27112340142 sbc.convergedgroup.co.za-za)
  484. 2018-10-31 23:05:59.214860 [DEBUG] mod_translate.c:128 translating [27112340142] against [sbc.convergedgroup.co.za-za] profile
  485. 2018-10-31 23:05:59.214860 [DEBUG] mod_translate.c:137 27112340142 =~ /^\+(\d+)$/
  486. 2018-10-31 23:05:59.214860 [DEBUG] mod_translate.c:137 27112340142 =~ /^(00\d{9,17})$/
  487. 2018-10-31 23:05:59.214860 [DEBUG] mod_translate.c:137 27112340142 =~ /^0(\d+)$/
  488. 2018-10-31 23:05:59.214860 [DEBUG] mod_translate.c:137 27112340142 =~ /^(1\d{3,4})$/
  489. 2018-10-31 23:05:59.214860 [DEBUG] mod_translate.c:137 27112340142 =~ /^(27\d{9})$/
  490. 2018-10-31 23:05:59.214860 [NOTICE] mod_translate.c:249 Translated: 27112340142
  491. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za set(destination_number=27112340142)
  492. 2018-10-31 23:05:59.214860 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27104760604@sbc.convergedgroup.co.za [destination_number]=[27112340142]
  493. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za set(outside_call=true)
  494. 2018-10-31 23:05:59.214860 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27104760604@sbc.convergedgroup.co.za [outside_call]=[true]
  495. 2018-10-31 23:05:59.214860 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f4636e58500 Connected.
  496. 2018-10-31 23:05:59.234877 [NOTICE] switch_cpp.cpp:1365 The number was ported to CTEL with DCode D005
  497.  
  498. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('lnp_enabled', 'true')
  499. 2018-10-31 23:05:59.234877 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f4636e58500 released.
  500. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:1112 sofia/internal/27104760604@sbc.convergedgroup.co.za destroy/unlink session from object
  501. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za set(lnp_dest_num=D00527112340142)
  502. 2018-10-31 23:05:59.234877 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27104760604@sbc.convergedgroup.co.za [lnp_dest_num]=[D00527112340142]
  503. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za lua(cgrtbilling/cgrtbilling_v2.luac)
  504. 2018-10-31 23:05:59.234877 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  505. 2018-10-31 23:05:59.234877 [INFO] switch_cpp.cpp:1365 Destination_number: 27112340142<-----------
  506.  
  507. 2018-10-31 23:05:59.234877 [NOTICE] switch_cpp.cpp:1365 SELECT mc.id, mc.name, mc.account_type, mc.account_code, b.balance_uuid, b.value as balance, t.name as tenant,
  508.     mc.origination, mc.orig_credit_limit, mc.max_per_minute_rate as max_rate, mc.max_daily_spend, mc.play_audio_messages as play_msgs,
  509.     mc.orig_max_channels as max_channels, mc.orig_max_cps as max_cps, tc.max_call_length as max_duration, mc.enable_calls, mc.enabled
  510.     FROM management_client mc
  511.     INNER JOIN management_tenant t ON t.id = mc.tenant_id
  512.     INNER JOIN management_tenantconfiguration tc ON ( t.id = tc.tenant_id )
  513.     INNER JOIN management_clientbalances b ON mc.id = b.client_id
  514.     WHERE mc.account_code = '7915106451' AND b.balance_type = '*monetary' AND weight = '10'
  515. 2018-10-31 23:05:59.234877 [WARNING] switch_cpp.cpp:1365 <------- Getting Account Info for Client: Bright Networks with account_code: 7915106451 ------->
  516.  
  517. 2018-10-31 23:05:59.234877 [NOTICE] switch_cpp.cpp:1365 SELECT mc.account_code, s.username, s.password, s.ip_address, s.caller_id_name as cid_name, s.caller_id_number as cid_number,
  518.     s.bypass_media as bymedia, s.pass_thru_caller_id, s.custom_sip_headers, c1.description as c1, c2.description as c2,
  519.     c3.description as c3, c4.description as c4, s.enabled
  520.     FROM management_sipaccount s
  521.     INNER JOIN management_client mc ON s.client_id = mc.id
  522.     LEFT OUTER JOIN configuration_codecpreference c1 ON s.codec1_id = c1.id
  523.     LEFT OUTER JOIN configuration_codecpreference c2 ON s.codec2_id = c2.id
  524.     LEFT OUTER JOIN configuration_codecpreference c3 ON s.codec3_id = c3.id
  525.     LEFT OUTER JOIN configuration_codecpreference c4 ON s.codec4_id = c4.id
  526.     WHERE  mc.id = '5458337077370540' AND s.username = 'brightnetworks'AND s.enabled = 't'
  527. 2018-10-31 23:05:59.234877 [WARNING] switch_cpp.cpp:1365 elapsed time: 0.000969
  528.  
  529. 2018-10-31 23:05:59.234877 [WARNING] switch_cpp.cpp:1365 -------------> Geting Client Tariff Plan info ------------->
  530.  
  531. 2018-10-31 23:05:59.234877 [NOTICE] switch_cpp.cpp:1365 SELECT mt.tech_prefix, mt.tpb_id, t.name as tpb_name, mt.routing_plan_id, r.routing_type, r.allow_negative_profit
  532.       FROM management_tpballocation mt
  533.       INNER JOIN management_client mc ON mt.client_id = mc.id
  534.       INNER JOIN routing_routingplan r ON mt.routing_plan_id = r.id
  535.       INNER JOIN tariff_plans_tpb t ON t.id = mt.tpb_id
  536.       WHERE mc.account_code = '7915106451'
  537. 2018-10-31 23:05:59.234877 [INFO] switch_cpp.cpp:1365 <----------------------------------------------------->
  538. 2018-10-31 23:05:59.234877 [INFO] switch_cpp.cpp:1365 Trying without tech prefix
  539. 2018-10-31 23:05:59.234877 [INFO] switch_cpp.cpp:1365 Dialed number : 27112340142
  540. 2018-10-31 23:05:59.234877 [INFO] switch_cpp.cpp:1365 Tariff Plan Name : RESELLER_PLUS7
  541. 2018-10-31 23:05:59.234877 [INFO] switch_cpp.cpp:1365 <----------------------------------------------------->
  542.  
  543. 2018-10-31 23:05:59.234877 [WARNING] switch_cpp.cpp:1365 ------------  Getting Call cost for client  ------------
  544.  
  545. 2018-10-31 23:05:59.234877 [NOTICE] switch_cpp.cpp:1365 SELECT tp.code, tp.destination_name, tp.connect_fee, tp.rate, tp.rate_minimum, tp.rate_increment, tp.effective_date, tp.expiry_date, tp.enabled
  546.     FROM tariff_plans_rates tp
  547.     WHERE code @> '27112340142' AND tpb_id = '5458313715722524' AND tp.effective_date <= tp.expiry_date AND tp.expiry_date >= now()
  548.     ORDER BY CODE ASC LIMIT 1
  549. 2018-10-31 23:05:59.234877 [NOTICE] switch_cpp.cpp:1365 Code: 2711
  550. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za export(execute_on_answer=nibblebill adjust -0)
  551. 2018-10-31 23:05:59.234877 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [execute_on_answer]=[nibblebill adjust -0]
  552. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('connect_fee', '0')
  553. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_rate', '0.16')
  554. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_minimum', '0.0026666666666667')
  555. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_increment', '1')
  556. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nibble_account', '8C261155-C5FF-449F-8B4D-382C0C916647')
  557. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_account', '7915106451')
  558. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('client_id', '5458337077370540')
  559. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_tenant', 'sbc.convergedgroup.co.za')
  560. 2018-10-31 23:05:59.234877 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('nobal_amt', '-50000')
  561. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za nibblebill(heartbeat 60)
  562. 2018-10-31 23:05:59.254857 [WARNING] switch_core_session.c:1605 sofia/internal/27104760604@sbc.convergedgroup.co.za using scheduler due to bypass media or media is not established.
  563. 2018-10-31 23:05:59.254857 [DEBUG] switch_scheduler.c:249 Added task 8876729 switch_core_session_sched_heartbeat (f892355f-e010-46db-a054-dee5a15cf95f) to run at 1541020019
  564. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_dept', ' ')
  565. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_site', ' ')
  566. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_extension', ' ')
  567. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_custom', ' ')
  568. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_subject', ' ')
  569. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_supplier', ' ')
  570. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_reqtype', 'POSTPAID')
  571. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('o_category', 'RESELLER_PLUS7')
  572. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('prefix', '2711')
  573. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('destination_name', 'SA National_2711')
  574. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('destination_number', '27112340142')
  575. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('tor', '*voice')
  576. 2018-10-31 23:05:59.254857 [WARNING] switch_cpp.cpp:1365 -------------> Removing unwanted SIP Headers ------------->
  577.  
  578. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za unset(sip_h_X-accountcode)
  579. 2018-10-31 23:05:59.254857 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-accountcode]
  580. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za unset(sip_h_X-username)
  581. 2018-10-31 23:05:59.254857 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-username]
  582. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za unset(sip_h_X-extension)
  583. 2018-10-31 23:05:59.254857 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-extension]
  584. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za unset(sip_h_X-dept)
  585. 2018-10-31 23:05:59.254857 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-dept]
  586. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za unset(sip_h_X-site)
  587. 2018-10-31 23:05:59.254857 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-site]
  588. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za unset(sip_h_X-custom)
  589. 2018-10-31 23:05:59.254857 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-custom]
  590. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 Checking if 27112340142 is a DID <-------------
  591. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 SELECT status from management_did where did_number = '27112340142' and status != 'ported_out'
  592. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  593. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  594. 2018-10-31 23:05:59.254857 [WARNING] switch_cpp.cpp:1365 ------------  Getting LCR info  ------------
  595.  
  596. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 SELECT *
  597.     FROM (SELECT DISTINCT ON (t.name) t.name as tariff_plan, rt.id AS rt_id, r.code, r.destination_name, r.connect_fee, r.rate, r.rate_minimum, r.rate_increment,
  598.     t.prefix, t.suffix, t.quality, t.reliability, t.client_id AS carrier_id, r.effective_date, r.expiry_date, t.gw1_id, t.gw2_id, t.gw3_id, r.enabled
  599.     FROM tariff_plans_rates r
  600.     INNER JOIN tariff_plans_tpb t ON r.tpb_id = t.id
  601.     INNER JOIN routing_routingplantariff rt ON rt.tariff_plan_id = t.id
  602.     WHERE rt.routing_plan_id = '5160625866222829' AND code @> 'D00527112340142' AND enabled = 't' AND (CURRENT_TIMESTAMP BETWEEN r.effective_date AND r.expiry_date)
  603.     ORDER BY t.name, code ASC, "effective_date" DESC) n
  604.     ORDER BY rate ASC, quality DESC, reliability DESC
  605. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  606. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ------------------  No of routes found: 2  ------------------
  607. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ------->                   lcr_profile: lc
  608. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ------->     lcr_allow_negative_profit: 0.00
  609.  
  610. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  611. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 SELECT lead_strip, tail_strip, add_prefix, add_suffix, terminator_id
  612.         FROM routing_providernumbertranslation
  613.         WHERE routing_providernumbertranslation.terminator_id = '946479979601305' AND substring('D00527112340142',1,length(lead_strip)) = lead_strip
  614. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  615. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365   <-------------- OK! There is a match -------------->
  616. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365   Dialed Number: [D00527112340142] <-----------
  617. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365      Lead Strip: [D00527] <-----------
  618. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365      Add Prefix: [D0050] <-----------
  619. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365   <-------------------------------------------------->
  620.  
  621. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365   Number Translated to: [D0050112340142] <-----------
  622.  
  623. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 -----------------------  Route [1 of 2 ] -----------------------
  624. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->             lcr_code[1]: D005
  625. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 -------> lcr_destination_name[1]: CTEL
  626. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_connect_fee[1]: 0.00000
  627. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->             lcr_rate[1]: 0.18000
  628. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->     lcr_rate_minimum[1]: 1
  629. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->   lcr_rate_increment[1]: 1
  630. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->           lcr_prefix[1]:  
  631. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_tariff_plan[1]: TELKOM_NAT
  632. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->       lcr_carrier_id[1]: 946479979601305
  633. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->   lcr_effective_date[1]: 2017-09-24 21:50:00
  634. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_expiry_date[1]: 2027-09-24 21:50:00
  635. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->          lcr_enabled[1]: 1
  636. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ------------------------------------------------------------------  
  637.  
  638. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  639. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 SELECT lead_strip, tail_strip, add_prefix, add_suffix, terminator_id
  640.         FROM routing_providernumbertranslation
  641.         WHERE routing_providernumbertranslation.terminator_id = '937975527397526' AND substring('D00527112340142',1,length(lead_strip)) = lead_strip
  642. 2018-10-31 23:05:59.254857 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  643. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365   <-------------- OK! There is a match -------------->
  644. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365   Dialed Number: [D00527112340142] <-----------
  645. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365      Lead Strip: [D00527] <-----------
  646. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365      Add Prefix: [27] <-----------
  647. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365   <-------------------------------------------------->
  648.  
  649. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365   Number Translated to: [27112340142] <-----------
  650.  
  651. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 -----------------------  Route [2 of 2 ] -----------------------
  652. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->             lcr_code[2]: D005
  653. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 -------> lcr_destination_name[2]: CTEL
  654. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_connect_fee[2]: 0.00000
  655. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->             lcr_rate[2]: 0.28000
  656. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->     lcr_rate_minimum[2]: 1
  657. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->   lcr_rate_increment[2]: 1
  658. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->           lcr_prefix[2]:  
  659. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_tariff_plan[2]: LIQUIDTEL_NAT
  660. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->       lcr_carrier_id[2]: 937975527397526
  661. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->   lcr_effective_date[2]: 2017-09-24 21:50:39.307041
  662. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->      lcr_expiry_date[2]: 2027-09-24 21:50:40.264676
  663. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:1365 ------->          lcr_enabled[2]: 1
  664. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ------------------------------------------------------------------  
  665.  
  666. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('sip_h_X-cid', '9b7708e8-57f3-1237-8b97-002590ebc304')
  667. 2018-10-31 23:05:59.254857 [WARNING] switch_cpp.cpp:1365 ------->f892355f-e010-46db-a054-dee5a15cf95f - WS CALL Set value :.....: sip_h_X-cid 9b7708e8-57f3-1237-8b97-002590ebc304<-------------
  668. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ----------> Call progressing through the diaplan <----------
  669.  
  670. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 --------------------- Customer rate: 0.16
  671. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ----------- Negative profit allowed: 0.00%
  672. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 ---- Maximum provider rate for call: 0.16
  673.  
  674. EXECUTE sofia/internal/27104760604@sbc.convergedgroup.co.za limit(hash sbc.convergedgroup.co.za brightnetworks 30 5/1 !CLIENT_LIMIT_EXCEEDED)
  675. 2018-10-31 23:05:59.254857 [DEBUG] switch_limit.c:126 incr called: sbc.convergedgroup.co.za_brightnetworks max:30, interval:0
  676. 2018-10-31 23:05:59.254857 [DEBUG] mod_hash.c:196 Usage for sbc.convergedgroup.co.za_brightnetworks is now 1/30
  677. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 Limit for this client: brightnetworks is 30 Concurrent and 5 CPS <-----------
  678.  
  679. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 -------------> Provider_1 rate: 0.18000 <-----------
  680. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 <-------------------------------------------------->
  681. 2018-10-31 23:05:59.254857 [ALERT] switch_cpp.cpp:1365 ------ Rate is more than maximum allowed rate of: 0.16 ------
  682.  
  683. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 -------------> Provider_2 rate: 0.28000 <-----------
  684. 2018-10-31 23:05:59.254857 [INFO] switch_cpp.cpp:1365 <-------------------------------------------------->
  685. 2018-10-31 23:05:59.254857 [ALERT] switch_cpp.cpp:1365 ------ Rate is more than maximum allowed rate of: 0.16 ------
  686.  
  687. 2018-10-31 23:05:59.254857 [WARNING] switch_cpp.cpp:1365 ------ Looks like we ran out of routes to try ------
  688.  
  689. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable('proto_specific_hangup_cause', 'sip:503')
  690. 2018-10-31 23:05:59.254857 [WARNING] switch_cpp.cpp:1365 ------->f892355f-e010-46db-a054-dee5a15cf95f - WS CALL Set value :.....: proto_specific_hangup_cause sip:503<-------------
  691. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:721 CoreSession::hangup
  692. 2018-10-31 23:05:59.254857 [NOTICE] switch_cpp.cpp:723 Hangup sofia/internal/27104760604@sbc.convergedgroup.co.za [CS_EXECUTE] [BEARERCAPABILITY_NOTAVAIL]
  693. 2018-10-31 23:05:59.254857 [DEBUG] mod_hash.c:297 Usage for sbc.convergedgroup.co.za_brightnetworks is now 0
  694. 2018-10-31 23:05:59.254857 [DEBUG] switch_cpp.cpp:1112 sofia/internal/27104760604@sbc.convergedgroup.co.za destroy/unlink session from object
  695. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_session.c:2815 sofia/internal/27104760604@sbc.convergedgroup.co.za skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
  696. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State EXECUTE going to sleep
  697. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_HANGUP (Cur 11 Tot 3729052)
  698. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Callstate Change RINGING -> HANGUP
  699. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State HANGUP
  700. 2018-10-31 23:05:59.254857 [DEBUG] mod_sofia.c:438 Channel sofia/internal/27104760604@sbc.convergedgroup.co.za hanging up, cause: BEARERCAPABILITY_NOTAVAIL
  701. 2018-10-31 23:05:59.254857 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 503
  702. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.16 per minute to account 8C261155-C5FF-449F-8B4D-382C0C916647
  703. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:518 Not billing 8C261155-C5FF-449F-8B4D-382C0C916647 - call is not in answered state
  704. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  705. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='8C261155-C5FF-449F-8B4D-382C0C916647']
  706. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account 8C261155-C5FF-449F-8B4D-382C0C916647 (balance = -196.236180)
  707. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:523 Comparing -196.236180 to hangup balance of -50000.000000, taking into account minimum charge of 0.002667
  708. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  709. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='8C261155-C5FF-449F-8B4D-382C0C916647']
  710. 2018-10-31 23:05:59.254857 [DEBUG] sofia.c:7084 Channel sofia/external/27112340142 entering state [terminated][500]
  711. 2018-10-31 23:05:59.254857 [NOTICE] sofia.c:8273 Hangup sofia/external/27112340142 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
  712. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:584 (sofia/external/27112340142) Running State Change CS_HANGUP (Cur 11 Tot 3729052)
  713. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:850 (sofia/external/27112340142) Callstate Change DOWN -> HANGUP
  714. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account 8C261155-C5FF-449F-8B4D-382C0C916647 (balance = -196.236180)
  715. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:852 (sofia/external/27112340142) State HANGUP
  716. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:60 sofia/internal/27104760604@sbc.convergedgroup.co.za Standard HANGUP, cause: BEARERCAPABILITY_NOTAVAIL
  717. 2018-10-31 23:05:59.254857 [DEBUG] mod_sofia.c:438 Channel sofia/external/27112340142 hanging up, cause: NORMAL_TEMPORARY_FAILURE
  718. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State HANGUP going to sleep
  719. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State Change CS_HANGUP -> CS_REPORTING
  720. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.16000 per minute to account CCE9A0C3-B568-424A-A254-90474CED1E60
  721. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:518 Not billing CCE9A0C3-B568-424A-A254-90474CED1E60 - call is not in answered state
  722. 2018-10-31 23:05:59.254857 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  723. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='CCE9A0C3-B568-424A-A254-90474CED1E60']
  724. 2018-10-31 23:05:59.254857 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_REPORTING (Cur 11 Tot 3729052)
  725. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State REPORTING
  726. 2018-10-31 23:05:59.274854 [INFO] mod_json_cdr.c:271 Process [f892355f-e010-46db-a054-dee5a15cf95f.cdr.json]
  727. 2018-10-31 23:05:59.274854 [INFO] mod_json_cdr.c:275 Log to disk [/var/log/freeswitch/json_cdr/f892355f-e010-46db-a054-dee5a15cf95f.cdr.json]
  728. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:174 sofia/internal/27104760604@sbc.convergedgroup.co.za Standard REPORTING, cause: BEARERCAPABILITY_NOTAVAIL
  729. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State REPORTING going to sleep
  730. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account CCE9A0C3-B568-424A-A254-90474CED1E60 (balance = -774.072176)
  731. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:523 Comparing -774.072176 to hangup balance of -30000.000000, taking into account minimum charge of 0.002667
  732. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  733. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='CCE9A0C3-B568-424A-A254-90474CED1E60']
  734. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State Change CS_REPORTING -> CS_DESTROY
  735. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_session.c:1665 Session 3729052 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Locked, Waiting on external entities
  736. 2018-10-31 23:05:59.274854 [NOTICE] switch_core_session.c:1683 Session 3729052 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Ended
  737. 2018-10-31 23:05:59.274854 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/27104760604@sbc.convergedgroup.co.za [CS_DESTROY]
  738. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/27104760604@sbc.convergedgroup.co.za) Running State Change CS_DESTROY (Cur 10 Tot 3729052)
  739. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State DESTROY
  740. 2018-10-31 23:05:59.274854 [DEBUG] mod_sofia.c:343 sofia/internal/27104760604@sbc.convergedgroup.co.za SOFIA DESTROY
  741. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:181 sofia/internal/27104760604@sbc.convergedgroup.co.za Standard DESTROY
  742. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/27104760604@sbc.convergedgroup.co.za) State DESTROY going to sleep
  743. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account CCE9A0C3-B568-424A-A254-90474CED1E60 (balance = -774.072176)
  744. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:60 sofia/external/27112340142 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
  745. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:852 (sofia/external/27112340142) State HANGUP going to sleep
  746. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:619 (sofia/external/27112340142) State Change CS_HANGUP -> CS_REPORTING
  747. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:584 (sofia/external/27112340142) Running State Change CS_REPORTING (Cur 10 Tot 3729052)
  748. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:938 (sofia/external/27112340142) State REPORTING
  749. 2018-10-31 23:05:59.274854 [INFO] mod_json_cdr.c:271 Process [7734e05b-cb41-4986-bb14-15db1f8f000b.cdr.json]
  750. 2018-10-31 23:05:59.274854 [INFO] mod_json_cdr.c:275 Log to disk [/var/log/freeswitch/json_cdr/7734e05b-cb41-4986-bb14-15db1f8f000b.cdr.json]
  751. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:174 sofia/external/27112340142 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
  752. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:938 (sofia/external/27112340142) State REPORTING going to sleep
  753. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:610 (sofia/external/27112340142) State Change CS_REPORTING -> CS_DESTROY
  754. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_session.c:1665 Session 3729051 (sofia/external/27112340142) Locked, Waiting on external entities
  755. 2018-10-31 23:05:59.274854 [DEBUG] switch_ivr_originate.c:3848 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
  756. 2018-10-31 23:05:59.274854 [NOTICE] switch_core_session.c:1683 Session 3729051 (sofia/external/27112340142) Ended
  757. 2018-10-31 23:05:59.274854 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/27112340142 [CS_DESTROY]
  758. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:741 (sofia/external/27112340142) Running State Change CS_DESTROY (Cur 9 Tot 3729052)
  759. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:751 (sofia/external/27112340142) State DESTROY
  760. 2018-10-31 23:05:59.274854 [DEBUG] mod_sofia.c:343 sofia/external/27112340142 SOFIA DESTROY
  761. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:181 sofia/external/27112340142 Standard DESTROY
  762. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:751 (sofia/external/27112340142) State DESTROY going to sleep
  763. 2018-10-31 23:05:59.274854 [INFO] mod_dptools.c:3436 Originate Failed.  Cause: NORMAL_TEMPORARY_FAILURE
  764. 2018-10-31 23:05:59.274854 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f47adec6430 Connected.
  765. 2018-10-31 23:05:59.274854 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f47adec6430 released.
  766. 2018-10-31 23:05:59.274854 [WARNING] switch_cpp.cpp:1365 The call failed with NORMAL_TEMPORARY_FAILURE <-----------
  767.  
  768. 2018-10-31 23:05:59.274854 [DEBUG] switch_cpp.cpp:1112 sofia/internal/27104760604@sbc.brightnetworks.co.za destroy/unlink session from object
  769. 2018-10-31 23:05:59.274854 [NOTICE] switch_core_state_machine.c:385 sofia/internal/27104760604@sbc.brightnetworks.co.za has executed the last dialplan instruction, hanging up.
  770. 2018-10-31 23:05:59.274854 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/internal/27104760604@sbc.brightnetworks.co.za [CS_EXECUTE] [NORMAL_CLEARING]
  771. 2018-10-31 23:05:59.274854 [DEBUG] mod_hash.c:297 Usage for sbc.brightnetworks.co.za_Bright-Converged is now 0
  772. 2018-10-31 23:05:59.274854 [DEBUG] mod_hash.c:297 Usage for sbc.brightnetworks.co.za_27104760604 is now 0
  773. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State EXECUTE going to sleep
  774. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_HANGUP (Cur 9 Tot 3729052)
  775. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Callstate Change RINGING -> HANGUP
  776. 2018-10-31 23:05:59.274854 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State HANGUP
  777. 2018-10-31 23:05:59.274854 [DEBUG] mod_sofia.c:432 sofia/internal/27104760604@sbc.brightnetworks.co.za Overriding SIP cause 480 with 500 from the other leg
  778. 2018-10-31 23:05:59.274854 [DEBUG] mod_sofia.c:438 Channel sofia/internal/27104760604@sbc.brightnetworks.co.za hanging up, cause: NORMAL_CLEARING
  779. 2018-10-31 23:05:59.274854 [DEBUG] mod_sofia.c:577 Responding to INVITE with: 500
  780. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.4 per minute to account A6E32D84-0D4C-476A-A0A8-1F4B229027F6
  781. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:518 Not billing A6E32D84-0D4C-476A-A0A8-1F4B229027F6 - call is not in answered state
  782. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  783. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='A6E32D84-0D4C-476A-A0A8-1F4B229027F6']
  784. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account A6E32D84-0D4C-476A-A0A8-1F4B229027F6 (balance = -1098.533355)
  785. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:523 Comparing -1098.533355 to hangup balance of -5000.000000, taking into account minimum charge of 0.006667
  786. 2018-10-31 23:05:59.274854 [DEBUG] mod_nibblebill.c:422 Doing lookup query
  787. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='A6E32D84-0D4C-476A-A0A8-1F4B229027F6']
  788. 2018-10-31 23:05:59.294857 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account A6E32D84-0D4C-476A-A0A8-1F4B229027F6 (balance = -1098.533355)
  789. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:60 sofia/internal/27104760604@sbc.brightnetworks.co.za Standard HANGUP, cause: NORMAL_CLEARING
  790. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State HANGUP going to sleep
  791. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:619 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State Change CS_HANGUP -> CS_REPORTING
  792. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_REPORTING (Cur 9 Tot 3729052)
  793. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State REPORTING
  794. 2018-10-31 23:05:59.294857 [INFO] mod_json_cdr.c:271 Process [145c3b64-b3d5-4d4d-acc9-9edffa54b8aa.cdr.json]
  795. 2018-10-31 23:05:59.294857 [INFO] mod_json_cdr.c:275 Log to disk [/var/log/freeswitch/json_cdr/145c3b64-b3d5-4d4d-acc9-9edffa54b8aa.cdr.json]
  796. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:174 sofia/internal/27104760604@sbc.brightnetworks.co.za Standard REPORTING, cause: NORMAL_CLEARING
  797. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:938 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State REPORTING going to sleep
  798. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:610 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State Change CS_REPORTING -> CS_DESTROY
  799. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_session.c:1665 Session 3729050 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Locked, Waiting on external entities
  800. 2018-10-31 23:05:59.294857 [NOTICE] switch_core_session.c:1683 Session 3729050 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Ended
  801. 2018-10-31 23:05:59.294857 [NOTICE] switch_core_session.c:1687 Close Channel sofia/internal/27104760604@sbc.brightnetworks.co.za [CS_DESTROY]
  802. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:741 (sofia/internal/27104760604@sbc.brightnetworks.co.za) Running State Change CS_DESTROY (Cur 8 Tot 3729052)
  803. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State DESTROY
  804. 2018-10-31 23:05:59.294857 [DEBUG] mod_sofia.c:343 sofia/internal/27104760604@sbc.brightnetworks.co.za SOFIA DESTROY
  805. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:181 sofia/internal/27104760604@sbc.brightnetworks.co.za Standard DESTROY
  806. 2018-10-31 23:05:59.294857 [DEBUG] switch_core_state_machine.c:751 (sofia/internal/27104760604@sbc.brightnetworks.co.za) State DESTROY going to sleep
  807. 2018-10-31 23:05:59.754890 [DEBUG] switch_scheduler.c:144 Deleting task 8876727 switch_core_session_sched_heartbeat (145c3b64-b3d5-4d4d-acc9-9edffa54b8aa)
  808. 2018-10-31 23:05:59.754890 [DEBUG] switch_scheduler.c:144 Deleting task 8876728 switch_core_session_sched_heartbeat (7734e05b-cb41-4986-bb14-15db1f8f000b)
  809. 2018-10-31 23:05:59.754890 [DEBUG] switch_scheduler.c:144 Deleting task 8876729 switch_core_session_sched_heartbeat (f892355f-e010-46db-a054-dee5a15cf95f)
  810. freeswitch@freeswitch> /exit
  811.  
  812. root@fs01:~#
  813.  

Reply to "Untitled"