[Freeswitch-users] Codec Negotiation Error Lync/UCMA -> external provider
Michael Collins
msc at freeswitch.org
Wed May 22 02:36:55 MSD 2013
Looks like a device is misbehaving and violating RFC3711. Fortunately you
can explicitly allow this behavior:
http://wiki.freeswitch.org/wiki/NDLB#NDLB-allow-crypto-in-avp
Let us know if that works.
-MC
On Tue, May 21, 2013 at 9:11 AM, JohnGalt1717 <jrlh at outlook.com> wrote:
> Hi there, I'm a newbee, but I've been reading everything I can and I can't
> find anything that assists with this.
>
> I have a UCMA app that is internal that communicates on the internal sip
> port (set to 5042) and it bridges with dialplan to the external sip trunk
> (trying 2, one of which is siproutes).
>
> If I enable proxy, the call rings out and I get dead air on the other side,
> but it won't ever properly establish the call in the UCMA app because of
> some issue with codecs from what I can tell.
>
> Obviously I don't want to use proxy mode, what I really want to do is use
> it
> straight up and have FS do the transcoding etc.
>
> The problem is that once I do this I get a Codec Negotiation error and I
> can't figure out why. Anyone have any ideas as to why it's freaking out
> like
> this? (log below) Thanks!
>
> 2013-05-21 12:09:41.570884 [DEBUG] sofia_glue.c:1219 Local SDP:
> v=0
> o=FreeSWITCH 1369129003 1369129004 IN IP4 10.8.0.158
> s=FreeSWITCH
> c=IN IP4 10.8.0.158
> t=0 0
> m=audio 23578 RTP/AVP 9 0 8 101 13
> a=rtpmap:9 G722/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
>
> 2013-05-21 12:09:41.570884 [DEBUG] mod_sofia.c:114
> (sofia/external/+16032897972) State Change CS_INIT -> CS_ROUTING
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_session.c:1340 Send signal
> sofia/external/+16032897972 [BREAK]
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:454
> (sofia/external/+16032897972) State INIT going to sleep
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/+16032897972) Running State Change CS_ROUTING
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:470
> (sofia/external/+16032897972) State ROUTING
> 2013-05-21 12:09:41.570884 [DEBUG] mod_sofia.c:137
> sofia/external/+16032897972 SOFIA ROUTING
> 2013-05-21 12:09:41.570884 [DEBUG] switch_ivr_originate.c:67
> (sofia/external/+16032897972) State Change CS_ROUTING -> CS_CONSUME_MEDIA
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_session.c:1340 Send signal
> sofia/external/+16032897972 [BREAK]
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:470
> (sofia/external/+16032897972) State ROUTING going to sleep
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:415
> (sofia/external/+16032897972) Running State Change CS_CONSUME_MEDIA
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:489
> (sofia/external/+16032897972) State CONSUME_MEDIA
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_state_machine.c:489
> (sofia/external/+16032897972) State CONSUME_MEDIA going to sleep
> 2013-05-21 12:09:41.570884 [DEBUG] switch_core_session.c:1005 Send signal
> sofia/external/+16032897972 [BREAK]
> 2013-05-21 12:09:41.570884 [DEBUG] sofia.c:5742 Channel
> sofia/external/+16032897972 entering state [calling][0]
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_session.c:1005 Send signal
> sofia/external/+16032897972 [BREAK]
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_session.c:1005 Send signal
> sofia/external/+16032897972 [BREAK]
> 2013-05-21 12:09:43.891308 [INFO] sofia.c:966 sofia/external/+16032897972
> Update Callee ID to "+16032897972" <sip:+16032897972 at 4.30.136.195>
> 2013-05-21 12:09:43.891308 [DEBUG] sofia.c:5742 Channel
> sofia/external/+16032897972 entering state [proceeding][183]
> 2013-05-21 12:09:43.891308 [DEBUG] sofia.c:5751 Remote SDP:
> v=0
> o=Sonus_UAC 10608 14579 IN IP4 207.239.33.59
> s=SIP Media Capabilities
> c=IN IP4 207.239.33.59
> t=0 0
> m=audio 10460 RTP/AVP 0 101
> a=rtpmap:0 PCMU/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-15
> a=maxptime:20
>
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:2714 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[G722:9:8000:20:64000]
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:2714 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:1813 Set Codec
> sofia/external/+16032897972 PCMU/8000 20 ms 160 samples 64000 bits
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_codec.c:111
> sofia/external/+16032897972 Original read codec set to PCMU:0
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:2876 Set 2833 dtmf
> send payload to 101
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:3800 AUDIO RTP
> [sofia/external/+16032897972] 10.8.0.158 port 23578 -> 207.239.33.59 port
> 10460 codec: 0 m
> s: 20
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:2659 Starting timer [soft]
> 160 bytes per 20ms
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]: START
> SESSION INITIALIZATION. sID=4.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> ZID=306130383030396530393363.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> Loading User's profile:
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> allowclear: OFF
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> autosecure: ON
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> disclose_bit: OFF
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> signal. role: Initiator
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> TTL: 4294967295
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]: SAS
> schemes: 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 B256
> 2013-05-21 12:09:
> 43.891308 [DEBUG] switch_rtp.c:1231 B32 2013-05-21 12:09:43.891308 [DEBUG]
> switch_rtp.c:1231
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> Ciphers: 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 AES3
> 2013-05-21 12:09:4
> 3.891308 [DEBUG] switch_rtp.c:1231 AES1 2013-05-21 12:09:43.891308 [DEBUG]
> switch_rtp.c:1231
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]: PK
> schemes: 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 EC25
> 2013-05-21 12:09:
> 43.891308 [DEBUG] switch_rtp.c:1231 DH3k 2013-05-21 12:09:43.891308 [DEBUG]
> switch_rtp.c:1231 DH2k 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231
> Mult 201
> 3-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> ATL: 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 HS32 2013-05-21
> 12:09:
> 43.891308 [DEBUG] switch_rtp.c:1231
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> Hashes: 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 S256
> 2013-05-21
> 12:09:4
> 3.891308 [DEBUG] switch_rtp.c:1231
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> Session initialization - DONE. sID=4.
>
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> ATTACH
> NEW STREAM to sID=4:
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp]:
> Stream ID=0 UNKNOWN switching <NONE> ---> <ACTIVE>.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> Empty slot was found - initializing new stream with ID=4.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> Preparing ZRTP Hello according to the Session profile.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp main]:
> ATTACH
> NEW STREAM - DONE.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp engine]: START
> STREAM ID=4 mode=CLEAR state=ACTIVE.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp]:
> Stream ID=4 CLEAR switching <ACTIVE> ---> <START>.
> 2013-05-21 12:09:43.891308 [DEBUG] switch_rtp.c:1231 [ zrtp utils]:
> Send
> <HELLO> ssrc=1428962591 seq=54611 size=144. Stream 4:CLEAR:START
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:4145 Set 2833 dtmf
> send payload to 101
> 2013-05-21 12:09:43.891308 [DEBUG] switch_core_media.c:4151 Set 2833 dtmf
> receive payload to 101
> 2013-05-21 12:09:43.891308 [NOTICE] sofia_media.c:92 Pre-Answer
> sofia/external/+16032897972!
> 2013-05-21 12:09:43.891308 [DEBUG] switch_channel.c:3273 Send signal
> sofia/internal/+16032897972 at 173.255.174.20 [BREAK]
> 2013-05-21 12:09:43.891308 [DEBUG] switch_channel.c:3277
> (sofia/external/+16032897972) Callstate Change DOWN -> EARLY
> 2013-05-21 12:09:43.911297 [DEBUG] switch_ivr_originate.c:411 Setting codec
> string on sofia/internal/+16032897972 at 173.255.174.20 to PCMU at 8000h@20i
> 2013-05-21 12:09:43.911297 [INFO] switch_ivr_originate.c:3416 Sending early
> media
> 2013-05-21 12:09:43.911297 [ERR] switch_core_media.c:2549 a=crypto in
> RTP/AVP, refer to rfc3711
> 2013-05-21 12:09:43.911297 [ERR] mod_sofia.c:2081 CODEC NEGOTIATION ERROR.
> SDP:
> v=0
> o=- 1 0 IN IP4 10.8.0.158
> s=session
> c=IN IP4 10.8.0.158
> b=CT:10000
> t=0 0
> m=audio 2908 RTP/AVP 9 112 111 0 8 116 13 118 97 101
> c=IN IP4 10.8.0.158
> a=rtpmap:9 G722/8000
> a=rtpmap:112 G7221/16000
> a=fmtp:112 bitrate=24000
> a=rtpmap:111 SIREN/16000
> a=fmtp:111 bitrate=16000
> a=rtpmap:0 PCMU/8000
> a=rtpmap:8 PCMA/8000
> a=rtpmap:116 AAL2-G726-32/8000
> a=rtpmap:13 CN/8000
> a=rtpmap:118 CN/16000
> a=rtpmap:97 RED/8000
> a=rtpmap:101 telephone-event/8000
> a=fmtp:101 0-16,36
> a=rtcp:2909
> a=label:main-audio
> a=crypto:1 AES_CM_128_HMAC_SHA1_80
> inline:BqtEfRv/sMasd3GS0I4FJRX5hh7BKVt+r8/vKbOk
>
>
>
>
>
>
> --
> View this message in context:
> http://freeswitch-users.2379917.n2.nabble.com/Codec-Negotiation-Error-Lync-UCMA-external-provider-tp7590911.html
> Sent from the freeswitch-users mailing list archive at Nabble.com.
>
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services:
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
>
>
>
>
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://wiki.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
>
--
Michael S Collins
Twitter: @mercutioviz
http://www.FreeSWITCH.org
http://www.ClueCon.com
http://www.OSTAG.org
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20130521/c32f4d2b/attachment-0001.html
Join us at ClueCon 2011 Aug 9-11, 2011
More information about the FreeSWITCH-users
mailing list