------------------------------------------------------------------------ recv 2217 bytes from ws/[134.213.206.157]:47652 at 18:12:01.780365: ------------------------------------------------------------------------ INVITE sip:9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com SIP/2.0 Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK9539584 Max-Forwards: 70 To: From: ;tag=g294kid7sg Call-ID: dot4lkudmc6ubterpeth CSeq: 3067 INVITE Contact: Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Content-Type: application/sdp Supported: outbound User-Agent: SIP.js/0.7.5 Content-Length: 1679 v=0 o=- 4552988607047744733 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS ARDAMS m=audio 42527 UDP/TLS/RTP/SAVPF 111 103 9 102 0 8 106 105 13 127 126 c=IN IP4 46.159.161.140 a=rtcp:38050 IN IP4 46.159.161.140 a=candidate:3350409123 1 udp 2122260223 192.168.0.101 42527 typ host generation 0 a=candidate:3350409123 2 udp 2122260222 192.168.0.101 38050 typ host generation 0 a=candidate:1190865175 2 udp 1686052606 46.159.161.140 38050 typ srflx raddr 192.168.0.101 rport 38050 generation 0 a=candidate:1190865175 1 udp 1686052607 46.159.161.140 42527 typ srflx raddr 192.168.0.101 rport 42527 generation 0 a=candidate:2301678419 1 tcp 1518280447 192.168.0.101 37171 typ host tcptype passive generation 0 a=candidate:2301678419 2 tcp 1518280446 192.168.0.101 34973 typ host tcptype passive generation 0 a=ice-ufrag:zlFE8VtX26klZtLa a=ice-pwd:0LGWvsW5Zazi35Xk8BlzzkOY a=fingerprint:sha-256 E5:C8:6E:BD:1C:03:D6:B4:4F:E2:8F:B1:84:DE:A1:6A:37:4C:D7:C6:F2:A5:6D:47:45:DD:CA:7A:30:6E:93:BE a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=sendrecv a=rtcp-mux a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10; useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:9 G722/8000 a=rtpmap:102 ILBC/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:127 red/8000 a=rtpmap:126 telephone-event/8000 a=maxptime:60 a=ssrc:2537041755 cname:7CbYDw1WUcfBYXkJ a=ssrc:2537041755 msid:ARDAMS ARDAMSa0 a=ssrc:2537041755 mslabel:ARDAMS a=ssrc:2537041755 label:ARDAMSa0 ------------------------------------------------------------------------ send 355 bytes to ws/[134.213.206.157]:47652 at 18:12:01.780822: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK9539584;received=134.213.206.157;rport=47652 From: ;tag=g294kid7sg To: Call-ID: dot4lkudmc6ubterpeth CSeq: 3067 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Content-Length: 0 ------------------------------------------------------------------------ a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.772593 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/280@3waytalk.com [a39771e4-fbf1-4964-b499-e9843b7bfe59] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.772593 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/280@3waytalk.com) Running State Change CS_NEW a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.772593 [DEBUG] sofia.c:9520 sofia/internal/280@3waytalk.com receiving invite from 134.213.206.157:47652 version: 1.7.0 -915-35ee4ee 64bit 2016-09-01 18:12:01.772593 [DEBUG] sofia.c:9687 IP 134.213.206.157 Rejected by acl "domains". Falling back to Digest auth. 2016-09-01 18:12:01.772593 [WARNING] sofia_reg.c:1787 SIP auth challenge (INVITE) on sofia profile 'internal' for [9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com] from ip 134.213.206.157 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.772593 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/280@3waytalk.com) State NEW send 712 bytes to ws/[134.213.206.157]:47652 at 18:12:01.781774: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK9539584;received=134.213.206.157;rport=47652 From: ;tag=g294kid7sg To: ;tag=8FFmSNUcy7NUN Call-ID: dot4lkudmc6ubterpeth CSeq: 3067 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="3waytalk.com", nonce="f77993ea-b1e3-4aa3-ad6e-5a2f30d0e121", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2016-09-01 18:12:01.772593 [DEBUG] sofia.c:2248 detaching session a39771e4-fbf1-4964-b499-e9843b7bfe59 recv 325 bytes from ws/[134.213.206.157]:47652 at 18:12:01.786830: ------------------------------------------------------------------------ ACK sip:9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com SIP/2.0 Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK9539584 To: ;tag=8FFmSNUcy7NUN From: ;tag=g294kid7sg Call-ID: dot4lkudmc6ubterpeth Content-Length: 0 CSeq: 3067 ACK ------------------------------------------------------------------------ recv 2499 bytes from ws/[134.213.206.157]:47652 at 18:12:01.788439: ------------------------------------------------------------------------ INVITE sip:9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com SIP/2.0 Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK7963946 Max-Forwards: 70 To: From: ;tag=g294kid7sg Call-ID: dot4lkudmc6ubterpeth CSeq: 3068 INVITE Proxy-Authorization: Digest algorithm=MD5, username="280", realm="3waytalk.com", nonce="f77993ea-b1e3-4aa3-ad6e-5a2f30d0e121", uri="sip:9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com", response="4a7b1162f5959bbae35884e7c56c16fd", qop=auth, cnonce="f7e6rci30534", nc=00000001 Contact: Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Content-Type: application/sdp Supported: outbound User-Agent: SIP.js/0.7.5 Content-Length: 1679 v=0 o=- 4552988607047744733 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS ARDAMS m=audio 42527 UDP/TLS/RTP/SAVPF 111 103 9 102 0 8 106 105 13 127 126 c=IN IP4 46.159.161.140 a=rtcp:38050 IN IP4 46.159.161.140 a=candidate:3350409123 1 udp 2122260223 192.168.0.101 42527 typ host generation 0 a=candidate:3350409123 2 udp 2122260222 192.168.0.101 38050 typ host generation 0 a=candidate:1190865175 2 udp 1686052606 46.159.161.140 38050 typ srflx raddr 192.168.0.101 rport 38050 generation 0 a=candidate:1190865175 1 udp 1686052607 46.159.161.140 42527 typ srflx raddr 192.168.0.101 rport 42527 generation 0 a=candidate:2301678419 1 tcp 1518280447 192.168.0.101 37171 typ host tcptype passive generation 0 a=candidate:2301678419 2 tcp 1518280446 192.168.0.101 34973 typ host tcptype passive generation 0 a=ice-ufrag:zlFE8VtX26klZtLa a=ice-pwd:0LGWvsW5Zazi35Xk8BlzzkOY a=fingerprint:sha-256 E5:C8:6E:BD:1C:03:D6:B4:4F:E2:8F:B1:84:DE:A1:6A:37:4C:D7:C6:F2:A5:6D:47:45:DD:CA:7A:30:6E:93:BE a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=sendrecv a=rtcp-mux a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10; useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:9 G722/8000 a=rtpmap:102 ILBC/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:127 red/8000 a=rtpmap:126 telephone-event/8000 a=maxptime:60 a=ssrc:2537041755 cname:7CbYDw1WUcfBYXkJ a=ssrc:2537041755 msid:ARDAMS ARDAMSa0 a=ssrc:2537041755 mslabel:ARDAMS a=ssrc:2537041755 label:ARDAMSa0 ------------------------------------------------------------------------ send 355 bytes to ws/[134.213.206.157]:47652 at 18:12:01.789007: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK7963946;received=134.213.206.157;rport=47652 From: ;tag=g294kid7sg To: Call-ID: dot4lkudmc6ubterpeth CSeq: 3068 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Content-Length: 0 ------------------------------------------------------------------------ 2016-09-01 18:12:01.772593 [DEBUG] sofia.c:2356 Re-attaching to session a39771e4-fbf1-4964-b499-e9843b7bfe59 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.792592 [DEBUG] sofia.c:9520 sofia/internal/280@3waytalk.com receiving invite from 134.213.206.157:47652 version: 1.7.0 -915-35ee4ee 64bit 2016-09-01 18:12:01.792592 [DEBUG] sofia.c:9687 IP 134.213.206.157 Rejected by acl "domains". Falling back to Digest auth. 2016-09-01 18:12:01.792592 [NOTICE] switch_cpp.cpp:1360 directory request 2016-09-01 18:12:01.852591 [NOTICE] switch_cpp.cpp:1360 Authenticated user 2747 send 568 bytes to wss/[186.7.200.185]:62075 at 18:12:01.856891: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/WSS inkljrtqk4e4.invalid;branch=z9hG4bK6858992;received=186.7.200.185;rport=62075 From: ;tag=631gm8n46g To: ;tag=76NUQta90yZ8S Call-ID: ogp0fs00ul7q5ce8jdni5n CSeq: 514 REGISTER Contact: ;expires=60 Date: Thu, 01 Sep 2016 18:12:01 GMT User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 2016-09-01 18:12:01.952593 [NOTICE] switch_cpp.cpp:1360 Authenticated user 280 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] sofia.c:10823 Setting NAT mode based on via received a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] sofia.c:6937 Channel sofia/internal/280@3waytalk.com entering state [received][100] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] sofia.c:6947 Remote SDP: a39771e4-fbf1-4964-b499-e9843b7bfe59 v=0 a39771e4-fbf1-4964-b499-e9843b7bfe59 o=- 4552988607047744733 2 IN IP4 127.0.0.1 a39771e4-fbf1-4964-b499-e9843b7bfe59 s=- a39771e4-fbf1-4964-b499-e9843b7bfe59 t=0 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=group:BUNDLE audio a39771e4-fbf1-4964-b499-e9843b7bfe59 a=msid-semantic: WMS ARDAMS a39771e4-fbf1-4964-b499-e9843b7bfe59 m=audio 42527 UDP/TLS/RTP/SAVPF 111 103 9 102 0 8 106 105 13 127 126 a39771e4-fbf1-4964-b499-e9843b7bfe59 c=IN IP4 46.159.161.140 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:111 opus/48000/2 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=fmtp:111 minptime=10; useinbandfec=1 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:103 ISAC/16000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:9 G722/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:102 ILBC/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:0 PCMU/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:8 PCMA/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:106 CN/32000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:105 CN/16000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:13 CN/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:127 red/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:126 telephone-event/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtcp:38050 IN IP4 46.159.161.140 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:3350409123 1 udp 2122260223 192.168.0.101 42527 typ host generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:3350409123 2 udp 2122260222 192.168.0.101 38050 typ host generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:1190865175 2 udp 1686052606 46.159.161.140 38050 typ srflx raddr 192.168.0.101 rport 38050 generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:1190865175 1 udp 1686052607 46.159.161.140 42527 typ srflx raddr 192.168.0.101 rport 42527 generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:2301678419 1 tcp 1518280447 192.168.0.101 37171 typ host tcptype passive generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:2301678419 2 tcp 1518280446 192.168.0.101 34973 typ host tcptype passive generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ice-ufrag:zlFE8VtX26klZtLa a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ice-pwd:0LGWvsW5Zazi35Xk8BlzzkOY a39771e4-fbf1-4964-b499-e9843b7bfe59 a=fingerprint:sha-256 E5:C8:6E:BD:1C:03:D6:B4:4F:E2:8F:B1:84:DE:A1:6A:37:4C:D7:C6:F2:A5:6D:47:45:DD:CA:7A:30:6E:93:BE a39771e4-fbf1-4964-b499-e9843b7bfe59 a=setup:actpass a39771e4-fbf1-4964-b499-e9843b7bfe59 a=mid:audio a39771e4-fbf1-4964-b499-e9843b7bfe59 a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a39771e4-fbf1-4964-b499-e9843b7bfe59 a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtcp-mux a39771e4-fbf1-4964-b499-e9843b7bfe59 a=maxptime:60 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:2537041755 cname:7CbYDw1WUcfBYXkJ a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:2537041755 msid:ARDAMS ARDAMSa0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:2537041755 mslabel:ARDAMS a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:2537041755 label:ARDAMSa0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [opus:111:48000:60:0:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4366 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [G722:9:8000:60:64000:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [ILBC:102:8000:30:13330:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [CN:106:32000:60:0:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [red:127:8000:60:0:1]/[opus:116:48000:20:0:1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4227 Set telephone-event payload to 126@8000 2016-09-01 18:12:01.952593 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [72000bps] 2016-09-01 18:12:01.952593 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled 2016-09-01 18:12:01.952593 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [72000bps] 2016-09-01 18:12:01.952593 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3018 Set Codec sofia/internal/280@3waytalk.com opus/48000 20 ms 960 samples 0 bits 1 channels a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_codec.c:111 sofia/internal/280@3waytalk.com Original read codec set to opus:116 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [WARNING] switch_core_media.c:3392 NO candidate ACL defined, Defaulting to wan.auto a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.0.101:42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 2 proto: udp type: host addr: 192.168.0.101:38050 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 2 proto: udp type: srflx addr: 46.159.161.140:38050 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 1 proto: udp type: srflx addr: 46.159.161.140:42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3464 Searching for rtp candidate. a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3469 Choose rtp candidate, index 1, 46.159.161.140:42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3247 sofia/internal/280@3waytalk.com choosing family v4 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3480 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute 46.159.161.140:42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3525 setting remote audio ice addr to index 1 46.159.161.140:42527 based on candidate a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:3546 Setting remote rtcp audio addr to 46.159.161.140:42527 based on candidate a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_media.c:4639 sofia/internal/280@3waytalk.com Set 2833 dtmf send payload to 126 recv payload to 126 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] sofia.c:7336 (sofia/internal/280@3waytalk.com) State Change CS_NEW -> CS_INIT a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/280@3waytalk.com) Running State Change CS_INIT a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/280@3waytalk.com) State INIT a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] mod_sofia.c:90 sofia/internal/280@3waytalk.com SOFIA INIT a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:40 sofia/internal/280@3waytalk.com Standard INIT a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/280@3waytalk.com) State Change CS_INIT -> CS_ROUTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/280@3waytalk.com) State INIT going to sleep a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/280@3waytalk.com) Running State Change CS_ROUTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_channel.c:2249 (sofia/internal/280@3waytalk.com) Callstate Change DOWN -> RINGING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/280@3waytalk.com) State ROUTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] mod_sofia.c:143 sofia/internal/280@3waytalk.com SOFIA ROUTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:236 sofia/internal/280@3waytalk.com Standard ROUTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [INFO] mod_dialplan_xml.c:637 Processing 280 <280>->9d1e1675fa8a804e12512d65e0388421_rukoru in context default a39771e4-fbf1-4964-b499-e9843b7bfe59 Dialplan: sofia/internal/280@3waytalk.com parsing [default->test] continue=false a39771e4-fbf1-4964-b499-e9843b7bfe59 Dialplan: sofia/internal/280@3waytalk.com Regex (FAIL) [test] destination_number(9d1e1675fa8a804e12512d65e0388421_rukoru) =~ /^test_(.*)$/ break=on-false a39771e4-fbf1-4964-b499-e9843b7bfe59 Dialplan: sofia/internal/280@3waytalk.com parsing [default->translator] continue=false a39771e4-fbf1-4964-b499-e9843b7bfe59 Dialplan: sofia/internal/280@3waytalk.com Regex (PASS) [translator] destination_number(9d1e1675fa8a804e12512d65e0388421_rukoru) =~ /^(.*)$/ break=on-false a39771e4-fbf1-4964-b499-e9843b7bfe59 Dialplan: sofia/internal/280@3waytalk.com Action socket(127.0.0.1:8085 async full) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/280@3waytalk.com) State Change CS_ROUTING -> CS_EXECUTE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/280@3waytalk.com) State ROUTING going to sleep a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/280@3waytalk.com) Running State Change CS_EXECUTE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/280@3waytalk.com) State EXECUTE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] mod_sofia.c:198 sofia/internal/280@3waytalk.com SOFIA EXECUTE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [DEBUG] switch_core_state_machine.c:328 sofia/internal/280@3waytalk.com Standard EXECUTE a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com socket(127.0.0.1:8085 async full) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:01.952593 [NOTICE] mod_event_socket.c:432 Trying host: 127.0.0.1:8085 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute answer(undefined) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com answer(undefined) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_core_media.c:6465 AUDIO RTP [sofia/internal/280@3waytalk.com] 134.213.206.157 port 23278 -> 46.159.161.140 port 42527 codec: 111 ms: 20 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 960 bytes per 20ms a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [INFO] switch_core_media.c:6640 Activating Audio ICE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [NOTICE] switch_rtp.c:4314 Activating RTP audio ICE: zlFE8VtX26klZtLa:mR4D536XcQ1YUJEM 46.159.161.140:42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_core_media.c:6683 Activating RTCP PORT 42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_rtp.c:4211 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 42527 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [INFO] switch_core_media.c:6691 Skipping RTCP ICE (Same as RTP) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [INFO] switch_rtp.c:3328 Activate RTP/RTCP audio DTLS client a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [INFO] switch_rtp.c:3459 Changing audio DTLS state from OFF to HANDSHAKE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_core_media.c:1989 Setting Jitterbuffer to 60ms (3 frames) (50 max frames) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_core_media.c:6764 sofia/internal/280@3waytalk.com Set 2833 dtmf send payload to 126 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_core_media.c:6771 sofia/internal/280@3waytalk.com Set 2833 dtmf receive payload to 126 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_core_media.c:6794 sofia/internal/280@3waytalk.com Set rtp dtmf delay to 40 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] mod_sofia.c:822 Local SDP sofia/internal/280@3waytalk.com: a39771e4-fbf1-4964-b499-e9843b7bfe59 v=0 a39771e4-fbf1-4964-b499-e9843b7bfe59 o=FreeSWITCH 1472730244 1472730245 IN IP4 134.213.206.157 a39771e4-fbf1-4964-b499-e9843b7bfe59 s=FreeSWITCH a39771e4-fbf1-4964-b499-e9843b7bfe59 c=IN IP4 134.213.206.157 a39771e4-fbf1-4964-b499-e9843b7bfe59 t=0 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=msid-semantic: WMS 4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQ a39771e4-fbf1-4964-b499-e9843b7bfe59 a=end-of-candidates a39771e4-fbf1-4964-b499-e9843b7bfe59 m=audio 23278 UDP/TLS/RTP/SAVPF 111 126 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:111 opus/48000/2 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=fmtp:111 useinbandfec=0; cbr=1; minptime=10 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtpmap:126 telephone-event/8000 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=silenceSupp:off - - - - a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ptime:20 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=sendrecv a39771e4-fbf1-4964-b499-e9843b7bfe59 a=fingerprint:sha-256 96:C6:72:D0:36:F1:BA:16:EA:24:7E:A3:3B:27:E8:E7:A1:C1:4B:D6:CD:DD:4E:9E:8C:39:F4:80:38:67:74:09 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=setup:active a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtcp-mux a39771e4-fbf1-4964-b499-e9843b7bfe59 a=rtcp:23278 IN IP4 134.213.206.157 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ice-ufrag:mR4D536XcQ1YUJEM a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ice-pwd:fN7D1otSIeJIXTI9ADDwxzjz a39771e4-fbf1-4964-b499-e9843b7bfe59 a=candidate:1264925573 1 udp 659136 134.213.206.157 23278 typ host generation 0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:399277753 cname:2GivxnqZ1uU09Tka a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:399277753 msid:4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQ a0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:399277753 mslabel:4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQ a39771e4-fbf1-4964-b499-e9843b7bfe59 a=ssrc:399277753 label:4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQa0 a39771e4-fbf1-4964-b499-e9843b7bfe59 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [NOTICE] mod_dptools.c:1309 Channel [sofia/internal/280@3waytalk.com] has been answered send 1797 bytes to ws/[134.213.206.157]:47652 at 18:12:02.044712: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK7963946;received=134.213.206.157;rport=47652 From: ;tag=g294kid7sg To: ;tag=9r8cUgcgUgceH Call-ID: dot4lkudmc6ubterpeth CSeq: 3068 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Content-Type: application/sdp Content-Disposition: session Content-Length: 925 Remote-Party-ID: "9d1e1675fa8a804e12512d65e0388421_rukoru" ;party=calling;privacy=off;screen=no v=0 o=FreeSWITCH 1472730244 1472730245 IN IP4 134.213.206.157 s=FreeSWITCH c=IN IP4 134.213.206.157 t=0 0 a=msid-semantic: WMS 4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQ a=end-of-candidates m=audio 23278 UDP/TLS/RTP/SAVPF 111 126 a=rtpmap:111 opus/48000/2 a=fmtp:111 useinbandfec=0; cbr=1; minptime=10 a=rtpmap:126 telephone-event/8000 a=silenceSupp:off - - - - a=ptime:20 a=fingerprint:sha-256 96:C6:72:D0:36:F1:BA:16:EA:24:7E:A3:3B:27:E8:E7:A1:C1:4B:D6:CD:DD:4E:9E:8C:39:F4:80:38:67:74:09 a=setup:active a=rtcp-mux a=rtcp:23278 IN IP4 134.213.206.157 a=ice-ufrag:mR4D536XcQ1YUJEM a=ice-pwd:fN7D1otSIeJIXTI9ADDwxzjz a=candidate:1264925573 1 udp 659136 134.213.206.157 23278 typ host generation 0 a=ssrc:399277753 cname:2GivxnqZ1uU09Tka a=ssrc:399277753 msid:4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQ a0 a=ssrc:399277753 mslabel:4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQ a=ssrc:399277753 label:4YYCC0e5BNe59O8tbDG3ro9C1iUeVdRQa0 ------------------------------------------------------------------------ a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] switch_channel.c:3770 (sofia/internal/280@3waytalk.com) Callstate Change RINGING -> ACTIVE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.032588 [DEBUG] sofia.c:6937 Channel sofia/internal/280@3waytalk.com entering state [completed][200] recv 412 bytes from ws/[134.213.206.157]:47652 at 18:12:02.050097: ------------------------------------------------------------------------ ACK sip:9d1e1675fa8a804e12512d65e0388421_rukoru@134.213.206.157:5060;transport=udp SIP/2.0 Via: SIP/2.0/WS amicqbtrlg6o.invalid;branch=z9hG4bK5939068 Max-Forwards: 70 To: ;tag=9r8cUgcgUgceH From: ;tag=g294kid7sg Call-ID: dot4lkudmc6ubterpeth CSeq: 3068 ACK Supported: outbound User-Agent: SIP.js/0.7.5 Content-Length: 0 ------------------------------------------------------------------------ a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.052588 [DEBUG] sofia.c:6937 Channel sofia/internal/280@3waytalk.com entering state [ready][200] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.092583 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute info(notice) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com info(notice) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.092583 [NOTICE] mod_dptools.c:1732 CHANNEL_DATA: a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-State: [CS_EXECUTE] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Call-State: [ACTIVE] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-State-Number: [4] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Name: [sofia/internal/280@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 Unique-ID: [a39771e4-fbf1-4964-b499-e9843b7bfe59] a39771e4-fbf1-4964-b499-e9843b7bfe59 Call-Direction: [inbound] a39771e4-fbf1-4964-b499-e9843b7bfe59 Presence-Call-Direction: [inbound] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-HIT-Dialplan: [true] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Call-UUID: [a39771e4-fbf1-4964-b499-e9843b7bfe59] a39771e4-fbf1-4964-b499-e9843b7bfe59 Answer-State: [answered] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Read-Codec-Name: [opus] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Read-Codec-Rate: [48000] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Read-Codec-Bit-Rate: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Write-Codec-Name: [opus] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Write-Codec-Rate: [48000] a39771e4-fbf1-4964-b499-e9843b7bfe59 Channel-Write-Codec-Bit-Rate: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Direction: [inbound] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Logical-Direction: [inbound] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Username: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Dialplan: [XML] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Caller-ID-Name: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Caller-ID-Number: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Orig-Caller-ID-Name: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Orig-Caller-ID-Number: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Network-Addr: [134.213.206.157] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-ANI: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Destination-Number: [9d1e1675fa8a804e12512d65e0388421_rukoru] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Unique-ID: [a39771e4-fbf1-4964-b499-e9843b7bfe59] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Source: [mod_sofia] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Context: [default] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Name: [sofia/internal/280@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Profile-Index: [1] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Profile-Created-Time: [1472753521952593] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Created-Time: [1472753521952593] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Answered-Time: [1472753522032588] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Progress-Time: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Progress-Media-Time: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Hangup-Time: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Transfer-Time: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Resurrect-Time: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Bridged-Time: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Last-Hold: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Channel-Hold-Accum: [0] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Screen-Bit: [true] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Privacy-Hide-Name: [false] a39771e4-fbf1-4964-b499-e9843b7bfe59 Caller-Privacy-Hide-Number: [false] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_direction: [inbound] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_uuid: [a39771e4-fbf1-4964-b499-e9843b7bfe59] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_session_id: [210] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_from_user: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_from_uri: [280@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_from_host: [3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_video_media_flow: [sendrecv] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_channel_name: [sofia/internal/280@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_ep_codec_string: [mod_opus.opus@48000h@20i@2c] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_local_network_addr: [134.213.206.157] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_network_ip: [134.213.206.157] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_network_port: [47652] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_received_ip: [134.213.206.157] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_received_port: [47652] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_via_protocol: [ws] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_authorized: [true] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Name: [REQUEST_PARAMS] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Core-UUID: [123f7e3b-36a3-44d6-b6aa-8b98c8273e98] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_FreeSWITCH-Hostname: [voip-prod] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_FreeSWITCH-Switchname: [voip-prod] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_FreeSWITCH-IPv4: [134.213.206.157] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_FreeSWITCH-IPv6: [2a00:1a48:7812:102:be76:4eff:fe08:bec0] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Date-Local: [2016-09-01 18:12:01] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Date-GMT: [Thu, 01 Sep 2016 18:12:01 GMT] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Date-Timestamp: [1472753521792592] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Calling-File: [sofia.c] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Calling-Function: [sofia_handle_sip_i_invite] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Calling-Line-Number: [9734] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_Event-Sequence: [26722] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_number_alias: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_auth_username: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_auth_realm: [3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_number_alias: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_requested_user_name: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_requested_domain_name: [3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_user_context: [default] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_user_name: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_domain_name: [3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_from_user_stripped: [280] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sofia_profile_name: [internal] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_recovery_profile_name: [internal] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_req_user: [9d1e1675fa8a804e12512d65e0388421_rukoru] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_req_uri: [9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_req_host: [3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_to_user: [9d1e1675fa8a804e12512d65e0388421_rukoru] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_to_uri: [9d1e1675fa8a804e12512d65e0388421_rukoru@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_to_host: [3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_contact_params: [transport=ws;ob] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_contact_user: [1kfef9k8] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_contact_uri: [1kfef9k8@amicqbtrlg6o.invalid] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_contact_host: [amicqbtrlg6o.invalid] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_user_agent: [SIP.js/0.7.5] a39771e4-fbf1-4964-b499-e9843b7bfe59 variable_sip_via_host: [amicqbtrlg6o.invalid] variable_sip_via_rport: [47652] variable_max_forwards: [70] variable_switch_r_sdp: [v=0 o=- 4552988607047744733 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS ARDAMS m=audio 42527 UDP/TLS/RTP/SAVPF 111 103 9 102 0 8 106 105 13 127 126 c=IN IP4 46.159.161.140 a=rtpmap:111 opus/48000/2 a=fmtp:111 minptime=10; useinbandfec=1 a=rtpmap:103 ISAC/16000 a=rtpmap:9 G722/8000 a=rtpmap:102 ILBC/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:127 red/8000 a=rtpmap:126 telephone-event/8000 a=rtcp:38050 IN IP4 46.159.161.140 a=candidate:3350409123 1 udp 2122260223 192.168.0.101 42527 typ host generation 0 a=candidate:3350409123 2 udp 2122260222 192.168.0.101 38050 typ host generation 0 a=candidate:1190865175 2 udp 1686052606 46.159.161.140 38050 typ srflx raddr 192.168.0.101 rport 38050 generation 0 a=candidate:1190865175 1 udp 1686052607 46.159.161.140 42527 typ srflx raddr 192.168.0.101 rport 42527 generation 0 a=candidate:2301678419 1 tcp 1518280447 192.168.0.101 37171 typ host tcptype passive generation 0 a=candidate:2301678419 2 tcp 1518280446 192.168.0.101 34973 typ host tcptype passive generation 0 a=ice-ufrag:zlFE8VtX26klZtLa a=ice-pwd:0LGWvsW5Zazi35Xk8BlzzkOY a=fingerprint:sha-256 E5:C8:6E:BD:1C:03:D6:B4:4F:E2:8F:B1:84:DE:A1:6A:37:4C:D7:C6:F2:A5:6D:47:45:DD:CA:7A:30:6E:93:BE a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=rtcp-mux a=maxptime:60 a=ssrc:2537041755 cname:7CbYDw1WUcfBYXkJ a=ssrc:2537041755 msid:ARDAMS ARDAMSa0 a=ssrc:2537041755 mslabel:ARDAMS a=ssrc:2537041755 label:ARDAMSa0 ] variable_audio_media_flow: [sendrecv] variable_rtp_use_codec_string: [OPUS] variable_rtp_remote_audio_rtcp_port: [38050 IN IP4 46.159.161.140] variable_rtp_audio_recv_pt: [111] variable_rtp_use_codec_name: [opusa39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.512591 [INFO] switch_rtp.c:3119 Changing audio DTLS state from HANDSHAKE to SETUP a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.532598 [INFO] switch_rtp.c:3028 audio Fingerprint Verified. a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.532598 [INFO] switch_rtp.c:3644 Activating Audio Secure RTP SEND a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.532598 [INFO] switch_rtp.c:3622 Activating Audio Secure RTP RECV 2016-09-01 18:12:02.532598 [DEBUG] switch_core_sqldb.c:2612 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.532598 [INFO] switch_rtp.c:3068 Changing audio DTLS state from SETUP to READY 2016-09-01 18:12:02.532598 [DEBUG] switch_core_sqldb.c:2612 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:02.772593 [DEBUG] switch_rtp.c:1846 rtcp_stats_init: audio ssrc[2537041755] base_seq[22618] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(hangup_after_bridge=false) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(hangup_after_bridge=false) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [hangup_after_bridge]=[false] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(ringback=file_string:///home/threewaytalk/3waytalk/audio/please_wait.wav!tone_stream://${us-ring};loops=-1) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(ringback=file_string:///home/threewaytalk/3waytalk/audio/please_wait.wav!tone_stream://%(2000,4000,440,480);loops=-1) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [ringback]=[file_string:///home/threewaytalk/3waytalk/audio/please_wait.wav!tone_stream://%(2000,4000,440,480);loops=-1] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(continue_on_fail=true) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(continue_on_fail=true) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [continue_on_fail]=[true] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(bypass_media=false) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(bypass_media=false) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [bypass_media]=[false] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(effective_caller_id_name=incoming call (Russian)) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(effective_caller_id_name=incoming call (Russian)) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [effective_caller_id_name]=[incoming call (Russian)] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(jitterbuffer_msec=90:300:600) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(jitterbuffer_msec=90:300:600) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [jitterbuffer_msec]=[90:300:600] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(sip_jitter_buffer_during_bridge=true) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(sip_jitter_buffer_during_bridge=true) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [sip_jitter_buffer_during_bridge]=[true] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute export(nolocal:jitterbuffer_msec=90:300:600) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com export(nolocal:jitterbuffer_msec=90:300:600) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [jitterbuffer_msec]=[90:300:600] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute export(bridge_generate_comfort_noise=true) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com export(bridge_generate_comfort_noise=true) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [bridge_generate_comfort_noise]=[true] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute set(call_timeout=20) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com set(call_timeout=20) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] mod_dptools.c:1519 SET sofia/internal/280@3waytalk.com [call_timeout]=[20] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute export(nolocal:absolute_codec_string=OPUS) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com export(nolocal:absolute_codec_string=OPUS) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) (REMOTE ONLY) [absolute_codec_string]=[OPUS] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute bridge({ignore_early_media=false}user/2183@${domain_name}) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com bridge({ignore_early_media=false}user/2183@3waytalk.com) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1823 (sofia/internal/280@3waytalk.com) Callstate Change ACTIVE -> RING_WAIT a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1250 sofia/internal/280@3waytalk.com EXPORTING[export_vars] [jitterbuffer_msec]=[90:300:600] to event a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1250 sofia/internal/280@3waytalk.com EXPORTING[export_vars] [bridge_generate_comfort_noise]=[true] to event a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_channel.c:1250 sofia/internal/280@3waytalk.com EXPORTING[export_vars] [absolute_codec_string]=[OPUS] to event a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.032589 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables 2016-09-01 18:12:03.032589 [NOTICE] switch_cpp.cpp:1360 directory request 2016-09-01 18:12:03.852586 [NOTICE] switch_cpp.cpp:1360 Authenticated user 2183 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.852586 [DEBUG] switch_channel.c:1250 sofia/internal/280@3waytalk.com EXPORTING[export_vars] [jitterbuffer_msec]=[90:300:600] to event a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.852586 [DEBUG] switch_channel.c:1250 sofia/internal/280@3waytalk.com EXPORTING[export_vars] [bridge_generate_comfort_noise]=[true] to event a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.852586 [DEBUG] switch_channel.c:1250 sofia/internal/280@3waytalk.com EXPORTING[export_vars] [absolute_codec_string]=[OPUS] to event a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.852586 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid [5b8b1c43-a010-4570-b282-6eb4a965a4db] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] mod_sofia.c:4754 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_NEW -> CS_INIT 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_INIT 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State INIT 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] mod_sofia.c:90 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid SOFIA INIT 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] sofia_glue.c:1220 sip:qiin1j5e@46.159.161.140:56849;transport=wss Setting proxy route to sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] sofia_glue.c:1249 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid sending invite version: 1.7.0 -915-35ee4ee 64bit 5b8b1c43-a010-4570-b282-6eb4a965a4db Local SDP: 5b8b1c43-a010-4570-b282-6eb4a965a4db v=0 5b8b1c43-a010-4570-b282-6eb4a965a4db o=FreeSWITCH 1472730617 1472730618 IN IP4 134.213.206.157 5b8b1c43-a010-4570-b282-6eb4a965a4db s=FreeSWITCH 5b8b1c43-a010-4570-b282-6eb4a965a4db c=IN IP4 134.213.206.157 5b8b1c43-a010-4570-b282-6eb4a965a4db t=0 0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=msid-semantic: WMS EPL0w1YessmR7IRxAwu5xOVMMjHG6kaB 5b8b1c43-a010-4570-b282-6eb4a965a4db a=end-of-candidates 5b8b1c43-a010-4570-b282-6eb4a965a4db m=audio 22906 RTP/SAVPF 102 101 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtpmap:102 opus/48000/2 5b8b1c43-a010-4570-b282-6eb4a965a4db a=fmtp:102 useinbandfec=0; cbr=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtpmap:101 telephone-event/48000 5b8b1c43-a010-4570-b282-6eb4a965a4db a=fingerprint:sha-256 96:C6:72:D0:36:F1:BA:16:EA:24:7E:A3:3B:27:E8:E7:A1:C1:4B:D6:CD:DD:4E:9E:8C:39:F4:80:38:67:74:09 5b8b1c43-a010-4570-b282-6eb4a965a4db a=setup:actpass 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtcp-mux 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtcp:22906 IN IP4 134.213.206.157 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:3152737755 cname:0MsmDgrVzEDwckUD 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:3152737755 msid:EPL0w1YessmR7IRxAwu5xOVMMjHG6kaB a0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:3152737755 mslabel:EPL0w1YessmR7IRxAwu5xOVMMjHG6kaB 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:3152737755 label:EPL0w1YessmR7IRxAwu5xOVMMjHG6kaBa0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ice-ufrag:Hey5TkHwte2qp3Rf 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ice-pwd:F9s8gJUGeo2gzNK6S92BjzYC 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:0578070984 1 udp 659136 134.213.206.157 22906 typ host generation 0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:0578070984 2 udp 659136 134.213.206.157 22906 typ host generation 0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=silenceSupp:off - - - - 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ptime:20 5b8b1c43-a010-4570-b282-6eb4a965a4db a=sendrecv 5b8b1c43-a010-4570-b282-6eb4a965a4db 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:40 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Standard INIT 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:48 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_INIT -> CS_ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:586 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State INIT going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] mod_sofia.c:143 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid SOFIA ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_ivr_originate.c:67 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_ROUTING -> CS_CONSUME_MEDIA 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State ROUTING going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_CONSUME_MEDIA send 2038 bytes to wss/[46.159.161.140]:56849 at 18:12:03.857631: ------------------------------------------------------------------------ INVITE sip:qiin1j5e@bvhvt1dfbk4m.invalid;transport=ws SIP/2.0 Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK5gSv9QXKr1U1B Route: ;transport=wss Max-Forwards: 69 From: "incoming call (Russian)" ;tag=a215vBXKrS20c To: Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040697 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Session-Expires: 1800;refresher=uac Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 1075 X-FS-Support: update_display,send_info Remote-Party-ID: "incoming call (Russian)" ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1472730617 1472730618 IN IP4 134.213.206.157 s=FreeSWITCH c=IN IP4 134.213.206.157 t=0 0 a=msid-semantic: WMS EPL0w1YessmR7IRxAwu5xOVMMjHG6kaB a=end-of-candidates m=audio 22906 RTP/SAVPF 102 101 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=0; cbr=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 a=rtpmap:101 telephone-event/48000 a=fingerprint:sha-256 96:C6:72:D0:36:F1:BA:16:EA:24:7E:A3:3B:27:E8:E7:A1:C1:4B:D6:CD:DD:4E:9E:8C:39:F4:80:38:67:74:09 a=setup:actpass a=rtcp-mux a=rtcp:22906 IN IP4 134.213.206.157 a=ssrc:3152737755 cname:0MsmDgrVzEDwckUD a=ssrc:3152737755 msid:EPL0w1YessmR7IRxAwu5xOVMMjHG6kaB a0 a=ssrc:3152737755 mslabel:EPL0w1YessmR7IRxAwu5xOVMMjHG6kaB a=ssrc:3152737755 label:EPL0w1YessmR7IRxAwu5xOVMMjHG6kaBa0 a=ice-ufrag:Hey5TkHwte2qp3Rf a=ice-pwd:F9s8gJUGeo2gzNK6S92BjzYC a=candidate:0578070984 1 udp 659136 134.213.206.157 22906 typ host generation 0 a=candidate:0578070984 2 udp 659136 134.213.206.157 22906 typ host generation 0 a=silenceSupp:off - - - - a=ptime:20 ------------------------------------------------------------------------ 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State CONSUME_MEDIA 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] switch_core_state_machine.c:621 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State CONSUME_MEDIA going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.852586 [DEBUG] sofia.c:6937 Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid entering state [calling][0] recv 359 bytes from wss/[46.159.161.140]:56849 at 18:12:03.955287: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK5gSv9QXKr1U1B To: From: "incoming call (Russian)" ;tag=a215vBXKrS20c Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040697 INVITE Supported: outbound User-Agent: SIP.js/0.7.5 Content-Length: 0 ------------------------------------------------------------------------ recv 434 bytes from wss/[46.159.161.140]:56849 at 18:12:03.961962: ------------------------------------------------------------------------ SIP/2.0 180 Ringing Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK5gSv9QXKr1U1B To: ;tag=fm2qiedr5v From: "incoming call (Russian)" ;tag=a215vBXKrS20c Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040697 INVITE Contact: Supported: outbound User-Agent: SIP.js/0.7.5 Content-Length: 0 ------------------------------------------------------------------------ 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.952585 [DEBUG] sofia.c:6937 Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid entering state [proceeding][180] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.952585 [NOTICE] sofia.c:7045 Ring-Ready sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid! 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:03.952585 [DEBUG] switch_channel.c:3343 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Callstate Change DOWN -> RINGING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.972592 [DEBUG] switch_ivr_originate.c:1273 Raw Codec Activation Success L16@48000hz 1 channel 20ms a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.972592 [DEBUG] switch_core_codec.c:221 sofia/internal/280@3waytalk.com Push codec L16:100 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:03.972592 [DEBUG] switch_ivr_originate.c:1305 Play Ringback File [file_string:///home/threewaytalk/3waytalk/audio/please_wait.wav!tone_stream://%(2000,4000,440,480);loops=-1] 2016-09-01 18:12:03.972592 [DEBUG] switch_core_file.c:330 File /home/threewaytalk/3waytalk/audio/please_wait.wav sample rate 44100 doesn't match requested rate 48000 recv 2040 bytes from wss/[46.159.161.140]:56849 at 18:12:12.063548: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK5gSv9QXKr1U1B To: ;tag=fm2qiedr5v From: "incoming call (Russian)" ;tag=a215vBXKrS20c Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040697 INVITE Contact: Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Supported: outbound User-Agent: SIP.js/0.7.5 Content-Type: application/sdp Content-Length: 1513 v=0 o=- 746996579908061199 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS 8A92izLjuVeE3mQmph5V0EMsmUiXGRJ5byy5 m=audio 57792 UDP/TLS/RTP/SAVPF 102 c=IN IP4 46.159.161.140 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:3573973069 1 udp 2122260223 192.168.0.102 57792 typ host generation 0 network-id 3 a=candidate:2999745851 1 udp 2122194687 192.168.56.1 57793 typ host generation 0 network-id 2 a=candidate:3013953624 1 udp 2122129151 192.168.1.100 57794 typ host generation 0 network-id 1 a=candidate:1414432505 1 udp 1686052607 46.159.161.140 57792 typ srflx raddr 192.168.0.102 rport 57792 generation 0 network-id 3 a=candidate:2609216701 1 tcp 1518280447 192.168.0.102 9 typ host tcptype active generation 0 network-id 3 a=candidate:4233069003 1 tcp 1518214911 192.168.56.1 9 typ host tcptype active generation 0 network-id 2 a=candidate:4247172264 1 tcp 1518149375 192.168.1.100 9 typ host tcptype active generation 0 network-id 1 a=ice-ufrag:IqBC5aTb1e50SUKi a=ice-pwd:V2chuu0uZjXEnxUMukcz0b34 a=fingerprint:sha-256 AD:1F:11:FC:6C:91:DC:4D:A3:5B:9C:F4:93:16:50:B0:81:B3:CB:D4:FE:62:2A:2C:A9:9A:F3:5A:0C:5C:44:20 a=setup:active a=mid:audio a=sendrecv a=rtcp-mux a=rtpmap:102 opus/48000/2 a=fmtp:102 minptime=10;useinbandfec=1 a=ssrc:1546595284 cname:+d2oOSujhW7VK759 a=ssrc:1546595284 msid:8A92izLjuVeE3mQmph5V0EMsmUiXGRJ5byy5 053c5609-13b8-4081-a1b0-cb099a328ae6 a=ssrc:1546595284 mslabel:8A92izLjuVeE3mQmph5V0EMsmUiXGRJ5byy5 a=ssrc:1546595284 label:053c5609-13b8-4081-a1b0-cb099a328ae6 ------------------------------------------------------------------------ 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] sofia.c:6937 Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid entering state [completing][200] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] sofia.c:6947 Remote SDP: 5b8b1c43-a010-4570-b282-6eb4a965a4db v=0 5b8b1c43-a010-4570-b282-6eb4a965a4db o=- 746996579908061199 2 IN IP4 127.0.0.1 5b8b1c43-a010-4570-b282-6eb4a965a4db s=- 5b8b1c43-a010-4570-b282-6eb4a965a4db t=0 0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=msid-semantic: WMS 8A92izLjuVeE3mQmph5V0EMsmUiXGRJ5byy5 5b8b1c43-a010-4570-b282-6eb4a965a4db m=audio 57792 UDP/TLS/RTP/SAVPF 102 5b8b1c43-a010-4570-b282-6eb4a965a4db c=IN IP4 46.159.161.140 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtpmap:102 opus/48000/2 5b8b1c43-a010-4570-b282-6eb4a965a4db a=fmtp:102 minptime=10;useinbandfec=1 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtcp:9 IN IP4 0.0.0.0 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:3573973069 1 udp 2122260223 192.168.0.102 57792 typ host generation 0 network-id 3 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:2999745851 1 udp 2122194687 192.168.56.1 57793 typ host generation 0 network-id 2 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:3013953624 1 udp 2122129151 192.168.1.100 57794 typ host generation 0 network-id 1 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:1414432505 1 udp 1686052607 46.159.161.140 57792 typ srflx raddr 192.168.0.102 rport 57792 generation 0 network-id 3 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:2609216701 1 tcp 1518280447 192.168.0.102 9 typ host tcptype active generation 0 network-id 3 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:4233069003 1 tcp 1518214911 192.168.56.1 9 typ host tcptype active generation 0 network-id 2 5b8b1c43-a010-4570-b282-6eb4a965a4db a=candidate:4247172264 1 tcp 1518149375 192.168.1.100 9 typ host tcptype active generation 0 network-id 1 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ice-ufrag:IqBC5aTb1e50SUKi 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ice-pwd:V2chuu0uZjXEnxUMukcz0b34 5b8b1c43-a010-4570-b282-6eb4a965a4db a=fingerprint:sha-256 AD:1F:11:FC:6C:91:DC:4D:A3:5B:9C:F4:93:16:50:B0:81:B3:CB:D4:FE:62:2A:2C:A9:9A:F3:5A:0C:5C:44:20 5b8b1c43-a010-4570-b282-6eb4a965a4db a=setup:active 5b8b1c43-a010-4570-b282-6eb4a965a4db a=mid:audio 5b8b1c43-a010-4570-b282-6eb4a965a4db a=rtcp-mux 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:1546595284 cname:+d2oOSujhW7VK759 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:1546595284 msid:8A92izLjuVeE3mQmph5V0EMsmUiXGRJ5byy5 053c5609-13b8-4081-a1b0-cb099a328ae6 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:1546595284 mslabel:8A92izLjuVeE3mQmph5V0EMsmUiXGRJ5byy5 5b8b1c43-a010-4570-b282-6eb4a965a4db a=ssrc:1546595284 label:053c5609-13b8-4081-a1b0-cb099a328ae6 5b8b1c43-a010-4570-b282-6eb4a965a4db send 429 bytes to wss/[46.159.161.140]:56849 at 18:12:12.064682: ------------------------------------------------------------------------ ACK sip:qiin1j5e@bvhvt1dfbk4m.invalid;transport=ws SIP/2.0 Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK6SjNBKeQNajmQ Max-Forwards: 70 From: "incoming call (Russian)" ;tag=a215vBXKrS20c To: ;tag=fm2qiedr5v Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040697 ACK Contact: Content-Length: 0 ------------------------------------------------------------------------ 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] sofia.c:6937 Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid entering state [ready][200] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [opus:102:48000:20:0:1]/[opus:116:48000:20:0:1] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:4366 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2016-09-01 18:12:12.052597 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [72000bps] 2016-09-01 18:12:12.052597 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled 2016-09-01 18:12:12.052597 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [72000bps] 2016-09-01 18:12:12.052597 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3018 Set Codec sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid opus/48000 20 ms 960 samples 0 bits 1 channels 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_codec.c:111 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Original read codec set to opus:116 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [WARNING] switch_core_media.c:3392 NO candidate ACL defined, Defaulting to wan.auto 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.0.102:57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.56.1:57793 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.1.100:57794 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3422 Save audio Candidate cid: 1 proto: udp type: srflx addr: 46.159.161.140:57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3464 Searching for rtp candidate. 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3469 Choose rtp candidate, index 3, 46.159.161.140:57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3247 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid choosing family v4 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3480 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 46.159.161.140:57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3525 setting remote audio ice addr to index 3 46.159.161.140:57792 based on candidate 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:3546 Setting remote rtcp audio addr to 46.159.161.140:57792 based on candidate 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:4646 No 2833 in SDP. Disable 2833 dtmf and switch to INFO 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:6465 AUDIO RTP [sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid] 134.213.206.157 port 22906 -> 46.159.161.140 port 57792 codec: 102 ms: 20 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_rtp.c:3832 Starting timer [soft] 960 bytes per 20ms 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [INFO] switch_core_media.c:6640 Activating Audio ICE 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [NOTICE] switch_rtp.c:4314 Activating RTP audio ICE: IqBC5aTb1e50SUKi:Hey5TkHwte2qp3Rf 46.159.161.140:57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:6683 Activating RTCP PORT 57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_rtp.c:4211 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 57792 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [INFO] switch_core_media.c:6691 Skipping RTCP ICE (Same as RTP) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [INFO] switch_rtp.c:3328 Activate RTP/RTCP audio DTLS server 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [INFO] switch_rtp.c:3459 Changing audio DTLS state from OFF to HANDSHAKE 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:1989 Setting Jitterbuffer to 90ms (4 frames) (15 max frames) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_core_media.c:6794 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Set rtp dtmf delay to 40 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [NOTICE] sofia.c:7970 Channel [sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid] has been answered 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.052597 [DEBUG] switch_channel.c:3770 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Callstate Change RINGING -> ACTIVE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.072591 [DEBUG] switch_core_codec.c:246 sofia/internal/280@3waytalk.com Restore previous codec opus:116. a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.072591 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.072591 [DEBUG] switch_channel.c:2047 (sofia/internal/280@3waytalk.com) Callstate Change RING_WAIT -> ACTIVE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.072591 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.072591 [DEBUG] switch_core_media.c:9640 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid PAUSE Jitterbuffer a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.072591 [DEBUG] switch_core_media.c:9640 sofia/internal/280@3waytalk.com PAUSE Jitterbuffer 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.072591 [DEBUG] switch_ivr_bridge.c:1599 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.072591 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_EXCHANGE_MEDIA 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.072591 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State EXCHANGE_MEDIA 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.072591 [DEBUG] mod_sofia.c:631 SOFIA EXCHANGE_MEDIA 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.072591 [DEBUG] switch_ivr_bridge.c:439 Setup generated silence from sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid to sofia/internal/280@3waytalk.com at 1400 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.072591 [DEBUG] switch_ivr_bridge.c:439 Setup generated silence from sofia/internal/280@3waytalk.com to sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid at 1400 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.112591 [DEBUG] switch_core_media.c:2474 [VBR]: Correcting calculated ptime value from [840] to [20] to compensate for [41] lost packet(s) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.112591 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0] 2016-09-01 18:12:12.112591 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [72000bps] 2016-09-01 18:12:12.112591 [DEBUG] mod_opus.c:578 Opus encoder: CBR mode enabled a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] switch_core_media.c:9697 sofia/internal/280@3waytalk.com RESUME Jitterbuffer a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute conference(9d1e1675fa8a804e12512d65e0388421) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com conference(9d1e1675fa8a804e12512d65e0388421) 2016-09-01 18:12:12.292592 [DEBUG] mod_conference.c:3017 using channel sound prefix: /usr/share/freeswitch/sounds/ru/RU/elena a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] conference_member.c:1654 Raw Codec Activation Success L16@48000hz 1 channel 20ms a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] conference_member.c:1701 Raw Codec Activation Success L16@48000hz 1 channel 20ms a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] switch_core_codec.c:221 sofia/internal/280@3waytalk.com Push codec L16:100 2016-09-01 18:12:12.292592 [DEBUG] mod_conference.c:220 Setup timer success interval: 20 samples: 960 2016-09-01 18:12:12.292592 [DEBUG] conference_member.c:128 sofia/internal/280@3waytalk.com binding '9' to 'energy up' 2016-09-01 18:12:12.292592 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf' 2016-09-01 18:12:12.292592 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fa3e557ab30 data: 0x7fa36431d8a0 2016-09-01 18:12:12.292592 [DEBUG] conference_member.c:128 sofia/internal/280@3waytalk.com binding '7' to 'energy dn' 2016-09-01 18:12:12.292592 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fa3e557ab30 data: 0x7fa36431d8d0 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] switch_core_media.c:9640 sofia/internal/280@3waytalk.com PAUSE Jitterbuffer a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] conference_loop.c:1101 Setup timer soft success interval: 20 samples: 960 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.292592 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute transfer(-bleg 9d1e1675fa8a804e12512d65e0388421 XML conf) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com transfer(-bleg 9d1e1675fa8a804e12512d65e0388421 XML conf) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_ivr.c:2160 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_EXCHANGE_MEDIA -> CS_ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [NOTICE] switch_ivr.c:2167 Transfer sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid to XML[9d1e1675fa8a804e12512d65e0388421@conf] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_ivr_bridge.c:785 BRIDGE THREAD DONE [sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:612 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State EXCHANGE_MEDIA going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] mod_sofia.c:143 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid SOFIA ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:236 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Standard ROUTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [INFO] mod_dialplan_xml.c:637 Processing incoming call (Russian) <280>->9d1e1675fa8a804e12512d65e0388421 in context conf 5b8b1c43-a010-4570-b282-6eb4a965a4db Dialplan: sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid parsing [conf->conference] continue=false 5b8b1c43-a010-4570-b282-6eb4a965a4db Dialplan: sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Regex (PASS) [conference] destination_number(9d1e1675fa8a804e12512d65e0388421) =~ /^(.*)$/ break=on-false 5b8b1c43-a010-4570-b282-6eb4a965a4db Dialplan: sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Action socket(127.0.0.1:8085 async full) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [INFO] switch_channel.c:3127 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Flipping CID from "incoming call (Russian)" <280> to "Outbound Call" 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:286 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_ROUTING -> CS_EXECUTE 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:602 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State ROUTING going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_EXECUTE 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State EXECUTE 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] mod_sofia.c:198 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid SOFIA EXECUTE 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [DEBUG] switch_core_state_machine.c:328 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Standard EXECUTE 5b8b1c43-a010-4570-b282-6eb4a965a4db EXECUTE sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid socket(127.0.0.1:8085 async full) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.292592 [NOTICE] mod_event_socket.c:432 Trying host: 127.0.0.1:8085 2016-09-01 18:12:12.312591 [INFO] mod_conference.c:361 Auto recording file: /var/www/recordings/9d1e1675fa8a804e12512d65e0388421.wav 2016-09-01 18:12:12.312591 [DEBUG] conference_record.c:279 Setup timer success interval: 20 samples: 960 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.372588 [INFO] switch_rtp.c:3119 Changing audio DTLS state from HANDSHAKE to SETUP a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.392589 [DEBUG] switch_core_media.c:2474 [VBR]: Correcting calculated ptime value from [120] to [20] to compensate for [5] lost packet(s) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [INFO] switch_rtp.c:3028 audio Fingerprint Verified. 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [INFO] switch_rtp.c:3644 Activating Audio Secure RTP SEND 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [INFO] switch_rtp.c:3622 Activating Audio Secure RTP RECV 2016-09-01 18:12:12.392589 [DEBUG] switch_core_sqldb.c:2612 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [INFO] switch_rtp.c:3068 Changing audio DTLS state from SETUP to READY 2016-09-01 18:12:12.392589 [DEBUG] switch_core_sqldb.c:2612 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [DEBUG] switch_ivr.c:623 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Command Execute conference(9d1e1675fa8a804e12512d65e0388421) 5b8b1c43-a010-4570-b282-6eb4a965a4db EXECUTE sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid conference(9d1e1675fa8a804e12512d65e0388421) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [DEBUG] conference_member.c:1654 Raw Codec Activation Success L16@48000hz 1 channel 20ms 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [DEBUG] conference_member.c:1701 Raw Codec Activation Success L16@48000hz 1 channel 20ms 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [DEBUG] switch_core_codec.c:221 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Push codec L16:100 2016-09-01 18:12:12.392589 [DEBUG] conference_member.c:128 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid binding '9' to 'energy up' 2016-09-01 18:12:12.392589 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf' 2016-09-01 18:12:12.392589 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fa3e557ab30 data: 0x7fa34c1e2c00 2016-09-01 18:12:12.392589 [DEBUG] conference_member.c:128 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid binding '7' to 'energy dn' 2016-09-01 18:12:12.392589 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fa3e557ab30 data: 0x7fa34c1e2c30 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.392589 [DEBUG] conference_loop.c:1101 Setup timer soft success interval: 20 samples: 960 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.452588 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute jitterbuffer(debug:off) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com jitterbuffer(debug:off) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:12.452588 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute jitterbuffer(resume) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com jitterbuffer(resume) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:12.492587 [DEBUG] switch_rtp.c:1846 rtcp_stats_init: audio ssrc[1546595284] base_seq[23543] 2016-09-01 18:12:19.372586 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables 2016-09-01 18:12:19.372586 [DEBUG] switch_ivr_originate.c:2580 Parsing session specific variables 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [NOTICE] switch_channel.c:1104 New Channel sofia/external/+79001234567 [51d3d083-740d-4133-ab84-a6b169be9de0] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] mod_sofia.c:4754 (sofia/external/+79001234567) State Change CS_NEW -> CS_INIT 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_session.c:613 sofia/external/+79001234567 set UUID=51d3d083-740d-4133-ab84-a6b169be9de0 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_INIT 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:586 (sofia/external/+79001234567) State INIT 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] mod_sofia.c:90 sofia/external/+79001234567 SOFIA INIT 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] sofia_glue.c:1249 sofia/external/+79001234567 sending invite version: 1.7.0 -915-35ee4ee 64bit 51d3d083-740d-4133-ab84-a6b169be9de0 Local SDP: 51d3d083-740d-4133-ab84-a6b169be9de0 v=0 51d3d083-740d-4133-ab84-a6b169be9de0 o=FreeSWITCH 1472732073 1472732074 IN IP4 134.213.206.157 51d3d083-740d-4133-ab84-a6b169be9de0 s=FreeSWITCH 51d3d083-740d-4133-ab84-a6b169be9de0 c=IN IP4 134.213.206.157 51d3d083-740d-4133-ab84-a6b169be9de0 t=0 0 51d3d083-740d-4133-ab84-a6b169be9de0 m=audio 21466 RTP/AVP 8 0 101 13 51d3d083-740d-4133-ab84-a6b169be9de0 a=rtpmap:8 PCMA/8000 51d3d083-740d-4133-ab84-a6b169be9de0 a=rtpmap:0 PCMU/8000 51d3d083-740d-4133-ab84-a6b169be9de0 a=rtpmap:101 telephone-event/8000 51d3d083-740d-4133-ab84-a6b169be9de0 a=fmtp:101 0-16 51d3d083-740d-4133-ab84-a6b169be9de0 a=rtpmap:13 CN/8000 51d3d083-740d-4133-ab84-a6b169be9de0 a=ptime:20 51d3d083-740d-4133-ab84-a6b169be9de0 a=sendrecv 51d3d083-740d-4133-ab84-a6b169be9de0 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:40 sofia/external/+79001234567 Standard INIT 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:48 (sofia/external/+79001234567) State Change CS_INIT -> CS_ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:586 (sofia/external/+79001234567) State INIT going to sleep send 1185 bytes to udp/[54.171.127.193]:5060 at 18:12:19.376996: ------------------------------------------------------------------------ INVITE sip:+79001234567@3waytalk.pstn.ie1.twilio.com SIP/2.0 Via: SIP/2.0/UDP 134.213.206.157:5080;rport;branch=z9hG4bKU9NvDBUae3HrQ Max-Forwards: 70 From: "" ;tag=Ft6DDX0mX2mXc To: Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 96040705 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Session-Expires: 1800;refresher=uac Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 274 X-FS-Support: update_display,send_info Remote-Party-ID: ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1472732073 1472732074 IN IP4 134.213.206.157 s=FreeSWITCH c=IN IP4 134.213.206.157 t=0 0 m=audio 21466 RTP/AVP 8 0 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:602 (sofia/external/+79001234567) State ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] mod_sofia.c:143 sofia/external/+79001234567 SOFIA ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_ivr_originate.c:67 (sofia/external/+79001234567) State Change CS_ROUTING -> CS_CONSUME_MEDIA 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:602 (sofia/external/+79001234567) State ROUTING going to sleep 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_CONSUME_MEDIA 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] sofia.c:6937 Channel sofia/external/+79001234567 entering state [calling][0] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:621 (sofia/external/+79001234567) State CONSUME_MEDIA 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.372586 [DEBUG] switch_core_state_machine.c:621 (sofia/external/+79001234567) State CONSUME_MEDIA going to sleep recv 361 bytes from udp/[54.171.127.193]:5060 at 18:12:19.392173: ------------------------------------------------------------------------ SIP/2.0 100 Giving a try Via: SIP/2.0/UDP 134.213.206.157:5080;received=134.213.206.157;rport=5080;branch=z9hG4bKU9NvDBUae3HrQ From: "" ;tag=Ft6DDX0mX2mXc To: Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 96040705 INVITE Server: Twilio Gateway Content-Length: 0 ------------------------------------------------------------------------ recv 610 bytes from udp/[54.171.127.193]:5060 at 18:12:19.663291: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication required CSeq: 96040705 INVITE Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 From: "" ;tag=Ft6DDX0mX2mXc To: ;tag=38114634_6772d868_8588d2da-cc47-40a2-bc09-44781d4b2646 Via: SIP/2.0/UDP 134.213.206.157:5080;received=134.213.206.157;rport=5080;branch=z9hG4bKU9NvDBUae3HrQ Server: Twilio Contact: Proxy-Authenticate: Digest realm="sip.twilio.com",qop="auth",nonce="c55064a1af158115e3504b058309bf0f",opaque="16f00e973dac288064caa33b910f0c68" Content-Length: 0 ------------------------------------------------------------------------ send 414 bytes to udp/[54.171.127.193]:5060 at 18:12:19.663438: ------------------------------------------------------------------------ ACK sip:+79001234567@3waytalk.pstn.ie1.twilio.com SIP/2.0 Via: SIP/2.0/UDP 134.213.206.157:5080;rport;branch=z9hG4bKU9NvDBUae3HrQ Max-Forwards: 70 From: "" ;tag=Ft6DDX0mX2mXc To: ;tag=38114634_6772d868_8588d2da-cc47-40a2-bc09-44781d4b2646 Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 96040705 ACK Content-Length: 0 ------------------------------------------------------------------------ send 1509 bytes to udp/[54.171.127.193]:5060 at 18:12:19.663717: ------------------------------------------------------------------------ INVITE sip:+79001234567@3waytalk.pstn.ie1.twilio.com SIP/2.0 Via: SIP/2.0/UDP 134.213.206.157:5080;rport;branch=z9hG4bKvjFNF6BeBc8aK Max-Forwards: 70 From: "" ;tag=Ft6DDX0mX2mXc To: Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 96040706 INVITE Contact: User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authorization: Digest username="02345", realm="sip.twilio.com", nonce="c55064a1af158115e3504b058309bf0f", cnonce="dptBZOsSEjSKNrx2Tgi+wA", opaque="16f00e973dac288064caa33b910f0c68", algorithm=MD5, uri="sip:+79001234567@3waytalk.pstn.ie1.twilio.com", response="d9a0c66afc6892cc9b029b232f4dfaa6", qop=auth, nc=00000001 Session-Expires: 1800;refresher=uac Min-SE: 120 Content-Type: application/sdp Content-Disposition: session Content-Length: 274 X-FS-Support: update_display,send_info Remote-Party-ID: ;party=calling;screen=yes;privacy=off v=0 o=FreeSWITCH 1472732073 1472732074 IN IP4 134.213.206.157 s=FreeSWITCH c=IN IP4 134.213.206.157 t=0 0 m=audio 21466 RTP/AVP 8 0 101 13 a=rtpmap:8 PCMA/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=rtpmap:13 CN/8000 a=ptime:20 ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:19.652588 [DEBUG] sofia.c:6937 Channel sofia/external/+79001234567 entering state [calling][0] recv 361 bytes from udp/[54.171.127.193]:5060 at 18:12:19.677973: ------------------------------------------------------------------------ SIP/2.0 100 Giving a try Via: SIP/2.0/UDP 134.213.206.157:5080;received=134.213.206.157;rport=5080;branch=z9hG4bKvjFNF6BeBc8aK From: "" ;tag=Ft6DDX0mX2mXc To: Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 96040706 INVITE Server: Twilio Gateway Content-Length: 0 ------------------------------------------------------------------------ recv 767 bytes from udp/[89.163.148.171]:5070 at 18:12:27.523449: ------------------------------------------------------------------------ INVITE sip:00441904891563@134.213.206.157 SIP/2.0 To: 00441904891563 From: 90000;tag=217fb9db Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE Contact: Max-Forwards: 70 Allow: INVITE, ACK, CANCEL, BYE User-Agent: sipcli/v1.8 Content-Type: application/sdp Content-Length: 284 v=0 o=sipcli-Session 1276903744 965574643 IN IP4 89.163.148.171 s=sipcli c=IN IP4 89.163.148.171 t=0 0 m=audio 5072 RTP/AVP 18 0 8 101 a=fmtp:101 0-15 a=rtpmap:18 G729/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=ptime:20 a=sendrecv ------------------------------------------------------------------------ send 364 bytes to udp/[89.163.148.171]:5070 at 18:12:27.523717: ------------------------------------------------------------------------ SIP/2.0 100 Trying Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Content-Length: 0 ------------------------------------------------------------------------ 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:27.512587 [NOTICE] switch_channel.c:1104 New Channel sofia/internal/90000@134.213.206.157 [6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6] 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:27.512587 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/90000@134.213.206.157) Running State Change CS_NEW 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:27.512587 [DEBUG] sofia.c:9520 sofia/internal/90000@134.213.206.157 receiving invite from 89.163.148.171:5070 version: 1.7.0 -915-35ee4ee 64bit 2016-09-01 18:12:27.512587 [DEBUG] sofia.c:9687 IP 89.163.148.171 Rejected by acl "domains". Falling back to Digest auth. 2016-09-01 18:12:27.512587 [WARNING] sofia_reg.c:1787 SIP auth challenge (INVITE) on sofia profile 'internal' for [00441904891563@134.213.206.157] from ip 89.163.148.171 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:27.512587 [DEBUG] switch_core_state_machine.c:562 (sofia/internal/90000@134.213.206.157) State NEW send 725 bytes to udp/[89.163.148.171]:5070 at 18:12:27.524735: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 ;tag=BBUyy6DQN2rKr Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="134.213.206.157", nonce="c45b1ac3-6b1b-4cac-8ddd-52ce5e5f96da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 2016-09-01 18:12:27.512587 [DEBUG] sofia.c:2248 detaching session 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 recv 560 bytes from udp/[54.171.127.193]:5060 at 18:12:27.793264: ------------------------------------------------------------------------ SIP/2.0 180 Ringing CSeq: 96040706 INVITE Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 From: "" ;tag=Ft6DDX0mX2mXc To: ;tag=17511146_6772d868_457731f5-5d71-4662-9b26-c2603858a736 Via: SIP/2.0/UDP 134.213.206.157:5080;received=134.213.206.157;rport=5080;branch=z9hG4bKvjFNF6BeBc8aK Record-Route: Server: Twilio Contact: X-Twilio-CallSid: CAaa11f79f30a6d8af6d7bcb46422d636e Content-Length: 0 ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:27.792592 [DEBUG] sofia.c:6937 Channel sofia/external/+79001234567 entering state [proceeding][180] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:27.792592 [NOTICE] sofia.c:7045 Ring-Ready sofia/external/+79001234567! 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:27.792592 [DEBUG] switch_channel.c:3343 (sofia/external/+79001234567) Callstate Change DOWN -> RINGING send 725 bytes to udp/[89.163.148.171]:5070 at 18:12:28.024701: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 ;tag=BBUyy6DQN2rKr Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="134.213.206.157", nonce="c45b1ac3-6b1b-4cac-8ddd-52ce5e5f96da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:28.492589 [DEBUG] switch_core_media.c:2474 [VBR]: Correcting calculated ptime value from [40] to [20] to compensate for [1] lost packet(s) send 725 bytes to udp/[89.163.148.171]:5070 at 18:12:29.025178: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 ;tag=BBUyy6DQN2rKr Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="134.213.206.157", nonce="c45b1ac3-6b1b-4cac-8ddd-52ce5e5f96da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ send 725 bytes to udp/[89.163.148.171]:5070 at 18:12:31.026265: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 ;tag=BBUyy6DQN2rKr Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="134.213.206.157", nonce="c45b1ac3-6b1b-4cac-8ddd-52ce5e5f96da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 838 bytes from udp/[54.171.127.193]:5060 at 18:12:32.794562: ------------------------------------------------------------------------ SIP/2.0 200 OK CSeq: 96040706 INVITE Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 From: "" ;tag=Ft6DDX0mX2mXc To: ;tag=17511146_6772d868_457731f5-5d71-4662-9b26-c2603858a736 Via: SIP/2.0/UDP 134.213.206.157:5080;received=134.213.206.157;rport=5080;branch=z9hG4bKvjFNF6BeBc8aK Record-Route: Server: Twilio Contact: Content-Type: application/sdp X-Twilio-CallSid: CAaa11f79f30a6d8af6d7bcb46422d636e Content-Length: 250 v=0 o=- 110710448 110710448 IN IP4 54.171.127.237 s=Twilio Media Gateway c=IN IP4 54.171.127.237 t=0 0 m=audio 15410 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-15 a=maxptime:20 a=ptime:20 a=sendrecv ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] sofia.c:6937 Channel sofia/external/+79001234567 entering state [completing][200] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] sofia.c:6947 Remote SDP: 51d3d083-740d-4133-ab84-a6b169be9de0 v=0 51d3d083-740d-4133-ab84-a6b169be9de0 o=- 110710448 110710448 IN IP4 54.171.127.237 51d3d083-740d-4133-ab84-a6b169be9de0 s=Twilio Media Gateway 51d3d083-740d-4133-ab84-a6b169be9de0 c=IN IP4 54.171.127.237 51d3d083-740d-4133-ab84-a6b169be9de0 t=0 0 51d3d083-740d-4133-ab84-a6b169be9de0 m=audio 15410 RTP/AVP 0 101 51d3d083-740d-4133-ab84-a6b169be9de0 a=rtpmap:0 PCMU/8000 51d3d083-740d-4133-ab84-a6b169be9de0 a=rtpmap:101 telephone-event/8000 51d3d083-740d-4133-ab84-a6b169be9de0 a=fmtp:101 0-15 51d3d083-740d-4133-ab84-a6b169be9de0 a=maxptime:20 51d3d083-740d-4133-ab84-a6b169be9de0 a=ptime:20 51d3d083-740d-4133-ab84-a6b169be9de0 send 861 bytes to udp/[54.171.127.193]:5060 at 18:12:32.795542: ------------------------------------------------------------------------ ACK sip:172.18.197.204:5060 SIP/2.0 Via: SIP/2.0/UDP 134.213.206.157:5080;rport;branch=z9hG4bKXU8DH1vH8myXe Route: Max-Forwards: 70 From: "" ;tag=Ft6DDX0mX2mXc To: ;tag=17511146_6772d868_457731f5-5d71-4662-9b26-c2603858a736 Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 96040706 ACK Contact: Proxy-Authorization: Digest username="02345", realm="sip.twilio.com", nonce="c55064a1af158115e3504b058309bf0f", cnonce="dptBZOsSEjSKNrx2Tgi+wA", opaque="16f00e973dac288064caa33b910f0c68", algorithm=MD5, uri="sip:+79001234567@3waytalk.pstn.ie1.twilio.com", response="d9a0c66afc6892cc9b029b232f4dfaa6", qop=auth, nc=00000001 Content-Length: 0 ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] sofia.c:6937 Channel sofia/external/+79001234567 entering state [ready][200] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:4311 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:4366 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:4227 Set telephone-event payload to 101@8000 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:3018 Set Codec sofia/external/+79001234567 PCMU/8000 20 ms 160 samples 64000 bits 1 channels 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_codec.c:111 sofia/external/+79001234567 Original read codec set to PCMU:0 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:4580 Set telephone-event payload to 101@8000 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:4639 sofia/external/+79001234567 Set 2833 dtmf send payload to 101 recv payload to 101 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:6465 AUDIO RTP [sofia/external/+79001234567] 134.213.206.157 port 21466 -> 54.171.127.237 port 15410 codec: 0 ms: 20 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_rtp.c:3850 Not using a timer 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:1989 Setting Jitterbuffer to 60ms (3 frames) (50 max frames) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:6764 sofia/external/+79001234567 Set 2833 dtmf send payload to 101 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:6771 sofia/external/+79001234567 Set 2833 dtmf receive payload to 101 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_media.c:6794 sofia/external/+79001234567 Set rtp dtmf delay to 40 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [NOTICE] sofia.c:7970 Channel [sofia/external/+79001234567] has been answered 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_channel.c:3770 (sofia/external/+79001234567) Callstate Change RINGING -> ACTIVE 2016-09-01 18:12:32.792593 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/external/+79001234567] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_ivr.c:2160 (sofia/external/+79001234567) State Change CS_CONSUME_MEDIA -> CS_ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [NOTICE] switch_ivr.c:2167 Transfer sofia/external/+79001234567 to XML[9d1e1675fa8a804e12512d65e0388421@external] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:602 (sofia/external/+79001234567) State ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] mod_sofia.c:143 sofia/external/+79001234567 SOFIA ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:236 sofia/external/+79001234567 Standard ROUTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [INFO] mod_dialplan_xml.c:637 Processing <+441277420392>->9d1e1675fa8a804e12512d65e0388421 in context external 51d3d083-740d-4133-ab84-a6b169be9de0 Dialplan: sofia/external/+79001234567 parsing [external->3waycall] continue=false 51d3d083-740d-4133-ab84-a6b169be9de0 Dialplan: sofia/external/+79001234567 Regex (PASS) [3waycall] destination_number(9d1e1675fa8a804e12512d65e0388421) =~ /^(.*)$/ break=on-false 51d3d083-740d-4133-ab84-a6b169be9de0 Dialplan: sofia/external/+79001234567 Action socket(127.0.0.1:8085 async full) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [INFO] switch_channel.c:3127 sofia/external/+79001234567 Flipping CID from "" <+441277420392> to "Outbound Call" <+79001234567> 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:286 (sofia/external/+79001234567) State Change CS_ROUTING -> CS_EXECUTE 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:602 (sofia/external/+79001234567) State ROUTING going to sleep 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_EXECUTE 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:609 (sofia/external/+79001234567) State EXECUTE 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] mod_sofia.c:198 sofia/external/+79001234567 SOFIA EXECUTE 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [DEBUG] switch_core_state_machine.c:328 sofia/external/+79001234567 Standard EXECUTE 51d3d083-740d-4133-ab84-a6b169be9de0 EXECUTE sofia/external/+79001234567 socket(127.0.0.1:8085 async full) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.792593 [NOTICE] mod_event_socket.c:432 Trying host: 127.0.0.1:8085 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.872589 [DEBUG] switch_rtp.c:6711 Correct audio ip/port confirmed. 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.892589 [DEBUG] switch_ivr.c:623 sofia/external/+79001234567 Command Execute set(jitterbuffer_msec=60:200:20) 51d3d083-740d-4133-ab84-a6b169be9de0 EXECUTE sofia/external/+79001234567 set(jitterbuffer_msec=60:200:20) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.892589 [DEBUG] mod_dptools.c:1519 SET sofia/external/+79001234567 [jitterbuffer_msec]=[60:200:20] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.892589 [DEBUG] switch_ivr.c:623 sofia/external/+79001234567 Command Execute answer(undefined) 51d3d083-740d-4133-ab84-a6b169be9de0 EXECUTE sofia/external/+79001234567 answer(undefined) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.952589 [DEBUG] switch_ivr.c:623 sofia/external/+79001234567 Command Execute conference(9d1e1675fa8a804e12512d65e0388421) 51d3d083-740d-4133-ab84-a6b169be9de0 EXECUTE sofia/external/+79001234567 conference(9d1e1675fa8a804e12512d65e0388421) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.952589 [DEBUG] conference_member.c:1654 Raw Codec Activation Success L16@8000hz 1 channel 20ms 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.952589 [DEBUG] conference_member.c:1701 Raw Codec Activation Success L16@48000hz 1 channel 20ms 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.952589 [DEBUG] switch_core_codec.c:221 sofia/external/+79001234567 Push codec L16:100 2016-09-01 18:12:32.952589 [DEBUG] conference_member.c:128 sofia/external/+79001234567 binding '9' to 'energy up' 2016-09-01 18:12:32.952589 [INFO] switch_ivr_async.c:214 Digit parser mod_conference: Setting realm to 'conf' 2016-09-01 18:12:32.952589 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 9/conf/0 callback: 0x7fa3e557ab30 data: 0x7fa3501df450 2016-09-01 18:12:32.952589 [DEBUG] conference_member.c:128 sofia/external/+79001234567 binding '7' to 'energy dn' 2016-09-01 18:12:32.952589 [DEBUG] switch_ivr_async.c:323 Digit parser mod_conference: binding 7/conf/0 callback: 0x7fa3e557ab30 data: 0x7fa3501df480 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.952589 [DEBUG] conference_loop.c:1101 Setup timer soft success interval: 20 samples: 160 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:32.972588 [NOTICE] switch_core_io.c:1202 Activating write resampler 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:33.212590 [DEBUG] conference_member.c:1654 Raw Codec Activation Success L16@8000hz 1 channel 20ms 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:33.212590 [DEBUG] conference_member.c:1701 Raw Codec Activation Success L16@48000hz 1 channel 20ms 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:33.212590 [DEBUG] conference_loop.c:1101 Setup timer soft success interval: 20 samples: 160 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:33.512588 [DEBUG] switch_core_media.c:2474 [VBR]: Correcting calculated ptime value from [40] to [20] to compensate for [1] lost packet(s) send 725 bytes to udp/[89.163.148.171]:5070 at 18:12:35.026549: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 ;tag=BBUyy6DQN2rKr Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="134.213.206.157", nonce="c45b1ac3-6b1b-4cac-8ddd-52ce5e5f96da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [WARNING] switch_core_state_machine.c:646 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 sofia/internal/90000@134.213.206.157 Abandoned 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [NOTICE] switch_core_state_machine.c:649 Hangup sofia/internal/90000@134.213.206.157 [CS_NEW] [WRONG_CALL_STATE] 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/90000@134.213.206.157) Running State Change CS_HANGUP 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/90000@134.213.206.157) Callstate Change DOWN -> HANGUP 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/90000@134.213.206.157) State HANGUP 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] mod_sofia.c:438 Channel sofia/internal/90000@134.213.206.157 hanging up, cause: WRONG_CALL_STATE 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:60 sofia/internal/90000@134.213.206.157 Standard HANGUP, cause: WRONG_CALL_STATE 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/90000@134.213.206.157) State HANGUP going to sleep 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/90000@134.213.206.157) State Change CS_HANGUP -> CS_REPORTING 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/90000@134.213.206.157) Running State Change CS_REPORTING 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/90000@134.213.206.157) State REPORTING 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:174 sofia/internal/90000@134.213.206.157 Standard REPORTING, cause: WRONG_CALL_STATE 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/90000@134.213.206.157) State REPORTING going to sleep 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/90000@134.213.206.157) State Change CS_REPORTING -> CS_DESTROY 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_session.c:1647 Session 213 (sofia/internal/90000@134.213.206.157) Locked, Waiting on external entities 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [NOTICE] switch_core_session.c:1665 Session 213 (sofia/internal/90000@134.213.206.157) Ended 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/90000@134.213.206.157 [CS_DESTROY] 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/90000@134.213.206.157) Running State Change CS_DESTROY 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/90000@134.213.206.157) State DESTROY 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] mod_sofia.c:343 sofia/internal/90000@134.213.206.157 SOFIA DESTROY 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:181 sofia/internal/90000@134.213.206.157 Standard DESTROY 6fa5e3ba-96d2-4ceb-b3c4-a52339fbf6d6 2016-09-01 18:12:37.552595 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/90000@134.213.206.157) State DESTROY going to sleep send 725 bytes to udp/[89.163.148.171]:5070 at 18:12:39.026787: ------------------------------------------------------------------------ SIP/2.0 407 Proxy Authentication Required Via: SIP/2.0/UDP 89.163.148.171:5070;branch=z9hG4bK-7dc16171259d5a30313463c2ec3b752c;rport=5070 From: 90000;tag=217fb9db To: 00441904891563 ;tag=BBUyy6DQN2rKr Call-ID: 7dc16171259d5a30313463c2ec3b752c CSeq: 1 INVITE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Accept: application/sdp Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Allow-Events: talk, hold, conference, refer Proxy-Authenticate: Digest realm="134.213.206.157", nonce="c45b1ac3-6b1b-4cac-8ddd-52ce5e5f96da", algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 765 bytes from wss/[46.159.161.140]:56849 at 18:12:39.655113: ------------------------------------------------------------------------ REGISTER sip:3waytalk.com SIP/2.0 Via: SIP/2.0/WSS bvhvt1dfbk4m.invalid;branch=z9hG4bK5077393 Max-Forwards: 70 To: From: ;tag=58kqj6906r Call-ID: tpvh45d1k0vvdqmpf5m86u CSeq: 85 REGISTER Authorization: Digest algorithm=MD5, username="2183", realm="3waytalk.com", nonce="6b337996-e90b-4087-aada-a5875132f88e", uri="sip:3waytalk.com", response="a9959700b600305be674905d5b2f249d", qop=auth, cnonce="0ea45i7s00l1", nc=00000001 Contact: ;reg-id=1;+sip.instance="";expires=60 Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Supported: path, gruu, outbound User-Agent: SIP.js/0.7.5 Content-Length: 0 ------------------------------------------------------------------------ 2016-09-01 18:12:39.652592 [WARNING] sofia_reg.c:1787 SIP auth challenge (REGISTER) on sofia profile 'internal' for [2183@3waytalk.com] from ip 46.159.161.140 send 603 bytes to wss/[46.159.161.140]:56849 at 18:12:39.656184: ------------------------------------------------------------------------ SIP/2.0 401 Unauthorized Via: SIP/2.0/WSS bvhvt1dfbk4m.invalid;branch=z9hG4bK5077393;received=46.159.161.140;rport=56849 From: ;tag=58kqj6906r To: ;tag=cmmQ01ytjBF6K Call-ID: tpvh45d1k0vvdqmpf5m86u CSeq: 85 REGISTER User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces WWW-Authenticate: Digest realm="3waytalk.com", nonce="5fe3e0b3-977b-4899-819a-d42ccb5d24fb", stale=true, algorithm=MD5, qop="auth" Content-Length: 0 ------------------------------------------------------------------------ recv 765 bytes from wss/[46.159.161.140]:56849 at 18:12:39.755273: ------------------------------------------------------------------------ REGISTER sip:3waytalk.com SIP/2.0 Via: SIP/2.0/WSS bvhvt1dfbk4m.invalid;branch=z9hG4bK9356754 Max-Forwards: 70 To: From: ;tag=58kqj6906r Call-ID: tpvh45d1k0vvdqmpf5m86u CSeq: 86 REGISTER Authorization: Digest algorithm=MD5, username="2183", realm="3waytalk.com", nonce="5fe3e0b3-977b-4899-819a-d42ccb5d24fb", uri="sip:3waytalk.com", response="4e3457b5b3a26693298600d4a866f67a", qop=auth, cnonce="7dov08ackk02", nc=00000001 Contact: ;reg-id=1;+sip.instance="";expires=60 Allow: ACK,CANCEL,INVITE,MESSAGE,BYE,OPTIONS,INFO,NOTIFY,REFER Supported: path, gruu, outbound User-Agent: SIP.js/0.7.5 Content-Length: 0 ------------------------------------------------------------------------ 2016-09-01 18:12:39.752589 [NOTICE] switch_cpp.cpp:1360 directory request 2016-09-01 18:12:39.892592 [NOTICE] switch_cpp.cpp:1360 Authenticated user 2183 send 568 bytes to wss/[46.159.161.140]:56849 at 18:12:39.903212: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/WSS bvhvt1dfbk4m.invalid;branch=z9hG4bK9356754;received=46.159.161.140;rport=56849 From: ;tag=58kqj6906r To: ;tag=DXDg2vFyFm5rF Call-ID: tpvh45d1k0vvdqmpf5m86u CSeq: 86 REGISTER Contact: ;expires=60 Date: Thu, 01 Sep 2016 18:12:39 GMT User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ recv 687 bytes from udp/[54.171.127.193]:5060 at 18:12:40.236422: ------------------------------------------------------------------------ BYE sip:gw+Twilio-outbound@134.213.206.157:5080;transport=udp;gw=Twilio-outbound SIP/2.0 CSeq: 1 BYE From: ;tag=17511146_6772d868_457731f5-5d71-4662-9b26-c2603858a736 To: "" ;tag=Ft6DDX0mX2mXc Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 Max-Forwards: 68 Via: SIP/2.0/UDP 54.171.127.193:5060;branch=z9hG4bK54a8.126ea8b.0 Via: SIP/2.0/UDP 172.18.197.204:5060;rport=5060;received=54.171.127.237;branch=z9hG4bK457731f5-5d71-4662-9b26-c2603858a736_6772d868_566126959637384 Reason: Q.850;cause=16 User-Agent: Twilio Gateway X-Twilio-CallSid: CAaa11f79f30a6d8af6d7bcb46422d636e Content-Length: 0 ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [NOTICE] sofia.c:988 Hangup sofia/external/+79001234567 [CS_EXECUTE] [NORMAL_CLEARING] send 661 bytes to udp/[54.171.127.193]:5060 at 18:12:40.237598: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/UDP 54.171.127.193:5060;branch=z9hG4bK54a8.126ea8b.0 Via: SIP/2.0/UDP 172.18.197.204:5060;rport=5060;received=54.171.127.237;branch=z9hG4bK457731f5-5d71-4662-9b26-c2603858a736_6772d868_566126959637384 From: ;tag=17511146_6772d868_457731f5-5d71-4662-9b26-c2603858a736 To: "" ;tag=Ft6DDX0mX2mXc Call-ID: 766f85b5-eb12-1234-368a-bc764e08bec0 CSeq: 1 BYE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REFER, NOTIFY Supported: timer, path, replaces Content-Length: 0 ------------------------------------------------------------------------ 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [INFO] conference_loop.c:1400 Channel leaving conference, cause: NORMAL_CLEARING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] mod_conference.c:2215 sofia/external/+79001234567 skip receive message [UNBRIDGE] (channel is hungup already) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_media.c:9330 sofia/external/+79001234567 skip receive message [HARD_MUTE] (channel is hungup already) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_codec.c:258 Restore original codec. 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_session.c:2797 sofia/external/+79001234567 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_ivr.c:666 sofia/external/+79001234567 skip receive message [AUDIO_SYNC] (channel is hungup already) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_session.c:2797 sofia/external/+79001234567 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:609 (sofia/external/+79001234567) State EXECUTE going to sleep 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_HANGUP 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:809 (sofia/external/+79001234567) Callstate Change ACTIVE -> HANGUP 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:811 (sofia/external/+79001234567) State HANGUP 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] mod_sofia.c:438 Channel sofia/external/+79001234567 hanging up, cause: NORMAL_CLEARING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:60 sofia/external/+79001234567 Standard HANGUP, cause: NORMAL_CLEARING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:811 (sofia/external/+79001234567) State HANGUP going to sleep 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:578 (sofia/external/+79001234567) State Change CS_HANGUP -> CS_REPORTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:543 (sofia/external/+79001234567) Running State Change CS_REPORTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:897 (sofia/external/+79001234567) State REPORTING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:174 sofia/external/+79001234567 Standard REPORTING, cause: NORMAL_CLEARING 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:897 (sofia/external/+79001234567) State REPORTING going to sleep 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_state_machine.c:569 (sofia/external/+79001234567) State Change CS_REPORTING -> CS_DESTROY 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.232589 [DEBUG] switch_core_session.c:1647 Session 212 (sofia/external/+79001234567) Locked, Waiting on external entities 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.252589 [DEBUG] mod_event_socket.c:1441 sofia/external/+79001234567 Socket Linger -1 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [NOTICE] switch_core_session.c:1665 Session 212 (sofia/external/+79001234567) Ended 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [NOTICE] switch_core_session.c:1669 Close Channel sofia/external/+79001234567 [CS_DESTROY] 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [DEBUG] switch_core_state_machine.c:700 (sofia/external/+79001234567) Running State Change CS_DESTROY 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [DEBUG] switch_core_state_machine.c:710 (sofia/external/+79001234567) State DESTROY 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [DEBUG] mod_sofia.c:343 sofia/external/+79001234567 SOFIA DESTROY 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [DEBUG] switch_core_state_machine.c:181 sofia/external/+79001234567 Standard DESTROY 51d3d083-740d-4133-ab84-a6b169be9de0 2016-09-01 18:12:40.452593 [DEBUG] switch_core_state_machine.c:710 (sofia/external/+79001234567) State DESTROY going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.512591 [DEBUG] switch_ivr.c:623 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Command Execute hangup(undefined) 5b8b1c43-a010-4570-b282-6eb4a965a4db EXECUTE sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid hangup(undefined) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.512591 [NOTICE] mod_dptools.c:1283 Hangup sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid [CS_EXECUTE] [NORMAL_CLEARING] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.512591 [DEBUG] switch_core_session.c:2797 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.532589 [INFO] conference_loop.c:1400 Channel leaving conference, cause: NONE a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.532589 [DEBUG] switch_core_media.c:9697 sofia/internal/280@3waytalk.com RESUME Jitterbuffer a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.532589 [DEBUG] switch_core_codec.c:246 sofia/internal/280@3waytalk.com Restore previous codec opus:116. 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [INFO] conference_loop.c:1400 Channel leaving conference, cause: NORMAL_CLEARING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] mod_conference.c:2215 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid skip receive message [UNBRIDGE] (channel is hungup already) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_media.c:9330 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid skip receive message [HARD_MUTE] (channel is hungup already) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_codec.c:246 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Restore previous codec opus:116. 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_session.c:2797 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_ivr.c:666 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid skip receive message [AUDIO_SYNC] (channel is hungup already) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_session.c:2797 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State EXECUTE going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_HANGUP 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Callstate Change ACTIVE -> HANGUP 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State HANGUP 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] mod_sofia.c:438 Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid hanging up, cause: NORMAL_CLEARING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:60 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Standard HANGUP, cause: NORMAL_CLEARING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State HANGUP going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_HANGUP -> CS_REPORTING send 611 bytes to wss/[46.159.161.140]:56849 at 18:12:43.548930: ------------------------------------------------------------------------ 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_REPORTING BYE sip:qiin1j5e@bvhvt1dfbk4m.invalid;transport=ws SIP/2.0 Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK72BeDeZtjK86j Max-Forwards: 70 From: "incoming call (Russian)" ;tag=a215vBXKrS20c To: ;tag=fm2qiedr5v Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040698 BYE User-Agent: FreeSWITCH-mod_sofia/1.7.0-915-35ee4ee~64bit Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported: timer, path, replaces Reason: Q.850;cause=16;text="NORMAL_CLEARING" Content-Length: 0 ------------------------------------------------------------------------ 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State REPORTING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:174 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Standard REPORTING, cause: NORMAL_CLEARING 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State REPORTING going to sleep 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State Change CS_REPORTING -> CS_DESTROY 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] switch_core_session.c:1647 Session 211 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Locked, Waiting on external entities 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.532589 [DEBUG] mod_event_socket.c:1441 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Socket Linger -1 a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_ivr_bridge.c:706 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid ending bridge by request from write function a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_ivr_bridge.c:785 BRIDGE THREAD DONE [sofia/internal/280@3waytalk.com] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_ivr.c:623 sofia/internal/280@3waytalk.com Command Execute hangup(undefined) a39771e4-fbf1-4964-b499-e9843b7bfe59 EXECUTE sofia/internal/280@3waytalk.com hangup(undefined) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [NOTICE] mod_dptools.c:1283 Hangup sofia/internal/280@3waytalk.com [CS_EXECUTE] [NORMAL_CLEARING] 2016-09-01 18:12:43.552586 [DEBUG] mod_conference.c:782 Write Lock ON a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_session.c:2797 sofia/internal/280@3waytalk.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_ivr.c:666 sofia/internal/280@3waytalk.com skip receive message [AUDIO_SYNC] (channel is hungup already) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_ivr.c:666 sofia/internal/280@3waytalk.com skip receive message [AUDIO_SYNC] (channel is hungup already) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_session.c:2797 sofia/internal/280@3waytalk.com skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already) a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:609 (sofia/internal/280@3waytalk.com) State EXECUTE going to sleep a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/280@3waytalk.com) Running State Change CS_HANGUP a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:809 (sofia/internal/280@3waytalk.com) Callstate Change ACTIVE -> HANGUP a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/280@3waytalk.com) State HANGUP a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] mod_sofia.c:438 Channel sofia/internal/280@3waytalk.com hanging up, cause: NORMAL_CLEARING 2016-09-01 18:12:43.552586 [INFO] conference_record.c:394 Recording of {channels=1,samplerate=48000,vw=0,vh=0,fps=0.00}/var/www/recordings/9d1e1675fa8a804e12512d65e0388421.wav Stopped a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] mod_sofia.c:491 Sending BYE to sofia/internal/280@3waytalk.com 2016-09-01 18:12:43.552586 [DEBUG] mod_conference.c:785 Write Lock OFF a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:60 sofia/internal/280@3waytalk.com Standard HANGUP, cause: NORMAL_CLEARING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:811 (sofia/internal/280@3waytalk.com) State HANGUP going to sleep a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:578 (sofia/internal/280@3waytalk.com) State Change CS_HANGUP -> CS_REPORTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:543 (sofia/internal/280@3waytalk.com) Running State Change CS_REPORTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/280@3waytalk.com) State REPORTING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:174 sofia/internal/280@3waytalk.com Standard REPORTING, cause: NORMAL_CLEARING a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:897 (sofia/internal/280@3waytalk.com) State REPORTING going to sleep a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_state_machine.c:569 (sofia/internal/280@3waytalk.com) State Change CS_REPORTING -> CS_DESTROY a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] switch_core_session.c:1647 Session 210 (sofia/internal/280@3waytalk.com) Locked, Waiting on external entities a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.552586 [DEBUG] mod_event_socket.c:1441 sofia/internal/280@3waytalk.com Socket Linger -1 recv 367 bytes from wss/[46.159.161.140]:56849 at 18:12:43.645543: ------------------------------------------------------------------------ SIP/2.0 200 OK Via: SIP/2.0/WSS 134.213.206.157:7443;rport;branch=z9hG4bK72BeDeZtjK86j To: ;tag=fm2qiedr5v From: "incoming call (Russian)" ;tag=a215vBXKrS20c Call-ID: 6d2f7341-eb12-1234-368a-bc764e08bec0 CSeq: 96040698 BYE Supported: outbound User-Agent: SIP.js/0.7.5 Content-Length: 0 ------------------------------------------------------------------------ a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [NOTICE] switch_core_session.c:1665 Session 210 (sofia/internal/280@3waytalk.com) Ended a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/280@3waytalk.com [CS_DESTROY] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [NOTICE] switch_core_session.c:1665 Session 211 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Ended 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [NOTICE] switch_core_session.c:1669 Close Channel sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid [CS_DESTROY] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/280@3waytalk.com) Running State Change CS_DESTROY 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:700 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) Running State Change CS_DESTROY 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State DESTROY 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] mod_sofia.c:343 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid SOFIA DESTROY 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[1551] PLC[0] FEC[0] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/280@3waytalk.com) State DESTROY a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] mod_sofia.c:343 sofia/internal/280@3waytalk.com SOFIA DESTROY a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[1951] PLC[0] FEC[0] a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0] 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:181 sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid Standard DESTROY 5b8b1c43-a010-4570-b282-6eb4a965a4db 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/qiin1j5e@bvhvt1dfbk4m.invalid) State DESTROY going to sleep a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:181 sofia/internal/280@3waytalk.com Standard DESTROY a39771e4-fbf1-4964-b499-e9843b7bfe59 2016-09-01 18:12:43.932588 [DEBUG] switch_core_state_machine.c:710 (sofia/internal/280@3waytalk.com) State DESTROY going to sleep