2017-05-18 18:27:05.704303 [DEBUG] mod_verto.c:4064 89.1.250.120:60761 Client Connect from 89.1.250.120:60761 accepted
2017-05-18 18:27:05.704303 [DEBUG] mod_verto.c:1978 89.1.250.120:60761 Starting client thread.
2017-05-18 18:27:05.744296 [DEBUG] mod_verto.c:1267 89.1.250.120:60761 re-connecting session 29958187-3a76-c51b-2e6c-cdf1e5d92f49
2017-05-18 18:27:28.404299 [DEBUG] mod_verto.c:4064 89.1.250.120:60816 Client Connect from 89.1.250.120:60816 accepted
2017-05-18 18:27:28.404299 [DEBUG] mod_verto.c:1978 89.1.250.120:60816 Starting client thread.
2017-05-18 18:27:28.444300 [DEBUG] mod_verto.c:1267 89.1.250.120:60816 re-connecting session 85f46bc0-257b-df98-4db7-a32d1e941279
2017-05-18 18:27:36.504289 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT
2017-05-18 18:27:36.504289 [DEBUG] switch_core_session.c:613 N/A set UUID=85f4dcc6-3b5e-183e-af2f-925d5db97b66
2017-05-18 18:27:36.504289 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/1001 [85f4dcc6-3b5e-183e-af2f-925d5db97b66]
2017-05-18 18:27:36.504289 [DEBUG] mod_verto.c:3603 Remote SDP verto.rtc/1001:
v=0
o=- 1081317877255920020 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS 7Idx1eQKTwlSZEC1lCROARBqn9vrN8T1yspw
m=audio 50533 UDP/TLS/RTP/SAVPF 111 103 104 9 0 8 106 105 13 110 112 113 126
c=IN IP4 89.1.250.120
a=rtcp:9 IN IP4 0.0.0.0
a=candidate:1543227530 1 udp 2122265343 fd66:1762:b6b8:1000:59fe:c8b2:6a05:3c50 50532 typ host generation 0 network-id 3 network-cost 50
a=candidate:1566881451 1 udp 2122194687 89.1.250.120 50533 typ host generation 0 network-id 2
a=candidate:2999745851 1 udp 2122129151 192.168.56.1 50534 typ host generation 0 network-id 1
a=candidate:360199290 1 tcp 1518285567 fd66:1762:b6b8:1000:59fe:c8b2:6a05:3c50 9 typ host tcptype active generation 0 network-id 3 network-cost 50
a=candidate:333924955 1 tcp 1518214911 89.1.250.120 9 typ host tcptype active generation 0 network-id 2
a=candidate:4233069003 1 tcp 1518149375 192.168.56.1 9 typ host tcptype active generation 0 network-id 1
a=ice-ufrag:afPg
a=ice-pwd:rcj6SsVgZRjRkJWJYBnEOPtY
a=fingerprint:sha-256 2A:E9:59:A0:D2:73:69:7F:B5:F7:9B:A7:C3:B3:03:3E:5F:E9:5C:B5:ED:E2:F1:3E:66:A1:32:77:F5:8D:00:04
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
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:1992292474 cname:bQsBu1h5TT6DmiUv
a=ssrc:1992292474 msid:7Idx1eQKTwlSZEC1lCROARBqn9vrN8T1yspw 5497791f-6fdd-49b8-9931-b6646a243cf0
a=ssrc:1992292474 mslabel:7Idx1eQKTwlSZEC1lCROARBqn9vrN8T1yspw
a=ssrc:1992292474 label:5497791f-6fdd-49b8-9931-b6646a243cf0

