Debugging help - Inbound audio randomly scrambles and disappears

Hello Everyone,

Out of nothing some users started to have random issues in the middle of a call, not hearing the external party on a landline. The recording shows that both channels are reaching PBX fine, as we can hear both speaking, but when the problem starts the inbound audio does not reach the internal SIP user correctly.

As the audio scrambles it seems that the packets get out of order on the user side, and start to fill up a buffer until the inbound buffer is exhausted and simply stops, so we do not get any audio in. The external continues hearing the user just fine. In the recording we hear the user saying “hello, hello, can you hear me” and the external party replying “yes, yes I can hear you fine”.

#User setup
Dell notebook - 100mbps network adapter
Softphone - linphone 4.1.1

#PBX setup
LAN <-> Freepbx 13 (Digium TE235 -2) <-> E1

#Network setup
Freepbx <-(1gbps)-> TPLINK T1600G-28TS <-(1gbps)-> NETGEAR GS108Ev3 <-(100mbps)-> User

I have enabled QoS (Diffserv) and I see it in effect when sniffing packets.
Also I enabled Jitter Buffer in Freepbx.

Can this be caused by the different link speeds between the Freepbx and the User?
How can I debug this issue to funnel down the problems?

Any clue, tip is well appreciated.

Thank you,
Aleks

Do you have 10000-20000 fwded to the PBX?

Server and client are in the LAN. No routing / firewall involved.
Freepbx 192.168.1.50
User: 192.168.1.xxx

Do you have a SIP Trunk connecting to outside of your network ?

No it is an E1. Sip runs only internally.

Then I doubt that your jitter buffer is helping you. it is in a fact a buffer that can ‘fill-up’

You are right!

This is happening so randomly, some times only once in a day other days does not happen at all. It has been hard to diagnose and isolate the problem.

I will look into the network adapter and enable linphone’s log. Let’s see…

From the asterisk CLI

rtp set debug ip (suspect host)

you will see any out of order or delayed rtp packets , I suggest you install sngrep and RTFM for it :slight_smile:

As in the server the recording does not present the problem, I thought that I would not see delayed packets when running “rtp set debug ip”. And I understood that the ordering problem was happening exclusively on the user’s side.

Anyways, I am going to check sngrep and RTFM! :wink: Thanks for the tip, very well appreciated!

I do not know if this is helpful but looking in linphone’s log, I see a bunch of these messages during the call were we had the problem.

2018-08-10 10:39:04:497 WARNING Not enough ref samples, using zeroes
2018-08-10 10:39:04:507 WARNING Too many samples to drop, dropping entire frame.
2018-08-10 10:39:04:528 MESSAGE Samples are back.

And at end of the call the stats show…

2018-08-10 10:43:06:781 MESSAGE MSQualityIndicator[0CC22050][audio], remote statistics available:
Loss rate : 0.0%
Inter-arrival jitter: 1.0ms
RT propagation : 5.0ms

and final stats.

2018-08-10 10:43:10:057 MESSAGE ===========================================================
2018-08-10 10:43:10:057 MESSAGE AUDIO SESSION’S RTP STATISTICS
2018-08-10 10:43:10:057 MESSAGE -----------------------------------------------------------
2018-08-10 10:43:10:057 MESSAGE sent 50907 packets
2018-08-10 10:43:10:057 MESSAGE 0 duplicated packets
2018-08-10 10:43:10:057 MESSAGE 8756004 bytes
2018-08-10 10:43:10:057 MESSAGE received 50914 packets
2018-08-10 10:43:10:057 MESSAGE 0 duplicated packets
2018-08-10 10:43:10:057 MESSAGE 8757208 bytes
2018-08-10 10:43:10:057 MESSAGE incoming delivered to the app 8754972 bytes
2018-08-10 10:43:10:058 MESSAGE incoming cumulative lost 1 packets
2018-08-10 10:43:10:058 MESSAGE incoming received too late 1 packets
2018-08-10 10:43:10:058 MESSAGE incoming bad formatted 0 packets
2018-08-10 10:43:10:058 MESSAGE incoming discarded (queue overflow) 0 packets
2018-08-10 10:43:10:058 MESSAGE sent rtcp 193 packets
2018-08-10 10:43:10:058 MESSAGE received rtcp 203 packets
2018-08-10 10:43:10:058 MESSAGE ===========================================================

