2017-02-24 11:47:36.668715 [NOTICE] mod_logfile.c:192 New log started. tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f602400fd20 from (udp/172.21.0.10:5080) has 1221 bytes, veclen = 1 recv 1221 bytes from udp/[172.21.0.12]:5060 at 11:49:23.668644: ------------------------------------------------------------------------ INVITE sip:3613612202@172.21.0.10:5080 SIP/2.0 Record-Route: Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.ff4d1330fdf889a72137635ea4ba63d8.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-0 Max-Forwards: 43 To: "3613612202" From: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 1 INVITE Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,MESSAGE,SUBSCRIBE,INFO Content-Type: application/sdp User-Agent: eyeBeam release 9330a stamp 37653 Content-Length: 434 Server: SIPp Server P-Asserted-Identity: "3613612209" Contact: v=0 o=ipjib 1487263187420 1487263187420 IN IP4 10.112.48.79 s=CounterPath eyeBeam 1.5 c=IN IP4 10.112.48.79 t=0 0 m=audio 60578 RTP/AVP 119 6 0 98 8 3 5 101 a=alt:1 2 : FwGzks7j aVPEMhBL 10.112.48.79 60578 a=alt:2 1 : NxVGnjOA 78sxYW0G 10.112.200.224 60578 a=fmtp:101 0-15 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f602400fd20 (1221 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:3613612202@172.21.0.10:5080 SIP/2.0 (CSeq 1) nta.c:3248 agent_aliases() nta: canonizing sip:3613612202@172.21.0.10:5080 with contact nta.c:3085 agent_recv_request() nta: INVITE (1) going to a default leg nta.c:1350 set_timeout() nta: timer set to 200 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::0x7f6024001930, 0x7f6024001130, 0x7f602400e290) called soa.c:403 soa_set_params() soa_set_params(static::0x7f602400eb60, ...) called nta.c:4417 nta_leg_tcreate() nta_leg_tcreate(0x7f602400f470) soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f602400eb60) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f602400eb60, (nil), 0x7f6024006533, 434) called nua_dialog.c:338 nua_dialog_usage_add() nua(0x7f602400e290): adding session usage tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 439 bytes of 439 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 439 send 439 bytes to udp/[172.21.0.12]:5060 at 11:49:23.669117: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.ff4d1330fdf889a72137635ea4ba63d8.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-0 Record-Route: From: "3613612209" ;tag=1 To: "3613612202" Call-ID: 1-1765@172.21.0.11 CSeq: 1 INVITE User-Agent: Voicis WebRTC Gateway Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (1) nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_invite 100 Trying nua_session.c:4139 signal_call_state_change() nua(0x7f602400e290): call state changed: init -> received, received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f602400eb60, [0x7f604a04a8c8], [0x7f604a04a8d0], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 100 Trying nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua.c:342 nua_handle_bind() nua: nua_handle_bind: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [NOTICE] switch_channel.c:1104 New Channel sofia/external/3613612209@webrtc.example.com [810f2514-ac39-4e49-b8fe-2e2adb046646] nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_NEW (Cur 1 Tot 9) nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] sofia.c:9819 sofia/external/3613612209@webrtc.example.com receiving invite from 172.21.0.12:5060 version: 1.6.15 -32-bec4538 64bit nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [received][100] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] sofia.c:7052 Remote SDP: 810f2514-ac39-4e49-b8fe-2e2adb046646 v=0 810f2514-ac39-4e49-b8fe-2e2adb046646 o=ipjib 1487263187420 1487263187420 IN IP4 10.112.48.79 810f2514-ac39-4e49-b8fe-2e2adb046646 s=CounterPath eyeBeam 1.5 810f2514-ac39-4e49-b8fe-2e2adb046646 c=IN IP4 10.112.48.79 810f2514-ac39-4e49-b8fe-2e2adb046646 t=0 0 810f2514-ac39-4e49-b8fe-2e2adb046646 m=audio 60578 RTP/AVP 119 6 0 98 8 3 5 101 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:119 BV32-FEC/16000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:98 iLBC/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:101 telephone-event/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=fmtp:101 0-15 810f2514-ac39-4e49-b8fe-2e2adb046646 a=alt:1 2 : FwGzks7j aVPEMhBL 10.112.48.79 60578 810f2514-ac39-4e49-b8fe-2e2adb046646 a=alt:2 1 : NxVGnjOA 78sxYW0G 10.112.200.224 60578 810f2514-ac39-4e49-b8fe-2e2adb046646 a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC 810f2514-ac39-4e49-b8fe-2e2adb046646 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:6:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:6:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:5:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:5:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4316 Set telephone-event payload to 101@8000 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:3047 Set Codec sofia/external/3613612209@webrtc.example.com PCMU/8000 20 ms 160 samples 64000 bits 1 channels 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_codec.c:111 sofia/external/3613612209@webrtc.example.com Original read codec set to PCMU:0 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4659 Set telephone-event payload to 101@8000 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_media.c:4718 sofia/external/3613612209@webrtc.example.com Set 2833 dtmf send payload to 101 recv payload to 101 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] sofia.c:7465 (sofia/external/3613612209@webrtc.example.com) State Change CS_NEW -> CS_INIT nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:603 (sofia/external/3613612209@webrtc.example.com) State NEW 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_INIT (Cur 1 Tot 9) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3613612209@webrtc.example.com) State INIT 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] mod_sofia.c:90 sofia/external/3613612209@webrtc.example.com SOFIA INIT 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:40 sofia/external/3613612209@webrtc.example.com Standard INIT 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:48 (sofia/external/3613612209@webrtc.example.com) State Change CS_INIT -> CS_ROUTING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:627 (sofia/external/3613612209@webrtc.example.com) State INIT going to sleep 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_ROUTING (Cur 1 Tot 9) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_channel.c:2249 (sofia/external/3613612209@webrtc.example.com) Callstate Change DOWN -> RINGING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3613612209@webrtc.example.com) State ROUTING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] mod_sofia.c:143 sofia/external/3613612209@webrtc.example.com SOFIA ROUTING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:236 sofia/external/3613612209@webrtc.example.com Standard ROUTING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [INFO] mod_dialplan_xml.c:637 Processing 3613612209 <3613612209>->3613612202 in context public 810f2514-ac39-4e49-b8fe-2e2adb046646 Dialplan: sofia/external/3613612209@webrtc.example.com parsing [public->call_debug] continue=true 810f2514-ac39-4e49-b8fe-2e2adb046646 Dialplan: sofia/external/3613612209@webrtc.example.com Absolute Condition [call_debug] 810f2514-ac39-4e49-b8fe-2e2adb046646 Dialplan: sofia/external/3613612209@webrtc.example.com Action info() 810f2514-ac39-4e49-b8fe-2e2adb046646 Dialplan: sofia/external/3613612209@webrtc.example.com parsing [public->public_extensions] continue=false 810f2514-ac39-4e49-b8fe-2e2adb046646 Dialplan: sofia/external/3613612209@webrtc.example.com Absolute Condition [public_extensions] 810f2514-ac39-4e49-b8fe-2e2adb046646 Dialplan: sofia/external/3613612209@webrtc.example.com Action bridge(${verto_contact(${destination_number}@webrtc.example.com)}) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:286 (sofia/external/3613612209@webrtc.example.com) State Change CS_ROUTING -> CS_EXECUTE 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:643 (sofia/external/3613612209@webrtc.example.com) State ROUTING going to sleep 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_EXECUTE (Cur 1 Tot 9) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:650 (sofia/external/3613612209@webrtc.example.com) State EXECUTE 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] mod_sofia.c:198 sofia/external/3613612209@webrtc.example.com SOFIA EXECUTE 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:328 sofia/external/3613612209@webrtc.example.com Standard EXECUTE 810f2514-ac39-4e49-b8fe-2e2adb046646 EXECUTE sofia/external/3613612209@webrtc.example.com info() 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [INFO] mod_dptools.c:1740 CHANNEL_DATA: 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-State: [CS_EXECUTE] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Call-State: [RINGING] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-State-Number: [4] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Name: [sofia/external/3613612209@webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 Unique-ID: [810f2514-ac39-4e49-b8fe-2e2adb046646] 810f2514-ac39-4e49-b8fe-2e2adb046646 Call-Direction: [inbound] 810f2514-ac39-4e49-b8fe-2e2adb046646 Presence-Call-Direction: [inbound] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-HIT-Dialplan: [true] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Call-UUID: [810f2514-ac39-4e49-b8fe-2e2adb046646] 810f2514-ac39-4e49-b8fe-2e2adb046646 Answer-State: [ringing] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Read-Codec-Name: [PCMU] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Read-Codec-Rate: [8000] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Read-Codec-Bit-Rate: [64000] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Write-Codec-Name: [PCMU] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Write-Codec-Rate: [8000] 810f2514-ac39-4e49-b8fe-2e2adb046646 Channel-Write-Codec-Bit-Rate: [64000] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Direction: [inbound] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Logical-Direction: [inbound] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Username: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Dialplan: [XML] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Caller-ID-Name: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Caller-ID-Number: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Orig-Caller-ID-Name: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Orig-Caller-ID-Number: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Network-Addr: [172.21.0.12] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-ANI: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Destination-Number: [3613612202] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Unique-ID: [810f2514-ac39-4e49-b8fe-2e2adb046646] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Source: [mod_sofia] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Context: [public] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Name: [sofia/external/3613612209@webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Profile-Index: [1] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Profile-Created-Time: [1487936963669056] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Created-Time: [1487936963669056] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Answered-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Progress-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Progress-Media-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Hangup-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Transfer-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Resurrect-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Bridged-Time: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Last-Hold: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Channel-Hold-Accum: [0] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Screen-Bit: [true] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Privacy-Hide-Name: [false] 810f2514-ac39-4e49-b8fe-2e2adb046646 Caller-Privacy-Hide-Number: [false] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_direction: [inbound] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_uuid: [810f2514-ac39-4e49-b8fe-2e2adb046646] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_session_id: [9] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_from_user: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_from_uri: [3613612209@webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_from_host: [webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_video_media_flow: [sendrecv] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_channel_name: [sofia/external/3613612209@webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_call_id: [1-1765@172.21.0.11] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_ep_codec_string: [CORE_PCM_MODULE.PCMU@8000h@20i@64000b,CORE_PCM_MODULE.PCMA@8000h@20i@64000b] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_local_network_addr: [172.21.0.10] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_network_ip: [172.21.0.12] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_network_port: [5060] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_received_ip: [172.21.0.12] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_received_port: [5060] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_via_protocol: [udp] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_from_user_stripped: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_from_tag: [1] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sofia_profile_name: [external] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_recovery_profile_name: [external] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_P-Asserted-Identity: ["3613612209" ] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_cid_type: [pid] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_invite_route_uri: [] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_invite_record_route: [] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_full_via: [SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.ff4d1330fdf889a72137635ea4ba63d8.0,SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-0] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_from_display: [3613612209] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_full_from: ["3613612209" ;tag=1] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_to_display: [3613612202] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_full_to: ["3613612202" ] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_allow: [INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_req_user: [3613612202] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_req_port: [5080] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_req_uri: [3613612202@172.21.0.10:5080] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_req_host: [172.21.0.10] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_to_user: [3613612202] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_to_uri: [3613612202@webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_to_host: [webrtc.example.com] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_contact_params: [abcct=7369703a31302e3131322e32362e38353a35303630] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_contact_user: [siplb] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_contact_port: [5061] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_contact_uri: [siplb@172.21.0.11:5061] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_contact_host: [172.21.0.11] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_user_agent: [eyeBeam release 9330a stamp 37653] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_via_host: [172.21.0.12] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_max_forwards: [43] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_from: ["3613612209" ;tag=1] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_to: ["3613612202" ] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_call_id: [1-1765@172.21.0.11] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_cseq: [1 INVITE] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_max_forwards: [43] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_contact: [] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_user_agent: [eyeBeam release 9330a stamp 37653] 810f2514-ac39-4e49-b8fe-2e2adb046646 variable_sip_i_allow: [INVITE, ACK, CANCEL, OPTIONS, BYE, REFER, NOTIFY, MESSAGE, SUBSCRIBE, INFO] variable_sip_i_content_type: [application/sdp] variable_sip_i_content_length: [434] variable_sip_i_via: [ARRAY::SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.ff4d1330fdf889a72137635ea4ba63d8.0|:SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-0] variable_sip_i_record_route: [] variable_sip_i_p_asserted_identity: ["3613612209" ] variable_switch_r_sdp: [v=0 o=ipjib 1487263187420 1487263187420 IN IP4 10.112.48.79 s=CounterPath eyeBeam 1.5 c=IN IP4 10.112.48.79 t=0 0 m=audio 60578 RTP/AVP 119 6 0 98 8 3 5 101 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=alt:1 2 : FwGzks7j aVPEMhBL 10.112.48.79 60578 a=alt:2 1 : NxVGnjOA 78sxYW0G 10.112.200.224 60578 a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC ] variable_audio_media_flow: [sendrecv] variable_rtp_use_codec_string: [PCMA,PCMU] variable_remote_media_ip: [10.112.48.79] variable_remote_media_port: [60578] variable_rtp_audio_recv_pt: [0] variable_rtp_use_codec_name: [PCMU] variable_rtp_use_codec_rate: [8000] variable_rtp_use_codec_ptime: [20] variable_rtp_use_codec_channels: [1] variable_rtp_last_audio_codec_string: [PCMU@8000h@20i@1c] variable_read_codec: [PCMU] variable_original_read_codec: [PCMU] variable_read_rate: [8000] variable_original_read_rate: [8000] variable_write_codec: [PCMU] variable_write_rate: [8000] variable_dtmf_type: [rfc2833] variable_endpoint_disposition: [RECEIVED] variable_call_uuid: [810f2514-ac39-4e49-b8fe-2e2adb046646] variable_current_application: [info] 810f2514-ac39-4e49-b8fe-2e2adb046646 EXECUTE sofia/external/3613612209@webrtc.example.com bridge(verto.rtc/u:d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a [5749daf1-911f-4eff-81ba-d53899e6f055] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_INIT (Cur 2 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State INIT 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] mod_verto.c:2218 Local verto.invite SDP verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a: 5749daf1-911f-4eff-81ba-d53899e6f055 v=0 5749daf1-911f-4eff-81ba-d53899e6f055 o=FreeSWITCH 1487909137 1487909138 IN IP4 172.21.0.10 5749daf1-911f-4eff-81ba-d53899e6f055 s=FreeSWITCH 5749daf1-911f-4eff-81ba-d53899e6f055 c=IN IP4 172.21.0.10 5749daf1-911f-4eff-81ba-d53899e6f055 t=0 0 5749daf1-911f-4eff-81ba-d53899e6f055 a=msid-semantic: WMS vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfm 5749daf1-911f-4eff-81ba-d53899e6f055 m=audio 27826 RTP/SAVPF 0 5749daf1-911f-4eff-81ba-d53899e6f055 a=rtpmap:0 PCMU/8000 5749daf1-911f-4eff-81ba-d53899e6f055 a=fingerprint:sha-256 41:97:2A:DD:7A:AD:58:E8:BC:50:42:80:46:1D:35:55:CE:58:97:C3:93:7A:2F:93:70:0C:8B:CE:77:B8:1A:42 5749daf1-911f-4eff-81ba-d53899e6f055 a=setup:actpass 5749daf1-911f-4eff-81ba-d53899e6f055 a=rtcp-mux 5749daf1-911f-4eff-81ba-d53899e6f055 a=rtcp:27826 IN IP4 172.21.0.10 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:1018326419 cname:ID16PN4CNxzAQEgp 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:1018326419 msid:vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfm a0 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:1018326419 mslabel:vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfm 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:1018326419 label:vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfma0 5749daf1-911f-4eff-81ba-d53899e6f055 a=ice-ufrag:I6f7buPpotOfGUsf 5749daf1-911f-4eff-81ba-d53899e6f055 a=ice-pwd:njb3X6vAtU09p7oX4uU5PAk3 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:6230667560 1 udp 659136 172.21.0.10 27826 typ host generation 0 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:6230667560 2 udp 659136 172.21.0.10 27826 typ host generation 0 5749daf1-911f-4eff-81ba-d53899e6f055 a=silenceSupp:off - - - - 5749daf1-911f-4eff-81ba-d53899e6f055 a=ptime:20 5749daf1-911f-4eff-81ba-d53899e6f055 a=sendrecv 5749daf1-911f-4eff-81ba-d53899e6f055 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [NOTICE] mod_verto.c:2318 Ring-Ready verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a! 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_channel.c:3345 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Callstate Change DOWN -> RINGING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:40 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a Standard INIT 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State Change CS_INIT -> CS_ROUTING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State INIT going to sleep 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_ROUTING (Cur 2 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State ROUTING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] mod_rtc.c:89 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a RTC ROUTING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_ivr_originate.c:67 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State Change CS_ROUTING -> CS_CONSUME_MEDIA 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State ROUTING going to sleep 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State CONSUME_MEDIA 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:23.669056 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State CONSUME_MEDIA going to sleep nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f602400e290): sent signal r_respond 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [NOTICE] mod_sofia.c:2263 Ring-Ready sofia/external/3613612209@webrtc.example.com! nua_stack.c:573 nua_stack_signal() nua(0x7f602400e290): recv signal r_respond 180 Ringing nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f602400eb60, ...) called nua_session.c:2320 nua_invite_server_respond() nua: nua_invite_server_respond: entering tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [NOTICE] switch_ivr_originate.c:525 Ring Ready sofia/external/3613612209@webrtc.example.com! tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 810 bytes of 810 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 810 send 810 bytes to udp/[172.21.0.12]:5060 at 11:49:23.678125: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.ff4d1330fdf889a72137635ea4ba63d8.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-0 Record-Route: From: "3613612209" ;tag=1 To: "3613612202" ;tag=1DK7cet40aNjD Call-ID: 1-1765@172.21.0.11 CSeq: 1 INVITE Contact: User-Agent: Voicis WebRTC Gateway 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-Length: 0 P-Asserted-Identity: "Outbound Call" ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 180 Ringing for INVITE (1) nua_session.c:4139 signal_call_state_change() nua(0x7f602400e290): call state changed: received -> early nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 180 Ringing nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 2017-02-24 11:49:23.669056 [ALERT] mod_verto.c:604 WRITE 172.21.0.1:45670 [{ "jsonrpc": "2.0", "id": 9, "method": "verto.invite", "params": { "callID": "5749daf1-911f-4eff-81ba-d53899e6f055", "sdp": "v=0\r\no=FreeSWITCH 1487909137 1487909138 IN IP4 172.21.0.10\r\ns=FreeSWITCH\r\nc=IN IP4 172.21.0.10\r\nt=0 0\r\na=msid-semantic: WMS vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfm\r\nm=audio 27826 RTP/SAVPF 0\r\na=rtpmap:0 PCMU/8000\r\na=fingerprint:sha-256 41:97:2A:DD:7A:AD:58:E8:BC:50:42:80:46:1D:35:55:CE:58:97:C3:93:7A:2F:93:70:0C:8B:CE:77:B8:1A:42\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:27826 IN IP4 172.21.0.10\r\na=ssrc:1018326419 cname:ID16PN4CNxzAQEgp\r\na=ssrc:1018326419 msid:vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfm a0\r\na=ssrc:1018326419 mslabel:vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfm\r\na=ssrc:1018326419 label:vvxOxmW8W9C6XtfQIdZ0zepSo3Ny1nfma0\r\na=ice-ufrag:I6f7buPpotOfGUsf\r\na=ice-pwd:njb3X6vAtU09p7oX4uU5PAk3\r\na=candidate:6230667560 1 udp 659136 172.21.0.10 27826 typ host generation 0\r\na=candidate:6230667560 2 udp 659136 172.21.0.10 27826 typ host generation 0\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\n", "caller_id_name": "3613612209", "caller_id_number": "3613612209", "callee_id_name": "Outbound Call", "callee_id_number": "d5c3b5fa-9ccf-0b60-a6b7-027231713d4a", "display_direction": "outbound" } }] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:23.669056 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [early][180] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 2017-02-24 11:49:23.708713 [ALERT] mod_verto.c:1373 READ 172.21.0.1:45670 [{ "jsonrpc": "2.0", "id": 9, "result": { "method": "verto.invite" } }] nta.c:1296 agent_timer() nta: timer set next to 59810 ms 2017-02-24 11:49:30.348710 [ALERT] mod_verto.c:1373 READ 172.21.0.1:45670 [{ "jsonrpc": "2.0", "method": "verto.answer", "params": { "sdp": "v=0\r\no=- 2894448575661892366 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=msid-semantic: WMS EK0UNUUr9W2DIwXDN7aZDr7iN7wikXZ2hYlQ\r\nm=audio 42477 RTP/SAVPF 0\r\nc=IN IP4 172.17.0.1\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=candidate:3885250869 1 udp 2122260223 172.17.0.1 42477 typ host generation 0 network-id 2 network-cost 50\r\na=candidate:410389623 1 udp 2122194687 172.21.0.1 45448 typ host generation 0 network-id 1 network-cost 50\r\na=candidate:88617392 1 udp 2122129151 10.178.17.174 41805 typ host generation 0 network-id 4\r\na=candidate:1019731727 1 udp 2122063615 192.168.1.104 33126 typ host generation 0 network-id 3\r\na=candidate:2836907461 1 tcp 1518280447 172.17.0.1 9 typ host tcptype active generation 0 network-id 2 network-cost 50\r\na=candidate:1458958471 1 tcp 1518214911 172.21.0.1 9 typ host tcptype active generation 0 network-id 1 network-cost 50\r\na=candidate:1271647552 1 tcp 1518149375 10.178.17.174 9 typ host tcptype active generation 0 network-id 4\r\na=candidate:1917068287 1 tcp 1518083839 192.168.1.104 9 typ host tcptype active generation 0 network-id 3\r\na=ice-ufrag:zcgf\r\na=ice-pwd:xnmyy4hBg/BhKkAWsWFt32H6\r\na=fingerprint:sha-256 94:5C:5D:F4:19:6A:97:A9:3B:06:A1:B5:E9:EB:DA:C0:E9:44:E9:90:1A:B3:D8:01:EB:51:A2:C3:73:65:A5:4F\r\na=setup:active\r\na=mid:audio\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:0 PCMU/8000\r\na=ssrc:568988862 cname:Rxz2Rr65tvR/99/O\r\na=ssrc:568988862 msid:EK0UNUUr9W2DIwXDN7aZDr7iN7wikXZ2hYlQ b524ddbc-ddbf-46b3-b0d0-641a54fb1d14\r\na=ssrc:568988862 mslabel:EK0UNUUr9W2DIwXDN7aZDr7iN7wikXZ2hYlQ\r\na=ssrc:568988862 label:b524ddbc-ddbf-46b3-b0d0-641a54fb1d14\r\n", "dialogParams": { "screenShare": false, "useMic": "any", "useSpeak": "any", "tag": "webcam", "localTag": null, "login": "3613612202@webrtc.example.com", "videoParams": { "minWidth": "1280", "minHeight": "720", "minFrameRate": 30 }, "callID": "5749daf1-911f-4eff-81ba-d53899e6f055", "caller_id_name": "3613612209", "caller_id_number": "3613612209", "callee_id_name": "3613612202", "callee_id_number": "3613612202", "display_direction": "outbound", "remote_caller_id_name": "3613612209", "remote_caller_id_number": "3613612209" }, "sessid": "d5c3b5fa-9ccf-0b60-a6b7-027231713d4a" }, "id": 25 }] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] mod_verto.c:2673 Remote SDP verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a: 5749daf1-911f-4eff-81ba-d53899e6f055 v=0 5749daf1-911f-4eff-81ba-d53899e6f055 o=- 2894448575661892366 2 IN IP4 127.0.0.1 5749daf1-911f-4eff-81ba-d53899e6f055 s=- 5749daf1-911f-4eff-81ba-d53899e6f055 t=0 0 5749daf1-911f-4eff-81ba-d53899e6f055 a=msid-semantic: WMS EK0UNUUr9W2DIwXDN7aZDr7iN7wikXZ2hYlQ 5749daf1-911f-4eff-81ba-d53899e6f055 m=audio 42477 RTP/SAVPF 0 5749daf1-911f-4eff-81ba-d53899e6f055 c=IN IP4 172.17.0.1 5749daf1-911f-4eff-81ba-d53899e6f055 a=rtcp:9 IN IP4 0.0.0.0 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:3885250869 1 udp 2122260223 172.17.0.1 42477 typ host generation 0 network-id 2 network-cost 50 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:410389623 1 udp 2122194687 172.21.0.1 45448 typ host generation 0 network-id 1 network-cost 50 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:88617392 1 udp 2122129151 10.178.17.174 41805 typ host generation 0 network-id 4 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:1019731727 1 udp 2122063615 192.168.1.104 33126 typ host generation 0 network-id 3 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:2836907461 1 tcp 1518280447 172.17.0.1 9 typ host tcptype active generation 0 network-id 2 network-cost 50 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:1458958471 1 tcp 1518214911 172.21.0.1 9 typ host tcptype active generation 0 network-id 1 network-cost 50 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:1271647552 1 tcp 1518149375 10.178.17.174 9 typ host tcptype active generation 0 network-id 4 5749daf1-911f-4eff-81ba-d53899e6f055 a=candidate:1917068287 1 tcp 1518083839 192.168.1.104 9 typ host tcptype active generation 0 network-id 3 5749daf1-911f-4eff-81ba-d53899e6f055 a=ice-ufrag:zcgf 5749daf1-911f-4eff-81ba-d53899e6f055 a=ice-pwd:xnmyy4hBg/BhKkAWsWFt32H6 5749daf1-911f-4eff-81ba-d53899e6f055 a=fingerprint:sha-256 94:5C:5D:F4:19:6A:97:A9:3B:06:A1:B5:E9:EB:DA:C0:E9:44:E9:90:1A:B3:D8:01:EB:51:A2:C3:73:65:A5:4F 5749daf1-911f-4eff-81ba-d53899e6f055 a=setup:active 5749daf1-911f-4eff-81ba-d53899e6f055 a=mid:audio 5749daf1-911f-4eff-81ba-d53899e6f055 a=sendrecv 5749daf1-911f-4eff-81ba-d53899e6f055 a=rtcp-mux 5749daf1-911f-4eff-81ba-d53899e6f055 a=rtpmap:0 PCMU/8000 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:568988862 cname:Rxz2Rr65tvR/99/O 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:568988862 msid:EK0UNUUr9W2DIwXDN7aZDr7iN7wikXZ2hYlQ b524ddbc-ddbf-46b3-b0d0-641a54fb1d14 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:568988862 mslabel:EK0UNUUr9W2DIwXDN7aZDr7iN7wikXZ2hYlQ 5749daf1-911f-4eff-81ba-d53899e6f055 a=ssrc:568988862 label:b524ddbc-ddbf-46b3-b0d0-641a54fb1d14 5749daf1-911f-4eff-81ba-d53899e6f055 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [WARNING] switch_ivr.c:3858 can't find user [3613612202@webrtc.example.com] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3047 Set Codec verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a PCMU/8000 20 ms 160 samples 64000 bits 1 channels 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_codec.c:111 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a Original read codec set to PCMU:0 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: udp type: host addr: 172.17.0.1:42477 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: udp type: host addr: 172.21.0.1:45448 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: udp type: host addr: 10.178.17.174:41805 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3455 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.1.104:33126 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3497 Searching for rtp candidate. 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3502 Choose rtp candidate, index 1, 172.21.0.1:45448 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3276 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a choosing family v4 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3513 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 172.21.0.1:45448 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3558 setting remote audio ice addr to index 1 172.21.0.1:45448 based on candidate 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:3579 Setting remote rtcp audio addr to 172.21.0.1:45448 based on candidate 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:4725 No 2833 in SDP. Disable 2833 dtmf and switch to INFO 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:6732 AUDIO RTP [verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a] 172.21.0.10 port 27826 -> 172.21.0.1 port 45448 codec: 0 ms: 20 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 160 bytes per 20ms 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [INFO] switch_core_media.c:6914 Activating Audio ICE 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [NOTICE] switch_rtp.c:4367 Activating RTP audio ICE: zcgf:I6f7buPpotOfGUsf 172.21.0.1:45448 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:6957 Activating RTCP PORT 45448 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_rtp.c:4264 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 45448 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [INFO] switch_core_media.c:6965 Skipping RTCP ICE (Same as RTP) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [INFO] switch_rtp.c:3371 Activate RTP/RTCP audio DTLS server 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [INFO] switch_rtp.c:3505 Changing audio DTLS state from OFF to HANDSHAKE 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:2017 Setting Jitterbuffer to 20ms (1 frames) (50 max frames) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_core_media.c:6715 Audio params are unchanged for verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a. 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [NOTICE] mod_verto.c:2707 Channel [verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a] has been answered 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.348710 [DEBUG] switch_channel.c:3772 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Callstate Change RINGING -> ACTIVE 2017-02-24 11:49:30.348710 [ALERT] mod_verto.c:604 WRITE 172.21.0.1:45670 [{ "jsonrpc": "2.0", "id": 25, "result": { "sessid": "d5c3b5fa-9ccf-0b60-a6b7-027231713d4a" } }] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/3613612209@webrtc.example.com] 172.21.0.10 port 18246 -> 10.112.48.79 port 60578 codec: 0 ms: 20 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_rtp.c:3878 Starting timer [soft] 160 bytes per 20ms 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_core_media.c:7038 sofia/external/3613612209@webrtc.example.com Set 2833 dtmf send payload to 101 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_core_media.c:7045 sofia/external/3613612209@webrtc.example.com Set 2833 dtmf receive payload to 101 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_core_media.c:7068 sofia/external/3613612209@webrtc.example.com Set rtp dtmf delay to 40 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] mod_sofia.c:850 Local SDP sofia/external/3613612209@webrtc.example.com: 810f2514-ac39-4e49-b8fe-2e2adb046646 v=0 810f2514-ac39-4e49-b8fe-2e2adb046646 o=FreeSWITCH 1487918724 1487918725 IN IP4 172.21.0.10 810f2514-ac39-4e49-b8fe-2e2adb046646 s=FreeSWITCH 810f2514-ac39-4e49-b8fe-2e2adb046646 c=IN IP4 172.21.0.10 810f2514-ac39-4e49-b8fe-2e2adb046646 t=0 0 810f2514-ac39-4e49-b8fe-2e2adb046646 m=audio 18246 RTP/AVP 0 101 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:0 PCMU/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:101 telephone-event/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=fmtp:101 0-16 810f2514-ac39-4e49-b8fe-2e2adb046646 a=ptime:20 810f2514-ac39-4e49-b8fe-2e2adb046646 a=sendrecv 810f2514-ac39-4e49-b8fe-2e2adb046646 nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f602400e290): sent signal r_respond nua_stack.c:573 nua_stack_signal() nua(0x7f602400e290): 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::0x7f602400eb60, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f602400eb60, (nil), 0x7f5fe400d517, -1) called soa.c:890 soa_set_capability_sdp() soa_set_capability_sdp(static::0x7f602400eb60, (nil), 0x7f5fe400d517, -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::0x7f602400eb60) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f602400eb60, soa_generate_answer): called soa_static.c:1189 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): generating local description soa_static.c:1230 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): upgrade with remote description 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [NOTICE] switch_ivr_originate.c:3628 Channel [sofia/external/3613612209@webrtc.example.com] has been answered soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f604a048ab0, 0x7f6024010c40, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f602400eb60, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f602400eb60, [(nil)], [0x7f604a04ac38], [0x7f604a04ac34]) called tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 1032 bytes of 1032 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 1032 send 1032 bytes to udp/[172.21.0.12]:5060 at 11:49:30.371405: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.ff4d1330fdf889a72137635ea4ba63d8.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-0 Record-Route: From: "3613612209" ;tag=1 To: "3613612202" ;tag=1DK7cet40aNjD Call-ID: 1-1765@172.21.0.11 CSeq: 1 INVITE Contact: User-Agent: Voicis WebRTC Gateway 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 P-Asserted-Identity: "3613612202" v=0 o=FreeSWITCH 1487918724 1487918725 IN IP4 172.21.0.10 s=FreeSWITCH c=IN IP4 172.21.0.10 t=0 0 m=audio 18246 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (1) nta.c:1348 set_timeout() nta: timer shortened to 500 ms nua_session.c:4139 signal_call_state_change() nua(0x7f602400e290): call state changed: early -> completed, sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f602400eb60, [0x7f604a04ace8], [0x7f604a04acf0], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f602400eb60, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_channel.c:3772 (sofia/external/3613612209@webrtc.example.com) Callstate Change RINGING -> ACTIVE nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] switch_ivr_originate.c:3686 Originate Resulted in Success: [verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a] tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f602400c080 from (udp/172.21.0.10:5080) has 559 bytes, veclen = 1 recv 559 bytes from udp/[172.21.0.12]:5060 at 11:49:30.373852: ------------------------------------------------------------------------ ACK sip:3613612202@172.21.0.10:5080 SIP/2.0 Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bK1ecb.6e9fe01c3e93fa8fd334c24492f422d7.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-4 Max-Forwards: 43 To: "3613612202" ;tag=1DK7cet40aNjD From: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 1 ACK User-Agent: eyeBeam release 9330a stamp 37653 Content-Length: 0 Server: SIPp Server Contact: ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f602400c080 (559 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:3613612202@172.21.0.10:5080 SIP/2.0 (CSeq 1) nta.c:3019 agent_recv_request() nta: ACK (1) is going to INVITE (1) nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f602400eb60) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_ack 200 OK nua_session.c:4139 signal_call_state_change() nua(0x7f602400e290): call state changed: completed -> ready nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 200 OK nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_active 200 Call active 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_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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:30.368704 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [ready][200] 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 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.368704 [DEBUG] switch_core_media.c:9969 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a PAUSE Jitterbuffer 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.368704 [DEBUG] switch_ivr_bridge.c:1566 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.368704 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.368704 [DEBUG] switch_core_state_machine.c:653 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State EXCHANGE_MEDIA 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.368704 [DEBUG] mod_rtc.c:146 RTC EXCHANGE_MEDIA 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.408706 [INFO] switch_rtp.c:3162 Changing audio DTLS state from HANDSHAKE to SETUP 2017-02-24 11:49:30.408706 [ALERT] mod_verto.c:604 WRITE 172.21.0.1:45670 [{ "jsonrpc": "2.0", "id": 10, "method": "verto.display", "params": { "callID": "5749daf1-911f-4eff-81ba-d53899e6f055", "display_name": "3613612209", "display_number": "3613612209", "caller_id_name": "3613612209", "caller_id_number": "3613612209", "callee_id_name": "3613612202", "callee_id_number": "3613612202", "display_direction": "outbound" } }] 2017-02-24 11:49:30.408706 [ALERT] mod_verto.c:1373 READ 172.21.0.1:45670 [{ "jsonrpc": "2.0", "id": 10, "result": { "method": "verto.display" } }] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.428713 [INFO] switch_rtp.c:3071 audio Fingerprint Verified. 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.428713 [INFO] switch_rtp.c:3690 Activating Audio Secure RTP SEND 2017-02-24 11:49:30.428713 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.428713 [INFO] switch_rtp.c:3668 Activating Audio Secure RTP RECV 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.428713 [INFO] switch_rtp.c:3111 Changing audio DTLS state from SETUP to READY 2017-02-24 11:49:30.428713 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:30.448708 [DEBUG] switch_rtp.c:1878 rtcp_stats_init: audio ssrc[568988862] base_seq[6658] nta.c:1296 agent_timer() nta: timer set next to 4502 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f602400c080 from (udp/172.21.0.10:5080) has 1006 bytes, veclen = 1 recv 1006 bytes from udp/[172.21.0.12]:5060 at 11:49:32.375481: ------------------------------------------------------------------------ INVITE sip:3613612202@172.21.0.10:5080 SIP/2.0 Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKedcb.e53a29b4a9efba0ad34db660d2cff5d0.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-6 Max-Forwards: 43 To: "3613612202" ;tag=1DK7cet40aNjD From: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 2 INVITE Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,MESSAGE,SUBSCRIBE,INFO Content-Type: application/sdp User-Agent: eyeBeam release 9330a stamp 37653 Content-Length: 260 Server: SIPp Server P-Asserted-Identity: "3613612209" Contact: v=0 o=ipjib 1487263187420 1487263187421 IN IP4 10.112.48.79 s=CounterPath eyeBeam 1.5 c=IN IP4 0.0.0.0 t=0 0 m=audio 60578 RTP/AVP 0 101 a=fmtp:101 0-15 a=rtpmap:101 telephone-event/8000 a=sendonly a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f602400c080 (1006 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:3613612202@172.21.0.10:5080 SIP/2.0 (CSeq 2) nta.c:3248 agent_aliases() nta: canonizing sip:3613612202@172.21.0.10:5080 with contact nta.c:3060 agent_recv_request() nta: INVITE (2) going to existing leg nta.c:1348 set_timeout() nta: timer shortened to 200 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f602400eb60) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f602400eb60, (nil), 0x7f602400b45a, 260) called tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 398 bytes of 398 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 398 send 398 bytes to udp/[172.21.0.12]:5060 at 11:49:32.375907: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKedcb.e53a29b4a9efba0ad34db660d2cff5d0.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-6 From: "3613612209" ;tag=1 To: "3613612202" ;tag=1DK7cet40aNjD Call-ID: 1-1765@172.21.0.11 CSeq: 2 INVITE User-Agent: Voicis WebRTC Gateway Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (2) nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_invite 100 Trying nua_session.c:4145 signal_call_state_change() nua(0x7f602400e290): ready call updated: received received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f602400eb60, [0x7f604a04a8c8], [0x7f604a04a8d0], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 100 Trying 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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [received][100] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] sofia.c:7052 Remote SDP: 810f2514-ac39-4e49-b8fe-2e2adb046646 v=0 810f2514-ac39-4e49-b8fe-2e2adb046646 o=ipjib 1487263187420 1487263187421 IN IP4 10.112.48.79 810f2514-ac39-4e49-b8fe-2e2adb046646 s=CounterPath eyeBeam 1.5 810f2514-ac39-4e49-b8fe-2e2adb046646 c=IN IP4 0.0.0.0 810f2514-ac39-4e49-b8fe-2e2adb046646 t=0 0 810f2514-ac39-4e49-b8fe-2e2adb046646 m=audio 60578 RTP/AVP 0 101 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:101 telephone-event/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=fmtp:101 0-15 810f2514-ac39-4e49-b8fe-2e2adb046646 a=sendonly 810f2514-ac39-4e49-b8fe-2e2adb046646 a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC 810f2514-ac39-4e49-b8fe-2e2adb046646 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [WARNING] switch_core_media.c:3895 RFC2543 from March 1999 called; They want their 0.0.0.0 hold method back..... 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_channel.c:1844 (sofia/external/3613612209@webrtc.example.com) Callstate Change ACTIVE -> HELD 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:4316 Set telephone-event payload to 101@8000 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:4659 Set telephone-event payload to 101@8000 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:4718 sofia/external/3613612209@webrtc.example.com Set 2833 dtmf send payload to 101 recv payload to 101 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:6721 Audio params changed for sofia/external/3613612209@webrtc.example.com from 10.112.48.79:60578 to 0.0.0.0:60578 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/3613612209@webrtc.example.com] 172.21.0.10 port 18246 -> 0.0.0.0 port 60578 codec: 0 ms: 20 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] switch_core_media.c:6761 AUDIO RTP CHANGING DEST TO: [0.0.0.0:60578] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] sofia.c:7942 Processing updated SDP nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f602400e290): sent signal r_respond nua_stack.c:573 nua_stack_signal() nua(0x7f602400e290): recv signal r_respond 200 OK nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f602400eb60, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f602400eb60, (nil), 0x7f5fe400c100, -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::0x7f602400eb60) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f602400eb60, soa_generate_answer): called soa_static.c:1230 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): upgrade with remote description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f604a048ab0, 0x7f6024015840, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f602400eb60, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f602400eb60, [(nil)], [0x7f604a04ac38], [0x7f604a04ac34]) called tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 894 bytes of 894 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 894 send 894 bytes to udp/[172.21.0.12]:5060 at 11:49:32.391571: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKedcb.e53a29b4a9efba0ad34db660d2cff5d0.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-6 From: "3613612209" ;tag=1 To: "3613612202" ;tag=1DK7cet40aNjD Call-ID: 1-1765@172.21.0.11 CSeq: 2 INVITE Contact: User-Agent: Voicis WebRTC Gateway Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Type: application/sdp Content-Disposition: session Content-Length: 230 v=0 o=FreeSWITCH 1487918724 1487918726 IN IP4 172.21.0.10 s=FreeSWITCH c=IN IP4 172.21.0.10 t=0 0 m=audio 18246 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=recvonly a=ptime:20 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (2) nua_session.c:4145 signal_call_state_change() nua(0x7f602400e290): ready call updated: completed sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f602400eb60, [0x7f604a04ace8], [0x7f604a04acf0], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f602400eb60, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): 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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.388712 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [completed][200] nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f6024015c40 from (udp/172.21.0.10:5080) has 560 bytes, veclen = 1 recv 560 bytes from udp/[172.21.0.12]:5060 at 11:49:32.392578: ------------------------------------------------------------------------ ACK sip:3613612202@172.21.0.10:5080 SIP/2.0 Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKedcb.b658716bcccbec13308c303df53936a9.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-10 Max-Forwards: 43 To: "3613612202" ;tag=1DK7cet40aNjD From: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 2 ACK User-Agent: eyeBeam release 9330a stamp 37653 Content-Length: 0 Server: SIPp Server Contact: ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f6024015c40 (560 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:3613612202@172.21.0.10:5080 SIP/2.0 (CSeq 2) nta.c:3019 agent_recv_request() nta: ACK (2) is going to INVITE (2) nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f602400eb60) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_ack 200 OK nua_session.c:4145 signal_call_state_change() nua(0x7f602400e290): ready call updated: ready nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 200 OK nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_active 200 Call active 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_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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:32.428710 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [ready][200] 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 nta.c:1296 agent_timer() nta: timer set next to 2798 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f6024015c40 from (udp/172.21.0.10:5080) has 1180 bytes, veclen = 1 recv 1180 bytes from udp/[172.21.0.12]:5060 at 11:49:34.393591: ------------------------------------------------------------------------ INVITE sip:3613612202@172.21.0.10:5080 SIP/2.0 Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKfdcb.e6ec50a7476e7ee19c795a4bbcbefb85.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-12 Max-Forwards: 43 To: "3613612202" ;tag=1DK7cet40aNjD From: "3613612201" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 3 INVITE Allow: INVITE,ACK,CANCEL,OPTIONS,BYE,REFER,NOTIFY,MESSAGE,SUBSCRIBE,INFO Content-Type: application/sdp User-Agent: eyeBeam release 9330a stamp 37653 Content-Length: 434 Server: SIPp Server P-Asserted-Identity: "3613612201" Contact: v=0 o=ipjib 1487263187420 1487263187420 IN IP4 10.112.48.79 s=CounterPath eyeBeam 1.5 c=IN IP4 10.112.48.79 t=0 0 m=audio 60578 RTP/AVP 119 6 0 98 8 3 5 101 a=alt:1 2 : FwGzks7j aVPEMhBL 10.112.48.79 60578 a=alt:2 1 : NxVGnjOA 78sxYW0G 10.112.200.224 60578 a=fmtp:101 0-15 a=rtpmap:119 BV32-FEC/16000 a=rtpmap:98 iLBC/8000 a=rtpmap:101 telephone-event/8000 a=sendrecv a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f6024015c40 (1180 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:2880 agent_recv_request() nta: received INVITE sip:3613612202@172.21.0.10:5080 SIP/2.0 (CSeq 3) nta.c:3248 agent_aliases() nta: canonizing sip:3613612202@172.21.0.10:5080 with contact nta.c:3060 agent_recv_request() nta: INVITE (3) going to existing leg nta.c:1348 set_timeout() nta: timer shortened to 200 ms nua_server.c:102 nua_stack_process_request() nua: nua_stack_process_request: entering soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f602400eb60) called soa.c:1171 soa_set_remote_sdp() soa_set_remote_sdp(static::0x7f602400eb60, (nil), 0x7f6024012dba, 434) called tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 399 bytes of 399 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 399 send 399 bytes to udp/[172.21.0.12]:5060 at 11:49:34.393951: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKfdcb.e6ec50a7476e7ee19c795a4bbcbefb85.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-12 From: "3613612201" ;tag=1 To: "3613612202" ;tag=1DK7cet40aNjD Call-ID: 1-1765@172.21.0.11 CSeq: 3 INVITE User-Agent: Voicis WebRTC Gateway Content-Length: 0 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 100 Trying for INVITE (3) nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_invite 100 Trying nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_session.c:4145 signal_call_state_change() nua(0x7f602400e290): ready call updated: received received offer soa.c:1098 soa_get_remote_sdp() soa_get_remote_sdp(static::0x7f602400eb60, [0x7f604a04a8c8], [0x7f604a04a8d0], [(nil)]) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 100 Trying 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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.388723 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [received][100] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.388723 [DEBUG] sofia.c:7052 Remote SDP: 810f2514-ac39-4e49-b8fe-2e2adb046646 v=0 810f2514-ac39-4e49-b8fe-2e2adb046646 o=ipjib 1487263187420 1487263187420 IN IP4 10.112.48.79 810f2514-ac39-4e49-b8fe-2e2adb046646 s=CounterPath eyeBeam 1.5 810f2514-ac39-4e49-b8fe-2e2adb046646 c=IN IP4 10.112.48.79 810f2514-ac39-4e49-b8fe-2e2adb046646 t=0 0 810f2514-ac39-4e49-b8fe-2e2adb046646 m=audio 60578 RTP/AVP 119 6 0 98 8 3 5 101 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:119 BV32-FEC/16000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:98 iLBC/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=rtpmap:101 telephone-event/8000 810f2514-ac39-4e49-b8fe-2e2adb046646 a=fmtp:101 0-15 810f2514-ac39-4e49-b8fe-2e2adb046646 a=alt:1 2 : FwGzks7j aVPEMhBL 10.112.48.79 60578 810f2514-ac39-4e49-b8fe-2e2adb046646 a=alt:2 1 : NxVGnjOA 78sxYW0G 10.112.200.224 60578 810f2514-ac39-4e49-b8fe-2e2adb046646 a=x-rtp-session-id:397A5FF0FB494996B741C71582F2FEAC 810f2514-ac39-4e49-b8fe-2e2adb046646 nta.c:1296 agent_timer() nta: timer set next to 780 ms 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_channel.c:2029 (sofia/external/3613612209@webrtc.example.com) Callstate Change HELD -> UNHELD 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [BV32-FEC:119:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:6:16000:20:0:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:6:16000:20:0:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [iLBC:98:8000:30:13330:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4455 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [GSM:3:8000:20:13200:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:5:8000:20:0:1]/[PCMA:8:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4400 Audio Codec Compare [DVI4:5:8000:20:0:1]/[PCMU:0:8000:20:64000:1] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4316 Set telephone-event payload to 101@8000 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4659 Set telephone-event payload to 101@8000 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:4718 sofia/external/3613612209@webrtc.example.com Set 2833 dtmf send payload to 101 recv payload to 101 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:6721 Audio params changed for sofia/external/3613612209@webrtc.example.com from 0.0.0.0:60578 to 10.112.48.79:60578 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:6732 AUDIO RTP [sofia/external/3613612209@webrtc.example.com] 172.21.0.10 port 18246 -> 10.112.48.79 port 60578 codec: 0 ms: 20 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_media.c:6761 AUDIO RTP CHANGING DEST TO: [10.112.48.79:60578] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] sofia.c:7942 Processing updated SDP nua.c:879 nua_respond() nua: nua_respond: entering nua_stack.c:529 nua_signal() nua(0x7f602400e290): sent signal r_respond nua.c:366 nua_handle_magic() nua: nua_handle_magic: entering nua_stack.c:573 nua_stack_signal() nua(0x7f602400e290): 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::0x7f602400eb60, ...) called soa.c:1052 soa_set_user_sdp() soa_set_user_sdp(static::0x7f602400eb60, (nil), 0x7f5fe4011560, -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::0x7f602400eb60) called soa_static.c:1148 offer_answer_step() soa_static_offer_answer_action(0x7f602400eb60, soa_generate_answer): called soa_static.c:1230 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): upgrade with remote description soa_static.c:1029 soa_sdp_mode_set() soa_sdp_mode_set(0x7f604a048ab0, 0x7f60240192a0, ""): called soa_static.c:1446 offer_answer_step() soa_static(0x7f602400eb60, soa_generate_answer): storing local description soa.c:1730 soa_activate() soa_activate(static::0x7f602400eb60, (nil)) called soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f602400eb60, [(nil)], [0x7f604a04ac38], [0x7f604a04ac34]) called tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = UDP/172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name UDP/172.21.0.12:5060 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.648726 [DEBUG] switch_core_io.c:941 (sofia/external/3613612209@webrtc.example.com) Callstate Change UNHELD -> ACTIVE tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 883 bytes of 883 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 883 send 883 bytes to udp/[172.21.0.12]:5060 at 11:49:34.653032: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKfdcb.e6ec50a7476e7ee19c795a4bbcbefb85.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-12 From: "3613612201" ;tag=1 To: "3613612202" ;tag=1DK7cet40aNjD Call-ID: 1-1765@172.21.0.11 CSeq: 3 INVITE Contact: User-Agent: Voicis WebRTC Gateway Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Type: application/sdp Content-Disposition: session Content-Length: 218 v=0 o=FreeSWITCH 1487918724 1487918727 IN IP4 172.21.0.10 s=FreeSWITCH c=IN IP4 172.21.0.10 t=0 0 m=audio 18246 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 ------------------------------------------------------------------------ nta.c:6791 incoming_reply() nta: sent 200 OK for INVITE (3) nta.c:1348 set_timeout() nta: timer shortened to 500 ms nua_session.c:4145 signal_call_state_change() nua(0x7f602400e290): ready call updated: completed sent answer soa.c:1270 soa_get_local_sdp() soa_get_local_sdp(static::0x7f602400eb60, [0x7f604a04ace8], [0x7f604a04acf0], [(nil)]) called soa.c:616 soa_get_params() soa_get_params(static::0x7f602400eb60, ...) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 200 OK tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f6024015840 from (udp/172.21.0.10:5080) has 560 bytes, veclen = 1 nua_stack.c:359 nua_application_event() nua: nua_application_event: entering recv 560 bytes from udp/[172.21.0.12]:5060 at 11:49:34.653968: ------------------------------------------------------------------------ ACK sip:3613612202@172.21.0.10:5080 SIP/2.0 Via: SIP/2.0/UDP 172.21.0.12;branch=z9hG4bKfdcb.dd2f63e3d5c786fb7fbf66d16619b89f.0 Via: SIP/2.0/UDP 172.21.0.11:5061;branch=z9hG4bK-1765-1-16 Max-Forwards: 43 To: "3613612202" ;tag=1DK7cet40aNjD From: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 3 ACK User-Agent: eyeBeam release 9330a stamp 37653 Content-Length: 0 Server: SIPp Server Contact: ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f6024015840 (560 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:2880 agent_recv_request() nta: received ACK sip:3613612202@172.21.0.10:5080 SIP/2.0 (CSeq 3) nta.c:3019 agent_recv_request() nta: ACK (3) is going to INVITE (3) nua_session.c:2569 process_ack_or_cancel() nua: process_ack_or_cancel: entering soa.c:1214 soa_clear_remote_sdp() soa_clear_remote_sdp(static::0x7f602400eb60) called nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_ack 200 OK nua_session.c:4145 signal_call_state_change() nua(0x7f602400e290): ready call updated: ready nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 200 OK nua_stack.c:359 nua_application_event() nua: nua_application_event: entering nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_active 200 Call active 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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.668709 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [completed][200] 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 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:34.668709 [DEBUG] sofia.c:7042 Channel sofia/external/3613612209@webrtc.example.com entering state [ready][200] 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 nta.c:1296 agent_timer() nta: timer set next to 219 ms nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 200 response nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f604a04ac60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/3 term, 1/3 free nta.c:1296 agent_timer() nta: timer set next to 2019 ms nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 200 response nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f604a04ac60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/2 term, 1/2 free nta.c:1296 agent_timer() nta: timer set next to 2259 ms nta.c:7134 _nta_incoming_timer() nta: timer I fired, terminate 200 response nta.c:5825 incoming_reclaim_queued() incoming_reclaim_all((nil), (nil), 0x7f604a04ac60) nta.c:7188 _nta_incoming_timer() nta_incoming_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free nta.c:1289 agent_timer() nta: timer not set 2017-02-24 11:49:41.568711 [ALERT] mod_verto.c:1373 READ 172.21.0.1:45670 [{ "jsonrpc": "2.0", "method": "verto.bye", "params": { "dialogParams": { "screenShare": false, "useMic": "any", "useSpeak": "any", "tag": "webcam", "localTag": null, "login": "3613612202@webrtc.example.com", "videoParams": { "minWidth": "1280", "minHeight": "720", "minFrameRate": 30 }, "callID": "5749daf1-911f-4eff-81ba-d53899e6f055", "caller_id_name": "3613612209", "caller_id_number": "3613612209", "callee_id_name": "3613612202", "callee_id_number": "3613612202", "display_direction": "outbound", "remote_caller_id_name": "3613612209", "remote_caller_id_number": "3613612209" }, "sessid": "d5c3b5fa-9ccf-0b60-a6b7-027231713d4a" }, "id": 26 }] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [NOTICE] mod_verto.c:2764 Hangup verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2017-02-24 11:49:41.568711 [ALERT] mod_verto.c:604 WRITE 172.21.0.1:45670 [{ "jsonrpc": "2.0", "id": 26, "result": { "callID": "5749daf1-911f-4eff-81ba-d53899e6f055", "message": "CALL ENDED", "causeCode": 16, "cause": "NORMAL_CLEARING", "sessid": "d5c3b5fa-9ccf-0b60-a6b7-027231713d4a" } }] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_ivr_bridge.c:679 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a ending bridge by request from read function 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_ivr_bridge.c:752 BRIDGE THREAD DONE [verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:653 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State EXCHANGE_MEDIA going to sleep 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_HANGUP (Cur 2 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Callstate Change ACTIVE -> HANGUP 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State HANGUP 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:60 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a Standard HANGUP, cause: NORMAL_CLEARING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State HANGUP going to sleep 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State Change CS_HANGUP -> CS_REPORTING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_REPORTING (Cur 2 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State REPORTING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:174 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a Standard REPORTING, cause: NORMAL_CLEARING 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State REPORTING going to sleep 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State Change CS_REPORTING -> CS_DESTROY 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.568711 [DEBUG] switch_core_session.c:1664 Session 10 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Locked, Waiting on external entities 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_ivr_bridge.c:752 BRIDGE THREAD DONE [sofia/external/3613612209@webrtc.example.com] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [NOTICE] switch_core_session.c:1682 Session 10 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Ended 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [NOTICE] switch_core_session.c:1686 Close Channel verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a [CS_DESTROY] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) Running State Change CS_DESTROY (Cur 1 Tot 10) 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State DESTROY 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [DEBUG] mod_rtc.c:132 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a RTC DESTROY 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [NOTICE] switch_core_state_machine.c:385 sofia/external/3613612209@webrtc.example.com has executed the last dialplan instruction, hanging up. 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [NOTICE] switch_core_state_machine.c:387 Hangup sofia/external/3613612209@webrtc.example.com [CS_EXECUTE] [NORMAL_CLEARING] 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:181 verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a Standard DESTROY 5749daf1-911f-4eff-81ba-d53899e6f055 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/d5c3b5fa-9ccf-0b60-a6b7-027231713d4a) State DESTROY going to sleep 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:650 (sofia/external/3613612209@webrtc.example.com) State EXECUTE going to sleep 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_HANGUP (Cur 1 Tot 10) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:850 (sofia/external/3613612209@webrtc.example.com) Callstate Change ACTIVE -> HANGUP 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3613612209@webrtc.example.com) State HANGUP 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] mod_sofia.c:438 Channel sofia/external/3613612209@webrtc.example.com hanging up, cause: NORMAL_CLEARING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/external/3613612209@webrtc.example.com nua.c:645 nua_bye() nua: nua_bye: entering nua_stack.c:529 nua_signal() nua(0x7f602400e290): sent signal r_bye 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:60 sofia/external/3613612209@webrtc.example.com Standard HANGUP, cause: NORMAL_CLEARING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:852 (sofia/external/3613612209@webrtc.example.com) State HANGUP going to sleep 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:619 (sofia/external/3613612209@webrtc.example.com) State Change CS_HANGUP -> CS_REPORTING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:584 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_REPORTING (Cur 1 Tot 10) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3613612209@webrtc.example.com) State REPORTING nua_stack.c:569 nua_stack_signal() nua(0x7f602400e290): recv signal r_bye nua_params.c:480 nua_stack_set_params() nua: nua_stack_set_params: entering soa.c:403 soa_set_params() soa_set_params(static::0x7f602400eb60, ...) called soa.c:1784 soa_terminate() soa_terminate(static::0x7f602400eb60) called soa.c:1302 soa_init_offer_answer() soa_init_offer_answer(static::0x7f602400eb60) called nta.c:2665 nta_tpn_by_url() nta: selecting scheme sip tport.c:3257 tport_tsend() tport_tsend(0x7f6024004530) tpn = */172.21.0.12:5060 tport.c:4046 tport_resolve() tport_resolve addrinfo = 172.21.0.12:5060 tport.c:4680 tport_by_addrinfo() tport_by_addrinfo(0x7f6024004530): not found by name */172.21.0.12:5060 tport.c:3594 tport_vsend() tport_vsend(0x7f6024004530): 639 bytes of 639 to udp/172.21.0.12:5060 tport.c:3492 tport_send_msg() tport_vsend returned 639 send 639 bytes to udp/[172.21.0.12]:5060 at 11:49:41.592938: ------------------------------------------------------------------------ BYE sip:siplb@172.21.0.11:5061;abcct=7369703a31302e3131322e32362e38353a35303630 SIP/2.0 Via: SIP/2.0/UDP 172.21.0.10:5080;rport;branch=z9hG4bKyBr8Fre4p84Bg Route: Max-Forwards: 70 From: "3613612202" ;tag=1DK7cet40aNjD To: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 103632426 BYE User-Agent: Voicis WebRTC Gateway 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 (103632426) to */172.21.0.12:5060 tport.c:4160 tport_pend() tport_pend(0x7f6024004530): pending 0x7f6024011f80 for udp/172.21.0.10:5080 (already 0) nta.c:1350 set_timeout() nta: timer set to 32000 ms nta.c:1348 set_timeout() nta: timer shortened to 1000 ms tport.c:2749 tport_wakeup_pri() tport_wakeup_pri(0x7f6024004530): events IN tport.c:2864 tport_recv_event() tport_recv_event(0x7f6024004530) tport.c:3205 tport_recv_iovec() tport_recv_iovec(0x7f6024004530) msg 0x7f602400c2e0 from (udp/172.21.0.10:5080) has 316 bytes, veclen = 1 recv 316 bytes from udp/[172.21.0.12]:5060 at 11:49:41.593928: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 172.21.0.10:5080;received=172.21.0.10;rport=5080;branch=z9hG4bKyBr8Fre4p84Bg From: "3613612202" ;tag=1DK7cet40aNjD To: "3613612209" ;tag=1 Call-ID: 1-1765@172.21.0.11 CSeq: 103632426 BYE Content-Length: 0 ------------------------------------------------------------------------ tport.c:3023 tport_deliver() tport_deliver(0x7f6024004530): msg 0x7f602400c2e0 (316 bytes) from udp/172.21.0.12:5080/sip next=(nil) nta.c:3299 agent_recv_response() nta: received 200 OK for BYE (103632426) nta.c:3366 agent_recv_response() nta: 200 OK is going to a transaction nta.c:9564 outgoing_estimate_delay() nta_outgoing: RTT is 1.137 ms tport.c:4222 tport_release() tport_release(0x7f6024004530): 0x7f6024011f80 by 0x7f602400be70 with 0x7f602400c2e0 nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event r_bye 200 OK nua_session.c:4139 signal_call_state_change() nua(0x7f602400e290): call state changed: terminating -> terminated nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_state 200 to BYE nua_stack.c:271 nua_stack_event() nua(0x7f602400e290): event i_terminated 200 to BYE nua_dialog.c:397 nua_dialog_usage_remove_at() nua(0x7f602400e290): removing session usage soa.c:356 soa_destroy() soa_destroy(static::0x7f602400eb60) called nta.c:4470 nta_leg_destroy() nta_leg_destroy(0x7f602400f470) nua_session.c:351 nua_session_usage_destroy() nua: terminated session 0x7f602400e290 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_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(0x7f602400e290): sent signal r_destroy nua_stack.c:569 nua_stack_signal() nua(0x7f602400e290): recv signal r_destroy nta.c:4470 nta_leg_destroy() nta_leg_destroy((nil)) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:174 sofia/external/3613612209@webrtc.example.com Standard REPORTING, cause: NORMAL_CLEARING 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:938 (sofia/external/3613612209@webrtc.example.com) State REPORTING going to sleep 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:610 (sofia/external/3613612209@webrtc.example.com) State Change CS_REPORTING -> CS_DESTROY 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_session.c:1664 Session 9 (sofia/external/3613612209@webrtc.example.com) Locked, Waiting on external entities 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [NOTICE] switch_core_session.c:1682 Session 9 (sofia/external/3613612209@webrtc.example.com) Ended 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [NOTICE] switch_core_session.c:1686 Close Channel sofia/external/3613612209@webrtc.example.com [CS_DESTROY] 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:741 (sofia/external/3613612209@webrtc.example.com) Running State Change CS_DESTROY (Cur 0 Tot 10) 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3613612209@webrtc.example.com) State DESTROY 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] mod_sofia.c:343 sofia/external/3613612209@webrtc.example.com SOFIA DESTROY 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:181 sofia/external/3613612209@webrtc.example.com Standard DESTROY 810f2514-ac39-4e49-b8fe-2e2adb046646 2017-02-24 11:49:41.588708 [DEBUG] switch_core_state_machine.c:751 (sofia/external/3613612209@webrtc.example.com) State DESTROY going to sleep nta.c:1296 agent_timer() nta: timer set next to 4000 ms nta.c:9101 outgoing_timer_dk() nta: timer K fired, terminate BYE (103632426) nta.c:8799 outgoing_reclaim_queued() outgoing_reclaim_all((nil), (nil), 0x7f604a04ad40) nta.c:8929 _nta_outgoing_timer() nta_outgoing_timer: 0/0 resent, 0/0 tout, 1/1 term, 1/1 free nta.c:1289 agent_timer() nta: timer not set