[Freeswitch-users] codec error on 1.6

[Sandro Bordacchini]

 Hi everyone.

I am facing a weird issue on a production setup, FS version
1.6.16~33~e6d643b-1~jessie+1 installed with deb from offcial repo, o.s.
debian 8.
Scenario is pretty straightforward: call incoming from voip provider and
routed to a sip phone, i have no nat between FS and provider, i have nat
between FS and sip phone.

Provider sends INVITE with sdp (g711a + g729 + te) to FS
FS sends INVITE with sdp (g711a + g729 + te) to sip phone
sip phone sends 180 RINGING back to FS
FS sends 183 SESS PROG with sdp (g711a + te) back to provider
PRACK and 200OK between provider and FS
sip phone sends 200 OK with sdp (g729 + te) to FS
FS sends ACK to sip phone
FS sends 200 without sdp to provider
FS sends UPDATE with sdp (g729 + te + g711a)
provider sends ACK to FS
sip phone sends 200OK (to the UPDATE) with sdp (G729 + te) to FS

At this point I have a bidirectional g711a rtp stream on the external
profile. Instead on the internal profile i receive g729 from the phone but
FS does not send any G729 stream to the phone.

I have run some tests: if i don't have G711a codec as 1st choice in the
incoming INVITE, the audio is ok; both the provider and the phone support
both G711a and G729, but sip phone always answer ONLY with its preferred
codec (in this test, G729).
Generally speaking, if sip phone's preferred codec is different from the
first codec in the incoming INVITE from the provider, i have the issue.
Since the codec mix and order from the provider is not known, i cannot
configure the sip phone accordingly.

On both external and internal profiles i have:
*inbound-codec-negotiation = generous*
*inbound-late-negotiation = true*
**-codec-prefs= G729, PCMA*

FS logfile presents an error (loglevel: INFO, privacy data screened with *):

922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:27:59.997037 [NOTICE]
switch_channel.c:1104 New Channel sofia/external/********@******.net
[922bb07e-8dce-4416-9073-52db21a8a432]
922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:27:59.997037 [INFO]
mod_dialplan_xml.c:637 Processing ******* <*******>->************ in
context public
922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:28:00.037033 [NOTICE]
switch_ivr.c:2172 Transfer sofia/external/ ********@******.net to XML[6000@
************]
922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:28:00.037033 [INFO]
mod_dialplan_xml.c:637 Processing  ******** < ******** >->6000 in context
************
[...]
fb16ac80-17f5-451b-a8ee-d22a135afc51 2019-05-09 17:28:00.197034 [NOTICE]
switch_channel.c:1104 New Channel sofia/internal-bs/6000 at 192.168.50.119:5064
[fb16ac80-17f5-451b-a8ee-d22a135afc51]
[...]
2019-05-09 17:28:00.277039 [INFO] sofia.c:1279 sofia/internal-bs/
6000 at 192.168.50.119:5064 Update Callee ID to "6000 6000" <6000>
fb16ac80-17f5-451b-a8ee-d22a135afc51 2019-05-09 17:28:00.277039 [NOTICE]
sofia.c:7156 Ring-Ready sofia/internal-bs/6000 at 192.168.50.119:5064!
922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:28:00.277039 [INFO]
switch_ivr_originate.c:1215 Sending early media
922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:28:00.277039 [NOTICE]
sofia_media.c:92 Pre-Answer sofia/external/********@******.net!
[...]
fb16ac80-17f5-451b-a8ee-d22a135afc51 2019-05-09 17:28:03.497034 [NOTICE]
sofia.c:8167 Channel [sofia/internal-bs/6000 at 192.168.50.119:5064] has been
answered
922bb07e-8dce-4416-9073-52db21a8a432 2019-05-09 17:28:03.497034 [NOTICE]
switch_ivr_originate.c:3632 Channel [sofia/external/********@******.net]
has been answered
fb16ac80-17f5-451b-a8ee-d22a135afc51 2019-05-09 17:28:03.577036 [ERR]
sofia.c:8020 Codec Error! v=0
fb16ac80-17f5-451b-a8ee-d22a135afc51 o=- 1027803 1027804 IN IP4
192.168.50.119
fb16ac80-17f5-451b-a8ee-d22a135afc51 s=-
fb16ac80-17f5-451b-a8ee-d22a135afc51 c=IN IP4 192.168.50.119
fb16ac80-17f5-451b-a8ee-d22a135afc51 t=0 0
fb16ac80-17f5-451b-a8ee-d22a135afc51 m=audio 25546 RTP/AVP 18 101
fb16ac80-17f5-451b-a8ee-d22a135afc51 a=rtpmap:18 G729/8000
fb16ac80-17f5-451b-a8ee-d22a135afc51 a=fmtp:18 annexb=no
fb16ac80-17f5-451b-a8ee-d22a135afc51 a=rtpmap:101 telephone-event/8000
fb16ac80-17f5-451b-a8ee-d22a135afc51 a=fmtp:101 0-15
fb16ac80-17f5-451b-a8ee-d22a135afc51 a=ptime:20
fb16ac80-17f5-451b-a8ee-d22a135afc51

Matching packets time and logfile time, the "sofia.c:8020 Codec Error!"
matches the sip phone 200OK answer to the UPDATE message.
I tried to navigate the sofia.c code but i can't actually figure out what's
happening.

Please note that on a FS 1.4.9 setup (with a, i would say, "identical"
configuration) this works, i.e. a bidirectional g729 stream is estabilished
on the FS<->phone leg, also with identical signalling.
I am wondering if there is any config parameter that should be
edited/added/removed on the 1.6.x compared to the 1.4.x configuration.
Btw, G729 commercial codec is active and running on both systems.

Any hint is appreciated and, if needed i can post more data/log/tests.

Thanks in advance.
SB
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20190514/7d726cc1/attachment-0001.html>