[Freeswitch-users] ESL Reporting of RTCP / Jitter is incorrect... does not match RTP originally reported

[David S. Dee]

Hello again...

Just to cover myself, I recompiled freeswitch from the ground up, with a fresh clone of the git repository for the v1.4 branch... hoping that maybe there was something that did not get recompiled correctly, but I am still seeing these same issues when accessing the RTCP data via a Perl event client.  I moved a greatly-minimized version of the event client to the actually Voip machine itself in an attempt to eliminate any network byte ordering issues, but that did not help either.  I still suspect it is a byte-alignment or storage sizing discrepancy that is happening between the switch_rtp.c module and when it gets received on the client side by the ESL module, but I can't prove it.

Any chance that I can get some attention from someone more knowledgeable on this aspect of Freeswitch that I can troubleshoot this with, and possibly figure out the code fixes that need to happen?

Thanks,
David




On Wed, Sep 23, 2015, at 09:40, David S. Dee wrote:
> 
> I am trying to do some external actions based on the RTCP reporting of Jitter that comes in.
> 
> My problem is that the numbers that show up in the freeswitch logs no longer match what gets reported via Event'ing
> 
> eg, the freeswitch logs show:
> 
> 
> 2015-09-23 08:22:24.221437 [NOTICE] switch_rtp.c:5206 Receiving an RTCP packet[2015-23-08 14:22:24.241238] SSRC[626145724]RTT[0.092102] A[874528193] - DLSR[38600] - LSR[874483557]
> 2015-09-23 08:22:29.622369 [NOTICE] switch_rtp.c:5206 Receiving an RTCP packet[2015-23-08 14:22:29.640323] SSRC[626145724]RTT[0.106003] A[874882028] - DLSR[63832] - LSR[874811249]
> 2015-09-23 08:22:35.041676 [NOTICE] switch_rtp.c:5206 Receiving an RTCP packet[2015-23-08 14:22:35.60396] SSRC[626145724]RTT[0.142044] A[875237238] - DLSR[88997] - LSR[875138932]
> 2015-09-23 08:22:40.461243 [NOTICE] switch_rtp.c:5206 Receiving an RTCP packet[2015-23-08 14:22:40.480321] SSRC[626145724]RTT[0.181702] A[875592438] - DLSR[113836] - LSR[875466694]
> 2015-09-23 08:22:45.882464 [NOTICE] switch_rtp.c:5206 Receiving an RTCP packet[2015-23-08 14:22:45.900353] SSRC[626145724]RTT[0.215042] A[875947645] - DLSR[139264] - LSR[875794288]
> 2015-09-23 08:22:51.301265 [NOTICE] switch_rtp.c:5206 Receiving an RTCP packet[2015-23-08 14:22:51.320380] SSRC[626145724]RTT[0.249069] A[876302852] - DLSR[164560] - LSR[876121969]
> 
> And the (short form) of what I receive via the ESL are:
> 
> 
> 
> Sep 23 09:33:55:       RTCP message not sent, too soon: SSRC: 255239bc, RTP-Timestamp: 0, Sender-Packet-Count: 0, Octect-Packet-Count: 874483557, Last-RTP-Timestamp: 2018933311, RTP-Rate: 8000, Capture-Time: 1443018144241365, Source0-Fraction: 129, Source0-Lost: 3388998144, Source0-Highest-Sequence-Number-Received: 626145724, Source0-Jitter: 16777216, Source0-LSR: 788957780, Source0-DLSR: 17891
> Sep 23 09:34:00:       RTCP message not sent, too soon: SSRC: 255239bc, RTP-Timestamp: 0, Sender-Packet-Count: 0, Octect-Packet-Count: 874811249, Last-RTP-Timestamp: 2018973151, RTP-Rate: 8000, Capture-Time: 1443018149640379, Source0-Fraction: 129, Source0-Lost: 3388998144, Source0-Highest-Sequence-Number-Received: 626145724, Source0-Jitter: 16777216, Source0-LSR: 788957780, Source0-DLSR: 17891
> Sep 23 09:34:05:       RTCP message not sent, too soon: SSRC: 255239bc, RTP-Timestamp: 0, Sender-Packet-Count: 0, Octect-Packet-Count: 875138932, Last-RTP-Timestamp: 2019013151, RTP-Rate: 8000, Capture-Time: 1443018155060479, Source0-Fraction: 129, Source0-Lost: 3388998144, Source0-Highest-Sequence-Number-Received: 626145724, Source0-Jitter: 16777216, Source0-LSR: 788957780, Source0-DLSR: 17891
> Sep 23 09:34:15:       RTCP message not sent, too soon: SSRC: 255239bc, RTP-Timestamp: 0, Sender-Packet-Count: 0, Octect-Packet-Count: 875794288, Last-RTP-Timestamp: 2019093311, RTP-Rate: 8000, Capture-Time: 1443018165900409, Source0-Fraction: 129, Source0-Lost: 3388998144, Source0-Highest-Sequence-Number-Received: 626145724, Source0-Jitter: 16777216, Source0-LSR: 788957780, Source0-DLSR: 17891
> Sep 23 09:34:20:       RTCP message not sent, too soon: SSRC: 255239bc, RTP-Timestamp: 0, Sender-Packet-Count: 0, Octect-Packet-Count: 876121969, Last-RTP-Timestamp: 2019133311, RTP-Rate: 8000, Capture-Time: 1443018171320579, Source0-Fraction: 129, Source0-Lost: 3388998144, Source0-Highest-Sequence-Number-Received: 626145724, Source0-Jitter: 16777216, Source0-LSR: 788957780, Source0-DLSR: 17891  
> 
> (yes, the timestamps are off right now, that's actually fine).
> 
> This used to work in an older version of Freeswitch, but when I rebuilt my system with an updated FS version last month, this broke.
> 
> You'll note that the Sender-Packet-Count is (obviously) wrong, as well as the RTP-Timestamp, and the DLSR and LSR... none of them advance, while you can see them advancing in the freeswitch log.
> 
> I suspect it is alignment of the values in the structure that gets populated for the ESL, but my C is rusty enough that I can't trace it anymore.
> 
> Is anyone else able to view the Event data for RTCP packets?
> 
> Thanks,
> David
> 
> _________________________________________________________________________
> Professional FreeSWITCH Consulting Services: 
> consulting at freeswitch.org
> http://www.freeswitchsolutions.com
> 
> Official FreeSWITCH Sites
> http://www.freeswitch.org
> http://confluence.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