From Violet Pudu, 6 Years ago, written in Plain Text.
- go back
Embed
Viewing differences between and via originate
  1. 2017-10-10 17:59:08.595302 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/1002.csv
  2. 2017-10-10 17:59:08.595302 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv
  3. 2017-10-10 17:59:08.595302 [NOTICE] mod_logfile.c:192 New log started.
  4. 2017-10-10 17:59:21.915303 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables
  5. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [NOTICE] switch_channel.c:1104 New Channel sofia/external/1001@65.15.69.32 [f60823b3-5d51-4d93-bbb6-60cf6f0dea9d]
  6. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] mod_sofia.c:5026 (sofia/external/1001@65.15.69.32) State Change CS_NEW -> CS_INIT
  7. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_INIT (Cur 1 Tot 4)
  8. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1001@65.15.69.32) State INIT
  9. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [ALERT] switch_core_state_machine.c:627 sofia/external/1001@65.15.69.32 Send KeyFrame
  10. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] mod_sofia.c:93 sofia/external/1001@65.15.69.32 SOFIA INIT
  11. 2017-10-10 17:59:21.915303 [ALERT] switch_core_media.c:934 ADD PMAP REQ opus 102
  12. 2017-10-10 17:59:21.915303 [ALERT] switch_core_media.c:934 ADD PMAP REQ G722 9
  13. 2017-10-10 17:59:21.915303 [ALERT] switch_core_media.c:934 ADD PMAP REQ PCMU 0
  14. 2017-10-10 17:59:21.915303 [ALERT] switch_core_media.c:934 ADD PMAP REQ PCMA 8
  15. 2017-10-10 17:59:21.915303 [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. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [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. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d Local SDP:
  20. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d v=0
  21. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d o=FreeSWITCH 1507641889 1507641890 IN IP4 74.208.165.83
  22. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d s=FreeSWITCH
  23. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d c=IN IP4 74.208.165.83
  24. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d t=0 0
  25. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d m=audio 16472 RTP/AVP 102 9 0 8 104 101
  26. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:102 opus/48000/2
  27. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40
  28. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:9 G722/8000
  29. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:0 PCMU/8000
  30. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:8 PCMA/8000
  31. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:104 telephone-event/48000
  32. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=fmtp:104 0-16
  33. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:101 telephone-event/8000
  34. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=fmtp:101 0-16
  35. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=ptime:20
  36. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=sendrecv
  37. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d m=video 16420 RTP/AVP 103
  38. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d b=AS:1024
  39. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtpmap:103 VP8/90000
  40. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=sendrecv
  41. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtcp-fb:103 ccm fir
  42. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtcp-fb:103 ccm tmmbr
  43. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtcp-fb:103 nack
  44. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d a=rtcp-fb:103 nack pli
  45. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d
  46. nua.c:633 nua_invite() nua: nua_invite: entering
  47. nua_stack.c:569 nua_stack_signal() nua(0x7fb9f00015c0): 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::0x7fb9d8001930, 0x7fb9d8001150, 0x7fb9f00015c0) called
  50. soa.c:403 soa_set_params() soa_set_params(static::0x7fb9d80f3340, ...) called
  51. soa.c:403 soa_set_params() soa_set_params(static::0x7fb9d80f3340, ...) called
  52. soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7fb9d80f3340, (nil), 0x7fb9f0021399, -1) called
  53. soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7fb9d80f3340, (nil), 0x7fb9f0021399, -1) called
  54. nua_dialog.c:338 nua_dialog_usage_add() nua(0x7fb9f00015c0): adding session usage
  55. nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7fb9d80f5ee0)
  56. soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7fb9d80f3340) called
  57. soa.c:1426 soa_generate_offer() soa_generate_offer(static::0x7fb9d80f3340, 0) called
  58. soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7fb9d80f3340, soa_generate_offer): called
  59. soa_static.c:1189 offer_answer_step() soa_static(0x7fb9d80f3340, soa_generate_offer): generating local description
  60. soa_static.c:1217 offer_answer_step() soa_static(0x7fb9d80f3340, soa_generate_offer): upgrade with local description
  61. soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7fb9df8b4ac0, (nil), ""): called
  62. soa_static.c:1446 offer_answer_step() soa_static(0x7fb9d80f3340, soa_generate_offer): storing local description
  63. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fb9d80f3340, [(nil)], [0x7fb9df8b6bf8], [0x7fb9df8b6bf4]) called
  64. nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip
  65. tport.c:3257 tport_tsend() tport_tsend(0x7fb9d8004640) 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(0x7fb9d8004640): not found by name */65.15.69.32:5060
  68. tport.c:3594 tport_vsend() tport_vsend(0x7fb9d8004640): 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 17:59:21.924243:
  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=z9hG4bK1a4y6a2B7cDXg
  74.    Max-Forwards: 70
  75.    From: "" <sip:0000000000@74.208.165.83>;tag=3gXv5DSvXK1BN
  76.    To: <sip:1001@65.15.69.32>
  77.    Call-ID: 95eca443-2887-1236-1aab-0050560f07d6
  78.    CSeq: 113493116 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 1507641889 1507641890 IN IP4 74.208.165.83
  92.    s=FreeSWITCH
  93.    c=IN IP4 74.208.165.83
  94.    t=0 0
  95.    m=audio 16472 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 16420 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 (113493116) to */65.15.69.32:5060
  115. tport.c:4160 tport_pend() tport_pend(0x7fb9d8004640): pending 0x7fb9d80eb960 for udp/74.208.165.83:5080 (already 1)
  116. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  117. nua_session.c:4139 signal_call_state_change() nua(0x7fb9f00015c0): call state changed: init -> calling, sent offer
  118. soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7fb9d80f3340, [0x7fb9df8b6bd8], [0x7fb9df8b6be0], [(nil)]) called
  119. nua_stack.c:269 nua_stack_event() nua(0x7fb9f00015c0): event i_state INVITE sent
  120. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  121. nua_stack.c:529 nua_signal() nua(0x7fb9f00015c0): sent signal r_invite
  122. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:40 sofia/external/1001@65.15.69.32 Standard INIT
  123. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:48 (sofia/external/1001@65.15.69.32) State Change CS_INIT -> CS_ROUTING
  124. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:627 (sofia/external/1001@65.15.69.32) State INIT going to sleep
  125. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_ROUTING (Cur 1 Tot 4)
  126. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  127. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] sofia.c:7283 Channel sofia/external/1001@65.15.69.32 entering state [calling][0]
  128. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  129. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1001@65.15.69.32) State ROUTING
  130. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [ALERT] switch_core_state_machine.c:643 sofia/external/1001@65.15.69.32 Send KeyFrame
  131. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] mod_sofia.c:154 sofia/external/1001@65.15.69.32 SOFIA ROUTING
  132. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_ivr_originate.c:67 (sofia/external/1001@65.15.69.32) State Change CS_ROUTING -> CS_CONSUME_MEDIA
  133. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:643 (sofia/external/1001@65.15.69.32) State ROUTING going to sleep
  134. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_CONSUME_MEDIA (Cur 1 Tot 4)
  135. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001@65.15.69.32) State CONSUME_MEDIA
  136. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [ALERT] switch_core_state_machine.c:662 sofia/external/1001@65.15.69.32 Send KeyFrame
  137. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [DEBUG] switch_core_state_machine.c:662 (sofia/external/1001@65.15.69.32) State CONSUME_MEDIA going to sleep
  138. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:21.915303 [ALERT] switch_core_state_machine.c:701 sofia/external/1001@65.15.69.32 session thread sleep state: CS_CONSUME_MEDIA!
  139. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7fb9d8004640): events IN
  140. tport.c:2864 tport_recv_event() tport_recv_event(0x7fb9d8004640)
  141. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fb9d8004640) msg 0x7fb9d80e3670 from (udp/74.208.165.83:5080) has 353 bytes, veclen = 1
  142. recv 353 bytes from udp/[65.15.69.32]:5060 at 17:59:21.975574:
  143.    ------------------------------------------------------------------------
  144.    SIP/2.0 100 Trying
  145.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport=5080;branch=z9hG4bK1a4y6a2B7cDXg
  146.    From: "" <sip:0000000000@74.208.165.83>;tag=3gXv5DSvXK1BN
  147.    To: <sip:1001@65.15.69.32>
  148.    Call-ID: 95eca443-2887-1236-1aab-0050560f07d6
  149.    CSeq: 113493116 INVITE
  150.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20171010T123804Z~e28abe2929~64bit
  151.    Content-Length: 0
  152.    
  153.    ------------------------------------------------------------------------
  154. tport.c:3023 tport_deliver() tport_deliver(0x7fb9d8004640): msg 0x7fb9d80e3670 (353 bytes) from udp/65.15.69.32:5080/sip next=(nil)
  155. nta.c:3299 agent_recv_response() nta: received 100 Trying for INVITE (113493116)
  156. nta.c:3366 agent_recv_response() nta: 100 Trying is going to a transaction
  157. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 51.402 ms
  158. tport.c:4222 tport_release() tport_release(0x7fb9d8004640): 0x7fb9d80eb960 by 0x7fb9d80ecc00 with 0x7fb9d80e3670 (preliminary)
  159. nta.c:1296 agent_timer() nta: timer set next to 5432 ms
  160. nta.c:9107 outgoing_timer_dk() nta: timer D fired, terminate INVITE (113493090)
  161. tport.c:4222 tport_release() tport_release(0x7fb9d8004640): 0x7fb9d8084170 by 0x7fb9d80f5380 with (nil)
  162. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7fb9df8b6d40)
  163. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/2 free
  164. nta.c:7165 _nta_incoming_timer() nta: timer J fired, terminate 200 response
  165. nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7fb9df8b6c60)
  166. nta.c:7194 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free
  167. nta.c:1289 agent_timer() nta: timer not set
  168. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7fb9d8004640): events IN
  169. tport.c:2864 tport_recv_event() tport_recv_event(0x7fb9d8004640)
  170. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fb9d8004640) msg 0x7fb9d8084170 from (udp/74.208.165.83:5080) has 593 bytes, veclen = 1
  171. recv 593 bytes from udp/[65.15.69.32]:5060 at 17:59:54.335671:
  172.    ------------------------------------------------------------------------
  173.    BYE sip:mod_sofia@74.208.165.83:5080 SIP/2.0
  174.    Via: SIP/2.0/UDP 192.168.1.113;rport;branch=z9hG4bKKFv7X2XaQyZ3g
  175.    Max-Forwards: 70
  176.    From: <sip:1001@65.15.69.32>;tag=UU3tF5t2aNeaF
  177.    To: "" <sip:0000000000@74.208.165.83>;tag=3gXv5DSvXK1BN
  178.    Call-ID: 95eca443-2887-1236-1aab-0050560f07d6
  179.    CSeq: 113493139 BYE
  180.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20171010T123804Z~e28abe2929~64bit
  181.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY, PUBLISH, SUBSCRIBE
  182.    Supported: timer, path, replaces
  183.    Reason: Q.850;cause=16;text="NORMAL_CLEARING"
  184.    Content-Length: 0
  185.    
  186.    ------------------------------------------------------------------------
  187. tport.c:3023 tport_deliver() tport_deliver(0x7fb9d8004640): msg 0x7fb9d8084170 (593 bytes) from udp/65.15.69.32:5080/sip next=(nil)
  188. nta.c:2880 agent_recv_request() nta: received BYE sip:mod_sofia@74.208.165.83:5080 SIP/2.0 (CSeq 113493139)
  189. nta.c:3174 agent_check_request_via() nta: Via check: received=65.15.69.32
  190. nta.c:3248 agent_aliases() nta: canonizing sip:mod_sofia@74.208.165.83:5080 with contact
  191. nta.c:3060 agent_recv_request() nta: BYE (113493139) going to existing leg
  192. nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering
  193. nua_stack.c:271 nua_stack_event() nua(0x7fb9f00015c0): event i_bye 100 Trying
  194. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  195. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [ALERT] switch_core_state_machine.c:705 sofia/external/1001@65.15.69.32 session thread wake state: CS_CONSUME_MEDIA!
  196. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  197. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [NOTICE] sofia.c:1079 Hangup sofia/external/1001@65.15.69.32 [CS_CONSUME_MEDIA] [NORMAL_CLEARING]
  198. nua.c:879 nua_respond() nua: nua_respond: entering
  199. nua_stack.c:573 nua_stack_signal() nua(0x7fb9f00015c0): recv signal r_respond 200 OK
  200. nua_params.c:482 nua_stack_set_params() nua: nua_stack_set_params: entering
  201. soa.c:403 soa_set_params() soa_set_params(static::0x7fb9d80f3340, ...) called
  202. tport.c:3257 tport_tsend() tport_tsend(0x7fb9d8004640) tpn = UDP/65.15.69.32:5060
  203. tport.c:4046 tport_resolve() tport_resolve addrinfo = 65.15.69.32:5060
  204. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7fb9d8004640): not found by name UDP/65.15.69.32:5060
  205. tport.c:3594 tport_vsend() tport_vsend(0x7fb9d8004640): 504 bytes of 504 to udp/65.15.69.32:5060
  206. tport.c:3492 tport_send_msg() tport_vsend returned 504
  207. send 504 bytes to udp/[65.15.69.32]:5060 at 17:59:54.336345:
  208.    ------------------------------------------------------------------------
  209.    SIP/2.0 200 OK
  210.    Via: SIP/2.0/UDP 192.168.1.113;rport=5060;branch=z9hG4bKKFv7X2XaQyZ3g;received=65.15.69.32
  211.    From: <sip:1001@65.15.69.32>;tag=UU3tF5t2aNeaF
  212.    To: "" <sip:0000000000@74.208.165.83>;tag=3gXv5DSvXK1BN
  213.    Call-ID: 95eca443-2887-1236-1aab-0050560f07d6
  214.    CSeq: 113493139 BYE
  215.    User-Agent: FreeSWITCH-mod_sofia/1.9.0+git~20170924T203829Z~542825ef81~64bit
  216.    Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY
  217.    Supported: timer, path, replaces
  218.    Content-Length: 0
  219.    
  220.    ------------------------------------------------------------------------
  221. nta.c:6797 incoming_reply() nta: sent 200 OK for BYE (113493139)
  222. nta.c:1350 set_timeout() nta: timer set to 32000 ms
  223. nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7fb9f00015c0): removing session usage
  224. nua_session.c:4139 signal_call_state_change() nua(0x7fb9f00015c0): call state changed: calling -> terminated
  225. nua_stack.c:271 nua_stack_event() nua(0x7fb9f00015c0): event i_state 200 Early Session Terminated
  226. nua_stack.c:271 nua_stack_event() nua(0x7fb9f00015c0): event i_terminated 200 Early Session Terminated
  227. soa.c:356 soa_destroy() soa_destroy(static::0x7fb9d80f3340) called
  228. nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7fb9d80f5ee0)
  229. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  230. nua_stack.c:359 nua_application_event() nua: nua_application_event: entering
  231. nua_stack.c:529 nua_signal() nua(0x7fb9f00015c0): sent signal r_respond
  232. nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering
  233. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  234. nua_stack.c:569 nua_stack_signal() nua(0x7fb9f00015c0): recv signal r_destroy
  235. tport.c:3257 tport_tsend() tport_tsend(0x7fb9d8004640) tpn = UDP/65.15.69.32:5060
  236. tport.c:4046 tport_resolve() tport_resolve addrinfo = 65.15.69.32:5060
  237. tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7fb9d8004640): not found by name UDP/65.15.69.32:5060
  238. tport.c:3594 tport_vsend() tport_vsend(0x7fb9d8004640): 305 bytes of 305 to udp/65.15.69.32:5060
  239. tport.c:3492 tport_send_msg() tport_vsend returned 305
  240. send 305 bytes to udp/[65.15.69.32]:5060 at 17:59:54.336526:
  241.    ------------------------------------------------------------------------
  242.    CANCEL sip:1001@65.15.69.32 SIP/2.0
  243.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport;branch=z9hG4bK1a4y6a2B7cDXg
  244.    Max-Forwards: 70
  245.    From: "" <sip:0000000000@74.208.165.83>;tag=3gXv5DSvXK1BN
  246.    To: <sip:1001@65.15.69.32>
  247.    Call-ID: 95eca443-2887-1236-1aab-0050560f07d6
  248.    CSeq: 113493116 CANCEL
  249.    Content-Length: 0
  250.    
  251.    ------------------------------------------------------------------------
  252. nta.c:8310 outgoing_send() nta: sent CANCEL (113493116) to UDP/65.15.69.32:5060
  253. tport.c:4160 tport_pend() tport_pend(0x7fb9d8004640): pending 0x7fb9d80eb550 for udp/74.208.165.83:5080 (already 1)
  254. nta.c:1348 set_timeout() nta: timer shortened to 1000 ms
  255. nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil))
  256. nua_stack.c:529 nua_signal() nua(0x7fb9f00015c0): sent signal r_destroy
  257. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_HANGUP (Cur 1 Tot 4)
  258. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:850 (sofia/external/1001@65.15.69.32) Callstate Change DOWN -> HANGUP
  259. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001@65.15.69.32) State HANGUP
  260. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [ALERT] switch_core_state_machine.c:852 sofia/external/1001@65.15.69.32 Send KeyFrame
  261. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] mod_sofia.c:449 Channel sofia/external/1001@65.15.69.32 hanging up, cause: NORMAL_CLEARING
  262. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:60 sofia/external/1001@65.15.69.32 Standard HANGUP, cause: NORMAL_CLEARING
  263. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:852 (sofia/external/1001@65.15.69.32) State HANGUP going to sleep
  264. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:619 (sofia/external/1001@65.15.69.32) State Change CS_HANGUP -> CS_REPORTING
  265. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:584 (sofia/external/1001@65.15.69.32) Running State Change CS_REPORTING (Cur 1 Tot 4)
  266. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001@65.15.69.32) State REPORTING
  267. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [ALERT] switch_core_state_machine.c:938 sofia/external/1001@65.15.69.32 Send KeyFrame
  268. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:174 sofia/external/1001@65.15.69.32 Standard REPORTING, cause: NORMAL_CLEARING
  269. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:938 (sofia/external/1001@65.15.69.32) State REPORTING going to sleep
  270. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:610 (sofia/external/1001@65.15.69.32) State Change CS_REPORTING -> CS_DESTROY
  271. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_session.c:1713 Session 4 (sofia/external/1001@65.15.69.32) Locked, Waiting on external entities
  272. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  273. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  274. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  275. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  276. nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering
  277. nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering
  278. 2017-10-10 17:59:54.335305 [DEBUG] switch_ivr_originate.c:3865 Originate Resulted in Error Cause: 16 [NORMAL_CLEARING]
  279. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [NOTICE] switch_core_session.c:1731 Session 4 (sofia/external/1001@65.15.69.32) Ended
  280. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [NOTICE] switch_core_session.c:1735 Close Channel sofia/external/1001@65.15.69.32 [CS_DESTROY]
  281. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:741 (sofia/external/1001@65.15.69.32) Running State Change CS_DESTROY (Cur 0 Tot 4)
  282. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001@65.15.69.32) State DESTROY
  283. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [ALERT] switch_core_state_machine.c:751 sofia/external/1001@65.15.69.32 Send KeyFrame
  284. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] mod_sofia.c:354 sofia/external/1001@65.15.69.32 SOFIA DESTROY
  285. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:181 sofia/external/1001@65.15.69.32 Standard DESTROY
  286. f60823b3-5d51-4d93-bbb6-60cf6f0dea9d 2017-10-10 17:59:54.335305 [DEBUG] switch_core_state_machine.c:751 (sofia/external/1001@65.15.69.32) State DESTROY going to sleep
  287. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7fb9d8004640): events IN
  288. tport.c:2864 tport_recv_event() tport_recv_event(0x7fb9d8004640)
  289. tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7fb9d8004640) msg 0x7fb9d80a1df0 from (udp/74.208.165.83:5080) has 318 bytes, veclen = 1
  290. recv 318 bytes from udp/[65.15.69.32]:5060 at 17:59:54.385053:
  291.    ------------------------------------------------------------------------
  292.    SIP/2.0 481 Call/Transaction Does Not Exist
  293.    Via: SIP/2.0/UDP 74.208.165.83:5080;rport=5080;branch=z9hG4bK1a4y6a2B7cDXg
  294.    From: "" <sip:0000000000@74.208.165.83>;tag=3gXv5DSvXK1BN
  295.    To: <sip:1001@65.15.69.32>;tag=v4vKH0B67X4va
  296.    Call-ID: 95eca443-2887-1236-1aab-0050560f07d6
  297.    CSeq: 113493116 CANCEL
  298.    Content-Length: 0
  299.    
  300.    ------------------------------------------------------------------------
  301. tport.c:3023 tport_deliver() tport_deliver(0x7fb9d8004640): msg 0x7fb9d80a1df0 (318 bytes) from udp/65.15.69.32:5080/sip next=(nil)
  302. nta.c:3299 agent_recv_response() nta: received 481 Call/Transaction Does Not Exist for CANCEL (113493116)
  303. nta.c:3366 agent_recv_response() nta: 481 Call/Transaction Does Not Exist is going to a transaction
  304. nta.c:9570 outgoing_estimate_delay() nta_outgoing: RTT is 48.587 ms
  305. tport.c:4222 tport_release() tport_release(0x7fb9d8004640): 0x7fb9d80eb550 by 0x7fb9d80ed0f0 with 0x7fb9d80a1df0
  306. nta.c:1296 agent_timer() nta: timer set next to 4048 ms
  307. nta.c:9107 outgoing_timer_dk() nta: timer K fired, terminate CANCEL (113493116)
  308. nta.c:8805 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7fb9df8b6d40)
  309. nta.c:8935 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free
  310. nta.c:1296 agent_timer() nta: timer set next to 26951 ms
  311.