v2v call - no media in prod FS_CLI: +OK log level [7] 2020-02-10 20:26:32.438738 [DEBUG] mod_verto.c:1415 READ 75.69.229.242:55707 [{ "jsonrpc": "2.0", "method": "verto.invite", "params": { "sdp": "v=0\r\no=- 5294435820167355833 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio\r\na=msid-semantic: WMS 73CZbHY19upuW80v0kyhdfNyDpN0ECx9MQY5\r\nm=audio 54872 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126\r\nc=IN IP4 75.69.229.242\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=candidate:2456471252 1 udp 2122260223 10.0.0.13 54872 typ host generation 0 network-id 1 network-cost 10\r\na=candidate:3504814172 1 udp 1686052607 75.69.229.242 54872 typ srflx raddr 10.0.0.13 rport 54872 generation 0 network-id 1 network-cost 10\r\na=candidate:3706272292 1 tcp 1518280447 10.0.0.13 9 typ host tcptype active generation 0 network-id 1 network-cost 10\r\na=ice-ufrag:7EfF\r\na=ice-pwd:Z8WH62o+Yhj+iqbOdIAapNpG\r\na=ice-options:trickle\r\na=fingerprint:sha-256 24:84:49:A3:18:F7:CC:BC:72:5D:72:3D:14:B4:79:B8:F4:70:76:51:86:9E:11:CD:A8:FE:CD:50:33:D5:BA:90\r\na=setup:actpass\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01\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:3135906121 cname:4sygjsSsqgZzYttl\r\na=ssrc:3135906121 msid:73CZbHY19upuW80v0kyhdfNyDpN0ECx9MQY5 262eeec0-fe95-472a-b579-03389273d351\r\na=ssrc:3135906121 mslabel:73CZbHY19upuW80v0kyhdfNyDpN0ECx9MQY5\r\na=ssrc:3135906121 label:262eeec0-fe95-472a-b579-03389273d351\r\n", "dialogParams": { "useVideo": false, "useStereo": true, "screenShare": false, "useCamera": "f76590a55f1c1fd642aae28210b44ba4e366d3e0ec613d8860358fe0bb9ff58c", "useMic": "default", "useSpeak": "default", "tag": "webcam", "localTag": null, "login": "2201@pbx.performityinctest.com", "videoParams": { "minWidth": 1280, "minHeight": 720, "maxWidth": 1280, "maxHeight": 720, "minFrameRate": 15 }, "useStream": null, "destination_number": "2001", "caller_id_name": "Bennett Malbon", "caller_id_number": "bennett.malbon@gmail.com", "outgoingBandwidth": 4377, "incomingBandwidth": null, "dedEnc": false, "mirrorInput": false, "userVariables": { "email": "bennett.malbon@gmail.com", "avatar": "http://gravatar.com/avatar/9264cd2d9ebc0d7d78c2c73b39a5c176.png?s=600" }, "callID": "3d4878b9-8f16-5a58-feee-a300d1e8e84c", "remote_caller_id_name": "Outbound Call", "remote_caller_id_number": "2001" }, "sessid": "cc7e3c7a-d037-28b6-6743-6775eeb505a8" }, "id": 16 }] 2020-02-10 20:26:32.438738 [DEBUG] mod_rtc.c:390 () State Change CS_NEW -> CS_INIT 2020-02-10 20:26:32.438738 [DEBUG] switch_core_session.c:641 N/A set UUID=3d4878b9-8f16-5a58-feee-a300d1e8e84c 2020-02-10 20:26:32.438738 [NOTICE] switch_channel.c:1118 New Channel verto.rtc/2001 [3d4878b9-8f16-5a58-feee-a300d1e8e84c] 2020-02-10 20:26:32.438738 [DEBUG] mod_verto.c:3797 Remote SDP verto.rtc/2001: v=0 o=- 5294435820167355833 2 IN IP4 127.0.0.1 s=- t=0 0 a=group:BUNDLE audio a=msid-semantic: WMS 73CZbHY19upuW80v0kyhdfNyDpN0ECx9MQY5 m=audio 54872 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126 c=IN IP4 75.69.229.242 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:2456471252 1 udp 2122260223 10.0.0.13 54872 typ host generation 0 network-id 1 network-cost 10 a=candidate:3504814172 1 udp 1686052607 75.69.229.242 54872 typ srflx raddr 10.0.0.13 rport 54872 generation 0 network-id 1 network-cost 10 a=candidate:3706272292 1 tcp 1518280447 10.0.0.13 9 typ host tcptype active generation 0 network-id 1 network-cost 10 a=ice-ufrag:7EfF a=ice-pwd:Z8WH62o+Yhj+iqbOdIAapNpG a=ice-options:trickle a=fingerprint:sha-256 24:84:49:A3:18:F7:CC:BC:72:5D:72:3D:14:B4:79:B8:F4:70:76:51:86:9E:11:CD:A8:FE:CD:50:33:D5:BA:90 a=setup:actpass a=mid:audio a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level a=extmap:2 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time a=extmap:3 http://www.ietf.org/id/draft-holmer-rmcat-transport-wide-cc-extensions-01 a=sendrecv a=rtcp-mux a=rtpmap:111 opus/48000/2 a=rtcp-fb:111 transport-cc a=fmtp:111 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1 a=rtpmap:103 ISAC/16000 a=rtpmap:104 ISAC/32000 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:106 CN/32000 a=rtpmap:105 CN/16000 a=rtpmap:13 CN/8000 a=rtpmap:110 telephone-event/48000 a=rtpmap:112 telephone-event/32000 a=rtpmap:113 telephone-event/16000 a=rtpmap:126 telephone-event/8000 a=ssrc:3135906121 cname:4sygjsSsqgZzYttl a=ssrc:3135906121 msid:73CZbHY19upuW80v0kyhdfNyDpN0ECx9MQY5 262eeec0-fe95-472a-b579-03389273d351 a=ssrc:3135906121 mslabel:73CZbHY19upuW80v0kyhdfNyDpN0ECx9MQY5 a=ssrc:3135906121 label:262eeec0-fe95-472a-b579-03389273d351 2020-02-10 20:26:32.438738 [DEBUG] mod_verto.c:607 WRITE 75.69.229.242:55707 [{ "jsonrpc": "2.0", "id": 16, "result": { "message": "CALL CREATED", "callID": "3d4878b9-8f16-5a58-feee-a300d1e8e84c", "sessid": "cc7e3c7a-d037-28b6-6743-6775eeb505a8" } }] 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/2001) Running State Change CS_INIT (Cur 1 Tot 25) 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:628 (verto.rtc/2001) State INIT 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:40 verto.rtc/2001 Standard INIT 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/2001) State Change CS_INIT -> CS_ROUTING 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:628 (verto.rtc/2001) State INIT going to sleep 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/2001) Running State Change CS_ROUTING (Cur 1 Tot 25) 2020-02-10 20:26:32.438738 [DEBUG] switch_channel.c:2332 (verto.rtc/2001) Callstate Change DOWN -> RINGING 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:644 (verto.rtc/2001) State ROUTING 2020-02-10 20:26:32.438738 [DEBUG] mod_rtc.c:89 verto.rtc/2001 RTC ROUTING 2020-02-10 20:26:32.438738 [DEBUG] switch_core_state_machine.c:236 verto.rtc/2001 Standard ROUTING 2020-02-10 20:26:32.438738 [INFO] mod_dialplan_xml.c:637 Processing Bennett Malbon ->2001 in context pbx.performityinctest.com Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->user_exists] continue=true Dialplan: verto.rtc/2001 Regex (PASS) [user_exists] () =~ // break=on-false Dialplan: verto.rtc/2001 Action set(user_exists=${user_exists id ${destination_number} ${domain_name}}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(user_exists=true) 2020-02-10 20:26:32.438738 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [user_exists]=[true] Dialplan: verto.rtc/2001 Action set(from_user_exists=${user_exists id ${sip_from_user} ${sip_from_host}}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(from_user_exists=false) 2020-02-10 20:26:32.438738 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [from_user_exists]=[false] Dialplan: verto.rtc/2001 Regex (PASS) [user_exists] ${user_exists}(true) =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 Action set(extension_uuid=${user_data ${destination_number}@${domain_name} var extension_uuid}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(extension_uuid=cb74a4f9-f557-4e2f-82e9-b822ea00185c) 2020-02-10 20:26:32.438738 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [extension_uuid]=[cb74a4f9-f557-4e2f-82e9-b822ea00185c] Dialplan: verto.rtc/2001 Action set(hold_music=${user_data ${destination_number}@${domain_name} var hold_music}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(hold_music=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [hold_music]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_all_enabled=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_all_enabled]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_all_destination=${user_data ${destination_number}@${domain_name} var forward_all_destination}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_all_destination=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_all_destination]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_busy_enabled=${user_data ${destination_number}@${domain_name} var forward_busy_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_busy_enabled=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_busy_enabled]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_busy_destination=${user_data ${destination_number}@${domain_name} var forward_busy_destination}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_busy_destination=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_busy_destination]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_no_answer_enabled=${user_data ${destination_number}@${domain_name} var forward_no_answer_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_no_answer_enabled=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_no_answer_enabled]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_no_answer_destination=${user_data ${destination_number}@${domain_name} var forward_no_answer_destination}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_no_answer_destination=) 2020-02-10 20:26:32.458742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_no_answer_destination]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_user_not_registered_enabled=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_user_not_registered_enabled=) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_user_not_registered_enabled]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_user_not_registered_destination=${user_data ${destination_number}@${domain_name} var forward_user_not_registered_destination}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_user_not_registered_destination=) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_user_not_registered_destination]=[UNDEF] Dialplan: verto.rtc/2001 Action set(forward_all_enabled=${user_data ${destination_number}@${domain_name} var forward_all_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(forward_all_enabled=) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [forward_all_enabled]=[UNDEF] Dialplan: verto.rtc/2001 Action set(follow_me_enabled=${user_data ${destination_number}@${domain_name} var follow_me_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(follow_me_enabled=) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [follow_me_enabled]=[UNDEF] Dialplan: verto.rtc/2001 Action set(do_not_disturb=${user_data ${destination_number}@${domain_name} var do_not_disturb}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(do_not_disturb=) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [do_not_disturb]=[UNDEF] Dialplan: verto.rtc/2001 Action set(call_timeout=${user_data ${destination_number}@${domain_name} var call_timeout}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(call_timeout=30) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [call_timeout]=[30] Dialplan: verto.rtc/2001 Action set(missed_call_app=${user_data ${destination_number}@${domain_name} var missed_call_app}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(missed_call_app=) 2020-02-10 20:26:32.478742 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [missed_call_app]=[UNDEF] Dialplan: verto.rtc/2001 Action set(missed_call_data=${user_data ${destination_number}@${domain_name} var missed_call_data}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(missed_call_data=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [missed_call_data]=[UNDEF] Dialplan: verto.rtc/2001 Action set(toll_allow=${user_data ${destination_number}@${domain_name} var toll_allow}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(toll_allow=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [toll_allow]=[UNDEF] Dialplan: verto.rtc/2001 Action set(call_screen_enabled=${user_data ${destination_number}@${domain_name} var call_screen_enabled}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(call_screen_enabled=false) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [call_screen_enabled]=[false] Dialplan: verto.rtc/2001 Action set(user_record=${user_data ${destination_number}@${domain_name} var user_record}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(user_record=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [user_record]=[UNDEF] Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->caller-details] continue=true Dialplan: verto.rtc/2001 Regex (PASS) [caller-details] ${caller_destination}() =~ /^$/ break=never Dialplan: verto.rtc/2001 Action set(caller_destination=${destination_number}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(caller_destination=2001) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [caller_destination]=[2001] Dialplan: verto.rtc/2001 Action set(caller_id_name=${caller_id_name}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(caller_id_name=2201) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [caller_id_name]=[2201] Dialplan: verto.rtc/2001 Action set(caller_id_number=${caller_id_number}) Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call-direction] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [call-direction] ${call_direction}() =~ /^(inbound|outbound|local)$/ break=never Dialplan: verto.rtc/2001 ANTI-Action export(call_direction=local) INLINE EXECUTE [depth=0] verto.rtc/2001 export(call_direction=local) 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [call_direction]=[local] Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->variables] continue=true Dialplan: verto.rtc/2001 Regex (PASS) [variables] () =~ // break=on-false Dialplan: verto.rtc/2001 Action export(origination_callee_id_name=${destination_number}) Dialplan: verto.rtc/2001 Action set(RFC2822_DATE=${strftime(%a, %d %b %Y %T %z)}) Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->is_loopback] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [is_loopback] ${is_follow_me_loopback}() =~ /true/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->user_record] continue=true Dialplan: verto.rtc/2001 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${user_record}() =~ /^all$/ break=never Dialplan: verto.rtc/2001 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${user_record}() =~ /^inbound$/ break=never Dialplan: verto.rtc/2001 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${user_record}() =~ /^outbound$/ break=never Dialplan: verto.rtc/2001 Regex (PASS) [user_record] ${user_exists}(true) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${user_record}() =~ /^local$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_record}() =~ /^all$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^inbound$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_record}() =~ /^inbound$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${call_direction}(local) =~ /^outbound$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_record}() =~ /^outbound$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_exists}(false) =~ /^true$/ break=never Dialplan: verto.rtc/2001 Regex (PASS) [user_record] ${call_direction}(local) =~ /^local$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${from_user_record}() =~ /^local$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [user_record] ${record_session}() =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->redial] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [redial] destination_number(2001) =~ /^(redial|\*870)$/ break=on-true Dialplan: verto.rtc/2001 Regex (PASS) [redial] () =~ // break=never Dialplan: verto.rtc/2001 Action hash(insert/${domain_name}-last_dial/${caller_id_number}/${destination_number}) Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->speed_dial] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [speed_dial] destination_number(2001) =~ /^\*0(.*)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->default_caller_id] continue=true Dialplan: verto.rtc/2001 Regex (PASS) [default_caller_id] ${emergency_caller_id_number}() =~ /^$/ break=never Dialplan: verto.rtc/2001 Action set(emergency_caller_id_name=${default_emergency_caller_id_name}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(emergency_caller_id_name=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [emergency_caller_id_name]=[UNDEF] Dialplan: verto.rtc/2001 Action set(emergency_caller_id_number=${default_emergency_caller_id_number}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(emergency_caller_id_number=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [emergency_caller_id_number]=[UNDEF] Dialplan: verto.rtc/2001 Regex (PASS) [default_caller_id] ${outbound_caller_id_number}() =~ /^$/ break=never Dialplan: verto.rtc/2001 Action set(outbound_caller_id_name=${default_outbound_caller_id_name}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(outbound_caller_id_name=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [outbound_caller_id_name]=[UNDEF] Dialplan: verto.rtc/2001 Action set(outbound_caller_id_number=${default_outbound_caller_id_number}) INLINE EXECUTE [depth=0] verto.rtc/2001 set(outbound_caller_id_number=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [outbound_caller_id_number]=[UNDEF] Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->Cisco.PRI] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [Cisco.PRI] ${user_exists}(true) =~ /false/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->Cisco.d4] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [Cisco.d4] ${user_exists}(true) =~ /false/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->verto_screen_share] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [verto_screen_share] destination_number(2001) =~ /^(\d+)-screen$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->agent_status] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [agent_status] destination_number(2001) =~ /^\*22$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [agent_status] destination_number(2001) =~ /^(agent\+)(.*)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->agent_status_id] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [agent_status_id] destination_number(2001) =~ /^\*23$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->TestQue] continue= Dialplan: verto.rtc/2001 Regex (FAIL) [TestQue] destination_number(2001) =~ /^([^#]+#)(.*)$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [TestQue] destination_number(2001) =~ /^3003$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->group-intercept] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [group-intercept] destination_number(2001) =~ /^\*8$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->page-extension] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [page-extension] destination_number(2001) =~ /^\*8(\d{2,7})$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->eavesdrop] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [eavesdrop] destination_number(2001) =~ /^\*33(\d{2,7})$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call_privacy] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [call_privacy] destination_number(2001) =~ /^\*67(\d+)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call_return] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [call_return] destination_number(2001) =~ /^\*69$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->intercept-ext-polycom] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [intercept-ext-polycom] destination_number(2001) =~ /^\*97(\d+)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->extension_queue] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [extension_queue] destination_number(2001) =~ /^\*800(.*)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->intercept-ext] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [intercept-ext] destination_number(2001) =~ /^\*\*(\d+)$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [intercept-ext] destination_number(2001) =~ /^\*\*$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->dx] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [dx] destination_number(2001) =~ /^dx$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->send_to_voicemail] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [send_to_voicemail] destination_number(2001) =~ /^\*99(\d{2,10})$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->extension-to-voicemail] continue=false Dialplan: verto.rtc/2001 Regex (PASS) [extension-to-voicemail] ${user_exists}(true) =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 Regex (FAIL) [extension-to-voicemail] username(2201@pbx.performityinctest.com) =~ /^2201$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->att_xfer] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [att_xfer] destination_number(2001) =~ /^att_xfer$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->xfer_vm] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [xfer_vm] destination_number(2001) =~ /^xfer_vm$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->vmain] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [vmain] destination_number(2001) =~ /^vmain$|^\*4000$|^\*98$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [vmain] destination_number(2001) =~ /^(vmain$|^\*4000$|^\*98)(\d{2,12})$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->vmain_user] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [vmain_user] destination_number(2001) =~ /^\*97$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->is_transfer] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [is_transfer] destination_number(2001) =~ /^is_transfer$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->delay_echo] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [delay_echo] destination_number(2001) =~ /^\*9195$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->cf] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [cf] destination_number(2001) =~ /^cf$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->echo] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [echo] destination_number(2001) =~ /^\*9196$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->is_zrtp_secure] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [is_zrtp_secure] ${zrtp_secure_media_confirmed}() =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 ANTI-Action eval(not_secure) Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->milliwatt] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [milliwatt] destination_number(2001) =~ /^\*9197$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->tone_stream] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [tone_stream] destination_number(2001) =~ /^\*9198$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->is_secure] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [is_secure] ${sip_via_protocol}() =~ /tls/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->hold_music] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [hold_music] destination_number(2001) =~ /^\*9664$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->recordings] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [recordings] destination_number(2001) =~ /^\*(732)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->directory] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [directory] destination_number(2001) =~ /^\*411$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->wake-up] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [wake-up] destination_number(2001) =~ /^\*(925)$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->valet_park] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [valet_park] destination_number(2001) =~ /^(park\+)?\*(59[0-9][0-9])$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [valet_park] ${sip_h_Referred-By}() =~ /sip:(.*)@.*/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [valet_park] destination_number(2001) =~ /^(park\+)?\*(59[0-9][0-9])$/ break=never Dialplan: verto.rtc/2001 Regex (FAIL) [valet_park] destination_number(2001) =~ /^(park\+)?\*(59[0-9][0-9])$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->operator] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [operator] destination_number(2001) =~ /^0$|^operator$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->operator-forward] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [operator-forward] destination_number(2001) =~ /^\*000$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->do-not-disturb] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [do-not-disturb] destination_number(2001) =~ /^\*77$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [do-not-disturb] destination_number(2001) =~ /^\*78$|\*363$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [do-not-disturb] destination_number(2001) =~ /^\*79$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [do-not-disturb] destination_number(2001) =~ /^dnd\+2201$/ break=on-true Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call_screen] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [call_screen] ${call_screen_enabled}(false) =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->follow-me-destinations] continue=false Dialplan: verto.rtc/2001 Regex (PASS) [follow-me-destinations] ${user_exists}(true) =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 Regex (FAIL) [follow-me-destinations] ${follow_me_enabled}() =~ /^true$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call-forward] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [call-forward] destination_number(2001) =~ /^\*72(\d*)$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [call-forward] destination_number(2001) =~ /^\*73$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [call-forward] destination_number(2001) =~ /^\*74$/ break=on-true Dialplan: verto.rtc/2001 Regex (FAIL) [call-forward] destination_number(2001) =~ /^forward\+(\Q2201\E)(?:\/(\d+))?$/ break=on-true Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call forward all] continue=false Dialplan: verto.rtc/2001 Regex (PASS) [call forward all] ${user_exists}(true) =~ /true/ break=on-false Dialplan: verto.rtc/2001 Regex (FAIL) [call forward all] ${forward_all_enabled}() =~ /true/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->call forward not registered] continue=false Dialplan: verto.rtc/2001 Regex (PASS) [call forward not registered] ${user_exists}(true) =~ /true/ break=on-false Dialplan: verto.rtc/2001 Regex (FAIL) [call forward not registered] ${forward_user_not_registered_enabled}() =~ /true/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->follow-me] continue=false Dialplan: verto.rtc/2001 Regex (FAIL) [follow-me] destination_number(2001) =~ /^\*21$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->talking clock date and time] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [talking clock date and time] destination_number(2001) =~ /^\*9172$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->clear_sip_auto_answer] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [clear_sip_auto_answer] ${click_to_call}() =~ /true/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->talking clock time] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [talking clock time] destination_number(2001) =~ /^\*9170$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->talking clock date] continue=true Dialplan: verto.rtc/2001 Regex (FAIL) [talking clock date] destination_number(2001) =~ /^\*9171$/ break=on-false Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->local_extension] continue=true Dialplan: verto.rtc/2001 Regex (PASS) [local_extension] ${user_exists}(true) =~ /true/ break=on-false Dialplan: verto.rtc/2001 Action export(dialed_extension=${destination_number}) INLINE EXECUTE [depth=0] verto.rtc/2001 export(dialed_extension=2001) 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [dialed_extension]=[2001] Dialplan: verto.rtc/2001 Action limit(hash ${domain_name} ${destination_number} ${limit_max} ${limit_destination}) Dialplan: verto.rtc/2001 Regex (PASS) [local_extension] () =~ // break=on-false Dialplan: verto.rtc/2001 Action set(hangup_after_bridge=true) Dialplan: verto.rtc/2001 Action set(continue_on_fail=true) Dialplan: verto.rtc/2001 Action hash(insert/${domain_name}-call_return/${dialed_extension}/${caller_id_number}) Dialplan: verto.rtc/2001 Action hash(insert/${domain_name}-last_dial_ext/${dialed_extension}/${uuid}) Dialplan: verto.rtc/2001 Action set(called_party_call_group=${user_data(${dialed_extension}@${domain_name} var call_group)}) Dialplan: verto.rtc/2001 Action hash(insert/${domain_name}-last_dial/${called_party_call_group}/${uuid}) Dialplan: verto.rtc/2001 Action set(api_hangup_hook=lua app.lua hangup) Dialplan: verto.rtc/2001 Action export(domain_name=${domain_name}) Dialplan: verto.rtc/2001 Action bridge(user/${destination_number}@${domain_name}) Dialplan: verto.rtc/2001 Action lua(app.lua failure_handler) Dialplan: verto.rtc/2001 parsing [pbx.performityinctest.com->voicemail] continue=false Dialplan: verto.rtc/2001 Regex (PASS) [voicemail] ${user_exists}(true) =~ /true/ break=on-false Dialplan: verto.rtc/2001 Action set(record_append=false) Dialplan: verto.rtc/2001 Action set(voicemail_action=save) Dialplan: verto.rtc/2001 Action set(voicemail_id=${destination_number}) Dialplan: verto.rtc/2001 Action set(voicemail_profile=default) Dialplan: verto.rtc/2001 Action lua(app.lua voicemail) 2020-02-10 20:26:32.498741 [DEBUG] switch_core_state_machine.c:287 (verto.rtc/2001) State Change CS_ROUTING -> CS_EXECUTE 2020-02-10 20:26:32.498741 [DEBUG] switch_core_state_machine.c:644 (verto.rtc/2001) State ROUTING going to sleep 2020-02-10 20:26:32.498741 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/2001) Running State Change CS_EXECUTE (Cur 1 Tot 25) 2020-02-10 20:26:32.498741 [DEBUG] switch_core_state_machine.c:651 (verto.rtc/2001) State EXECUTE 2020-02-10 20:26:32.498741 [DEBUG] mod_rtc.c:120 verto.rtc/2001 RTC EXECUTE 2020-02-10 20:26:32.498741 [DEBUG] switch_core_state_machine.c:329 verto.rtc/2001 Standard EXECUTE EXECUTE [depth=0] verto.rtc/2001 set(caller_id_number=2201) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [caller_id_number]=[2201] EXECUTE [depth=0] verto.rtc/2001 export(origination_callee_id_name=2001) 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [origination_callee_id_name]=[2001] EXECUTE [depth=0] verto.rtc/2001 set(RFC2822_DATE=Mon, 10 Feb 2020 20:26:32 +0000) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [RFC2822_DATE]=[Mon, 10 Feb 2020 20:26:32 +0000] EXECUTE [depth=0] verto.rtc/2001 hash(insert/pbx.performityinctest.com-last_dial/2201/2001) EXECUTE [depth=0] verto.rtc/2001 eval(not_secure) EXECUTE [depth=0] verto.rtc/2001 limit(hash pbx.performityinctest.com 2001 5 error/user_busy) 2020-02-10 20:26:32.498741 [DEBUG] switch_limit.c:124 incr called: pbx.performityinctest.com_2001 max:5, interval:0 2020-02-10 20:26:32.498741 [DEBUG] mod_hash.c:196 Usage for pbx.performityinctest.com_2001 is now 1/5 EXECUTE [depth=0] verto.rtc/2001 set(hangup_after_bridge=true) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [hangup_after_bridge]=[true] EXECUTE [depth=0] verto.rtc/2001 set(continue_on_fail=true) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [continue_on_fail]=[true] EXECUTE [depth=0] verto.rtc/2001 hash(insert/pbx.performityinctest.com-call_return/2001/2201) EXECUTE [depth=0] verto.rtc/2001 hash(insert/pbx.performityinctest.com-last_dial_ext/2001/3d4878b9-8f16-5a58-feee-a300d1e8e84c) EXECUTE [depth=0] verto.rtc/2001 set(called_party_call_group=) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [called_party_call_group]=[UNDEF] EXECUTE [depth=0] verto.rtc/2001 hash(insert/pbx.performityinctest.com-last_dial//3d4878b9-8f16-5a58-feee-a300d1e8e84c) EXECUTE [depth=0] verto.rtc/2001 set(api_hangup_hook=lua app.lua hangup) 2020-02-10 20:26:32.498741 [DEBUG] mod_dptools.c:1672 SET verto.rtc/2001 [api_hangup_hook]=[lua app.lua hangup] EXECUTE [depth=0] verto.rtc/2001 export(domain_name=pbx.performityinctest.com) 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1310 EXPORT (export_vars) [domain_name]=[pbx.performityinctest.com] EXECUTE [depth=0] verto.rtc/2001 bridge(user/2001@pbx.performityinctest.com) 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [domain_name]=[pbx.performityinctest.com] to event 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [call_direction]=[local] to event 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [dialed_extension]=[2001] to event 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [origination_callee_id_name]=[2001] to event 2020-02-10 20:26:32.498741 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [domain_name]=[pbx.performityinctest.com] to event 2020-02-10 20:26:32.498741 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [domain_name]=[pbx.performityinctest.com] to event 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [call_direction]=[local] to event 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [dialed_extension]=[2001] to event 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [origination_callee_id_name]=[2001] to event 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:1264 verto.rtc/2001 EXPORTING[export_vars] [domain_name]=[pbx.performityinctest.com] to event 2020-02-10 20:26:32.518742 [DEBUG] switch_ivr_originate.c:2212 Parsing global variables 2020-02-10 20:26:32.518742 [NOTICE] switch_ivr_originate.c:2952 Cannot create outgoing channel of type [error] cause: [USER_NOT_REGISTERED] *** NOTE: no 'originate failed', and both clients show call connected, just without media *** 2020-02-10 20:26:32.518742 [DEBUG] mod_rtc.c:390 () State Change CS_NEW -> CS_INIT 2020-02-10 20:26:32.518742 [NOTICE] switch_channel.c:1118 New Channel verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 [5d064648-18e8-4004-b4e6-bdda6cefa96f] 2020-02-10 20:26:32.518742 [DEBUG] switch_ivr_originate.c:3064 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Setting leg timeout to 30 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Running State Change CS_INIT (Cur 2 Tot 26) 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:628 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State INIT *** 2020-02-10 20:26:32.518742 [CRIT] switch_channel.c:1484 Invalid data (${advertised_media_ip} contains a variable) 2020-02-10 20:26:32.518742 [CRIT] switch_channel.c:1484 Invalid data (${local_video_ip} contains a variable) 2020-02-10 20:26:32.518742 [CRIT] switch_channel.c:1484 Invalid data (${rtp_local_sdp_str} contains a variable) *** 2020-02-10 20:26:32.518742 [DEBUG] mod_verto.c:2272 Local verto.invite SDP verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2: v=0 o=FreeSWITCH 1581346272 1581346273 IN IP4 ${external_rtp_ip} s=FreeSWITCH c=IN IP4 ${external_rtp_ip} t=0 0 a=msid-semantic: WMS GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q m=audio 20120 RTP/SAVPF 102 9 0 8 103 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 opus/48000/2 a=fmtp:103 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 a=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3 a=setup:actpass a=rtcp-mux a=rtcp:20120 IN IP4 ${external_rtp_ip} a=ssrc:1380421024 cname:qTfDHrzty7XiZScD a=ssrc:1380421024 msid:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a0 a=ssrc:1380421024 mslabel:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a=ssrc:1380421024 label:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Qa0 a=ice-ufrag:lO7nNTWvTVZ3KUK1 a=ice-pwd:EQub7UvwRjFH2Ibdm8r0SdmC a=candidate:3536908466 1 udp 659136 ${external_rtp_ip} 20120 typ host generation 0 a=candidate:3536908466 2 udp 659136 ${external_rtp_ip} 20120 typ host generation 0 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 20122 RTP/SAVPF 104 105 b=AS:1024 a=rtpmap:104 VP8/90000 a=rtpmap:105 VP9/90000 a=sendrecv a=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3 a=setup:actpass a=rtcp-mux a=rtcp:20122 IN IP4 ${external_rtp_ip} a=rtcp-fb:104 ccm fir a=rtcp-fb:104 ccm tmmbr a=rtcp-fb:104 nack a=rtcp-fb:104 nack pli a=rtcp-fb:105 ccm fir a=rtcp-fb:105 ccm tmmbr a=rtcp-fb:105 nack a=rtcp-fb:105 nack pli a=ssrc:589759212 cname:qTfDHrzty7XiZScD a=ssrc:589759212 msid:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q v0 a=ssrc:589759212 mslabel:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a=ssrc:589759212 label:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Qv0 a=ice-ufrag:nOqJsoNhRoYS1I6C a=ice-pwd:KbWQrJLKQ7PUJaBXPSw76afN a=candidate:7693262838 1 udp 659136 ${external_rtp_ip} 20122 typ host generation 0 a=candidate:7693262838 2 udp 659135 ${external_rtp_ip} 20122 typ host generation 0 a=end-of-candidates 2020-02-10 20:26:32.518742 [NOTICE] mod_verto.c:2372 Ring-Ready verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2! 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:3437 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Callstate Change DOWN -> RINGING 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:40 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Standard INIT 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State Change CS_INIT -> CS_ROUTING 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:628 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State INIT going to sleep 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Running State Change CS_ROUTING (Cur 2 Tot 26) 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:644 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State ROUTING 2020-02-10 20:26:32.518742 [DEBUG] mod_rtc.c:89 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 RTC ROUTING 2020-02-10 20:26:32.518742 [DEBUG] switch_ivr_originate.c:67 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State Change CS_ROUTING -> CS_CONSUME_MEDIA 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:644 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State ROUTING going to sleep 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 26) 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:111:48000:20:0:2]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [CN:106:32000:20:0:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [CN:105:16000:20:0:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [CN:13:8000:20:0:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5506 Set telephone-event payload to 110@48000 2020-02-10 20:26:32.518742 [DEBUG] mod_opus.c:613 Opus encoder: set bitrate to local settings [120000bps] 2020-02-10 20:26:32.518742 [DEBUG] mod_opus.c:613 Opus encoder: set bitrate to local settings [120000bps] 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:3834 Set Codec verto.rtc/2001 opus/48000 20 ms 960 samples 0 bits 2 channels 2020-02-10 20:26:32.518742 [DEBUG] switch_core_codec.c:111 verto.rtc/2001 Original read codec set to opus:116 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: host addr: 10.0.0.13:54872 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: srflx addr: 75.69.229.242:54872 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:663 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State CONSUME_MEDIA 2020-02-10 20:26:32.518742 [DEBUG] switch_core_state_machine.c:663 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State CONSUME_MEDIA going to sleep 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4324 Searching for rtp candidate. 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4333 Choose rtp candidate, index 1, 75.69.229.242:54872 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4099 verto.rtc/2001 choosing family v4 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4344 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 75.69.229.242:54872 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4396 setting remote audio ice addr to index 1 75.69.229.242:54872 based on candidate 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:4431 Setting remote rtcp audio addr to 75.69.229.242:54872 based on candidate 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5849 Set telephone-event payload to 110@48000 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:5907 verto.rtc/2001 Set 2833 dtmf send payload to 110 recv payload to 110 2020-02-10 20:26:32.518742 [CRIT] switch_channel.c:1484 Invalid data (${advertised_media_ip} contains a variable) 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:8658 AUDIO RTP [verto.rtc/2001] 172.20.253.46 port 31314 -> 75.69.229.242 port 54872 codec: 111 ms: 20 2020-02-10 20:26:32.518742 [CRIT] switch_channel.c:1484 Invalid data (${advertised_media_ip} contains a variable) 2020-02-10 20:26:32.518742 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 960 bytes per 20ms 2020-02-10 20:26:32.518742 [INFO] switch_core_media.c:8840 Activating Audio ICE 2020-02-10 20:26:32.518742 [NOTICE] switch_rtp.c:4910 Activating RTP audio ICE: 7EfF:euKNmM0JJcZQhDh2 75.69.229.242:54872 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:8880 Activating RTCP PORT 54872 2020-02-10 20:26:32.518742 [DEBUG] switch_rtp.c:4806 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 54872 2020-02-10 20:26:32.518742 [INFO] switch_core_media.c:8891 Skipping RTCP ICE (Same as RTP) 2020-02-10 20:26:32.518742 [INFO] switch_rtp.c:3736 Activate RTP/RTCP audio DTLS client 2020-02-10 20:26:32.518742 [INFO] switch_rtp.c:3903 Changing audio DTLS state from OFF to HANDSHAKE 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:2549 Setting Jitterbuffer to 20ms (1 frames) (50 max frames) 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:8972 verto.rtc/2001 Set 2833 dtmf send payload to 110 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:8979 verto.rtc/2001 Set 2833 dtmf receive payload to 110 2020-02-10 20:26:32.518742 [CRIT] switch_channel.c:1484 Invalid data (${rtp_local_sdp_str} contains a variable) 2020-02-10 20:26:32.518742 [DEBUG] switch_core_media.c:8640 Audio params are unchanged for verto.rtc/2001. 2020-02-10 20:26:32.518742 [DEBUG] mod_verto.c:2519 Local SDP verto.rtc/2001: v=0 o=FreeSWITCH 1581335078 1581335079 IN IP4 ${external_rtp_ip} s=FreeSWITCH c=IN IP4 ${external_rtp_ip} t=0 0 a=msid-semantic: WMS tRdhIVXwVqToQK858NgKI2bmx7mpheOA m=audio 31314 UDP/TLS/RTP/SAVPF 111 110 a=rtpmap:111 opus/48000/2 a=fmtp:111 useinbandfec=1; minptime=10; stereo=1; sprop-stereo=1 a=rtpmap:110 telephone-event/48000 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv a=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3 a=setup:active a=rtcp-mux a=rtcp:31314 IN IP4 ${external_rtp_ip} a=ice-ufrag:euKNmM0JJcZQhDh2 a=ice-pwd:mPmPb34Nuw6vYkv3E5HRHxqh a=candidate:4653287215 1 udp 659136 ${external_rtp_ip} 31314 typ host generation 0 a=end-of-candidates a=ssrc:1112046320 cname:VSIuDvRoMACsbBna a=ssrc:1112046320 msid:tRdhIVXwVqToQK858NgKI2bmx7mpheOA a0 a=ssrc:1112046320 mslabel:tRdhIVXwVqToQK858NgKI2bmx7mpheOA a=ssrc:1112046320 label:tRdhIVXwVqToQK858NgKI2bmx7mpheOAa0 2020-02-10 20:26:32.518742 [NOTICE] switch_ivr_originate.c:1246 Pre-Answer verto.rtc/2001! 2020-02-10 20:26:32.518742 [DEBUG] switch_channel.c:3565 (verto.rtc/2001) Callstate Change RINGING -> EARLY 2020-02-10 20:26:32.518742 [DEBUG] switch_ivr_originate.c:1304 Raw Codec Activation Success L16@48000hz 2 channel 20ms 2020-02-10 20:26:32.518742 [DEBUG] switch_core_codec.c:223 verto.rtc/2001 Push codec L16:100 2020-02-10 20:26:32.518742 [DEBUG] switch_ivr_originate.c:1378 Play Ringback Tone [%(2000,4000,440,480)] 2020-02-10 20:26:32.538739 [DEBUG] mod_verto.c:607 WRITE 75.69.229.242:55707 [{ "jsonrpc": "2.0", "id": 39, "method": "verto.media", "params": { "callID": "3d4878b9-8f16-5a58-feee-a300d1e8e84c", "sdp": "v=0\r\no=FreeSWITCH 1581335078 1581335079 IN IP4 ${external_rtp_ip}\r\ns=FreeSWITCH\r\nc=IN IP4 ${external_rtp_ip}\r\nt=0 0\r\na=msid-semantic: WMS tRdhIVXwVqToQK858NgKI2bmx7mpheOA\r\nm=audio 31314 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 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3\r\na=setup:active\r\na=rtcp-mux\r\na=rtcp:31314 IN IP4 ${external_rtp_ip}\r\na=ice-ufrag:euKNmM0JJcZQhDh2\r\na=ice-pwd:mPmPb34Nuw6vYkv3E5HRHxqh\r\na=candidate:4653287215 1 udp 659136 ${external_rtp_ip} 31314 typ host generation 0\r\na=end-of-candidates\r\na=ssrc:1112046320 cname:VSIuDvRoMACsbBna\r\na=ssrc:1112046320 msid:tRdhIVXwVqToQK858NgKI2bmx7mpheOA a0\r\na=ssrc:1112046320 mslabel:tRdhIVXwVqToQK858NgKI2bmx7mpheOA\r\na=ssrc:1112046320 label:tRdhIVXwVqToQK858NgKI2bmx7mpheOAa0\r\n" } }] 2020-02-10 20:26:32.538739 [DEBUG] mod_verto.c:607 WRITE 47.208.143.73:53106 [{ "jsonrpc": "2.0", "id": 38, "method": "verto.invite", "params": { "callID": "5d064648-18e8-4004-b4e6-bdda6cefa96f", "sdp": "v=0\r\no=FreeSWITCH 1581346272 1581346273 IN IP4 ${external_rtp_ip}\r\ns=FreeSWITCH\r\nc=IN IP4 ${external_rtp_ip}\r\nt=0 0\r\na=msid-semantic: WMS GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q\r\nm=audio 20120 RTP/SAVPF 102 9 0 8 103\r\na=rtpmap:102 opus/48000/2\r\na=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=rtpmap:103 opus/48000/2\r\na=fmtp:103 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40\r\na=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:20120 IN IP4 ${external_rtp_ip}\r\na=ssrc:1380421024 cname:qTfDHrzty7XiZScD\r\na=ssrc:1380421024 msid:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a0\r\na=ssrc:1380421024 mslabel:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q\r\na=ssrc:1380421024 label:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Qa0\r\na=ice-ufrag:lO7nNTWvTVZ3KUK1\r\na=ice-pwd:EQub7UvwRjFH2Ibdm8r0SdmC\r\na=candidate:3536908466 1 udp 659136 ${external_rtp_ip} 20120 typ host generation 0\r\na=candidate:3536908466 2 udp 659136 ${external_rtp_ip} 20120 typ host generation 0\r\na=silenceSupp:off - - - -\r\na=ptime:20\r\na=sendrecv\r\nm=video 20122 RTP/SAVPF 104 105\r\nb=AS:1024\r\na=rtpmap:104 VP8/90000\r\na=rtpmap:105 VP9/90000\r\na=sendrecv\r\na=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3\r\na=setup:actpass\r\na=rtcp-mux\r\na=rtcp:20122 IN IP4 ${external_rtp_ip}\r\na=rtcp-fb:104 ccm fir\r\na=rtcp-fb:104 ccm tmmbr\r\na=rtcp-fb:104 nack\r\na=rtcp-fb:104 nack pli\r\na=rtcp-fb:105 ccm fir\r\na=rtcp-fb:105 ccm tmmbr\r\na=rtcp-fb:105 nack\r\na=rtcp-fb:105 nack pli\r\na=ssrc:589759212 cname:qTfDHrzty7XiZScD\r\na=ssrc:589759212 msid:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q v0\r\na=ssrc:589759212 mslabel:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q\r\na=ssrc:589759212 label:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Qv0\r\na=ice-ufrag:nOqJsoNhRoYS1I6C\r\na=ice-pwd:KbWQrJLKQ7PUJaBXPSw76afN\r\na=candidate:7693262838 1 udp 659136 ${external_rtp_ip} 20122 typ host generation 0\r\na=candidate:7693262838 2 udp 659135 ${external_rtp_ip} 20122 typ host generation 0\r\na=end-of-candidates\r\n", "caller_id_name": "Bennett Malbon", "caller_id_number": "bennett.malbon@gmail.com", "callee_id_name": "River Hume", "callee_id_number": "2001", "display_direction": "outbound" } }] 2020-02-10 20:26:32.638740 [DEBUG] mod_verto.c:1415 READ 47.208.143.73:53106 [{ "jsonrpc": "2.0", "id": 38, "result": { "method": "verto.invite" } }] 2020-02-10 20:26:32.638740 [DEBUG] mod_verto.c:1415 READ 75.69.229.242:55707 [{ "jsonrpc": "2.0", "id": 39, "result": { "method": "verto.media" } }] 2020-02-10 20:26:35.298739 [DEBUG] mod_verto.c:1415 READ 47.208.143.73:53106 [{ "jsonrpc": "2.0", "method": "verto.answer", "params": { "sdp": "v=0\r\no=- 2086842449089840571 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=msid-semantic: WMS L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v\r\nm=audio 61518 RTP/SAVPF 102 9 0 8\r\nc=IN IP4 47.208.143.73\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=candidate:544163749 1 udp 2122260223 192.168.203.1 61517 typ host generation 0 network-id 1\r\na=candidate:1817745826 1 udp 2122194687 192.168.11.4 61518 typ host generation 0 network-id 2 network-cost 10\r\na=candidate:1861008213 1 tcp 1518280447 192.168.203.1 9 typ host tcptype active generation 0 network-id 1\r\na=candidate:584803666 1 tcp 1518214911 192.168.11.4 9 typ host tcptype active generation 0 network-id 2 network-cost 10\r\na=candidate:2588467318 1 udp 1685987071 47.208.143.73 61518 typ srflx raddr 192.168.11.4 rport 61518 generation 0 network-id 2 network-cost 10\r\na=ice-ufrag:H55r\r\na=ice-pwd:rzNXN8nz6FBo5Nf3QZz32aNL\r\na=ice-options:trickle\r\na=fingerprint:sha-256 5A:28:05:08:10:7A:E4:87:34:EF:3B:42:64:2E:D4:FC:F4:AB:95:2C:76:3B:8B:F1:E7:02:45:44:15:C7:33:2D\r\na=setup:active\r\na=mid:audio\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:102 opus/48000/2\r\na=fmtp:102 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1\r\na=rtpmap:9 G722/8000\r\na=rtpmap:0 PCMU/8000\r\na=rtpmap:8 PCMA/8000\r\na=ssrc:2328629703 cname:TpichWJD8vJa7eUl\r\na=ssrc:2328629703 msid:L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v b89f0657-9a2d-4e86-b094-a52701603622\r\na=ssrc:2328629703 mslabel:L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v\r\na=ssrc:2328629703 label:b89f0657-9a2d-4e86-b094-a52701603622\r\nm=video 61520 RTP/SAVPF 104 105\r\nc=IN IP4 47.208.143.73\r\na=rtcp:9 IN IP4 0.0.0.0\r\na=candidate:544163749 1 udp 2122260223 192.168.203.1 61519 typ host generation 0 network-id 1\r\na=candidate:1817745826 1 udp 2122194687 192.168.11.4 61520 typ host generation 0 network-id 2 network-cost 10\r\na=candidate:1861008213 1 tcp 1518280447 192.168.203.1 9 typ host tcptype active generation 0 network-id 1\r\na=candidate:584803666 1 tcp 1518214911 192.168.11.4 9 typ host tcptype active generation 0 network-id 2 network-cost 10\r\na=candidate:2588467318 1 udp 1685987071 47.208.143.73 61520 typ srflx raddr 192.168.11.4 rport 61520 generation 0 network-id 2 network-cost 10\r\na=ice-ufrag:/xeC\r\na=ice-pwd:w2ArNzyEcxKMPQ5YpFb7IGBO\r\na=ice-options:trickle\r\na=fingerprint:sha-256 5A:28:05:08:10:7A:E4:87:34:EF:3B:42:64:2E:D4:FC:F4:AB:95:2C:76:3B:8B:F1:E7:02:45:44:15:C7:33:2D\r\na=setup:active\r\na=mid:video\r\na=recvonly\r\na=rtcp-mux\r\na=rtpmap:104 VP8/90000\r\na=rtcp-fb:104 ccm fir\r\na=rtcp-fb:104 nack\r\na=rtcp-fb:104 nack pli\r\na=rtpmap:105 VP9/90000\r\na=rtcp-fb:105 ccm fir\r\na=rtcp-fb:105 nack\r\na=rtcp-fb:105 nack pli\r\na=fmtp:105 profile-id=0\r\n", "dialogParams": { "useStereo": true, "screenShare": false, "useCamera": "b17ca3d0e160db0e8ba5bcdc4d2888451133c8e3ab8cb486618b7a0fb11fed25", "useMic": "default", "useSpeak": "default", "tag": "webcam", "localTag": null, "login": "2001@pbx.performityinctest.com", "videoParams": { "minWidth": 1280, "minHeight": 720, "maxWidth": 1280, "maxHeight": 720, "minFrameRate": 15 }, "useStream": null, "callID": "5d064648-18e8-4004-b4e6-bdda6cefa96f", "caller_id_name": "Bennett Malbon", "caller_id_number": "bennett.malbon@gmail.com", "callee_id_name": "River Hume", "callee_id_number": "2001", "display_direction": "outbound", "wantVideo": true, "remote_caller_id_name": "Bennett Malbon", "remote_caller_id_number": "bennett.malbon@gmail.com" }, "sessid": "7374663b-9d73-f499-a2a6-05d579db6fa2" }, "id": 36 }] 2020-02-10 20:26:35.298739 [DEBUG] mod_verto.c:2753 Remote SDP verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2: v=0 o=- 2086842449089840571 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v m=audio 61518 RTP/SAVPF 102 9 0 8 c=IN IP4 47.208.143.73 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:544163749 1 udp 2122260223 192.168.203.1 61517 typ host generation 0 network-id 1 a=candidate:1817745826 1 udp 2122194687 192.168.11.4 61518 typ host generation 0 network-id 2 network-cost 10 a=candidate:1861008213 1 tcp 1518280447 192.168.203.1 9 typ host tcptype active generation 0 network-id 1 a=candidate:584803666 1 tcp 1518214911 192.168.11.4 9 typ host tcptype active generation 0 network-id 2 network-cost 10 a=candidate:2588467318 1 udp 1685987071 47.208.143.73 61518 typ srflx raddr 192.168.11.4 rport 61518 generation 0 network-id 2 network-cost 10 a=ice-ufrag:H55r a=ice-pwd:rzNXN8nz6FBo5Nf3QZz32aNL a=ice-options:trickle a=fingerprint:sha-256 5A:28:05:08:10:7A:E4:87:34:EF:3B:42:64:2E:D4:FC:F4:AB:95:2C:76:3B:8B:F1:E7:02:45:44:15:C7:33:2D a=setup:active a=mid:audio a=sendrecv a=rtcp-mux a=rtpmap:102 opus/48000/2 a=fmtp:102 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=ssrc:2328629703 cname:TpichWJD8vJa7eUl a=ssrc:2328629703 msid:L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v b89f0657-9a2d-4e86-b094-a52701603622 a=ssrc:2328629703 mslabel:L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v a=ssrc:2328629703 label:b89f0657-9a2d-4e86-b094-a52701603622 m=video 61520 RTP/SAVPF 104 105 c=IN IP4 47.208.143.73 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:544163749 1 udp 2122260223 192.168.203.1 61519 typ host generation 0 network-id 1 a=candidate:1817745826 1 udp 2122194687 192.168.11.4 61520 typ host generation 0 network-id 2 network-cost 10 a=candidate:1861008213 1 tcp 1518280447 192.168.203.1 9 typ host tcptype active generation 0 network-id 1 a=candidate:584803666 1 tcp 1518214911 192.168.11.4 9 typ host tcptype active generation 0 network-id 2 network-cost 10 a=candidate:2588467318 1 udp 1685987071 47.208.143.73 61520 typ srflx raddr 192.168.11.4 rport 61520 generation 0 network-id 2 network-cost 10 a=ice-ufrag:/xeC a=ice-pwd:w2ArNzyEcxKMPQ5YpFb7IGBO a=ice-options:trickle a=fingerprint:sha-256 5A:28:05:08:10:7A:E4:87:34:EF:3B:42:64:2E:D4:FC:F4:AB:95:2C:76:3B:8B:F1:E7:02:45:44:15:C7:33:2D a=setup:active a=mid:video a=recvonly a=rtcp-mux a=rtpmap:104 VP8/90000 a=rtcp-fb:104 ccm fir a=rtcp-fb:104 nack a=rtcp-fb:104 nack pli a=rtpmap:105 VP9/90000 a=rtcp-fb:105 ccm fir a=rtcp-fb:105 nack a=rtcp-fb:105 nack pli a=fmtp:105 profile-id=0 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:2] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [opus:116:48000:20:0:2] ++++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:102:48000:20:0:2]/[G722:9:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMU:0:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:102:48000:20:0:2]/[PCMA:8:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [opus:102:48000:20:0:2]/[opus:116:48000:20:0:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:2] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [G722:9:8000:20:64000:1] ++++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [G722:9:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:2] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:2] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[G722:9:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5645 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5590 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1] 2020-02-10 20:26:35.298739 [DEBUG] mod_opus.c:613 Opus encoder: set bitrate to local settings [120000bps] 2020-02-10 20:26:35.298739 [DEBUG] mod_opus.c:613 Opus encoder: set bitrate to local settings [120000bps] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:3834 Set Codec verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 opus/48000 20 ms 960 samples 0 bits 2 channels 2020-02-10 20:26:35.298739 [DEBUG] switch_core_codec.c:111 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Original read codec set to opus:116 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.203.1:61517 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.11.4:61518 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4279 Save audio Candidate cid: 1 proto: udp type: srflx addr: 47.208.143.73:61518 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4324 Searching for rtp candidate. 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4333 Choose rtp candidate, index 2, 47.208.143.73:61518 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4099 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 choosing family v4 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4344 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 47.208.143.73:61518 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4396 setting remote audio ice addr to index 2 47.208.143.73:61518 based on candidate 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4431 Setting remote rtcp audio addr to 47.208.143.73:61518 based on candidate 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:5914 No 2833 in SDP. Disable 2833 dtmf and switch to INFO 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:6191 Video Codec Compare [VP8:104]/[VP8:99] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:6223 Video Codec Compare [VP8:104] +++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:6191 Video Codec Compare [VP8:104]/[VP9:99] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:6191 Video Codec Compare [VP9:105]/[VP8:99] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:6191 Video Codec Compare [VP9:105]/[VP9:99] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:6223 Video Codec Compare [VP9:105] +++ is saved as a match 2020-02-10 20:26:35.298739 [DEBUG] switch_vpx.c:703 VPX VER:v1.7.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:8 2020-02-10 20:26:35.298739 [DEBUG] switch_vpx.c:703 VPX VER:v1.7.0 VPX_IMAGE_ABI_VERSION:4 VPX_CODEC_ABI_VERSION:8 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:3644 Set VIDEO Codec verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 VP8/90000 0 ms 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4279 Save video Candidate cid: 1 proto: udp type: host addr: 192.168.203.1:61519 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4279 Save video Candidate cid: 1 proto: udp type: host addr: 192.168.11.4:61520 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4279 Save video Candidate cid: 1 proto: udp type: srflx addr: 47.208.143.73:61520 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4324 Searching for rtp candidate. 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4333 Choose rtp candidate, index 2, 47.208.143.73:61520 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4099 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 choosing family v4 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4344 Choose same candidate, index 0, for rtcp based on rtcp-mux attribute 47.208.143.73:61520 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4396 setting remote video ice addr to index 2 47.208.143.73:61520 based on candidate 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:4431 Setting remote rtcp video addr to 47.208.143.73:61520 based on candidate 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:8658 AUDIO RTP [verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2] 172.20.253.46 port 20120 -> 47.208.143.73 port 61518 codec: 102 ms: 20 2020-02-10 20:26:35.298739 [CRIT] switch_channel.c:1484 Invalid data (${advertised_media_ip} contains a variable) 2020-02-10 20:26:35.298739 [DEBUG] switch_rtp.c:4408 Starting timer [soft] 960 bytes per 20ms 2020-02-10 20:26:35.298739 [INFO] switch_core_media.c:8840 Activating Audio ICE 2020-02-10 20:26:35.298739 [NOTICE] switch_rtp.c:4910 Activating RTP audio ICE: H55r:lO7nNTWvTVZ3KUK1 47.208.143.73:61518 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:8880 Activating RTCP PORT 61518 2020-02-10 20:26:35.298739 [DEBUG] switch_rtp.c:4806 RTCP send rate is: 1000 and packet rate is: 20000 Remote Port: 61518 2020-02-10 20:26:35.298739 [INFO] switch_core_media.c:8891 Skipping RTCP ICE (Same as RTP) 2020-02-10 20:26:35.298739 [INFO] switch_rtp.c:3736 Activate RTP/RTCP audio DTLS server 2020-02-10 20:26:35.298739 [INFO] switch_rtp.c:3903 Changing audio DTLS state from OFF to HANDSHAKE 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:2549 Setting Jitterbuffer to 20ms (1 frames) (50 max frames) 2020-02-10 20:26:35.298739 [CRIT] switch_channel.c:1484 Invalid data (${local_video_ip} contains a variable) 2020-02-10 20:26:35.298739 [DEBUG] switch_rtp.c:4423 Starting video timer. 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:9504 VIDEO RTP [verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2] 172.20.253.46:20122->47.208.143.73:61520 codec: 104 ms: 0 [SUCCESS] 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:7625 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Starting Video thread 2020-02-10 20:26:35.298739 [DEBUG] switch_core_media.c:7491 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Video thread started. Echo is off 2020-02-10 20:26:35.298739 [INFO] switch_core_media.c:9548 Activating Video ICE 2020-02-10 20:26:35.298739 [NOTICE] switch_rtp.c:4910 Activating RTP video ICE: /xeC:nOqJsoNhRoYS1I6C 47.208.143.73:61520 2020-02-10 20:26:35.298739 [INFO] switch_core_media.c:9585 Activating VIDEO RTCP PORT 61520 interval 1000 mux 1 2020-02-10 20:26:35.298739 [DEBUG] switch_rtp.c:4806 RTCP send rate is: 1000 and packet rate is: 90000 Remote Port: 61520 2020-02-10 20:26:35.298739 [INFO] switch_core_media.c:9598 Skipping VIDEO RTCP ICE (Same as VIDEO RTP) 2020-02-10 20:26:35.298739 [INFO] switch_rtp.c:3736 Activate RTP/RTCP video DTLS server 2020-02-10 20:26:35.318744 [INFO] switch_rtp.c:3903 Changing video DTLS state from OFF to HANDSHAKE 2020-02-10 20:26:35.318744 [DEBUG] switch_core_media.c:8640 Audio params are unchanged for verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2. 2020-02-10 20:26:35.318744 [DEBUG] switch_core_media.c:9361 Video params are unchanged for verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2. 2020-02-10 20:26:35.318744 [NOTICE] mod_verto.c:2787 Channel [verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2] has been answered 2020-02-10 20:26:35.318744 [DEBUG] switch_channel.c:3865 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Callstate Change RINGING -> ACTIVE 2020-02-10 20:26:35.318744 [DEBUG] mod_verto.c:607 WRITE 47.208.143.73:53106 [{ "jsonrpc": "2.0", "id": 36, "result": { "sessid": "7374663b-9d73-f499-a2a6-05d579db6fa2" } }] 2020-02-10 20:26:35.318744 [DEBUG] switch_core_codec.c:248 verto.rtc/2001 Restore previous codec opus:116. 2020-02-10 20:26:35.338741 [DEBUG] mod_verto.c:607 WRITE 75.69.229.242:55707 [{ "jsonrpc": "2.0", "id": 40, "method": "verto.answer", "params": { "callID": "3d4878b9-8f16-5a58-feee-a300d1e8e84c" } }] 2020-02-10 20:26:35.418737 [INFO] switch_vpx.c:564 config: vp8 2020-02-10 20:26:35.418737 [NOTICE] switch_vpx.c:599 VPX encoder reset (WxH/BW) from 0x0/0 to 352x288/1024 2020-02-10 20:26:35.478737 [DEBUG] mod_verto.c:1415 READ 75.69.229.242:55707 [{ "jsonrpc": "2.0", "id": 40, "result": { "method": "verto.answer" } }] 2020-02-10 20:26:42.998738 [DEBUG] mod_verto.c:1415 READ 47.208.143.73:53106 [{ "jsonrpc": "2.0", "method": "verto.bye", "params": { "dialogParams": { "useStereo": true, "screenShare": false, "useCamera": "b17ca3d0e160db0e8ba5bcdc4d2888451133c8e3ab8cb486618b7a0fb11fed25", "useMic": "default", "useSpeak": "default", "tag": "webcam", "localTag": null, "login": "2001@pbx.performityinctest.com", "videoParams": { "minWidth": 1280, "minHeight": 720, "maxWidth": 1280, "maxHeight": 720, "minFrameRate": 15 }, "useStream": null, "callID": "5d064648-18e8-4004-b4e6-bdda6cefa96f", "caller_id_name": "Bennett Malbon", "caller_id_number": "bennett.malbon@gmail.com", "callee_id_name": "River Hume", "callee_id_number": "2001", "display_direction": "outbound", "wantVideo": true, "remote_caller_id_name": "Bennett Malbon", "remote_caller_id_number": "bennett.malbon@gmail.com" }, "sessid": "7374663b-9d73-f499-a2a6-05d579db6fa2" }, "id": 37 }] 2020-02-10 20:26:42.998738 [NOTICE] mod_verto.c:2867 Hangup verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 [CS_CONSUME_MEDIA] [NORMAL_CLEARING] 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Running State Change CS_HANGUP (Cur 2 Tot 26) 2020-02-10 20:26:42.998738 [DEBUG] mod_verto.c:607 WRITE 47.208.143.73:53106 [{ "jsonrpc": "2.0", "id": 37, "result": { "callID": "5d064648-18e8-4004-b4e6-bdda6cefa96f", "message": "CALL ENDED", "causeCode": 16, "cause": "NORMAL_CLEARING", "sessid": "7374663b-9d73-f499-a2a6-05d579db6fa2" } }] 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:848 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Callstate Change ACTIVE -> HANGUP 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State HANGUP 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:850 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 skip receive message [VIDEO_REFRESH_REQ] (channel is hungup already) 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:60 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Standard HANGUP, cause: NORMAL_CLEARING 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State HANGUP going to sleep 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:620 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State Change CS_HANGUP -> CS_REPORTING 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:585 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Running State Change CS_REPORTING (Cur 2 Tot 26) 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:936 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State REPORTING 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:174 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Standard REPORTING, cause: NORMAL_CLEARING 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:936 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State REPORTING going to sleep 2020-02-10 20:26:42.998738 [DEBUG] switch_core_state_machine.c:611 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) State Change CS_REPORTING -> CS_DESTROY 2020-02-10 20:26:42.998738 [DEBUG] switch_core_session.c:1726 Session 26 (verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2) Locked, Waiting on external entities 2020-02-10 20:26:42.998738 [DEBUG] switch_core_media.c:7592 verto.rtc/7374663b-9d73-f499-a2a6-05d579db6fa2 Video thread ended ------------------------- WEB CONSOLE OUTPUT: Dialog 5d064648-18e8-4004-b4e6-bdda6cefa96f: state change from new to ringing scripts.js:13339 onDialogState: a.verto.dialog {params: {…}, verto: a.verto, direction: {…}, lastState: {…}, state: {…}, …}params: {useVideo: undefined, useStereo: true, screenShare: false, useCamera: "b17ca3d0e160db0e8ba5bcdc4d2888451133c8e3ab8cb486618b7a0fb11fed25", useMic: "default", …}verto: a.verto {options: {…}, sessid: "7374663b-9d73-f499-a2a6-05d579db6fa2", dialogs: {…}, callbacks: {…}, eventSUBS: {…}, …}direction: {name: "inbound", val: 0}lastState: {name: "hangup", val: 9}state: {name: "destroy", val: 10}callbacks: {onWSLogin: ƒ, onMessage: ƒ, onDialogState: ƒ, onWSClose: ƒ, onEvent: ƒ}answered: trueattach: falsescreenShare: falseuseCamera: "b17ca3d0e160db0e8ba5bcdc4d2888451133c8e3ab8cb486618b7a0fb11fed25"useCameraLabel: undefineduseMic: "default"useMicLabel: undefineduseSpeak: "default"callID: "5d064648-18e8-4004-b4e6-bdda6cefa96f"audioStream: video#webcam.hidertc: a.FSRTC {options: {…}, audioEnabled: true, videoEnabled: true, mediaData: {…}, constraints: {…}, …}cause: "NORMAL_CLEARING"__proto__: Object scripts.js:11875 Incoming call from: bennett.malbon@gmail.com scripts.js:11889 Mon Feb 10 2020 12:25:13 GMT-0800 (Pacific Standard Time) scripts.js:1122 inbound sdp: v=0 o=FreeSWITCH 1581346272 1581346273 IN IP4 ${external_rtp_ip} s=FreeSWITCH c=IN IP4 ${external_rtp_ip} t=0 0 a=msid-semantic: WMS GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q m=audio 20120 RTP/SAVPF 102 9 0 8 103 a=rtpmap:102 opus/48000/2 a=fmtp:102 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40; stereo=1 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:103 opus/48000/2 a=fmtp:103 useinbandfec=1; maxaveragebitrate=30000; maxplaybackrate=48000; ptime=20; minptime=10; maxptime=40 a=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3 a=setup:actpass a=rtcp-mux a=rtcp:20120 IN IP4 ${external_rtp_ip} a=ssrc:1380421024 cname:qTfDHrzty7XiZScD a=ssrc:1380421024 msid:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a0 a=ssrc:1380421024 mslabel:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a=ssrc:1380421024 label:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Qa0 a=ice-ufrag:lO7nNTWvTVZ3KUK1 a=ice-pwd:EQub7UvwRjFH2Ibdm8r0SdmC a=candidate:3536908466 1 udp 659136 ${external_rtp_ip} 20120 typ host generation 0 a=candidate:3536908466 2 udp 659136 ${external_rtp_ip} 20120 typ host generation 0 a=silenceSupp:off - - - - a=ptime:20 a=sendrecv m=video 20122 RTP/SAVPF 104 105 b=AS:1024 a=rtpmap:104 VP8/90000 a=rtpmap:105 VP9/90000 a=sendrecv a=fingerprint:sha-256 96:E9:38:23:96:4C:07:4E:61:4F:80:B7:05:E6:BE:BA:04:CA:F3:69:B6:90:E0:43:59:AD:F1:A9:4B:D1:57:C3 a=setup:actpass a=rtcp-mux a=rtcp:20122 IN IP4 ${external_rtp_ip} a=rtcp-fb:104 ccm fir a=rtcp-fb:104 ccm tmmbr a=rtcp-fb:104 nack a=rtcp-fb:104 nack pli a=rtcp-fb:105 ccm fir a=rtcp-fb:105 ccm tmmbr a=rtcp-fb:105 nack a=rtcp-fb:105 nack pli a=ssrc:589759212 cname:qTfDHrzty7XiZScD a=ssrc:589759212 msid:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q v0 a=ssrc:589759212 mslabel:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q a=ssrc:589759212 label:GBYymXl6WhHDT244NCLEc9WJS98DkZ4Qv0 a=ice-ufrag:nOqJsoNhRoYS1I6C a=ice-pwd:KbWQrJLKQ7PUJaBXPSw76afN a=candidate:7693262838 1 udp 659136 ${external_rtp_ip} 20122 typ host generation 0 a=candidate:7693262838 2 udp 659135 ${external_rtp_ip} 20122 typ host generation 0 a=end-of-candidates scripts.js:1304 Camera Disabled scripts.js:1163 Audio constraints {googEchoCancellation: true, googNoiseSuppression: true, googHighpassFilter: true, googAutoGainControl: true, googAutoGainControl2: true, …}googEchoCancellation: truegoogNoiseSuppression: truegoogHighpassFilter: truegoogAutoGainControl: truegoogAutoGainControl2: truedeviceId: {deviceId: {…}}__proto__: Object scripts.js:1164 Video constraints false scripts.js:1707 Tried to use constraint fallbacks but did not found vendor function `assureMediaInputId` on window scope. Did you forget to import `vendor/media-device-id.js` before Verto? v @ scripts.js:1707 z @ scripts.js:1765 a.FSRTC.createAnswer @ scripts.js:1190 a.verto.dialog.answer @ scripts.js:4460 a.answerCall @ scripts.js:11943 (anonymous) @ scripts.js:11891 i @ vendor.js:22848 (anonymous) @ vendor.js:22864 $eval @ vendor.js:24100 $digest @ vendor.js:23916 $apply @ vendor.js:24205 (anonymous) @ vendor.js:31235 dispatch @ vendor.js:4435 q.handle @ vendor.js:4121 scripts.js:1707 Tried to use constraint fallbacks but did not found vendor function `assureMediaInputId` on window scope. Did you forget to import `vendor/media-device-id.js` before Verto? v @ scripts.js:1707 z @ scripts.js:1766 a.FSRTC.createAnswer @ scripts.js:1190 a.verto.dialog.answer @ scripts.js:4460 a.answerCall @ scripts.js:11943 (anonymous) @ scripts.js:11891 i @ vendor.js:22848 (anonymous) @ vendor.js:22864 $eval @ vendor.js:24100 $digest @ vendor.js:23916 $apply @ vendor.js:24205 (anonymous) @ vendor.js:31235 dispatch @ vendor.js:4435 q.handle @ vendor.js:4121 scripts.js:14061 0 scripts.js:11251 Executing InCallController. scripts.js:921 Stream Success scripts.js:3958 stream started scripts.js:1504 Peer Track RTCTrackEvent {isTrusted: true, transceiver: {…}, receiver: RTCRtpReceiver, track: MediaStreamTrack, streams: Array(1), …} scripts.js:991 REMOTE STREAM MediaStream {id: "GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q", active: true, onaddtrack: null, onremovetrack: null, onactive: null, …} ​ scripts.js:926 Remote Stream Success scripts.js:3965 remote stream started scripts.js:1504 Peer Track RTCTrackEvent {isTrusted: true, transceiver: {…}, receiver: RTCRtpReceiver, track: MediaStreamTrack, streams: Array(1), …} scripts.js:991 REMOTE STREAM MediaStream {id: "GBYymXl6WhHDT244NCLEc9WJS98DkZ4Q", active: true, onaddtrack: null, onremovetrack: null, onactive: null, …} ​ scripts.js:926 Remote Stream Success scripts.js:3965 remote stream started scripts.js:11385 broadcast time-start incall scripts.js:944 ICE Complete scripts.js:955 ICE SDP scripts.js:3912 RECV answer SDP v=0 o=- 2086842449089840571 2 IN IP4 127.0.0.1 s=- t=0 0 a=msid-semantic: WMS L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v m=audio 61518 RTP/SAVPF 102 9 0 8 c=IN IP4 47.208.143.73 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:544163749 1 udp 2122260223 192.168.203.1 61517 typ host generation 0 network-id 1 a=candidate:1817745826 1 udp 2122194687 192.168.11.4 61518 typ host generation 0 network-id 2 network-cost 10 a=candidate:1861008213 1 tcp 1518280447 192.168.203.1 9 typ host tcptype active generation 0 network-id 1 a=candidate:584803666 1 tcp 1518214911 192.168.11.4 9 typ host tcptype active generation 0 network-id 2 network-cost 10 a=candidate:2588467318 1 udp 1685987071 47.208.143.73 61518 typ srflx raddr 192.168.11.4 rport 61518 generation 0 network-id 2 network-cost 10 a=ice-ufrag:H55r a=ice-pwd:rzNXN8nz6FBo5Nf3QZz32aNL a=ice-options:trickle a=fingerprint:sha-256 5A:28:05:08:10:7A:E4:87:34:EF:3B:42:64:2E:D4:FC:F4:AB:95:2C:76:3B:8B:F1:E7:02:45:44:15:C7:33:2D a=setup:active a=mid:audio a=sendrecv a=rtcp-mux a=rtpmap:102 opus/48000/2 a=fmtp:102 minptime=10;useinbandfec=1; stereo=1; sprop-stereo=1 a=rtpmap:9 G722/8000 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=ssrc:2328629703 cname:TpichWJD8vJa7eUl a=ssrc:2328629703 msid:L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v b89f0657-9a2d-4e86-b094-a52701603622 a=ssrc:2328629703 mslabel:L0aEOuZ3LaFUV6AIRKXnRO3LiVXme4Lo9e2v a=ssrc:2328629703 label:b89f0657-9a2d-4e86-b094-a52701603622 m=video 61520 RTP/SAVPF 104 105 c=IN IP4 47.208.143.73 a=rtcp:9 IN IP4 0.0.0.0 a=candidate:544163749 1 udp 2122260223 192.168.203.1 61519 typ host generation 0 network-id 1 a=candidate:1817745826 1 udp 2122194687 192.168.11.4 61520 typ host generation 0 network-id 2 network-cost 10 a=candidate:1861008213 1 tcp 1518280447 192.168.203.1 9 typ host tcptype active generation 0 network-id 1 a=candidate:584803666 1 tcp 1518214911 192.168.11.4 9 typ host tcptype active generation 0 network-id 2 network-cost 10 a=candidate:2588467318 1 udp 1685987071 47.208.143.73 61520 typ srflx raddr 192.168.11.4 rport 61520 generation 0 network-id 2 network-cost 10 a=ice-ufrag:/xeC a=ice-pwd:w2ArNzyEcxKMPQ5YpFb7IGBO a=ice-options:trickle a=fingerprint:sha-256 5A:28:05:08:10:7A:E4:87:34:EF:3B:42:64:2E:D4:FC:F4:AB:95:2C:76:3B:8B:F1:E7:02:45:44:15:C7:33:2D a=setup:active a=mid:video a=recvonly a=rtcp-mux a=rtpmap:104 VP8/90000 a=rtcp-fb:104 ccm fir a=rtcp-fb:104 nack a=rtcp-fb:104 nack pli a=rtpmap:105 VP9/90000 a=rtcp-fb:105 ccm fir a=rtcp-fb:105 nack a=rtcp-fb:105 nack pli a=fmtp:105 profile-id=0 scripts.js:4116 Dialog 5d064648-18e8-4004-b4e6-bdda6cefa96f: state change from ringing to answering scripts.js:13339 onDialogState: a.verto.dialog {params: {…}, verto: a.verto, direction: {…}, lastState: {…}, state: {…}, …} *** not implemented state: destroy ??? *** scripts.js:13375 Got a not implemented state: a.verto.dialog {params: {…}, verto: a.verto, direction: {…}, lastState: {…}, state: {…}, …}params: {useVideo: undefined, useStereo: true, screenShare: false, useCamera: "b17ca3d0e160db0e8ba5bcdc4d2888451133c8e3ab8cb486618b7a0fb11fed25", useMic: "default", …}verto: a.verto {options: {…}, sessid: "7374663b-9d73-f499-a2a6-05d579db6fa2", dialogs: {…}, callbacks: {…}, eventSUBS: {…}, …}direction: {name: "inbound", val: 0}lastState: {name: "hangup", val: 9} state: name: "destroy"val: 10__proto__: Objectcallbacks: {onWSLogin: ƒ, onMessage: ƒ, onDialogState: ƒ, onWSClose: ƒ, onEvent: ƒ}answered: trueattach: falsescreenShare: falseuseCamera: "b17ca3d0e160db0e8ba5bcdc4d2888451133c8e3ab8cb486618b7a0fb11fed25"useCameraLabel: undefineduseMic: "default"useMicLabel: undefineduseSpeak: "default"callID: "5d064648-18e8-4004-b4e6-bdda6cefa96f"audioStream: video#webcam.hidertc: a.FSRTC {options: {…}, audioEnabled: true, videoEnabled: true, mediaData: {…}, constraints: {…}, …}cause: "NORMAL_CLEARING"__proto__: Object onDialogState @ scripts.js:13375 a.verto.dialog.setState @ scripts.js:4122 f.onICESDP @ scripts.js:3933 l @ scripts.js:939 o @ scripts.js:956 onICESDP @ scripts.js:1140 b @ scripts.js:1452 setTimeout (async) o.onicecandidate @ scripts.js:1464 scripts.js:4116 Dialog 5d064648-18e8-4004-b4e6-bdda6cefa96f: state change from answering to active scripts.js:13339 onDialogState: a.verto.dialog {params: {…}, verto: a.verto, direction: {…}, lastState: {…}, state: {…}, …} scripts.js:13354 Talking to: Bennett Malbon scripts.js:4131 Using Speaker: default scripts.js:12812 Setting video size to NaN/null scripts.js:4075 Dialog: 5d064648-18e8-4004-b4e6-bdda6cefa96f Setting speaker: ​ Default - Speakers (Dell USB Audio) (17e9:436e) scripts.js:4079 Dialog: 5d064648-18e8-4004-b4e6-bdda6cefa96f Success, audio output device attached: default scripts.js:13659 Attempting to hangup the current call. scripts.js:4116 Dialog 5d064648-18e8-4004-b4e6-bdda6cefa96f: state change from active to hangup scripts.js:13339 onDialogState: a.verto.dialog {params: {…}, verto: a.verto, direction: {…}, lastState: {…}, state: {…}, …} scripts.js:13360 Call ended with cause: NORMAL_CLEARING scripts.js:4116 Dialog 5d064648-18e8-4004-b4e6-bdda6cefa96f: state change from hangup to destroy scripts.js:13339 onDialogState: a.verto.dialog {params: {…}, verto: a.verto, direction: {…}, lastState: {…}, state: {…}, …} scripts.js:13364 Destroying: NORMAL_CLEARING scripts.js:13251 stopConference() scripts.js:13258 Doesn't found data.liveArray. scripts.js:11772 Redirecting to dialpad page. scripts.js:11778 not digest scripts.js:1033 Stopping localStream tracks: [MediaStreamTrack] scripts.js:1049 stopping peer scripts.js:13673 The call was hangup. scripts.js:11102 Executing DialPadController.