From Gentle Cat, 5 Years ago, written in FreeSWITCH.
- view diff
Embed
  1. span style="color: goldenrod; font-weight: bold;"> 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:10044 IP 117.247.91.162 Rejected by acl "default". Falling back to Digest auth.
  2. 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [received][100]
  3. 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:7094 Remote SDP:
  4. v=0
  5. o=7661455301 8001 8000 IN IP4 117.247.91.162
  6. s=SIP Call
  7. c=IN IP4 117.247.91.162
  8. t=0 0
  9. m=audio 5008 RTP/AVP 18 101
  10. a=rtpmap:18 G729/8000
  11. a=fmtp:18 annexb=no
  12. a=rtpmap:101 telephone-event/8000
  13. a=fmtp:101 0-15
  14. a=ptime:20
  15.  
  16. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  17. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  18. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  19. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  20. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  21. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/7661455301@fs.beconnected.co.za G729/8000 20 ms 160 samples 8000 bits 1 channels
  22. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_codec.c:111 sofia/default/7661455301@fs.beconnected.co.za Original read codec set to G729:18
  23. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  24. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_media.c:4767 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf send payload to 101 recv payload to 101
  25. 2018-12-10 13:16:26.173249 [DEBUG] sofia.c:7507 (sofia/default/7661455301@fs.beconnected.co.za) State Change CS_NEW -> CS_INIT
  26. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7661455301@fs.beconnected.co.za) Running State Change CS_INIT (Cur 2 Tot 7797)
  27. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7661455301@fs.beconnected.co.za) State INIT
  28. 2018-12-10 13:16:26.173249 [DEBUG] mod_sofia.c:90 sofia/default/7661455301@fs.beconnected.co.za SOFIA INIT
  29. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:40 sofia/default/7661455301@fs.beconnected.co.za Standard INIT
  30. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:48 (sofia/default/7661455301@fs.beconnected.co.za) State Change CS_INIT -> CS_ROUTING
  31. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:627 (sofia/default/7661455301@fs.beconnected.co.za) State INIT going to sleep
  32. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7661455301@fs.beconnected.co.za) Running State Change CS_ROUTING (Cur 2 Tot 7797)
  33. 2018-12-10 13:16:26.173249 [DEBUG] switch_channel.c:2249 (sofia/default/7661455301@fs.beconnected.co.za) Callstate Change DOWN -> RINGING
  34. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7661455301@fs.beconnected.co.za) State ROUTING
  35. 2018-12-10 13:16:26.173249 [DEBUG] mod_sofia.c:143 sofia/default/7661455301@fs.beconnected.co.za SOFIA ROUTING
  36. 2018-12-10 13:16:26.173249 [DEBUG] switch_core_state_machine.c:236 sofia/default/7661455301@fs.beconnected.co.za Standard ROUTING
  37. 2018-12-10 13:16:26.173249 [INFO] mod_dialplan_xml.c:637 Processing 7661455301 <7661455301>->6835959900 in context default
  38. 2018-12-10 13:16:26.173249 [DEBUG] freeswitch_lua.cpp:365 DBH handle 0x7f83143cc970 Connected.
  39. 2018-12-10 13:16:26.173249 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [LOAD_CONF] Query :SELECT name,value FROM system WHERE group_title IN ('global','opensips','callingcard')
  40. 2018-12-10 13:16:26.193199 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [xml_handler] Params:
  41. 'Event-Name: REQUEST_PARAMS
  42. Core-UUID: ce67deb0-ce57-4faa-b8de-66c407c6216d
  43. FreeSWITCH-Hostname: fs
  44. FreeSWITCH-Switchname: fs
  45. FreeSWITCH-IPv4: 169.255.171.130
  46. FreeSWITCH-IPv6: %3A%3A1
  47. Event-Date-Local: 2018-12-10%2013%3A16%3A26
  48. Event-Date-GMT: Mon,%2010%20Dec%202018%2011%3A16%3A26%20GMT
  49. Event-Date-Timestamp: 1544440586173249
  50. Event-Calling-File: mod_dialplan_xml.c
  51. Event-Calling-Function: dialplan_xml_locate
  52. Event-Calling-Line-Number: 608
  53. Event-Sequence: 131020
  54. Channel-State: CS_ROUTING
  55. Channel-Call-State: RINGING
  56. Channel-State-Number: 2
  57. Channel-Name: sofia/default/7661455301%40fs.beconnected.co.za
  58. Unique-ID: ffa90ab3-4098-4b77-a0e9-662d212b2765
  59. Call-Direction: inbound
  60. Presence-Call-Direction: inbound
  61. Channel-HIT-Dialplan: true
  62. Channel-Presence-ID: 7661455301%40fs.beconnected.co.za
  63. Channel-Call-UUID: ffa90ab3-4098-4b77-a0e9-662d212b2765
  64. Answer-State: ringing
  65. Channel-Read-Codec-Name: G729
  66. Channel-Read-Codec-Rate: 8000
  67. Channel-Read-Codec-Bit-Rate: 8000
  68. Channel-Write-Codec-Name: G729
  69. Channel-Write-Codec-Rate: 8000
  70. Channel-Write-Codec-Bit-Rate: 8000
  71. Caller-Direction: inbound
  72. Caller-Logical-Direction: inbound
  73. Caller-Username: 7661455301
  74. Caller-Dialplan: XML
  75. Caller-Caller-ID-Name: 7661455301
  76. Caller-Caller-ID-Number: 7661455301
  77. Caller-Orig-Caller-ID-Name: 7661455301
  78. Caller-Orig-Caller-ID-Number: 7661455301
  79. Caller-Network-Addr: 117.247.91.162
  80. Caller-ANI: 7661455301
  81. Caller-Destination-Number: 6835959900
  82. Caller-Unique-ID: ffa90ab3-4098-4b77-a0e9-662d212b2765
  83. Caller-Source: mod_sofia
  84. Caller-Context: default
  85. Caller-Channel-Name: sofia/default/7661455301%40fs.beconnected.co.za
  86. Caller-Profile-Index: 1
  87. Caller-Profile-Created-Time: 1544440586173249
  88. Caller-Channel-Created-Time: 1544440586173249
  89. Caller-Channel-Answered-Time: 0
  90. Caller-Channel-Progress-Time: 0
  91. Caller-Channel-Progress-Media-Time: 0
  92. Caller-Channel-Hangup-Time: 0
  93. Caller-Channel-Transfer-Time: 0
  94. Caller-Channel-Resurrect-Time: 0
  95. Caller-Channel-Bridged-Time: 0
  96. Caller-Channel-Last-Hold: 0
  97. Caller-Channel-Hold-Accum: 0
  98. Caller-Screen-Bit: true
  99. Caller-Privacy-Hide-Name: false
  100. Caller-Privacy-Hide-Number: false
  101. variable_direction: inbound
  102. variable_uuid: ffa90ab3-4098-4b77-a0e9-662d212b2765
  103. variable_session_id: 7796
  104. variable_sip_from_user: 7661455301
  105. variable_sip_from_uri: 7661455301%40fs.beconnected.co.za
  106. variable_sip_from_host: fs.beconnected.co.za
  107. variable_video_media_flow: sendrecv
  108. variable_channel_name: sofia/default/7661455301%40fs.beconnected.co.za
  109. variable_sip_call_id: 1673991354-27987-24%40BJC.BGI.B.BGB
  110. variable_ep_codec_string: mod_bcg729.G729%408000h%4020i%408000b
  111. variable_sip_local_network_addr: 169.255.171.130
  112. variable_sip_network_ip: 117.247.91.162
  113. variable_sip_network_port: 27987
  114. variable_sip_invite_stamp: 1544440586173249
  115. variable_sip_received_ip: 117.247.91.162
  116. variable_sip_received_port: 27987
  117. variable_sip_via_protocol: udp
  118. variable_sip_authorized: true
  119. variable_Event-Name: REQUEST_PARAMS
  120. variable_Core-UUID: ce67deb0-ce57-4faa-b8de-66c407c6216d
  121. variable_FreeSWITCH-Hostname: fs
  122. variable_FreeSWITCH-Switchname: fs
  123. variable_FreeSWITCH-IPv4: 169.255.171.130
  124. variable_FreeSWITCH-IPv6: %3A%3A1
  125. variable_Event-Date-Local: 2018-12-10%2013%3A16%3A26
  126. variable_Event-Date-GMT: Mon,%2010%20Dec%202018%2011%3A16%3A26%20GMT
  127. variable_Event-Date-Timestamp: 1544440586173249
  128. variable_Event-Calling-File: sofia.c
  129. variable_Event-Calling-Function: sofia_handle_sip_i_invite
  130. variable_Event-Calling-Line-Number: 10096
  131. variable_Event-Sequence: 131011
  132. variable_sip_number_alias: 7661455301
  133. variable_sip_auth_username: 7661455301
  134. variable_sip_auth_realm: fs.beconnected.co.za
  135. variable_number_alias: 7661455301
  136. variable_requested_user_name: 7661455301
  137. variable_requested_domain_name: fs.beconnected.co.za
  138. variable_effective_caller_id_name: 7661455301
  139. variable_effective_caller_id_number: 12334556
  140. variable_sipcall: true
  141. variable_accountcode: 6835959900
  142. variable_user_name: 7661455301
  143. variable_domain_name: fs.beconnected.co.za
  144. variable_sip_from_user_stripped: 7661455301
  145. variable_sip_from_tag: 156202635
  146. variable_sofia_profile_name: default
  147. variable_recovery_profile_name: default
  148. variable_sip_P-Preferred-Identity: %227661455301%22%20%3Csip%3A7661455301%40fs.beconnected.co.za%3E
  149. variable_sip_cid_type: pid
  150. variable_sip_full_via: SIP/2.0/UDP%20117.247.91.162%3A27987%3Bbranch%3Dz9hG4bK932791135%3Brport%3D27987
  151. variable_sip_from_display: 7661455301
  152. variable_sip_full_from: %227661455301%22%20%3Csip%3A7661455301%40fs.beconnected.co.za%3E%3Btag%3D156202635
  153. variable_sip_full_to: %3Csip%3A6835959900%40fs.beconnected.co.za%3E
  154. variable_sip_allow: INVITE,%20ACK,%20OPTIONS,%20CANCEL,%20BYE,%20SUBSCRIBE,%20NOTIFY,%20INFO,%20REFER,%20UPDATE,%20MESSAGE
  155. variable_sip_req_user: 6835959900
  156. variable_sip_req_uri: 6835959900%40fs.beconnected.co.za
  157. variable_sip_req_host: fs.beconnected.co.za
  158. variable_sip_to_user: 6835959900
  159. variable_sip_to_uri: 6835959900%40fs.beconnected.co.za
  160. variable_sip_to_host: fs.beconnected.co.za
  161. variable_sip_contact_user: 7661455301
  162. variable_sip_contact_port: 27987
  163. variable_sip_contact_uri: 7661455301%40117.247.91.162%3A27987
  164. variable_sip_contact_host: 117.247.91.162
  165. variable_sip_user_agent: Grandstream%20GXP1620%201.0.0.38
  166. variable_sip_via_host: 117.247.91.162
  167. variable_sip_via_port: 27987
  168. variable_sip_via_rport: 27987
  169. variable_max_forwards: 70
  170. variable_presence_id: 7661455301%40fs.beconnected.co.za
  171. variable_sip_Privacy: none
  172. variable_switch_r_sdp: v%3D0%0D%0Ao%3D7661455301%208001%208000%20IN%20IP4%20117.247.91.162%0D%0As%3DSIP%20Call%0D%0Ac%3DIN%20IP4%20117.247.91.162%0D%0At%3D0%200%0D%0Am%3Daudio%205008%20RTP/AVP%2018%20101%0D%0Aa%3Drtpmap%3A18%20G729/8000%0D%0Aa%3Dfmtp%3A18%20annexb%3Dno%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-15%0D%0Aa%3Dptime%3A20%0D%0A
  173. variable_rtp_use_codec_string: PCMA,PCMU,G729
  174. variable_audio_media_flow: sendrecv
  175. variable_remote_media_ip: 117.247.91.162
  176. variable_remote_media_port: 5008
  177. variable_rtp_audio_recv_pt: 18
  178. variable_rtp_use_codec_name: G729
  179. variable_rtp_use_codec_fmtp: annexb%3Dno
  180. variable_rtp_use_codec_rate: 8000
  181. variable_rtp_use_codec_ptime: 20
  182. variable_rtp_use_codec_channels: 1
  183. variable_rtp_last_audio_codec_string: G729%408000h%4020i%401c
  184. variable_read_codec: G729
  185. variable_original_read_codec: G729
  186. variable_read_rate: 8000
  187. variable_original_read_rate: 8000
  188. variable_write_codec: G729
  189. variable_write_rate: 8000
  190. variable_dtmf_type: rfc2833
  191. variable_endpoint_disposition: RECEIVED
  192. variable_call_uuid: ffa90ab3-4098-4b77-a0e9-662d212b2765
  193. Hunt-Direction: inbound
  194. Hunt-Logical-Direction: inbound
  195. Hunt-Username: 7661455301
  196. Hunt-Dialplan: XML
  197. Hunt-Caller-ID-Name: 7661455301
  198. Hunt-Caller-ID-Number: 7661455301
  199. Hunt-Orig-Caller-ID-Name: 7661455301
  200. Hunt-Orig-Caller-ID-Number: 7661455301
  201. Hunt-Network-Addr: 117.247.91.162
  202. Hunt-ANI: 7661455301
  203. Hunt-Destination-Number: 6835959900
  204. Hunt-Unique-ID: ffa90ab3-4098-4b77-a0e9-662d212b2765
  205. Hunt-Source: mod_sofia
  206. Hunt-Context: default
  207. Hunt-Channel-Name: sofia/default/7661455301%40fs.beconnected.co.za
  208. Hunt-Profile-Index: 1
  209. Hunt-Profile-Created-Time: 1544440586173249
  210. Hunt-Channel-Created-Time: 1544440586173249
  211. Hunt-Channel-Answered-Time: 0
  212. Hunt-Channel-Progress-Time: 0
  213. Hunt-Channel-Progress-Media-Time: 0
  214. Hunt-Channel-Hangup-Time: 0
  215. Hunt-Channel-Transfer-Time: 0
  216. Hunt-Channel-Resurrect-Time: 0
  217. Hunt-Channel-Bridged-Time: 0
  218. Hunt-Channel-Last-Hold: 0
  219. Hunt-Channel-Hold-Accum: 0
  220. Hunt-Screen-Bit: true
  221. Hunt-Privacy-Hide-Name: false
  222. Hunt-Privacy-Hide-Number: false
  223.  
  224. '
  225. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] section: dialplan
  226. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] tag_name:
  227. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_value:
  228. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [xml_REQUEST] key_name:
  229. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Dialed number : 6835959900
  230. 2018-12-10 13:16:26.193199 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FAXER] in custom Caller ID
  231. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Caller Id name / number  : 7661455301 / 12334556
  232. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_DID] Query :SELECT A.id as id,B.id as accountid,B.number as account_code,B.did_cid_translation as did_cid_translation,A.number as  did_number,A.connectcost,A.includedseconds,A.cost,A.inc,A.extensions,A.maxchannels,A.call_type,A.city,A.province,A.init_inc,A.leg_timeout FROM dids AS A,accounts AS B WHERE A.status=0 AND B.status=0 AND B.deleted=0 AND B.id=A.accountid AND A.number ="6835959900" LIMIT 1
  233. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as  accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="6835959900" limit 1
  234. 2018-12-10 13:16:26.193199 [INFO] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Call direction : local
  235. 2018-12-10 13:16:26.193199 [NOTICE] switch_cpp.cpp:1365 [ASTPP] [Accountcode : 6835959900]
  236. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_ROUTING_INFO] Query :select id,routing_prefix,pricelist_id_admin from pricelists WHERE (routing_prefix = '6835959900' OR routing_prefix = '683595990' OR routing_prefix = '68359599' OR routing_prefix = '6835959' OR routing_prefix = '683595' OR routing_prefix = '68359' OR routing_prefix = '6835' OR routing_prefix = '683' OR routing_prefix = '68' OR routing_prefix = '6' OR routing_prefix ='--') AND status = 0 limit 1
  237. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [DOAUTHORIZATION] Query :SELECT * FROM accounts WHERE (number = "6835959900" OR id="6835959900") AND status=0 AND deleted=0 AND (expiry >= '2018-12-10 11:16:26' OR expiry = '0000-00-00 00:00:00') limit 1
  238. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CALLERID_NUMBER] CALLERID :12334556
  239. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CUSTOMER_ID] USERID :63
  240. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_CIDPOOL] CIDPOOL :0
  241. 2018-12-10 13:16:26.193199 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PACKAGE_INFO] Query :SELECT * FROM packages  as P inner join package_patterns as PKGPTR on P.id = PKGPTR.package_id WHERE (patterns = '^6835959900.*' OR patterns = '^683595990.*' OR patterns = '^68359599.*' OR patterns = '^6835959.*' OR patterns = '^683595.*' OR patterns = '^68359.*' OR patterns = '^6835.*' OR patterns = '^683.*' OR patterns = '^68.*' OR patterns = '^6.*' OR patterns ='--') AND status = 0 AND pricelist_id = 1 ORDER BY LENGTH(PKGPTR.patterns) DESC LIMIT 1
  242. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] =============== Account Information ===================
  243. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] User id : 63
  244. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Account code : 6835959900
  245. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Type : 0 [0:prepaid,1:postpaid]
  246. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Ratecard id : 1
  247. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] ========================================================
  248. 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET_PRICELIST_INFO] Query :select * from pricelists WHERE id = 1 AND status = 0
  249. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] [FIND_MAXLENGTH] Call is free - assigning max length!!! :: 100
  250. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] Call Max length duration : 100 minutes
  251. 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [CHECK_LOCAL_CALL] Query :SELECT sip_devices.id as sip_id,sip_devices.username as username,accounts.number as accountcode,sip_devices.accountid as accountid,accounts.did_cid_translation as did_cid_translation FROM sip_devices as sip_devices,accounts as  accounts WHERE accounts.status=0 AND accounts.deleted=0 AND accounts.id=sip_devices.accountid AND sip_devices.username="6835959900" limit 1
  252. 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Functions] [GET_queue_INFO] Query :SELECT id,destination_number,agent_hold_file from pbx_queue WHERE destination_number = 6835959900 and status=0 LIMIT 1
  253. 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [fifo_agent_flag] fifo_agent_flag0
  254. 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [GET multidomain] Query :SELECT * FROM multidomain WHERE accountid = 63
  255. 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [user_domain] user_domainfs.beconnected.co.za
  256. 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Starts
  257. 2018-12-10 13:16:26.213193 [WARNING] switch_cpp.cpp:1365 [ASTPP] [FSXMLLOCAL] Caller ID Translation Ends
  258. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] SIP ID : 127
  259. 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] [GET_ROUTING_INFO] Query :SELECT * from sip_device_routing WHERE sip_device_id = 127 limit 1
  260. 2018-12-10 13:16:26.213193 [INFO] switch_cpp.cpp:1365 [ASTPP] [PBX_SIP_ROUTING] SIP Call forwarding Disable
  261. 2018-12-10 13:16:26.213193 [DEBUG] switch_cpp.cpp:1365 [ASTPP] [Dialplan] Generated XML:
  262. <?xml version="1.0" encoding="UTF-8" standalone="no"?>
  263. <document type="freeswitch/xml">
  264. <section name="dialplan" description="ASTPP Dialplan">
  265. <context name="default">
  266. <extension name="6835959900">
  267. <condition field="destination_number" expression="6835959900">
  268. <action application="set" data="effective_destination_number=6835959900"/>
  269. <action application="sched_hangup" data="+6000 normal_clearing"/>
  270. <action application="set" data="callstart=2018-12-10 11:16:26"/>
  271. <action application="set" data="hangup_after_bridge=true"/>
  272. <action application="set" data="continue_on_fail=TRUE"/>
  273. <action application="set" data="account_id=63"/>
  274. <action application="set" data="parent_id=0"/>
  275. <action application="set" data="entity_id=0"/>
  276. <action application="set" data="call_processed=internal"/>
  277. <action application="set" data="call_direction=local"/>
  278. <action application="set" data="accountname=default"/>
  279. <action application="set" data="origination_rates=ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63"/>
  280. <action application="set" data="original_caller_id_name=7661455301"/>
  281. <action application="set" data="original_caller_id_number=12334556"/>
  282. <action application="set" data="effective_caller_id_name=7661455301"/>
  283. <action application="set" data="effective_caller_id_number=12334556"/>
  284. <action application="set" data="calltype=LOCAL"/>
  285. <action application="set" data="receiver_accid=63"/>
  286. <action application="bridge" data="[leg_timeout=30]user/6835959900@fs.beconnected.co.za"/>
  287. <condition field="${cond(${user_data 6835959900@${domain_name} param vm-enabled} == true ? YES : NO)}" expression="^YES$">
  288. <action application="answer"/>
  289. <action application="export" data="voicemail_alternate_greet_id=6835959900"/>
  290. <action application="voicemail" data="default $${domain_name} 6835959900"/>
  291. <anti-action application="hangup" data="${originate_disposition}"/>
  292. </condition>
  293. </condition>
  294. </extension>
  295. </context>
  296. </section>
  297. </document>
  298. 2018-12-10 13:16:26.213193 [DEBUG] freeswitch_lua.cpp:382 DBH handle 0x7f83143cc970 released.
  299. Dialplan: sofia/default/7661455301@fs.beconnected.co.za parsing [default->6835959900] continue=false
  300. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Regex (PASS) [6835959900] destination_number(6835959900) =~ /6835959900/ break=on-false
  301. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(effective_destination_number=6835959900)
  302. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action sched_hangup(+6000 normal_clearing)
  303. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(callstart=2018-12-10 11:16:26)
  304. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(hangup_after_bridge=true)
  305. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(continue_on_fail=TRUE)
  306. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(account_id=63)
  307. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(parent_id=0)
  308. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(entity_id=0)
  309. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(call_processed=internal)
  310. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(call_direction=local)
  311. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(accountname=default)
  312. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(origination_rates=ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63)
  313. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(original_caller_id_name=7661455301)
  314. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(original_caller_id_number=12334556)
  315. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(effective_caller_id_name=7661455301)
  316. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(effective_caller_id_number=12334556)
  317. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(calltype=LOCAL)
  318. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action set(receiver_accid=63)
  319. Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action bridge([leg_timeout=30]user/6835959900@fs.beconnected.co.za)
  320. |--- Dialplan: Processing recursive conditions level:1 [6835959900_recur_1] require-nested=TRUE
  321. |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Regex (PASS) [6835959900_recur_1] ${cond(${user_data 6835959900@${domain_name} param vm-enabled} == true ? YES : NO)}(YES) =~ /^YES$/ break=on-false
  322. |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action answer()
  323. |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action export(voicemail_alternate_greet_id=6835959900)
  324. |--- Dialplan: sofia/default/7661455301@fs.beconnected.co.za Action voicemail(default $${domain_name} 6835959900)
  325. 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:286 (sofia/default/7661455301@fs.beconnected.co.za) State Change CS_ROUTING -> CS_EXECUTE
  326. 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:643 (sofia/default/7661455301@fs.beconnected.co.za) State ROUTING going to sleep
  327. 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:584 (sofia/default/7661455301@fs.beconnected.co.za) Running State Change CS_EXECUTE (Cur 2 Tot 7797)
  328. 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:650 (sofia/default/7661455301@fs.beconnected.co.za) State EXECUTE
  329. 2018-12-10 13:16:26.213193 [DEBUG] mod_sofia.c:198 sofia/default/7661455301@fs.beconnected.co.za SOFIA EXECUTE
  330. 2018-12-10 13:16:26.213193 [DEBUG] switch_core_state_machine.c:328 sofia/default/7661455301@fs.beconnected.co.za Standard EXECUTE
  331. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(effective_destination_number=6835959900)
  332. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [effective_destination_number]=[6835959900]
  333. EXECUTE sofia/default/7661455301@fs.beconnected.co.za sched_hangup(+6000 normal_clearing)
  334. 2018-12-10 13:16:26.213193 [DEBUG] switch_scheduler.c:249 Added task 158 switch_ivr_schedule_hangup (ffa90ab3-4098-4b77-a0e9-662d212b2765) to run at 1544446586
  335. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(callstart=2018-12-10 11:16:26)
  336. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [callstart]=[2018-12-10 11:16:26]
  337. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(hangup_after_bridge=true)
  338. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [hangup_after_bridge]=[true]
  339. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(continue_on_fail=TRUE)
  340. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [continue_on_fail]=[TRUE]
  341. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(account_id=63)
  342. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [account_id]=[63]
  343. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(parent_id=0)
  344. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [parent_id]=[0]
  345. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(entity_id=0)
  346. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [entity_id]=[0]
  347. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(call_processed=internal)
  348. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [call_processed]=[internal]
  349. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(call_direction=local)
  350. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [call_direction]=[local]
  351. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(accountname=default)
  352. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [accountname]=[default]
  353. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(origination_rates=ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63)
  354. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [origination_rates]=[ID:0|CODE:6835959900|DESTINATION:Local|CONNECTIONCOST:0|INCLUDEDSECONDS:0|COST:0|INC:60|INITIALBLOCK:0|RATEGROUP:1|MARKUP:0|ACCID:63]
  355. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(original_caller_id_name=7661455301)
  356. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [original_caller_id_name]=[7661455301]
  357. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(original_caller_id_number=12334556)
  358. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [original_caller_id_number]=[12334556]
  359. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(effective_caller_id_name=7661455301)
  360. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [effective_caller_id_name]=[7661455301]
  361. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(effective_caller_id_number=12334556)
  362. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [effective_caller_id_number]=[12334556]
  363. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(calltype=LOCAL)
  364. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [calltype]=[LOCAL]
  365. EXECUTE sofia/default/7661455301@fs.beconnected.co.za set(receiver_accid=63)
  366. 2018-12-10 13:16:26.213193 [DEBUG] mod_dptools.c:1548 SET sofia/default/7661455301@fs.beconnected.co.za [receiver_accid]=[63]
  367. EXECUTE sofia/default/7661455301@fs.beconnected.co.za bridge([leg_timeout=30]user/6835959900@fs.beconnected.co.za)
  368. 2018-12-10 13:16:26.213193 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  369. 2018-12-10 13:16:26.213193 [DEBUG] switch_ivr_originate.c:2669 Parsing session specific variables
  370. 2018-12-10 13:16:26.233192 [DEBUG] switch_ivr_originate.c:2142 Parsing global variables
  371. 2018-12-10 13:16:26.233192 [NOTICE] switch_channel.c:1104 New Channel sofia/default/6835959900@117.247.91.162:5060 [806f29a9-ef75-424a-bb7a-e8cb4155ffa0]
  372. 2018-12-10 13:16:26.233192 [DEBUG] mod_sofia.c:4819 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_NEW -> CS_INIT
  373. 2018-12-10 13:16:26.233192 [DEBUG] switch_ivr_originate.c:2963 sofia/default/6835959900@117.247.91.162:5060 Setting leg timeout to 30
  374. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_INIT (Cur 3 Tot 7798)
  375. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:627 (sofia/default/6835959900@117.247.91.162:5060) State INIT
  376. 2018-12-10 13:16:26.233192 [DEBUG] mod_sofia.c:90 sofia/default/6835959900@117.247.91.162:5060 SOFIA INIT
  377. 2018-12-10 13:16:26.233192 [DEBUG] sofia_glue.c:1295 sofia/default/6835959900@117.247.91.162:5060 sending invite version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
  378. Local SDP:
  379. v=0
  380. o=FreeSWITCH 1544429808 1544429809 IN IP4 169.255.171.130
  381. s=FreeSWITCH
  382. c=IN IP4 169.255.171.130
  383. t=0 0
  384. m=audio 10778 RTP/AVP 18 101
  385. a=rtpmap:18 G729/8000
  386. a=fmtp:18 annexb=no
  387. a=rtpmap:101 telephone-event/8000
  388. a=fmtp:101 0-16
  389. a=ptime:20
  390. a=sendrecv
  391.  
  392. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:40 sofia/default/6835959900@117.247.91.162:5060 Standard INIT
  393. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:48 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_INIT -> CS_ROUTING
  394. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:627 (sofia/default/6835959900@117.247.91.162:5060) State INIT going to sleep
  395. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_ROUTING (Cur 3 Tot 7798)
  396. 2018-12-10 13:16:26.233192 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [calling][0]
  397. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:643 (sofia/default/6835959900@117.247.91.162:5060) State ROUTING
  398. 2018-12-10 13:16:26.233192 [DEBUG] mod_sofia.c:143 sofia/default/6835959900@117.247.91.162:5060 SOFIA ROUTING
  399. 2018-12-10 13:16:26.233192 [DEBUG] switch_ivr_originate.c:67 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  400. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:643 (sofia/default/6835959900@117.247.91.162:5060) State ROUTING going to sleep
  401. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_CONSUME_MEDIA (Cur 3 Tot 7798)
  402. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:662 (sofia/default/6835959900@117.247.91.162:5060) State CONSUME_MEDIA
  403. 2018-12-10 13:16:26.233192 [DEBUG] switch_core_state_machine.c:662 (sofia/default/6835959900@117.247.91.162:5060) State CONSUME_MEDIA going to sleep
  404. 2018-12-10 13:16:26.873246 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [proceeding][180]
  405. 2018-12-10 13:16:26.873246 [NOTICE] sofia.c:7192 Ring-Ready sofia/default/6835959900@117.247.91.162:5060!
  406. 2018-12-10 13:16:26.873246 [DEBUG] switch_channel.c:3346 (sofia/default/6835959900@117.247.91.162:5060) Callstate Change DOWN -> RINGING
  407. 2018-12-10 13:16:26.893191 [NOTICE] mod_sofia.c:2273 Ring-Ready sofia/default/7661455301@fs.beconnected.co.za!
  408. 2018-12-10 13:16:26.893191 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [early][180]
  409. 2018-12-10 13:16:26.893191 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/default/7661455301@fs.beconnected.co.za!
  410. 2018-12-10 13:16:28.253249 [NOTICE] switch_channel.c:1104 New Channel sofia/default/5081@169.255.171.130 [1534e618-fd5f-4149-92b0-265d35812406]
  411. 2018-12-10 13:16:28.253249 [DEBUG] switch_core_state_machine.c:584 (sofia/default/5081@169.255.171.130) Running State Change CS_NEW (Cur 4 Tot 7799)
  412. 2018-12-10 13:16:28.253249 [DEBUG] sofia.c:9873 sofia/default/5081@169.255.171.130 receiving invite from 37.49.231.120:62181 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
  413. 2018-12-10 13:16:28.253249 [DEBUG] sofia.c:10044 IP 37.49.231.120 Rejected by acl "default". Falling back to Digest auth.
  414. 2018-12-10 13:16:28.253249 [DEBUG] sofia.c:2334 detaching session 1534e618-fd5f-4149-92b0-265d35812406
  415. 2018-12-10 13:16:28.253249 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [0048221284837@169.255.171.130] from ip 37.49.231.120
  416. 2018-12-10 13:16:28.253249 [DEBUG] switch_core_state_machine.c:603 (sofia/default/5081@169.255.171.130) State NEW
  417. 2018-12-10 13:16:28.493218 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [completing][200]
  418. 2018-12-10 13:16:28.493218 [DEBUG] sofia.c:7094 Remote SDP:
  419. v=0
  420. o=root 1509274545 1509274545 IN IP4 117.247.91.162
  421. s=Asterisk PBX 1.6.2.13
  422. c=IN IP4 117.247.91.162
  423. t=0 0
  424. m=audio 10002 RTP/AVP 18 101
  425. a=rtpmap:18 G729/8000
  426. a=fmtp:18 annexb=no
  427. a=rtpmap:101 telephone-event/8000
  428. a=fmtp:101 0-16
  429. a=silenceSupp:off - - - -
  430. a=ptime:20
  431.  
  432. 2018-12-10 13:16:28.513263 [DEBUG] sofia.c:7084 Channel sofia/default/6835959900@117.247.91.162:5060 entering state [ready][200]
  433. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  434. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  435. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  436. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/6835959900@117.247.91.162:5060 G729/8000 20 ms 160 samples 8000 bits 1 channels
  437. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_codec.c:111 sofia/default/6835959900@117.247.91.162:5060 Original read codec set to G729:18
  438. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  439. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:4767 sofia/default/6835959900@117.247.91.162:5060 Set 2833 dtmf send payload to 101 recv payload to 101
  440. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/6835959900@117.247.91.162:5060] 169.255.171.130 port 10778 -> 117.247.91.162 port 10002 codec: 18 ms: 20
  441. 2018-12-10 13:16:28.513263 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
  442. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:7179 sofia/default/6835959900@117.247.91.162:5060 Set 2833 dtmf send payload to 101
  443. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:7186 sofia/default/6835959900@117.247.91.162:5060 Set 2833 dtmf receive payload to 101
  444. 2018-12-10 13:16:28.513263 [DEBUG] switch_core_media.c:7209 sofia/default/6835959900@117.247.91.162:5060 Set rtp dtmf delay to 40
  445. 2018-12-10 13:16:28.513263 [NOTICE] sofia.c:8218 Channel [sofia/default/6835959900@117.247.91.162:5060] has been answered
  446. 2018-12-10 13:16:28.513263 [DEBUG] switch_channel.c:3773 (sofia/default/6835959900@117.247.91.162:5060) Callstate Change RINGING -> ACTIVE
  447. 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/default/7661455301@fs.beconnected.co.za] 169.255.171.130 port 18968 -> 117.247.91.162 port 5008 codec: 18 ms: 20
  448. 2018-12-10 13:16:28.533213 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms
  449. 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:7179 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf send payload to 101
  450. 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:7186 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf receive payload to 101
  451. 2018-12-10 13:16:28.533213 [DEBUG] switch_core_media.c:7209 sofia/default/7661455301@fs.beconnected.co.za Set rtp dtmf delay to 40
  452. 2018-12-10 13:16:28.533213 [DEBUG] mod_sofia.c:850 Local SDP sofia/default/7661455301@fs.beconnected.co.za:
  453. v=0
  454. o=FreeSWITCH 1544421620 1544421621 IN IP4 169.255.171.130
  455. s=FreeSWITCH
  456. c=IN IP4 169.255.171.130
  457. t=0 0
  458. m=audio 18968 RTP/AVP 18 101
  459. a=rtpmap:18 G729/8000
  460. a=fmtp:18 annexb=no
  461. a=rtpmap:101 telephone-event/8000
  462. a=fmtp:101 0-16
  463. a=ptime:20
  464. a=sendrecv
  465.  
  466. 2018-12-10 13:16:28.533213 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [completed][200]
  467. 2018-12-10 13:16:28.533213 [NOTICE] switch_ivr_originate.c:3647 Channel [sofia/default/7661455301@fs.beconnected.co.za] has been answered
  468. 2018-12-10 13:16:28.533213 [DEBUG] switch_channel.c:3773 (sofia/default/7661455301@fs.beconnected.co.za) Callstate Change RINGING -> ACTIVE
  469. 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/6835959900@117.247.91.162:5060]
  470. 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_originate.c:2963 sofia/default/6835959900@117.247.91.162:5060 Setting leg timeout to 30
  471. 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/default/6835959900@117.247.91.162:5060]
  472. 2018-12-10 13:16:28.533213 [DEBUG] switch_ivr_bridge.c:1614 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
  473. 2018-12-10 13:16:28.533213 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_EXCHANGE_MEDIA (Cur 4 Tot 7799)
  474. 2018-12-10 13:16:28.533213 [DEBUG] switch_core_state_machine.c:653 (sofia/default/6835959900@117.247.91.162:5060) State EXCHANGE_MEDIA
  475. 2018-12-10 13:16:28.533213 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA
  476. 2018-12-10 13:16:28.593211 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
  477. 2018-12-10 13:16:28.773213 [WARNING] switch_core_media.c:2480 [CBR]: Asynchronous PTIME not supported, changing our end from 20 to 30
  478. 2018-12-10 13:16:28.773213 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [ready][200]
  479. 2018-12-10 13:16:28.793215 [DEBUG] switch_core_media.c:2959 Changing Codec from G729@20ms@8000hz to G729@30ms@8000hz
  480. 2018-12-10 13:16:28.793215 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [calling][0]
  481. 2018-12-10 13:16:28.833250 [DEBUG] switch_rtp.c:3986 RE-Starting timer [soft] 240 bytes per 30ms
  482. 2018-12-10 13:16:28.833250 [DEBUG] switch_core_media.c:3061 Set Codec sofia/default/6835959900@117.247.91.162:5060 G729/8000 30 ms 240 samples 8000 bits 1 channels
  483. 2018-12-10 13:16:28.833250 [DEBUG] switch_core_codec.c:123 sofia/default/6835959900@117.247.91.162:5060 Original read codec replaced with G729:18
  484. 2018-12-10 13:16:28.893208 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 320 bytes to accommodate 480->320
  485. 2018-12-10 13:16:29.013247 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed.
  486. 2018-12-10 13:16:29.013247 [DEBUG] switch_core_io.c:1448 Engaging Write Buffer at 480 bytes to accommodate 320->480
  487. 2018-12-10 13:16:29.093214 [DEBUG] sofia.c:7084 Channel sofia/default/7661455301@fs.beconnected.co.za entering state [ready][200]
  488. 2018-12-10 13:16:29.093214 [DEBUG] sofia.c:7094 Remote SDP:
  489. v=0
  490. o=7661455301 8001 8001 IN IP4 117.247.91.162
  491. s=SIP Call
  492. c=IN IP4 117.247.91.162
  493. t=0 0
  494. m=audio 5008 RTP/AVP 18 101
  495. a=rtpmap:18 G729/8000
  496. a=fmtp:18 annexb=no
  497. a=rtpmap:101 telephone-event/8000
  498. a=fmtp:101 0-15
  499. a=ptime:20
  500.  
  501. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1]
  502. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1]
  503. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G729:18:8000:20:8000:1]
  504. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
  505. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
  506. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
  507. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:4767 sofia/default/7661455301@fs.beconnected.co.za Set 2833 dtmf send payload to 101 recv payload to 101
  508. 2018-12-10 13:16:29.093214 [DEBUG] sofia.c:8061 Processing updated SDP
  509. 2018-12-10 13:16:29.093214 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/default/7661455301@fs.beconnected.co.za.
  510. 2018-12-10 13:16:32.253222 [NOTICE] switch_channel.c:1104 New Channel sofia/default/36005@169.255.171.130 [7f5a9ac0-623d-4f34-b914-be8b38416c12]
  511. 2018-12-10 13:16:32.253222 [DEBUG] switch_core_state_machine.c:584 (sofia/default/36005@169.255.171.130) Running State Change CS_NEW (Cur 5 Tot 7800)
  512. 2018-12-10 13:16:32.253222 [DEBUG] sofia.c:9873 sofia/default/36005@169.255.171.130 receiving invite from 158.69.126.203:51535 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
  513. 2018-12-10 13:16:32.253222 [DEBUG] sofia.c:10044 IP 158.69.126.203 Rejected by acl "default". Falling back to Digest auth.
  514. 2018-12-10 13:16:32.253222 [DEBUG] sofia.c:2334 detaching session 7f5a9ac0-623d-4f34-b914-be8b38416c12
  515. 2018-12-10 13:16:32.253222 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [900441492550028@169.255.171.130] from ip 158.69.126.203
  516. 2018-12-10 13:16:32.253222 [DEBUG] switch_core_state_machine.c:603 (sofia/default/36005@169.255.171.130) State NEW
  517. 2018-12-10 13:16:32.393220 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [7222@169.255.171.130] from ip 46.166.151.168
  518. 2018-12-10 13:16:32.573247 [WARNING] sofia_reg.c:2906 Can't find user [7222@169.255.171.130] from 46.166.151.168
  519. You must define a domain called '169.255.171.130' in your directory and add a user with the id="7222" attribute
  520. and you must configure your device to use the proper domain in it's authentication credentials.
  521. 2018-12-10 13:16:32.573247 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [7222@169.255.171.130] from ip 46.166.151.168
  522. 2018-12-10 13:16:33.273217 [NOTICE] switch_channel.c:1104 New Channel sofia/default/980001@169.255.171.130 [e3cb53a1-450d-4e20-82a2-7168186fd9c7]
  523. 2018-12-10 13:16:33.273217 [DEBUG] switch_core_state_machine.c:584 (sofia/default/980001@169.255.171.130) Running State Change CS_NEW (Cur 6 Tot 7801)
  524. 2018-12-10 13:16:33.273217 [DEBUG] sofia.c:9873 sofia/default/980001@169.255.171.130 receiving invite from 37.49.231.131:53999 version: 1.6.19 git 7a77e0b 2017-07-13 12:01:45Z 64bit
  525. 2018-12-10 13:16:33.273217 [DEBUG] sofia.c:10044 IP 37.49.231.131 Rejected by acl "default". Falling back to Digest auth.
  526. 2018-12-10 13:16:33.273217 [DEBUG] sofia.c:2334 detaching session e3cb53a1-450d-4e20-82a2-7168186fd9c7
  527. 2018-12-10 13:16:33.273217 [WARNING] sofia_reg.c:1792 SIP auth challenge (INVITE) on sofia profile 'default' for [000441158220041@169.255.171.130] from ip 37.49.231.131
  528. 2018-12-10 13:16:33.273217 [DEBUG] switch_core_state_machine.c:603 (sofia/default/980001@169.255.171.130) State NEW
  529. 2018-12-10 13:16:36.153245 [WARNING] switch_core_state_machine.c:687 460d13be-b2d8-4019-9ddb-e0f2f467d304 sofia/default/20001@169.255.171.130 Abandoned
  530. 2018-12-10 13:16:36.153245 [NOTICE] switch_core_state_machine.c:690 Hangup sofia/default/20001@169.255.171.130 [CS_NEW] [WRONG_CALL_STATE]
  531. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:584 (sofia/default/20001@169.255.171.130) Running State Change CS_HANGUP (Cur 6 Tot 7801)
  532. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:850 (sofia/default/20001@169.255.171.130) Callstate Change DOWN -> HANGUP
  533. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:852 (sofia/default/20001@169.255.171.130) State HANGUP
  534. 2018-12-10 13:16:36.153245 [DEBUG] mod_sofia.c:438 Channel sofia/default/20001@169.255.171.130 hanging up, cause: WRONG_CALL_STATE
  535. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:60 sofia/default/20001@169.255.171.130 Standard HANGUP, cause: WRONG_CALL_STATE
  536. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:852 (sofia/default/20001@169.255.171.130) State HANGUP going to sleep
  537. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:619 (sofia/default/20001@169.255.171.130) State Change CS_HANGUP -> CS_REPORTING
  538. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:584 (sofia/default/20001@169.255.171.130) Running State Change CS_REPORTING (Cur 6 Tot 7801)
  539. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:938 (sofia/default/20001@169.255.171.130) State REPORTING
  540. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:174 sofia/default/20001@169.255.171.130 Standard REPORTING, cause: WRONG_CALL_STATE
  541. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:938 (sofia/default/20001@169.255.171.130) State REPORTING going to sleep
  542. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:610 (sofia/default/20001@169.255.171.130) State Change CS_REPORTING -> CS_DESTROY
  543. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_session.c:1665 Session 7797 (sofia/default/20001@169.255.171.130) Locked, Waiting on external entities
  544. 2018-12-10 13:16:36.153245 [NOTICE] switch_core_session.c:1683 Session 7797 (sofia/default/20001@169.255.171.130) Ended
  545. 2018-12-10 13:16:36.153245 [NOTICE] switch_core_session.c:1687 Close Channel sofia/default/20001@169.255.171.130 [CS_DESTROY]
  546. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:741 (sofia/default/20001@169.255.171.130) Running State Change CS_DESTROY (Cur 5 Tot 7801)
  547. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:751 (sofia/default/20001@169.255.171.130) State DESTROY
  548. 2018-12-10 13:16:36.153245 [DEBUG] mod_sofia.c:343 sofia/default/20001@169.255.171.130 SOFIA DESTROY
  549. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:181 sofia/default/20001@169.255.171.130 Standard DESTROY
  550. 2018-12-10 13:16:36.153245 [DEBUG] switch_core_state_machine.c:751 (sofia/default/20001@169.255.171.130) State DESTROY going to sleep
  551. 2018-12-10 13:16:36.293254 [WARNING] sofia_reg.c:1792 SIP auth challenge (REGISTER) on sofia profile 'default' for [7188363009@169.255.171.130] from ip 41.13.194.12
  552. 2018-12-10 13:16:36.333266 [WARNING] sofia_reg.c:2906 Can't find user [7188363009@169.255.171.130] from 41.13.194.12
  553. You must define a domain called '169.255.171.130' in your directory and add a user with the id="7188363009" attribute
  554. and you must configure your device to use the proper domain in it's authentication credentials.
  555. 2018-12-10 13:16:36.333266 [WARNING] sofia_reg.c:1737 SIP auth failure (REGISTER) on sofia profile 'default' for [7188363009@169.255.171.130] from ip 41.13.194.12
  556. 2018-12-10 13:16:37.653222 [NOTICE] sofia.c:1012 Hangup sofia/default/6835959900@117.247.91.162:5060 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
  557. 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/6835959900@117.247.91.162:5060]
  558. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:653 (sofia/default/6835959900@117.247.91.162:5060) State EXCHANGE_MEDIA going to sleep
  559. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_HANGUP (Cur 5 Tot 7801)
  560. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:850 (sofia/default/6835959900@117.247.91.162:5060) Callstate Change ACTIVE -> HANGUP
  561. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:852 (sofia/default/6835959900@117.247.91.162:5060) State HANGUP
  562. 2018-12-10 13:16:37.653222 [DEBUG] mod_sofia.c:438 Channel sofia/default/6835959900@117.247.91.162:5060 hanging up, cause: NORMAL_CLEARING
  563. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:60 sofia/default/6835959900@117.247.91.162:5060 Standard HANGUP, cause: NORMAL_CLEARING
  564. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:852 (sofia/default/6835959900@117.247.91.162:5060) State HANGUP going to sleep
  565. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:619 (sofia/default/6835959900@117.247.91.162:5060) State Change CS_HANGUP -> CS_REPORTING
  566. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:584 (sofia/default/6835959900@117.247.91.162:5060) Running State Change CS_REPORTING (Cur 5 Tot 7801)
  567. 2018-12-10 13:16:37.653222 [DEBUG] switch_core_state_machine.c:938 (sofia/default/6835959900@117.247.91.162:5060) State REPORTING
  568. 2018-12-10 13:16:37.653222 [INFO] mod_json_cdr.c:271 Process [806f29a9-ef75-424a-bb7a-e8cb4155ffa0.cdr.json]
  569. 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:706 sofia/default/6835959900@117.247.91.162:5060 ending bridge by request from write function
  570. 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:787 BRIDGE THREAD DONE [sofia/default/7661455301@fs.beconnected.co.za]
  571. 2018-12-10 13:16:37.653222 [DEBUG] switch_ivr_bridge.c:1712 sofia/default/6835959900@117.247.91.162:5060 skip receive message [UNBRIDGE] (channel is hungup already)
  572.