1. 2018-07-13 11:32:36.884237 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'internal' for [0114620900@sbc.convergedgroup.co.za] from ip 154.118.252.35
2. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.884237 [DEBUG] switch_core_state_machine.c:603 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State NEW
3. 2018-07-13 11:32:36.884237 [DEBUG] sofia.c:2334 detaching session c6f4bb20-baef-4b94-9d88-e4fdbbb674ec
4. 2018-07-13 11:32:36.884237 [DEBUG] sofia.c:2442 Re-attaching to session c6f4bb20-baef-4b94-9d88-e4fdbbb674ec
5. ce26ac42-68c4-4e92-87b1-6052ebabf94a 2018-07-13 11:32:36.904238 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
6. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:9873 sofia/internal/27105914607@sbc.convergedgroup.co.za receiving invite from 154.118.252.35:5060 version: 1.6.19 -36-7a77e0b 64bit
7. 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:9999 1 acls to check for proxy
8. 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:10004 checking 154.118.252.35 against acl proxies
9. 2018-07-13 11:32:36.904238 [INFO] sofia.c:10006 154.118.252.35 is a proxy according to the proxies acl
10. 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:10016 network ip is a proxy
11. 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:10020 found auth ip [X-Auth-IP] header of [10.192.0.82]
12. 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:10044 IP 154.118.252.35 Rejected by acl "domains". Falling back to Digest auth.
13. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:7084 Channel sofia/internal/27105914607@sbc.convergedgroup.co.za entering state [received][100]
14. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:7094 Remote SDP:
15. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec v=0
16. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec o=- 6577632273683585815 1 IN IP4 10.192.0.82
17. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec s=MX-ONE
18. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec c=IN IP4 10.192.0.82
19. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec t=0 0
20. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec m=audio 18554 RTP/AVP 18 101 13
21. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=rtpmap:18 G729/8000
22. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=fmtp:18 annexb=no
23. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=rtpmap:101 telephone-event/8000
24. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=rtpmap:13 CN/8000
25. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=ptime:20
26. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=sqn:0
27. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cdsc:1 image udptl t38
28. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cpar:a=T38FaxVersion:0
29. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cpar:a=T38MaxBitRate:14400
30. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cpar:a=T38FaxRateManagement:transferredTCF
31. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cpar:a=T38FaxMaxBuffer:9772
32. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cpar:a=T38FaxMaxDatagram:1472
33. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=cpar:a=T38FaxUdpEC:t38UDPRedundancy
34. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=silenceSupp:on - - - -
35. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=oldmediaip:192.168.16.199
36. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec a=oldmediaip:192.168.16.199
37. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec
38. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] sofia.c:7486 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State Change CS_NEW -> CS_INIT
39. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27105914607@sbc.convergedgroup.co.za) Running State Change CS_INIT (Cur 519 Tot 1556718)
40. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State INIT
41. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] mod_sofia.c:90 sofia/internal/27105914607@sbc.convergedgroup.co.za SOFIA INIT
42. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:40 sofia/internal/27105914607@sbc.convergedgroup.co.za Standard INIT
43. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State Change CS_INIT -> CS_ROUTING
44. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:627 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State INIT going to sleep
45. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27105914607@sbc.convergedgroup.co.za) Running State Change CS_ROUTING (Cur 519 Tot 1556718)
46. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_channel.c:2249 (sofia/internal/27105914607@sbc.convergedgroup.co.za) Callstate Change DOWN -> RINGING
47. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State ROUTING
48. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] mod_sofia.c:143 sofia/internal/27105914607@sbc.convergedgroup.co.za SOFIA ROUTING
49. 2018-07-13 11:32:36.904238 [DEBUG] mod_nibblebill.c:422 Doing lookup query
50. [SELECT value AS nibble_balance FROM management_clientbalances WHERE balance_uuid='9d589cb4-4bc5-4dbf-ac0d-67e9d0c666b3']
51. 2018-07-13 11:32:36.904238 [DEBUG] mod_nibblebill.c:430 Retrieved current balance for account 9d589cb4-4bc5-4dbf-ac0d-67e9d0c666b3 (balance = -2175.195819)
52. --
53. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [INFO] mod_dialplan_xml.c:637 Processing Andrew Colin <27105914607>->0114620900 in context cgrtbilling
54. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za parsing [cgrtbilling->unloop] continue=false
55. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false
56. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false
57. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za parsing [cgrtbilling->call_debug] continue=true
58. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never
59. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za parsing [cgrtbilling->block_account] continue=false
60. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (FAIL) [block_account] destination_number(0114620900) =~ /^(block_account)$/ break=on-false
61. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za parsing [cgrtbilling->check_auth] continue=true
62. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (PASS) [check_auth] ${sip_authorized}(true) =~ /^true$/ break=never
63. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za parsing [cgrtbilling->calls_from_converged] continue=true
64. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (PASS) [calls_from_converged] ${sip_req_host}(sbc.convergedgroup.co.za) =~ /^sbc.convergedgroup.co.za$/ break=on-false
65. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: Processing recursive conditions level:1 [calls_from_converged_recur_1] require-nested=TRUE
66. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (PASS) [calls_from_converged_recur_1] destination_number(0114620900) =~ /^(.*)$/ break=on-false
67. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action translate(${destination_number} sbc.convergedgroup.co.za-za)
68. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action set(destination_number=${translated})
69. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action set(outside_call=true)
70. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action set(lnp_dest_num=${lua(cgrtbilling/sa_lnp_lookup.lua ${destination_number})})
71. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec |--- Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action lua(cgrtbilling/cgrtbilling_v2.luac)
72. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za parsing [cgrtbilling->calls_from_tenants] continue=true
73. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Regex (PASS) [calls_from_tenants] destination_number(0114620900) =~ /^(.*)$/ break=on-false
74. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action translate(${destination_number} sbc.convergedgroup.co.za-za)
75. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action set(destination_number=${translated})
76. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action set(outside_call=true)
77. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec Dialplan: sofia/internal/27105914607@sbc.convergedgroup.co.za Action lua(cgrtbilling/cgrtbilling_v2.luac)
78. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State Change CS_ROUTING -> CS_EXECUTE
79. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:643 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State ROUTING going to sleep
80. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/27105914607@sbc.convergedgroup.co.za) Running State Change CS_EXECUTE (Cur 519 Tot 1556718)
81. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/27105914607@sbc.convergedgroup.co.za) State EXECUTE
82. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] mod_sofia.c:198 sofia/internal/27105914607@sbc.convergedgroup.co.za SOFIA EXECUTE
83. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] switch_core_state_machine.c:328 sofia/internal/27105914607@sbc.convergedgroup.co.za Standard EXECUTE
84. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za translate(0114620900 sbc.convergedgroup.co.za-za)
85. 2018-07-13 11:32:36.904238 [DEBUG] mod_translate.c:128 translating [0114620900] against [sbc.convergedgroup.co.za-za] profile
86. 2018-07-13 11:32:36.904238 [DEBUG] mod_translate.c:137 0114620900 =~ /^\+(\d+)$/
87. 2018-07-13 11:32:36.904238 [DEBUG] mod_translate.c:137 0114620900 =~ /^(00\d{9,17})$/
88. 2018-07-13 11:32:36.904238 [DEBUG] mod_translate.c:137 0114620900 =~ /^0(\d+)$/
89. 2018-07-13 11:32:36.904238 [NOTICE] mod_translate.c:249 Translated: 27114620900
90. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za set(destination_number=27114620900)
91. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27105914607@sbc.convergedgroup.co.za [destination_number]=[27114620900]
92. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za set(outside_call=true)
93. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.904238 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27105914607@sbc.convergedgroup.co.za [outside_call]=[true]
94. 2018-07-13 11:32:36.904238 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa889421220 Connected.
95. 2018-07-13 11:32:36.924238 [NOTICE] switch_cpp.cpp:1365 The number was ported to ECN with DCode D001
96.  
97. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(lnp_enabled, true)
98. 2018-07-13 11:32:36.924238 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa889421220 released.
99. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:1112 sofia/internal/27105914607@sbc.convergedgroup.co.za destroy/unlink session from object
100. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za set(lnp_dest_num=D00127114620900)
101. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] mod_dptools.c:1548 SET sofia/internal/27105914607@sbc.convergedgroup.co.za [lnp_dest_num]=[D00127114620900]
102. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za lua(cgrtbilling/cgrtbilling_v2.luac)
103. 2018-07-13 11:32:36.924238 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa882de4800 Connected.
104. 2018-07-13 11:32:36.924238 [INFO] switch_cpp.cpp:1365 Destination_number: 27114620900<-----------
105.  
106. 2018-07-13 11:32:36.924238 [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,
107.     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,
108.     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
109.     FROM management_client mc
110.     INNER JOIN management_tenant t ON t.id = mc.tenant_id
111.     INNER JOIN management_tenantconfiguration tc ON ( t.id = tc.tenant_id )
112.     INNER JOIN management_clientbalances b ON mc.id = b.client_id
113.     WHERE mc.account_code = '4597204894' AND b.balance_type = '*monetary' AND weight = '10'
114. 2018-07-13 11:32:36.924238 [NOTICE] switch_cpp.cpp:1365 <-------> Enable calls: 1 -----
115.  
116. 2018-07-13 11:32:36.924238 [WARNING] switch_cpp.cpp:1365 <------- Getting Account Info for Client: Converged Telecoms with account_code: 4597204894 ------->
117.  
118. 2018-07-13 11:32:36.924238 [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,
119.     s.bypass_media as bymedia, s.pass_thru_caller_id, s.custom_sip_headers, c1.description as c1, c2.description as c2,
120.     c3.description as c3, c4.description as c4, s.enabled
121.     FROM management_sipaccount s
122.     INNER JOIN management_client mc ON s.client_id = mc.id
123.     LEFT OUTER JOIN configuration_codecpreference c1 ON s.codec1_id = c1.id
124.     LEFT OUTER JOIN configuration_codecpreference c2 ON s.codec2_id = c2.id
125.     LEFT OUTER JOIN configuration_codecpreference c3 ON s.codec3_id = c3.id
126.     LEFT OUTER JOIN configuration_codecpreference c4 ON s.codec4_id = c4.id
127.     WHERE  mc.id = '1740885166862658' AND s.username = 'convergedjhb'AND s.enabled = 't'
128. 516a0cba-8a23-4990-9cc4-68854048e8d7 2018-07-13 11:32:36.924238 [NOTICE] sofia.c:1012 Hangup sofia/external/+27714760793 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
129. 516a0cba-8a23-4990-9cc4-68854048e8d7 2018-07-13 11:32:36.924238 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/external/+27714760793]
130. 516a0cba-8a23-4990-9cc4-68854048e8d7 2018-07-13 11:32:36.924238 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.13000 per minute to account 89A062DA-8E85-4C24-95D3-4B0E9667D177
131. 516a0cba-8a23-4990-9cc4-68854048e8d7 2018-07-13 11:32:36.924238 [DEBUG] mod_nibblebill.c:573 2 seconds passed since last bill time of 2018-07-13 11:32:34
132. 516a0cba-8a23-4990-9cc4-68854048e8d7 2018-07-13 11:32:36.924238 [DEBUG] mod_nibblebill.c:590 Billing $0.006500 to 89A062DA-8E85-4C24-95D3-4B0E9667D177 (Call: 516a0cba-8a23-4990-9cc4-68854048e8d7 / 0.312000 so far)
133. 2018-07-13 11:32:36.924238 [DEBUG] mod_nibblebill.c:395 Doing update query
134. [UPDATE management_clientbalances SET value=value- 0.006500 WHERE balance_uuid='89A062DA-8E85-4C24-95D3-4B0E9667D177']
135. 2018-07-13 11:32:36.924238 [WARNING] switch_cpp.cpp:1365 elapsed time: 0.008926
136.  
137. 2018-07-13 11:32:36.924238 [WARNING] switch_cpp.cpp:1365 -------------> Geting Client Tariff Plan info ------------->
138.  
139. 2018-07-13 11:32:36.924238 [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
140.       FROM management_tpballocation mt
141.       INNER JOIN management_client mc ON mt.client_id = mc.id
142.       INNER JOIN routing_routingplan r ON mt.routing_plan_id = r.id
143.       INNER JOIN tariff_plans_tpb t ON t.id = mt.tpb_id
144.       WHERE mc.account_code = '4597204894'
145. 2018-07-13 11:32:36.924238 [INFO] switch_cpp.cpp:1365 <----------------------------------------------------->
146. 2018-07-13 11:32:36.924238 [INFO] switch_cpp.cpp:1365 Trying without tech prefix
147. 2018-07-13 11:32:36.924238 [INFO] switch_cpp.cpp:1365 Dialed number : 27114620900
148. 2018-07-13 11:32:36.924238 [INFO] switch_cpp.cpp:1365 Tariff Plan Name : SPECIAL_CUST
149. 2018-07-13 11:32:36.924238 [INFO] switch_cpp.cpp:1365 <----------------------------------------------------->
150.  
151. 2018-07-13 11:32:36.924238 [WARNING] switch_cpp.cpp:1365 ------------  Getting Call cost for client  ------------
152.  
153. 2018-07-13 11:32:36.924238 [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
154.     FROM tariff_plans_rates tp
155.     WHERE code @> '27114620900' AND tpb_id = '4566351673973515' AND tp.effective_date <= tp.expiry_date AND tp.expiry_date >= now()
156.     ORDER BY CODE ASC LIMIT 1
157. 2018-07-13 11:32:36.924238 [NOTICE] switch_cpp.cpp:1365 Code: 2711
158. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za export(execute_on_answer=nibblebill adjust -0)
159. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [execute_on_answer]=[nibblebill adjust -0]
160. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.924238 [DEBUG] sofia.c:7084 Channel sofia/external/27118184224 entering state [proceeding][180]
161. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.924238 [NOTICE] sofia.c:7192 Ring-Ready sofia/external/27118184224!
162. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(connect_fee, 0)
163. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(nibble_rate, 0.12)
164. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(nibble_minimum, 0.002)
165. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(nibble_increment, 1)
166. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(nibble_account, 9D589CB4-4BC5-4DBF-AC0D-67E9D0C666B3)
167. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_account, 4597204894)
168. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(client_id, 1740885166862658)
169. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_tenant, sbc.convergedgroup.co.za)
170. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(nobal_amt, -5000)
171. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za nibblebill(heartbeat 60)
172. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [WARNING] switch_core_session.c:1605 sofia/internal/27105914607@sbc.convergedgroup.co.za using scheduler due to bypass media or media is not established.
173. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.924238 [DEBUG] switch_channel.c:3346 (sofia/external/27118184224) Callstate Change DOWN -> RINGING
174. 2018-07-13 11:32:36.924238 [DEBUG] switch_scheduler.c:249 Added task 3748168 switch_core_session_sched_heartbeat (c6f4bb20-baef-4b94-9d88-e4fdbbb674ec) to run at 1531474416
175. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_dept,  )
176. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_site,  )
177. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_extension,  )
178. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_custom,  )
179. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_subject,  )
180. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_supplier,  )
181. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_reqtype, POSTPAID)
182. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(o_category, SPECIAL_CUST)
183. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(prefix, 2711)
184. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(destination_name, SA National_2711)
185. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(destination_number, 27114620900)
186. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.924238 [DEBUG] switch_cpp.cpp:745 CoreSession::setVariable(tor, *voice)
187. 2018-07-13 11:32:36.924238 [WARNING] switch_cpp.cpp:1365 -------------> Removing unwanted SIP Headers ------------->
188.  
189. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za unset(sip_h_X-accountcode)
190. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.924238 [DEBUG] switch_ivr_bridge.c:706 sofia/external/+27714760793 ending bridge by request from write function
191. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.944238 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-accountcode]
192. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za unset(sip_h_X-username)
193. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] sofia.c:7084 Channel sofia/external/27118184224 entering state [proceeding][183]
194. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] sofia.c:7094 Remote SDP:
195. 070ab190-0a52-43cc-9e53-2877e462d2b3 v=0
196. 070ab190-0a52-43cc-9e53-2877e462d2b3 o=CvtVoice-2 1367596759 1367596759 IN IP4 154.118.252.38
197. 070ab190-0a52-43cc-9e53-2877e462d2b3 s=CvtVoice-2
198. 070ab190-0a52-43cc-9e53-2877e462d2b3 c=IN IP4 154.118.252.38
199. 070ab190-0a52-43cc-9e53-2877e462d2b3 t=0 0
200. 070ab190-0a52-43cc-9e53-2877e462d2b3 m=audio 25728 RTP/AVP 18 101
201. 070ab190-0a52-43cc-9e53-2877e462d2b3 a=rtpmap:18 G729/8000
202. 070ab190-0a52-43cc-9e53-2877e462d2b3 a=fmtp:18 annexb=no
203. 070ab190-0a52-43cc-9e53-2877e462d2b3 a=rtpmap:101 telephone-event/8000
204. 070ab190-0a52-43cc-9e53-2877e462d2b3 a=fmtp:101 0-16
205. 070ab190-0a52-43cc-9e53-2877e462d2b3 a=silenceSupp:off - - - -
206. 070ab190-0a52-43cc-9e53-2877e462d2b3 a=ptime:20
207. 070ab190-0a52-43cc-9e53-2877e462d2b3
208. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
209. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
210. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
211. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.944238 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-username]
212. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/27118184224 G729/8000 20 ms 160 samples 8000 bits 1 channels
213. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_codec.c:111 sofia/external/27118184224 Original read codec set to G729:18
214. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za unset(sip_h_X-extension)
215. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
216. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4767 sofia/external/27118184224 Set 2833 dtmf send payload to 101 recv payload to 101
217. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/27118184224] 154.118.252.36 port 17128 -> 154.118.252.38 port 25728 codec: 18 ms: 20
218. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
219. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.944238 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-extension]
220. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za]
221. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za unset(sip_h_X-dept)
222. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.944238 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-dept]
223. 516a0cba-8a23-4990-9cc4-68854048e8d7 2018-07-13 11:32:36.944238 [DEBUG] switch_ivr_bridge.c:1712 sofia/external/+27714760793 skip receive message [UNBRIDGE] (channel is hungup already)
224. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [NOTICE] switch_ivr_bridge.c:1764 Hangup sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za [CS_EXECUTE] [NORMAL_CLEARING]
225. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za unset(sip_h_X-site)
226. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:7179 sofia/external/27118184224 Set 2833 dtmf send payload to 101
227. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:7186 sofia/external/27118184224 Set 2833 dtmf receive payload to 101
228. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:7209 sofia/external/27118184224 Set rtp dtmf delay to 40
229. 070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/27118184224!
230. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec 2018-07-13 11:32:36.944238 [DEBUG] mod_dptools.c:1693 UNSET [sip_h_X-site]
231. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_hash.c:297 Usage for sbc.convergedgroup.co.za_Vodacom_Silver is now 60
232. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_hash.c:297 Usage for sbc.convergedgroup.co.za_ccdcouriers-jhb is now 21
233. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_hash.c:297 Usage for sbc.convergedgroup.co.za_Vodacom_mid is now 60
234. c6f4bb20-baef-4b94-9d88-e4fdbbb674ec EXECUTE sofia/internal/27105914607@sbc.convergedgroup.co.za unset(sip_h_X-custom)
235. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_core_session.c:2815 sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
236. --
237. 2018-07-13 11:32:36.944238 [NOTICE] switch_cpp.cpp:1365 Checking if 27114620900 is a DID <-------------
238. 2018-07-13 11:32:36.944238 [NOTICE] switch_cpp.cpp:1365 SELECT status from management_did where did_number = '27114620900' and status != 'ported_out'070ab190-0a52-43cc-9e53-2877e462d2b3 2018-07-13 11:32:36.944238 [DEBUG] switch_channel.c:3474 (sofia/external/27118184224) Callstate Change RINGING -> EARLY
239. 2018-07-13 11:32:36.944238 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa882de4800 released.
240. 2018-07-13 11:32:36.944238 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7fa882de4800 Connected.
241. 2018-07-13 11:32:36.944238 [WARNING] switch_cpp.cpp:1365 ------------  Getting LCR info  ------------
242.  
243. 2018-07-13 11:32:36.944238 [NOTICE] switch_cpp.cpp:1365 SELECT *
244.     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,
245.     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
246.     FROM tariff_plans_rates r
247.     INNER JOIN tariff_plans_tpb t ON r.tpb_id = t.id
248.     INNER JOIN routing_routingplantariff rt ON rt.tariff_plan_id = t.id
249.     WHERE rt.routing_plan_id = '1947940545902389' AND code @> 'D00127114620900' AND enabled = 't' AND (CURRENT_TIMESTAMP BETWEEN r.effective_date AND r.expiry_date)
250.     ORDER BY t.name, code ASC, "effective_date" DESC) n
251.     ORDER BY rate ASC, quality DESC, reliability DESC
252. 2018-07-13 11:32:36.944238 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7fa882457f00 released.
253. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_cpp.cpp:1112 sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za destroy/unlink session from object
254. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_core_session.c:2815 sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
255. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_core_state_machine.c:650 (sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za) State EXECUTE going to sleep
256. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_core_state_machine.c:584 (sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za) Running State Change CS_HANGUP (Cur 519 Tot 1556718)
257. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_core_state_machine.c:850 (sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za) Callstate Change ACTIVE -> HANGUP
258. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] switch_core_state_machine.c:852 (sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za) State HANGUP
259. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_sofia.c:432 sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za Overriding SIP cause 480 with 200 from the other leg
260. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_sofia.c:438 Channel sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za hanging up, cause: NORMAL_CLEARING
261. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/ccdcouriers-jhb@sbc.convergedgroup.co.za
262. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/internal/27113603825@sbc.convergedgroup.co.za!
263. 453a8084-0ed8-4244-9216-9157a5a70f37 2018-07-13 11:32:36.944238 [DEBUG] mod_nibblebill.c:506 Attempting to bill at $0.39 per minute to account F01143E1-0937-4058-8B7B-D9D6882201A4
264. c63530e4-2303-48b6-b79e-78bf6b34f861 2018-07-13 11:32:36.944238 [DEBUG] switch_rtp.c:6721 Correct audio RTCP ip/port confirmed.
265. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [DEBUG] sofia.c:7084 Channel sofia/internal/27113603825@sbc.convergedgroup.co.za entering state [early][180]
266. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/internal/27113603825@sbc.convergedgroup.co.za!
267. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [INFO] switch_ivr_originate.c:3654 Sending early media
268. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
269. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
270. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
271. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [DEBUG] switch_core_media.c:3061 Set Codec sofia/internal/27113603825@sbc.convergedgroup.co.za G729/8000 20 ms 160 samples 8000 bits 1 channels
272. a5ef2324-03e9-4998-b93c-09c22bb60bf5 2018-07-13 11:32:36.944238 [DEBUG] switch_core_codec.c:111 sofia/internal/27113603825@sbc.convergedg