[Freeswitch-users] codec negotiation weirdness

Sat Feb 16 14:40:07 MSK 2013

Sorry about the self reply, but I figured out something new: if I
don't specify the codec params in inbound-codec-prefs, and instead
just specify:

opus,isac,speex at 16000h@20i,speex at 8000h@20i,PCMU

... then isac does get selected when opus isn't advertised by the client:

2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [ISAC:103:16000:30:0]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [ISAC:104:32000:30:0]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [PCMU:0:8000:20:64000]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [PCMA:8:8000:20:64000]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [CN:106:32000:20:0]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [CN:105:16000:20:0]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [CN:13:8000:20:0]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [telephone-event:126:8000:20:0]/[opus:116:48000:40:32000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5268 Set 2833 dtmf
send/recv payload to 126
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5139 Audio Codec
Compare [ISAC:103:16000:30:0]/[isac:99:32000:60:160000]
2013-02-16 03:23:53.045715 [DEBUG] sofia_glue.c:5161 Bah HUMBUG!
Sticking with isac at 32000h@60i

However, in that case it picks a 60ms ptime, which is not what I want.
 FS startup messages seem to indicate the isac version I'm using does
support 30ms:

2013-02-16 03:21:49.163553 [NOTICE] switch_loadable_module.c:187
Adding Codec isac 99 isac 32000hz 60ms 160000bps
2013-02-16 03:21:49.163562 [NOTICE] switch_loadable_module.c:187
Adding Codec isac 99 isac 32000hz 30ms 160000bps
2013-02-16 03:21:49.163567 [NOTICE] switch_loadable_module.c:187
Adding Codec isac 99 isac 16000hz 60ms 53400bps
2013-02-16 03:21:49.163572 [NOTICE] switch_loadable_module.c:187
Adding Codec isac 99 isac 16000hz 30ms 53400bps

Why won't it let me select 30ms?  Why does FS auto-select 60ms when I
don't specify a preference?

Forgot to mention before: I'm using current git master, rev 9733740.

On Sat, Feb 16, 2013 at 2:04 AM, Brian J. Tarricone <brian at tarricone.org> wrote:
> Hi all,
>
> I'm experiencing some strange behavior with codec negotiation.  I'm
> using the default early negotiation, and I'm setting
> inbound-codec-negotiation to "scrooge" so FS will always have the
> final word on what codec is used.  (I've also tried "greedy" with the
> same results.  "generous" does not meet my needs, unfortunately.)
>
> I'm setting inbound-codec-prefs to the following:
>
> opus at 48000h@20i,isac at 32000h@30i,speex at 16000h@20i,speex at 8000h@20i,PCMU
>
> However, I'm seeing FS select PCMU for a client that advertises both
> isac/32k and PCMU.  The relevant portion of the FS log is below.
>
> 2013-02-16 01:45:06.947647 [DEBUG] sofia.c:5589 Remote SDP:
> v=0
> o=- 1772524861 1772524861 IN IP4 10.70.209.126
> s=-
> c=IN IP4 10.70.209.126
> t=0 0
> m=audio 57178 RTP/AVP 103 104 0 8 106 105 13 126
> c=IN IP4 10.70.209.126
> 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
>
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:103:16000:30:0]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:104:32000:30:0]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMA:8:8000:20:64000]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:106:32000:20:0]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:105:16000:20:0]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:13:8000:20:0]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [telephone-event:126:8000:20:0]/[opus:116:48000:20:32000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5268 Set 2833 dtmf
> send/recv payload to 126
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:103:16000:30:0]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:104:32000:30:0]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMA:8:8000:20:64000]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:106:32000:20:0]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:105:16000:20:0]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:13:8000:20:0]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [telephone-event:126:8000:20:0]/[SPEEX:99:16000:20:42200]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5268 Set 2833 dtmf
> send/recv payload to 126
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:103:16000:30:0]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:104:32000:30:0]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMA:8:8000:20:64000]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:106:32000:20:0]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:105:16000:20:0]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [CN:13:8000:20:0]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [telephone-event:126:8000:20:0]/[SPEEX:99:8000:20:24600]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5268 Set 2833 dtmf
> send/recv payload to 126
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:103:16000:30:0]/[PCMU:0:8000:20:64000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:104:32000:30:0]/[PCMU:0:8000:20:64000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [PCMU:0:8000:20:64000]/[PCMU:0:8000:20:64000]
> 2013-02-16 01:45:06.947647 [DEBUG] sofia_glue.c:5161 Bah HUMBUG!
> Sticking with PCMU at 8000h@20i
>
> As you can see, it first compares all offered codecs against opus/48k,
> next skips isac completely, then goes to speex/16k, speex/8k, and
> PCMU, and eventually grudgingly accepts PCMU.
>
> Interestingly, if I drop opus from the list, and leave the rest as-is,
> it does select isac/32k, but weirdly:
>
> 2013-02-16 01:51:10.691314 [DEBUG] sofia_glue.c:5139 Audio Codec
> Compare [ISAC:103:16000:30:0]/[isac:99:32000:30:160000]
> 2013-02-16 01:51:10.691314 [DEBUG] sofia_glue.c:5161 Bah HUMBUG!
> Sticking with isac at 32000h@30i
>
> It picks isac/32k after only examining the isac/16k line in the SDP,
> before it even gets to isac/32k.  (In fact those are the only 2 lines
> after the SDP is printed; it makes the decision after making just one
> comparison.)
>
> Any ideas?  Am I just misunderstanding how this works?
>
> Thanks,
> Brian