1. nua.c:575 nua_set_params() nua: nua_set_params: entering
2. nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params
3. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
4. soa.c:403 soa_set_params() soa_set_params(static::0x7f8aa4001930, ...) called
5. nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK
6. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
7. nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params
8. nua.c:575 nua_set_params() nua: nua_set_params: entering
9. nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params
10. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
11. soa.c:403 soa_set_params() soa_set_params(static::0x195dc10, ...) called
12. nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK
13. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
14. nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params
15. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
16. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
17. tport.c:2773 tport_wakeup() tport_wakeup(0x18b5d90): events IN
18. tport.c:2864 tport_recv_event() tport_recv_event(0x18b5d90)
19. tport_type_tcp.c:302 tport_recv_stream() tport_recv_stream(0x18b5d90): received keepalive (total 0)
20. tport_type_tcp.c:542 tport_tcp_pong() tport_tcp_pong(0x18b5d90): sending PONG to tcp/197.210.64.58:29139/sip
21. tport.c:2296 tport_set_secondary_timer() tport(0x18b5d90): reset timer
22. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x192f5f0): events IN
23. tport.c:2864 tport_recv_event() tport_recv_event(0x192f5f0)
24. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x192f5f0) msg 0x19421f0 from (udp/139.162.188.90:5060) has 4 bytes, veclen = 1
25. tport.c:3023 tport_deliver() tport_deliver(0x192f5f0): bad msg 0x19421f0 (4 bytes) from udp/197.210.64.58:5060/sip next=(nil)
26. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x192f5f0): events IN
27. tport.c:2864 tport_recv_event() tport_recv_event(0x192f5f0)
28. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x192f5f0) msg 0x193bd40 from (udp/139.162.188.90:5060) has 4 bytes, veclen = 1
29. tport.c:3023 tport_deliver() tport_deliver(0x192f5f0): bad msg 0x193bd40 (4 bytes) from udp/197.210.64.58:5060/sip next=(nil)
30. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f8aa4004c20): events IN
31. tport.c:2864 tport_recv_event() tport_recv_event(0x7f8aa4004c20)
32. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f8aa4004c20) msg 0x7f8aa4009a60 from (udp/139.162.188.90:5080) has 1263 bytes, veclen = 1
33. recv 1263 bytes from udp/[69.164.196.139]:5060 at 16:50:54.036792:
34.    ------------------------------------------------------------------------
35.    INVITE sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea SIP/2.0
36.    Via: SIP/2.0/UDP 69.164.196.139;rport;branch=z9hG4bKH4j65UrNZr3rc
37.    Max-Forwards: 67
38.    From: "08167976335" <sip:08167976335@69.164.196.139>;tag=1m7S9jSHHX9vc
39.    To: <sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea>
40.    Call-ID: d3ec33fd-442a-1237-9285-f23c91f71923
41.    CSeq: 129086262 INVITE
42.    Contact: <sip:mod_sofia@69.164.196.139:5060>
43.    User-Agent: ASTPP
44.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
45.    Supported: path, replaces
46.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
47.    Content-Type: application/sdp
48.    Content-Disposition: session
49.    Content-Length: 224
50.    Remote-Party-ID: "08167976335" <sip:08167976335@69.164.196.139>;party=calling;screen=yes;privacy=off
51.  
52.    v=0
53.    o=FreeSWITCH 1538820536 1538820537 IN IP4 69.164.196.139
54.    s=FreeSWITCH
55.    c=IN IP4 69.164.196.139
56.    t=0 0
57.    m=audio 24116 RTP/AVP 8 101
58.    a=rtpmap:8 PCMA/8000
59.    a=rtpmap:101 telephone-event/8000
60.    a=fmtp:101 0-16
61.    a=ptime:10
62.    ------------------------------------------------------------------------
63. tport.c:3023 tport_deliver() tport_deliver(0x7f8aa4004c20): msg 0x7f8aa4009a60 (1263 bytes) from udp/69.164.196.139:5080/sip next=(nil)
64. nta.c:2880 agent_recv_request() nta: received INVITE sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea SIP/2.0 (CSeq 129086262)
65. nta.c:3248 agent_aliases() nta: canonizing sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080 with contact
66. nta.c:3085 agent_recv_request() nta: INVITE (129086262) going to a default leg
67. nta.c:1350 set_timeout() nta: timer set to 200 ms
68. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
69. nua_stack.c:899 nh_create() nua: nh_create: entering
70. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
71. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
72. soa.c:280 soa_clone() soa_clone(static::0x7f8aa4001930, 0x7f8aa4001130, 0x7f8aa409a950) called
73. soa.c:403 soa_set_params() soa_set_params(static::0x7f8aa409b240, ...) called
74. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f8aa40975e0)
75. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f8aa409b240) called
76. soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f8aa409b240, (nil), 0x7f8aa40128af, 224) called
77. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f8aa409a950): adding session usage
78. tport.c:3257 tport_tsend() tport_tsend(0x7f8aa4004c20) tpn = UDP/69.164.196.139:5060
79. tport.c:4046 tport_resolve() tport_resolve addrinfo = 69.164.196.139:5060
80. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f8aa4004c20): not found by name UDP/69.164.196.139:5060
81. tport.c:3594 tport_vsend() tport_vsend(0x7f8aa4004c20): 400 bytes of 400 to udp/69.164.196.139:5060
82. tport.c:3492 tport_send_msg() tport_vsend returned 400
83. send 400 bytes to udp/[69.164.196.139]:5060 at 16:50:54.037100:
84.    ------------------------------------------------------------------------
85.    SIP/2.0 100 Trying
86.    Via: SIP/2.0/UDP 69.164.196.139;rport=5060;branch=z9hG4bKH4j65UrNZr3rc
87.    From: "08167976335" <sip:08167976335@69.164.196.139>;tag=1m7S9jSHHX9vc
88.    To: <sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea>
89.    Call-ID: d3ec33fd-442a-1237-9285-f23c91f71923
90.    CSeq: 129086262 INVITE
91.    User-Agent: RAYDO
92.    Content-Length: 0
93.  
94.    ------------------------------------------------------------------------
95. nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (129086262)
96. nua_stack.c:271 nua_stack_event() nua(0x7f8aa409a950): event i_invite 100 Trying
97. nua_session.c:4139 signal_call_state_change() nua(0x7f8aa409a950): call state changed: init -> received, received offer
98. soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f8aa409b240, [0x7f8abc6048c8], [0x7f8abc6048d0], [(nil)]) called
99. nua_stack.c:271 nua_stack_event() nua(0x7f8aa409a950): event i_state 100 Trying
100. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
101. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
102. 2018-10-06 16:50:54.032190 [NOTICE] switch_channel.c:1104 New Channel sofia/external/08167976335@69.164.196.139 [a8c5a8e6-b7f5-47ad-9683-6fe61051de60]
103. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
104. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_NEW (Cur 1 Tot 129)
105. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
106. 2018-10-06 16:50:54.032190 [DEBUG] sofia.c:9873 sofia/external/08167976335@69.164.196.139 receiving invite from 69.164.196.139:5060 version: 1.6.20 -37-987c9b9 64bit
107. nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering
108. nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil)
109. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
110. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
111. 2018-10-06 16:50:54.032190 [DEBUG] sofia.c:7084 Channel sofia/external/08167976335@69.164.196.139 entering state [received][100]
112. 2018-10-06 16:50:54.032190 [DEBUG] sofia.c:7094 Remote SDP:
113. v=0
114. o=FreeSWITCH 1538820536 1538820537 IN IP4 69.164.196.139
115. s=FreeSWITCH
116. c=IN IP4 69.164.196.139
117. t=0 0
118. m=audio 24116 RTP/AVP 8 101
119. a=rtpmap:8 PCMA/8000
120. a=rtpmap:101 telephone-event/8000
121. a=fmtp:101 0-16
122. a=ptime:10
123.  
124. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:10:64000:1]/[opus:116:48000:20:0:1]
125. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:10:64000:1]/[G722:9:8000:20:64000:1]
126. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:10:64000:1]/[PCMU:0:8000:20:64000:1]
127. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMA:8:8000:10:64000:1]/[PCMA:8:8000:20:64000:1]
128. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4485 Audio Codec Compare [PCMA:8:8000:20:64000:1] is saved as a near-match
129. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000
130. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4556 Substituting codec PCMA@10i@8000h@1c
131. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/08167976335@69.164.196.139 PCMA/8000 10 ms 80 samples 64000 bits 1 channels
132. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_codec.c:111 sofia/external/08167976335@69.164.196.139 Original read codec set to PCMA:8
133. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000
134. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_media.c:4767 sofia/external/08167976335@69.164.196.139 Set 2833 dtmf send payload to 101 recv payload to 101
135. 2018-10-06 16:50:54.032190 [DEBUG] sofia.c:7507 (sofia/external/08167976335@69.164.196.139) State Change CS_NEW -> CS_INIT
136. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
137. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:603 (sofia/external/08167976335@69.164.196.139) State NEW
138. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_INIT (Cur 1 Tot 129)
139. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:627 (sofia/external/08167976335@69.164.196.139) State INIT
140. 2018-10-06 16:50:54.032190 [DEBUG] mod_sofia.c:90 sofia/external/08167976335@69.164.196.139 SOFIA INIT
141. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:40 sofia/external/08167976335@69.164.196.139 Standard INIT
142. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:48 (sofia/external/08167976335@69.164.196.139) State Change CS_INIT -> CS_ROUTING
143. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:627 (sofia/external/08167976335@69.164.196.139) State INIT going to sleep
144. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_ROUTING (Cur 1 Tot 129)
145. 2018-10-06 16:50:54.032190 [DEBUG] switch_channel.c:2249 (sofia/external/08167976335@69.164.196.139) Callstate Change DOWN -> RINGING
146. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:643 (sofia/external/08167976335@69.164.196.139) State ROUTING
147. 2018-10-06 16:50:54.032190 [DEBUG] mod_sofia.c:143 sofia/external/08167976335@69.164.196.139 SOFIA ROUTING
148. 2018-10-06 16:50:54.032190 [DEBUG] switch_core_state_machine.c:236 sofia/external/08167976335@69.164.196.139 Standard ROUTING
149. 2018-10-06 16:50:54.032190 [INFO] mod_dialplan_xml.c:637 Processing 08167976335 <08167976335>->7737174858 in context public
150. 2018-10-06 16:50:54.032190 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
151. 'Event-Name: REQUEST_PARAMS
152. Core-UUID: e29dc518-8161-4dc3-8fba-b47b545a2cf9
153. FreeSWITCH-Hostname: test-fs-001
154. FreeSWITCH-Switchname: test-fs-001
155. FreeSWITCH-IPv4: 139.162.188.90
156. FreeSWITCH-IPv6: %3A%3A1
157. Event-Date-Local: 2018-10-06%2016%3A50%3A54
158. Event-Date-GMT: Sat,%2006%20Oct%202018%2016%3A50%3A54%20GMT
159. Event-Date-Timestamp: 1538844654032190
160. Event-Calling-File: mod_dialplan_xml.c
161. Event-Calling-Function: dialplan_xml_locate
162. Event-Calling-Line-Number: 608
163. Event-Sequence: 3646
164. Channel-State: CS_ROUTING
165. Channel-Call-State: RINGING
166. Channel-State-Number: 2
167. Channel-Name: sofia/external/08167976335%4069.164.196.139
168. Unique-ID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
169. Call-Direction: inbound
170. Presence-Call-Direction: inbound
171. Channel-HIT-Dialplan: true
172. Channel-Call-UUID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
173. Answer-State: ringing
174. Channel-Read-Codec-Name: PCMA
175. Channel-Read-Codec-Rate: 8000
176. Channel-Read-Codec-Bit-Rate: 64000
177. Channel-Write-Codec-Name: PCMA
178. Channel-Write-Codec-Rate: 8000
179. Channel-Write-Codec-Bit-Rate: 64000
180. Caller-Direction: inbound
181. Caller-Logical-Direction: inbound
182. Caller-Username: 08167976335
183. Caller-Dialplan: XML
184. Caller-Caller-ID-Name: 08167976335
185. Caller-Caller-ID-Number: 08167976335
186. Caller-Orig-Caller-ID-Name: 08167976335
187. Caller-Orig-Caller-ID-Number: 08167976335
188. Caller-Network-Addr: 69.164.196.139
189. Caller-ANI: 08167976335
190. Caller-Destination-Number: 7737174858
191. Caller-Unique-ID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
192. Caller-Source: mod_sofia
193. Caller-Context: public
194. Caller-Channel-Name: sofia/external/08167976335%4069.164.196.139
195. Caller-Profile-Index: 1
196. Caller-Profile-Created-Time: 1538844654032190
197. Caller-Channel-Created-Time: 1538844654032190
198. Caller-Channel-Answered-Time: 0
199. Caller-Channel-Progress-Time: 0
200. Caller-Channel-Progress-Media-Time: 0
201. Caller-Channel-Hangup-Time: 0
202. Caller-Channel-Transfer-Time: 0
203. Caller-Channel-Resurrect-Time: 0
204. Caller-Channel-Bridged-Time: 0
205. Caller-Channel-Last-Hold: 0
206. Caller-Channel-Hold-Accum: 0
207. Caller-Screen-Bit: true
208. Caller-Privacy-Hide-Name: false
209. Caller-Privacy-Hide-Number: false
210. variable_direction: inbound
211. variable_uuid: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
212. variable_session_id: 129
213. variable_sip_from_user: 08167976335
214. variable_sip_from_uri: 08167976335%4069.164.196.139
215. variable_sip_from_host: 69.164.196.139
216. variable_video_media_flow: sendrecv
217. variable_channel_name: sofia/external/08167976335%4069.164.196.139
218. variable_sip_call_id: d3ec33fd-442a-1237-9285-f23c91f71923
219. variable_ep_codec_string: CORE_PCM_MODULE.PCMA%408000h%4010i%4064000b
220. variable_sip_local_network_addr: 139.162.188.90
221. variable_sip_network_ip: 69.164.196.139
222. variable_sip_network_port: 5060
223. variable_sip_invite_stamp: 1538844654032190
224. variable_sip_received_ip: 69.164.196.139
225. variable_sip_received_port: 5060
226. variable_sip_via_protocol: udp
227. variable_sip_from_user_stripped: 08167976335
228. variable_sip_from_tag: 1m7S9jSHHX9vc
229. variable_sofia_profile_name: external
230. variable_recovery_profile_name: external
231. variable_sip_Remote-Party-ID: %2208167976335%22%20%3Csip%3A08167976335%4069.164.196.139%3E%3Bparty%3Dcalling%3Bscreen%3Dyes%3Bprivacy%3Doff
232. variable_sip_cid_type: rpid
233. variable_sip_full_via: SIP/2.0/UDP%2069.164.196.139%3Brport%3D5060%3Bbranch%3Dz9hG4bKH4j65UrNZr3rc
234. variable_sip_from_display: 08167976335
235. variable_sip_full_from: %2208167976335%22%20%3Csip%3A08167976335%4069.164.196.139%3E%3Btag%3D1m7S9jSHHX9vc
236. variable_sip_full_to: %3Csip%3Agw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea%40139.162.188.90%3A5080%3Btransport%3Dudp%3Bgw%3D5f80d9a5-49c7-4197-8ebf-df94cd4671ea%3E
237. variable_sip_allow: INVITE,%20ACK,%20BYE,%20CANCEL,%20OPTIONS,%20MESSAGE,%20INFO,%20UPDATE,%20REGISTER,%20NOTIFY,%20PUBLISH,%20SUBSCRIBE
238. variable_sip_req_params: transport%3Dudp%3Bgw%3D5f80d9a5-49c7-4197-8ebf-df94cd4671ea
239. variable_sip_req_user: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea
240. variable_sip_req_port: 5080
241. variable_sip_req_uri: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea%40139.162.188.90%3A5080
242. variable_sip_req_host: 139.162.188.90
243. variable_sip_to_params: transport%3Dudp%3Bgw%3D5f80d9a5-49c7-4197-8ebf-df94cd4671ea
244. variable_sip_to_user: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea
245. variable_sip_to_port: 5080
246. variable_sip_to_uri: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea%40139.162.188.90%3A5080
247. variable_sip_to_host: 139.162.188.90
248. variable_sip_contact_user: mod_sofia
249. variable_sip_contact_port: 5060
250. variable_sip_contact_uri: mod_sofia%4069.164.196.139%3A5060
251. variable_sip_contact_host: 69.164.196.139
252. variable_sip_user_agent: ASTPP
253. variable_sip_via_host: 69.164.196.139
254. variable_sip_via_rport: 5060
255. variable_max_forwards: 67
256. variable_sip_gateway: 5f80d9a5-49c7-4197-8ebf-df94cd4671ea
257. variable_switch_r_sdp: v%3D0%0D%0Ao%3DFreeSWITCH%201538820536%201538820537%20IN%20IP4%2069.164.196.139%0D%0As%3DFreeSWITCH%0D%0Ac%3DIN%20IP4%2069.164.196.139%0D%0At%3D0%200%0D%0Am%3Daudio%2024116%20RTP/AVP%208%20101%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-16%0D%0Aa%3Dptime%3A10%0D%0A
258. variable_rtp_use_codec_string: OPUS,G722,PCMU,PCMA,VP8
259. variable_audio_media_flow: sendrecv
260. variable_remote_media_ip: 69.164.196.139
261. variable_remote_media_port: 24116
262. variable_rtp_audio_recv_pt: 8
263. variable_rtp_use_codec_name: PCMA
264. variable_rtp_use_codec_rate: 8000
265. variable_rtp_use_codec_ptime: 10
266. variable_rtp_use_codec_channels: 1
267. variable_rtp_last_audio_codec_string: PCMA%408000h%4010i%401c
268. variable_read_codec: PCMA
269. variable_original_read_codec: PCMA
270. variable_read_rate: 8000
271. variable_original_read_rate: 8000
272. variable_write_codec: PCMA
273. variable_write_rate: 8000
274. variable_dtmf_type: rfc2833
275. variable_endpoint_disposition: RECEIVED
276. variable_call_uuid: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
277. Hunt-Direction: inbound
278. Hunt-Logical-Direction: inbound
279. Hunt-Username: 08167976335
280. Hunt-Dialplan: XML
281. Hunt-Caller-ID-Name: 08167976335
282. Hunt-Caller-ID-Number: 08167976335
283. Hunt-Orig-Caller-ID-Name: 08167976335
284. Hunt-Orig-Caller-ID-Number: 08167976335
285. Hunt-Network-Addr: 69.164.196.139
286. Hunt-ANI: 08167976335
287. Hunt-Destination-Number: 7737174858
288. Hunt-Unique-ID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
289. Hunt-Source: mod_sofia
290. Hunt-Context: public
291. Hunt-Channel-Name: sofia/external/08167976335%4069.164.196.139
292. Hunt-Profile-Index: 1
293. Hunt-Profile-Created-Time: 1538844654032190
294. Hunt-Channel-Created-Time: 1538844654032190
295. Hunt-Channel-Answered-Time: 0
296. Hunt-Channel-Progress-Time: 0
297. Hunt-Channel-Progress-Media-Time: 0
298. Hunt-Channel-Hangup-Time: 0
299. Hunt-Channel-Transfer-Time: 0
300. Hunt-Channel-Resurrect-Time: 0
301. Hunt-Channel-Bridged-Time: 0
302. Hunt-Channel-Last-Hold: 0
303. Hunt-Channel-Hold-Accum: 0
304. Hunt-Screen-Bit: true
305. Hunt-Privacy-Hide-Name: false
306. Hunt-Privacy-Hide-Number: false
307.  
308. '
309. 2018-10-06 16:50:54.032190 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: dialplan
310. 2018-10-06 16:50:54.032190 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name:
311. 2018-10-06 16:50:54.032190 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name:
312. 2018-10-06 16:50:54.032190 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value:
313. nta.c:1289 agent_timer() nta: timer not set
314. 2018-10-06 16:50:56.312179 [NOTICE] switch_cpp.cpp:1365 [xml]: <?xml version="1.0" encoding="UTF-8" standalone="no"?>
315. <document type="freeswitch/xml">
316.  
317. <section name="dialplan" description="">
318.  
319.   <context name="public">
320.  
321.     <extension name="018889201" continue="false" uuid="9ee26370-09e7-4df4-876c-87a79f61b30d"><condition field="destination_number" expression="^(018889201)$"></condition></extension>
322.  
323.     <extension name="7737174858" continue="false" uuid="b0f01f9d-4f7b-48be-934e-67129ad860f7"><condition field="destination_number" expression="^(7737174858)$"><action application="set" data="call_direction=inbound" inline="true"/><action application="set" data="domain_uuid=3d9d8d4a-8610-4fc8-bfcf-0e898c1b1dac" inline="true"/><action application="set" data="domain_name=tekart.convodeck.com" inline="true"/><action application="transfer" data="1001 XML tekart.convodeck.com"/></condition></extension>
324.  
325.   </context>
326.  
327. </section>
328.  
329. </document>
330. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [public->018889201] continue=false
331. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (FAIL) [018889201] destination_number(7737174858) =~ /^(018889201)$/ break=on-false
332. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [public->7737174858] continue=false
333. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [7737174858] destination_number(7737174858) =~ /^(7737174858)$/ break=on-false
334. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(call_direction=inbound) INLINE
335. EXECUTE sofia/external/08167976335@69.164.196.139 set(call_direction=inbound)
336. 2018-10-06 16:50:56.312179 [DEBUG] mod_dptools.c:1548 SET sofia/external/08167976335@69.164.196.139 [call_direction]=[inbound]
337. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(domain_uuid=3d9d8d4a-8610-4fc8-bfcf-0e898c1b1dac) INLINE
338. EXECUTE sofia/external/08167976335@69.164.196.139 set(domain_uuid=3d9d8d4a-8610-4fc8-bfcf-0e898c1b1dac)
339. 2018-10-06 16:50:56.312179 [DEBUG] mod_dptools.c:1548 SET sofia/external/08167976335@69.164.196.139 [domain_uuid]=[3d9d8d4a-8610-4fc8-bfcf-0e898c1b1dac]
340. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(domain_name=tekart.convodeck.com) INLINE
341. EXECUTE sofia/external/08167976335@69.164.196.139 set(domain_name=tekart.convodeck.com)
342. 2018-10-06 16:50:56.312179 [DEBUG] mod_dptools.c:1548 SET sofia/external/08167976335@69.164.196.139 [domain_name]=[tekart.convodeck.com]
343. Dialplan: sofia/external/08167976335@69.164.196.139 Action transfer(1001 XML tekart.convodeck.com)
344. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:286 (sofia/external/08167976335@69.164.196.139) State Change CS_ROUTING -> CS_EXECUTE
345. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:643 (sofia/external/08167976335@69.164.196.139) State ROUTING going to sleep
346. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_EXECUTE (Cur 1 Tot 129)
347. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:650 (sofia/external/08167976335@69.164.196.139) State EXECUTE
348. 2018-10-06 16:50:56.312179 [DEBUG] mod_sofia.c:198 sofia/external/08167976335@69.164.196.139 SOFIA EXECUTE
349. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:328 sofia/external/08167976335@69.164.196.139 Standard EXECUTE
350. EXECUTE sofia/external/08167976335@69.164.196.139 transfer(1001 XML tekart.convodeck.com)
351. 2018-10-06 16:50:56.312179 [DEBUG] switch_ivr.c:2165 (sofia/external/08167976335@69.164.196.139) State Change CS_EXECUTE -> CS_ROUTING
352. 2018-10-06 16:50:56.312179 [NOTICE] switch_ivr.c:2172 Transfer sofia/external/08167976335@69.164.196.139 to XML[1001@tekart.convodeck.com]
353. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:650 (sofia/external/08167976335@69.164.196.139) State EXECUTE going to sleep
354. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_ROUTING (Cur 1 Tot 129)
355. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:643 (sofia/external/08167976335@69.164.196.139) State ROUTING
356. 2018-10-06 16:50:56.312179 [DEBUG] mod_sofia.c:143 sofia/external/08167976335@69.164.196.139 SOFIA ROUTING
357. 2018-10-06 16:50:56.312179 [DEBUG] switch_core_state_machine.c:236 sofia/external/08167976335@69.164.196.139 Standard ROUTING
358. 2018-10-06 16:50:56.312179 [INFO] mod_dialplan_xml.c:637 Processing 08167976335 <08167976335>->1001 in context tekart.convodeck.com
359. 2018-10-06 16:50:56.312179 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
360. 'Event-Name: REQUEST_PARAMS
361. Core-UUID: e29dc518-8161-4dc3-8fba-b47b545a2cf9
362. FreeSWITCH-Hostname: test-fs-001
363. FreeSWITCH-Switchname: test-fs-001
364. FreeSWITCH-IPv4: 139.162.188.90
365. FreeSWITCH-IPv6: %3A%3A1
366. Event-Date-Local: 2018-10-06%2016%3A50%3A56
367. Event-Date-GMT: Sat,%2006%20Oct%202018%2016%3A50%3A56%20GMT
368. Event-Date-Timestamp: 1538844656312179
369. Event-Calling-File: mod_dialplan_xml.c
370. Event-Calling-Function: dialplan_xml_locate
371. Event-Calling-Line-Number: 608
372. Event-Sequence: 3658
373. Channel-State: CS_ROUTING
374. Channel-Call-State: RINGING
375. Channel-State-Number: 2
376. Channel-Name: sofia/external/08167976335%4069.164.196.139
377. Unique-ID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
378. Call-Direction: inbound
379. Presence-Call-Direction: inbound
380. Channel-HIT-Dialplan: true
381. Channel-Call-UUID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
382. Answer-State: ringing
383. Channel-Read-Codec-Name: PCMA
384. Channel-Read-Codec-Rate: 8000
385. Channel-Read-Codec-Bit-Rate: 64000
386. Channel-Write-Codec-Name: PCMA
387. Channel-Write-Codec-Rate: 8000
388. Channel-Write-Codec-Bit-Rate: 64000
389. Caller-Direction: inbound
390. Caller-Logical-Direction: inbound
391. Caller-Username: 08167976335
392. Caller-Dialplan: XML
393. Caller-Caller-ID-Name: 08167976335
394. Caller-Caller-ID-Number: 08167976335
395. Caller-Orig-Caller-ID-Name: 08167976335
396. Caller-Orig-Caller-ID-Number: 08167976335
397. Caller-Network-Addr: 69.164.196.139
398. Caller-ANI: 08167976335
399. Caller-Destination-Number: 1001
400. Caller-Unique-ID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
401. Caller-Source: mod_sofia
402. Caller-Transfer-Source: 1538844656%3A88683e5a-fc16-4d7a-9b0c-aa45eea70ad9%3Abl_xfer%3A1001/tekart.convodeck.com/XML
403. Caller-Context: tekart.convodeck.com
404. Caller-RDNIS: 7737174858
405. Caller-Channel-Name: sofia/external/08167976335%4069.164.196.139
406. Caller-Profile-Index: 2
407. Caller-Profile-Created-Time: 1538844656312179
408. Caller-Channel-Created-Time: 1538844654032190
409. Caller-Channel-Answered-Time: 0
410. Caller-Channel-Progress-Time: 0
411. Caller-Channel-Progress-Media-Time: 0
412. Caller-Channel-Hangup-Time: 0
413. Caller-Channel-Transfer-Time: 0
414. Caller-Channel-Resurrect-Time: 0
415. Caller-Channel-Bridged-Time: 0
416. Caller-Channel-Last-Hold: 0
417. Caller-Channel-Hold-Accum: 0
418. Caller-Screen-Bit: true
419. Caller-Privacy-Hide-Name: false
420. Caller-Privacy-Hide-Number: false
421. variable_direction: inbound
422. variable_uuid: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
423. variable_session_id: 129
424. variable_sip_from_user: 08167976335
425. variable_sip_from_uri: 08167976335%4069.164.196.139
426. variable_sip_from_host: 69.164.196.139
427. variable_video_media_flow: sendrecv
428. variable_channel_name: sofia/external/08167976335%4069.164.196.139
429. variable_sip_call_id: d3ec33fd-442a-1237-9285-f23c91f71923
430. variable_ep_codec_string: CORE_PCM_MODULE.PCMA%408000h%4010i%4064000b
431. variable_sip_local_network_addr: 139.162.188.90
432. variable_sip_network_ip: 69.164.196.139
433. variable_sip_network_port: 5060
434. variable_sip_invite_stamp: 1538844654032190
435. variable_sip_received_ip: 69.164.196.139
436. variable_sip_received_port: 5060
437. variable_sip_via_protocol: udp
438. variable_sip_from_user_stripped: 08167976335
439. variable_sip_from_tag: 1m7S9jSHHX9vc
440. variable_sofia_profile_name: external
441. variable_recovery_profile_name: external
442. variable_sip_Remote-Party-ID: %2208167976335%22%20%3Csip%3A08167976335%4069.164.196.139%3E%3Bparty%3Dcalling%3Bscreen%3Dyes%3Bprivacy%3Doff
443. variable_sip_cid_type: rpid
444. variable_sip_full_via: SIP/2.0/UDP%2069.164.196.139%3Brport%3D5060%3Bbranch%3Dz9hG4bKH4j65UrNZr3rc
445. variable_sip_from_display: 08167976335
446. variable_sip_full_from: %2208167976335%22%20%3Csip%3A08167976335%4069.164.196.139%3E%3Btag%3D1m7S9jSHHX9vc
447. variable_sip_full_to: %3Csip%3Agw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea%40139.162.188.90%3A5080%3Btransport%3Dudp%3Bgw%3D5f80d9a5-49c7-4197-8ebf-df94cd4671ea%3E
448. variable_sip_allow: INVITE,%20ACK,%20BYE,%20CANCEL,%20OPTIONS,%20MESSAGE,%20INFO,%20UPDATE,%20REGISTER,%20NOTIFY,%20PUBLISH,%20SUBSCRIBE
449. variable_sip_req_params: transport%3Dudp%3Bgw%3D5f80d9a5-49c7-4197-8ebf-df94cd4671ea
450. variable_sip_req_user: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea
451. variable_sip_req_port: 5080
452. variable_sip_req_uri: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea%40139.162.188.90%3A5080
453. variable_sip_req_host: 139.162.188.90
454. variable_sip_to_params: transport%3Dudp%3Bgw%3D5f80d9a5-49c7-4197-8ebf-df94cd4671ea
455. variable_sip_to_user: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea
456. variable_sip_to_port: 5080
457. variable_sip_to_uri: gw%2B5f80d9a5-49c7-4197-8ebf-df94cd4671ea%40139.162.188.90%3A5080
458. variable_sip_to_host: 139.162.188.90
459. variable_sip_contact_user: mod_sofia
460. variable_sip_contact_port: 5060
461. variable_sip_contact_uri: mod_sofia%4069.164.196.139%3A5060
462. variable_sip_contact_host: 69.164.196.139
463. variable_sip_user_agent: ASTPP
464. variable_sip_via_host: 69.164.196.139
465. variable_sip_via_rport: 5060
466. variable_sip_gateway: 5f80d9a5-49c7-4197-8ebf-df94cd4671ea
467. variable_switch_r_sdp: v%3D0%0D%0Ao%3DFreeSWITCH%201538820536%201538820537%20IN%20IP4%2069.164.196.139%0D%0As%3DFreeSWITCH%0D%0Ac%3DIN%20IP4%2069.164.196.139%0D%0At%3D0%200%0D%0Am%3Daudio%2024116%20RTP/AVP%208%20101%0D%0Aa%3Drtpmap%3A8%20PCMA/8000%0D%0Aa%3Drtpmap%3A101%20telephone-event/8000%0D%0Aa%3Dfmtp%3A101%200-16%0D%0Aa%3Dptime%3A10%0D%0A
468. variable_rtp_use_codec_string: OPUS,G722,PCMU,PCMA,VP8
469. variable_audio_media_flow: sendrecv
470. variable_remote_media_ip: 69.164.196.139
471. variable_remote_media_port: 24116
472. variable_rtp_audio_recv_pt: 8
473. variable_rtp_use_codec_name: PCMA
474. variable_rtp_use_codec_rate: 8000
475. variable_rtp_use_codec_ptime: 10
476. variable_rtp_use_codec_channels: 1
477. variable_rtp_last_audio_codec_string: PCMA%408000h%4010i%401c
478. variable_read_codec: PCMA
479. variable_original_read_codec: PCMA
480. variable_read_rate: 8000
481. variable_original_read_rate: 8000
482. variable_write_codec: PCMA
483. variable_write_rate: 8000
484. variable_dtmf_type: rfc2833
485. variable_endpoint_disposition: RECEIVED
486. variable_DP_MATCH: ARRAY%3A%3A7737174858%7C%3A7737174858
487. variable_call_direction: inbound
488. variable_domain_uuid: 3d9d8d4a-8610-4fc8-bfcf-0e898c1b1dac
489. variable_domain_name: tekart.convodeck.com
490. variable_current_application_data: 1001%20XML%20tekart.convodeck.com
491. variable_current_application: transfer
492. variable_max_forwards: 66
493. variable_transfer_history: 1538844656%3A88683e5a-fc16-4d7a-9b0c-aa45eea70ad9%3Abl_xfer%3A1001/tekart.convodeck.com/XML
494. variable_transfer_source: 1538844656%3A88683e5a-fc16-4d7a-9b0c-aa45eea70ad9%3Abl_xfer%3A1001/tekart.convodeck.com/XML
495. variable_call_uuid: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
496. Hunt-Direction: inbound
497. Hunt-Logical-Direction: inbound
498. Hunt-Username: 08167976335
499. Hunt-Dialplan: XML
500. Hunt-Caller-ID-Name: 08167976335
501. Hunt-Caller-ID-Number: 08167976335
502. Hunt-Orig-Caller-ID-Name: 08167976335
503. Hunt-Orig-Caller-ID-Number: 08167976335
504. Hunt-Network-Addr: 69.164.196.139
505. Hunt-ANI: 08167976335
506. Hunt-Destination-Number: 1001
507. Hunt-Unique-ID: a8c5a8e6-b7f5-47ad-9683-6fe61051de60
508. Hunt-Source: mod_sofia
509. Hunt-Transfer-Source: 1538844656%3A88683e5a-fc16-4d7a-9b0c-aa45eea70ad9%3Abl_xfer%3A1001/tekart.convodeck.com/XML
510. Hunt-Context: tekart.convodeck.com
511. Hunt-RDNIS: 7737174858
512. Hunt-Channel-Name: sofia/external/08167976335%4069.164.196.139
513. Hunt-Profile-Index: 2
514. Hunt-Profile-Created-Time: 1538844656312179
515. Hunt-Channel-Created-Time: 1538844654032190
516. Hunt-Channel-Answered-Time: 0
517. Hunt-Channel-Progress-Time: 0
518. Hunt-Channel-Progress-Media-Time: 0
519. Hunt-Channel-Hangup-Time: 0
520. Hunt-Channel-Transfer-Time: 0
521. Hunt-Channel-Resurrect-Time: 0
522. Hunt-Channel-Bridged-Time: 0
523. Hunt-Channel-Last-Hold: 0
524. Hunt-Channel-Hold-Accum: 0
525. Hunt-Screen-Bit: true
526. Hunt-Privacy-Hide-Name: false
527. Hunt-Privacy-Hide-Number: false
528.  
529. '
530. 2018-10-06 16:50:56.312179 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: dialplan
531. 2018-10-06 16:50:56.312179 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name:
532. 2018-10-06 16:50:56.312179 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name:
533. 2018-10-06 16:50:56.312179 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value:
534. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f8aa4004c20): events IN
535. tport.c:2864 tport_recv_event() tport_recv_event(0x7f8aa4004c20)
536. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f8aa4004c20) msg 0x7f8aa4212da0 from (udp/139.162.188.90:5080) has 548 bytes, veclen = 1
537. recv 548 bytes from udp/[69.164.196.139]:5060 at 16:50:59.669688:
538.    ------------------------------------------------------------------------
539.    CANCEL sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea SIP/2.0
540.    Via: SIP/2.0/UDP 69.164.196.139;rport;branch=z9hG4bKH4j65UrNZr3rc
541.    Max-Forwards: 67
542.    From: "08167976335" <sip:08167976335@69.164.196.139>;tag=1m7S9jSHHX9vc
543.    To: <sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea>
544.    Call-ID: d3ec33fd-442a-1237-9285-f23c91f71923
545.    CSeq: 129086262 CANCEL
546.    Reason: SIP;cause=480;text="NO_ANSWER"
547.    Content-Length: 0
548.  
549.    ------------------------------------------------------------------------
550. tport.c:3023 tport_deliver() tport_deliver(0x7f8aa4004c20): msg 0x7f8aa4212da0 (548 bytes) from udp/69.164.196.139:5080/sip next=(nil)
551. nta.c:2880 agent_recv_request() nta: received CANCEL sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea SIP/2.0 (CSeq 129086262)
552. nta.c:3026 agent_recv_request() nta: CANCEL (129086262) is going to INVITE (129086262)
553. tport.c:3257 tport_tsend() tport_tsend(0x7f8aa4004c20) tpn = UDP/69.164.196.139:5060
554. tport.c:4046 tport_resolve() tport_resolve addrinfo = 69.164.196.139:5060
555. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f8aa4004c20): not found by name UDP/69.164.196.139:5060
556. tport.c:3594 tport_vsend() tport_vsend(0x7f8aa4004c20): 395 bytes of 395 to udp/69.164.196.139:5060
557. tport.c:3492 tport_send_msg() tport_vsend returned 395
558. send 395 bytes to udp/[69.164.196.139]:5060 at 16:50:59.669873:
559.    ------------------------------------------------------------------------
560.    SIP/2.0 200 OK
561.    Via: SIP/2.0/UDP 69.164.196.139;rport=5060;branch=z9hG4bKH4j65UrNZr3rc
562.    From: "08167976335" <sip:08167976335@69.164.196.139>;tag=1m7S9jSHHX9vc
563.    To: <sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea>;tag=pptcQ4Qt24tam
564.    Call-ID: d3ec33fd-442a-1237-9285-f23c91f71923
565.    CSeq: 129086262 CANCEL
566.    Content-Length: 0
567.  
568.    ------------------------------------------------------------------------
569. nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering
570. nua_stack.c:271 nua_stack_event() nua(0x7f8aa409a950): event i_cancel 200 OK
571. nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering
572. soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f8aa409b240) called
573. tport.c:3257 tport_tsend() tport_tsend(0x7f8aa4004c20) tpn = UDP/69.164.196.139:5060
574. tport.c:4046 tport_resolve() tport_resolve addrinfo = 69.164.196.139:5060
575. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f8aa4004c20): not found by name UDP/69.164.196.139:5060
576. tport.c:3594 tport_vsend() tport_vsend(0x7f8aa4004c20): 624 bytes of 624 to udp/69.164.196.139:5060
577. tport.c:3492 tport_send_msg() tport_vsend returned 624
578. send 624 bytes to udp/[69.164.196.139]:5060 at 16:50:59.670029:
579.    ------------------------------------------------------------------------
580.    SIP/2.0 487 Request Terminated
581.    Via: SIP/2.0/UDP 69.164.196.139;rport=5060;branch=z9hG4bKH4j65UrNZr3rc
582.    From: "08167976335" <sip:08167976335@69.164.196.139>;tag=1m7S9jSHHX9vc
583.    To: <sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea>;tag=pptcQ4Qt24tam
584.    Call-ID: d3ec33fd-442a-1237-9285-f23c91f71923
585.    CSeq: 129086262 INVITE
586.    User-Agent: RAYDO
587.    Accept: application/sdp
588.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
589.    Supported: timer, path, replaces
590.    Allow-Events: talk, hold, conference, refer
591.    Content-Length: 0
592.  
593.    ------------------------------------------------------------------------
594. nta.c:6791 incoming_reply() nta: sent 487 Request Terminated for INVITE (129086262)
595. nta.c:1350 set_timeout() nta: timer set to 500 ms
596. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f8aa409a950): removing session usage
597. nua_session.c:4139 signal_call_state_change() nua(0x7f8aa409a950): call state changed: received -> terminated
598. nua_stack.c:271 nua_stack_event() nua(0x7f8aa409a950): event i_state 487 Request Terminated
599. nua_stack.c:271 nua_stack_event() nua(0x7f8aa409a950): event i_terminated 487 Request Terminated
600. soa.c:356 soa_destroy() soa_destroy(static::0x7f8aa409b240) called
601. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f8aa40975e0)
602. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
603. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
604. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
605. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f8aa4004c20): events IN
606. tport.c:2864 tport_recv_event() tport_recv_event(0x7f8aa4004c20)
607. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f8aa4004c20) msg 0x7f8aa4098c70 from (udp/139.162.188.90:5080) has 520 bytes, veclen = 1
608. recv 520 bytes from udp/[69.164.196.139]:5060 at 16:50:59.793812:
609.    ------------------------------------------------------------------------
610.    ACK sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea SIP/2.0
611.    Via: SIP/2.0/UDP 69.164.196.139;rport;branch=z9hG4bKH4j65UrNZr3rc
612.    Max-Forwards: 67
613.    From: "08167976335" <sip:08167976335@69.164.196.139>;tag=1m7S9jSHHX9vc
614.    To: <sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea>;tag=pptcQ4Qt24tam
615.    Call-ID: d3ec33fd-442a-1237-9285-f23c91f71923
616.    CSeq: 129086262 ACK
617.    Content-Length: 0
618.  
619.    ------------------------------------------------------------------------
620. tport.c:3023 tport_deliver() tport_deliver(0x7f8aa4004c20): msg 0x7f8aa4098c70 (520 bytes) from udp/69.164.196.139:5080/sip next=(nil)
621. nta.c:2880 agent_recv_request() nta: received ACK sip:gw+5f80d9a5-49c7-4197-8ebf-df94cd4671ea@139.162.188.90:5080;transport=udp;gw=5f80d9a5-49c7-4197-8ebf-df94cd4671ea SIP/2.0 (CSeq 129086262)
622. nta.c:3019 agent_recv_request() nta: ACK (129086262) is going to INVITE (129086262)
623. nta.c:1296 agent_timer() nta: timer set next to 4622 ms
624. 2018-10-06 16:51:00.712283 [NOTICE] switch_cpp.cpp:1365 [xml]: <?xml version="1.0" encoding="UTF-8" standalone="no"?>
625. <document type="freeswitch/xml">
626.  
627. <section name="dialplan" description="">
628.  
629.   <context name="tekart.convodeck.com">
630.  
631.     <extension name="user_exists" continue="true" uuid="d22d4d07-66a3-430a-9af3-7ed16c9ec5e2"><condition field="" expression=""><action application="set" data="user_exists=${user_exists id ${destination_number} ${domain_name}}" inline="true"/></condition><condition field="${user_exists}" expression="^true$"><action application="set" data="extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}"/><action application="set" data="hold_music=${user_data ${destination_number}@${domain_name} var hold_music}"/></condition></extension>
632.  
633.     <extension name="call-direction" continue="true" uuid="963f09de-2f51-49c4-907c-92e7036977a1"><condition field="${call_direction}" expression="^(inbound|outbound|local)$" break="never"><anti-action application="set" data="call_direction=local"/></condition></extension>
634.  
635.     <extension name="variables" continue="true" uuid="8943a7d3-a14d-4e3b-8473-195dfe739fda"><condition field="" expression=""><action application="export" data="origination_callee_id_name=${destination_number}"/><action application="set" data="RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}"/></condition></extension>
636.  
637.     <extension name="International" continue="false" uuid="a59a8266-5d56-4ff5-a44d-2c572eeb6060"><condition field="${user_exists}" expression="false"/><condition field="destination_number" expression="^(\d{12,20})$"><action application="set" data="call_direction=outbound"/><action application="set" data="hangup_after_bridge=true"/><action application="set" data="effective_caller_id_name=${outbound_caller_id_name}"/><action application="set" data="effective_caller_id_number=${outbound_caller_id_number}"/><action application="set" data="inherit_codec=true"/><action application="set" data="ignore_display_updates=true"/><action application="set" data="callee_id_number=$1"/><action application="set" data="continue_on_fail=true"/><action application="bridge" data="sofia/gateway/5f80d9a5-49c7-4197-8ebf-df94cd4671ea/$1"/></condition></extension>
638.  
639.     <extension name="Local" continue="false" uuid="fed490d2-0632-4fa3-ae40-982126641804"><condition field="${user_exists}" expression="false"/><condition field="destination_number" expression="^0(\d{8,20})$"><action application="set" data="call_direction=outbound"/><action application="set" data="hangup_after_bridge=true"/><action application="set" data="effective_caller_id_name=${outbound_caller_id_name}"/><action application="set" data="effective_caller_id_number=${outbound_caller_id_number}"/><action application="set" data="inherit_codec=true"/><action application="set" data="ignore_display_updates=true"/><action application="set" data="callee_id_number=$1"/><action application="set" data="continue_on_fail=true"/><action application="set" data="outbound_prefix=0"/><action application="bridge" data="sofia/gateway/5f80d9a5-49c7-4197-8ebf-df94cd4671ea/234$1"/></condition></extension>
640.  
641.     <extension name="hold_music" continue="false" uuid="186cc900-157d-4d87-aaa5-117f2f4f1172"><condition field="destination_number" expression="^\*9664$"/><condition field="${sip_has_crypto}" expression="^(AES_CM_128_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_80)$"><action application="answer" data=""/><action application="execute_extension" data="is_secure XML ${context}"/><action application="playback" data="$${hold_music}"/><anti-action application="set" data="zrtp_secure_media=true"/><anti-action application="answer" data=""/><anti-action application="playback" data="silence_stream://2000"/><anti-action application="execute_extension" data="is_zrtp_secure XML ${context}"/><anti-action application="playback" data="$${hold_music}"/></condition></extension>
642.  
643.     <extension name="freeswitch_conference" continue="false" uuid="6e6e9019-4813-42a7-ad06-b06853da531b"><condition field="destination_number" expression="^\*9(888|8888|1616|3232)$"><action application="export" data="hold_music=silence"/><action application="bridge" data="sofia/${use_profile}/$1@conference.freeswitch.org"/></condition></extension>
644.  
645.     <extension name="local_extension" continue="true" uuid="7dd7469e-8207-454a-a6c9-6f1c28577323"><condition field="${user_exists}" expression="true"><action application="export" data="dialed_extension=${destination_number}" inline="true"/><action application="limit" data="hash ${domain_name} ${destination_number} ${limit_max} ${limit_destination}" inline="false"/></condition><condition field="${sip_authorized}" expression="true" break="never"><action application="set" data="bind_target=both" inline="true"/><anti-action application="set" data="bind_target=peer" inline="true"/></condition><condition field="" expression=""><action application="set" data="hangup_after_bridge=true"/><action application="set" data="continue_on_fail=true"/><action application="export" data="domain_name=${context}"/><action application="bridge" data="user/${destination_number}@${domain_name}"/></condition></extension>
646.  
647.   </context>
648.  
649. </section>
650.  
651. </document>
652. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->user_exists] continue=true
653. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [user_exists] () =~ // break=on-false
654. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE
655. 2018-10-06 16:51:00.722169 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
656. 'Event-Name: REQUEST_PARAMS
657. Core-UUID: e29dc518-8161-4dc3-8fba-b47b545a2cf9
658. FreeSWITCH-Hostname: test-fs-001
659. FreeSWITCH-Switchname: test-fs-001
660. FreeSWITCH-IPv4: 139.162.188.90
661. FreeSWITCH-IPv6: %3A%3A1
662. Event-Date-Local: 2018-10-06%2016%3A51%3A00
663. Event-Date-GMT: Sat,%2006%20Oct%202018%2016%3A51%3A00%20GMT
664. Event-Date-Timestamp: 1538844660722169
665. Event-Calling-File: switch_xml.c
666. Event-Calling-Function: switch_xml_locate_user
667. Event-Calling-Line-Number: 2109
668. Event-Sequence: 3661
669. key: id
670. user: 1001
671. domain: tekart.convodeck.com
672.  
673. '
674. 2018-10-06 16:51:00.722169 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: directory
675. 2018-10-06 16:51:00.722169 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name: domain
676. 2018-10-06 16:51:00.722169 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name: name
677. 2018-10-06 16:51:00.722169 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value: tekart.convodeck.com
678. 2018-10-06 16:51:02.672615 [NOTICE] switch_cpp.cpp:1365 [xml]: <?xml version="1.0" encoding="UTF-8" standalone="no"?>
679. <document type="freeswitch/xml">
680.  
681. <section name="directory">
682.  
683.   <domain name="tekart.convodeck.com" alias="true">
684.     <params>
685.       <param name="jsonrpc-allowed-methods" value="verto"/>
686.       <param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
687.     </params>
688.     <groups>
689.       <group name="default">
690.         <users>
691.  
692.           <user id="1001">
693.  
694.                   <params>
695.                     <param name="password" value=""/>
696.                     <param name="vm-enabled" value="false"/>
697.  
698.  
699.                     <param name="dial-string" value="{^^:sip_invite_domain=tekart.convodeck.com:presence_id=1001@tekart.convodeck.com}${sofia_contact(*/1001@tekart.convodeck.com)},${verto_contact 1001@tekart.convodeck.com}"/>
700.  
701.                     <param name="verto-context" value="tekart.convodeck.com"/>
702.                     <param name="verto-dialplan" value="XML"/>
703.                     <param name="jsonrpc-allowed-methods" value="verto"/>
704.                     <param name="jsonrpc-allowed-event-channels" value="demo,conference,presence"/>
705.                   </params>
706.                   <variables>
707.                     <variable name="domain_uuid" value="3d9d8d4a-8610-4fc8-bfcf-0e898c1b1dac"/>
708.                     <varibale name="domain_name" value="tekart.convodeck.com"/>
709.                     <variable name="user_id" value="4"/>
710.                     <variable name="extension_uuid" value="ca301077-645a-4740-a33a-e5989c8b4ab4"/>
711.                     <variable name="call_timeout" value="30"/>
712.                     <variable name="caller_id_name" value="1001"/>
713.                     <variable name="caller_id_number" value="1001"/>
714.                     <variable name="presence_id" value="1001@tekart.convodeck.com"/>
715.  
716.                     <variable name="user_context" value="tekart.convodeck.com"/>
717.  
718.  
719.  
720.  
721.                         <variable name="hold_music" value="local_stream://default"/>
722.  
723.  
724.  
725.  
726.  
727.  
728.  
729.  
730.  
731.                         <variable name="directory-visible" value="true"/>
732.  
733.  
734.                         <variable name="directory-exten-visible" value="true"/>
735.  
736.  
737.                         <variable name="limit_max" value="5"/>
738.  
739.  
740.  
741.  
742.  
743.  
744.  
745.  
746.                     <variable name="record_stereo" value="true"/>
747.                     <variable name="export_vars" value="domain_name"/>
748.                   </variables>
749.           </user>
750.         </users>
751.       </group>
752.     </groups>
753.   </domain>
754.  
755. </section>
756.  
757. </document>
758. EXECUTE sofia/external/08167976335@69.164.196.139 set(user_exists=true)
759. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
760. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
761. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
762. 2018-10-06 16:51:02.672615 [DEBUG] sofia.c:7084 Channel sofia/external/08167976335@69.164.196.139 entering state [terminated][487]
763. 2018-10-06 16:51:02.672615 [NOTICE] sofia.c:8273 Hangup sofia/external/08167976335@69.164.196.139 [CS_ROUTING] [ORIGINATOR_CANCEL]
764. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
765. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
766. nua_stack.c:569 nua_stack_signal() nua(0x7f8aa409a950): recv signal r_destroy
767. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
768. nua_stack.c:529 nua_signal() nua(0x7f8aa409a950): sent signal r_destroy
769. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
770. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
771. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
772. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
773. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
774. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
775. 2018-10-06 16:51:02.672615 [DEBUG] mod_dptools.c:1548 SET sofia/external/08167976335@69.164.196.139 [user_exists]=[true]
776. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_session.c:2815 sofia/external/08167976335@69.164.196.139 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
777. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false
778. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid})
779. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music})
780. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->call-direction] continue=true
781. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [call-direction] ${call_direction}(inbound) =~ /^(inbound|outbound|local)$/ break=never
782. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->variables] continue=true
783. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [variables] () =~ // break=on-false
784. Dialplan: sofia/external/08167976335@69.164.196.139 Action export(origination_callee_id_name=${destination_number})
785. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)})
786. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->International] continue=false
787. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (FAIL) [International] ${user_exists}(true) =~ /false/ break=on-false
788. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->Local] continue=false
789. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (FAIL) [Local] ${user_exists}(true) =~ /false/ break=on-false
790. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->hold_music] continue=false
791. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (FAIL) [hold_music] destination_number(1001) =~ /^\*9664$/ break=on-false
792. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->freeswitch_conference] continue=false
793. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (FAIL) [freeswitch_conference] destination_number(1001) =~ /^\*9(888|8888|1616|3232)$/ break=on-false
794. Dialplan: sofia/external/08167976335@69.164.196.139 parsing [tekart.convodeck.com->local_extension] continue=true
795. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [local_extension] ${user_exists}(true) =~ /true/ break=on-false
796. Dialplan: sofia/external/08167976335@69.164.196.139 Action export(dialed_extension=${destination_number}) INLINE
797. EXECUTE sofia/external/08167976335@69.164.196.139 export(dialed_extension=1001)
798. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_session.c:2800 sofia/external/08167976335@69.164.196.139 skip receive message [APPLICATION_EXEC] (channel is hungup already)
799. 2018-10-06 16:51:02.672615 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1001]
800. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_session.c:2815 sofia/external/08167976335@69.164.196.139 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
801. Dialplan: sofia/external/08167976335@69.164.196.139 Action limit(hash ${domain_name} ${destination_number} ${limit_max} ${limit_destination})
802. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (FAIL) [local_extension] ${sip_authorized}() =~ /true/ break=never
803. Dialplan: sofia/external/08167976335@69.164.196.139 ANTI-Action set(bind_target=peer) INLINE
804. EXECUTE sofia/external/08167976335@69.164.196.139 set(bind_target=peer)
805. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_session.c:2800 sofia/external/08167976335@69.164.196.139 skip receive message [APPLICATION_EXEC] (channel is hungup already)
806. 2018-10-06 16:51:02.672615 [DEBUG] mod_dptools.c:1548 SET sofia/external/08167976335@69.164.196.139 [bind_target]=[peer]
807. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_session.c:2815 sofia/external/08167976335@69.164.196.139 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
808. Dialplan: sofia/external/08167976335@69.164.196.139 Regex (PASS) [local_extension] () =~ // break=on-false
809. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(hangup_after_bridge=true)
810. Dialplan: sofia/external/08167976335@69.164.196.139 Action set(continue_on_fail=true)
811. Dialplan: sofia/external/08167976335@69.164.196.139 Action export(domain_name=${context})
812. Dialplan: sofia/external/08167976335@69.164.196.139 Action bridge(user/${destination_number}@${domain_name})
813. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:643 (sofia/external/08167976335@69.164.196.139) State ROUTING going to sleep
814. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_HANGUP (Cur 1 Tot 129)
815. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:850 (sofia/external/08167976335@69.164.196.139) Callstate Change RINGING -> HANGUP
816. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:852 (sofia/external/08167976335@69.164.196.139) State HANGUP
817. 2018-10-06 16:51:02.672615 [DEBUG] mod_sofia.c:438 Channel sofia/external/08167976335@69.164.196.139 hanging up, cause: ORIGINATOR_CANCEL
818. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:60 sofia/external/08167976335@69.164.196.139 Standard HANGUP, cause: ORIGINATOR_CANCEL
819. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:852 (sofia/external/08167976335@69.164.196.139) State HANGUP going to sleep
820. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:619 (sofia/external/08167976335@69.164.196.139) State Change CS_HANGUP -> CS_REPORTING
821. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:584 (sofia/external/08167976335@69.164.196.139) Running State Change CS_REPORTING (Cur 1 Tot 129)
822. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:938 (sofia/external/08167976335@69.164.196.139) State REPORTING
823. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:174 sofia/external/08167976335@69.164.196.139 Standard REPORTING, cause: ORIGINATOR_CANCEL
824. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:938 (sofia/external/08167976335@69.164.196.139) State REPORTING going to sleep
825. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:610 (sofia/external/08167976335@69.164.196.139) State Change CS_REPORTING -> CS_DESTROY
826. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_session.c:1665 Session 129 (sofia/external/08167976335@69.164.196.139) Locked, Waiting on external entities
827. 2018-10-06 16:51:02.672615 [NOTICE] switch_core_session.c:1683 Session 129 (sofia/external/08167976335@69.164.196.139) Ended
828. 2018-10-06 16:51:02.672615 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/08167976335@69.164.196.139 [CS_DESTROY]
829. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:741 (sofia/external/08167976335@69.164.196.139) Running State Change CS_DESTROY (Cur 0 Tot 129)
830. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:751 (sofia/external/08167976335@69.164.196.139) State DESTROY
831. 2018-10-06 16:51:02.672615 [DEBUG] mod_sofia.c:343 sofia/external/08167976335@69.164.196.139 SOFIA DESTROY
832. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:181 sofia/external/08167976335@69.164.196.139 Standard DESTROY
833. 2018-10-06 16:51:02.672615 [DEBUG] switch_core_state_machine.c:751 (sofia/external/08167976335@69.164.196.139) State DESTROY going to sleep
834. tport.c:2773 tport_wakeup() tport_wakeup(0x18b5d90): events IN
835. tport.c:2864 tport_recv_event() tport_recv_event(0x18b5d90)
836. tport_type_tcp.c:302 tport_recv_stream() tport_recv_stream(0x18b5d90): received keepalive (total 0)
837. tport_type_tcp.c:542 tport_tcp_pong() tport_tcp_pong(0x18b5d90): sending PONG to tcp/197.210.64.58:29139/sip
838. tport.c:2296 tport_set_secondary_timer() tport(0x18b5d90): reset timer
839. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x192f5f0): events IN
840. tport.c:2864 tport_recv_event() tport_recv_event(0x192f5f0)
841. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x192f5f0) msg 0x1efac10 from (udp/139.162.188.90:5060) has 619 bytes, veclen = 1
842. recv 619 bytes from udp/[197.210.64.58]:49804 at 16:51:04.783151:
843.    ------------------------------------------------------------------------
844.    SUBSCRIBE sip:1000@139.162.188.90:5060 SIP/2.0
845.    Via: SIP/2.0/UDP 192.168.43.205:49804;branch=z9hG4bK-524287-1---44ad3b7a5dc80340;rport
846.    Max-Forwards: 70
847.    Contact: <sip:1000@192.168.43.205:49804>
848.    To: <sip:1000@tekart.convodeck.com>;tag=zQK6B2CGGDLY
849.    From: "1000" <sip:1000@tekart.convodeck.com>;tag=b446301c
850.    Call-ID: 92361YjdlZjc3Y2Y1ZTdkNWRkMTc5OGNiOWE5MzNiMTI0NGQ
851.    CSeq: 4 SUBSCRIBE
852.    Expires: 300
853.    Accept: application/simple-message-summary
854.   Allow: SUBSCRIBE, NOTIFY, INVITE, ACK, CANCEL, BYE, REFER, INFO, OPTIONS, MESSAGE
855.    User-Agent: X-Lite release 5.3.1 stamp 92361
856.    Event: message-summary
857.    Content-Length: 0
858.  
859.    ------------------------------------------------------------------------
860. tport.c:3023 tport_deliver() tport_deliver(0x192f5f0): msg 0x1efac10 (619 bytes) from udp/197.210.64.58:5060/sip next=(nil)
861. nta.c:2880 agent_recv_request() nta: received SUBSCRIBE sip:1000@139.162.188.90:5060 SIP/2.0 (CSeq 4)
862. nta.c:3174 agent_check_request_via() nta: Via check: received=197.210.64.58
863. nta.c:3248 agent_aliases() nta: canonizing sip:1000@139.162.188.90:5060 with contact
864. nta.c:3085 agent_recv_request() nta: SUBSCRIBE (4) going to a default leg
865. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
866. nua_stack.c:899 nh_create() nua: nh_create: entering
867. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
868. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
869. soa.c:280 soa_clone() soa_clone(static::0x195dc10, 0x1c4c300, 0x18830c0) called
870. soa.c:403 soa_set_params() soa_set_params(static::0x19c7490, ...) called
871. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x1df4740)
872. nua_dialog.c:338 nua_dialog_usage_add() nua(0x18830c0): adding notify usage with event message-summary
873. nua_stack.c:271 nua_stack_event() nua(0x18830c0): event i_subscribe 100 Trying
874. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
875. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
876. nua_dialog.c:564 nua_dialog_usage_set_refresh_range() nua(): refresh notify after 300 seconds (in [300..300])
877. nua.c:879 nua_respond() nua: nua_respond: entering
878. nua_stack.c:573 nua_stack_signal() nua(0x18830c0): recv signal r_respond 202 Accepted
879. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
880. soa.c:403 soa_set_params() soa_set_params(static::0x19c7490, ...) called
881. tport.c:3257 tport_tsend() tport_tsend(0x192f5f0) tpn = UDP/197.210.64.58:49804
882. tport.c:4046 tport_resolve() tport_resolve addrinfo = 197.210.64.58:49804
883. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x192f5f0): not found by name UDP/197.210.64.58:49804
884. tport.c:3594 tport_vsend() tport_vsend(0x192f5f0): 780 bytes of 780 to udp/197.210.64.58:49804
885. tport.c:3492 tport_send_msg() tport_vsend returned 780
886. send 780 bytes to udp/[197.210.64.58]:49804 at 16:51:04.784463:
887.    ------------------------------------------------------------------------
888.    SIP/2.0 202 Accepted
889.    Via: SIP/2.0/UDP 192.168.43.205:49804;branch=z9hG4bK-524287-1---44ad3b7a5dc80340;rport=49804;received=197.210.64.58
890.    From: "1000" <sip:1000@tekart.convodeck.com>;tag=b446301c
891.    To: <sip:1000@tekart.convodeck.com>;tag=zQK6B2CGGDLY
892.    Call-ID: 92361YjdlZjc3Y2Y1ZTdkNWRkMTc5OGNiOWE5MzNiMTI0NGQ
893.    CSeq: 4 SUBSCRIBE
894.    Contact: <sip:1000@139.162.188.90:5060>
895.    Expires: 300
896.    User-Agent: RAYDO
897.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
898.    Supported: timer, path, replaces
899.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
900.    Subscription-State: active;expires=300
901.    Content-Length: 0
902.  
903.    ------------------------------------------------------------------------
904. nta.c:6791 incoming_reply() nta: sent 202 Accepted for SUBSCRIBE (4)
905. nta.c:1350 set_timeout() nta: timer set to 32000 ms
906. nua_stack.c:529 nua_signal() nua(0x18830c0): sent signal r_respond
907. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
908. nua_stack.c:569 nua_stack_signal() nua(0x18830c0): recv signal r_destroy
909. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x18830c0): removing notify usage with event message-summary
910. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x1df4740)
911. soa.c:356 soa_destroy() soa_destroy(static::0x19c7490) called
912. nua_stack.c:529 nua_signal() nua(0x18830c0): sent signal r_destroy
913. nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 487 response
914. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f8abc604c60)
915. nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
916. nta.c:1289 agent_timer() nta: timer not set
917. 2018-10-06 16:51:04.912181 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
918. 'Event-Name: GENERAL
919. Core-UUID: e29dc518-8161-4dc3-8fba-b47b545a2cf9
920. FreeSWITCH-Hostname: test-fs-001
921. FreeSWITCH-Switchname: test-fs-001
922. FreeSWITCH-IPv4: 139.162.188.90
923. FreeSWITCH-IPv6: %3A%3A1
924. Event-Date-Local: 2018-10-06%2016%3A51%3A04
925. Event-Date-GMT: Sat,%2006%20Oct%202018%2016%3A51%3A04%20GMT
926. Event-Date-Timestamp: 1538844664912181
927. Event-Calling-File: mod_voicemail.c
928. Event-Calling-Function: resolve_id
929. Event-Calling-Line-Number: 1363
930. Event-Sequence: 3677
931. action: message-count
932. key: id
933. user: 1000
934. domain: tekart.convodeck.com
935.  
936. '
937. 2018-10-06 16:51:04.912181 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: directory
938. 2018-10-06 16:51:04.912181 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name: domain
939. 2018-10-06 16:51:04.912181 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name: name
940. 2018-10-06 16:51:04.912181 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value: tekart.convodeck.com
941. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
942. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
943. nua.c:657 nua_options() nua: nua_options: entering
944. nua_stack.c:569 nua_stack_signal() nua(0x7f8aa04d9140): recv signal r_options
945. nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering
946. soa.c:280 soa_clone() soa_clone(static::0x7f8aa4001930, 0x7f8aa4001130, 0x7f8aa04d9140) called
947. soa.c:403 soa_set_params() soa_set_params(static::0x7f8aa41d2ba0, ...) called
948. soa.c:403 soa_set_params() soa_set_params(static::0x7f8aa41d2ba0, ...) called
949. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
950. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f8aa4002e80, SRV, "_sip._udp.vgw.xoip.biz.") called
951. sres_cache.c:318 sres_cache_get() sres_cache_get(0x7f8aa4002e80, SRV, "_sip._udp.vgw.xoip.biz.") returned 1 entries
952. nta.c:10598 outgoing_query_srv() nta: for "vgw.xoip.biz" query "_sip._udp.vgw.xoip.biz" SRV (cached)
953. sres_cache.c:272 sres_cache_get() sres_cache_get(0x7f8aa4002e80, A, "vgw.xoip.biz.") called
954. nta.c:10803 outgoing_query_a() nta: for "vgw.xoip.biz" query "vgw.xoip.biz" A
955. sres.c:968 sres_query() sres_query(0x7f8aa4002ba0, 0x7f8aa41df2a0, A, "vgw.xoip.biz") called
956. sres.c:2730 sres_send_dns_query() sres_send_dns_query(0x7f8aa4002ba0, 0x7f8aa4209a40) called
957. sres.c:2819 sres_send_dns_query() sres_send_dns_query(0x7f8aa4002ba0, 0x7f8aa4209a40) id=13931 A vgw.xoip.biz (to [139.162.133.5]:53)
958. nua_stack.c:529 nua_signal() nua(0x7f8aa04d9140): sent signal r_options
959. sres.c:3467 sres_resolver_receive() sres_resolver_receive(0x7f8aa4002ba0, 32) called
960. sres.c:3781 sres_create_record() ANSWER RR received vgw.xoip.biz. A IN 10 rdlen=4
961. sres.c:3572 sres_log_response() sres_resolver_receive(0x7f8aa4002ba0, 0x7f8aa4209a40) id=13931 (from [139.162.133.5]:53)
962. nta.c:10856 outgoing_answer_a() nta: vgw.xoip.biz. IN A 69.164.196.139
963. tport.c:3257 tport_tsend() tport_tsend(0x7f8aa4004c20) tpn = udp/69.164.196.139:5060
964. tport.c:4046 tport_resolve() tport_resolve addrinfo = 69.164.196.139:5060
965. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f8aa4004c20): not found by name udp/69.164.196.139:5060
966. tport.c:3594 tport_vsend() tport_vsend(0x7f8aa4004c20): 487 bytes of 487 to udp/69.164.196.139:5060
967. tport.c:3492 tport_send_msg() tport_vsend returned 487
968. send 487 bytes to udp/[69.164.196.139]:5060 at 16:51:05.726682:
969.    ------------------------------------------------------------------------
970.    OPTIONS sip:vgw.xoip.biz;transport=udp SIP/2.0
971.    Via: SIP/2.0/UDP 139.162.188.90:5080;rport;branch=z9hG4bKg4gB346K4893K
972.    Max-Forwards: 70
973.    From: <sip:vgw.xoip.biz>;tag=QZK5rZ8XZDHXF
974.    To: <sip:vgw.xoip.biz>
975.    Call-ID: db6bfd65-442a-1237-158f-f23c919fed9e
976.    CSeq: 129085306 OPTIONS
977.    User-Agent: RAYDO
978.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
979.    Supported: timer, path, replaces
980.    Allow-Events: talk, hold, conference, refer
981.    Content-Length: 0
982.  
983.    ------------------------------------------------------------------------
984. nta.c:8304 outgoing_send() nta: sent OPTIONS (129085306) to udp/69.164.196.139:5060
985. tport.c:4160 tport_pend() tport_pend(0x7f8aa4004c20): pending 0x7f8aa40f6cc0 for udp/139.162.188.90:5080 (already 0)
986. nta.c:1350 set_timeout() nta: timer set to 32000 ms
987. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
988. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f8aa4004c20): events IN
989. tport.c:2864 tport_recv_event() tport_recv_event(0x7f8aa4004c20)
990. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f8aa4004c20) msg 0x7f8aa41a4010 from (udp/139.162.188.90:5080) has 648 bytes, veclen = 1
991. recv 648 bytes from udp/[69.164.196.139]:5060 at 16:51:05.848468:
992.    ------------------------------------------------------------------------
993.    SIP/2.0 200 OK
994.    Via: SIP/2.0/UDP 139.162.188.90:5080;rport=5080;branch=z9hG4bKg4gB346K4893K
995.    From: <sip:vgw.xoip.biz>;tag=QZK5rZ8XZDHXF
996.    To: <sip:vgw.xoip.biz>;tag=FK9m2D528S12e
997.    Call-ID: db6bfd65-442a-1237-158f-f23c919fed9e
998.    CSeq: 129085306 OPTIONS
999.    Contact: <sip:69.164.196.139>
1000.    User-Agent: ASTPP
1001.    Accept: application/sdp
1002.   Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE
1003.    Supported: path, replaces
1004.    Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer
1005.    Content-Length: 0
1006.  
1007.    ------------------------------------------------------------------------
1008. tport.c:3023 tport_deliver() tport_deliver(0x7f8aa4004c20): msg 0x7f8aa41a4010 (648 bytes) from udp/69.164.196.139:5080/sip next=(nil)
1009. nta.c:3299 agent_recv_response() nta: received 200 OK for OPTIONS (129085306)
1010. nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction
1011. nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 121.968 ms
1012. tport.c:4222 tport_release() tport_release(0x7f8aa4004c20): 0x7f8aa40f6cc0 by 0x7f8aa41df2a0 with 0x7f8aa41a4010
1013. nua_stack.c:271 nua_stack_event() nua(0x7f8aa04d9140): event r_options 200 OK
1014. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
1015. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
1016. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
1017. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
1018. nua_stack.c:569 nua_stack_signal() nua(0x7f8aa04d9140): recv signal r_destroy
1019. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
1020. soa.c:356 soa_destroy() soa_destroy(static::0x7f8aa41d2ba0) called
1021. nua_stack.c:529 nua_signal() nua(0x7f8aa04d9140): sent signal r_destroy
1022. nta.c:1296 agent_timer() nta: timer set next to 4121 ms
1023. 2018-10-06 16:51:06.742565 [NOTICE] switch_cpp.cpp:1365 [xml]: <?xml version="1.0" encoding="UTF-8" standalone="no"?>
1024. <document type="freeswitch/xml">
1025.  
1026. <section name="result">
1027.         <result status="not found"/>
1028. </section>
1029.  
1030. </document>
1031. 2018-10-06 16:51:06.762167 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Params:
1032. 'Event-Name: GENERAL
1033. Core-UUID: e29dc518-8161-4dc3-8fba-b47b545a2cf9
1034. FreeSWITCH-Hostname: test-fs-001
1035. FreeSWITCH-Switchname: test-fs-001
1036. FreeSWITCH-IPv4: 139.162.188.90
1037. FreeSWITCH-IPv6: %3A%3A1
1038. Event-Date-Local: 2018-10-06%2016%3A51%3A04
1039. Event-Date-GMT: Sat,%2006%20Oct%202018%2016%3A51%3A04%20GMT
1040. Event-Date-Timestamp: 1538844664912181
1041. Event-Calling-File: mod_voicemail.c
1042. Event-Calling-Function: resolve_id
1043. Event-Calling-Line-Number: 1363
1044. Event-Sequence: 3677
1045. action: message-count
1046. key: id
1047. user: 1000
1048. domain: tekart.convodeck.com
1049. key: number-alias
1050. user: 1000
1051. domain: tekart.convodeck.com
1052.  
1053. '
1054. 2018-10-06 16:51:06.762167 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Section: directory
1055. 2018-10-06 16:51:06.762167 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Tag Name: domain
1056. 2018-10-06 16:51:06.762167 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Name: name
1057. 2018-10-06 16:51:06.762167 [NOTICE] switch_cpp.cpp:1365 [xml_handler] Key Value: tekart.convodeck.com
1058. 2018-10-06 16:51:08.412195 [NOTICE] switch_cpp.cpp:1365 [xml]: <?xml version="1.0" encoding="UTF-8" standalone="no"?>
1059. <document type="freeswitch/xml">
1060.  
1061. <section name="result">
1062.         <result status="not found"/>
1063. </section>
1064.  
1065. </document>
1066.