[Freeswitch-users] FreeSWITCH 1.8.2 - 1-2 second dropped Audio\RTP at the start of a call

Wed Dec 19 14:07:18 UTC 2018

Thank you all for your recommendations. We raised a JIRA but it was closed as incomplete, we will look at re-opening once we've compiled the relevant logs and pcaps etc unless we reach a conclusion before hand.

Some additional points:

- We do not set "answer_delay".

- There is still a 1-2 second delay after setting "disable_rtp_auto_adjust" on the SIP profile.

We've identified this as a package issue, when FreeSWITCH is built with certain packages installed this is causing mod_sofia.so to be much smaller than it should be (5.49MB instead of 8.58MB).

We're able to consistently reproduce the following when running FreeSWITCH on the same Debian 9 server using the same FreeSWITCH configuration and scripts etc:

- FreeSWITCH 1.8.2 built on Debian 9 - 1-2 second audio\RTP delay on answer

- FreeSWITCH 1.6.20 built on Debian 9 - 1-2 second audio\RTP delay on answer

- FreeSWITCH 1.6.20 built on Debian 8 (moved binaries to Debian 9 server) - No audio\RTP delay on answer (audio\RTP is instantaneous)

- FreeSWITCH 1.8.2 built on Debian 9 base (no additional packages) - No audio\RTP delay on answer (audio\RTP is instantaneous)

Will post back once we've identified the root cause.

Thanks,

Shaun

________________________________
From: FreeSWITCH-users <freeswitch-users-bounces at lists.freeswitch.org> on behalf of Anthony Minessale <anthony.minessale at gmail.com>
Sent: 17 December 2018 20:55
To: FreeSWITCH Users Help
Subject: Re: [Freeswitch-users] FreeSWITCH 1.8.2 - 1-2 second dropped Audio\RTP at the start of a call

Sounds like a broken record but the mailing list is not the best place to report issues.  Almost inevitably, questions will be asked and data will need to be collected like logs etc.
This is why we already point to JIRA to file tickets.

Recommendations:

1) Make sure you don't have "answer_delay" set.
2) Check the media signaling data to make sure you are not using "rtp-auto-adjust which adds a time to media establishment to correct for incorrect media IPs.
3) Get a pcap as well as debug + sip trace before reporting any issue because its always going to be the first request anyway.
4) Use JIRA, feel free to ask about the JIRA here but don't rely on 1990's listserv server to track the issue progress.

sofia global siptrace on
console loglevel debug
fsctl debug_level 10

On Mon, Dec 17, 2018 at 2:48 PM Shaun Stokes <shaun.stokes at itec-support.co.uk<mailto:shaun.stokes at itec-support.co.uk>> wrote:

We reverted back to FreeSWITCH 1.6.20 but when this is compiled on the Debian 9 server the problem still occurs.

We had to workaround some build errors for FS 1.6.20 to compile on Debian 9 with PostgreSQL 11 but the problem was still present, as follows.

--------------------

# Uninstall 1.1.0 SSL header files (libssl-dev) and install the older ones (libssl1.0-dev).
apt-get install libssl1.0-dev

# Fix PGSQL 11 Support
In the file:
/usr/src/freeswitch/srcswitch_pgsql.c
On line 389, replace this:
#if POSTGRESQL_MAJOR_VERSION >= 9 && POSTGRESQL_MINOR_VERSION >= 2
With:
#if (POSTGRESQL_MAJOR_VERSION == 9 && POSTGRESQL_MINOR_VERSION >= 2) || POSTGRESQL_MAJOR_VERSION > 9

# Do not build mod_flite or mod_enum
sed -i /usr/src/freeswitch/modules.conf -e s:'asr_tts/mod_flite:#asr_tts/mod_flite:'
sed -i /usr/src/freeswitch/modules.conf -e s:'applications/mod_enum:#applications/mod_enum:'
--------------------

We took the FS 1.6.20 binaries (pre-compiled) from a Debian 8 server and restored them to our Debian 9 server which resolved the issue but we had to copy some missing libs from a Debian 8 server:
/usr/lib/x86_64-linux-gnu/libssl.so.1.0.0
/usr/lib/x86_64-linux-gnu/libcrypto.so.1.0.0

Given that the problem changes when the source-code is compiled on different servers we suspect this may be a package problem not specific to FreeSWITCH.

This is also a problem on master, raised JIRA: https://freeswitch.org/jira/browse/FS-11572

