Add logs when no RTCP RR has been received for three regular RTCP intervals.

BUG=1267
TEST=Unittest added.

Review URL: https://webrtc-codereview.appspot.com/1019006

git-svn-id: http://webrtc.googlecode.com/svn/trunk@3346 4adac7df-926f-26a2-2b94-8c16560cd09d

webrtc/modules/rtp_rtcp/source/rtcp_receiver.cc

@@ -27,6 +27,9 @@ namespace webrtc {
 using namespace RTCPUtility;
 using namespace RTCPHelp;
 
+// The number of RTCP time intervals needed to trigger a timeout.
+const int kRrTimeoutIntervals = 3;
+
 RTCPReceiver::RTCPReceiver(const WebRtc_Word32 id, RtpRtcpClock* clock,
                            ModuleRtpRtcpImpl* owner)
     : TMMBRHelp(),
@@ -49,7 +52,9 @@ RTCPReceiver::RTCPReceiver(const WebRtc_Word32 id, RtpRtcpClock* clock,
     _lastReceivedSRNTPfrac(0),
     _receivedInfoMap(),
     _packetTimeOutMS(0),
-      _rtt(0) {
+    _lastReceivedRrMs(0),
+    _lastIncreasedSequenceNumberMs(0),
+    _rtt(0) {
     memset(&_remoteSenderInfo, 0, sizeof(_remoteSenderInfo));
     WEBRTC_TRACE(kTraceMemory, kTraceRtpRtcp, id, "%s created", __FUNCTION__);
 }
@@ -460,12 +465,21 @@ RTCPReceiver::HandleReportBlock(const RTCPUtility::RTCPPacket& rtcpPacket,
                  "\tfailed to CreateReportBlockInformation(%u)", remoteSSRC);
     return;
   }
+
+  _lastReceivedRrMs = _clock.GetTimeInMS();
   const RTCPPacketReportBlockItem& rb = rtcpPacket.ReportBlockItem;
   reportBlock->remoteReceiveBlock.remoteSSRC = remoteSSRC;
   reportBlock->remoteReceiveBlock.sourceSSRC = rb.SSRC;
   reportBlock->remoteReceiveBlock.fractionLost = rb.FractionLost;
   reportBlock->remoteReceiveBlock.cumulativeLost =
       rb.CumulativeNumOfPacketsLost;
+  if (rb.ExtendedHighestSequenceNumber >
+      reportBlock->remoteReceiveBlock.extendedHighSeqNum) {
+    // We have successfully delivered new RTP packets to the remote side after
+    // the last RR was sent from the remote side.
+    _lastIncreasedSequenceNumberMs = _lastReceivedRrMs;
+
+  }
   reportBlock->remoteReceiveBlock.extendedHighSeqNum =
       rb.ExtendedHighestSequenceNumber;
   reportBlock->remoteReceiveBlock.jitter = rb.Jitter;
@@ -631,6 +645,34 @@ void RTCPReceiver::UpdateReceiveInformation(
   receiveInformation.lastTimeReceived = _clock.GetTimeInMS();
 }
 
+bool RTCPReceiver::RtcpRrTimeout(int64_t rtcp_interval_ms) {
+  CriticalSectionScoped lock(_criticalSectionRTCPReceiver);
+  if (_lastReceivedRrMs == 0)
+    return false;
+
+  int64_t time_out_ms = kRrTimeoutIntervals * rtcp_interval_ms;
+  if (_clock.GetTimeInMS() > _lastReceivedRrMs + time_out_ms) {
+    // Reset the timer to only trigger one log.
+    _lastReceivedRrMs = 0;
+    return true;
+  }
+  return false;
+}
+
+bool RTCPReceiver::RtcpRrSequenceNumberTimeout(int64_t rtcp_interval_ms) {
+  CriticalSectionScoped lock(_criticalSectionRTCPReceiver);
+  if (_lastIncreasedSequenceNumberMs == 0)
+    return false;
+
+  int64_t time_out_ms = kRrTimeoutIntervals * rtcp_interval_ms;
+  if (_clock.GetTimeInMS() > _lastIncreasedSequenceNumberMs + time_out_ms) {
+    // Reset the timer to only trigger one log.
+    _lastIncreasedSequenceNumberMs = 0;
+    return true;
+  }
+  return false;
+}
+
 bool RTCPReceiver::UpdateRTCPReceiveInformationTimers() {
   CriticalSectionScoped lock(_criticalSectionRTCPReceiver);
 

webrtc/modules/rtp_rtcp/source/rtcp_receiver.h

@@ -83,6 +83,16 @@ public:
     WebRtc_Word32 StatisticsReceived(
         std::vector<RTCPReportBlock>* receiveBlocks) const;
 
+    // Returns true if we haven't received an RTCP RR for several RTCP
+    // intervals, but only triggers true once.
+    bool RtcpRrTimeout(int64_t rtcp_interval_ms);
+
+    // Returns true if we haven't received an RTCP RR telling the receive side
+    // has not received RTP packets for too long, i.e. extended highest sequence
+    // number hasn't increased for several RTCP intervals. The function only
+    // returns true once until a new RR is received.
+    bool RtcpRrSequenceNumberTimeout(int64_t rtcp_interval_ms);
+
     // Get TMMBR
     WebRtc_Word32 TMMBRReceived(const WebRtc_UWord32 size,
                                 const WebRtc_UWord32 accNumCandidates,
@@ -218,6 +228,13 @@ protected:
 
   WebRtc_UWord32            _packetTimeOutMS;
 
+  // The last time we received an RTCP RR.
+  int64_t _lastReceivedRrMs;
+
+  // The time we last received an RTCP RR telling we have ssuccessfully
+  // delivered RTP packet to the remote side.
+  int64_t _lastIncreasedSequenceNumberMs;
+
   // Externally set RTT. This value can only be used if there are no valid
   // RTT estimates.
   WebRtc_UWord16 _rtt;

webrtc/modules/rtp_rtcp/source/rtcp_receiver_unittest.cc

@@ -92,6 +92,18 @@ class PacketBuilder {
     Add32(0);  // Sender's octet count
   }
 
+  void AddRrPacket(WebRtc_UWord32 sender_ssrc, WebRtc_UWord32 rtp_ssrc,
+                   WebRtc_UWord32 extended_max) {
+    AddRtcpHeader(201, 1);
+    Add32(sender_ssrc);
+    Add32(rtp_ssrc);
+    Add32(0);  // No loss.
+    Add32(extended_max);
+    Add32(0);  // Jitter.
+    Add32(0);  // Last SR.
+    Add32(0);  // Delay since last SR.
+  }
+
   const WebRtc_UWord8* packet() {
     PatchLengthField();
     return buffer_;
@@ -255,6 +267,66 @@ TEST_F(RtcpReceiverTest, InjectSrPacket) {
             kRtcpSr & rtcp_packet_info_.rtcpPacketTypeFlags);
 }
 
+TEST_F(RtcpReceiverTest, ReceiveReportTimeout) {
+  const uint32_t kSenderSsrc = 0x10203;
+  const uint32_t kSourceSsrc = 0x40506;
+  const int64_t kRtcpIntervalMs = 1000;
+
+  rtcp_receiver_->SetSSRC(kSourceSsrc);
+
+  uint32_t sequence_number = 1234;
+  system_clock_->AdvanceClock(3 * kRtcpIntervalMs);
+
+  // No RR received, shouldn't trigger a timeout.
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrSequenceNumberTimeout(kRtcpIntervalMs));
+
+  // Add a RR and advance the clock just enough to not trigger a timeout.
+  PacketBuilder p1;
+  p1.AddRrPacket(kSenderSsrc, kSourceSsrc, sequence_number);
+  EXPECT_EQ(0, InjectRtcpPacket(p1.packet(), p1.length()));
+  system_clock_->AdvanceClock(3 * kRtcpIntervalMs - 1);
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrSequenceNumberTimeout(kRtcpIntervalMs));
+
+  // Add a RR with the same extended max as the previous RR to trigger a
+  // sequence number timeout, but not a RR timeout.
+  PacketBuilder p2;
+  p2.AddRrPacket(kSenderSsrc, kSourceSsrc, sequence_number);
+  EXPECT_EQ(0, InjectRtcpPacket(p2.packet(), p2.length()));
+  system_clock_->AdvanceClock(2);
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+  EXPECT_TRUE(rtcp_receiver_->RtcpRrSequenceNumberTimeout(kRtcpIntervalMs));
+
+  // Advance clock enough to trigger an RR timeout too.
+  system_clock_->AdvanceClock(3 * kRtcpIntervalMs);
+  EXPECT_TRUE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+
+  // We should only get one timeout even though we still haven't received a new
+  // RR.
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrSequenceNumberTimeout(kRtcpIntervalMs));
+
+  // Add a new RR with increase sequence number to reset timers.
+  PacketBuilder p3;
+  sequence_number++;
+  p2.AddRrPacket(kSenderSsrc, kSourceSsrc, sequence_number);
+  EXPECT_EQ(0, InjectRtcpPacket(p2.packet(), p2.length()));
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrSequenceNumberTimeout(kRtcpIntervalMs));
+
+  // Verify we can get a timeout again once we've received new RR.
+  system_clock_->AdvanceClock(2 * kRtcpIntervalMs);
+  PacketBuilder p4;
+  p4.AddRrPacket(kSenderSsrc, kSourceSsrc, sequence_number);
+  EXPECT_EQ(0, InjectRtcpPacket(p4.packet(), p4.length()));
+  system_clock_->AdvanceClock(kRtcpIntervalMs + 1);
+  EXPECT_FALSE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+  EXPECT_TRUE(rtcp_receiver_->RtcpRrSequenceNumberTimeout(kRtcpIntervalMs));
+  system_clock_->AdvanceClock(2 * kRtcpIntervalMs);
+  EXPECT_TRUE(rtcp_receiver_->RtcpRrTimeout(kRtcpIntervalMs));
+}
+
 TEST_F(RtcpReceiverTest, TmmbrReceivedWithNoIncomingPacket) {
   // This call is expected to fail because no data has arrived.
   EXPECT_EQ(-1, rtcp_receiver_->TMMBRReceived(0, 0, NULL));

webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl.cc

@@ -8,20 +8,22 @@
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
-#include "rtp_rtcp_impl.h"
+#include "webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl.h"
+
+#include <cassert>
+#include <string.h>
+
+#include "webrtc/common_types.h"
+#include "webrtc/modules/rtp_rtcp/source/rtp_receiver_audio.h"
+#include "webrtc/modules/rtp_rtcp/source/rtp_receiver_video.h"
+#include "webrtc/system_wrappers/interface/logging.h"
+#include "webrtc/system_wrappers/interface/trace.h"
 
 #ifdef MATLAB
-#include "../test/BWEStandAlone/MatlabPlot.h"
+#include "webrtc/modules/rtp_rtcp/test/BWEStandAlone/MatlabPlot.h"
 extern MatlabEngine eng; // global variable defined elsewhere
 #endif
 
-#include <string.h> //memcpy
-#include <cassert> //assert
-
-#include "common_types.h"
-#include "rtp_receiver_audio.h"
-#include "rtp_receiver_video.h"
-#include "trace.h"
 
 // local for this file
 namespace {
@@ -228,6 +230,19 @@ WebRtc_Word32 ModuleRtpRtcpImpl::Process() {
       // No own rtt calculation or set rtt, use default value.
       max_rtt = kDefaultRtt;
     }
+
+    // Verify receiver reports are delivered and the reported sequence number is
+    // increasing.
+    if (_rtcpSender.Sending()) {
+      int64_t rtcp_interval = RtcpReportInterval();
+      if (_rtcpReceiver.RtcpRrTimeout(rtcp_interval)) {
+        LOG_F(LS_WARNING) << "Timeout: No RTCP RR received.";
+      } else if (_rtcpReceiver.RtcpRrSequenceNumberTimeout(rtcp_interval)) {
+        LOG_F(LS_WARNING) <<
+            "Timeout: No increase in RTCP RR extended highest sequence number.";
+      }
+    }
+
     if (remote_bitrate_) {
       // TODO(mflodman) Remove this and let this be propagated by CallStats.
       remote_bitrate_->SetRtt(max_rtt);
@@ -2037,4 +2052,12 @@ WebRtc_Word32 ModuleRtpRtcpImpl::BoundingSet(bool& tmmbrOwner,
                                              TMMBRSet*& boundingSet) {
   return _rtcpReceiver.BoundingSet(tmmbrOwner, boundingSet);
 }
+
+int64_t ModuleRtpRtcpImpl::RtcpReportInterval() {
+  if (_audio)
+    return RTCP_INTERVAL_AUDIO_MS;
+  else
+    return RTCP_INTERVAL_VIDEO_MS;
+}
+
 }  // namespace webrtc

webrtc/modules/rtp_rtcp/source/rtp_rtcp_impl.h

@@ -483,6 +483,8 @@ protected:
     bool                      _owns_clock;
     RtpRtcpClock&             _clock;
 private:
+    int64_t RtcpReportInterval();
+
     WebRtc_Word32             _id;
     const bool                _audio;
     bool                      _collisionDetected;