[Freeswitch-users] Call failed with mod_verto
bhavik patel
bhavikpatel14388 at gmail.com
Mon Mar 14 10:48:24 MSK 2016
Thank you for your answer.
Now outbound calls seems to be working.
But inbound calls have still the same issue that the call drops after
answer.
Here i am attaching call and SIP logs.
On Fri, Mar 11, 2016 at 5:17 PM, Ítalo Rossi <italo at freeswitch.org> wrote:
> Your SDP doesn't contain audio codecs, you're setting
> absolute_codec_string wrong,it should be
>
> absolute_codec_string=^^:G729:PCMA:PCMU:opus
>
> You missed the ':' as the separator being used in the array.
>
> 2016-03-03 08:01:53.050843 [DEBUG] mod_db.c:194 Usage for
> Demo_xxxxxxxxx30_gw_Demo_xxxxxxxxx30 is now 1/4 EXECUTE
> verto.rtc/xxxxxxxxx65
> *bridge({absolute_codec_string=^^G729:PCMA:PCMU:opus}*
> sofia/gateway/Demo_xxxxxxxxx30/xxxxxxxxx65)
> 2016-03-03 08:01:53.050843 [DEBUG] switch_channel.c:1237
> verto.rtc/xxxxxxxxx65 EXPORTING[export_vars] [t38_passthru]=[true] to event
> 2016-03-03 08:01:53.050843 [DEBUG] switch_ivr_originate.c:2127 Parsing
> global variables 2016-03-03 08:01:53.050843 [NOTICE] switch_channel.c:1091
> New Channel sofia/default/xxxxxxxxx65
> [de7384fd-8cf3-4b25-ab09-6d029f6b3c28] 2016-03-03 08:01:53.050843 [DEBUG]
> mod_sofia.c:4765 (sofia/default/xxxxxxxxx65) State Change CS_NEW -> CS_INIT
> 2016-03-03 08:01:53.050843 [DEBUG] switch_core_state_machine.c:473
> (sofia/default/xxxxxxxxx65) Running State Change CS_INIT
> 2016-03-03 08:01:53.050843 [DEBUG] switch_core_state_machine.c:516
> (sofia/default/xxxxxxxxx65) State INIT
> 2016-03-03 08:01:53.050843 [DEBUG] mod_sofia.c:88
> sofia/default/xxxxxxxxx65 SOFIA INIT
> 2016-03-03 08:01:53.050843 [DEBUG] sofia_glue.c:1228 sip:x.x.x.91 Setting
> proxy route to sofia/default/xxxxxxxxx65 2016-03-03 08:01:53.050843 [DEBUG]
> sofia_glue.c:1257 sofia/default/xxxxxxxxx65 sending invite version: 1.6.5
> 64bit Local SDP:
> v=0 o=FreeSWITCH 1456966735 1456966736
> IN IP4 x.x.x.88
> s=FreeSWITCH
> c=IN IP4 x.x.x.88
> t=0 0
>
> Ítalo Rossi
> italo at freeswitch.org
> IRC chat.freenode.net #freeswitch #freeswitch-dev
> Bugs? https://freeswitch.org/jira
> Docs? https://freeswitch.org/jira
> Chat? https://hipchat.freeswitch.org/gUdAgy0m6
>
> On Mar 11 2016, at 1:22 am, bhavik patel <bhavikpatel14388 at gmail.com>
>> wrote:
>> Can anyone please suggest me for this issue ?
>>
>> On Mon, Mar 7, 2016 at 6:18 PM, bhavik patel <bhavikpatel14388 at gmail.com>
>> wrote:
>>
>> I did try with PCMA:PCMU and getting same result.
>>
>> PFA
>>
>> On Mon, Mar 7, 2016 at 5:58 PM, Gregor Nanger <gregor at infomedia.si>
>> wrote:
>>
>> I guess that there is something with codec. As I see it select g729. Try
>> to force PCMA:PCMU for test.
>>
>> 2016-03-07 13:01 GMT+01:00 bhavik patel <bhavikpatel14388 at gmail.com>:
>>
>> Can anyone faces similar kind of issue with Verto ?
>>
>> Here i am attaching *INCOMPATIBLE_DESTINATION. *Logs.
>>
>> On Thu, Mar 3, 2016 at 6:59 PM, bhavik patel <bhavikpatel14388 at gmail.com>
>> wrote:
>>
>> Thanks for the reply.
>>
>> I tried not this params and getting *Originate Failed. Cause:
>> INCOMPATIBLE_DESTINATION.*
>>
>> Any other Clue.
>>
>> On Thu, Mar 3, 2016 at 6:12 PM, Ítalo Rossi <italo at freeswitch.org> wrote:
>>
>> Have you tried setting media_mix_inbound_outbound_codec=true ?
>>
>> On Thu, Mar 3, 2016 at 4:09 AM, bhavik patel <bhavikpatel14388 at gmail.com>
>> wrote:
>>
>> Hi All,
>>
>> I have Freeswitch-1.6.5 running on Debian-8.2.
>>
>> I want to use mod_verto for webrtc and followed steps mentioned at
>> https://freeswitch.org/confluence/display/FREESWITCH/mod_verto.
>> But calls are not working.
>>
>> Outbound call fails with NORMAL_TEMPORARY_FAILURE.
>>
>> When make inbound call it rings at destination and drops as soon as it
>> answer.
>>
>> Here i am attaching logs for both type of calls.
>>
>> Let me know if you require anything else from my end.
>>
>>
>>
>> Thanks
>>
>>
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://confluence.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>>
>>
>> --
>> Ítalo Rossi
>> italo at freeswitch.org
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://confluence.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>>
>>
>> --
>> Thanks,
>> Bhavik Patel
>>
>>
>>
>>
>> --
>> Thanks,
>> Bhavik Patel
>>
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://confluence.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>>
>>
>> --
>> Gregor Nanger
>>
>> *CTO*
>> t./f.: 00386 (0) 7 6000 308/309 • m:. 00386 (0)41 756485
>> • Infomedia d.o.o. • Jerebova 3, Novo mesto, Slovenia
>> • www.infomedia.si
>>
>> _________________________________________________________________________
>> Professional FreeSWITCH Consulting Services:
>> consulting at freeswitch.org
>> http://www.freeswitchsolutions.com
>>
>> Official FreeSWITCH Sites
>> http://www.freeswitch.org
>> http://confluence.freeswitch.org
>> http://www.cluecon.com
>>
>> FreeSWITCH-users mailing list
>> FreeSWITCH-users at lists.freeswitch.org
>> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
>> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
>> http://www.freeswitch.org
>>
>>
>>
>>
>> --
>> Thanks,
>> Bhavik Patel
>>
>>
>>
>>
>> --
>> Thanks,
>> Bhavik Patel
>>
>>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.freeswitch.org
> http://www.cluecon.com
>
> FreeSWITCH-users mailing list
> FreeSWITCH-users at lists.freeswitch.org
> http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
> UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
> http://www.freeswitch.org
>
--
Thanks,
Bhavik Patel
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20160314/f8458217/attachment-0001.html
-------------- next part --------------
2016-03-14 06:56:27.659471 [ALERT] mod_verto.c:1365 READ x.x.x.47:42702 [{
"jsonrpc": "2.0",
"method": "verto.invite",
"params": {
"sdp": "v=0\r\no=- 4925387713699119444 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio\r\na=msid-semantic: WMS kpfPv3N3VMm60huukmLdC13YFjik83CkC8uT\r\nm=audio 35020 RTP/SAVPF 111 103 104 0 8 106 105 13 126\r\nc=IN IP4 x.x.x.47\r\na=rtcp:35020 IN IP4 x.x.x.47\r\na=candidate:2608808550 1 udp 2122260223 192.168.1.33 35020 typ host generation 0\r\na=candidate:2608808550 2 udp 2122260223 192.168.1.33 35020 typ host generation 0\r\na=candidate:3590110870 1 tcp 1518280447 192.168.1.33 0 typ host tcptype active generation 0\r\na=candidate:3590110870 2 tcp 1518280447 192.168.1.33 0 typ host tcptype active generation 0\r\na=candidate:1836006322 1 udp 1686052607 x.x.x.47 35020 typ srflx raddr 192.168.1.33 rport 35020 generation 0\r\na=candidate:1836006322 2 udp 1686052607 x.x.x.47 35020 typ srflx raddr 192.168.1.33 rport 35020 generation 0\r\na=ice-ufrag:dOi1z9hQuFdB4joS\r\na=ice-pwd:XCvCkJT3Iwt4chKDNpBkEUVQ\r\na=ice-options:google-ice\r\na=fingerprint:sha-256 87:64:1C:26:A3:1B:4C:8F:37:28:9C:B9:8D:42:71:B3:42:E1:92:C6:CE:F9:75:B7:1E:A4:60:A6:EC:42:C5:D0\r\na=setup:actpass\r\na=mid:audio\r\na=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=sendrecv\r\na=rtcp-mux\r\na=rtpmap:111 opus/48000/2\r\na=fmtp:111 minptime=10; stereo=1\r\na=rtpmap:103 ISAC/16000\r\na=rtpmap:104 ISAC/32000\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:126 telephone-event/8000\r\na=maxptime:60\r\na=ssrc:1052942947 cname:5sn+L4USHksfOGkm\r\na=ssrc:1052942947 msid:kpfPv3N3VMm60huukmLdC13YFjik83CkC8uT 7d18ec77-a85d-452c-a5c0-5fc5653907d5\r\na=ssrc:1052942947 mslabel:kpfPv3N3VMm60huukmLdC13YFjik83CkC8uT\r\na=ssrc:1052942947 label:7d18ec77-a85d-452c-a5c0-5fc5653907d5\r\n",
"dialogParams": {
"useVideo": false,
"useStereo": true,
"tag": "webcam",
"login": "456456 at x.x.x.91",
"destination_number": "123123",
"caller_id_name": "xxxxxxxx30",
"caller_id_number": "xxxxxxxx30",
"callID": "22edc3da-1886-1832-eed3-55220c6f0bfc",
"remote_caller_id_name": "Outbound Call",
"remote_caller_id_number": "123123"
},
"sessid": "d6b2f69f-e53a-8313-54dd-5fca0e7eebd8"
},
"id": 5
}]
2016-03-14 06:56:27.659471 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT
2016-03-14 06:56:27.659471 [DEBUG] switch_core_session.c:613 N/A set UUID=22edc3da-1886-1832-eed3-55220c6f0bfc
2016-03-14 06:56:27.659471 [NOTICE] switch_channel.c:1091 New Channel verto.rtc/123123 [22edc3da-1886-1832-eed3-55220c6f0bfc]
2016-03-14 06:56:27.779410 [DEBUG] mod_verto.c:3553 Remote SDP verto.rtc/123123:
v=0
o=- 4925387713699119444 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio
a=msid-semantic: WMS kpfPv3N3VMm60huukmLdC13YFjik83CkC8uT
m=audio 35020 RTP/SAVPF 111 103 104 0 8 106 105 13 126
c=IN IP4 x.x.x.47
a=rtcp:35020 IN IP4 x.x.x.47
a=candidate:2608808550 1 udp 2122260223 192.168.1.33 35020 typ host generation 0
a=candidate:2608808550 2 udp 2122260223 192.168.1.33 35020 typ host generation 0
a=candidate:3590110870 1 tcp 1518280447 192.168.1.33 0 typ host tcptype active generation 0
a=candidate:3590110870 2 tcp 1518280447 192.168.1.33 0 typ host tcptype active generation 0
a=candidate:1836006322 1 udp 1686052607 x.x.x.47 35020 typ srflx raddr 192.168.1.33 rport 35020 generation 0
a=candidate:1836006322 2 udp 1686052607 x.x.x.47 35020 typ srflx raddr 192.168.1.33 rport 35020 generation 0
a=ice-ufrag:dOi1z9hQuFdB4joS
a=ice-pwd:XCvCkJT3Iwt4chKDNpBkEUVQ
a=ice-options:google-ice
a=fingerprint:sha-256 87:64:1C:26:A3:1B:4C:8F:37:28:9C:B9:8D:42:71:B3:42:E1:92:C6:CE:F9:75:B7:1E:A4:60:A6:EC:42:C5:D0
a=setup:actpass
a=mid:audio
a=extmap:1 urn:ietf:params:rtp-hdrext:ssrc-audio-level
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=sendrecv
a=rtcp-mux
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; stereo=1
a=rtpmap:103 ISAC/16000
a=rtpmap:104 ISAC/32000
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:126 telephone-event/8000
a=maxptime:60
a=ssrc:1052942947 cname:5sn+L4USHksfOGkm
a=ssrc:1052942947 msid:kpfPv3N3VMm60huukmLdC13YFjik83CkC8uT 7d18ec77-a85d-452c-a5c0-5fc5653907d5
a=ssrc:1052942947 mslabel:kpfPv3N3VMm60huukmLdC13YFjik83CkC8uT
a=ssrc:1052942947 label:7d18ec77-a85d-452c-a5c0-5fc5653907d5
2016-03-14 06:56:27.779410 [ALERT] mod_verto.c:604 WRITE x.x.x.47:42702 [{
"jsonrpc": "2.0",
"id": 5,
"result": {
"message": "CALL CREATED",
"callID": "22edc3da-1886-1832-eed3-55220c6f0bfc",
"sessid": "d6b2f69f-e53a-8313-54dd-5fca0e7eebd8"
}
}]
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/123123) Running State Change CS_INIT
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:516 (verto.rtc/123123) State INIT
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:40 verto.rtc/123123 Standard INIT
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/123123) State Change CS_INIT -> CS_ROUTING
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:516 (verto.rtc/123123) State INIT going to sleep
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/123123) Running State Change CS_ROUTING
2016-03-14 06:56:27.779410 [DEBUG] switch_channel.c:2239 (verto.rtc/123123) Callstate Change DOWN -> RINGING
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:532 (verto.rtc/123123) State ROUTING
2016-03-14 06:56:27.779410 [DEBUG] mod_rtc.c:89 verto.rtc/123123 RTC ROUTING
2016-03-14 06:56:27.779410 [DEBUG] switch_core_state_machine.c:166 verto.rtc/123123 Standard ROUTING
2016-03-14 06:56:27.779410 [INFO] mod_dialplan_xml.c:637 Processing xxxxxxxx30 <xxxxxxxx30>->123123 in context default
Dialplan: verto.rtc/123123 parsing [default->] continue=false
Dialplan: verto.rtc/123123 Regex (PASS) [] destination_number(123123) =~ // break=on-false
Dialplan: verto.rtc/123123 Action set(callstart=2016-03-14 04:56:27)
Dialplan: verto.rtc/123123 Action set(call_processed=internal)
Dialplan: verto.rtc/123123 Action set(originated_destination_number=123123)
Dialplan: verto.rtc/123123 Action set(hangup_after_bridge=true)
Dialplan: verto.rtc/123123 Action set(fax_enable_t38=true)
Dialplan: verto.rtc/123123 Action set(fax_enable_t38_request=true)
Dialplan: verto.rtc/123123 Action export(t38_passthru=true)
Dialplan: verto.rtc/123123 Action set(call_direction=inbound)
Dialplan: verto.rtc/123123 Action sched_hangup(+6000 allotted_timeout)
Dialplan: verto.rtc/123123 Action export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
Dialplan: verto.rtc/123123 Action set(effective_destination_number=123123)
Dialplan: verto.rtc/123123 Action set(hangup_after_bridge=true)
Dialplan: verto.rtc/123123 Action set(continue_on_fail=true)
Dialplan: verto.rtc/123123 Action export(absolute_codec_string=opus,PCMA,PCMU)
Dialplan: verto.rtc/123123 Action bridge({sip_invite_to_uri=<sip:789789 at x.x.x.47:5062,sip_invite_req_uri=sip:789789 at x.x.x.47:5062}sofia/default/sip:789789 at x.x.x.47:5062;fs_path=sip%3Ax.x.x.91%3Blr%3Breceived%3Dsip%3Ax.x.x.47%3A5062)
2016-03-14 06:56:27.879411 [DEBUG] switch_core_state_machine.c:216 (verto.rtc/123123) State Change CS_ROUTING -> CS_EXECUTE
2016-03-14 06:56:27.879411 [DEBUG] switch_core_state_machine.c:532 (verto.rtc/123123) State ROUTING going to sleep
2016-03-14 06:56:27.879411 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/123123) Running State Change CS_EXECUTE
2016-03-14 06:56:27.879411 [DEBUG] switch_core_state_machine.c:539 (verto.rtc/123123) State EXECUTE
2016-03-14 06:56:27.879411 [DEBUG] mod_rtc.c:120 verto.rtc/123123 RTC EXECUTE
2016-03-14 06:56:27.879411 [DEBUG] switch_core_state_machine.c:258 verto.rtc/123123 Standard EXECUTE
EXECUTE verto.rtc/123123 set(callstart=2016-03-14 04:56:27)
2016-03-14 06:56:27.879411 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [callstart]=[2016-03-14 04:56:27]
EXECUTE verto.rtc/123123 set(call_processed=internal)
2016-03-14 06:56:27.879411 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [call_processed]=[internal]
EXECUTE verto.rtc/123123 set(originated_destination_number=123123)
2016-03-14 06:56:27.879411 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [originated_destination_number]=[123123]
EXECUTE verto.rtc/123123 set(hangup_after_bridge=true)
2016-03-14 06:56:27.879411 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [hangup_after_bridge]=[true]
EXECUTE verto.rtc/123123 set(fax_enable_t38=true)
2016-03-14 06:56:27.879411 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [fax_enable_t38]=[true]
EXECUTE verto.rtc/123123 set(fax_enable_t38_request=true)
2016-03-14 06:56:27.879411 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [fax_enable_t38_request]=[true]
EXECUTE verto.rtc/123123 export(t38_passthru=true)
2016-03-14 06:56:27.879411 [DEBUG] switch_channel.c:1283 EXPORT (export_vars) [t38_passthru]=[true]
EXECUTE verto.rtc/123123 set(call_direction=inbound)
2016-03-14 06:56:27.899473 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [call_direction]=[inbound]
EXECUTE verto.rtc/123123 sched_hangup(+6000 allotted_timeout)
2016-03-14 06:56:27.899473 [DEBUG] switch_scheduler.c:249 Added task 42 switch_ivr_schedule_hangup (22edc3da-1886-1832-eed3-55220c6f0bfc) to run at 1457937387
EXECUTE verto.rtc/123123 export(rtp_append_audio_sdp=a=fmtp:18 annexb=no)
2016-03-14 06:56:27.899473 [DEBUG] switch_channel.c:1283 EXPORT (export_vars) [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no]
EXECUTE verto.rtc/123123 set(effective_destination_number=123123)
2016-03-14 06:56:27.899473 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [effective_destination_number]=[123123]
EXECUTE verto.rtc/123123 set(hangup_after_bridge=true)
2016-03-14 06:56:27.899473 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [hangup_after_bridge]=[true]
EXECUTE verto.rtc/123123 set(continue_on_fail=true)
2016-03-14 06:56:27.899473 [DEBUG] mod_dptools.c:1498 SET verto.rtc/123123 [continue_on_fail]=[true]
EXECUTE verto.rtc/123123 export(absolute_codec_string=opus,PCMA,PCMU)
2016-03-14 06:56:27.899473 [DEBUG] switch_channel.c:1283 EXPORT (export_vars) [absolute_codec_string]=[opus,PCMA,PCMU]
EXECUTE verto.rtc/123123 bridge({sip_invite_to_uri=<sip:789789 at x.x.x.47:5062,sip_invite_req_uri=sip:789789 at x.x.x.47:5062}sofia/default/sip:789789 at x.x.x.47:5062;fs_path=sip%3Ax.x.x.91%3Blr%3Breceived%3Dsip%3Ax.x.x.47%3A5062)
2016-03-14 06:56:27.899473 [DEBUG] switch_channel.c:1237 verto.rtc/123123 EXPORTING[export_vars] [t38_passthru]=[true] to event
2016-03-14 06:56:27.899473 [DEBUG] switch_channel.c:1237 verto.rtc/123123 EXPORTING[export_vars] [rtp_append_audio_sdp]=[a=fmtp:18 annexb=no] to event
2016-03-14 06:56:27.899473 [DEBUG] switch_channel.c:1237 verto.rtc/123123 EXPORTING[export_vars] [absolute_codec_string]=[opus,PCMA,PCMU] to event
2016-03-14 06:56:27.899473 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
2016-03-14 06:56:27.899473 [NOTICE] switch_channel.c:1091 New Channel sofia/default/789789 at x.x.x.47:5062 [ec918bd1-ac35-430f-8109-253e6f22fd17]
2016-03-14 06:56:27.899473 [DEBUG] mod_sofia.c:4765 (sofia/default/789789 at x.x.x.47:5062) State Change CS_NEW -> CS_INIT
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:473 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_INIT
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:516 (sofia/default/789789 at x.x.x.47:5062) State INIT
2016-03-14 06:56:27.899473 [DEBUG] mod_sofia.c:88 sofia/default/789789 at x.x.x.47:5062 SOFIA INIT
2016-03-14 06:56:27.899473 [DEBUG] sofia_glue.c:1228 sip:x.x.x.91;lr;received=sip:x.x.x.47:5062 Setting proxy route to sofia/default/789789 at x.x.x.47:5062
2016-03-14 06:56:27.899473 [DEBUG] sofia_glue.c:1257 sofia/default/789789 at x.x.x.47:5062 sending invite version: 1.6.5 64bit
Local SDP:
v=0
o=FreeSWITCH 1457913003 1457913004 IN IP4 x.x.x.88
s=FreeSWITCH
c=IN IP4 x.x.x.88
t=0 0
m=audio 18384 RTP/AVP 111 8 0 102 101
a=rtpmap:111 opus/48000/2
a=fmtp:111 minptime=10; stereo=1
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:102 telephone-event/48000
a=fmtp:102 0-16
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:40 sofia/default/789789 at x.x.x.47:5062 Standard INIT
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:48 (sofia/default/789789 at x.x.x.47:5062) State Change CS_INIT -> CS_ROUTING
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:516 (sofia/default/789789 at x.x.x.47:5062) State INIT going to sleep
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:473 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_ROUTING
2016-03-14 06:56:27.899473 [DEBUG] sofia.c:6750 Channel sofia/default/789789 at x.x.x.47:5062 entering state [calling][0]
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:532 (sofia/default/789789 at x.x.x.47:5062) State ROUTING
2016-03-14 06:56:27.899473 [DEBUG] mod_sofia.c:141 sofia/default/789789 at x.x.x.47:5062 SOFIA ROUTING
2016-03-14 06:56:27.899473 [DEBUG] switch_ivr_originate.c:67 (sofia/default/789789 at x.x.x.47:5062) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:532 (sofia/default/789789 at x.x.x.47:5062) State ROUTING going to sleep
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:473 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_CONSUME_MEDIA
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:551 (sofia/default/789789 at x.x.x.47:5062) State CONSUME_MEDIA
2016-03-14 06:56:27.899473 [DEBUG] switch_core_state_machine.c:551 (sofia/default/789789 at x.x.x.47:5062) State CONSUME_MEDIA going to sleep
2016-03-14 06:56:28.499484 [DEBUG] sofia.c:6750 Channel sofia/default/789789 at x.x.x.47:5062 entering state [proceeding][180]
2016-03-14 06:56:28.499484 [NOTICE] sofia.c:6852 Ring-Ready sofia/default/789789 at x.x.x.47:5062!
2016-03-14 06:56:28.499484 [DEBUG] switch_channel.c:3332 (sofia/default/789789 at x.x.x.47:5062) Callstate Change DOWN -> RINGING
2016-03-14 06:56:28.499484 [NOTICE] switch_ivr_originate.c:528 Ring Ready verto.rtc/123123!
2016-03-14 06:56:28.499484 [NOTICE] switch_ivr_originate.c:528 Ring-Ready verto.rtc/123123!
2016-03-14 06:56:28.819484 [DEBUG] sofia.c:6750 Channel sofia/default/789789 at x.x.x.47:5062 entering state [proceeding][180]
2016-03-14 06:56:34.219406 [DEBUG] sofia.c:6750 Channel sofia/default/789789 at x.x.x.47:5062 entering state [completing][200]
2016-03-14 06:56:34.219406 [DEBUG] sofia.c:6760 Remote SDP:
v=0
o=789789 8001 8000 IN IP4 x.x.x.47
s=SIP Call
c=IN IP4 x.x.x.47
t=0 0
m=audio 5008 RTP/AVP 8 0 102
a=rtpmap:8 PCMA/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:102 telephone-event/8000
a=fmtp:102 0-15
a=ptime:20
2016-03-14 06:56:34.219406 [DEBUG] sofia.c:6750 Channel sofia/default/789789 at x.x.x.47:5062 entering state [ready][200]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4182 Bah HUMBUG! Sticking with PCMA at 8000h@20i
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4208 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMA:8:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMU:0:8000:20:64000:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4182 Bah HUMBUG! Sticking with PCMU at 8000h@20i
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4208 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4069 Set telephone-event payload to 102 at 8000
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:2898 Set Codec sofia/default/789789 at x.x.x.47:5062 PCMA/8000 20 ms 160 samples 64000 bits 1 channels
2016-03-14 06:56:34.219406 [DEBUG] switch_core_codec.c:111 sofia/default/789789 at x.x.x.47:5062 Original read codec set to PCMA:8
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4417 Set telephone-event payload to 102 at 8000
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4473 sofia/default/789789 at x.x.x.47:5062 Set 2833 dtmf send payload to 102 recv payload to 101
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6027 AUDIO RTP [sofia/default/789789 at x.x.x.47:5062] x.x.x.88 port 18384 -> x.x.x.47 port 5008 codec: 8 ms: 20
2016-03-14 06:56:34.219406 [DEBUG] switch_rtp.c:3788 Starting timer [soft] 160 bytes per 20ms
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6326 sofia/default/789789 at x.x.x.47:5062 Set 2833 dtmf send payload to 102
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6333 sofia/default/789789 at x.x.x.47:5062 Set 2833 dtmf receive payload to 101
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6356 sofia/default/789789 at x.x.x.47:5062 Set rtp dtmf delay to 40
2016-03-14 06:56:34.219406 [NOTICE] sofia.c:7714 Channel [sofia/default/789789 at x.x.x.47:5062] has been answered
2016-03-14 06:56:34.219406 [DEBUG] switch_channel.c:3759 (sofia/default/789789 at x.x.x.47:5062) Callstate Change RINGING -> ACTIVE
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [opus:111:48000:60:0:2]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4208 Audio Codec Compare [opus:116:48000:20:0:1] ++++ is saved as a match
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [opus:111:48000:60:0:2]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [opus:111:48000:60:0:2]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [ISAC:103:16000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [ISAC:104:32000:30:32000:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMU:0:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4208 Audio Codec Compare [PCMU:0:8000:20:64000:1] ++++ is saved as a match
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4208 Audio Codec Compare [PCMA:8:8000:20:64000:1] ++++ is saved as a match
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [PCMA:8:8000:60:64000:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:106:32000:60:0:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:106:32000:60:0:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:106:32000:60:0:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:105:16000:60:0:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:105:16000:60:0:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:13:8000:60:0:1]/[opus:116:48000:20:0:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMA:8:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [CN:13:8000:60:0:1]/[PCMU:0:8000:20:64000:1]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4069 Set telephone-event payload to 126 at 8000
2016-03-14 06:56:34.219406 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [120000bps]
2016-03-14 06:56:34.219406 [DEBUG] mod_opus.c:559 Opus encoder: set bitrate to local settings [120000bps]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:2898 Set Codec verto.rtc/123123 opus/48000 20 ms 960 samples 0 bits 2 channels
2016-03-14 06:56:34.219406 [DEBUG] switch_core_codec.c:111 verto.rtc/123123 Original read codec set to opus:116
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3296 Save audio Candidate cid: 1 proto: udp type: host addr: 192.168.1.33:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3296 Save audio Candidate cid: 2 proto: udp type: host addr: 192.168.1.33:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3296 Save audio Candidate cid: 1 proto: udp type: srflx addr: x.x.x.47:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3296 Save audio Candidate cid: 2 proto: udp type: srflx addr: x.x.x.47:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3336 Searching for rtp candidate.
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3341 Choose rtp candidate, index 1, x.x.x.47:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3127 verto.rtc/123123 choosing family v4
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3352 Choose same candidate, index 2, for rtcp based on rtcp-mux attribute x.x.x.47:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3397 setting remote audio ice addr to index 1 x.x.x.47:35020 based on candidate
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:3418 Setting remote rtcp audio addr to x.x.x.47:35020 based on candidate
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:4473 verto.rtc/123123 Set 2833 dtmf send payload to 126 recv payload to 126
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6027 AUDIO RTP [verto.rtc/123123] x.x.x.88 port 27548 -> x.x.x.47 port 35020 codec: 111 ms: 20
2016-03-14 06:56:34.219406 [DEBUG] switch_rtp.c:3788 Starting timer [soft] 960 bytes per 20ms
2016-03-14 06:56:34.219406 [INFO] switch_core_media.c:6202 Activating Audio ICE
2016-03-14 06:56:34.219406 [NOTICE] switch_rtp.c:4270 Activating RTP audio ICE: dOi1z9hQuFdB4joS:yoWTsStz55fNiric x.x.x.47:35020
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6245 Activating RTCP PORT 35020
2016-03-14 06:56:34.219406 [DEBUG] switch_rtp.c:4167 RTCP send rate is: 5000 and packet rate is: 20000 Remote Port: 35020
2016-03-14 06:56:34.219406 [INFO] switch_core_media.c:6253 Skipping RTCP ICE (Same as RTP)
2016-03-14 06:56:34.219406 [INFO] switch_rtp.c:3286 Activate RTP/RTCP audio DTLS client
2016-03-14 06:56:34.219406 [INFO] switch_rtp.c:3415 Changing audio DTLS state from OFF to HANDSHAKE
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:1939 Setting Jitterbuffer to 20ms (1 frames) (50 max frames)
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6326 verto.rtc/123123 Set 2833 dtmf send payload to 126
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:6333 verto.rtc/123123 Set 2833 dtmf receive payload to 126
2016-03-14 06:56:34.219406 [DEBUG] mod_verto.c:2437 Local SDP verto.rtc/123123:
v=0
o=FreeSWITCH 1457903846 1457903847 IN IP4 x.x.x.88
s=FreeSWITCH
c=IN IP4 x.x.x.88
t=0 0
a=msid-semantic: WMS XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlF
m=audio 27548 RTP/SAVPF 111 126
a=rtpmap:111 opus/48000/2
a=fmtp:111 useinbandfec=0; minptime=10; stereo=1
a=rtpmap:126 telephone-event/8000
a=silenceSupp:off - - - -
a=fmtp:18 annexb=no
a=ptime:20
a=sendrecv
a=fingerprint:sha-256 AC:05:AC:85:29:10:9B:21:01:B5:0C:36:78:36:F7:D3:F5:02:2E:DB:B1:7D:85:FE:52:D8:0D:B3:2E:05:F4:B5
a=setup:active
a=rtcp-mux
a=rtcp:27548 IN IP4 x.x.x.88
a=ice-ufrag:yoWTsStz55fNiric
a=ice-pwd:dCq9aHWpUbI6QzSeNFY6nhwj
a=candidate:7405685272 1 udp 659136 x.x.x.88 27548 typ host generation 0
a=ssrc:585776411 cname:3Wun6HrWpmpslO1W
a=ssrc:585776411 msid:XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlF a0
a=ssrc:585776411 mslabel:XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlF
a=ssrc:585776411 label:XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlFa0
2016-03-14 06:56:34.219406 [NOTICE] switch_ivr_originate.c:3549 Channel [verto.rtc/123123] has been answered
2016-03-14 06:56:34.219406 [DEBUG] switch_channel.c:3759 (verto.rtc/123123) Callstate Change RINGING -> ACTIVE
2016-03-14 06:56:34.219406 [DEBUG] switch_ivr_originate.c:3607 Originate Resulted in Success: [sofia/default/789789 at x.x.x.47:5062]
2016-03-14 06:56:34.219406 [DEBUG] switch_core_media.c:9118 verto.rtc/123123 PAUSE Jitterbuffer
2016-03-14 06:56:34.219406 [DEBUG] switch_ivr_bridge.c:1591 (sofia/default/789789 at x.x.x.47:5062) State Change CS_CONSUME_MEDIA -> CS_EXCHANGE_MEDIA
2016-03-14 06:56:34.219406 [DEBUG] switch_core_state_machine.c:473 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_EXCHANGE_MEDIA
2016-03-14 06:56:34.219406 [DEBUG] switch_core_state_machine.c:542 (sofia/default/789789 at x.x.x.47:5062) State EXCHANGE_MEDIA
2016-03-14 06:56:34.219406 [DEBUG] mod_sofia.c:613 SOFIA EXCHANGE_MEDIA
2016-03-14 06:56:34.239410 [ALERT] mod_verto.c:604 WRITE x.x.x.47:42702 [{
"jsonrpc": "2.0",
"id": 57,
"method": "verto.answer",
"params": {
"callID": "22edc3da-1886-1832-eed3-55220c6f0bfc",
"sdp": "v=0\no=FreeSWITCH 1457903846 1457903847 IN IP4 x.x.x.88\ns=FreeSWITCH\nc=IN IP4 x.x.x.88\nt=0 0\na=msid-semantic: WMS XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlF\nm=audio 27548 RTP/SAVPF 111 126\na=rtpmap:111 opus/48000/2\na=fmtp:111 useinbandfec=0; minptime=10; stereo=1\na=rtpmap:126 telephone-event/8000\na=silenceSupp:off - - - -\na=fmtp:18 annexb=no\na=ptime:20\na=sendrecv\na=fingerprint:sha-256 AC:05:AC:85:29:10:9B:21:01:B5:0C:36:78:36:F7:D3:F5:02:2E:DB:B1:7D:85:FE:52:D8:0D:B3:2E:05:F4:B5\na=setup:active\na=rtcp-mux\na=rtcp:27548 IN IP4 x.x.x.88\na=ice-ufrag:yoWTsStz55fNiric\na=ice-pwd:dCq9aHWpUbI6QzSeNFY6nhwj\na=candidate:7405685272 1 udp 659136 x.x.x.88 27548 typ host generation 0\na=ssrc:585776411 cname:3Wun6HrWpmpslO1W\na=ssrc:585776411 msid:XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlF a0\na=ssrc:585776411 mslabel:XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlF\na=ssrc:585776411 label:XQKYtjndZR5Dd8yILTx9vd6JhmMPRnlFa0\n"
}
}]
2016-03-14 06:56:34.279398 [ALERT] mod_verto.c:604 WRITE x.x.x.47:42702 [{
"jsonrpc": "2.0",
"id": 58,
"method": "verto.display",
"params": {
"callID": "22edc3da-1886-1832-eed3-55220c6f0bfc",
"display_name": "Outbound Call",
"display_number": "789789",
"caller_id_name": "xxxxxxxx30",
"caller_id_number": "xxxxxxxx30",
"callee_id_name": "Outbound Call",
"callee_id_number": "789789",
"display_direction": "inbound"
}
}]
2016-03-14 06:56:34.619410 [ALERT] mod_verto.c:1365 READ x.x.x.47:42702 [{
"jsonrpc": "2.0",
"method": "verto.bye",
"params": {
"dialogParams": {
"useVideo": false,
"useStereo": true,
"tag": "webcam",
"login": "456456 at x.x.x.91",
"destination_number": "123123",
"caller_id_name": "xxxxxxxx30",
"caller_id_number": "xxxxxxxx30",
"callID": "22edc3da-1886-1832-eed3-55220c6f0bfc",
"remote_caller_id_name": "Outbound Call",
"remote_caller_id_number": "123123"
},
"sessid": "d6b2f69f-e53a-8313-54dd-5fca0e7eebd8"
},
"id": 6
}]
2016-03-14 06:56:34.619410 [NOTICE] mod_verto.c:2738 Hangup verto.rtc/123123 [CS_EXECUTE] [NORMAL_CLEARING]
2016-03-14 06:56:34.619410 [ALERT] mod_verto.c:604 WRITE x.x.x.47:42702 [{
"jsonrpc": "2.0",
"id": 6,
"result": {
"callID": "22edc3da-1886-1832-eed3-55220c6f0bfc",
"message": "CALL ENDED",
"causeCode": 16,
"cause": "NORMAL_CLEARING",
"sessid": "d6b2f69f-e53a-8313-54dd-5fca0e7eebd8"
}
}]
2016-03-14 06:56:34.619410 [ALERT] mod_verto.c:1365 READ x.x.x.47:42702 [{
"jsonrpc": "2.0",
"id": 57,
"result": {
"method": "verto.answer"
}
}]
2016-03-14 06:56:34.639408 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD DONE [sofia/default/789789 at x.x.x.47:5062]
2016-03-14 06:56:34.639408 [NOTICE] switch_ivr_bridge.c:881 Hangup sofia/default/789789 at x.x.x.47:5062 [CS_EXCHANGE_MEDIA] [NORMAL_CLEARING]
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:542 (sofia/default/789789 at x.x.x.47:5062) State EXCHANGE_MEDIA going to sleep
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:473 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_HANGUP
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:739 (sofia/default/789789 at x.x.x.47:5062) Callstate Change ACTIVE -> HANGUP
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:741 (sofia/default/789789 at x.x.x.47:5062) State HANGUP
2016-03-14 06:56:34.639408 [DEBUG] mod_sofia.c:431 Channel sofia/default/789789 at x.x.x.47:5062 hanging up, cause: NORMAL_CLEARING
2016-03-14 06:56:34.639408 [DEBUG] mod_sofia.c:484 Sending BYE to sofia/default/789789 at x.x.x.47:5062
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:60 sofia/default/789789 at x.x.x.47:5062 Standard HANGUP, cause: NORMAL_CLEARING
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:741 (sofia/default/789789 at x.x.x.47:5062) State HANGUP going to sleep
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:508 (sofia/default/789789 at x.x.x.47:5062) State Change CS_HANGUP -> CS_REPORTING
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:473 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_REPORTING
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:827 (sofia/default/789789 at x.x.x.47:5062) State REPORTING
2016-03-14 06:56:34.639408 [DEBUG] switch_ivr_bridge.c:705 verto.rtc/123123 ending bridge by request from read function
2016-03-14 06:56:34.639408 [DEBUG] switch_ivr_bridge.c:778 BRIDGE THREAD DONE [verto.rtc/123123]
2016-03-14 06:56:34.639408 [DEBUG] switch_ivr_bridge.c:1689 sofia/default/789789 at x.x.x.47:5062 skip receive message [UNBRIDGE] (channel is hungup already)
2016-03-14 06:56:34.639408 [DEBUG] switch_ivr_bridge.c:1692 verto.rtc/123123 skip receive message [UNBRIDGE] (channel is hungup already)
2016-03-14 06:56:34.639408 [DEBUG] switch_core_session.c:2796 verto.rtc/123123 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:539 (verto.rtc/123123) State EXECUTE going to sleep
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/123123) Running State Change CS_HANGUP
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:739 (verto.rtc/123123) Callstate Change ACTIVE -> HANGUP
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/123123) State HANGUP
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:60 verto.rtc/123123 Standard HANGUP, cause: NORMAL_CLEARING
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/123123) State HANGUP going to sleep
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:508 (verto.rtc/123123) State Change CS_HANGUP -> CS_REPORTING
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/123123) Running State Change CS_REPORTING
2016-03-14 06:56:34.639408 [DEBUG] switch_core_state_machine.c:827 (verto.rtc/123123) State REPORTING
2016-03-14 06:56:34.659410 [ALERT] mod_verto.c:1365 READ x.x.x.47:42702 [{
"jsonrpc": "2.0",
"id": 58,
"result": {
"method": "verto.display"
}
}]
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:104 sofia/default/789789 at x.x.x.47:5062 Standard REPORTING, cause: NORMAL_CLEARING
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:827 (sofia/default/789789 at x.x.x.47:5062) State REPORTING going to sleep
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:499 (sofia/default/789789 at x.x.x.47:5062) State Change CS_REPORTING -> CS_DESTROY
2016-03-14 06:56:34.919400 [DEBUG] switch_core_session.c:1646 Session 121 (sofia/default/789789 at x.x.x.47:5062) Locked, Waiting on external entities
2016-03-14 06:56:34.919400 [NOTICE] switch_core_session.c:1664 Session 121 (sofia/default/789789 at x.x.x.47:5062) Ended
2016-03-14 06:56:34.919400 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/789789 at x.x.x.47:5062 [CS_DESTROY]
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:630 (sofia/default/789789 at x.x.x.47:5062) Running State Change CS_DESTROY
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:640 (sofia/default/789789 at x.x.x.47:5062) State DESTROY
2016-03-14 06:56:34.919400 [DEBUG] mod_sofia.c:341 sofia/default/789789 at x.x.x.47:5062 SOFIA DESTROY
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:111 sofia/default/789789 at x.x.x.47:5062 Standard DESTROY
2016-03-14 06:56:34.919400 [DEBUG] switch_core_state_machine.c:640 (sofia/default/789789 at x.x.x.47:5062) State DESTROY going to sleep
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:104 verto.rtc/123123 Standard REPORTING, cause: NORMAL_CLEARING
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:827 (verto.rtc/123123) State REPORTING going to sleep
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:499 (verto.rtc/123123) State Change CS_REPORTING -> CS_DESTROY
2016-03-14 06:56:34.939411 [DEBUG] switch_core_session.c:1646 Session 120 (verto.rtc/123123) Locked, Waiting on external entities
2016-03-14 06:56:34.939411 [NOTICE] switch_core_session.c:1664 Session 120 (verto.rtc/123123) Ended
2016-03-14 06:56:34.939411 [NOTICE] switch_core_session.c:1668 Close Channel verto.rtc/123123 [CS_DESTROY]
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:630 (verto.rtc/123123) Running State Change CS_DESTROY
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:640 (verto.rtc/123123) State DESTROY
2016-03-14 06:56:34.939411 [DEBUG] mod_rtc.c:132 verto.rtc/123123 RTC DESTROY
2016-03-14 06:56:34.939411 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2016-03-14 06:56:34.939411 [DEBUG] mod_opus.c:661 Opus decoder stats: Frames[0] PLC[0] FEC[0]
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:111 verto.rtc/123123 Standard DESTROY
2016-03-14 06:56:34.939411 [DEBUG] switch_core_state_machine.c:640 (verto.rtc/123123) State DESTROY going to sleep
2016-03-14 06:56:35.399439 [DEBUG] switch_scheduler.c:144 Deleting task 42 switch_ivr_schedule_hangup (22edc3da-1886-1832-eed3-55220c6f0bfc)
-------------- next part --------------
U x.x.x.88:5060 -> x.x.x.91:5060
INVITE sip:789789 at x.x.x.47:5062 SIP/2.0.
Via: SIP/2.0/UDP x.x.x.88;rport;branch=z9hG4bK6yX1N7aDcgt8S.
Route: <sip:x.x.x.91>;lr;received=sip:x.x.x.47:5062.
Max-Forwards: 70.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629629 INVITE.
Contact: <sip:mod_sofia at x.x.x.88:5060>.
User-Agent: GoldtelSolutions.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: path, replaces.
Allow-Events: talk, hold, conference, presence, as-feature-event, dialog, line-seize, call-info, sla, include-session-description, presence.winfo, message-summary, refer.
Content-Type: application/sdp.
Content-Disposition: session.
Content-Length: 366.
X-FS-Support: update_display,send_info.
Remote-Party-ID: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;party=calling;screen=yes;privacy=off.
.
v=0.
o=FreeSWITCH 1457913003 1457913004 IN IP4 x.x.x.88.
s=FreeSWITCH.
c=IN IP4 x.x.x.88.
t=0 0.
m=audio 18384 RTP/AVP 111 8 0 102 101.
a=rtpmap:111 opus/48000/2.
a=fmtp:111 minptime=10; stereo=1.
a=rtpmap:8 PCMA/8000.
a=rtpmap:0 PCMU/8000.
a=rtpmap:102 telephone-event/48000.
a=fmtp:102 0-16.
a=rtpmap:101 telephone-event/8000.
a=fmtp:101 0-16.
a=ptime:20.
U x.x.x.91:5060 -> x.x.x.88:5060
SIP/2.0 100 Giving a try.
Via: SIP/2.0/UDP x.x.x.88;received=x.x.x.88;rport=5060;branch=z9hG4bK6yX1N7aDcgt8S.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629629 INVITE.
server: SIP Proxy.
Content-Length: 0.
.
U x.x.x.91:5060 -> x.x.x.88:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP x.x.x.88;received=x.x.x.88;rport=5060;branch=z9hG4bK6yX1N7aDcgt8S.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>;tag=992100717.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629629 INVITE.
Contact: <sip:789789 at x.x.x.91;did=cbd.1b45e6d1>.
Supported: replaces, path, timer.
User-Agent: Grandstream GXP1400 1.0.6.11.
Allow-Events: talk, hold.
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE.
Content-Length: 0.
.
U x.x.x.91:5060 -> x.x.x.88:5060
SIP/2.0 180 Ringing.
Via: SIP/2.0/UDP x.x.x.88;received=x.x.x.88;rport=5060;branch=z9hG4bK6yX1N7aDcgt8S.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>;tag=992100717.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629629 INVITE.
Contact: <sip:789789 at x.x.x.91;did=cbd.1b45e6d1>.
Supported: replaces, path, timer.
User-Agent: Grandstream GXP1400 1.0.6.11.
Allow-Events: talk, hold.
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE.
Content-Length: 0.
.
U x.x.x.91:5060 -> x.x.x.88:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP x.x.x.88;received=x.x.x.88;rport=5060;branch=z9hG4bK6yX1N7aDcgt8S.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>;tag=992100717.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629629 INVITE.
Contact: <sip:789789 at x.x.x.91;did=cbd.1b45e6d1>.
Supported: replaces, path, timer.
User-Agent: Grandstream GXP1400 1.0.6.11.
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE.
Content-Type: application/sdp.
Content-Length: 239.
.
v=0.
o=789789 8001 8000 IN IP4 x.x.x.47.
s=SIP Call.
c=IN IP4 x.x.x.47.
t=0 0.
m=audio 5008 RTP/AVP 8 0 102.
a=sendrecv.
a=rtpmap:8 PCMA/8000.
a=ptime:20.
a=rtpmap:0 PCMU/8000.
a=rtpmap:102 telephone-event/8000.
a=fmtp:102 0-15.
U x.x.x.88:5060 -> x.x.x.91:5060
ACK sip:789789 at x.x.x.91;did=cbd.1b45e6d1 SIP/2.0.
Via: SIP/2.0/UDP x.x.x.88;rport;branch=z9hG4bK77ptQ2Ug9rgUN.
Max-Forwards: 70.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>;tag=992100717.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629629 ACK.
Contact: <sip:mod_sofia at x.x.x.88:5060>.
Content-Length: 0.
.
U x.x.x.88:5060 -> x.x.x.91:5060
BYE sip:789789 at x.x.x.91;did=cbd.1b45e6d1 SIP/2.0.
Via: SIP/2.0/UDP x.x.x.88;rport;branch=z9hG4bK8ggKSXcm616DH.
Max-Forwards: 70.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>;tag=992100717.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629630 BYE.
User-Agent: GoldtelSolutions.
Allow: INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, NOTIFY, PUBLISH, SUBSCRIBE.
Supported: path, replaces.
Reason: Q.850;cause=16;text="NORMAL_CLEARING".
Content-Length: 0.
.
U x.x.x.91:5060 -> x.x.x.88:5060
SIP/2.0 200 OK.
Via: SIP/2.0/UDP x.x.x.88;received=x.x.x.88;rport=5060;branch=z9hG4bK8ggKSXcm616DH.
From: "xxxxxxxx30" <sip:xxxxxxxx30 at x.x.x.88>;tag=jZvFvaZXDmecH.
To: <sip:789789 at x.x.x.47:5062>;tag=992100717.
Call-ID: f3b3bc6c-6443-1234-e5b0-0024e83afa77.
CSeq: 88629630 BYE.
Contact: <sip:789789 at x.x.x.91;did=cbd.1b45e6d1>.
Supported: replaces, path, timer.
User-Agent: Grandstream GXP1400 1.0.6.11.
Allow: INVITE, ACK, OPTIONS, CANCEL, BYE, SUBSCRIBE, NOTIFY, INFO, REFER, UPDATE, MESSAGE.
Content-Length: 0.
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list