[Freeswitch-users] Call failed with mod_verto
bhavik patel
bhavikpatel14388 at gmail.com
Mon Mar 7 15:01:42 MSK 2016
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
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20160307/804f76e6/attachment-0001.html
-------------- next part --------------
2016-03-07 13:33:21.210914 [ALERT] mod_verto.c:1365 READ x.x.x.47:38105 [{
"jsonrpc": "2.0",
"method": "verto.invite",
"params": {
"sdp": "v=0\r\no=- 8839241919991864351 2 IN IP4 127.0.0.1\r\ns=-\r\nt=0 0\r\na=group:BUNDLE audio video\r\na=msid-semantic: WMS zk8dxi4qdO2fDxKlmYREHM28A590jNHRZ5wM\r\nm=audio 60098 RTP/SAVPF 111 103 104 0 8 106 105 13 126\r\nc=IN IP4 x.x.x.47\r\na=rtcp:60098 IN IP4 x.x.x.47\r\na=candidate:2608808550 1 udp 2122260223 192.168.1.33 60098 typ host generation 0\r\na=candidate:2608808550 2 udp 2122260223 192.168.1.33 60098 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 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0\r\na=candidate:1836006322 2 udp 1686052607 x.x.x.47 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0\r\na=ice-ufrag:ulSc0VI6wblyj/Yh\r\na=ice-pwd:xljyntK2FrUbN6pR+kJe0w0L\r\na=ice-options:google-ice\r\na=fingerprint:sha-256 56:32:AB:CD:46:DF:9F:D6:AD:18:AA:73:A6:58:D3:D8:22:E4:20:3E:F1:54:E4:A7:6E:83:67:C3:E2:57:E5:8E\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; sprop-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:2255451044 cname:mn0BfhWXIhxUt2jW\r\na=ssrc:2255451044 msid:zk8dxi4qdO2fDxKlmYREHM28A590jNHRZ5wM d3c12d3f-b09e-44c3-84bd-68b6ce65e4bb\r\na=ssrc:2255451044 mslabel:zk8dxi4qdO2fDxKlmYREHM28A590jNHRZ5wM\r\na=ssrc:2255451044 label:d3c12d3f-b09e-44c3-84bd-68b6ce65e4bb\r\nm=video 60098 RTP/SAVPF 100 116 117 96\r\nc=IN IP4 x.x.x.47\r\na=rtcp:60098 IN IP4 x.x.x.47\r\na=candidate:2608808550 1 udp 2122260223 192.168.1.33 60098 typ host generation 0\r\na=candidate:2608808550 2 udp 2122260223 192.168.1.33 60098 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 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0\r\na=candidate:1836006322 2 udp 1686052607 x.x.x.47 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0\r\na=ice-ufrag:ulSc0VI6wblyj/Yh\r\na=ice-pwd:xljyntK2FrUbN6pR+kJe0w0L\r\na=ice-options:google-ice\r\na=fingerprint:sha-256 56:32:AB:CD:46:DF:9F:D6:AD:18:AA:73:A6:58:D3:D8:22:E4:20:3E:F1:54:E4:A7:6E:83:67:C3:E2:57:E5:8E\r\na=setup:actpass\r\na=mid:video\r\na=extmap:2 urn:ietf:params:rtp-hdrext:toffset\r\na=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time\r\na=recvonly\r\na=rtcp-mux\r\na=rtpmap:100 VP8/90000\r\na=rtcp-fb:100 ccm fir\r\na=rtcp-fb:100 nack\r\na=rtcp-fb:100 nack pli\r\na=rtcp-fb:100 goog-remb\r\na=rtpmap:116 red/90000\r\na=rtpmap:117 ulpfec/90000\r\na=rtpmap:96 rtx/90000\r\na=fmtp:96 apt=100\r\n",
"dialogParams": {
"useVideo": true,
"useStereo": true,
"screenShare": false,
"useCamera": "none",
"useMic": "any",
"useSpeak": "any",
"tag": "webcam",
"localTag": null,
"login": "789789 at x.x.x.91",
"videoParams": {
"minWidth": 320,
"minHeight": 240,
"maxWidth": 320,
"maxHeight": 240,
"minFrameRate": 15
},
"destination_number": "1026",
"caller_id_name": "789789",
"caller_id_number": "xxxxxxxxx30",
"outgoingBandwidth": "363",
"incomingBandwidth": "795",
"dedEnc": false,
"mirrorInput": false,
"userVariables": {
"avatar": "",
"email": ""
},
"callID": "a0f03438-a7ba-0145-ad28-c57405615cbd",
"remote_caller_id_name": "Outbound Call",
"remote_caller_id_number": "1026"
},
"sessid": "f6c5ce70-2fc5-6599-5b1a-b190cc072f27"
},
"id": 18
}]
2016-03-07 13:33:21.210914 [DEBUG] mod_rtc.c:389 () State Change CS_NEW -> CS_INIT
2016-03-07 13:33:21.210914 [DEBUG] switch_core_session.c:613 N/A set UUID=a0f03438-a7ba-0145-ad28-c57405615cbd
2016-03-07 13:33:21.210914 [NOTICE] switch_channel.c:1091 New Channel verto.rtc/1026 [a0f03438-a7ba-0145-ad28-c57405615cbd]
2016-03-07 13:33:21.310905 [DEBUG] mod_verto.c:3553 Remote SDP verto.rtc/1026:
v=0
o=- 8839241919991864351 2 IN IP4 127.0.0.1
s=-
t=0 0
a=group:BUNDLE audio video
a=msid-semantic: WMS zk8dxi4qdO2fDxKlmYREHM28A590jNHRZ5wM
m=audio 60098 RTP/SAVPF 111 103 104 0 8 106 105 13 126
c=IN IP4 x.x.x.47
a=rtcp:60098 IN IP4 x.x.x.47
a=candidate:2608808550 1 udp 2122260223 192.168.1.33 60098 typ host generation 0
a=candidate:2608808550 2 udp 2122260223 192.168.1.33 60098 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 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0
a=candidate:1836006322 2 udp 1686052607 x.x.x.47 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0
a=ice-ufrag:ulSc0VI6wblyj/Yh
a=ice-pwd:xljyntK2FrUbN6pR+kJe0w0L
a=ice-options:google-ice
a=fingerprint:sha-256 56:32:AB:CD:46:DF:9F:D6:AD:18:AA:73:A6:58:D3:D8:22:E4:20:3E:F1:54:E4:A7:6E:83:67:C3:E2:57:E5:8E
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; sprop-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:2255451044 cname:mn0BfhWXIhxUt2jW
a=ssrc:2255451044 msid:zk8dxi4qdO2fDxKlmYREHM28A590jNHRZ5wM d3c12d3f-b09e-44c3-84bd-68b6ce65e4bb
a=ssrc:2255451044 mslabel:zk8dxi4qdO2fDxKlmYREHM28A590jNHRZ5wM
a=ssrc:2255451044 label:d3c12d3f-b09e-44c3-84bd-68b6ce65e4bb
m=video 60098 RTP/SAVPF 100 116 117 96
c=IN IP4 x.x.x.47
a=rtcp:60098 IN IP4 x.x.x.47
a=candidate:2608808550 1 udp 2122260223 192.168.1.33 60098 typ host generation 0
a=candidate:2608808550 2 udp 2122260223 192.168.1.33 60098 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 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0
a=candidate:1836006322 2 udp 1686052607 x.x.x.47 60098 typ srflx raddr 192.168.1.33 rport 60098 generation 0
a=ice-ufrag:ulSc0VI6wblyj/Yh
a=ice-pwd:xljyntK2FrUbN6pR+kJe0w0L
a=ice-options:google-ice
a=fingerprint:sha-256 56:32:AB:CD:46:DF:9F:D6:AD:18:AA:73:A6:58:D3:D8:22:E4:20:3E:F1:54:E4:A7:6E:83:67:C3:E2:57:E5:8E
a=setup:actpass
a=mid:video
a=extmap:2 urn:ietf:params:rtp-hdrext:toffset
a=extmap:3 http://www.webrtc.org/experiments/rtp-hdrext/abs-send-time
a=recvonly
a=rtcp-mux
a=rtpmap:100 VP8/90000
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
a=rtcp-fb:100 goog-remb
a=rtpmap:116 red/90000
a=rtpmap:117 ulpfec/90000
a=rtpmap:96 rtx/90000
a=fmtp:96 apt=100
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/1026) Running State Change CS_INIT
2016-03-07 13:33:21.310905 [ALERT] mod_verto.c:604 WRITE x.x.x.47:38105 [{
"jsonrpc": "2.0",
"id": 18,
"result": {
"message": "CALL CREATED",
"callID": "a0f03438-a7ba-0145-ad28-c57405615cbd",
"sessid": "f6c5ce70-2fc5-6599-5b1a-b190cc072f27"
}
}]
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:516 (verto.rtc/1026) State INIT
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:40 verto.rtc/1026 Standard INIT
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:48 (verto.rtc/1026) State Change CS_INIT -> CS_ROUTING
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:516 (verto.rtc/1026) State INIT going to sleep
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/1026) Running State Change CS_ROUTING
2016-03-07 13:33:21.310905 [DEBUG] switch_channel.c:2239 (verto.rtc/1026) Callstate Change DOWN -> RINGING
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:532 (verto.rtc/1026) State ROUTING
2016-03-07 13:33:21.310905 [DEBUG] mod_rtc.c:89 verto.rtc/1026 RTC ROUTING
2016-03-07 13:33:21.310905 [DEBUG] switch_core_state_machine.c:166 verto.rtc/1026 Standard ROUTING
2016-03-07 13:33:21.310905 [INFO] mod_dialplan_xml.c:637 Processing 789789 <xxxxxxxxx30>->1026 in context default
Dialplan: verto.rtc/1026 parsing [default->] continue=false
Dialplan: verto.rtc/1026 Regex (PASS) [] destination_number(1026) =~ // break=on-false
Dialplan: verto.rtc/1026 Action set(callstart=2016-03-07 11:33:21)
Dialplan: verto.rtc/1026 Action set(call_processed=internal)
Dialplan: verto.rtc/1026 Action set(originated_destination_number=1026)
Dialplan: verto.rtc/1026 Action set(hangup_after_bridge=true)
Dialplan: verto.rtc/1026 Action set(continue_on_fail=true)
Dialplan: verto.rtc/1026 Action set(fax_enable_t38=true)
Dialplan: verto.rtc/1026 Action set(fax_enable_t38_request=true)
Dialplan: verto.rtc/1026 Action export(t38_passthru=true)
Dialplan: verto.rtc/1026 Action set(call_direction=outbound)
Dialplan: verto.rtc/1026 Action set(calltype=STANDARD)
Dialplan: verto.rtc/1026 Action set(absolute_codec_string='^^G729:PCMA:PCMU:opus')
Dialplan: verto.rtc/1026 Action limit_execute(db Cust1_xxxx1 gw_Cust1_xxxx1 4 bridge {absolute_codec_string='^^G729:PCMA:PCMU:opus'}sofia/gateway/Cust1_xxxx1/1026)
Dialplan: verto.rtc/1026 Action bridge(sofia/gateway/test_gtw/1026)
Dialplan: verto.rtc/1026 Action bridge(sofia/gateway/test1_gtw/1026)
Dialplan: verto.rtc/1026 Action set(effective_destination_number=1026)
Dialplan: verto.rtc/1026 Action set(absolute_codec_string='^^G729:PCMA:PCMU:opus')
Dialplan: verto.rtc/1026 Action limit_execute(db Cust1_xxxx1 gw_Cust1_xxxx1 4 bridge {absolute_codec_string='^^G729:PCMA:PCMU:opus'}sofia/gateway/Cust1_xxxx1/1026)
Dialplan: verto.rtc/1026 Action bridge(sofia/gateway/test_gtw/1026)
Dialplan: verto.rtc/1026 Action bridge(sofia/gateway/test1_gtw/1026)
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:216 (verto.rtc/1026) State Change CS_ROUTING -> CS_EXECUTE
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:532 (verto.rtc/1026) State ROUTING going to sleep
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/1026) Running State Change CS_EXECUTE
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:539 (verto.rtc/1026) State EXECUTE
2016-03-07 13:33:21.430855 [DEBUG] mod_rtc.c:120 verto.rtc/1026 RTC EXECUTE
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:258 verto.rtc/1026 Standard EXECUTE
EXECUTE verto.rtc/1026 set(callstart=2016-03-07 11:33:21)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [callstart]=[2016-03-07 11:33:21]
EXECUTE verto.rtc/1026 set(call_processed=internal)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [call_processed]=[internal]
EXECUTE verto.rtc/1026 set(originated_destination_number=1026)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [originated_destination_number]=[1026]
EXECUTE verto.rtc/1026 set(hangup_after_bridge=true)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [hangup_after_bridge]=[true]
EXECUTE verto.rtc/1026 set(continue_on_fail=true)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [continue_on_fail]=[true]
EXECUTE verto.rtc/1026 set(fax_enable_t38=true)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [fax_enable_t38]=[true]
EXECUTE verto.rtc/1026 set(fax_enable_t38_request=true)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [fax_enable_t38_request]=[true]
EXECUTE verto.rtc/1026 export(t38_passthru=true)
2016-03-07 13:33:21.430855 [DEBUG] switch_channel.c:1283 EXPORT (export_vars) [t38_passthru]=[true]
EXECUTE verto.rtc/1026 set(call_direction=outbound)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [call_direction]=[outbound]
EXECUTE verto.rtc/1026 set(calltype=STANDARD)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [calltype]=[STANDARD]
EXECUTE verto.rtc/1026 sched_hangup(+1440 allotted_timeout)
2016-03-07 13:33:21.430855 [DEBUG] switch_scheduler.c:249 Added task 178 switch_ivr_schedule_hangup (a0f03438-a7ba-0145-ad28-c57405615cbd) to run at 1457351841
EXECUTE verto.rtc/1026 set(effective_destination_number=1026)
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [effective_destination_number]=[1026]
EXECUTE verto.rtc/1026 set(absolute_codec_string='^^G729:PCMA:PCMU:opus')
2016-03-07 13:33:21.430855 [DEBUG] mod_dptools.c:1498 SET verto.rtc/1026 [absolute_codec_string]=['^^G729:PCMA:PCMU:opus']
EXECUTE verto.rtc/1026 limit_execute(db Cust1_xxxx1 gw_Cust1_xxxx1 4 bridge {absolute_codec_string='^^G729:PCMA:PCMU:opus'}sofia/gateway/Cust1_xxxx1/1026)
2016-03-07 13:33:21.430855 [DEBUG] switch_limit.c:126 incr called: Cust1_xxxx1_gw_Cust1_xxxx1 max:4, interval:0
2016-03-07 13:33:21.430855 [DEBUG] mod_db.c:194 Usage for Cust1_xxxx1_gw_Cust1_xxxx1 is now 1/4
EXECUTE verto.rtc/1026 bridge({absolute_codec_string=^^G729:PCMA:PCMU:opus}sofia/gateway/Cust1_xxxx1/1026)
2016-03-07 13:33:21.430855 [DEBUG] switch_channel.c:1237 verto.rtc/1026 EXPORTING[export_vars] [t38_passthru]=[true] to event
2016-03-07 13:33:21.430855 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
2016-03-07 13:33:21.430855 [NOTICE] switch_channel.c:1091 New Channel sofia/default/1026 [0e609d49-eff1-4801-bd46-c7e2dd9cd511]
2016-03-07 13:33:21.430855 [DEBUG] mod_sofia.c:4765 (sofia/default/1026) State Change CS_NEW -> CS_INIT
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_INIT
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:516 (sofia/default/1026) State INIT
2016-03-07 13:33:21.430855 [DEBUG] mod_sofia.c:88 sofia/default/1026 SOFIA INIT
2016-03-07 13:33:21.430855 [DEBUG] sofia_glue.c:1228 sip:x.x.x.91 Setting proxy route to sofia/default/1026
2016-03-07 13:33:21.430855 [DEBUG] sofia_glue.c:1257 sofia/default/1026 sending invite version: 1.6.5 64bit
Local SDP:
v=0
o=FreeSWITCH 1457331549 1457331550 IN IP4 x.x.x.88
s=FreeSWITCH
c=IN IP4 x.x.x.88
t=0 0
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:40 sofia/default/1026 Standard INIT
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:48 (sofia/default/1026) State Change CS_INIT -> CS_ROUTING
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:516 (sofia/default/1026) State INIT going to sleep
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_ROUTING
2016-03-07 13:33:21.430855 [DEBUG] sofia.c:6750 Channel sofia/default/1026 entering state [calling][0]
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:532 (sofia/default/1026) State ROUTING
2016-03-07 13:33:21.430855 [DEBUG] mod_sofia.c:141 sofia/default/1026 SOFIA ROUTING
2016-03-07 13:33:21.430855 [DEBUG] switch_ivr_originate.c:67 (sofia/default/1026) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:532 (sofia/default/1026) State ROUTING going to sleep
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_CONSUME_MEDIA
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:551 (sofia/default/1026) State CONSUME_MEDIA
2016-03-07 13:33:21.430855 [DEBUG] switch_core_state_machine.c:551 (sofia/default/1026) State CONSUME_MEDIA going to sleep
2016-03-07 13:33:21.490963 [DEBUG] sofia.c:6750 Channel sofia/default/1026 entering state [terminated][400]
2016-03-07 13:33:21.490963 [NOTICE] sofia.c:7769 Hangup sofia/default/1026 [CS_CONSUME_MEDIA] [NORMAL_TEMPORARY_FAILURE]
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_HANGUP
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:739 (sofia/default/1026) Callstate Change DOWN -> HANGUP
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:741 (sofia/default/1026) State HANGUP
2016-03-07 13:33:21.490963 [DEBUG] mod_sofia.c:431 Channel sofia/default/1026 hanging up, cause: NORMAL_TEMPORARY_FAILURE
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:60 sofia/default/1026 Standard HANGUP, cause: NORMAL_TEMPORARY_FAILURE
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:741 (sofia/default/1026) State HANGUP going to sleep
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:508 (sofia/default/1026) State Change CS_HANGUP -> CS_REPORTING
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_REPORTING
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:827 (sofia/default/1026) State REPORTING
2016-03-07 13:33:21.490963 [DEBUG] switch_ivr_originate.c:3750 Originate Resulted in Error Cause: 41 [NORMAL_TEMPORARY_FAILURE]
2016-03-07 13:33:21.490963 [INFO] mod_dptools.c:3379 Originate Failed. Cause: NORMAL_TEMPORARY_FAILURE
2016-03-07 13:33:21.490963 [INFO] mod_dptools.c:4602 immediately releasing
EXECUTE verto.rtc/1026 bridge(sofia/gateway/test_gtw/1026)
2016-03-07 13:33:21.490963 [DEBUG] switch_channel.c:1237 verto.rtc/1026 EXPORTING[export_vars] [t38_passthru]=[true] to event
2016-03-07 13:33:21.490963 [DEBUG] switch_ivr_originate.c:2127 Parsing global variables
2016-03-07 13:33:21.490963 [NOTICE] switch_channel.c:1091 New Channel sofia/default/1026 [a501a816-7fd2-4fc0-9adf-fa7d87003b67]
2016-03-07 13:33:21.490963 [DEBUG] mod_sofia.c:4765 (sofia/default/1026) State Change CS_NEW -> CS_INIT
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_INIT
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:516 (sofia/default/1026) State INIT
2016-03-07 13:33:21.490963 [DEBUG] mod_sofia.c:88 sofia/default/1026 SOFIA INIT
2016-03-07 13:33:21.490963 [DEBUG] sofia_glue.c:1228 sip:x.x.x.91 Setting proxy route to sofia/default/1026
2016-03-07 13:33:21.490963 [DEBUG] sofia_glue.c:1257 sofia/default/1026 sending invite version: 1.6.5 64bit
Local SDP:
v=0
o=FreeSWITCH 1457320955 1457320956 IN IP4 x.x.x.88
s=FreeSWITCH
c=IN IP4 x.x.x.88
t=0 0
m=audio 29446 RTP/AVP 18 0 8 101
a=rtpmap:18 G729/8000
a=rtpmap:0 PCMU/8000
a=rtpmap:8 PCMA/8000
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-16
a=ptime:20
a=sendrecv
m=video 27274 RTP/AVP 100
a=rtpmap:100 VP8/90000
b=AS:1024
a=rtcp-fb:100 ccm fir
a=rtcp-fb:100 ccm tmmbr
a=rtcp-fb:100 nack
a=rtcp-fb:100 nack pli
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:40 sofia/default/1026 Standard INIT
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:48 (sofia/default/1026) State Change CS_INIT -> CS_ROUTING
2016-03-07 13:33:21.490963 [DEBUG] switch_core_state_machine.c:516 (sofia/default/1026) State INIT going to sleep
2016-03-07 13:33:21.510848 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_ROUTING
2016-03-07 13:33:21.510848 [DEBUG] sofia.c:6750 Channel sofia/default/1026 entering state [calling][0]
2016-03-07 13:33:21.510848 [DEBUG] switch_core_state_machine.c:532 (sofia/default/1026) State ROUTING
2016-03-07 13:33:21.510848 [DEBUG] mod_sofia.c:141 sofia/default/1026 SOFIA ROUTING
2016-03-07 13:33:21.510848 [DEBUG] switch_ivr_originate.c:67 (sofia/default/1026) State Change CS_ROUTING -> CS_CONSUME_MEDIA
2016-03-07 13:33:21.510848 [DEBUG] switch_core_state_machine.c:532 (sofia/default/1026) State ROUTING going to sleep
2016-03-07 13:33:21.510848 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_CONSUME_MEDIA
2016-03-07 13:33:21.510848 [DEBUG] switch_core_state_machine.c:551 (sofia/default/1026) State CONSUME_MEDIA
2016-03-07 13:33:21.510848 [DEBUG] switch_core_state_machine.c:551 (sofia/default/1026) State CONSUME_MEDIA going to sleep
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:104 sofia/default/1026 Standard REPORTING, cause: NORMAL_TEMPORARY_FAILURE
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:827 (sofia/default/1026) State REPORTING going to sleep
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:499 (sofia/default/1026) State Change CS_REPORTING -> CS_DESTROY
2016-03-07 13:33:21.750846 [DEBUG] switch_core_session.c:1646 Session 427 (sofia/default/1026) Locked, Waiting on external entities
2016-03-07 13:33:21.750846 [NOTICE] switch_core_session.c:1664 Session 427 (sofia/default/1026) Ended
2016-03-07 13:33:21.750846 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/1026 [CS_DESTROY]
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:630 (sofia/default/1026) Running State Change CS_DESTROY
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:640 (sofia/default/1026) State DESTROY
2016-03-07 13:33:21.750846 [DEBUG] mod_sofia.c:341 sofia/default/1026 SOFIA DESTROY
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:111 sofia/default/1026 Standard DESTROY
2016-03-07 13:33:21.750846 [DEBUG] switch_core_state_machine.c:640 (sofia/default/1026) State DESTROY going to sleep
2016-03-07 13:33:22.710917 [DEBUG] sofia.c:6750 Channel sofia/default/1026 entering state [proceeding][183]
2016-03-07 13:33:22.710917 [DEBUG] sofia.c:6760 Remote SDP:
v=0
o=Sippy 1999834334914869335 1 IN IP4 197.80.141.4
s=-
c=IN IP4 197.80.141.4
t=0 0
m=audio 25222 RTP/AVP 18 101
c=IN IP4 197.80.141.4
a=rtpmap:18 G729/8000
a=fmtp:18 annexb=no
a=rtpmap:101 telephone-event/8000
a=fmtp:101 0-15
a=pmft:T38
a=ptime:60
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [G729:18:8000:60:8000:1]/[G729:18:8000:20:8000:1]
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4182 Bah HUMBUG! Sticking with G729 at 8000h@20i
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4208 Audio Codec Compare [G729:18:8000:20:8000:1] ++++ is saved as a match
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [G729:18:8000:60:8000:1]/[PCMU:0:8000:20:64000:1]
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4153 Audio Codec Compare [G729:18:8000:60:8000:1]/[PCMA:8:8000:20:64000:1]
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4069 Set telephone-event payload to 101 at 8000
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:2898 Set Codec sofia/default/1026 G729/8000 20 ms 160 samples 8000 bits 1 channels
2016-03-07 13:33:22.710917 [DEBUG] switch_core_codec.c:111 sofia/default/1026 Original read codec set to G729:18
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4417 Set telephone-event payload to 101 at 8000
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:4473 sofia/default/1026 Set 2833 dtmf send payload to 101 recv payload to 101
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:6027 AUDIO RTP [sofia/default/1026] x.x.x.88 port 29446 -> 197.80.141.4 port 25222 codec: 18 ms: 20
2016-03-07 13:33:22.710917 [DEBUG] switch_rtp.c:3788 Starting timer [soft] 160 bytes per 20ms
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:6326 sofia/default/1026 Set 2833 dtmf send payload to 101
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:6333 sofia/default/1026 Set 2833 dtmf receive payload to 101
2016-03-07 13:33:22.710917 [DEBUG] switch_core_media.c:6356 sofia/default/1026 Set rtp dtmf delay to 40
2016-03-07 13:33:22.710917 [NOTICE] sofia_media.c:92 Pre-Answer sofia/default/1026!
2016-03-07 13:33:22.710917 [DEBUG] switch_channel.c:3460 (sofia/default/1026) Callstate Change DOWN -> EARLY
2016-03-07 13:33:22.730916 [DEBUG] switch_core_media.c:4069 Set telephone-event payload to 126 at 8000
2016-03-07 13:33:22.730916 [DEBUG] switch_core_media.c:4473 verto.rtc/1026 Set 2833 dtmf send payload to 126 recv payload to 126
2016-03-07 13:33:22.730916 [NOTICE] switch_channel.c:3501 Hangup verto.rtc/1026 [CS_EXECUTE] [INCOMPATIBLE_DESTINATION]
2016-03-07 13:33:22.730916 [DEBUG] switch_ivr_originate.c:3563 verto.rtc/1026 Media Establishment Failed.
2016-03-07 13:33:22.730916 [NOTICE] switch_ivr_originate.c:3565 Hangup sofia/default/1026 [CS_CONSUME_MEDIA] [INCOMPATIBLE_DESTINATION]
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_HANGUP
2016-03-07 13:33:22.730916 [DEBUG] switch_ivr_originate.c:3750 Originate Resulted in Error Cause: 88 [INCOMPATIBLE_DESTINATION]
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:739 (sofia/default/1026) Callstate Change EARLY -> HANGUP
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:741 (sofia/default/1026) State HANGUP
2016-03-07 13:33:22.730916 [DEBUG] mod_sofia.c:431 Channel sofia/default/1026 hanging up, cause: INCOMPATIBLE_DESTINATION
2016-03-07 13:33:22.730916 [INFO] mod_dptools.c:3379 Originate Failed. Cause: INCOMPATIBLE_DESTINATION
2016-03-07 13:33:22.730916 [DEBUG] switch_core_session.c:2796 verto.rtc/1026 skip receive message [APPLICATION_EXEC_COMPLETE] (channel is hungup already)
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:539 (verto.rtc/1026) State EXECUTE going to sleep
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/1026) Running State Change CS_HANGUP
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:739 (verto.rtc/1026) Callstate Change RINGING -> HANGUP
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/1026) State HANGUP
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:60 verto.rtc/1026 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:741 (verto.rtc/1026) State HANGUP going to sleep
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:508 (verto.rtc/1026) State Change CS_HANGUP -> CS_REPORTING
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:473 (verto.rtc/1026) Running State Change CS_REPORTING
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:827 (verto.rtc/1026) State REPORTING
2016-03-07 13:33:22.730916 [DEBUG] mod_sofia.c:495 Sending CANCEL to sofia/default/1026
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:60 sofia/default/1026 Standard HANGUP, cause: INCOMPATIBLE_DESTINATION
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:741 (sofia/default/1026) State HANGUP going to sleep
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:508 (sofia/default/1026) State Change CS_HANGUP -> CS_REPORTING
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:473 (sofia/default/1026) Running State Change CS_REPORTING
2016-03-07 13:33:22.730916 [DEBUG] switch_core_state_machine.c:827 (sofia/default/1026) State REPORTING
2016-03-07 13:33:22.770838 [ALERT] mod_verto.c:604 WRITE x.x.x.47:38105 [{
"jsonrpc": "2.0",
"id": 23,
"method": "verto.bye",
"params": {
"callID": "a0f03438-a7ba-0145-ad28-c57405615cbd",
"causeCode": 88,
"cause": "INCOMPATIBLE_DESTINATION"
}
}]
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:104 sofia/default/1026 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:827 (sofia/default/1026) State REPORTING going to sleep
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:499 (sofia/default/1026) State Change CS_REPORTING -> CS_DESTROY
2016-03-07 13:33:23.010891 [DEBUG] switch_core_session.c:1646 Session 428 (sofia/default/1026) Locked, Waiting on external entities
2016-03-07 13:33:23.010891 [NOTICE] switch_core_session.c:1664 Session 428 (sofia/default/1026) Ended
2016-03-07 13:33:23.010891 [NOTICE] switch_core_session.c:1668 Close Channel sofia/default/1026 [CS_DESTROY]
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:630 (sofia/default/1026) Running State Change CS_DESTROY
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:640 (sofia/default/1026) State DESTROY
2016-03-07 13:33:23.010891 [DEBUG] mod_sofia.c:341 sofia/default/1026 SOFIA DESTROY
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:111 sofia/default/1026 Standard DESTROY
2016-03-07 13:33:23.010891 [DEBUG] switch_core_state_machine.c:640 (sofia/default/1026) State DESTROY going to sleep
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:104 verto.rtc/1026 Standard REPORTING, cause: INCOMPATIBLE_DESTINATION
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:827 (verto.rtc/1026) State REPORTING going to sleep
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:499 (verto.rtc/1026) State Change CS_REPORTING -> CS_DESTROY
2016-03-07 13:33:23.030912 [DEBUG] switch_core_session.c:1646 Session 426 (verto.rtc/1026) Locked, Waiting on external entities
2016-03-07 13:33:23.030912 [NOTICE] switch_core_session.c:1664 Session 426 (verto.rtc/1026) Ended
2016-03-07 13:33:23.030912 [NOTICE] switch_core_session.c:1668 Close Channel verto.rtc/1026 [CS_DESTROY]
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:630 (verto.rtc/1026) Running State Change CS_DESTROY
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:640 (verto.rtc/1026) State DESTROY
2016-03-07 13:33:23.030912 [DEBUG] mod_rtc.c:132 verto.rtc/1026 RTC DESTROY
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:111 verto.rtc/1026 Standard DESTROY
2016-03-07 13:33:23.030912 [DEBUG] switch_core_state_machine.c:640 (verto.rtc/1026) State DESTROY going to sleep
2016-03-07 13:33:23.130972 [ALERT] mod_verto.c:1365 READ x.x.x.47:38105 [{
"jsonrpc": "2.0",
"method": "verto.bye",
"params": {
"dialogParams": {
"useVideo": true,
"useStereo": true,
"screenShare": false,
"useCamera": "none",
"useMic": "any",
"useSpeak": "any",
"tag": "webcam",
"localTag": null,
"login": "789789 at x.x.x.91",
"videoParams": {
"minWidth": 320,
"minHeight": 240,
"maxWidth": 320,
"maxHeight": 240,
"minFrameRate": 15
},
"destination_number": "1026",
"caller_id_name": "789789",
"caller_id_number": "xxxxxxxxx30",
"outgoingBandwidth": "363",
"incomingBandwidth": "795",
"dedEnc": false,
"mirrorInput": false,
"userVariables": {
"avatar": "",
"email": ""
},
"callID": "a0f03438-a7ba-0145-ad28-c57405615cbd",
"remote_caller_id_name": "Outbound Call",
"remote_caller_id_number": "1026"
},
"sessid": "f6c5ce70-2fc5-6599-5b1a-b190cc072f27"
},
"id": 19
}]
2016-03-07 13:33:23.130972 [ALERT] mod_verto.c:604 WRITE x.x.x.47:38105 [{
"jsonrpc": "2.0",
"id": 19,
"error": {
"callID": "a0f03438-a7ba-0145-ad28-c57405615cbd",
"message": "CALL DOES NOT EXIST",
"code": -32002
}
}]
2016-03-07 13:33:23.230917 [ALERT] mod_verto.c:1365 READ x.x.x.47:38105 [{
"jsonrpc": "2.0",
"id": 23,
"result": {
"method": "verto.bye"
}
}]
2016-03-07 13:33:23.430915 [DEBUG] switch_scheduler.c:144 Deleting task 178 switch_ivr_schedule_hangup (a0f03438-a7ba-0145-ad28-c57405615cbd)
Join us at ClueCon 2016 Aug 8-12, 2016
More information about the FreeSWITCH-users
mailing list