RTCP Reporting is broken

[greenfieldtech-nirs]

When using rtpengine with Homer server, it would seem that the RTCP inforation that is reported to Homer is broken. It would seem that the data reported is extremely large:

HEP3.f....................Q.......uE.....
W.qm...
.
................
.........
.5.......
C........&kxz7Wr15JJgA2AleTu6GvgLrjKynfRiq......{ "sender_information":{"ntp_timestamp_sec":2518786835,"ntp_timestamp_usec":3517447210,"octets":2584999171,"rtp_timestamp":426469031, "packets":2131419229},"ssrc":145716936,"type":200,"report_count":0,"report_blocks":[] }

U 67.205.xxx.xxx:40225 -> 178.62.xxx.xxx:9060
HEP3.5....................Q.......uE.....
W.qq...
.
..j.............
.........
.5.......
C........&kxz7Wr15JJgA2AleTu6GvgLrjKynfRiq......{ "sender_information":{"ntp_timestamp_sec":1433487491,"ntp_timestamp_usec":2481675417,"octets":829904220,"rtp_timestamp":4178015919, "packets":3715692798},"ssrc":145716936,"type":200,"report_count":3,"report_blocks":[{"source_ssrc":2838416413,"highest_seq_no":3177617446,"fraction_lost":208,"ia_jitter":3815682506,"packets_lost":8293549,"lsr":833282032,"dlsr":3434899853},{"source_ssrc":3391378510,"highest_seq_no":2438169395,"fraction_lost":144,"ia_jitter":830420724,"packets_lost":442289,"lsr":2855965574,"dlsr":3694041804},{"source_ssrc":1436940625,"highest_seq_no":2950619174,"fraction_lost":82,"ia_jitter":2639531911,"packets_lost":10331871,"lsr":1510372329,"dlsr":330736554}] }

As you can see from the above, the number are totally wacked for some reason. I'm using rtpengine on a Virtual Server in Digital Ocean, using CentOS 6 - 64Bit. I've tried various versions of rtpengine, all exhibited the same behaviour.

[rfuchs]

duplicate

[greenfieldtech-nirs]

Which is the duplicate ?

[greenfieldtech-nirs]

Oops

[vtzan]

Dear Team,

I have the same problem too. I am using rtpengine 5.4.0.0+0~mr5.4.0.0 Here is the data sent by rtpengine to homer ---> https://pastebin.com/TNTctVxD

as you can see the data below are not valid.

{"ntp_timestamp_sec":2, {"ntp_timestamp_sec":7 {"ntp_timestamp_sec":12,

lsb_release -a Distributor ID: Debian Description: Debian GNU/Linux 8.8 (jessie) Release: 8.8 Codename: jessie

NTP Service is running.

maybe some recent change on https://github.com/sipwise/rtpengine/commits/master/daemon/homer.c created that issue? I will try an older version to verify.

thank you in advance

[rfuchs]

The correct ticket for this issue is #282

[rfuchs]

Also, make sure your build includes commit a9d55c6fe71fb1be654b863f2243969ecae9684d as this might be a possible fix. (5.4.0.0+0~mr5.4.0.0 isn't really a version)

[vtzan]

Hi, Yes this version has this commit.

Same problem exists on latest master branch 5.5.0.0+0~mr5.5.0.0

ngrep :

..8......Aisbc03f7e4fmedg0m67edi76ef04d87e71g3@B.11.324.hostname.tld......{ "sender_information":{"ntp_timestamp_sec":4,"ntp_timestamp_usec":2362179584,"octets":36320,"rtp_timestamp":4060015024, "packets":227},"ssrc":1654711379,"type":200,"report_count":1,"report_blocks":[{"source_ssrc":55545992,"highest_seq_no":52560,"fraction_lost":0,"ia_jitter":1,"packets_lost":0,"lsr":0,"dlsr":0}],"sdes_report_count":1,"sdes_information": [ {"sdes_chunk_ssrc":1654711379,"type":1,"text":"7305@..*.142..."}] }

I have seen the same behavior on the following ones:

5.5.0.0+0~mr5.5.0.0 5.3.1.1+0~mr5.3.1.1 5.2.2.1+0~mr5.2.2.1 4.5.5.1+0~mr4.5.5.1

Am I doing something wrong?

[rfuchs]

Hard to say without seeing the actual RTCP packet in question. Do you have an appropriate pcap?

[vtzan]

sure, can I send it to you in private via email?

[rfuchs]

Sure, my address is in my profile

[rfuchs]

For posterity, from a private email exchage:

OK, so if you open this file in Wireshark and look at a random RTCP packet, say packet #287. The matching data sent to Homer can be seen in the following packet, #288. It says:

{ "sender_information":{"ntp_timestamp_sec":0,"ntp_timestamp_usec":644218880, ...

I assume the complaint is that the reported NTP timestamp is zero?

But if you look at the actual RTCP packet (#287) which triggered this Homer report, it contains:

Frame 287: 176 bytes on wire (1408 bits), 176 bytes captured (1408 bits) on interface 0
...
Real-time Transport Control Protocol (Sender Report)
...
    Timestamp, MSW: 0 (0x00000000)
    Timestamp, LSW: 644218880 (0x26660000)
    [MSW and LSW as NTP timestamp: Jan  1, 1970 00:00:00.149993000 UTC]
...

So this is actually what it says in the RTCP packet. Obviously rtpengine has no way of reporting anything else here.

Another example is RTCP packet #1359 and Homer packet #1360.

RTCP says:

Real-time Transport Control Protocol (Sender Report)
...
    Timestamp, MSW: 4 (0x00000004)
    Timestamp, LSW: 4080205824 (0xf3330000)
    [MSW and LSW as NTP timestamp: Feb  7, 2036 06:28:20.949996000 UTC]

And the packet sent to Homer contains:

{ "sender_information":{"ntp_timestamp_sec":4,"ntp_timestamp_usec":4080205824, ...

Again, that is correct. The UA sending these RTCP packets is obviously to blame here -- even though the RFC does not mandate sending a correct NTP timestamp and even allows sending a zero or otherwise bogus NTP timestamp (see RFC 3550, section 6.4.1)