2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1001) Running State Change CS_INIT (Cur 1 Tot 46)
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/1001) State INIT
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:40 verto.rtc/1001 Standard INIT
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/1001) State Change CS_INIT -> CS_ROUTING
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/1001) State INIT going to sleep
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1001) Running State Change CS_ROUTING (Cur 1 Tot 46)
2017-05-18 18:27:36.504289 [DEBUG] switch_channel.c:2249 (verto.rtc/1001) Callstate Change DOWN -> RINGING
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/1001) State ROUTING
2017-05-18 18:27:36.504289 [DEBUG] mod_rtc.c:89 verto.rtc/1001 RTC ROUTING
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:236 verto.rtc/1001 Standard ROUTING
2017-05-18 18:27:36.504289 [INFO] mod_dialplan_xml.c:637 Processing 1000 <1000>->1001 in context public
Dialplan: verto.rtc/1001 parsing [public->verto call] continue=true
Dialplan: verto.rtc/1001 Regex (PASS) [verto call] destination_number(1001) =~ /^(\d+)$/ break=on-false
Dialplan: verto.rtc/1001 Action log(INFO ***** Verto WebRTC Call ***** )
Dialplan: verto.rtc/1001 Action bridge(${verto_contact 1001})
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:286 (verto.rtc/1001) State Change CS_ROUTING -> CS_EXECUTE
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/1001) State ROUTING going to sleep
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1001) Running State Change CS_EXECUTE (Cur 1 Tot 46)
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:650 (verto.rtc/1001) State EXECUTE
2017-05-18 18:27:36.504289 [DEBUG] mod_rtc.c:120 verto.rtc/1001 RTC EXECUTE
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:328 verto.rtc/1001 Standard EXECUTE
EXECUTE verto.rtc/1001 log(INFO ***** Verto WebRTC Call ***** )
2017-05-18 18:27:36.504289 [INFO] mod_dptools.c:1721 ***** Verto WebRTC Call *****
EXECUTE verto.rtc/1001 bridge(verto.rtc/u:85f46bc0-257b-df98-4db7-a32d1e941279)
2017-05-18 18:27:36.504289 [DEBUG] switch_ivr_originate.c:2138 Parsing global variables
2017-05-18 18:27:36.504289 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT
2017-05-18 18:27:36.504289 [NOTICE] switch_channel.c:1104 New Channel verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 [4a53bb02-a26e-422f-8363-7945eab73e73]
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Running State Change CS_INIT (Cur 2 Tot 47)
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State INIT
2017-05-18 18:27:36.504289 [DEBUG] mod_verto.c:2212 Local verto.invite SDP verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279:
v=0
o=FreeSWITCH 1495103652 1495103653 IN IP4 10.100.2.83
s=FreeSWITCH
c=IN IP4 10.100.2.83
t=0 0
a=msid-semantic: WMS 0UdFfd2V86Bohk00iiRWfOWA4xeSZM5Q
m=audio 21204 RTP/SAVPF 102 9 0 8
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=fingerprint:sha-256 4F:04:51:8A:03:26:BA:4A:88:B4:E9:B6:74:C2:87:1B:20:D5:5A:8D:7D:BA:79:86:51:B0:43:22:7A:27:C4:BB
a=setup:actpass
a=rtcp-mux
a=rtcp:21204 IN IP4 10.100.2.83
a=ssrc:1898608344 cname:w8lCcenaaPoi0f88
a=ssrc:1898608344 msid:0UdFfd2V86Bohk00iiRWfOWA4xeSZM5Q a0
a=ssrc:1898608344 mslabel:0UdFfd2V86Bohk00iiRWfOWA4xeSZM5Q
a=ssrc:1898608344 label:0UdFfd2V86Bohk00iiRWfOWA4xeSZM5Qa0
a=ice-ufrag:nQUtuGTp4Y7TA2zX
a=ice-pwd:0Lp2PD3QjiY9nW8BDSVXpEck
a=candidate:6525246038 1 udp 659136 10.100.2.83 21204 typ host generation 0
a=candidate:6525246038 2 udp 659136 10.100.2.83 21204 typ host generation 0
a=silenceSupp:off - - - -
a=ptime:20
a=sendrecv

