diff options
Diffstat (limited to 'chromium/media/cast/rtcp/rtcp.cc')
| -rw-r--r-- | chromium/media/cast/rtcp/rtcp.cc | 335 |
1 files changed, 210 insertions, 125 deletions
diff --git a/chromium/media/cast/rtcp/rtcp.cc b/chromium/media/cast/rtcp/rtcp.cc index c3e2c8e4d88..4ea4bc99ba9 100644 --- a/chromium/media/cast/rtcp/rtcp.cc +++ b/chromium/media/cast/rtcp/rtcp.cc @@ -4,10 +4,10 @@ #include "media/cast/rtcp/rtcp.h" -#include "base/debug/trace_event.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" @@ -17,7 +17,7 @@ namespace media { namespace cast { -static const int kMaxRttMs = 1000000; // 1000 seconds. +static const int kMaxRttMs = 10000; // 10 seconds. // Time limit for received RTCP messages when we stop using it for lip-sync. static const int64 kMaxDiffSinceReceivedRtcpMs = 100000; // 100 seconds. @@ -52,11 +52,16 @@ RtcpNackMessage::~RtcpNackMessage() {} RtcpRembMessage::RtcpRembMessage() {} RtcpRembMessage::~RtcpRembMessage() {} +RtcpReceiverFrameLogMessage::RtcpReceiverFrameLogMessage(uint32 timestamp) + : rtp_timestamp_(timestamp) {} + +RtcpReceiverFrameLogMessage::~RtcpReceiverFrameLogMessage() {} class LocalRtcpReceiverFeedback : public RtcpReceiverFeedback { public: - explicit LocalRtcpReceiverFeedback(Rtcp* rtcp) - : rtcp_(rtcp) { + LocalRtcpReceiverFeedback(Rtcp* rtcp, + scoped_refptr<CastEnvironment> cast_environment) + : rtcp_(rtcp), cast_environment_(cast_environment) { } virtual void OnReceivedSenderReport( @@ -80,48 +85,128 @@ class LocalRtcpReceiverFeedback : public RtcpReceiverFeedback { rtcp_->OnReceivedSendReportRequest(); } + virtual void OnReceivedReceiverLog( + const RtcpReceiverLogMessage& receiver_log) OVERRIDE { + // Add received log messages into our log system. + RtcpReceiverLogMessage::const_iterator it = receiver_log.begin(); + + for (; it != receiver_log.end(); ++it) { + uint32 rtp_timestamp = it->rtp_timestamp_; + + RtcpReceiverEventLogMessages::const_iterator event_it = + it->event_log_messages_.begin(); + for (; event_it != it->event_log_messages_.end(); ++event_it) { + // TODO(pwestin): we need to send in the event_it->event_timestamp to + // the log system too. + switch (event_it->type) { + case kPacketReceived: + cast_environment_->Logging()->InsertPacketEvent(kPacketReceived, + rtp_timestamp, kFrameIdUnknown, event_it->packet_id, 0, 0); + break; + case kAckSent: + case kAudioFrameDecoded: + case kVideoFrameDecoded: + cast_environment_->Logging()->InsertFrameEvent(event_it->type, + rtp_timestamp, kFrameIdUnknown); + break; + case kAudioPlayoutDelay: + case kVideoRenderDelay: + cast_environment_->Logging()->InsertFrameEventWithDelay( + event_it->type, rtp_timestamp, kFrameIdUnknown, + event_it->delay_delta); + break; + default: + VLOG(2) << "Received log message via RTCP that we did not expect: " + << static_cast<int>(event_it->type); + break; + } + } + } + } + + virtual void OnReceivedSenderLog( + const RtcpSenderLogMessage& sender_log) OVERRIDE { + RtcpSenderLogMessage::const_iterator it = sender_log.begin(); + + for (; it != sender_log.end(); ++it) { + uint32 rtp_timestamp = it->rtp_timestamp; + CastLoggingEvent log_event = kUnknown; + + // These events are provided to know the status of frames that never + // reached the receiver. The timing information for these events are not + // relevant and is not sent over the wire. + switch (it->frame_status) { + case kRtcpSenderFrameStatusDroppedByFlowControl: + // A frame that have been dropped by the flow control would have + // kVideoFrameCaptured as its last event in the log. + log_event = kVideoFrameCaptured; + break; + case kRtcpSenderFrameStatusDroppedByEncoder: + // A frame that have been dropped by the encoder would have + // kVideoFrameSentToEncoder as its last event in the log. + log_event = kVideoFrameSentToEncoder; + break; + case kRtcpSenderFrameStatusSentToNetwork: + // A frame that have be encoded is always sent to the network. We + // do not add a new log entry for this. + log_event = kVideoFrameEncoded; + break; + default: + continue; + } + // TODO(pwestin): how do we handle the truncated rtp_timestamp? + // Add received log messages into our log system. + cast_environment_->Logging()->InsertFrameEvent(log_event, rtp_timestamp, + kFrameIdUnknown); + } + } + private: Rtcp* rtcp_; + scoped_refptr<CastEnvironment> cast_environment_; }; -Rtcp::Rtcp(RtcpSenderFeedback* sender_feedback, +Rtcp::Rtcp(scoped_refptr<CastEnvironment> cast_environment, + RtcpSenderFeedback* sender_feedback, PacedPacketSender* paced_packet_sender, RtpSenderStatistics* rtp_sender_statistics, RtpReceiverStatistics* rtp_receiver_statistics, RtcpMode rtcp_mode, const base::TimeDelta& rtcp_interval, - bool sending_media, uint32 local_ssrc, + uint32 remote_ssrc, const std::string& c_name) : rtcp_interval_(rtcp_interval), rtcp_mode_(rtcp_mode), - sending_media_(sending_media), local_ssrc_(local_ssrc), + remote_ssrc_(remote_ssrc), rtp_sender_statistics_(rtp_sender_statistics), rtp_receiver_statistics_(rtp_receiver_statistics), - receiver_feedback_(new LocalRtcpReceiverFeedback(this)), + receiver_feedback_(new LocalRtcpReceiverFeedback(this, cast_environment)), rtt_feedback_(new LocalRtcpRttFeedback(this)), - rtcp_sender_(new RtcpSender(paced_packet_sender, local_ssrc, c_name)), - last_report_sent_(0), + 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), min_rtt_(base::TimeDelta::FromMilliseconds(kMaxRttMs)), number_of_rtt_in_avg_(0), - clock_(&default_tick_clock_) { - rtcp_receiver_.reset(new RtcpReceiver(sender_feedback, + cast_environment_(cast_environment) { + rtcp_receiver_.reset(new RtcpReceiver(cast_environment, + sender_feedback, receiver_feedback_.get(), rtt_feedback_.get(), local_ssrc)); + rtcp_receiver_->SetRemoteSSRC(remote_ssrc); } Rtcp::~Rtcp() {} // static -bool Rtcp::IsRtcpPacket(const uint8* packet, int length) { - DCHECK_GE(length, 8) << "Invalid RTCP packet"; - if (length < 8) return false; +bool Rtcp::IsRtcpPacket(const uint8* packet, size_t length) { + DCHECK_GE(length, kMinLengthOfRtcp) << "Invalid RTCP packet"; + if (length < kMinLengthOfRtcp) return false; uint8 packet_type = packet[1]; if (packet_type >= kPacketTypeLow && packet_type <= kPacketTypeHigh) { @@ -131,7 +216,8 @@ bool Rtcp::IsRtcpPacket(const uint8* packet, int length) { } // static -uint32 Rtcp::GetSsrcOfSender(const uint8* rtcp_buffer, int length) { +uint32 Rtcp::GetSsrcOfSender(const uint8* rtcp_buffer, size_t length) { + DCHECK_GE(length, kMinLengthOfRtcp) << "Invalid RTCP packet"; uint32 ssrc_of_sender; net::BigEndianReader big_endian_reader(rtcp_buffer, length); big_endian_reader.Skip(4); // Skip header @@ -146,11 +232,7 @@ base::TimeTicks Rtcp::TimeToSendNextRtcpReport() { return next_time_to_send_rtcp_; } -void Rtcp::SetRemoteSSRC(uint32 ssrc) { - rtcp_receiver_->SetRemoteSSRC(ssrc); -} - -void Rtcp::IncomingRtcpPacket(const uint8* rtcp_buffer, int length) { +void Rtcp::IncomingRtcpPacket(const uint8* rtcp_buffer, size_t length) { RtcpParser rtcp_parser(rtcp_buffer, length); if (!rtcp_parser.IsValid()) { // Silently ignore packet. @@ -160,99 +242,38 @@ void Rtcp::IncomingRtcpPacket(const uint8* rtcp_buffer, int length) { rtcp_receiver_->IncomingRtcpPacket(&rtcp_parser); } -void Rtcp::SendRtcpCast(const RtcpCastMessage& cast_message) { - uint32 packet_type_flags = 0; - base::TimeTicks now = clock_->NowTicks(); - - if (rtcp_mode_ == kRtcpCompound || now >= next_time_to_send_rtcp_) { - if (sending_media_) { - packet_type_flags = RtcpSender::kRtcpSr; - } else { - packet_type_flags = RtcpSender::kRtcpRr; - } - } - packet_type_flags |= RtcpSender::kRtcpCast; - - SendRtcp(now, packet_type_flags, 0, &cast_message); -} - -void Rtcp::SendRtcpPli(uint32 pli_remote_ssrc) { +void Rtcp::SendRtcpFromRtpReceiver(const RtcpCastMessage* cast_message, + RtcpReceiverLogMessage* receiver_log) { uint32 packet_type_flags = 0; - base::TimeTicks now = clock_->NowTicks(); - if (rtcp_mode_ == kRtcpCompound || now >= next_time_to_send_rtcp_) { - if (sending_media_) { - packet_type_flags = RtcpSender::kRtcpSr; - } else { - packet_type_flags = RtcpSender::kRtcpRr; - } - } - packet_type_flags |= RtcpSender::kRtcpPli; - SendRtcp(now, packet_type_flags, pli_remote_ssrc, NULL); -} + base::TimeTicks now = cast_environment_->Clock()->NowTicks(); + RtcpReportBlock report_block; + RtcpReceiverReferenceTimeReport rrtr; -void Rtcp::SendRtcpReport(uint32 media_ssrc) { - uint32 packet_type_flags; - base::TimeTicks now = clock_->NowTicks(); - if (sending_media_) { - packet_type_flags = RtcpSender::kRtcpSr; - } else { - packet_type_flags = RtcpSender::kRtcpRr; + if (cast_message) { + packet_type_flags |= RtcpSender::kRtcpCast; + cast_environment_->Logging()->InsertGenericEvent(kAckSent, + cast_message->ack_frame_id_); } - SendRtcp(now, packet_type_flags, media_ssrc, NULL); -} - -void Rtcp::SendRtcp(const base::TimeTicks& now, - uint32 packet_type_flags, - uint32 media_ssrc, - const RtcpCastMessage* cast_message) { - if (packet_type_flags & RtcpSender::kRtcpSr || - packet_type_flags & RtcpSender::kRtcpRr) { - UpdateNextTimeToSendRtcp(); + if (receiver_log) { + packet_type_flags |= RtcpSender::kRtcpReceiverLog; } - if (packet_type_flags & RtcpSender::kRtcpSr) { - RtcpSenderInfo sender_info; - - if (rtp_sender_statistics_) { - rtp_sender_statistics_->GetStatistics(now, &sender_info); - } else { - memset(&sender_info, 0, sizeof(sender_info)); - } - time_last_report_sent_ = now; - last_report_sent_ = (sender_info.ntp_seconds << 16) + - (sender_info.ntp_fraction >> 16); - - RtcpDlrrReportBlock dlrr; - if (!time_last_report_received_.is_null()) { - packet_type_flags |= RtcpSender::kRtcpDlrr; - dlrr.last_rr = last_report_received_; - uint32 delay_seconds = 0; - uint32 delay_fraction = 0; - base::TimeDelta delta = now - time_last_report_received_; - ConvertTimeToFractions(delta.InMicroseconds(), - &delay_seconds, - &delay_fraction); + if (rtcp_mode_ == kRtcpCompound || now >= next_time_to_send_rtcp_) { + packet_type_flags |= RtcpSender::kRtcpRr; - dlrr.delay_since_last_rr = - ConvertToNtpDiff(delay_seconds, delay_fraction); - } - rtcp_sender_->SendRtcp(packet_type_flags, - &sender_info, - NULL, - media_ssrc, - &dlrr, - NULL, - NULL); - } else { - RtcpReportBlock report_block; report_block.remote_ssrc = 0; // Not needed to set send side. - report_block.media_ssrc = media_ssrc; // SSRC of the RTP packet sender. + 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); + cast_environment_->Logging()->InsertGenericEvent(kJitterMs, + report_block.jitter); + cast_environment_->Logging()->InsertGenericEvent(kPacketLoss, + report_block.fraction_lost); + } report_block.last_sr = last_report_received_; @@ -270,26 +291,59 @@ void Rtcp::SendRtcp(const base::TimeTicks& now, } packet_type_flags |= RtcpSender::kRtcpRrtr; - RtcpReceiverReferenceTimeReport rrtr; - ConvertTimeToNtp(now, &rrtr.ntp_seconds, &rrtr.ntp_fraction); - - time_last_report_sent_ = now; - last_report_sent_ = ConvertToNtpDiff(rrtr.ntp_seconds, rrtr.ntp_fraction); - - rtcp_sender_->SendRtcp(packet_type_flags, - NULL, - &report_block, - media_ssrc, - NULL, - &rrtr, - cast_message); + ConvertTimeTicksToNtp(now, &rrtr.ntp_seconds, &rrtr.ntp_fraction); + SaveLastSentNtpTime(now, rrtr.ntp_seconds, rrtr.ntp_fraction); + UpdateNextTimeToSendRtcp(); } + rtcp_sender_->SendRtcpFromRtpReceiver(packet_type_flags, + &report_block, + &rrtr, + cast_message, + receiver_log); +} + +void Rtcp::SendRtcpFromRtpSender( + RtcpSenderLogMessage* sender_log_message) { + uint32 packet_type_flags = RtcpSender::kRtcpSr; + base::TimeTicks now = cast_environment_->Clock()->NowTicks(); + + if (sender_log_message) { + packet_type_flags |= RtcpSender::kRtcpSenderLog; + } + + RtcpSenderInfo sender_info; + if (rtp_sender_statistics_) { + rtp_sender_statistics_->GetStatistics(now, &sender_info); + } else { + memset(&sender_info, 0, sizeof(sender_info)); + } + SaveLastSentNtpTime(now, sender_info.ntp_seconds, sender_info.ntp_fraction); + + RtcpDlrrReportBlock dlrr; + if (!time_last_report_received_.is_null()) { + packet_type_flags |= RtcpSender::kRtcpDlrr; + dlrr.last_rr = last_report_received_; + 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); + } + + rtcp_sender_->SendRtcpFromRtpSender(packet_type_flags, + &sender_info, + &dlrr, + sender_log_message); + UpdateNextTimeToSendRtcp(); } void Rtcp::OnReceivedNtp(uint32 ntp_seconds, uint32 ntp_fraction) { last_report_received_ = (ntp_seconds << 16) + (ntp_fraction >> 16); - base::TimeTicks now = clock_->NowTicks(); + base::TimeTicks now = cast_environment_->Clock()->NowTicks(); time_last_report_received_ = now; } @@ -302,7 +356,7 @@ void Rtcp::OnReceivedLipSyncInfo(uint32 rtp_timestamp, } void Rtcp::OnReceivedSendReportRequest() { - base::TimeTicks now = clock_->NowTicks(); + base::TimeTicks now = cast_environment_->Clock()->NowTicks(); // Trigger a new RTCP report at next timer. next_time_to_send_rtcp_ = now; @@ -333,22 +387,52 @@ bool Rtcp::RtpTimestampInSenderTime(int frequency, uint32 rtp_timestamp, // Sanity check. if (abs(rtp_time_diff_ms) > kMaxDiffSinceReceivedRtcpMs) return false; - *rtp_timestamp_in_ticks = - ConvertNtpToTime(last_received_ntp_seconds_, last_received_ntp_fraction_) + - base::TimeDelta::FromMilliseconds(rtp_time_diff_ms); + *rtp_timestamp_in_ticks = ConvertNtpToTimeTicks(last_received_ntp_seconds_, + last_received_ntp_fraction_) + + base::TimeDelta::FromMilliseconds(rtp_time_diff_ms); return true; } void Rtcp::OnReceivedDelaySinceLastReport(uint32 receivers_ssrc, uint32 last_report, uint32 delay_since_last_report) { - if (last_report_sent_ != last_report) return; // Feedback on another report. - if (time_last_report_sent_.is_null()) return; + RtcpSendTimeMap::iterator it = last_reports_sent_map_.find(last_report); + if (it == last_reports_sent_map_.end()) { + return; // Feedback on another report. + } - base::TimeDelta sender_delay = clock_->NowTicks() - time_last_report_sent_; + base::TimeDelta sender_delay = cast_environment_->Clock()->NowTicks() + - it->second; UpdateRtt(sender_delay, ConvertFromNtpDiff(delay_since_last_report)); } +void Rtcp::SaveLastSentNtpTime(const base::TimeTicks& now, + uint32 last_ntp_seconds, + uint32 last_ntp_fraction) { + // Make sure |now| is always greater than the last element in + // |last_reports_sent_queue_|. + if (!last_reports_sent_queue_.empty()) { + DCHECK(now >= last_reports_sent_queue_.back().second); + } + + uint32 last_report = ConvertToNtpDiff(last_ntp_seconds, last_ntp_fraction); + last_reports_sent_map_[last_report] = now; + last_reports_sent_queue_.push(std::make_pair(last_report, now)); + + base::TimeTicks timeout = now - base::TimeDelta::FromMilliseconds(kMaxRttMs); + + // Cleanup old statistics older than |timeout|. + while (!last_reports_sent_queue_.empty()) { + 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; + } + } +} + void Rtcp::UpdateRtt(const base::TimeDelta& sender_delay, const base::TimeDelta& receiver_delay) { base::TimeDelta rtt = sender_delay - receiver_delay; @@ -365,7 +449,6 @@ void Rtcp::UpdateRtt(const base::TimeDelta& sender_delay, avg_rtt_ms_ = rtt.InMilliseconds(); } number_of_rtt_in_avg_++; - TRACE_COUNTER_ID1("cast_rtcp", "RTT", local_ssrc_, rtt.InMilliseconds()); } bool Rtcp::Rtt(base::TimeDelta* rtt, @@ -377,7 +460,9 @@ bool Rtcp::Rtt(base::TimeDelta* rtt, DCHECK(min_rtt) << "Invalid argument"; DCHECK(max_rtt) << "Invalid argument"; - if (number_of_rtt_in_avg_ == 0) return false; + if (number_of_rtt_in_avg_ == 0) return false; + cast_environment_->Logging()->InsertGenericEvent(kRttMs, + rtt->InMilliseconds()); *rtt = rtt_; *avg_rtt = base::TimeDelta::FromMilliseconds(avg_rtt_ms_); @@ -408,7 +493,7 @@ void Rtcp::UpdateNextTimeToSendRtcp() { base::TimeDelta time_to_next = (rtcp_interval_ / 2) + (rtcp_interval_ * random / 1000); - base::TimeTicks now = clock_->NowTicks(); + base::TimeTicks now = cast_environment_->Clock()->NowTicks(); next_time_to_send_rtcp_ = now + time_to_next; } |