media/cast/sender/frame_sender.cc

   1 // Copyright 2014 The Chromium Authors. All rights reserved.
   2 // Use of this source code is governed by a BSD-style license that can be
   3 // found in the LICENSE file.
   4
   5 #include "media/cast/sender/frame_sender.h"
   6
   7 #include "base/trace_event/trace_event.h"
   8
   9 namespace media {
  10 namespace cast {
  11 namespace {
  12
  13 const int kMinSchedulingDelayMs = 1;
  14 const int kNumAggressiveReportsSentAtStart = 100;
  15
  16 // The additional number of frames that can be in-flight when input exceeds the
  17 // maximum frame rate.
  18 const int kMaxFrameBurst = 5;
  19
  20 }  // namespace
  21
  22 // Convenience macro used in logging statements throughout this file.
  23 #define SENDER_SSRC (is_audio_ ? "AUDIO[" : "VIDEO[") << ssrc_ << "] "
  24
  25 FrameSender::FrameSender(scoped_refptr<CastEnvironment> cast_environment,
  26                          bool is_audio,
  27                          CastTransportSender* const transport_sender,
  28                          int rtp_timebase,
  29                          uint32 ssrc,
  30                          double max_frame_rate,
  31                          base::TimeDelta min_playout_delay,
  32                          base::TimeDelta max_playout_delay,
  33                          CongestionControl* congestion_control)
  34     : cast_environment_(cast_environment),
  35       transport_sender_(transport_sender),
  36       ssrc_(ssrc),
  37       min_playout_delay_(min_playout_delay == base::TimeDelta() ?
  38                          max_playout_delay : min_playout_delay),
  39       max_playout_delay_(max_playout_delay),
  40       send_target_playout_delay_(false),
  41       max_frame_rate_(max_frame_rate),
  42       num_aggressive_rtcp_reports_sent_(0),
  43       last_sent_frame_id_(0),
  44       latest_acked_frame_id_(0),
  45       duplicate_ack_counter_(0),
  46       congestion_control_(congestion_control),
  47       rtp_timebase_(rtp_timebase),
  48       is_audio_(is_audio),
  49       weak_factory_(this) {
  50   DCHECK(transport_sender_);
  51   DCHECK_GT(rtp_timebase_, 0);
  52   DCHECK(congestion_control_);
  53   SetTargetPlayoutDelay(min_playout_delay_);
  54   send_target_playout_delay_ = false;
  55   memset(frame_rtp_timestamps_, 0, sizeof(frame_rtp_timestamps_));
  56 }
  57
  58 FrameSender::~FrameSender() {
  59 }
  60
  61 void FrameSender::ScheduleNextRtcpReport() {
  62   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
  63
  64   cast_environment_->PostDelayedTask(
  65       CastEnvironment::MAIN, FROM_HERE,
  66       base::Bind(&FrameSender::SendRtcpReport, weak_factory_.GetWeakPtr(),
  67                  true),
  68       base::TimeDelta::FromMilliseconds(kDefaultRtcpIntervalMs));
  69 }
  70
  71 void FrameSender::SendRtcpReport(bool schedule_future_reports) {
  72   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
  73
  74   // Sanity-check: We should have sent at least the first frame by this point.
  75   DCHECK(!last_send_time_.is_null());
  76
  77   // Create lip-sync info for the sender report.  The last sent frame's
  78   // reference time and RTP timestamp are used to estimate an RTP timestamp in
  79   // terms of "now."  Note that |now| is never likely to be precise to an exact
  80   // frame boundary; and so the computation here will result in a
  81   // |now_as_rtp_timestamp| value that is rarely equal to any one emitted by the
  82   // encoder.
  83   const base::TimeTicks now = cast_environment_->Clock()->NowTicks();
  84   const base::TimeDelta time_delta =
  85       now - GetRecordedReferenceTime(last_sent_frame_id_);
  86   const int64 rtp_delta = TimeDeltaToRtpDelta(time_delta, rtp_timebase_);
  87   const uint32 now_as_rtp_timestamp =
  88       GetRecordedRtpTimestamp(last_sent_frame_id_) +
  89           static_cast<uint32>(rtp_delta);
  90   transport_sender_->SendSenderReport(ssrc_, now, now_as_rtp_timestamp);
  91
  92   if (schedule_future_reports)
  93     ScheduleNextRtcpReport();
  94 }
  95
  96 void FrameSender::OnMeasuredRoundTripTime(base::TimeDelta rtt) {
  97   DCHECK(rtt > base::TimeDelta());
  98   current_round_trip_time_ = rtt;
  99 }
 100
 101 void FrameSender::SetTargetPlayoutDelay(
 102     base::TimeDelta new_target_playout_delay) {
 103   if (send_target_playout_delay_ &&
 104       target_playout_delay_ == new_target_playout_delay) {
 105     return;
 106   }
 107   new_target_playout_delay = std::max(new_target_playout_delay,
 108                                       min_playout_delay_);
 109   new_target_playout_delay = std::min(new_target_playout_delay,
 110                                       max_playout_delay_);
 111   VLOG(2) << SENDER_SSRC << "Target playout delay changing from "
 112           << target_playout_delay_.InMilliseconds() << " ms to "
 113           << new_target_playout_delay.InMilliseconds() << " ms.";
 114   target_playout_delay_ = new_target_playout_delay;
 115   send_target_playout_delay_ = true;
 116   congestion_control_->UpdateTargetPlayoutDelay(target_playout_delay_);
 117 }
 118
 119 void FrameSender::ResendCheck() {
 120   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
 121   DCHECK(!last_send_time_.is_null());
 122   const base::TimeDelta time_since_last_send =
 123       cast_environment_->Clock()->NowTicks() - last_send_time_;
 124   if (time_since_last_send > target_playout_delay_) {
 125     if (latest_acked_frame_id_ == last_sent_frame_id_) {
 126       // Last frame acked, no point in doing anything
 127     } else {
 128       VLOG(1) << SENDER_SSRC << "ACK timeout; last acked frame: "
 129               << latest_acked_frame_id_;
 130       ResendForKickstart();
 131     }
 132   }
 133   ScheduleNextResendCheck();
 134 }
 135
 136 void FrameSender::ScheduleNextResendCheck() {
 137   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
 138   DCHECK(!last_send_time_.is_null());
 139   base::TimeDelta time_to_next =
 140       last_send_time_ - cast_environment_->Clock()->NowTicks() +
 141       target_playout_delay_;
 142   time_to_next = std::max(
 143       time_to_next, base::TimeDelta::FromMilliseconds(kMinSchedulingDelayMs));
 144   cast_environment_->PostDelayedTask(
 145       CastEnvironment::MAIN,
 146       FROM_HERE,
 147       base::Bind(&FrameSender::ResendCheck, weak_factory_.GetWeakPtr()),
 148       time_to_next);
 149 }
 150
 151 void FrameSender::ResendForKickstart() {
 152   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
 153   DCHECK(!last_send_time_.is_null());
 154   VLOG(1) << SENDER_SSRC << "Resending last packet of frame "
 155           << last_sent_frame_id_ << " to kick-start.";
 156   last_send_time_ = cast_environment_->Clock()->NowTicks();
 157   transport_sender_->ResendFrameForKickstart(ssrc_, last_sent_frame_id_);
 158 }
 159
 160 void FrameSender::RecordLatestFrameTimestamps(uint32 frame_id,
 161                                               base::TimeTicks reference_time,
 162                                               RtpTimestamp rtp_timestamp) {
 163   DCHECK(!reference_time.is_null());
 164   frame_reference_times_[frame_id % arraysize(frame_reference_times_)] =
 165       reference_time;
 166   frame_rtp_timestamps_[frame_id % arraysize(frame_rtp_timestamps_)] =
 167       rtp_timestamp;
 168 }
 169
 170 base::TimeTicks FrameSender::GetRecordedReferenceTime(uint32 frame_id) const {
 171   return frame_reference_times_[frame_id % arraysize(frame_reference_times_)];
 172 }
 173
 174 RtpTimestamp FrameSender::GetRecordedRtpTimestamp(uint32 frame_id) const {
 175   return frame_rtp_timestamps_[frame_id % arraysize(frame_rtp_timestamps_)];
 176 }
 177
 178 int FrameSender::GetUnacknowledgedFrameCount() const {
 179   const int count =
 180       static_cast<int32>(last_sent_frame_id_ - latest_acked_frame_id_);
 181   DCHECK_GE(count, 0);
 182   return count;
 183 }
 184
 185 base::TimeDelta FrameSender::GetAllowedInFlightMediaDuration() const {
 186   // The total amount allowed in-flight media should equal the amount that fits
 187   // within the entire playout delay window, plus the amount of time it takes to
 188   // receive an ACK from the receiver.
 189   // TODO(miu): Research is needed, but there is likely a better formula.
 190   return target_playout_delay_ + (current_round_trip_time_ / 2);
 191 }
 192
 193 void FrameSender::SendEncodedFrame(
 194     int requested_bitrate_before_encode,
 195     scoped_ptr<EncodedFrame> encoded_frame) {
 196   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
 197
 198   VLOG(2) << SENDER_SSRC << "About to send another frame: last_sent="
 199           << last_sent_frame_id_ << ", latest_acked=" << latest_acked_frame_id_;
 200
 201   const uint32 frame_id = encoded_frame->frame_id;
 202
 203   const bool is_first_frame_to_be_sent = last_send_time_.is_null();
 204   last_send_time_ = cast_environment_->Clock()->NowTicks();
 205   last_sent_frame_id_ = frame_id;
 206   // If this is the first frame about to be sent, fake the value of
 207   // |latest_acked_frame_id_| to indicate the receiver starts out all caught up.
 208   // Also, schedule the periodic frame re-send checks.
 209   if (is_first_frame_to_be_sent) {
 210     latest_acked_frame_id_ = frame_id - 1;
 211     ScheduleNextResendCheck();
 212   }
 213
 214   VLOG_IF(1, !is_audio_ && encoded_frame->dependency == EncodedFrame::KEY)
 215       << SENDER_SSRC << "Sending encoded key frame, id=" << frame_id;
 216
 217   cast_environment_->Logging()->InsertEncodedFrameEvent(
 218       last_send_time_, FRAME_ENCODED,
 219       is_audio_ ? AUDIO_EVENT : VIDEO_EVENT,
 220       encoded_frame->rtp_timestamp,
 221       frame_id, static_cast<int>(encoded_frame->data.size()),
 222       encoded_frame->dependency == EncodedFrame::KEY,
 223       requested_bitrate_before_encode);
 224
 225   RecordLatestFrameTimestamps(frame_id,
 226                               encoded_frame->reference_time,
 227                               encoded_frame->rtp_timestamp);
 228
 229   if (!is_audio_) {
 230     // Used by chrome/browser/extension/api/cast_streaming/performance_test.cc
 231     TRACE_EVENT_INSTANT1(
 232         "cast_perf_test", "VideoFrameEncoded",
 233         TRACE_EVENT_SCOPE_THREAD,
 234         "rtp_timestamp", encoded_frame->rtp_timestamp);
 235   }
 236
 237   // At the start of the session, it's important to send reports before each
 238   // frame so that the receiver can properly compute playout times.  The reason
 239   // more than one report is sent is because transmission is not guaranteed,
 240   // only best effort, so send enough that one should almost certainly get
 241   // through.
 242   if (num_aggressive_rtcp_reports_sent_ < kNumAggressiveReportsSentAtStart) {
 243     // SendRtcpReport() will schedule future reports to be made if this is the
 244     // last "aggressive report."
 245     ++num_aggressive_rtcp_reports_sent_;
 246     const bool is_last_aggressive_report =
 247         (num_aggressive_rtcp_reports_sent_ == kNumAggressiveReportsSentAtStart);
 248     VLOG_IF(1, is_last_aggressive_report)
 249         << SENDER_SSRC << "Sending last aggressive report.";
 250     SendRtcpReport(is_last_aggressive_report);
 251   }
 252
 253   congestion_control_->SendFrameToTransport(
 254       frame_id, encoded_frame->data.size() * 8, last_send_time_);
 255
 256   if (send_target_playout_delay_) {
 257     encoded_frame->new_playout_delay_ms =
 258         target_playout_delay_.InMilliseconds();
 259   }
 260   transport_sender_->InsertFrame(ssrc_, *encoded_frame);
 261 }
 262
 263 void FrameSender::OnReceivedCastFeedback(const RtcpCastMessage& cast_feedback) {
 264   DCHECK(cast_environment_->CurrentlyOn(CastEnvironment::MAIN));
 265
 266   const bool have_valid_rtt = current_round_trip_time_ > base::TimeDelta();
 267   if (have_valid_rtt) {
 268     congestion_control_->UpdateRtt(current_round_trip_time_);
 269
 270     // Having the RTT value implies the receiver sent back a receiver report
 271     // based on it having received a report from here.  Therefore, ensure this
 272     // sender stops aggressively sending reports.
 273     if (num_aggressive_rtcp_reports_sent_ < kNumAggressiveReportsSentAtStart) {
 274       VLOG(1) << SENDER_SSRC
 275               << "No longer a need to send reports aggressively (sent "
 276               << num_aggressive_rtcp_reports_sent_ << ").";
 277       num_aggressive_rtcp_reports_sent_ = kNumAggressiveReportsSentAtStart;
 278       ScheduleNextRtcpReport();
 279     }
 280   }
 281
 282   if (last_send_time_.is_null())
 283     return;  // Cannot get an ACK without having first sent a frame.
 284
 285   if (cast_feedback.missing_frames_and_packets.empty()) {
 286     OnAck(cast_feedback.ack_frame_id);
 287
 288     // We only count duplicate ACKs when we have sent newer frames.
 289     if (latest_acked_frame_id_ == cast_feedback.ack_frame_id &&
 290         latest_acked_frame_id_ != last_sent_frame_id_) {
 291       duplicate_ack_counter_++;
 292     } else {
 293       duplicate_ack_counter_ = 0;
 294     }
 295     // TODO(miu): The values "2" and "3" should be derived from configuration.
 296     if (duplicate_ack_counter_ >= 2 && duplicate_ack_counter_ % 3 == 2) {
 297       VLOG(1) << SENDER_SSRC << "Received duplicate ACK for frame "
 298               << latest_acked_frame_id_;
 299       ResendForKickstart();
 300     }
 301   } else {
 302     // Only count duplicated ACKs if there is no NACK request in between.
 303     // This is to avoid aggresive resend.
 304     duplicate_ack_counter_ = 0;
 305   }
 306
 307   base::TimeTicks now = cast_environment_->Clock()->NowTicks();
 308   congestion_control_->AckFrame(cast_feedback.ack_frame_id, now);
 309
 310   cast_environment_->Logging()->InsertFrameEvent(
 311       now,
 312       FRAME_ACK_RECEIVED,
 313       is_audio_ ? AUDIO_EVENT : VIDEO_EVENT,
 314       GetRecordedRtpTimestamp(cast_feedback.ack_frame_id),
 315       cast_feedback.ack_frame_id);
 316
 317   const bool is_acked_out_of_order =
 318       static_cast<int32>(cast_feedback.ack_frame_id -
 319                              latest_acked_frame_id_) < 0;
 320   VLOG(2) << SENDER_SSRC
 321           << "Received ACK" << (is_acked_out_of_order ? " out-of-order" : "")
 322           << " for frame " << cast_feedback.ack_frame_id;
 323   if (!is_acked_out_of_order) {
 324     // Cancel resends of acked frames.
 325     std::vector<uint32> cancel_sending_frames;
 326     while (latest_acked_frame_id_ != cast_feedback.ack_frame_id) {
 327       latest_acked_frame_id_++;
 328       cancel_sending_frames.push_back(latest_acked_frame_id_);
 329     }
 330     transport_sender_->CancelSendingFrames(ssrc_, cancel_sending_frames);
 331     latest_acked_frame_id_ = cast_feedback.ack_frame_id;
 332   }
 333 }
 334
 335 bool FrameSender::ShouldDropNextFrame(base::TimeDelta frame_duration) const {
 336   // Check that accepting the next frame won't cause more frames to become
 337   // in-flight than the system's design limit.
 338   const int count_frames_in_flight =
 339       GetUnacknowledgedFrameCount() + GetNumberOfFramesInEncoder();
 340   if (count_frames_in_flight >= kMaxUnackedFrames) {
 341     VLOG(1) << SENDER_SSRC << "Dropping: Too many frames would be in-flight.";
 342     return true;
 343   }
 344
 345   // Check that accepting the next frame won't exceed the configured maximum
 346   // frame rate, allowing for short-term bursts.
 347   base::TimeDelta duration_in_flight = GetInFlightMediaDuration();
 348   const double max_frames_in_flight =
 349       max_frame_rate_ * duration_in_flight.InSecondsF();
 350   if (count_frames_in_flight >= max_frames_in_flight + kMaxFrameBurst) {
 351     VLOG(1) << SENDER_SSRC << "Dropping: Burst threshold would be exceeded.";
 352     return true;
 353   }
 354
 355   // Check that accepting the next frame won't exceed the allowed in-flight
 356   // media duration.
 357   const base::TimeDelta duration_would_be_in_flight =
 358       duration_in_flight + frame_duration;
 359   const base::TimeDelta allowed_in_flight = GetAllowedInFlightMediaDuration();
 360   if (VLOG_IS_ON(1)) {
 361     const int64 percent = allowed_in_flight > base::TimeDelta() ?
 362         100 * duration_would_be_in_flight / allowed_in_flight : kint64max;
 363     VLOG_IF(1, percent > 50)
 364         << SENDER_SSRC
 365         << duration_in_flight.InMicroseconds() << " usec in-flight + "
 366         << frame_duration.InMicroseconds() << " usec for next frame --> "
 367         << percent << "% of allowed in-flight.";
 368   }
 369   if (duration_would_be_in_flight > allowed_in_flight) {
 370     VLOG(1) << SENDER_SSRC << "Dropping: In-flight duration would be too high.";
 371     return true;
 372   }
 373
 374   // Next frame is accepted.
 375   return false;
 376 }
 377
 378 }  // namespace cast
 379 }  // namespace media