+OK Global siptrace on nua.c:575 nua_set_params() nua: nua_set_params: entering nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering nua.c:575 nua_set_params() nua: nua_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f48a4001930, ...) called nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params nua.c:575 nua_set_params() nua: nua_set_params: entering nua_stack.c:529 nua_signal() nua((nil)): sent signal r_set_params nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f48a0001930, ...) called nua_stack.c:569 nua_stack_signal() nua((nil)): recv signal r_set_params nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f48a4001930, ...) called nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK nua_stack.c:271 nua_stack_event() nua((nil)): event r_set_params 200 OK nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering tport.c:2773 tport_wakeup() tport_wakeup(0x7f48a0022230): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f48a0022230) tport_type_tls.c:434 tport_tls_recv() tport_tls_recv(0x7f48a0022230): tls_read() returned 1047 tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f48a0022230) msg 0x7f48a00b4b30 from (tls/4.3.2.1:8206) has 1047 bytes, veclen = 1 recv 1047 bytes from tls/[4.3.2.1]:8206 at 16:11:18.227879: ------------------------------------------------------------------------ INVITE sip:5540@c02-sps1.somedomain.biz:5061;transport=tls SIP/2.0 Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: Date: Fri, 12 Jan 2018 16:11:18 GMT Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 Supported: timer,resource-priority,replaces User-Agent: Oracle-ESBC Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY CSeq: 101 INVITE Expires: 180 Allow-Events: presence, kpml Contact: Max-Forwards: 68 Content-Type: application/sdp Content-Length: 296 Diversion: v=0 o=Oracle-ESBC 12176919 1 IN IP4 4.3.2.1 s=SIP Call c=IN IP4 4.3.2.1 b=TIAS:64000 b=AS:64 t=0 0 m=audio 20014 RTP/AVP 0 101 18 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=maxptime:20 a=record:on ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f48a0022230): msg 0x7f48a00b4b30 (1047 bytes) from tls/4.3.2.1:8206/sips next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:5540@c02-sps1.somedomain.biz:5061;transport=tls SIP/2.0 (CSeq 101) nta.c:3085 agent_recv_request() nta: INVITE (101) going to a default leg nta.c:1350 set_timeout() nta: timer set to 2000 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering nua_stack.c:899 nh_create() nua: nh_create: entering nua_common.c:108 nh_create_handle() nua: nh_create_handle: entering nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:280 soa_clone() soa_clone(static::0x7f48a0001930, 0x7f48a0001130, 0x7f48a00b7d30) called soa.c:403 soa_set_params() soa_set_params(static::0x7f48a00b80d0, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f48a00b7930) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f48a00b80d0) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f48a00b80d0, (nil), 0x7f48a00b44ef, 296) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f48a00b7d30): adding session usage tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00ba3f0 105 (105) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 135 (135) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00ba459 68 (68) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 382 bytes of 382 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 382 send 382 bytes to tls/[4.3.2.1]:8206 at 16:11:18.228145: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Content-Length: 0 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (101) nua_stack.c:271 nua_stack_event() nua(0x7f48a00b7d30): event i_invite 100 Trying nua_session.c:4139 signal_call_state_change() nua(0x7f48a00b7d30): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f48a00b80d0, [0x7f48c3ffe550], [0x7f48c3ffe558], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f48a00b7d30): event i_state 100 Trying nua_stack.c:359 nua_application_event() nua: nua_application_event: entering tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 2018-01-12 16:11:18.216865 [NOTICE] switch_channel.c:1104 New Channel sofia/external/4640@4.3.2.1 [38cd6d34-f7b3-11e7-9a76-3f103b71f070] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:584 (sofia/external/4640@4.3.2.1) Running State Change CS_NEW (Cur 1 Tot 7) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-01-12 16:11:18.216865 [DEBUG] sofia.c:9873 sofia/external/4640@4.3.2.1 receiving invite from 4.3.2.1:8206 version: 1.6.19 64bit nua.c:610 nua_set_hparams() nua: nua_set_hparams: entering nua.c:610 nua_set_hparams() nua: nua_r_set_params with invalid handle (nil) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-01-12 16:11:18.216865 [DEBUG] sofia.c:7084 Channel sofia/external/4640@4.3.2.1 entering state [received][100] 2018-01-12 16:11:18.216865 [DEBUG] sofia.c:7094 Remote SDP: v=0 o=Oracle-ESBC 12176919 1 IN IP4 4.3.2.1 s=SIP Call c=IN IP4 4.3.2.1 b=TIAS:64000 b=AS:64 t=0 0 m=audio 20014 RTP/AVP 0 101 18 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=fmtp:18 annexb=no a=maxptime:20 a=record:on 2018-01-12 16:11:18.216865 [DEBUG] sofia.c:7486 (sofia/external/4640@4.3.2.1) State Change CS_NEW -> CS_INIT nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:603 (sofia/external/4640@4.3.2.1) State NEW 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:584 (sofia/external/4640@4.3.2.1) Running State Change CS_INIT (Cur 1 Tot 7) 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:627 (sofia/external/4640@4.3.2.1) State INIT 2018-01-12 16:11:18.216865 [DEBUG] mod_sofia.c:90 sofia/external/4640@4.3.2.1 SOFIA INIT 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:40 sofia/external/4640@4.3.2.1 Standard INIT 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:48 (sofia/external/4640@4.3.2.1) State Change CS_INIT -> CS_ROUTING 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:627 (sofia/external/4640@4.3.2.1) State INIT going to sleep 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:584 (sofia/external/4640@4.3.2.1) Running State Change CS_ROUTING (Cur 1 Tot 7) 2018-01-12 16:11:18.216865 [DEBUG] switch_channel.c:2249 (sofia/external/4640@4.3.2.1) Callstate Change DOWN -> RINGING 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:643 (sofia/external/4640@4.3.2.1) State ROUTING 2018-01-12 16:11:18.216865 [DEBUG] mod_sofia.c:143 sofia/external/4640@4.3.2.1 SOFIA ROUTING 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:236 sofia/external/4640@4.3.2.1 Standard ROUTING 2018-01-12 16:11:18.216865 [INFO] mod_dialplan_xml.c:637 Processing Finesse Test2 <4640>->5540 in context public Dialplan: sofia/external/4640@4.3.2.1 parsing [public->unloop] continue=false Dialplan: sofia/external/4640@4.3.2.1 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false Dialplan: sofia/external/4640@4.3.2.1 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false Dialplan: sofia/external/4640@4.3.2.1 parsing [public->outside_call] continue=true Dialplan: sofia/external/4640@4.3.2.1 Absolute Condition [outside_call] Dialplan: sofia/external/4640@4.3.2.1 Action set(outside_call=true) Dialplan: sofia/external/4640@4.3.2.1 Action export(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: sofia/external/4640@4.3.2.1 parsing [public->call_debug] continue=true Dialplan: sofia/external/4640@4.3.2.1 Regex (FAIL) [call_debug] ${call_debug}(false) =~ /^true$/ break=never Dialplan: sofia/external/4640@4.3.2.1 parsing [public->transfer_to_default] continue=false Dialplan: sofia/external/4640@4.3.2.1 Absolute Condition [transfer_to_default] Dialplan: sofia/external/4640@4.3.2.1 Action answer() Dialplan: sofia/external/4640@4.3.2.1 Action set(playback_terminators=none) Dialplan: sofia/external/4640@4.3.2.1 Action playback(conference/16000/conf-one_other_member_conference.wav) Dialplan: sofia/external/4640@4.3.2.1 Action hangup() 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:286 (sofia/external/4640@4.3.2.1) State Change CS_ROUTING -> CS_EXECUTE 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:643 (sofia/external/4640@4.3.2.1) State ROUTING going to sleep 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:584 (sofia/external/4640@4.3.2.1) Running State Change CS_EXECUTE (Cur 1 Tot 7) 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:650 (sofia/external/4640@4.3.2.1) State EXECUTE 2018-01-12 16:11:18.216865 [DEBUG] mod_sofia.c:198 sofia/external/4640@4.3.2.1 SOFIA EXECUTE 2018-01-12 16:11:18.216865 [DEBUG] switch_core_state_machine.c:328 sofia/external/4640@4.3.2.1 Standard EXECUTE EXECUTE sofia/external/4640@4.3.2.1 set(outside_call=true) 2018-01-12 16:11:18.216865 [DEBUG] mod_dptools.c:1548 SET sofia/external/4640@4.3.2.1 [outside_call]=[true] EXECUTE sofia/external/4640@4.3.2.1 export(RFC2822_DATE=Fri, 12 Jan 2018 16:11:18 +0000) 2018-01-12 16:11:18.216865 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [RFC2822_DATE]=[Fri, 12 Jan 2018 16:11:18 +0000] EXECUTE sofia/external/4640@4.3.2.1 answer() 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4504 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4365 Set telephone-event payload to 101@8000 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[opus:116:48000:20:0:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[G722:9:8000:20:64000:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMU:0:8000:20:64000:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4449 Audio Codec Compare [G729:18:8000:20:8000:1]/[PCMA:8:8000:20:64000:1] 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:3061 Set Codec sofia/external/4640@4.3.2.1 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 2018-01-12 16:11:18.216865 [DEBUG] switch_core_codec.c:111 sofia/external/4640@4.3.2.1 Original read codec set to PCMU:0 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4708 Set telephone-event payload to 101@8000 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:4767 sofia/external/4640@4.3.2.1 Set 2833 dtmf send payload to 101 recv payload to 101 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:6878 AUDIO RTP [sofia/external/4640@4.3.2.1] 10.201.3.235 port 16918 -> 4.3.2.1 port 20014 codec: 0 ms: 20 2018-01-12 16:11:18.216865 [DEBUG] switch_rtp.c:4111 Starting timer [soft] 160 bytes per 20ms 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:7179 sofia/external/4640@4.3.2.1 Set 2833 dtmf send payload to 101 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:7186 sofia/external/4640@4.3.2.1 Set 2833 dtmf receive payload to 101 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:7209 sofia/external/4640@4.3.2.1 Set rtp dtmf delay to 40 2018-01-12 16:11:18.216865 [NOTICE] sofia_media.c:92 Pre-Answer sofia/external/4640@4.3.2.1! 2018-01-12 16:11:18.216865 [DEBUG] switch_channel.c:3474 (sofia/external/4640@4.3.2.1) Callstate Change RINGING -> EARLY 2018-01-12 16:11:18.216865 [DEBUG] switch_core_media.c:6861 Audio params are unchanged for sofia/external/4640@4.3.2.1. 2018-01-12 16:11:18.216865 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/4640@4.3.2.1: v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=sendrecv nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f48a00b7d30): sent signal r_respond nua_stack.c:573 nua_stack_signal() nua(0x7f48a00b7d30): recv signal r_respond 200 OK nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f48a00b80d0, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f48a00b80d0, (nil), 0x7f484c0011ee, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f48a00b80d0, (nil), 0x7f484c0011ee, -1) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering soa.c:1515 soa_generate_answer() soa_generate_answer(static::0x7f48a00b80d0) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f48a00b80d0, soa_generate_answer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f48a00b80d0, soa_generate_answer): generating local description soa_static.c:1230 offer_answer_step() soa_static(0x7f48a00b80d0, soa_generate_answer): upgrade with remote description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f48c3ffc9a0, 0x7f48a00b9ca0, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f48a00b80d0, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f48a00b80d0, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f48a00b80d0, [(nil)], [0x7f48c3ffeb10], [0x7f48c3ffeb0c]) called tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 2018-01-12 16:11:18.216865 [NOTICE] mod_dptools.c:1312 Channel [sofia/external/4640@4.3.2.1] has been answered tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:18.231765: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (101) nta.c:1348 set_timeout() nta: timer shortened to 500 ms nua_session.c:4139 signal_call_state_change() nua(0x7f48a00b7d30): call state changed: received -> completed, sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f48a00b80d0, [0x7f48c3ffec20], [0x7f48c3ffec28], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f48a00b80d0, ...) called 2018-01-12 16:11:18.216865 [DEBUG] switch_channel.c:3773 (sofia/external/4640@4.3.2.1) Callstate Change EARLY -> ACTIVE nua_stack.c:271 nua_stack_event() nua(0x7f48a00b7d30): event i_state 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2018-01-12 16:11:18.216865 [DEBUG] sofia.c:7084 Channel sofia/external/4640@4.3.2.1 entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering EXECUTE sofia/external/4640@4.3.2.1 set(playback_terminators=none) 2018-01-12 16:11:18.216865 [DEBUG] mod_dptools.c:1548 SET sofia/external/4640@4.3.2.1 [playback_terminators]=[none] EXECUTE sofia/external/4640@4.3.2.1 playback(conference/16000/conf-one_other_member_conference.wav) 2018-01-12 16:11:18.216865 [DEBUG] switch_core_file.c:342 File /usr/share/freeswitch/sounds/en/us/callie/conference/16000/conf-one_other_member_conference.wav sample rate 16000 doesn't match requested rate 8000 2018-01-12 16:11:18.216865 [DEBUG] switch_ivr_play_say.c:1498 Codec Activated L16@8000hz 1 channels 20ms 2018-01-12 16:11:18.396863 [DEBUG] switch_rtp.c:7271 Correct audio ip/port confirmed. nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:18.731934: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 1000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:19.731943: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 2000 ms 2018-01-12 16:11:20.276925 [DEBUG] switch_ivr_play_say.c:1942 done playing file /usr/share/freeswitch/sounds/en/us/callie/conference/16000/conf-one_other_member_conference.wav EXECUTE sofia/external/4640@4.3.2.1 hangup() 2018-01-12 16:11:20.276925 [NOTICE] mod_dptools.c:1286 Hangup sofia/external/4640@4.3.2.1 [CS_EXECUTE] [NORMAL_CLEARING] 2018-01-12 16:11:20.276925 [DEBUG] switch_core_session.c:2815 sofia/external/4640@4.3.2.1 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:650 (sofia/external/4640@4.3.2.1) State EXECUTE going to sleep 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:584 (sofia/external/4640@4.3.2.1) Running State Change CS_HANGUP (Cur 1 Tot 7) 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:850 (sofia/external/4640@4.3.2.1) Callstate Change ACTIVE -> HANGUP 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:852 (sofia/external/4640@4.3.2.1) State HANGUP 2018-01-12 16:11:20.276925 [DEBUG] mod_sofia.c:438 Channel sofia/external/4640@4.3.2.1 hanging up, cause: NORMAL_CLEARING 2018-01-12 16:11:20.276925 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/4640@4.3.2.1 nua.c:645 nua_bye() nua: nua_bye: entering nua_stack.c:529 nua_signal() nua(0x7f48a00b7d30): sent signal r_bye 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:60 sofia/external/4640@4.3.2.1 Standard HANGUP, cause: NORMAL_CLEARING 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:852 (sofia/external/4640@4.3.2.1) State HANGUP going to sleep nua_stack.c:569 nua_stack_signal() nua(0x7f48a00b7d30): recv signal r_bye nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:619 (sofia/external/4640@4.3.2.1) State Change CS_HANGUP -> CS_REPORTING soa.c:403 soa_set_params() soa_set_params(static::0x7f48a00b80d0, ...) called 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:584 (sofia/external/4640@4.3.2.1) Running State Change CS_REPORTING (Cur 1 Tot 7) soa.c:1784 soa_terminate() soa_terminate(static::0x7f48a00b80d0) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f48a00b80d0) called 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:938 (sofia/external/4640@4.3.2.1) State REPORTING nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3257 tport_tsend() tport_tsend(0x7f48a00044f0) tpn = UDP/4.3.2.1:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 4.3.2.1:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f48a00044f0): not found by name UDP/4.3.2.1:5060 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:174 sofia/external/4640@4.3.2.1 Standard REPORTING, cause: NORMAL_CLEARING 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:938 (sofia/external/4640@4.3.2.1) State REPORTING going to sleep tport.c:3594 tport_vsend() tport_vsend(0x7f48a00044f0): 592 bytes of 592 to udp/4.3.2.1:5060 tport.c:3492 tport_send_msg() tport_vsend returned 592 send 592 bytes to udp/[4.3.2.1]:5060 at 16:11:20.310748: ------------------------------------------------------------------------ BYE sip:4640@4.3.2.1:5060 SIP/2.0 Via: SIP/2.0/UDP 1.2.3.4;rport;branch=z9hG4bKr6jU1t193yS9S Max-Forwards: 70 From: ;tag=Z4S29HjHSyetD To: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 117550676 BYE User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ nta.c:8304 outgoing_send() nta: sent BYE (117550676) to UDP/4.3.2.1:5060 tport.c:4160 tport_pend() tport_pend(0x7f48a00044f0): pending 0x7f48a00bb830 for udp/10.201.3.235:5060 (already 0) nta.c:1348 set_timeout() nta: timer shortened to 1000 ms 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:610 (sofia/external/4640@4.3.2.1) State Change CS_REPORTING -> CS_DESTROY 2018-01-12 16:11:20.276925 [DEBUG] switch_core_session.c:1665 Session 7 (sofia/external/4640@4.3.2.1) Locked, Waiting on external entities 2018-01-12 16:11:20.276925 [NOTICE] switch_core_session.c:1683 Session 7 (sofia/external/4640@4.3.2.1) Ended 2018-01-12 16:11:20.276925 [NOTICE] switch_core_session.c:1687 Close Channel sofia/external/4640@4.3.2.1 [CS_DESTROY] 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:741 (sofia/external/4640@4.3.2.1) Running State Change CS_DESTROY (Cur 0 Tot 7) 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:751 (sofia/external/4640@4.3.2.1) State DESTROY 2018-01-12 16:11:20.276925 [DEBUG] mod_sofia.c:343 sofia/external/4640@4.3.2.1 SOFIA DESTROY 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:181 sofia/external/4640@4.3.2.1 Standard DESTROY 2018-01-12 16:11:20.276925 [DEBUG] switch_core_state_machine.c:751 (sofia/external/4640@4.3.2.1) State DESTROY going to sleep tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f48a00044f0): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f48a00044f0) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f48a00044f0) msg 0x7f48a00b9c90 from (udp/10.201.3.235:5060) has 418 bytes, veclen = 1 recv 418 bytes from udp/[4.3.2.1]:5060 at 16:11:20.348585: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 1.2.3.4;received=1.2.3.4;branch=z9hG4bKr6jU1t193yS9S;rport=5060 From: ;tag=Z4S29HjHSyetD To: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 117550676 BYE Date: Fri, 12 Jan 2018 16:11:20 GMT Server: Cisco-CUCM11.0 Content-Length: 0 ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f48a00044f0): msg 0x7f48a00b9c90 (418 bytes) from udp/4.3.2.1:5060/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 200 OK for BYE (117550676) nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 37.93 ms tport.c:4222 tport_release() tport_release(0x7f48a00044f0): 0x7f48a00bb830 by 0x7f48a00b71b0 with 0x7f48a00b9c90 nua_stack.c:271 nua_stack_event() nua(0x7f48a00b7d30): event r_bye 200 OK nua_session.c:4139 signal_call_state_change() nua(0x7f48a00b7d30): call state changed: terminating -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f48a00b7d30): event i_state 200 to BYE nua_stack.c:271 nua_stack_event() nua(0x7f48a00b7d30): event i_terminated 200 to BYE nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f48a00b7d30): removing session usage soa.c:356 soa_destroy() soa_destroy(static::0x7f48a00b80d0) called nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f48a00b7930) nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f48a00b7d30 nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:921 nua_handle_destroy() nua: nua_handle_destroy: entering nua_stack.c:529 nua_signal() nua(0x7f48a00b7d30): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f48a00b7d30): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) nta.c:1296 agent_timer() nta: timer set next to 421 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:21.732263: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 3617 ms nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate BYE (117550676) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f48c3ffec90) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free nta.c:1296 agent_timer() nta: timer set next to 382 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:25.731776: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:29.731783: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:33.731765: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:37.731769: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:41.731766: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:45.731812: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:6996 _nta_incoming_timer() nta: timer G fired, retransmitting 200 reply tport.c:3257 tport_tsend() tport_tsend(0x7f48a0022230) tpn = TLS/4.3.2.1:8206 tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcbc0 101 (101) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b428e 107 (107) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc25 46 (46) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b433a 56 (56) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00b4411 18 (18) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bcc53 461 (461) tport_type_tls.c:534 tport_tls_send() tport_tls_writevec: vec 0x7f48a0001870 0x7f48a00bb1d0 218 (218) tport.c:3594 tport_vsend() tport_vsend(0x7f48a0022230): 1007 bytes of 1007 to tls/4.3.2.1:8206 tport.c:3492 tport_send_msg() tport_vsend returned 1007 send 1007 bytes to tls/[4.3.2.1]:8206 at 16:11:49.731784: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/TLS 4.3.2.1:5061;branch=z9hG4bKp424bq202ooqg4i985l0.1;rport=8206 From: "Finesse Test2" ;tag=12176919~92885dea-9af6-4628-9a25-570d6af7a50a-35601172 To: ;tag=Z4S29HjHSyetD Call-ID: 37729c80-a581de26-2fe65c-b640a0a@10.10.100.11 CSeq: 101 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.6.19~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 218 Remote-Party-ID: "5540" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1515756560 1515756561 IN IP4 1.2.3.4 s=FreeSWITCH c=IN IP4 1.2.3.4 t=0 0 m=audio 16918 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 1/1 resent, 0/1 tout, 0/0 term, 0/1 free nta.c:1296 agent_timer() nta: timer set next to 500 ms nta.c:7105 _nta_incoming_timer() nta: timer H fired, timeout and terminate 200 response tport.c:2296 tport_set_secondary_timer() tport(0x7f48a0022230): reset timer nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f48c3ffeb60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/1 resent, 1/1 tout, 1/0 term, 1/1 free nta.c:1289 agent_timer() nta: timer not set freeswitch@c02-anvge-sps1.somedomain.biz>