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