2018-08-10 10:43:10:058 MESSAGE ===========================================================
2018-08-10 10:43:10:058 MESSAGE FILTER USAGE STATISTICS
2018-08-10 10:43:10:058 MESSAGE Name Count Time/tick (ms) CPU Usage
2018-08-10 10:43:10:059 MESSAGE -----------------------------------------------------------
2018-08-10 10:43:10:059 MESSAGE MSWebRTCAEC 101690 0.128861 33.2918
2018-08-10 10:43:10:059 MESSAGE MSRtpSend 101816 0.105994 27.418
2018-08-10 10:43:10:059 MESSAGE MSResample 203384 0.0319738 16.5214
2018-08-10 10:43:10:059 MESSAGE MSAudioFlowControl 50908 0.0431358 5.57913
2018-08-10 10:43:10:059 MESSAGE MSRtpRecv 102795 0.0188042 4.91095
2018-08-10 10:43:10:059 MESSAGE MSAudioMixer 305448 0.00371584 2.88356
2018-08-10 10:43:10:059 MESSAGE MSWASAPIWrite 101645 0.00673907 1.7403
2018-08-10 10:43:10:059 MESSAGE MSDtmfGen 203637 0.0029906 1.54722
2018-08-10 10:43:10:059 MESSAGE MSAlawEnc 101640 0.00484057 1.24997
2018-08-10 10:43:10:059 MESSAGE MSWASAPIRead 101816 0.00467505 1.20932
2018-08-10 10:43:10:059 MESSAGE MSVolume 137586 0.00309622 1.08229
2018-08-10 10:43:10:059 MESSAGE MSItcSource 101816 0.00338843 0.876502
2018-08-10 10:43:10:059 MESSAGE MSGenericPLC 101816 0.00211163 0.546226
2018-08-10 10:43:10:059 MESSAGE MSFilePlayer 101821 0.00172851 0.447143
2018-08-10 10:43:10:059 MESSAGE MSAlawDec 50901 0.00326117 0.421737
2018-08-10 10:43:10:059 MESSAGE MSTee 35946 0.00169694 0.154976
2018-08-10 10:43:10:059 MESSAGE MSEqualizer 137586 0.000218044 0.0762176
2018-08-10 10:43:10:059 MESSAGE MSOpusEnc 99 0.17 0.04319
2018-08-10 10:43:10:059 MESSAGE MSMKVRecorder 49 0 0
2018-08-10 10:43:10:059 MESSAGE MSFileRec 99 0 0
2018-08-10 10:43:10:059 MESSAGE MSVoidSink 0 0 0
2018-08-10 10:43:10:059 MESSAGE MSItcSink 0 0 0
2018-08-10 10:43:10:059 MESSAGE ===========================================================
2018-08-10 10:43:10:061 MESSAGE MKVRecorder: destroyed
2018-08-10 10:43:10:061 MESSAGE ===========================================================
2018-08-10 10:43:10:061 MESSAGE FILTER USAGE STATISTICS
2018-08-10 10:43:10:061 MESSAGE Name Count Time/tick (ms) CPU Usage
2018-08-10 10:43:10:061 MESSAGE -----------------------------------------------------------
2018-08-10 10:43:10:061 MESSAGE MSWebRTCAEC 101690 0.128861 33.2918
2018-08-10 10:43:10:062 MESSAGE MSRtpSend 101816 0.105994 27.418
2018-08-10 10:43:10:062 MESSAGE MSResample 203384 0.0319738 16.5214
2018-08-10 10:43:10:062 MESSAGE MSAudioFlowControl 50908 0.0431358 5.57913
2018-08-10 10:43:10:062 MESSAGE MSRtpRecv 102795 0.0188042 4.91095
2018-08-10 10:43:10:062 MESSAGE MSAudioMixer 305448 0.00371584 2.88356
2018-08-10 10:43:10:062 MESSAGE MSWASAPIWrite 101645 0.00673907 1.7403
2018-08-10 10:43:10:062 MESSAGE MSDtmfGen 203637 0.0029906 1.54722
2018-08-10 10:43:10:062 MESSAGE MSAlawEnc 101640 0.00484057 1.24997
2018-08-10 10:43:10:062 MESSAGE MSWASAPIRead 101816 0.00467505 1.20932
2018-08-10 10:43:10:062 MESSAGE MSVolume 137586 0.00309622 1.08229
2018-08-10 10:43:10:062 MESSAGE MSItcSource 101816 0.00338843 0.876502
2018-08-10 10:43:10:062 MESSAGE MSGenericPLC 101816 0.00211163 0.546226
2018-08-10 10:43:10:062 MESSAGE MSFilePlayer 101821 0.00172851 0.447143
2018-08-10 10:43:10:062 MESSAGE MSAlawDec 50901 0.00326117 0.421737
2018-08-10 10:43:10:062 MESSAGE MSTee 35946 0.00169694 0.154976
2018-08-10 10:43:10:062 MESSAGE MSEqualizer 137586 0.000218044 0.0762176
2018-08-10 10:43:10:062 MESSAGE MSOpusEnc 99 0.17 0.04319
2018-08-10 10:43:10:062 MESSAGE MSMKVRecorder 49 0 0
2018-08-10 10:43:10:062 MESSAGE MSFileRec 99 0 0
2018-08-10 10:43:10:062 MESSAGE MSVoidSink 0 0 0
2018-08-10 10:43:10:062 MESSAGE MSItcSink 0 0 0
2018-08-10 10:43:10:062 MESSAGE ===========================================================

Purely and simply, your PBX is losing touch with your Linphone somehow. That’s what the “WARNING Not enough ref samples, using zeroes” is trying to tell you per https://lists.nongnu.org/archive/html/linphone-developers/2011-05/msg00045.html

Since your call stats show 0.0% loss, I’d start with the Linphone itself. Is there any substitute (e.g. Zoiper, but I’m not recommending them) you can use instead, just for testing?

Thank you for the clarification on Linphone’s error message!

I made two changes and so far did not have problems yet.
1- Manually set Network Adapter to 100mbits Full Duplex instead of Auto-negotiate
2- In Linphone I disabled “Adaptive rate control”, as there should be plenty bandwidth in my LAN for it, specially with Diffserv enabled with Strict Priority.

I have the logs on to help debugging.
If the problem comes up again I will try Microsip as a softphone to continue the debugging process.

Thanks again for the tip! :wink:

Just to close this issue.

I might have had some network issues but if they were there they were gone with the enabling of Diffserv Strict Priority.

It seems that the root problem was being caused by Linphone itself. I noticed in the logs that although I was using only my SIP account of my own Freepbx server in my own LAN, it was registering itself to external Linphone’s SIP servers and establishing a STUN. Out of the blue it seemed to get lost.

After I’ve blocked Linphone’s addresses in my firewall the problem has never happened again.

Thanks for all the help from the community! :wink:

This topic was automatically closed 365 days after the last reply. New replies are no longer allowed.