[Cast] Repair receiver playout time calculations and frame skip logic.

media/cast/rtcp/rtcp.cc

 // Copyright 2013 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "media/cast/rtcp/rtcp.h"
 
 #include "base/big_endian.h"
 #include "base/rand_util.h"
 #include "media/cast/cast_config.h"
 #include "media/cast/cast_defines.h"
 #include "media/cast/cast_environment.h"
 #include "media/cast/rtcp/rtcp_defines.h"
 #include "media/cast/rtcp/rtcp_receiver.h"
 #include "media/cast/rtcp/rtcp_sender.h"
 #include "media/cast/rtcp/rtcp_utility.h"
 #include "media/cast/transport/cast_transport_defines.h"
 
 namespace media {
 namespace cast {
 
 static const int kMaxRttMs = 10000;  // 10 seconds.
-static const uint16 kMaxDelay = 2000;
-
-// Time limit for received RTCP messages when we stop using it for lip-sync.
-static const int64 kMaxDiffSinceReceivedRtcpMs = 100000;  // 100 seconds.
+static const int kMaxDelay = 2000;
 
 class LocalRtcpRttFeedback : public RtcpRttFeedback {
  public:
   explicit LocalRtcpRttFeedback(Rtcp* rtcp) : rtcp_(rtcp) {}
 
   virtual void OnReceivedDelaySinceLastReport(
       uint32 receivers_ssrc, uint32 last_report,
       uint32 delay_since_last_report) OVERRIDE {
     rtcp_->OnReceivedDelaySinceLastReport(receivers_ssrc, last_report,
                                           delay_since_last_report);
@@ skipping 87 matching lines @@
       rtcp_interval_(rtcp_interval),
       rtcp_mode_(rtcp_mode),
       local_ssrc_(local_ssrc),
       remote_ssrc_(remote_ssrc),
       c_name_(c_name),
       rtp_receiver_statistics_(rtp_receiver_statistics),
       rtt_feedback_(new LocalRtcpRttFeedback(this)),
       receiver_feedback_(new LocalRtcpReceiverFeedback(this, cast_environment)),
       rtcp_sender_(new RtcpSender(cast_environment, paced_packet_sender,
                                   local_ssrc, c_name)),
-      last_report_received_(0),
-      last_received_rtp_timestamp_(0),
-      last_received_ntp_seconds_(0),
-      last_received_ntp_fraction_(0),
+      last_report_ntp_time_(0),
+      lip_sync_rtp_timestamp_(0),
       min_rtt_(base::TimeDelta::FromMilliseconds(kMaxRttMs)),
       number_of_rtt_in_avg_(0),
       is_audio_(is_audio) {
   rtcp_receiver_.reset(new RtcpReceiver(cast_environment, sender_feedback,
                                         receiver_feedback_.get(),
                                         rtt_feedback_.get(), local_ssrc));
   rtcp_receiver_->SetRemoteSSRC(remote_ssrc);
 }
 
 Rtcp::~Rtcp() {}
@@ skipping 65 matching lines @@
     packet_type_flags |= transport::kRtcpRr;
 
     report_block.remote_ssrc = 0;            // Not needed to set send side.
     report_block.media_ssrc = remote_ssrc_;  // SSRC of the RTP packet sender.
     if (rtp_receiver_statistics_) {
       rtp_receiver_statistics_->GetStatistics(
           &report_block.fraction_lost, &report_block.cumulative_lost,
           &report_block.extended_high_sequence_number, &report_block.jitter);
     }
 
-    report_block.last_sr = last_report_received_;
+    report_block.last_sr = GetTruncatedLastNtpReportTime();
     if (!time_last_report_received_.is_null()) {
       uint32 delay_seconds = 0;
       uint32 delay_fraction = 0;
       base::TimeDelta delta = now - time_last_report_received_;
       ConvertTimeToFractions(delta.InMicroseconds(), &delay_seconds,
                              &delay_fraction);
       report_block.delay_since_last_sr =
           ConvertToNtpDiff(delay_seconds, delay_fraction);
     } else {
       report_block.delay_since_last_sr = 0;
@@ skipping 17 matching lines @@
 
   if (sender_log_message.size()) {
     packet_type_flags |= transport::kRtcpSenderLog;
   }
 
   SaveLastSentNtpTime(now, sender_info.ntp_seconds, sender_info.ntp_fraction);
 
   transport::RtcpDlrrReportBlock dlrr;
   if (!time_last_report_received_.is_null()) {
     packet_type_flags |= transport::kRtcpDlrr;
-    dlrr.last_rr = last_report_received_;
+    dlrr.last_rr = GetTruncatedLastNtpReportTime();
     uint32 delay_seconds = 0;
     uint32 delay_fraction = 0;
     base::TimeDelta delta = now - time_last_report_received_;
     ConvertTimeToFractions(delta.InMicroseconds(), &delay_seconds,
                            &delay_fraction);
 
     dlrr.delay_since_last_rr = ConvertToNtpDiff(delay_seconds, delay_fraction);
   }
 
   transport_sender_->SendRtcpFromRtpSender(
       packet_type_flags, sender_info, dlrr, sender_log_message, local_ssrc_,
       c_name_);
   UpdateNextTimeToSendRtcp();
 }
 
 void Rtcp::OnReceivedNtp(uint32 ntp_seconds, uint32 ntp_fraction) {
-  last_report_received_ = (ntp_seconds << 16) + (ntp_fraction >> 16);
-
-  base::TimeTicks now = cast_environment_->Clock()->NowTicks();
-  time_last_report_received_ = now;
+  time_last_report_received_ = cast_environment_->Clock()->NowTicks();
+  last_report_ntp_time_ =
+      (static_cast<uint64>(ntp_seconds) << 32) | ntp_fraction;
 }
 
 void Rtcp::OnReceivedLipSyncInfo(uint32 rtp_timestamp, uint32 ntp_seconds,
                                  uint32 ntp_fraction) {
-  last_received_rtp_timestamp_ = rtp_timestamp;
-  last_received_ntp_seconds_ = ntp_seconds;
-  last_received_ntp_fraction_ = ntp_fraction;
+  lip_sync_rtp_timestamp_ = rtp_timestamp;
+  lip_sync_capture_time_ = ToApproximateLocalTime(ntp_seconds, ntp_fraction);
 }
 
 void Rtcp::OnReceivedSendReportRequest() {
   base::TimeTicks now = cast_environment_->Clock()->NowTicks();
 
   // Trigger a new RTCP report at next timer.
   next_time_to_send_rtcp_ = now;
 }
 
-bool Rtcp::RtpTimestampInSenderTime(int frequency, uint32 rtp_timestamp,
-                                    base::TimeTicks* rtp_timestamp_in_ticks)
-    const {
-  if (last_received_ntp_seconds_ == 0)
-    return false;
+base::TimeTicks Rtcp::ToApproximateLocalTime(uint32 remote_ntp_seconds,
+                                             uint32 remote_ntp_fraction) const {
+  // Determine the clock difference between the local clock and the remote
+  // clock.  |last_report_ntp_time_| is assumed to be an accurate timestamp from
+  // the remote clock that was snapshotted "just before" the
+  // |time_last_report_received_| was snapshotted from the local clock.
+  //
+  // TODO(miu): This does not account for packet transmit latency across the
+  // network, which may or may not be siginifcant for our use cases.
+  if (time_last_report_received_.is_null())
+    return base::TimeTicks();
+  const base::TimeDelta local_clock_ahead_by = time_last_report_received_ -
+      ConvertNtpToTimeTicks(static_cast<uint32>(last_report_ntp_time_ >> 32),
+                            static_cast<uint32>(last_report_ntp_time_));
+  return ConvertNtpToTimeTicks(remote_ntp_seconds, remote_ntp_fraction) +
+      local_clock_ahead_by;
+}
 
-  int wrap = CheckForWrapAround(rtp_timestamp, last_received_rtp_timestamp_);
-  int64 rtp_timestamp_int64 = rtp_timestamp;
-  int64 last_received_rtp_timestamp_int64 = last_received_rtp_timestamp_;
+base::TimeTicks Rtcp::ToApproximateCaptureTime(uint32 rtp_timestamp,
+                                               int rtp_timebase) const {
+  // If the lip sync info has not been received yet, no conversion is possible.
+  if (lip_sync_capture_time_.is_null()) {
+    DVLOG(2) << "Requested capture time mapping before first lip sync update.";
+    return base::TimeTicks();

[hubbe, 2014/05/14 23:12:23]

I think this should be last_rtp_received_ticks + (rtp_timestamp -
last_rtp_received) / rtp_rate_per_second - kSenderLatencyGuess or something like
that.

[miu, 2014/05/16 22:45:47]

As discussed, this isn't base::TimeTicks::Now(); it is "null."  The guessing
logic happens in XXXXXReceiver::GetPlayoutTime() in response to a "null" return
from here.

+  } else {
+    // Sanity-check: Getting regular lip sync updates?
+    DCHECK((cast_environment_->Clock()->NowTicks() - lip_sync_capture_time_) <
+           base::TimeDelta::FromMinutes(1));
+  }
 
-  if (wrap == 1) {
-    rtp_timestamp_int64 += (1LL << 32);
-  } else if (wrap == -1) {
-    last_received_rtp_timestamp_int64 += (1LL << 32);
-  }
-  // Time since the last RTCP message.
-  // Note that this can be negative since we can compare a rtp timestamp from
-  // a frame older than the last received RTCP message.
-  int64 rtp_timestamp_diff =
-      rtp_timestamp_int64 - last_received_rtp_timestamp_int64;
-
-  int frequency_khz = frequency / 1000;
-  int64 rtp_time_diff_ms = rtp_timestamp_diff / frequency_khz;
-
-  // Sanity check.
-  if (std::abs(rtp_time_diff_ms) > kMaxDiffSinceReceivedRtcpMs)
-    return false;
-
-  *rtp_timestamp_in_ticks = ConvertNtpToTimeTicks(last_received_ntp_seconds_,
-                                                  last_received_ntp_fraction_) +
-                            base::TimeDelta::FromMilliseconds(rtp_time_diff_ms);
-  return true;
+  const int32 rtp_since_lip_sync =
+      static_cast<int32>(rtp_timestamp - lip_sync_rtp_timestamp_);
+  const base::TimeDelta time_since_lip_sync =
+      rtp_since_lip_sync * base::TimeDelta::FromSeconds(1) / rtp_timebase;
+  return lip_sync_capture_time_ + time_since_lip_sync;
 }
 
 void Rtcp::SetCastReceiverEventHistorySize(size_t size) {
   rtcp_receiver_->SetCastReceiverEventHistorySize(size);
 }
 
 void Rtcp::SetTargetDelay(base::TimeDelta target_delay) {
+  DCHECK(target_delay.InMilliseconds() < kMaxDelay);
   target_delay_ms_ = static_cast<uint16>(target_delay.InMilliseconds());
-  DCHECK(target_delay_ms_ < kMaxDelay);
 }
 
 void Rtcp::OnReceivedDelaySinceLastReport(uint32 receivers_ssrc,
                                           uint32 last_report,
                                           uint32 delay_since_last_report) {
   RtcpSendTimeMap::iterator it = last_reports_sent_map_.find(last_report);
   if (it == last_reports_sent_map_.end()) {
     return;  // Feedback on another report.
   }
 
@@ skipping 21 matching lines @@
     RtcpSendTimePair oldest_report = last_reports_sent_queue_.front();
     if (oldest_report.second < timeout) {
       last_reports_sent_map_.erase(oldest_report.first);
       last_reports_sent_queue_.pop();
     } else {
       break;
     }
   }
 }
 
+uint32 Rtcp::GetTruncatedLastNtpReportTime() const {
+  return static_cast<uint32>(last_report_ntp_time_ >> 16);
+}
+
 void Rtcp::UpdateRtt(const base::TimeDelta& sender_delay,
                      const base::TimeDelta& receiver_delay) {
   base::TimeDelta rtt = sender_delay - receiver_delay;
+  // TODO(miu): Find out why this is capped at 1 ms, and remove the cap if it's
+  // bogus.
   rtt = std::max(rtt, base::TimeDelta::FromMilliseconds(1));
   rtt_ = rtt;
   min_rtt_ = std::min(min_rtt_, rtt);
   max_rtt_ = std::max(max_rtt_, rtt);
 
+  // TODO(miu): Replace "average for all time" with an EWMA, or suitable
+  // "average over recent past" mechanism.
   if (number_of_rtt_in_avg_ != 0) {
-    float ac = static_cast<float>(number_of_rtt_in_avg_);
+    const double ac = static_cast<double>(number_of_rtt_in_avg_);
     avg_rtt_ms_ = ((ac / (ac + 1.0)) * avg_rtt_ms_) +
-                  ((1.0 / (ac + 1.0)) * rtt.InMilliseconds());
+                  ((1.0 / (ac + 1.0)) * rtt.InMillisecondsF());
   } else {
-    avg_rtt_ms_ = rtt.InMilliseconds();
+    avg_rtt_ms_ = rtt.InMillisecondsF();
   }
   number_of_rtt_in_avg_++;
 }
 
 bool Rtcp::Rtt(base::TimeDelta* rtt, base::TimeDelta* avg_rtt,
                base::TimeDelta* min_rtt, base::TimeDelta* max_rtt) const {
   DCHECK(rtt) << "Invalid argument";
   DCHECK(avg_rtt) << "Invalid argument";
   DCHECK(min_rtt) << "Invalid argument";
   DCHECK(max_rtt) << "Invalid argument";
 
   if (number_of_rtt_in_avg_ == 0) return false;
 
   *rtt = rtt_;
-  *avg_rtt = base::TimeDelta::FromMilliseconds(avg_rtt_ms_);
+  *avg_rtt = base::TimeDelta::FromMillisecondsD(avg_rtt_ms_);
   *min_rtt = min_rtt_;
   *max_rtt = max_rtt_;
   return true;
 }
 
-int Rtcp::CheckForWrapAround(uint32 new_timestamp, uint32 old_timestamp) const {

[hubbe, 2014/05/14 23:12:23]

Where did this logic go?

[miu, 2014/05/16 22:45:47]

It was meaningless.  Subtraction when zero, one, or both uint32's have
overflowed still works (in ToApproximateCaptureTime()).  The assumption there is
that the sender reports are providing RTP timestamps within 1 minute of those
found in the current packets/frames.

-  if (new_timestamp < old_timestamp) {
-    // This difference should be less than -2^31 if we have had a wrap around
-    // (e.g. |new_timestamp| = 1, |rtcp_rtp_timestamp| = 2^32 - 1). Since it is
-    // cast to a int32_t, it should be positive.
-    if (static_cast<int32>(new_timestamp - old_timestamp) > 0) {
-      return 1;  // Forward wrap around.
-    }
-  } else if (static_cast<int32>(old_timestamp - new_timestamp) > 0) {
-    // This difference should be less than -2^31 if we have had a backward wrap
-    // around. Since it is cast to a int32, it should be positive.
-    return -1;
-  }
-  return 0;
-}
-
 void Rtcp::UpdateNextTimeToSendRtcp() {
   int random = base::RandInt(0, 999);
   base::TimeDelta time_to_next =
       (rtcp_interval_ / 2) + (rtcp_interval_ * random / 1000);
 
   base::TimeTicks now = cast_environment_->Clock()->NowTicks();
   next_time_to_send_rtcp_ = now + time_to_next;
 }
 
 void Rtcp::OnReceivedReceiverLog(const RtcpReceiverLogMessage& receiver_log) {
@@ skipping 28 matching lines @@
           VLOG(2) << "Received log message via RTCP that we did not expect: "
                   << static_cast<int>(event_it->type);
           break;
       }
     }
   }
 }
 
 }  // namespace cast
 }  // namespace media