2017-05-18 18:27:36.504289 [NOTICE] mod_verto.c:2312 Ring-Ready verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279!
2017-05-18 18:27:36.504289 [DEBUG] switch_channel.c:3345 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Callstate Change DOWN -> RINGING
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:40 verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 Standard INIT
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State Change CS_INIT -> CS_ROUTING
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:627 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State INIT going to sleep
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Running State Change CS_ROUTING (Cur 2 Tot 47)
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State ROUTING
2017-05-18 18:27:36.504289 [DEBUG] mod_rtc.c:89 verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 RTC ROUTING
2017-05-18 18:27:36.504289 [DEBUG] switch_ivr_originate.c:67 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:643 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State ROUTING going to sleep
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Running State Change CS_CONSUME_MEDIA (Cur 2 Tot 47)
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State CONSUME_MEDIA
2017-05-18 18:27:36.504289 [DEBUG] switch_core_state_machine.c:662 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State CONSUME_MEDIA going to sleep
2017-05-18 18:27:36.504289 [NOTICE] switch_ivr_originate.c:525 Ring Ready verto.rtc/1001!
2017-05-18 18:27:36.504289 [NOTICE] switch_ivr_originate.c:525 Ring-Ready verto.rtc/1001!
2017-05-18 18:28:06.504295 [NOTICE] mod_verto.c:2755 Hangup verto.rtc/1001 [CS_EXECUTE] [NORMAL_CLEARING]
2017-05-18 18:28:06.524299 [NOTICE] switch_ivr_originate.c:3601 Hangup verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 [CS_CONSUME_MEDIA] [ORIGINATOR_CANCEL]
2017-05-18 18:28:06.524299 [DEBUG] switch_ivr_originate.c:3818 Originate Cancelled by originator termination Cause: 487 [ORIGINATOR_CANCEL]
2017-05-18 18:28:06.524299 [INFO] mod_dptools.c:3409 Originate Failed.  Cause: ORIGINATOR_CANCEL
2017-05-18 18:28:06.524299 [DEBUG] switch_core_session.c:2797 verto.rtc/1001 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:650 (verto.rtc/1001) State EXECUTE going to sleep
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1001) Running State Change CS_HANGUP (Cur 2 Tot 47)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/1001) Callstate Change RINGING -> HANGUP
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/1001) State HANGUP
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:60 verto.rtc/1001 Standard HANGUP, cause: NORMAL_CLEARING
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/1001) State HANGUP going to sleep
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/1001) State Change CS_HANGUP -> CS_REPORTING
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/1001) Running State Change CS_REPORTING (Cur 2 Tot 47)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/1001) State REPORTING
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:174 verto.rtc/1001 Standard REPORTING, cause: NORMAL_CLEARING
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/1001) State REPORTING going to sleep
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/1001) State Change CS_REPORTING -> CS_DESTROY
2017-05-18 18:28:06.524299 [DEBUG] switch_core_session.c:1647 Session 46 (verto.rtc/1001) Locked, Waiting on external entities
2017-05-18 18:28:06.524299 [NOTICE] switch_core_session.c:1665 Session 46 (verto.rtc/1001) Ended
2017-05-18 18:28:06.524299 [NOTICE] switch_core_session.c:1669 Close Channel verto.rtc/1001 [CS_DESTROY]
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/1001) Running State Change CS_DESTROY (Cur 1 Tot 47)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/1001) State DESTROY
2017-05-18 18:28:06.524299 [DEBUG] mod_rtc.c:132 verto.rtc/1001 RTC DESTROY
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:181 verto.rtc/1001 Standard DESTROY
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/1001) State DESTROY going to sleep
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Running State Change CS_HANGUP (Cur 1 Tot 47)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:850 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Callstate Change RINGING -> HANGUP
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State HANGUP
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:60 verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 Standard HANGUP, cause: ORIGINATOR_CANCEL
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:852 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State HANGUP going to sleep
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:619 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State Change CS_HANGUP -> CS_REPORTING
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:584 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Running State Change CS_REPORTING (Cur 1 Tot 47)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State REPORTING
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:174 verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 Standard REPORTING, cause: ORIGINATOR_CANCEL
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:938 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State REPORTING going to sleep
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:610 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State Change CS_REPORTING -> CS_DESTROY
2017-05-18 18:28:06.524299 [DEBUG] switch_core_session.c:1647 Session 47 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Locked, Waiting on external entities
2017-05-18 18:28:06.524299 [NOTICE] switch_core_session.c:1665 Session 47 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Ended
2017-05-18 18:28:06.524299 [NOTICE] switch_core_session.c:1669 Close Channel verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 [CS_DESTROY]
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) Running State Change CS_DESTROY (Cur 0 Tot 47)
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State DESTROY
2017-05-18 18:28:06.524299 [DEBUG] mod_rtc.c:132 verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 RTC DESTROY
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:181 verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279 Standard DESTROY
2017-05-18 18:28:06.524299 [DEBUG] switch_core_state_machine.c:751 (verto.rtc/85f46bc0-257b-df98-4db7-a32d1e941279) State DESTROY going to sleep