________________________________
From: FreeSWITCH-users <freeswitch-users-bounces at lists.freeswitch.org<mailto:freeswitch-users-bounces at lists.freeswitch.org>> on behalf of Shaun Stokes <shaun.stokes at itec-support.co.uk<mailto:shaun.stokes at itec-support.co.uk>>
Sent: 14 December 2018 13:16:14
To: FreeSWITCH Users Help
Subject: Re: [Freeswitch-users] FreeSWITCH 1.8.2 - 1-2 second dropped Audio\RTP at the start of a call

Correction, we had moved FreeSWITCH 1.4 (not 1.8) to Server 1 which worked without any audio delays. Upon testing FreeSWITCH 1.8 on Server 1 there is a 1-2 second delay before RTP is established once the call is answered.

This is a FreeSWITCH 1.8.2 issue, not a Debian 9 specific (also occurs on Debian 8). FreeSWITCH 1.6 and 1.4 are not effected using the same configuration through-out.
________________________________
From: Shaun Stokes
Sent: 14 December 2018 11:44:18
To: FreeSWITCH Users Help
Subject: Re: [Freeswitch-users] FreeSWITCH 1.8.2 - 1-2 second dropped Audio\RTP at the start of a call

We have built two test servers side by side on the same hardware with the same configuration, as follows.
Server 1: Debian 8 with FreeSWITCH 1.6.20
Server 2: Debian 9 with FreeSWITCH 1.8.2

We can replicate the 1-2 second delay on Server 2 only, whereas Server 1 provides near instant RTP in both directions upon answer. Interestingly, if we move FreeSWITCH 1.8.2 from Server 2 to Server 1 there are still no issues with delay on Server 1, the problem is only observable on the Server 2 running Debian 9 so the problem is not specifically related to FreeSWITCH 1.8.2.

At this stage it seems likely the issue lies with Debian 9 or the change in packages on Debian 9.

Thanks,
Shaun
________________________________
From: FreeSWITCH-users <freeswitch-users-bounces at lists.freeswitch.org<mailto:freeswitch-users-bounces at lists.freeswitch.org>> on behalf of Shaun Stokes <shaun.stokes at itec-support.co.uk<mailto:shaun.stokes at itec-support.co.uk>>
Sent: 11 December 2018 15:28:33
To: FreeSWITCH Users Help
Subject: [Freeswitch-users] FreeSWITCH 1.8.2 - 1-2 second dropped Audio\RTP at the start of a call

Hi All,

Since we've been using FreeSWITCH 1.8.2 we've noticed that the first 1-2 seconds of Audio\RTP at the start of the call when the call is answered is now dropped\missing but this doesn't occur on 1.6.20. When comparing the examples we've noticed the call flow is slightly different, as follows.

FreeSWITCH 1.8.2

Leg A: switch_channel.c:2249 (sofia/internal/SRC_EXT at DOMAIN:PORT) Callstate Change DOWN -> RINGING
Leg B: sofia.c:7291 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [calling][0]
Leg B: sofia.c:7291 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [proceeding][180]
Leg B: sofia.c:7401 Ring-Ready sofia/internal/DST_EXT at LAN_IP:PORT!
Leg B: switch_channel.c:3354 (sofia/internal/DST_EXT at LAN_IP:PORT) Callstate Change DOWN -> RINGING
Leg A: switch_ivr_originate.c:1246 Sending early media
Leg A: switch_channel.c:3482 (sofia/internal/SRC_EXT at DOMAIN:PORT) Callstate Change RINGING -> EARLY
Leg A: sofia.c:7291 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [early][183]
Leg B: sofia.c:7291 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [completing][200]
Leg B: switch_channel.c:3482 (sofia/internal/DST_EXT at LAN_IP:PORT) Callstate Change RINGING -> EARLY
Leg B: sofia.c:7291 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [ready][200]
Leg B: sofia.c:8429 Channel [sofia/internal/DST_EXT at LAN_IP:PORT] has been answered
Leg B: switch_channel.c:3781 (sofia/internal/DST_EXT at LAN_IP:PORT) Callstate Change EARLY -> ACTIVE
Leg A: switch_ivr_bridge.c:766 Channel [sofia/internal/SRC_EXT at DOMAIN:PORT] has been answered
Leg A: sofia.c:7291 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [completed][200]
Leg A: switch_channel.c:3781 (sofia/internal/SRC_EXT at DOMAIN:PORT) Callstate Change EARLY -> ACTIVE
Leg A: sofia.c:7291 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [ready][200]
Leg A: switch_ivr_async.c:1500 No silence detection configured; assuming start of speech
Leg B: sofia.c:7291 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [calling][0]
Leg A: sofia.c:7291 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [calling][0]
Leg A: sofia.c:7291 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [ready][200]
Leg A: sofia.c:8272 Processing updated SDP
Leg B: sofia.c:7291 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [ready][200]

