1. 2017-10-10 19:19:40.872580 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/1002.csv
2. 2017-10-10 19:19:40.872580 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
3. 2017-10-10 19:19:40.872580 [NOTICE] mod_logfile.c:192 New log started.
4. 2017-10-10 19:19:46.412582 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
5. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1001@65.15.69.32 [7282bba8-0656-4822-a8a0-866febb7c9f1]
6. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] mod_sofia.c:5026 (sofia/external/1001@65.15.69.32) State Change CS_NEW -> CS_INIT
7. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_INIT (Cur 1 Tot 10)
8. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1001@65.15.69.32) State INIT
9. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [ALERT] switch_core_state_machine.c:627 sofia/external/1001@65.15.69.32 Send KeyFrame
10. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] mod_sofia.c:93 sofia/external/1001@65.15.69.32 SOFIA INIT
11. 2017-10-10 19:19:46.412582 [ALERT] switch_core_media.c:934 ADD PMAP REQ opus 102
12. 2017-10-10 19:19:46.412582 [ALERT] switch_core_media.c:934 ADD PMAP REQ G722 9
13. 2017-10-10 19:19:46.412582 [ALERT] switch_core_media.c:934 ADD PMAP REQ PCMU 0
14. 2017-10-10 19:19:46.412582 [ALERT] switch_core_media.c:934 ADD PMAP REQ PCMA 8
15. 2017-10-10 19:19:46.412582 [ALERT] switch_core_media.c:934 ADD PMAP REQ VP8 103
16. nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering
17. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
18. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] sofia_glue.c:1299 sofia/external/1001@65.15.69.32 sending invite version: 1.9.0 git 542825e 2017-09-24 20:38:29Z 64bit
19. 7282bba8-0656-4822-a8a0-866febb7c9f1 Local SDP:
20. 7282bba8-0656-4822-a8a0-866febb7c9f1 v=0
21. 7282bba8-0656-4822-a8a0-866febb7c9f1 o=FreeSWITCH 1507646762 1507646763 IN IP4 74.208.165.83
22. 7282bba8-0656-4822-a8a0-866febb7c9f1 s=FreeSWITCH
23. 7282bba8-0656-4822-a8a0-866febb7c9f1 c=IN IP4 74.208.165.83
24. 7282bba8-0656-4822-a8a0-866febb7c9f1 t=0 0
25. 7282bba8-0656-4822-a8a0-866febb7c9f1 m=audio 16424 RTP/AVP 102 9 0 8 104 101
26. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:102 opus/48000/2
27. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
28. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:9 G722/8000
29. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:0 PCMU/8000
30. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:8 PCMA/8000
31. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:104 telephone-event/48000
32. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=fmtp:104 0-16
33. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:101 telephone-event/8000
34. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=fmtp:101 0-16
35. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=ptime:20
36. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=sendrecv
37. 7282bba8-0656-4822-a8a0-866febb7c9f1 m=video 16480 RTP/AVP 103
38. 7282bba8-0656-4822-a8a0-866febb7c9f1 b=AS:1024
39. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtpmap:103 VP8/90000
40. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=sendrecv
41. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtcp-fb:103 ccm fir
42. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtcp-fb:103 ccm tmmbr
43. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtcp-fb:103 nack
44. 7282bba8-0656-4822-a8a0-866febb7c9f1 a=rtcp-fb:103 nack pli
45. 7282bba8-0656-4822-a8a0-866febb7c9f1
46. nua.c:633 nua_invite() nua: nua_invite: entering
47. nua_stack.c:569 nua_stack_signal() nua(0x7f86cc020e80): recv signal r_invite
48. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
49. soa.c:280 soa_clone() soa_clone(static::0x7f86c8028d80, 0x7f86c80260e0, 0x7f86cc020e80) called
50. soa.c:403 soa_set_params() soa_set_params(static::0x7f86c8055430, ...) called
51. soa.c:403 soa_set_params() soa_set_params(static::0x7f86c8055430, ...) called
52. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f86c8055430, (nil), 0x7f86cc0655b9, -1) called
53. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f86c8055430, (nil), 0x7f86cc0655b9, -1) called
54. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f86cc020e80): adding session usage
55. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f86c8051730)
56. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f86c8055430) called
57. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7f86c8055430, 0) called
58. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f86c8055430, soa_generate_offer): called
59. soa_static.c:1189 offer_answer_step() soa_static(0x7f86c8055430, soa_generate_offer): generating local description
60. soa_static.c:1217 offer_answer_step() soa_static(0x7f86c8055430, soa_generate_offer): upgrade with local description
61. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f86e152dac0, (nil), ""): called
62. soa_static.c:1446 offer_answer_step() soa_static(0x7f86c8055430, soa_generate_offer): storing local description
63. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f86c8055430, [(nil)], [0x7f86e152fbf8], [0x7f86e152fbf4]) called
64. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
65. tport.c:3257 tport_tsend() tport_tsend(0x7f86c8033240) tpn = */65.15.69.32:5060
66. tport.c:4046 tport_resolve() tport_resolve addrinfo = 65.15.69.32:5060
67. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f86c8033240): not found by name */65.15.69.32:5060
68. tport.c:3594 tport_vsend() tport_vsend(0x7f86c8033240): 1409 bytes of 1409 to udp/65.15.69.32:5060
69. tport.c:3492 tport_send_msg() tport_vsend returned 1409
70. send 1409 bytes to udp/[65.15.69.32]:5060 at 19:19:46.420211:
71.    ------------------------------------------------------------------------
72.    INVITE sip:1001@65.15.69.32 SIP/2.0
73.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport;branch=z9hG4bK9NyeetDg9eSpK
74.    Max-Forwards: 70
75.    From: "" <sip:0000000000@74.208.165.83>;tag=9UmHUtD4Zc92N
76.    To: <sip:1001@65.15.69.32>
77.    Call-ID: d18c4d87-2892-1236-ad90-0050560f07d6
78.    CSeq: 113495529 INVITE
79.    Contact: <sip:mod_sofia@74.208.165.83:5080>
80.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170924T203829Z~542825ef81~64bit
81.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
82.    Supported: timer, path, replaces
83.    Allow-Events: talk, hold, conference, refer
84.    Content-Type: application/sdp
85.    Content-Disposition: session
86.    Content-Length: 623
87.    X-FS-Support: update_display,send_info
88.    Remote-Party-ID: <sip:0000000000@74.208.165.83>;party=calling;screen=yes;privacy=off
89.    
90.    v=0
91.    o=FreeSWITCH 1507646762 1507646763 IN IP4 74.208.165.83
92.    s=FreeSWITCH
93.    c=IN IP4 74.208.165.83
94.    t=0 0
95.    m=audio 16424 RTP/AVP 102 9 0 8 104 101
96.    a=rtpmap:102 opus/48000/2
97.    a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
98.    a=rtpmap:9 G722/8000
99.    a=rtpmap:0 PCMU/8000
100.    a=rtpmap:8 PCMA/8000
101.    a=rtpmap:104 telephone-event/48000
102.    a=fmtp:104 0-16
103.    a=rtpmap:101 telephone-event/8000
104.    a=fmtp:101 0-16
105.    a=ptime:20
106.    m=video 16480 RTP/AVP 103
107.    b=AS:1024
108.    a=rtpmap:103 VP8/90000
109.    a=rtcp-fb:103 ccm fir
110.    a=rtcp-fb:103 ccm tmmbr
111.    a=rtcp-fb:103 nack
112.    a=rtcp-fb:103 nack pli
113.    ------------------------------------------------------------------------
114. nta.c:8310 outgoing_send() nta: sent INVITE (113495529) to */65.15.69.32:5060
115. tport.c:4160 tport_pend() tport_pend(0x7f86c8033240): pending 0x7f86c8063c60 for udp/74.208.165.83:5080 (already 0)
116. nta.c:1350 set_timeout() nta: timer set to 32000 ms
117. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
118. nua_session.c:4139 signal_call_state_change() nua(0x7f86cc020e80): call state changed: init -> calling, sent offer
119. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f86c8055430, [0x7f86e152fbd8], [0x7f86e152fbe0], [(nil)]) called
120. nua_stack.c:269 nua_stack_event() nua(0x7f86cc020e80): event i_state INVITE sent
121. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
122. nua_stack.c:529 nua_signal() nua(0x7f86cc020e80): sent signal r_invite
123. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:40 sofia/external/1001@65.15.69.32 Standard INIT
124. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1001@65.15.69.32) State Change CS_INIT -> CS_ROUTING
125. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1001@65.15.69.32) State INIT going to sleep
126. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_ROUTING (Cur 1 Tot 10)
127. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
128. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] sofia.c:7283 Channel sofia/external/1001@65.15.69.32 entering state [calling][0]
129. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
130. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1001@65.15.69.32) State ROUTING
131. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [ALERT] switch_core_state_machine.c:643 sofia/external/1001@65.15.69.32 Send KeyFrame
132. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] mod_sofia.c:154 sofia/external/1001@65.15.69.32 SOFIA ROUTING
133. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_ivr_originate.c:67 (sofia/external/1001@65.15.69.32) State Change CS_ROUTING -> CS_CONSUME_MEDIA
134. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1001@65.15.69.32) State ROUTING going to sleep
135. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 10)
136. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001@65.15.69.32) State CONSUME_MEDIA
137. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [ALERT] switch_core_state_machine.c:662 sofia/external/1001@65.15.69.32 Send KeyFrame
138. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001@65.15.69.32) State CONSUME_MEDIA going to sleep
139. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:19:46.412582 [ALERT] switch_core_state_machine.c:701 sofia/external/1001@65.15.69.32 session thread sleep state: CS_CONSUME_MEDIA!
140. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f86c8033240): events IN
141. tport.c:2864 tport_recv_event() tport_recv_event(0x7f86c8033240)
142. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f86c8033240) msg 0x7f86c80687a0 from (udp/74.208.165.83:5080) has 353 bytes, veclen = 1
143. recv 353 bytes from udp/[65.15.69.32]:5060 at 19:19:46.486577:
144.    ------------------------------------------------------------------------
145.    SIP/2.0 100 Trying
146.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport=5080;branch=z9hG4bK9NyeetDg9eSpK
147.    From: "" <sip:0000000000@74.208.165.83>;tag=9UmHUtD4Zc92N
148.    To: <sip:1001@65.15.69.32>
149.    Call-ID: d18c4d87-2892-1236-ad90-0050560f07d6
150.    CSeq: 113495529 INVITE
151.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20171010T123804Z~e28abe2929~64bit
152.    Content-Length: 0
153.    
154.    ------------------------------------------------------------------------
155. tport.c:3023 tport_deliver() tport_deliver(0x7f86c8033240): msg 0x7f86c80687a0 (353 bytes) from udp/65.15.69.32:5080/sip next=(nil)
156. nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (113495529)
157. nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction
158. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 66.44 ms
159. tport.c:4222 tport_release() tport_release(0x7f86c8033240): 0x7f86c8063c60 by 0x7f86c8066a10 with 0x7f86c80687a0 (preliminary)
160. nta.c:1289 agent_timer() nta: timer not set
161. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f86c8033240): events IN
162. tport.c:2864 tport_recv_event() tport_recv_event(0x7f86c8033240)
163. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f86c8033240) msg 0x7f86c8064920 from (udp/74.208.165.83:5080) has 642 bytes, veclen = 1
164. recv 642 bytes from udp/[65.15.69.32]:5060 at 19:20:25.704451:
165.    ------------------------------------------------------------------------
166.    BYE sip:mod_sofia@74.208.165.83:5080 SIP/2.0
167.    Via: SIP/2.0/UDP 192.168.1.113;rport;branch=z9hG4bKyjjrHcQHQ0mHg
168.    Max-Forwards: 70
169.    From: <sip:1001@65.15.69.32>;tag=UXND18g4HF0pm
170.    To: "" <sip:0000000000@74.208.165.83>;tag=9UmHUtD4Zc92N
171.    Call-ID: d18c4d87-2892-1236-ad90-0050560f07d6
172.    CSeq: 113495554 BYE
173.    Contact: <sip:1001@192.168.1.113:5060;transport=udp>
174.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20171010T123804Z~e28abe2929~64bit
175.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
176.    Supported: timer, path, replaces
177.    Reason: SIP;cause=408;text="ACK Timeout"
178.    Content-Length: 0
179.    
180.    ------------------------------------------------------------------------
181. tport.c:3023 tport_deliver() tport_deliver(0x7f86c8033240): msg 0x7f86c8064920 (642 bytes) from udp/65.15.69.32:5080/sip next=(nil)
182. nta.c:2880 agent_recv_request() nta: received BYE sip:mod_sofia@74.208.165.83:5080 SIP/2.0 (CSeq 113495554)
183. nta.c:3174 agent_check_request_via() nta: Via check: received=65.15.69.32
184. nta.c:3248 agent_aliases() nta: canonizing sip:mod_sofia@74.208.165.83:5080 with contact
185. nta.c:3060 agent_recv_request() nta: BYE (113495554) going to existing leg
186. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
187. nua_stack.c:271 nua_stack_event() nua(0x7f86cc020e80): event i_bye 100 Trying
188. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
189. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [ALERT] switch_core_state_machine.c:705 sofia/external/1001@65.15.69.32 session thread wake state: CS_CONSUME_MEDIA!
190. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
191. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [NOTICE] sofia.c:1079 Hangup sofia/external/1001@65.15.69.32 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
192. nua.c:879 nua_respond() nua: nua_respond: entering
193. nua_stack.c:573 nua_stack_signal() nua(0x7f86cc020e80): recv signal r_respond 200 OK
194. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
195. soa.c:403 soa_set_params() soa_set_params(static::0x7f86c8055430, ...) called
196. tport.c:3257 tport_tsend() tport_tsend(0x7f86c8033240) tpn = UDP/65.15.69.32:5060
197. tport.c:4046 tport_resolve() tport_resolve addrinfo = 65.15.69.32:5060
198. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f86c8033240): not found by name UDP/65.15.69.32:5060
199. tport.c:3594 tport_vsend() tport_vsend(0x7f86c8033240): 504 bytes of 504 to udp/65.15.69.32:5060
200. tport.c:3492 tport_send_msg() tport_vsend returned 504
201. send 504 bytes to udp/[65.15.69.32]:5060 at 19:20:25.705238:
202.    ------------------------------------------------------------------------
203.    SIP/2.0 200 OK
204.    Via: SIP/2.0/UDP 192.168.1.113;rport=5060;branch=z9hG4bKyjjrHcQHQ0mHg;received=65.15.69.32
205.    From: <sip:1001@65.15.69.32>;tag=UXND18g4HF0pm
206.    To: "" <sip:0000000000@74.208.165.83>;tag=9UmHUtD4Zc92N
207.    Call-ID: d18c4d87-2892-1236-ad90-0050560f07d6
208.    CSeq: 113495554 BYE
209.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170924T203829Z~542825ef81~64bit
210.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
211.    Supported: timer, path, replaces
212.    Content-Length: 0
213.    
214.    ------------------------------------------------------------------------
215. nta.c:6797 incoming_reply() nta: sent 200 OK for BYE (113495554)
216. nta.c:1350 set_timeout() nta: timer set to 32000 ms
217. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f86cc020e80): removing session usage
218. nua_session.c:4139 signal_call_state_change() nua(0x7f86cc020e80): call state changed: calling -> terminated
219. nua_stack.c:271 nua_stack_event() nua(0x7f86cc020e80): event i_state 200 Early Session Terminated
220. nua_stack.c:271 nua_stack_event() nua(0x7f86cc020e80): event i_terminated 200 Early Session Terminated
221. soa.c:356 soa_destroy() soa_destroy(static::0x7f86c8055430) called
222. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f86c8051730)
223. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
224. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
225. nua_stack.c:529 nua_signal() nua(0x7f86cc020e80): sent signal r_respond
226. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
227. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
228. nua_stack.c:569 nua_stack_signal() nua(0x7f86cc020e80): recv signal r_destroy
229. tport.c:3257 tport_tsend() tport_tsend(0x7f86c8033240) tpn = UDP/65.15.69.32:5060
230. tport.c:4046 tport_resolve() tport_resolve addrinfo = 65.15.69.32:5060
231. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f86c8033240): not found by name UDP/65.15.69.32:5060
232. tport.c:3594 tport_vsend() tport_vsend(0x7f86c8033240): 305 bytes of 305 to udp/65.15.69.32:5060
233. tport.c:3492 tport_send_msg() tport_vsend returned 305
234. send 305 bytes to udp/[65.15.69.32]:5060 at 19:20:25.705410:
235.    ------------------------------------------------------------------------
236.    CANCEL sip:1001@65.15.69.32 SIP/2.0
237.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport;branch=z9hG4bK9NyeetDg9eSpK
238.    Max-Forwards: 70
239.    From: "" <sip:0000000000@74.208.165.83>;tag=9UmHUtD4Zc92N
240.    To: <sip:1001@65.15.69.32>
241.    Call-ID: d18c4d87-2892-1236-ad90-0050560f07d6
242.    CSeq: 113495529 CANCEL
243.    Content-Length: 0
244.    
245.    ------------------------------------------------------------------------
246. nta.c:8310 outgoing_send() nta: sent CANCEL (113495529) to UDP/65.15.69.32:5060
247. tport.c:4160 tport_pend() tport_pend(0x7f86c8033240): pending 0x7f86c806b360 for udp/74.208.165.83:5080 (already 1)
248. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
249. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
250. nua_stack.c:529 nua_signal() nua(0x7f86cc020e80): sent signal r_destroy
251. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_HANGUP (Cur 1 Tot 10)
252. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1001@65.15.69.32) Callstate Change DOWN -> HANGUP
253. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001@65.15.69.32) State HANGUP
254. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [ALERT] switch_core_state_machine.c:852 sofia/external/1001@65.15.69.32 Send KeyFrame
255. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] mod_sofia.c:449 Channel sofia/external/1001@65.15.69.32 hanging up, cause: NORMAL_CLEARING
256. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:60 sofia/external/1001@65.15.69.32 Standard HANGUP, cause: NORMAL_CLEARING
257. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001@65.15.69.32) State HANGUP going to sleep
258. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1001@65.15.69.32) State Change CS_HANGUP -> CS_REPORTING
259. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_REPORTING (Cur 1 Tot 10)
260. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001@65.15.69.32) State REPORTING
261. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [ALERT] switch_core_state_machine.c:938 sofia/external/1001@65.15.69.32 Send KeyFrame
262. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:174 sofia/external/1001@65.15.69.32 Standard REPORTING, cause: NORMAL_CLEARING
263. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001@65.15.69.32) State REPORTING going to sleep
264. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1001@65.15.69.32) State Change CS_REPORTING -> CS_DESTROY
265. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.702581 [DEBUG] switch_core_session.c:1713 Session 10 (sofia/external/1001@65.15.69.32) Locked, Waiting on external entities
266. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
267. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
268. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
269. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
270. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
271. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
272. 2017-10-10 19:20:25.712588 [DEBUG] switch_ivr_originate.c:3865 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
273. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [NOTICE] switch_core_session.c:1731 Session 10 (sofia/external/1001@65.15.69.32) Ended
274. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/1001@65.15.69.32 [CS_DESTROY]
275. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1001@65.15.69.32) Running State Change CS_DESTROY (Cur 0 Tot 10)
276. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001@65.15.69.32) State DESTROY
277. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [ALERT] switch_core_state_machine.c:751 sofia/external/1001@65.15.69.32 Send KeyFrame
278. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [DEBUG] mod_sofia.c:354 sofia/external/1001@65.15.69.32 SOFIA DESTROY
279. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [DEBUG] switch_core_state_machine.c:181 sofia/external/1001@65.15.69.32 Standard DESTROY
280. 7282bba8-0656-4822-a8a0-866febb7c9f1 2017-10-10 19:20:25.712588 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001@65.15.69.32) State DESTROY going to sleep
281. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f86c8033240): events IN
282. tport.c:2864 tport_recv_event() tport_recv_event(0x7f86c8033240)
283. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f86c8033240) msg 0x7f86c8068030 from (udp/74.208.165.83:5080) has 318 bytes, veclen = 1
284. recv 318 bytes from udp/[65.15.69.32]:5060 at 19:20:25.824743:
285.    ------------------------------------------------------------------------
286.    SIP/2.0 481 Call/Transaction Does Not Exist
287.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport=5080;branch=z9hG4bK9NyeetDg9eSpK
288.    From: "" <sip:0000000000@74.208.165.83>;tag=9UmHUtD4Zc92N
289.    To: <sip:1001@65.15.69.32>;tag=v6e62317erp9F
290.    Call-ID: d18c4d87-2892-1236-ad90-0050560f07d6
291.    CSeq: 113495529 CANCEL
292.    Content-Length: 0
293.    
294.    ------------------------------------------------------------------------
295. tport.c:3023 tport_deliver() tport_deliver(0x7f86c8033240): msg 0x7f86c8068030 (318 bytes) from udp/65.15.69.32:5080/sip next=(nil)
296. nta.c:3299 agent_recv_response() nta: received 481 Call/Transaction Does Not Exist for CANCEL (113495529)
297. nta.c:3366 agent_recv_response() nta: 481 Call/Transaction Does Not Exist is going to a transaction
298. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 119.395 ms
299. tport.c:4222 tport_release() tport_release(0x7f86c8033240): 0x7f86c806b360 by 0x7f86c80637c0 with 0x7f86c8068030
300. nta.c:1296 agent_timer() nta: timer set next to 4120 ms
301. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate CANCEL (113495529)
302. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f86e152fd40)
303. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
304. nta.c:1296 agent_timer() nta: timer set next to 26880 ms
305.