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