2017-10-05 10:59:55.444212 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/1003.csv 2017-10-05 10:59:55.444212 [NOTICE] mod_logfile.c:192 New log started. 2017-10-05 11:00:01.964211 [ALERT] mod_verto.c:1405 READ 192.168.1.1:55563 [{ "jsonrpc": "2.0", "method": "verto.invite", "params": { "sdp": "v=0\r\no=- 2752367973978024640 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK\r\nm=audio 51686 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126\r\nc=IN IP4 65.15.69.32\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=candidate:3676716184 1 udp 2122255103 2001::9d38:6ab8:2857:2624:bef0:badf 51685 typ host generation 0 network-id 1 network-cost 50\r\na=candidate:3687888086 1 udp 2122194687 192.168.1.123 51686 typ host generation 0 network-id 2\r\na=candidate:1519956578 1 udp 1685987071 65.15.69.32 51686 typ srflx raddr 192.168.1.123 rport 51686 generation 0 network-id 2\r\na=candidate:2510667880 1 tcp 1518275327 2001::9d38:6ab8:2857:2624:bef0:badf 9 typ host tcptype active generation 0 network-id 1 network-cost 50\r\na=candidate:2505263142 1 tcp 1518214911 192.168.1.123 9 typ host tcptype active generation 0 network-id 2\r\na=ice-ufrag:iTlu\r\na=ice-pwd:2z9+7ZinoPf0BfuMNQlkVeq6\r\na=ice-options:trickle\r\na=fingerprint:sha-256 DE:E3:A2:8A:E4:1F:94:68:CE:16:A6:74:7B:B1:25:A1:FC:F7:90:10:06:C0:F3:EB:F9:27:77:9F:1E:39:3D:92\r\na=setup:actpass\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=rtcp-fb:111 transport-cc\r\na=fmtp:111 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:106 CN/32000\r\na=rtpmap:105 CN/16000\r\na=rtpmap:13 CN/8000\r\na=rtpmap:110 telephone-event/48000\r\na=rtpmap:112 telephone-event/32000\r\na=rtpmap:113 telephone-event/16000\r\na=rtpmap:126 telephone-event/8000\r\na=ssrc:395565095 cname:aJLaOP3UK2dzvkhh\r\na=ssrc:395565095 msid:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK 7a7af0af-b247-4dc4-9916-3c10cbc478a5\r\na=ssrc:395565095 mslabel:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK\r\na=ssrc:395565095 label:7a7af0af-b247-4dc4-9916-3c10cbc478a5\r\nm=video 51688 UDP/TLS/RTP/SAVPF 96 98 100 102 127 97 99 101 125\r\nc=IN IP4 65.15.69.32\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=candidate:3676716184 1 udp 2122255103 2001::9d38:6ab8:2857:2624:bef0:badf 51687 typ host generation 0 network-id 1 network-cost 50\r\na=candidate:3687888086 1 udp 2122194687 192.168.1.123 51688 typ host generation 0 network-id 2\r\na=candidate:1519956578 1 udp 1685987071 65.15.69.32 51688 typ srflx raddr 192.168.1.123 rport 51688 generation 0 network-id 2\r\na=candidate:2510667880 1 tcp 1518275327 2001::9d38:6ab8:2857:2624:bef0:badf 9 typ host tcptype active generation 0 network-id 1 network-cost 50\r\na=candidate:2505263142 1 tcp 1518214911 192.168.1.123 9 typ host tcptype active generation 0 network-id 2\r\na=ice-ufrag:iTlu\r\na=ice-pwd:2z9+7ZinoPf0BfuMNQlkVeq6\r\na=ice-options:trickle\r\na=fingerprint:sha-256 DE:E3:A2:8A:E4:1F:94:68:CE:16:A6:74:7B:B1:25:A1:FC:F7:90:10:06:C0:F3:EB:F9:27:77:9F:1E:39:3D:92\r\na=setup:actpass\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:4 urn:3gpp:video-orientation\r\na=extmap:5 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01\r\na=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay\r\na=sendrecv\r\na=rtcp-mux\r\na=rtcp-rsize\r\na=rtpmap:96 VP8/90000\r\na=rtcp-fb:96 ccm fir\r\na=rtcp-fb:96 nack\r\na=rtcp-fb:96 nack pli\r\na=rtcp-fb:96 goog-remb\r\na=rtcp-fb:96 transport-cc\r\na=rtpmap:98 VP9/90000\r\na=rtcp-fb:98 ccm fir\r\na=rtcp-fb:98 nack\r\na=rtcp-fb:98 nack pli\r\na=rtcp-fb:98 goog-remb\r\na=rtcp-fb:98 transport-cc\r\na=rtpmap:100 H264/90000\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 nack pli\r\na=rtcp-fb:100 goog-remb\r\na=rtcp-fb:100 transport-cc\r\na=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\r\na=rtpmap:102 red/90000\r\na=rtpmap:127 ulpfec/90000\r\na=rtpmap:97 rtx/90000\r\na=fmtp:97 apt=96\r\na=rtpmap:99 rtx/90000\r\na=fmtp:99 apt=98\r\na=rtpmap:101 rtx/90000\r\na=fmtp:101 apt=100\r\na=rtpmap:125 rtx/90000\r\na=fmtp:125 apt=102\r\na=ssrc-group:FID 2784642864 1476148818\r\na=ssrc:2784642864 cname:aJLaOP3UK2dzvkhh\r\na=ssrc:2784642864 msid:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK 7d0e195f-df11-4940-993d-aee0e4ed4857\r\na=ssrc:2784642864 mslabel:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK\r\na=ssrc:2784642864 label:7d0e195f-df11-4940-993d-aee0e4ed4857\r\na=ssrc:1476148818 cname:aJLaOP3UK2dzvkhh\r\na=ssrc:1476148818 msid:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK 7d0e195f-df11-4940-993d-aee0e4ed4857\r\na=ssrc:1476148818 mslabel:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK\r\na=ssrc:1476148818 label:7d0e195f-df11-4940-993d-aee0e4ed4857\r\n", "dialogParams": { "useVideo": true, "useStereo": true, "screenShare": false, "useCamera": "045df2abc86d39fe84a007c577623bbed07263394e09491bf7508947970b2d5f", "useMic": "default", "useSpeak": "default", "tag": "webcam", "localTag": null, "login": "1001@baremetal.joshebosh.com", "videoParams": { "minWidth": 160, "minHeight": 120, "maxWidth": 160, "maxHeight": 120, "minFrameRate": 15 }, "destination_number": "1002", "caller_id_name": "1001", "caller_id_number": "joshua@freeswitch.org", "outgoingBandwidth": "250", "incomingBandwidth": "250", "dedEnc": true, "mirrorInput": false, "userVariables": { "email": "joshua@freeswitch.org", "avatar": "http://gravatar.com/avatar/4d744e87a0efca67c7418f2d8e098a98.png?s=600" }, "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "remote_caller_id_name": "Outbound Call", "remote_caller_id_number": "1002" }, "sessid": "8f00da09-b94a-6eac-7246-f8f6f4d3ad78" }, "id": 22 }] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] mod_rtc.c:392 () State Change CS_NEW -> CS_INIT a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_session.c:641 N/A set UUID=a64a2d13-097c-fad5-4a2e-4b9912283ade a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/1002 [a64a2d13-097c-fad5-4a2e-4b9912283ade] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] mod_verto.c:3761 Remote SDP verto.rtc/1002: a64a2d13-097c-fad5-4a2e-4b9912283ade v=0 a64a2d13-097c-fad5-4a2e-4b9912283ade o=- 2752367973978024640 2 IN IP4 127.0.0.1 a64a2d13-097c-fad5-4a2e-4b9912283ade s=- a64a2d13-097c-fad5-4a2e-4b9912283ade t=0 0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=group:BUNDLE audio video a64a2d13-097c-fad5-4a2e-4b9912283ade a=msid-semantic: WMS rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK a64a2d13-097c-fad5-4a2e-4b9912283ade m=audio 51686 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 a64a2d13-097c-fad5-4a2e-4b9912283ade c=IN IP4 65.15.69.32 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp:9 IN IP4 0.0.0.0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:3676716184 1 udp 2122255103 2001::9d38:6ab8:2857:2624:bef0:badf 51685 typ host generation 0 network-id 1 network-cost 50 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:3687888086 1 udp 2122194687 192.168.1.123 51686 typ host generation 0 network-id 2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:1519956578 1 udp 1685987071 65.15.69.32 51686 typ srflx raddr 192.168.1.123 rport 51686 generation 0 network-id 2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:2510667880 1 tcp 1518275327 2001::9d38:6ab8:2857:2624:bef0:badf 9 typ host tcptype active generation 0 network-id 1 network-cost 50 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:2505263142 1 tcp 1518214911 192.168.1.123 9 typ host tcptype active generation 0 network-id 2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-ufrag:iTlu a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-pwd:2z9+7ZinoPf0BfuMNQlkVeq6 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-options:trickle a64a2d13-097c-fad5-4a2e-4b9912283ade a=fingerprint:sha-256 DE:E3:A2:8A:E4:1F:94:68:CE:16:A6:74:7B:B1:25:A1:FC:F7:90:10:06:C0:F3:EB:F9:27:77:9F:1E:39:3D:92 a64a2d13-097c-fad5-4a2e-4b9912283ade a=setup:actpass a64a2d13-097c-fad5-4a2e-4b9912283ade a=mid:audio a64a2d13-097c-fad5-4a2e-4b9912283ade a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a64a2d13-097c-fad5-4a2e-4b9912283ade a=sendrecv a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-mux a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:111 opus/48000/2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:111 transport-cc a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:111 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:103 ISAC/16000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:104 ISAC/32000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:9 G722/8000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:0 PCMU/8000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:8 PCMA/8000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:106 CN/32000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:105 CN/16000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:13 CN/8000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:110 telephone-event/48000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:112 telephone-event/32000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:113 telephone-event/16000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:126 telephone-event/8000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:395565095 cname:aJLaOP3UK2dzvkhh a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:395565095 msid:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK 7a7af0af-b247-4dc4-9916-3c10cbc478a5 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:395565095 mslabel:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:395565095 label:7a7af0af-b247-4dc4-9916-3c10cbc478a5 a64a2d13-097c-fad5-4a2e-4b9912283ade m=video 51688 UDP/TLS/RTP/SAVPF 96 98 100 102 127 97 99 101 125 a64a2d13-097c-fad5-4a2e-4b9912283ade c=IN IP4 65.15.69.32 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp:9 IN IP4 0.0.0.0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:3676716184 1 udp 2122255103 2001::9d38:6ab8:2857:2624:bef0:badf 51687 typ host generation 0 network-id 1 network-cost 50 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:3687888086 1 udp 2122194687 192.168.1.123 51688 typ host generation 0 network-id 2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:1519956578 1 udp 1685987071 65.15.69.32 51688 typ srflx raddr 192.168.1.123 rport 51688 generation 0 network-id 2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:2510667880 1 tcp 1518275327 2001::9d38:6ab8:2857:2624:bef0:badf 9 typ host tcptype active generation 0 network-id 1 network-cost 50 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:2505263142 1 tcp 1518214911 192.168.1.123 9 typ host tcptype active generation 0 network-id 2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-ufrag:iTlu a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-pwd:2z9+7ZinoPf0BfuMNQlkVeq6 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-options:trickle a64a2d13-097c-fad5-4a2e-4b9912283ade a=fingerprint:sha-256 DE:E3:A2:8A:E4:1F:94:68:CE:16:A6:74:7B:B1:25:A1:FC:F7:90:10:06:C0:F3:EB:F9:27:77:9F:1E:39:3D:92 a64a2d13-097c-fad5-4a2e-4b9912283ade a=setup:actpass a64a2d13-097c-fad5-4a2e-4b9912283ade a=mid:video a64a2d13-097c-fad5-4a2e-4b9912283ade a=extmap:2 urn:ietf:params:rtp-hdrext:toffset a64a2d13-097c-fad5-4a2e-4b9912283ade a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a64a2d13-097c-fad5-4a2e-4b9912283ade a=extmap:4 urn:3gpp:video-orientation a64a2d13-097c-fad5-4a2e-4b9912283ade a=extmap:5 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a64a2d13-097c-fad5-4a2e-4b9912283ade a=extmap:6 http://www.webrtc.org/experiments/rtp-hdrext/playout-delay a64a2d13-097c-fad5-4a2e-4b9912283ade a=sendrecv a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-mux a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-rsize a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:96 VP8/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:96 ccm fir a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:96 nack a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:96 nack pli a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:96 goog-remb a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:96 transport-cc a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:98 VP9/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:98 ccm fir a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:98 nack a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:98 nack pli a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:98 goog-remb a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:98 transport-cc a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:100 H264/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 ccm fir a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 nack a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 nack pli a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 goog-remb a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 transport-cc a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:102 red/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:127 ulpfec/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:97 rtx/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:97 apt=96 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:99 rtx/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:99 apt=98 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:101 rtx/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:101 apt=100 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:125 rtx/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:125 apt=102 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc-group:FID 2784642864 1476148818 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:2784642864 cname:aJLaOP3UK2dzvkhh a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:2784642864 msid:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK 7d0e195f-df11-4940-993d-aee0e4ed4857 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:2784642864 mslabel:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:2784642864 label:7d0e195f-df11-4940-993d-aee0e4ed4857 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:1476148818 cname:aJLaOP3UK2dzvkhh a=ssrc:1476148818 msid:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK 7d0e195f-df11-4940-993d-aee0e4ed4857 a=ssrc:1476148818 mslabel:rMHRy69szr2SCaZAwfD563M8TUKF6elR9hfK a=ssrc:1476148818 label:7d0e195f-df11-4940-993d-aee0e4ed4857 2017-10-05 11:00:01.964211 [ALERT] mod_verto.c:601 WRITE 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 22, "result": { "message": "CALL CREATED", "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "sessid": "8f00da09-b94a-6eac-7246-f8f6f4d3ad78" } }] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1002) Running State Change CS_INIT (Cur 1 Tot 803) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/1002) State INIT a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_state_machine.c:40 verto.rtc/1002 Standard INIT a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/1002) State Change CS_INIT -> CS_ROUTING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/1002) State INIT going to sleep a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.964211 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1002) Running State Change CS_ROUTING (Cur 1 Tot 803) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_channel.c:2249 (verto.rtc/1002) Callstate Change DOWN -> RINGING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/1002) State ROUTING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_rtc.c:89 verto.rtc/1002 RTC ROUTING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:236 verto.rtc/1002 Standard ROUTING 2017-10-05 11:00:01.974180 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1001@192.168.1.113 { "data": { "channelCallState": "RINGING", "originalChannelCallState": "DOWN", "channelState": "CS_ROUTING", "callerUserName": "1001@192.168.1.113", "callerIDName": "1001", "callerIDNumber": "joshua@freeswitch.org", "calleeIDName": "Outbound Call", "calleeIDNumber": "1002", "channelUUID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "presenceCallDirection": "inbound", "channelPresenceID": "1001@192.168.1.113" }, "eventChannel": "presence.1001@192.168.1.113" } a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [INFO] mod_dialplan_xml.c:637 Processing 1001 ->1002 in context default a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->api-on-answer-test] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [api-on-answer-test] destination_number(1002) =~ /^(779)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->fifo_test_agent] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [fifo_test_agent] destination_number(1002) =~ /^(777)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->fifo_test_caller] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [fifo_test_caller] destination_number(1002) =~ /^(778)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->amd_test] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [amd_test] destination_number(1002) =~ /^(amd_test)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->flowroute.com] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [flowroute.com] destination_number(1002) =~ /^(\+?1?\d{11})$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->perl_test] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [perl_test] destination_number(1002) =~ /^(595)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->test flac play] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [test flac play] destination_number(1002) =~ /^(596)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->test flac record] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [test flac record] destination_number(1002) =~ /^(597)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->test lua] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [test lua] destination_number(1002) =~ /^(598)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->123_screen] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [123_screen] destination_number(1002) =~ /^(3600)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->conf_bridger] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [conf_bridger] destination_number(1002) =~ /^599$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->cdquality_stereo_conferences] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [cdquality_stereo_conferences] destination_number(1002) =~ /^599-screen$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->unloop] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (PASS) [unloop] ${unroll_loops}(true) =~ /^true$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [unloop] ${sip_looped_call}() =~ /^true$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->tod_example] continue=true a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Date/Time Match (PASS) [tod_example] break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(open=true) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->holiday_example] continue=true a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Date/TimeMatch (FAIL) [holiday_example] break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->global-intercept] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [global-intercept] destination_number(1002) =~ /^886$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->group-intercept] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [group-intercept] destination_number(1002) =~ /^\*8$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->intercept-ext] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [intercept-ext] destination_number(1002) =~ /^\*\*(\d+)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->redial] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [redial] destination_number(1002) =~ /^(redial|870)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->global] continue=true a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [global] ${call_debug}(false) =~ /^true$/ break=never a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [global] ${default_password}(j0sh3b0sh) =~ /^1234$/ break=never a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [global] ${rtp_has_crypto}() =~ /^(AEAD_AES_256_GCM_8|AEAD_AES_128_GCM_8|AES_CM_256_HMAC_SHA1_80|AES_CM_192_HMAC_SHA1_80|AES_CM_128_HMAC_SHA1_80|AES_CM_256_HMAC_SHA1_32|AES_CM_192_HMAC_SHA1_32|AES_CM_128_HMAC_SHA1_32|AES_CM_128_NULL_AUTH)$/ break=never a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [global] ${endpoint_disposition}() =~ /^(DELAYED NEGOTIATION)/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->snom-demo-2] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [snom-demo-2] destination_number(1002) =~ /^9001$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->snom-demo-1] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [snom-demo-1] destination_number(1002) =~ /^9000$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->eavesdrop] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^88(\d{4})$|^\*0(.*)$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->eavesdrop] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [eavesdrop] destination_number(1002) =~ /^779$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->call_return] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [call_return] destination_number(1002) =~ /^\*69$|^869$|^lcr$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->del-group] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [del-group] destination_number(1002) =~ /^80(\d{2})$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->add-group] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [add-group] destination_number(1002) =~ /^81(\d{2})$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->call-group-simo] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [call-group-simo] destination_number(1002) =~ /^82(\d{2})$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->call-group-order] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [call-group-order] destination_number(1002) =~ /^83(\d{2})$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->extension-intercom] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (FAIL) [extension-intercom] destination_number(1002) =~ /^8(10[01][0-9])$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 parsing [default->Local_Extension] continue=false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Regex (PASS) [Local_Extension] destination_number(1002) =~ /^(10[01][0-9])$/ break=on-false a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action export(dialed_extension=1002) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bind_meta_app(1 b s execute_extension::dx XML features) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/${caller_id_number}.${strftime(%Y-%m-%d-%H-%M-%S)}.wav) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bind_meta_app(3 b s execute_extension::cf XML features) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bind_meta_app(4 b s execute_extension::att_xfer XML features) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(ringback=${us-ring}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(transfer_ringback=/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(call_timeout=30) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(hangup_after_bridge=true) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(continue_on_fail=true) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(called_party_callgroup=${user_data(${dialed_extension}@${domain_name} var callgroup)}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action hash(insert/${domain_name}-last_dial_ext/${called_party_callgroup}/${uuid}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action hash(insert/${domain_name}-last_dial_ext/global/${uuid}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action hash(insert/${domain_name}-last_dial/${called_party_callgroup}/${uuid}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(media_bug_answer_req=true) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(record_concat_video=true) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action set(record_file_name=/var/www/html/fs/${strftime(%Y-%m-%d-%H-%M-%S)}_${uuid}.mp4) INLINE a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(record_file_name=/var/www/html/fs/2017-10-05-11-00-01_a64a2d13-097c-fad5-4a2e-4b9912283ade.mp4) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [record_file_name]=[/var/www/html/fs/2017-10-05-11-00-01_a64a2d13-097c-fad5-4a2e-4b9912283ade.mp4] a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action answer() a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bridge(user/${dialed_extension}@${domain_name}) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action sleep(1000) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bridge(user/1003@192.168.150.3) a64a2d13-097c-fad5-4a2e-4b9912283ade Dialplan: verto.rtc/1002 Action bridge(loopback/app=voicemail:default ${domain_name} ${dialed_extension}) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:286 (verto.rtc/1002) State Change CS_ROUTING -> CS_EXECUTE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/1002) State ROUTING going to sleep a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1002) Running State Change CS_EXECUTE (Cur 1 Tot 803) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:650 (verto.rtc/1002) State EXECUTE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_rtc.c:120 verto.rtc/1002 RTC EXECUTE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_core_state_machine.c:328 verto.rtc/1002 Standard EXECUTE a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(open=true) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [open]=[true] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 export(dialed_extension=1002) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] switch_channel.c:1296 EXPORT (export_vars) [dialed_extension]=[1002] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 bind_meta_app(1 b s execute_extension::dx XML features) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *1 execute_extension::dx XML features a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 bind_meta_app(2 b s record_session::/usr/local/freeswitch/recordings/joshua@freeswitch.org.2017-10-05-11-00-01.wav) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *2 record_session::/usr/local/freeswitch/recordings/joshua@freeswitch.org.2017-10-05-11-00-01.wav a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 bind_meta_app(3 b s execute_extension::cf XML features) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *3 execute_extension::cf XML features a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 bind_meta_app(4 b s execute_extension::att_xfer XML features) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [INFO] switch_ivr_async.c:4273 Bound B-Leg: *4 execute_extension::att_xfer XML features a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(ringback=%(2000,4000,440,480)) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [ringback]=[%(2000,4000,440,480)] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(transfer_ringback=/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [transfer_ringback]=[/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(call_timeout=30) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [call_timeout]=[30] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(hangup_after_bridge=true) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [hangup_after_bridge]=[true] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(continue_on_fail=true) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [continue_on_fail]=[true] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 hash(insert/192.168.1.113-call_return/1002/joshua@freeswitch.org) a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 hash(insert/192.168.1.113-last_dial_ext/1002/a64a2d13-097c-fad5-4a2e-4b9912283ade) a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(called_party_callgroup=management) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.974180 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [called_party_callgroup]=[management] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 hash(insert/192.168.1.113-last_dial_ext/management/a64a2d13-097c-fad5-4a2e-4b9912283ade) a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 hash(insert/192.168.1.113-last_dial_ext/global/a64a2d13-097c-fad5-4a2e-4b9912283ade) a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 hash(insert/192.168.1.113-last_dial/management/a64a2d13-097c-fad5-4a2e-4b9912283ade) a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(media_bug_answer_req=true) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [media_bug_answer_req]=[true] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 set(record_concat_video=true) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] mod_dptools.c:1588 SET verto.rtc/1002 [record_concat_video]=[true] a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 answer() a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [opus:111:48000:20:0:2]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5183 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [CN:106:32000:20:0:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [CN:105:16000:20:0:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [CN:13:8000:20:0:1]/[opus:116:48000:20:0:1] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5044 Set telephone-event payload to 110@48000 2017-10-05 11:00:01.984181 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps] 2017-10-05 11:00:01.984181 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3443 Set Codec verto.rtc/1002 opus/48000 20 ms 960 samples 0 bits 2 channels a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_codec.c:111 verto.rtc/1002 Original read codec set to opus:116 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3867 Drop audio Candidate cid: 1 proto: udp type: host addr: 2001::9d38:6ab8:2857:2624:bef0:badf:51685 (no network path) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3873 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.1.123:51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3873 Save audio Candidate cid: 1 proto: udp type: srflx addr: 65.15.69.32:51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3915 Searching for rtp candidate. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3920 Choose rtp candidate, index 0, 192.168.1.123:51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3693 verto.rtc/1002 choosing family v4 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3931 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 192.168.1.123:51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3978 setting remote audio ice addr to index 0 192.168.1.123:51686 based on candidate a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:4013 Setting remote rtcp audio addr to 192.168.1.123:51686 based on candidate a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5387 Set telephone-event payload to 110@48000 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5445 verto.rtc/1002 Set 2833 dtmf send payload to 110 recv payload to 110 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [VP8:96]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [VP9:98]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [H264:100]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5760 Video Codec Compare [H264:100] +++ is saved as a match a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [red:102]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [ulpfec:127]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [rtx:97]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [rtx:99]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [rtx:101]/[H264:99] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:5728 Video Codec Compare [rtx:125]/[H264:99] 2017-10-05 11:00:01.984181 [NOTICE] avcodec.c:1024 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 2017-10-05 11:00:01.984181 [NOTICE] avcodec.c:1024 codec: id=28 H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3253 Set VIDEO Codec verto.rtc/1002 H264/90000 0 ms a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3867 Drop video Candidate cid: 1 proto: udp type: host addr: 2001::9d38:6ab8:2857:2624:bef0:badf:51687 (no network path) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3873 Save video Candidate cid: 1 proto: udp type: host addr: 192.168.1.123:51688 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3873 Save video Candidate cid: 1 proto: udp type: srflx addr: 65.15.69.32:51688 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3915 Searching for rtp candidate. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3920 Choose rtp candidate, index 0, 192.168.1.123:51688 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3693 verto.rtc/1002 choosing family v4 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3931 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 192.168.1.123:51688 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:3978 setting remote video ice addr to index 0 192.168.1.123:51688 based on candidate a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:4013 Setting remote rtcp video addr to 192.168.1.123:51688 based on candidate a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8162 AUDIO RTP [verto.rtc/1002] 192.168.1.113 port 16454 -> 192.168.1.123 port 51686 codec: 111 ms: 20 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_rtp.c:4191 Starting timer [soft] 960 bytes per 20ms a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_core_media.c:8341 Activating Audio ICE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [NOTICE] switch_rtp.c:4690 Activating RTP audio ICE: iTlu:V9rA81ElyWoho6f2 192.168.1.123:51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8382 Activating RTCP PORT 51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_rtp.c:4587 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 51686 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_core_media.c:8393 Skipping RTCP ICE (Same as RTP) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_rtp.c:3643 Activate RTP/RTCP audio DTLS client a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_rtp.c:3806 Changing audio DTLS state from OFF to HANDSHAKE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:2204 Setting Jitterbuffer to 20ms (1 frames) (50 max frames) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8466 verto.rtc/1002 Set 2833 dtmf send payload to 110 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8473 verto.rtc/1002 Set 2833 dtmf receive payload to 110 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_rtp.c:4206 Starting video timer. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8991 VIDEO RTP [verto.rtc/1002] 192.168.1.113:16472->192.168.1.123:51688 codec: 100 ms: 0 [SUCCESS] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:7154 verto.rtc/1002 Starting Video thread 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:7020 verto.rtc/1002 Video thread started. Echo is off a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_core_media.c:9033 Activating Video ICE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [NOTICE] switch_rtp.c:4690 Activating RTP video ICE: iTlu:14Ku0NjrxWwD6t3Z 192.168.1.123:51688 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_core_media.c:9071 Activating VIDEO RTCP PORT 51688 interval 1000 mux 1 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_rtp.c:4587 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 51688 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_core_media.c:9082 Skipping VIDEO RTCP ICE (Same as VIDEO RTP) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_rtp.c:3643 Activate RTP/RTCP video DTLS client a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [INFO] switch_rtp.c:3806 Changing video DTLS state from OFF to HANDSHAKE a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8145 Audio params are unchanged for verto.rtc/1002. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] switch_core_media.c:8849 Video params are unchanged for verto.rtc/1002. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [DEBUG] mod_verto.c:2490 Local SDP verto.rtc/1002: a64a2d13-097c-fad5-4a2e-4b9912283ade v=0 a64a2d13-097c-fad5-4a2e-4b9912283ade o=FreeSWITCH 1507199147 1507199148 IN IP4 192.168.1.113 a64a2d13-097c-fad5-4a2e-4b9912283ade s=FreeSWITCH a64a2d13-097c-fad5-4a2e-4b9912283ade c=IN IP4 192.168.1.113 a64a2d13-097c-fad5-4a2e-4b9912283ade t=0 0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=msid-semantic: WMS pmYKmne611HHwCog5ybHO8JdnGscTBS8 a64a2d13-097c-fad5-4a2e-4b9912283ade m=audio 16454 UDP/TLS/RTP/SAVPF 111 110 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:111 opus/48000/2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:111 useinbandfec=1; minptime=10; stereo=1; sprop-stereo=1 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:110 telephone-event/48000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=silenceSupp:off - - - - a64a2d13-097c-fad5-4a2e-4b9912283ade a=ptime:20 a64a2d13-097c-fad5-4a2e-4b9912283ade a=sendrecv a64a2d13-097c-fad5-4a2e-4b9912283ade a=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64 a64a2d13-097c-fad5-4a2e-4b9912283ade a=setup:active a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-mux a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp:16454 IN IP4 192.168.1.113 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-ufrag:V9rA81ElyWoho6f2 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-pwd:DPTosGZY28QQvPAhPRHNJcZ7 a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:0510665810 1 udp 659136 192.168.1.113 16454 typ host generation 0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=end-of-candidates a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:1039850537 cname:OGJ0UNXLFvi2Xx8T a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:1039850537 msid:pmYKmne611HHwCog5ybHO8JdnGscTBS8 a0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:1039850537 mslabel:pmYKmne611HHwCog5ybHO8JdnGscTBS8 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:1039850537 label:pmYKmne611HHwCog5ybHO8JdnGscTBS8a0 a64a2d13-097c-fad5-4a2e-4b9912283ade m=video 16472 UDP/TLS/RTP/SAVPF 100 a64a2d13-097c-fad5-4a2e-4b9912283ade b=AS:250 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtpmap:100 H264/90000 a64a2d13-097c-fad5-4a2e-4b9912283ade a=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f a64a2d13-097c-fad5-4a2e-4b9912283ade a=sendrecv a64a2d13-097c-fad5-4a2e-4b9912283ade a=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64 a64a2d13-097c-fad5-4a2e-4b9912283ade a=setup:active a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-mux a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp:16472 IN IP4 192.168.1.113 a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 ccm fir a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 nack a64a2d13-097c-fad5-4a2e-4b9912283ade a=rtcp-fb:100 nack pli a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:286263712 cname:OGJ0UNXLFvi2Xx8T a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:286263712 msid:pmYKmne611HHwCog5ybHO8JdnGscTBS8 v0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:286263712 mslabel:pmYKmne611HHwCog5ybHO8JdnGscTBS8 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ssrc:286263712 label:pmYKmne611HHwCog5ybHO8JdnGscTBS8v0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-ufrag:14Ku0NjrxWwD6t3Z a64a2d13-097c-fad5-4a2e-4b9912283ade a=ice-pwd:YZ2da2bjFGmGCDQuxrOn5XFs a64a2d13-097c-fad5-4a2e-4b9912283ade a=candidate:6587643235 1 udp 659136 192.168.1.113 16472 typ host generation 0 a64a2d13-097c-fad5-4a2e-4b9912283ade a=end-of-candidates a64a2d13-097c-fad5-4a2e-4b9912283ade a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.984181 [NOTICE] mod_dptools.c:1352 Channel [verto.rtc/1002] has been answered a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [DEBUG] switch_channel.c:3781 (verto.rtc/1002) Callstate Change RINGING -> ACTIVE 2017-10-05 11:00:01.994180 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1001@192.168.1.113 { "data": { "channelCallState": "ACTIVE", "originalChannelCallState": "RINGING", "channelState": "CS_EXECUTE", "callerUserName": "1001@192.168.1.113", "callerIDName": "1001", "callerIDNumber": "joshua@freeswitch.org", "calleeIDName": "Outbound Call", "calleeIDNumber": "1002", "channelUUID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "presenceCallDirection": "inbound", "channelPresenceID": "1001@192.168.1.113" }, "eventChannel": "presence.1001@192.168.1.113" } a64a2d13-097c-fad5-4a2e-4b9912283ade EXECUTE verto.rtc/1002 bridge(user/1002@192.168.1.113) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [DEBUG] switch_channel.c:1823 (verto.rtc/1002) Callstate Change ACTIVE -> RING_WAIT 2017-10-05 11:00:01.994180 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1001@192.168.1.113 { "data": { "channelCallState": "RING_WAIT", "originalChannelCallState": "ACTIVE", "channelState": "CS_EXECUTE", "callerUserName": "1001@192.168.1.113", "callerIDName": "1001", "callerIDNumber": "joshua@freeswitch.org", "calleeIDName": "Outbound Call", "calleeIDNumber": "1002", "channelUUID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "presenceCallDirection": "inbound", "channelPresenceID": "1001@192.168.1.113" }, "eventChannel": "presence.1001@192.168.1.113" } a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [DEBUG] switch_channel.c:1250 verto.rtc/1002 EXPORTING[export_vars] [dialed_extension]=[1002] to event a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [DEBUG] switch_channel.c:1250 verto.rtc/1002 EXPORTING[export_vars] [dialed_extension]=[1002] to event a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [DEBUG] switch_ivr_originate.c:2159 Parsing global variables a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:01.994180 [NOTICE] switch_ivr_originate.c:2868 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] mod_rtc.c:392 () State Change CS_NEW -> CS_INIT b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 [b3dddbfc-a3ba-405b-8272-2541d73ad160] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_INIT (Cur 2 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State INIT b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] mod_verto.c:2255 Local verto.invite SDP verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5: b3dddbfc-a3ba-405b-8272-2541d73ad160 v=0 b3dddbfc-a3ba-405b-8272-2541d73ad160 o=FreeSWITCH 1507199137 1507199138 IN IP4 65.15.69.32 b3dddbfc-a3ba-405b-8272-2541d73ad160 s=FreeSWITCH b3dddbfc-a3ba-405b-8272-2541d73ad160 c=IN IP4 65.15.69.32 b3dddbfc-a3ba-405b-8272-2541d73ad160 t=0 0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=msid-semantic: WMS i2gahfk0u1Il79NE0mUASnLVjrugbcJj b3dddbfc-a3ba-405b-8272-2541d73ad160 m=audio 16464 RTP/SAVPF 102 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtpmap:102 opus/48000/2 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=setup:actpass b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-mux b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp:16464 IN IP4 65.15.69.32 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:3588277673 cname:4PkcVu2gmArjA4Nq b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:3588277673 msid:i2gahfk0u1Il79NE0mUASnLVjrugbcJj a0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:3588277673 mslabel:i2gahfk0u1Il79NE0mUASnLVjrugbcJj b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:3588277673 label:i2gahfk0u1Il79NE0mUASnLVjrugbcJja0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-ufrag:hyQ0LsMVK61L9AV4 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-pwd:g561qZ7CppLQkp7rNNip6UaG b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:2032564126 1 udp 659136 65.15.69.32 16464 typ host generation 0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:2032564126 2 udp 659136 65.15.69.32 16464 typ host generation 0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=silenceSupp:off - - - - b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ptime:20 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=sendrecv b3dddbfc-a3ba-405b-8272-2541d73ad160 m=video 16482 RTP/SAVPF 103 b3dddbfc-a3ba-405b-8272-2541d73ad160 b=AS:1024 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtpmap:103 H264/90000 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=sendrecv b3dddbfc-a3ba-405b-8272-2541d73ad160 a=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=setup:actpass b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-mux b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp:16482 IN IP4 65.15.69.32 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-fb:103 ccm fir b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-fb:103 ccm tmmbr b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-fb:103 nack b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-fb:103 nack pli b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:2834690848 cname:4PkcVu2gmArjA4Nq b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:2834690848 msid:i2gahfk0u1Il79NE0mUASnLVjrugbcJj v0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:2834690848 mslabel:i2gahfk0u1Il79NE0mUASnLVjrugbcJj b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:2834690848 label:i2gahfk0u1Il79NE0mUASnLVjrugbcJjv0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-ufrag:ujsQyZs19KFyZAAT b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-pwd:ESJtb5ZmzbQXZJajTsZhih9h b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:7675915594 1 udp 659136 65.15.69.32 16482 typ host generation 0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:7675915594 2 udp 659135 65.15.69.32 16482 typ host generation 0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=end-of-candidates b3dddbfc-a3ba-405b-8272-2541d73ad160 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [NOTICE] mod_verto.c:2355 Ring-Ready verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5! b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_channel.c:3354 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Callstate Change DOWN -> RINGING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:40 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 Standard INIT b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State Change CS_INIT -> CS_ROUTING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State INIT going to sleep 2017-10-05 11:00:01.994180 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1002@192.168.1.113 { "data": { "channelCallState": "RINGING", "originalChannelCallState": "DOWN", "channelState": "CS_INIT", "callerUserName": "1001@192.168.1.113", "callerIDName": "Extension 1001", "callerIDNumber": "1001", "calleeIDName": "1002", "calleeIDNumber": "1002", "channelUUID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "presenceCallDirection": "outbound", "channelPresenceID": "1002@192.168.1.113" }, "eventChannel": "presence.1002@192.168.1.113" } b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_ROUTING (Cur 2 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State ROUTING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] mod_rtc.c:89 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 RTC ROUTING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_ivr_originate.c:67 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State Change CS_ROUTING -> CS_CONSUME_MEDIA b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State ROUTING going to sleep b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State CONSUME_MEDIA b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:01.994180 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State CONSUME_MEDIA going to sleep a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.004186 [DEBUG] switch_ivr_originate.c:1278 Raw Codec Activation Success L16@48000hz 2 channel 20ms a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.004186 [DEBUG] switch_core_codec.c:223 verto.rtc/1002 Push codec L16:100 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.004186 [DEBUG] switch_ivr_originate.c:1310 Play Ringback File [/usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav] 2017-10-05 11:00:02.004186 [DEBUG] switch_core_file.c:358 File /usr/local/freeswitch/sounds/joshebosh/Tomtoms.wav sample rate 44100 doesn't match requested rate 48000 2017-10-05 11:00:02.004186 [WARNING] switch_core_file.c:376 File has 1 channels, muxing to 2 channels will occur. 2017-10-05 11:00:02.014178 [ALERT] mod_verto.c:601 WRITE 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 177, "method": "verto.answer", "params": { "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "sdp": "v=0\r\no=FreeSWITCH 1507199147 1507199148 IN IP4 192.168.1.113\r\ns=FreeSWITCH\r\nc=IN IP4 192.168.1.113\r\nt=0 0\r\na=msid-semantic: WMS pmYKmne611HHwCog5ybHO8JdnGscTBS8\r\nm=audio 16454 UDP/TLS/RTP/SAVPF 111 110\r\na=rtpmap:111 opus/48000/2\r\na=fmtp:111 useinbandfec=1; minptime=10; stereo=1; sprop-stereo=1\r\na=rtpmap:110 telephone-event/48000\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\na=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64\r\na=setup:active\r\na=rtcp-mux\r\na=rtcp:16454 IN IP4 192.168.1.113\r\na=ice-ufrag:V9rA81ElyWoho6f2\r\na=ice-pwd:DPTosGZY28QQvPAhPRHNJcZ7\r\na=candidate:0510665810 1 udp 659136 192.168.1.113 16454 typ host generation 0\r\na=end-of-candidates\r\na=ssrc:1039850537 cname:OGJ0UNXLFvi2Xx8T\r\na=ssrc:1039850537 msid:pmYKmne611HHwCog5ybHO8JdnGscTBS8 a0\r\na=ssrc:1039850537 mslabel:pmYKmne611HHwCog5ybHO8JdnGscTBS8\r\na=ssrc:1039850537 label:pmYKmne611HHwCog5ybHO8JdnGscTBS8a0\r\nm=video 16472 UDP/TLS/RTP/SAVPF 100\r\nb=AS:250\r\na=rtpmap:100 H264/90000\r\na=fmtp:100 level-asymmetry-allowed=1;packetization-mode=1;profile-level-id=42e01f\r\na=sendrecv\r\na=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64\r\na=setup:active\r\na=rtcp-mux\r\na=rtcp:16472 IN IP4 192.168.1.113\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 nack pli\r\na=ssrc:286263712 cname:OGJ0UNXLFvi2Xx8T\r\na=ssrc:286263712 msid:pmYKmne611HHwCog5ybHO8JdnGscTBS8 v0\r\na=ssrc:286263712 mslabel:pmYKmne611HHwCog5ybHO8JdnGscTBS8\r\na=ssrc:286263712 label:pmYKmne611HHwCog5ybHO8JdnGscTBS8v0\r\na=ice-ufrag:14Ku0NjrxWwD6t3Z\r\na=ice-pwd:YZ2da2bjFGmGCDQuxrOn5XFs\r\na=candidate:6587643235 1 udp 659136 192.168.1.113 16472 typ host generation 0\r\na=end-of-candidates\r\n" } }] 2017-10-05 11:00:02.024179 [ALERT] mod_verto.c:1405 READ 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 177, "result": { "method": "verto.answer" } }] 2017-10-05 11:00:02.024179 [ALERT] mod_verto.c:601 WRITE 166.170.56.190:53568 [{ "jsonrpc": "2.0", "id": 178, "method": "verto.invite", "params": { "callID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "sdp": "v=0\r\no=FreeSWITCH 1507199137 1507199138 IN IP4 65.15.69.32\r\ns=FreeSWITCH\r\nc=IN IP4 65.15.69.32\r\nt=0 0\r\na=msid-semantic: WMS i2gahfk0u1Il79NE0mUASnLVjrugbcJj\r\nm=audio 16464 RTP/SAVPF 102\r\na=rtpmap:102 opus/48000/2\r\na=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40\r\na=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:16464 IN IP4 65.15.69.32\r\na=ssrc:3588277673 cname:4PkcVu2gmArjA4Nq\r\na=ssrc:3588277673 msid:i2gahfk0u1Il79NE0mUASnLVjrugbcJj a0\r\na=ssrc:3588277673 mslabel:i2gahfk0u1Il79NE0mUASnLVjrugbcJj\r\na=ssrc:3588277673 label:i2gahfk0u1Il79NE0mUASnLVjrugbcJja0\r\na=ice-ufrag:hyQ0LsMVK61L9AV4\r\na=ice-pwd:g561qZ7CppLQkp7rNNip6UaG\r\na=candidate:2032564126 1 udp 659136 65.15.69.32 16464 typ host generation 0\r\na=candidate:2032564126 2 udp 659136 65.15.69.32 16464 typ host generation 0\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\nm=video 16482 RTP/SAVPF 103\r\nb=AS:1024\r\na=rtpmap:103 H264/90000\r\na=sendrecv\r\na=fingerprint:sha-256 A5:44:80:7A:3C:F0:D1:FD:3C:BD:DE:6E:41:C0:88:27:6C:7E:AA:B9:25:4F:36:20:71:3C:2F:68:BC:B8:D2:64\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:16482 IN IP4 65.15.69.32\r\na=rtcp-fb:103 ccm fir\r\na=rtcp-fb:103 ccm tmmbr\r\na=rtcp-fb:103 nack\r\na=rtcp-fb:103 nack pli\r\na=ssrc:2834690848 cname:4PkcVu2gmArjA4Nq\r\na=ssrc:2834690848 msid:i2gahfk0u1Il79NE0mUASnLVjrugbcJj v0\r\na=ssrc:2834690848 mslabel:i2gahfk0u1Il79NE0mUASnLVjrugbcJj\r\na=ssrc:2834690848 label:i2gahfk0u1Il79NE0mUASnLVjrugbcJjv0\r\na=ice-ufrag:ujsQyZs19KFyZAAT\r\na=ice-pwd:ESJtb5ZmzbQXZJajTsZhih9h\r\na=candidate:7675915594 1 udp 659136 65.15.69.32 16482 typ host generation 0\r\na=candidate:7675915594 2 udp 659135 65.15.69.32 16482 typ host generation 0\r\na=end-of-candidates\r\n", "caller_id_name": "Extension 1001", "caller_id_number": "1001", "callee_id_name": "1002", "callee_id_number": "1002", "display_direction": "outbound" } }] 2017-10-05 11:00:02.034184 [INFO] avcodec.c:1085 initializing encoder 352x288 2017-10-05 11:00:02.034184 [DEBUG] avcodec.c:833 NVENC HW CODEC NOT PRESENT using cpu capabilities: MMX2 SSE2Fast SSSE3 SSE4.2 AVX profile Constrained Baseline, level 3.1 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.074182 [INFO] switch_rtp.c:3191 Changing video DTLS state from HANDSHAKE to SETUP a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.074182 [INFO] switch_rtp.c:3100 video Fingerprint Verified. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.074182 [INFO] switch_rtp.c:3995 Activating video Secure RTP SEND 2017-10-05 11:00:02.074182 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.074182 [INFO] switch_rtp.c:3973 Activating video Secure RTP RECV a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.074182 [INFO] switch_rtp.c:3140 Changing video DTLS state from SETUP to READY 2017-10-05 11:00:02.074182 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:02.104213 [DEBUG] switch_rtp.c:1886 rtcp_stats_init: video ssrc[2784642864] base_seq[27825] 2017-10-05 11:00:02.124211 [ALERT] mod_verto.c:1405 READ 166.170.56.190:53568 [{ "jsonrpc": "2.0", "id": 178, "result": { "method": "verto.invite" } }] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:03.054179 [INFO] switch_rtp.c:3191 Changing audio DTLS state from HANDSHAKE to SETUP a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:03.074212 [INFO] switch_rtp.c:3100 audio Fingerprint Verified. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:03.074212 [INFO] switch_rtp.c:3995 Activating audio Secure RTP SEND a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:03.074212 [INFO] switch_rtp.c:3973 Activating audio Secure RTP RECV a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:03.074212 [INFO] switch_rtp.c:3140 Changing audio DTLS state from SETUP to READY 2017-10-05 11:00:03.074212 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 2017-10-05 11:00:03.074212 [DEBUG] switch_core_sqldb.c:2617 Secure Type: srtp:dtls:AES_CM_128_HMAC_SHA1_80 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:03.104211 [DEBUG] switch_rtp.c:1886 rtcp_stats_init: audio ssrc[395565095] base_seq[7115] 2017-10-05 11:00:09.064211 [ALERT] mod_verto.c:1405 READ 166.170.56.190:53568 [{ "jsonrpc": "2.0", "method": "verto.answer", "params": { "sdp": "v=0\r\no=mozilla...THIS_IS_SDPARTA-58.0a1 3065108213601928732 0 IN IP4 0.0.0.0\r\ns=-\r\nt=0 0\r\na=sendrecv\r\na=fingerprint:sha-256 9D:ED:6E:33:E4:04:52:47:B6:56:E4:82:CE:40:66:FB:29:93:E5:BE:EA:45:AD:DE:E8:44:B8:67:C6:1D:75:16\r\na=ice-options:trickle\r\na=msid-semantic:WMS *\r\nm=audio 1580 RTP/SAVPF 102\r\nc=IN IP4 166.170.56.190\r\na=candidate:0 1 UDP 2122252543 192.168.150.50 50222 typ host\r\na=candidate:2 1 UDP 2122187007 2001:0:9d38:6ab8:18c6:15de:3f57:69cd 50223 typ host\r\na=candidate:4 1 TCP 2105524479 192.168.150.50 9 typ host tcptype active\r\na=candidate:5 1 TCP 2105458943 2001:0:9d38:6ab8:18c6:15de:3f57:69cd 9 typ host tcptype active\r\na=candidate:1 1 UDP 1686052863 166.170.56.190 1580 typ srflx raddr 192.168.150.50 rport 50222\r\na=sendrecv\r\na=end-of-candidates\r\na=fmtp:102 maxplaybackrate=48000;stereo=1;useinbandfec=1\r\na=ice-pwd:e8a768678b97d9435e1a09767de3c6ed\r\na=ice-ufrag:4c6e3a96\r\na=msid:{212a93ca-642b-4e49-a9bf-7244bd56b1b8} {32c8665f-d178-4ae2-8984-a8e76e4b02b7}\r\na=rtcp-mux\r\na=rtpmap:102 opus/48000/2\r\na=setup:active\r\na=ssrc:2752822895 cname:{7774a22c-43d7-4652-b912-1e7323d9de19}\r\nm=video 0 RTP/SAVPF 120\r\nc=IN IP4 0.0.0.0\r\na=inactive\r\na=rtpmap:120 VP8/90000\r\n", "dialogParams": { "useVideo": true, "screenShare": false, "useCamera": "xI8gFA67oJwA0CBLRZ62Mkc8ZuyKoQgCoZaOmFs2oXI=", "useMic": "4Jd/M8fL+Viyc6uEeDNnMHsXYvNT4F1dDAQpSQUPy4E=", "useSpeak": null, "tag": "webcam", "localTag": null, "login": "1002@baremetal.joshebosh.com", "videoParams": { "minWidth": 320, "minHeight": 240, "maxWidth": 320, "maxHeight": 240, "minFrameRate": 15 }, "callID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "caller_id_name": "Extension 1001", "caller_id_number": "1001", "callee_id_name": "1002", "callee_id_number": "1002", "display_direction": "outbound", "wantVideo": true, "remote_caller_id_name": "Extension 1001", "remote_caller_id_number": "1001" }, "sessid": "b661ee3f-a8fe-86d4-d8fe-74652bb047a5" }, "id": 12 }] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.064211 [DEBUG] mod_verto.c:2721 Remote SDP verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5: b3dddbfc-a3ba-405b-8272-2541d73ad160 v=0 b3dddbfc-a3ba-405b-8272-2541d73ad160 o=mozilla...THIS_IS_SDPARTA-58.0a1 3065108213601928732 0 IN IP4 0.0.0.0 b3dddbfc-a3ba-405b-8272-2541d73ad160 s=- b3dddbfc-a3ba-405b-8272-2541d73ad160 t=0 0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=sendrecv b3dddbfc-a3ba-405b-8272-2541d73ad160 a=fingerprint:sha-256 9D:ED:6E:33:E4:04:52:47:B6:56:E4:82:CE:40:66:FB:29:93:E5:BE:EA:45:AD:DE:E8:44:B8:67:C6:1D:75:16 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-options:trickle b3dddbfc-a3ba-405b-8272-2541d73ad160 a=msid-semantic:WMS * b3dddbfc-a3ba-405b-8272-2541d73ad160 m=audio 1580 RTP/SAVPF 102 b3dddbfc-a3ba-405b-8272-2541d73ad160 c=IN IP4 166.170.56.190 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:0 1 UDP 2122252543 192.168.150.50 50222 typ host b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:2 1 UDP 2122187007 2001:0:9d38:6ab8:18c6:15de:3f57:69cd 50223 typ host b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:4 1 TCP 2105524479 192.168.150.50 9 typ host tcptype active b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:5 1 TCP 2105458943 2001:0:9d38:6ab8:18c6:15de:3f57:69cd 9 typ host tcptype active b3dddbfc-a3ba-405b-8272-2541d73ad160 a=candidate:1 1 UDP 1686052863 166.170.56.190 1580 typ srflx raddr 192.168.150.50 rport 50222 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=sendrecv b3dddbfc-a3ba-405b-8272-2541d73ad160 a=end-of-candidates b3dddbfc-a3ba-405b-8272-2541d73ad160 a=fmtp:102 maxplaybackrate=48000;stereo=1;useinbandfec=1 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-pwd:e8a768678b97d9435e1a09767de3c6ed b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ice-ufrag:4c6e3a96 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=msid:{212a93ca-642b-4e49-a9bf-7244bd56b1b8} {32c8665f-d178-4ae2-8984-a8e76e4b02b7} b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtcp-mux b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtpmap:102 opus/48000/2 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=setup:active b3dddbfc-a3ba-405b-8272-2541d73ad160 a=ssrc:2752822895 cname:{7774a22c-43d7-4652-b912-1e7323d9de19} b3dddbfc-a3ba-405b-8272-2541d73ad160 m=video 0 RTP/SAVPF 120 b3dddbfc-a3ba-405b-8272-2541d73ad160 c=IN IP4 0.0.0.0 b3dddbfc-a3ba-405b-8272-2541d73ad160 a=inactive b3dddbfc-a3ba-405b-8272-2541d73ad160 a=rtpmap:120 VP8/90000 b3dddbfc-a3ba-405b-8272-2541d73ad160 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.064211 [DEBUG] switch_core_media.c:5128 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:1] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.064211 [DEBUG] switch_core_media.c:5183 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2017-10-05 11:00:09.064211 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps] 2017-10-05 11:00:09.064211 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.064211 [DEBUG] switch_core_media.c:3443 Set Codec verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 opus/48000 20 ms 960 samples 0 bits 2 channels b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.064211 [DEBUG] switch_core_codec.c:111 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 Original read codec set to opus:116 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3873 Save audio Candidate cid: 1 proto: UDP type: host addr: 192.168.150.50:50222 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3867 Drop audio Candidate cid: 1 proto: UDP type: host addr: 2001:0:9d38:6ab8:18c6:15de:3f57:69cd:50223 (no network path) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3873 Save audio Candidate cid: 1 proto: UDP type: srflx addr: 166.170.56.190:1580 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3915 Searching for rtp candidate. b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3920 Choose rtp candidate, index 1, 166.170.56.190:1580 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3693 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 choosing family v4 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3931 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 166.170.56.190:1580 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:3978 setting remote audio ice addr to index 1 166.170.56.190:1580 based on candidate b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:4013 Setting remote rtcp audio addr to 166.170.56.190:1580 based on candidate b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:5416 No 2833 in SDP. Liberal DTMF mode adding 0 as telephone-event. b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:5452 No 2833 in SDP. Disable 2833 dtmf and switch to INFO b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:8162 AUDIO RTP [verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5] 192.168.1.113 port 16464 -> 166.170.56.190 port 1580 codec: 102 ms: 20 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_rtp.c:4191 Starting timer [soft] 960 bytes per 20ms b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [INFO] switch_core_media.c:8341 Activating Audio ICE b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [NOTICE] switch_rtp.c:4690 Activating RTP audio ICE: 4c6e3a96:hyQ0LsMVK61L9AV4 166.170.56.190:1580 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:8382 Activating RTCP PORT 1580 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_rtp.c:4587 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 1580 b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [INFO] switch_core_media.c:8393 Skipping RTCP ICE (Same as RTP) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [INFO] switch_rtp.c:3643 Activate RTP/RTCP audio DTLS server b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [INFO] switch_rtp.c:3806 Changing audio DTLS state from OFF to HANDSHAKE b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:2204 Setting Jitterbuffer to 20ms (1 frames) (50 max frames) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_core_media.c:8145 Audio params are unchanged for verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5. b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [NOTICE] mod_verto.c:2755 Channel [verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5] has been answered b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.074181 [DEBUG] switch_channel.c:3781 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Callstate Change RINGING -> ACTIVE 2017-10-05 11:00:09.074181 [ALERT] mod_verto.c:601 WRITE 166.170.56.190:53568 [{ "jsonrpc": "2.0", "id": 12, "result": { "sessid": "b661ee3f-a8fe-86d4-d8fe-74652bb047a5" } }] 2017-10-05 11:00:09.074181 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1002@192.168.1.113 { "data": { "channelCallState": "ACTIVE", "originalChannelCallState": "RINGING", "channelState": "CS_CONSUME_MEDIA", "callerUserName": "1001@192.168.1.113", "callerIDName": "Extension 1001", "callerIDNumber": "1001", "calleeIDName": "1002", "calleeIDNumber": "1002", "channelUUID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "presenceCallDirection": "outbound", "channelPresenceID": "1002@192.168.1.113" }, "eventChannel": "presence.1002@192.168.1.113" } a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:09.084186 [DEBUG] switch_core_codec.c:248 verto.rtc/1002 Restore previous codec opus:116. a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:09.084186 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:09.084186 [DEBUG] switch_channel.c:2047 (verto.rtc/1002) Callstate Change RING_WAIT -> ACTIVE 2017-10-05 11:00:09.084186 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1001@192.168.1.113 { "data": { "channelCallState": "ACTIVE", "originalChannelCallState": "RING_WAIT", "channelState": "CS_EXECUTE", "callerUserName": "1001@192.168.1.113", "callerIDName": "1001", "callerIDNumber": "joshua@freeswitch.org", "calleeIDName": "1002", "calleeIDNumber": "1002", "channelUUID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "presenceCallDirection": "inbound", "channelPresenceID": "1001@192.168.1.113" }, "eventChannel": "presence.1001@192.168.1.113" } a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:09.084186 [DEBUG] switch_ivr_originate.c:3722 Originate Resulted in Success: [verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.084186 [DEBUG] switch_core_media.c:12204 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 PAUSE Jitterbuffer b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.094179 [DEBUG] switch_ivr_bridge.c:1744 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.094179 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_EXCHANGE_MEDIA (Cur 2 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.094179 [DEBUG] switch_core_state_machine.c:653 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State EXCHANGE_MEDIA b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.094179 [DEBUG] mod_rtc.c:146 RTC EXCHANGE_MEDIA b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.104211 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:09.104211 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] 2017-10-05 11:00:09.104211 [DEBUG] mod_opus.c:617 Opus encoder: set bitrate to local settings [120000bps] 2017-10-05 11:00:09.124211 [ALERT] mod_verto.c:601 WRITE 166.170.56.190:53568 [{ "jsonrpc": "2.0", "id": 180, "method": "verto.display", "params": { "callID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "display_name": "Extension 1001", "display_number": "1001", "caller_id_name": "Extension 1001", "caller_id_number": "1001", "callee_id_name": "1002", "callee_id_number": "1002", "display_direction": "outbound" } }] 2017-10-05 11:00:09.124211 [ALERT] mod_verto.c:601 WRITE 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 179, "method": "verto.display", "params": { "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "display_name": "1002", "display_number": "1002", "caller_id_name": "1001", "caller_id_number": "joshua@freeswitch.org", "callee_id_name": "1002", "callee_id_number": "1002", "display_direction": "inbound" } }] 2017-10-05 11:00:09.124211 [ALERT] mod_verto.c:1405 READ 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 179, "result": { "method": "verto.display" } }] 2017-10-05 11:00:09.304212 [ALERT] mod_verto.c:1405 READ 166.170.56.190:53568 [{ "jsonrpc": "2.0", "id": 180, "result": { "method": "verto.display" } }] 2017-10-05 11:00:18.464212 [ALERT] mod_verto.c:1405 READ 166.170.56.190:53568 [{ "jsonrpc": "2.0", "method": "verto.bye", "params": { "dialogParams": { "useVideo": true, "screenShare": false, "useCamera": "xI8gFA67oJwA0CBLRZ62Mkc8ZuyKoQgCoZaOmFs2oXI=", "useMic": "4Jd/M8fL+Viyc6uEeDNnMHsXYvNT4F1dDAQpSQUPy4E=", "useSpeak": null, "tag": "webcam", "localTag": null, "login": "1002@baremetal.joshebosh.com", "videoParams": { "minWidth": 320, "minHeight": 240, "maxWidth": 320, "maxHeight": 240, "minFrameRate": 15 }, "callID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "caller_id_name": "Extension 1001", "caller_id_number": "1001", "callee_id_name": "1002", "callee_id_number": "1002", "display_direction": "outbound", "wantVideo": true, "remote_caller_id_name": "Extension 1001", "remote_caller_id_number": "1001" }, "sessid": "b661ee3f-a8fe-86d4-d8fe-74652bb047a5" }, "id": 13 }] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.464212 [NOTICE] mod_verto.c:2835 Hangup verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING] 2017-10-05 11:00:18.464212 [ALERT] mod_verto.c:601 WRITE 166.170.56.190:53568 [{ "jsonrpc": "2.0", "id": 13, "result": { "callID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "message": "CALL ENDED", "causeCode": 16, "cause": "NORMAL_CLEARING", "sessid": "b661ee3f-a8fe-86d4-d8fe-74652bb047a5" } }] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_ivr_bridge.c:831 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 ending bridge by request from read function b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:653 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State EXCHANGE_MEDIA going to sleep b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_HANGUP (Cur 2 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Callstate Change ACTIVE -> HANGUP b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State HANGUP b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:60 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 Standard HANGUP, cause: NORMAL_CLEARING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State HANGUP going to sleep b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State Change CS_HANGUP -> CS_REPORTING 2017-10-05 11:00:18.474179 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1002@192.168.1.113 { "data": { "channelCallState": "HANGUP", "originalChannelCallState": "ACTIVE", "channelState": "CS_HANGUP", "callerUserName": "1001@192.168.1.113", "callerIDName": "Extension 1001", "callerIDNumber": "1001", "calleeIDName": "1002", "calleeIDNumber": "1002", "channelUUID": "b3dddbfc-a3ba-405b-8272-2541d73ad160", "presenceCallDirection": "outbound", "channelPresenceID": "1002@192.168.1.113" }, "eventChannel": "presence.1002@192.168.1.113" } b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_REPORTING (Cur 2 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State REPORTING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [INFO] mod_json_cdr.c:271 Process [b3dddbfc-a3ba-405b-8272-2541d73ad160.cdr.json] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [INFO] mod_json_cdr.c:275 Log to disk [/usr/local/freeswitch/log/json_cdr/b3dddbfc-a3ba-405b-8272-2541d73ad160.cdr.json] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:174 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 Standard REPORTING, cause: NORMAL_CLEARING b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State REPORTING going to sleep b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State Change CS_REPORTING -> CS_DESTROY b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.474179 [DEBUG] switch_core_session.c:1713 Session 804 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Locked, Waiting on external entities a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_ivr_bridge.c:825 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 ending bridge by request from write function a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_ivr_bridge.c:917 BRIDGE THREAD DONE [verto.rtc/1002] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [NOTICE] switch_ivr_bridge.c:1895 Hangup verto.rtc/1002 [CS_EXECUTE] [NORMAL_CLEARING] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [NOTICE] switch_core_session.c:1731 Session 804 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Ended b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [NOTICE] switch_core_session.c:1735 Close Channel verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 [CS_DESTROY] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_session.c:2885 verto.rtc/1002 skip receive message [PHONE_EVENT] (channel is hungup already) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:650 (verto.rtc/1002) State EXECUTE going to sleep a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1002) Running State Change CS_HANGUP (Cur 1 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) Running State Change CS_DESTROY (Cur 1 Tot 804) b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State DESTROY b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] mod_rtc.c:132 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 RTC DESTROY b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:181 verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5 Standard DESTROY b3dddbfc-a3ba-405b-8272-2541d73ad160 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/b661ee3f-a8fe-86d4-d8fe-74652bb047a5) State DESTROY going to sleep a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/1002) Callstate Change ACTIVE -> HANGUP a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/1002) State HANGUP a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:60 verto.rtc/1002 Standard HANGUP, cause: NORMAL_CLEARING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/1002) State HANGUP going to sleep 2017-10-05 11:00:18.484217 [ALERT] mod_verto.c:5543 EVENT BROADCAST presence.1001@192.168.1.113 { "data": { "channelCallState": "HANGUP", "originalChannelCallState": "ACTIVE", "channelState": "CS_HANGUP", "callerUserName": "1001@192.168.1.113", "callerIDName": "1001", "callerIDNumber": "joshua@freeswitch.org", "calleeIDName": "1002", "calleeIDNumber": "1002", "channelUUID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "presenceCallDirection": "inbound", "channelPresenceID": "1001@192.168.1.113" }, "eventChannel": "presence.1001@192.168.1.113" } a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/1002) State Change CS_HANGUP -> CS_REPORTING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1002) Running State Change CS_REPORTING (Cur 1 Tot 804) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.484217 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/1002) State REPORTING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [INFO] mod_json_cdr.c:271 Process [a_a64a2d13-097c-fad5-4a2e-4b9912283ade.cdr.json] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [INFO] mod_json_cdr.c:275 Log to disk [/usr/local/freeswitch/log/json_cdr/a_a64a2d13-097c-fad5-4a2e-4b9912283ade.cdr.json] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:174 verto.rtc/1002 Standard REPORTING, cause: NORMAL_CLEARING a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/1002) State REPORTING going to sleep a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/1002) State Change CS_REPORTING -> CS_DESTROY a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_session.c:1713 Session 803 (verto.rtc/1002) Locked, Waiting on external entities 2017-10-05 11:00:18.494183 [DEBUG] switch_core_media.c:7121 verto.rtc/1002 Video thread ended a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [NOTICE] switch_core_session.c:1731 Session 803 (verto.rtc/1002) Ended a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [NOTICE] switch_core_session.c:1735 Close Channel verto.rtc/1002 [CS_DESTROY] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/1002) Running State Change CS_DESTROY (Cur 0 Tot 804) a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/1002) State DESTROY a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] mod_rtc.c:132 verto.rtc/1002 RTC DESTROY a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[301] PLC[0] FEC[0] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[0] Bytes encoded[0] Encoded length ms[0] Average encoded bitrate bps[0] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] mod_opus.c:725 Opus decoder stats: Frames[0] PLC[0] FEC[0] a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] mod_opus.c:740 Opus encoder stats: Frames[354] Bytes encoded[82196] Encoded length ms[7080] Average encoded bitrate bps[93938] frame I:4 Avg QP:10.25 size: 605 frame P:146 Avg QP: 0.25 size: 49 mb I I16..4: 99.0% 0.0% 1.0% mb P I16..4: 0.0% 0.0% 0.0% P16..4: 0.0% 0.0% 0.0% 0.0% 0.0% skip:100.0% coded y,uvDC,uvAC intra: 0.3% 0.0% 0.0% inter: 0.0% 0.0% 0.0% i16 v,h,dc,p: 79% 0% 21% 0% i4 v,h,dc,ddl,ddr,vr,hd,vl,hu: 0% 0% 100% 0% 0% 0% 0% 0% 0% i8c dc,h,v,p: 100% 0% 0% 0% kb/s:45.95 a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:181 verto.rtc/1002 Standard DESTROY a64a2d13-097c-fad5-4a2e-4b9912283ade 2017-10-05 11:00:18.494183 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/1002) State DESTROY going to sleep 2017-10-05 11:00:18.534189 [ALERT] mod_verto.c:601 WRITE 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 181, "method": "verto.bye", "params": { "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "causeCode": 16, "cause": "NORMAL_CLEARING" } }] 2017-10-05 11:00:18.534189 [ALERT] mod_verto.c:1405 READ 192.168.1.1:55563 [{ "jsonrpc": "2.0", "method": "verto.bye", "params": { "dialogParams": { "useVideo": true, "useStereo": true, "screenShare": false, "useCamera": "045df2abc86d39fe84a007c577623bbed07263394e09491bf7508947970b2d5f", "useMic": "default", "useSpeak": "default", "tag": "webcam", "localTag": null, "login": "1001@baremetal.joshebosh.com", "videoParams": { "minWidth": 160, "minHeight": 120, "maxWidth": 160, "maxHeight": 120, "minFrameRate": 15 }, "destination_number": "1002", "caller_id_name": "1001", "caller_id_number": "joshua@freeswitch.org", "outgoingBandwidth": "250", "incomingBandwidth": "250", "dedEnc": true, "mirrorInput": false, "userVariables": { "email": "joshua@freeswitch.org", "avatar": "http://gravatar.com/avatar/4d744e87a0efca67c7418f2d8e098a98.png?s=600" }, "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "remote_caller_id_name": "1002", "remote_caller_id_number": "1002" }, "sessid": "8f00da09-b94a-6eac-7246-f8f6f4d3ad78" }, "id": 23 }] 2017-10-05 11:00:18.534189 [ALERT] mod_verto.c:601 WRITE 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 23, "error": { "callID": "a64a2d13-097c-fad5-4a2e-4b9912283ade", "message": "CALL DOES NOT EXIST", "code": -32002 } }] 2017-10-05 11:00:18.584212 [ALERT] mod_verto.c:1405 READ 192.168.1.1:55563 [{ "jsonrpc": "2.0", "id": 181, "result": { "method": "verto.bye" } }] 2017-10-05 11:00:21.014189 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/1001.csv 2017-10-05 11:00:21.014189 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/1002.csv 2017-10-05 11:00:21.014189 [NOTICE] mod_cdr_csv.c:127 Rotated CDR logfile /usr/local/freeswitch/log/cdr-csv/Master.csv