FreeSWITCH 1.6.20

Leg A: switch_channel.c:2249 (sofia/internal/SRC_EXT at DOMAIN:PORT) Callstate Change DOWN -> RINGING
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [calling][0]
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [proceeding][180]
Leg B: sofia.c:7192 Ring-Ready sofia/internal/DST_EXT at LAN_IP:PORT!
Leg B: switch_channel.c:3346 (sofia/internal/DST_EXT at LAN_IP:PORT) Callstate Change DOWN -> RINGING
Leg A: switch_ivr_originate.c:1215 Sending early media
Leg A: switch_channel.c:3474 (sofia/internal/SRC_EXT at DOMAIN:PORT) Callstate Change RINGING -> EARLY
Leg A: sofia.c:7084 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [early][183]
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [completing][200]
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [ready][200]
Leg A: switch_channel.c:3773 (sofia/internal/SRC_EXT at DOMAIN:PORT) Callstate Change EARLY -> ACTIVE
Leg A: sofia.c:7084 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [completed][200]
Leg A: switch_ivr_originate.c:3705 Originate Resulted in Success: [sofia/internal/DST_EXT at LAN_IP:PORT]
Leg B: switch_channel.c:3773 (sofia/internal/DST_EXT at LAN_IP:PORT) Callstate Change RINGING -> ACTIVE
Leg A: sofia.c:7084 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [ready][200]
Leg B: Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [ready][200]
Leg A: switch_ivr_async.c:1500 No silence detection configured; assuming start of speech
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [calling][0]
Leg A: sofia.c:7084 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [calling][0]
Leg A: sofia.c:7084 Channel sofia/internal/SRC_EXT at DOMAIN:PORT entering state [ready][200]
Leg A: sofia.c:8061 Processing updated SDP
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [completing][200]
Leg B: sofia.c:7084 Channel sofia/internal/DST_EXT at LAN_IP:PORT entering state [ready][200]

On 1.6.20 Leg B changes straight from RINGING to ACTIVE, but on 1.8.2 Leg B first changes from RINGING to EARLY then EARLY to ACTIVE, not sure if this could be related.

We've experimented with the following to no avail.
rtp-rewrite-timestamps
send_silence_when_idle
fsctl sync_clock
suppress_cng
ignore_early_media

As per:
https://freeswitch.org/confluence/display/FREESWITCH/RTP+Issues
https://freeswitch.org/confluence/display/FREESWITCH/VAD+and+CNG
https://freeswitch.org/confluence/display/FREESWITCH/send_silence_when_idle
https://freeswitch.org/confluence/display/FREESWITCH/Early+Media

The calls are local between two extensions\endpoints on the same FreeSWITCH instance and the same SIP profile, the SIP profiles on both servers (1.6.20 and 1.8.2) are identical.

Does anyone have any ideas?

Thanks,

Shaun

_________________________________________________________________________
Professional FreeSWITCH Services
sales at freeswitch.com<mailto:sales at freeswitch.com>
https://freeswitch.com

Official FreeSWITCH Sites
https://freeswitch.com/oss
https://freeswitch.org/confluence
https://cluecon.com

FreeSWITCH-users mailing list
FreeSWITCH-users at lists.freeswitch.org<mailto:FreeSWITCH-users at lists.freeswitch.org>
http://lists.freeswitch.org/mailman/listinfo/freeswitch-users
UNSUBSCRIBE:http://lists.freeswitch.org/mailman/options/freeswitch-users
https://freeswitch.com

--
Anthony Minessale II
Founder, FreeSWITCH.
http://freeswitch.com

https://youtu.be/l_hOxzCt6X4
https://www.youtube.com/watch?v=oAxXgyx5jUw
https://www.youtube.com/watch?v=9XXgW34t40s
https://www.youtube.com/watch?v=NLaDpGQuZDA
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.freeswitch.org/pipermail/freeswitch-users/attachments/20181219/3079e65f/attachment-0001.html>