diff --git a/webrtc/call/call.cc b/webrtc/call/call.cc index f83d32050d..39357d57df 100644 --- a/webrtc/call/call.cc +++ b/webrtc/call/call.cc @@ -168,6 +168,8 @@ Call::Call(const Call::Config& config) config_.bitrate_config.min_bitrate_bps, config_.bitrate_config.start_bitrate_bps, config_.bitrate_config.max_bitrate_bps); + + congestion_controller_->GetBitrateController()->SetEventLog(event_log_); } Call::~Call() { diff --git a/webrtc/call/rtc_event_log.cc b/webrtc/call/rtc_event_log.cc index 550b556e80..abc2eb4709 100644 --- a/webrtc/call/rtc_event_log.cc +++ b/webrtc/call/rtc_event_log.cc @@ -54,6 +54,9 @@ class RtcEventLogImpl final : public RtcEventLog { const uint8_t* packet, size_t length) override {} void LogAudioPlayout(uint32_t ssrc) override {} + void LogBwePacketLossEvent(int32_t bitrate, + uint8_t fraction_loss, + int32_t total_packets) override {} }; #else // ENABLE_RTC_EVENT_LOG is defined @@ -78,6 +81,9 @@ class RtcEventLogImpl final : public RtcEventLog { const uint8_t* packet, size_t length) override; void LogAudioPlayout(uint32_t ssrc) override; + void LogBwePacketLossEvent(int32_t bitrate, + uint8_t fraction_loss, + int32_t total_packets) override; private: // Starts logging. This function assumes the file_ has been opened succesfully @@ -254,8 +260,7 @@ void RtcEventLogImpl::LogVideoReceiveStreamConfig( rtc::CritScope lock(&crit_); rtclog::Event event; - const int64_t timestamp = clock_->TimeInMicroseconds(); - event.set_timestamp_us(timestamp); + event.set_timestamp_us(clock_->TimeInMicroseconds()); event.set_type(rtclog::Event::VIDEO_RECEIVER_CONFIG_EVENT); rtclog::VideoReceiveConfig* receiver_config = @@ -296,8 +301,7 @@ void RtcEventLogImpl::LogVideoSendStreamConfig( rtc::CritScope lock(&crit_); rtclog::Event event; - const int64_t timestamp = clock_->TimeInMicroseconds(); - event.set_timestamp_us(timestamp); + event.set_timestamp_us(clock_->TimeInMicroseconds()); event.set_type(rtclog::Event::VIDEO_SENDER_CONFIG_EVENT); rtclog::VideoSendConfig* sender_config = event.mutable_video_sender_config(); @@ -348,8 +352,7 @@ void RtcEventLogImpl::LogRtpHeader(bool incoming, rtc::CritScope lock(&crit_); rtclog::Event rtp_event; - const int64_t timestamp = clock_->TimeInMicroseconds(); - rtp_event.set_timestamp_us(timestamp); + rtp_event.set_timestamp_us(clock_->TimeInMicroseconds()); rtp_event.set_type(rtclog::Event::RTP_EVENT); rtp_event.mutable_rtp_packet()->set_incoming(incoming); rtp_event.mutable_rtp_packet()->set_type(ConvertMediaType(media_type)); @@ -364,8 +367,7 @@ void RtcEventLogImpl::LogRtcpPacket(bool incoming, size_t length) { rtc::CritScope lock(&crit_); rtclog::Event rtcp_event; - const int64_t timestamp = clock_->TimeInMicroseconds(); - rtcp_event.set_timestamp_us(timestamp); + rtcp_event.set_timestamp_us(clock_->TimeInMicroseconds()); rtcp_event.set_type(rtclog::Event::RTCP_EVENT); rtcp_event.mutable_rtcp_packet()->set_incoming(incoming); rtcp_event.mutable_rtcp_packet()->set_type(ConvertMediaType(media_type)); @@ -376,21 +378,33 @@ void RtcEventLogImpl::LogRtcpPacket(bool incoming, void RtcEventLogImpl::LogAudioPlayout(uint32_t ssrc) { rtc::CritScope lock(&crit_); rtclog::Event event; - const int64_t timestamp = clock_->TimeInMicroseconds(); - event.set_timestamp_us(timestamp); + event.set_timestamp_us(clock_->TimeInMicroseconds()); event.set_type(rtclog::Event::AUDIO_PLAYOUT_EVENT); auto playout_event = event.mutable_audio_playout_event(); playout_event->set_local_ssrc(ssrc); HandleEvent(&event); } +void RtcEventLogImpl::LogBwePacketLossEvent(int32_t bitrate, + uint8_t fraction_loss, + int32_t total_packets) { + rtc::CritScope lock(&crit_); + rtclog::Event event; + event.set_timestamp_us(clock_->TimeInMicroseconds()); + event.set_type(rtclog::Event::BWE_PACKET_LOSS_EVENT); + auto bwe_event = event.mutable_bwe_packet_loss_event(); + bwe_event->set_bitrate(bitrate); + bwe_event->set_fraction_loss(fraction_loss); + bwe_event->set_total_packets(total_packets); + HandleEvent(&event); +} + void RtcEventLogImpl::StopLoggingLocked() { if (currently_logging_) { currently_logging_ = false; // Create a LogEnd event rtclog::Event event; - int64_t timestamp = clock_->TimeInMicroseconds(); - event.set_timestamp_us(timestamp); + event.set_timestamp_us(clock_->TimeInMicroseconds()); event.set_type(rtclog::Event::LOG_END); // Store the event and close the file RTC_DCHECK(file_->Open()); diff --git a/webrtc/call/rtc_event_log.h b/webrtc/call/rtc_event_log.h index 85d7525752..489687a195 100644 --- a/webrtc/call/rtc_event_log.h +++ b/webrtc/call/rtc_event_log.h @@ -77,6 +77,11 @@ class RtcEventLog { // Logs an audio playout event virtual void LogAudioPlayout(uint32_t ssrc) = 0; + // Logs a bitrate update from the bandwidth estimator based on packet loss. + virtual void LogBwePacketLossEvent(int32_t bitrate, + uint8_t fraction_loss, + int32_t total_packets) = 0; + // Reads an RtcEventLog file and returns true when reading was successful. // The result is stored in the given EventStream object. static bool ParseRtcEventLog(const std::string& file_name, diff --git a/webrtc/call/rtc_event_log.proto b/webrtc/call/rtc_event_log.proto index 6bdea7bd2f..e8ec99de99 100644 --- a/webrtc/call/rtc_event_log.proto +++ b/webrtc/call/rtc_event_log.proto @@ -34,10 +34,12 @@ message Event { RTP_EVENT = 3; RTCP_EVENT = 4; AUDIO_PLAYOUT_EVENT = 5; - VIDEO_RECEIVER_CONFIG_EVENT = 6; - VIDEO_SENDER_CONFIG_EVENT = 7; - AUDIO_RECEIVER_CONFIG_EVENT = 8; - AUDIO_SENDER_CONFIG_EVENT = 9; + BWE_PACKET_LOSS_EVENT = 6; + BWE_PACKET_DELAY_EVENT = 7; + VIDEO_RECEIVER_CONFIG_EVENT = 8; + VIDEO_SENDER_CONFIG_EVENT = 9; + AUDIO_RECEIVER_CONFIG_EVENT = 10; + AUDIO_SENDER_CONFIG_EVENT = 11; } // required - Indicates the type of this event @@ -52,17 +54,20 @@ message Event { // optional - but required if type == AUDIO_PLAYOUT_EVENT optional AudioPlayoutEvent audio_playout_event = 5; + // optional - but required if type == BWE_PACKET_LOSS_EVENT + optional BwePacketLossEvent bwe_packet_loss_event = 6; + // optional - but required if type == VIDEO_RECEIVER_CONFIG_EVENT - optional VideoReceiveConfig video_receiver_config = 6; + optional VideoReceiveConfig video_receiver_config = 8; // optional - but required if type == VIDEO_SENDER_CONFIG_EVENT - optional VideoSendConfig video_sender_config = 7; + optional VideoSendConfig video_sender_config = 9; // optional - but required if type == AUDIO_RECEIVER_CONFIG_EVENT - optional AudioReceiveConfig audio_receiver_config = 8; + optional AudioReceiveConfig audio_receiver_config = 10; // optional - but required if type == AUDIO_SENDER_CONFIG_EVENT - optional AudioSendConfig audio_sender_config = 9; + optional AudioSendConfig audio_sender_config = 11; } @@ -99,6 +104,19 @@ message AudioPlayoutEvent { optional uint32 local_ssrc = 2; } +message BwePacketLossEvent { + // required - Bandwidth estimate (in bps) after the update. + optional int32 bitrate = 1; + + // required - Fraction of lost packets since last receiver report + // computed as floor( 256 * (#lost_packets / #total_packets) ). + // The possible values range from 0 to 255. + optional uint32 fraction_loss = 2; + + // TODO(terelius): Is this really needed? Remove or make optional? + // required - Total number of packets that the BWE update is based on. + optional int32 total_packets = 3; +} // TODO(terelius): Video and audio streams could in principle share SSRC, // so identifying a stream based only on SSRC might not work. @@ -142,7 +160,7 @@ message DecoderConfig { optional string name = 1; // required - optional sint32 payload_type = 2; + optional int32 payload_type = 2; } @@ -152,7 +170,7 @@ message RtpHeaderExtension { optional string name = 1; // required - optional sint32 id = 2; + optional int32 id = 2; } @@ -163,13 +181,13 @@ message RtxConfig { optional uint32 rtx_ssrc = 1; // required - Payload type to use for the RTX stream. - optional sint32 rtx_payload_type = 2; + optional int32 rtx_payload_type = 2; } message RtxMap { // required - optional sint32 payload_type = 1; + optional int32 payload_type = 1; // required optional RtxConfig config = 2; @@ -189,7 +207,7 @@ message VideoSendConfig { repeated uint32 rtx_ssrcs = 3; // required if rtx_ssrcs is used - Payload type for retransmitted packets. - optional sint32 rtx_payload_type = 4; + optional int32 rtx_payload_type = 4; // required - Canonical end-point identifier. optional string c_name = 5; @@ -205,7 +223,7 @@ message EncoderConfig { optional string name = 1; // required - optional sint32 payload_type = 2; + optional int32 payload_type = 2; } diff --git a/webrtc/call/rtc_event_log_unittest.cc b/webrtc/call/rtc_event_log_unittest.cc index a4fdd13512..ff5abad99d 100644 --- a/webrtc/call/rtc_event_log_unittest.cc +++ b/webrtc/call/rtc_event_log_unittest.cc @@ -276,6 +276,21 @@ void VerifyPlayoutEvent(const rtclog::Event& event, uint32_t ssrc) { EXPECT_EQ(ssrc, playout_event.local_ssrc()); } +void VerifyBweLossEvent(const rtclog::Event& event, + int32_t bitrate, + uint8_t fraction_loss, + int32_t total_packets) { + ASSERT_TRUE(IsValidBasicEvent(event)); + ASSERT_EQ(rtclog::Event::BWE_PACKET_LOSS_EVENT, event.type()); + const rtclog::BwePacketLossEvent& bwe_event = event.bwe_packet_loss_event(); + ASSERT_TRUE(bwe_event.has_bitrate()); + EXPECT_EQ(bitrate, bwe_event.bitrate()); + ASSERT_TRUE(bwe_event.has_fraction_loss()); + EXPECT_EQ(fraction_loss, bwe_event.fraction_loss()); + ASSERT_TRUE(bwe_event.has_total_packets()); + EXPECT_EQ(total_packets, bwe_event.total_packets()); +} + void VerifyLogStartEvent(const rtclog::Event& event) { ASSERT_TRUE(IsValidBasicEvent(event)); EXPECT_EQ(rtclog::Event::LOG_START, event.type()); @@ -398,15 +413,18 @@ void GenerateVideoSendConfig(uint32_t extensions_bitvector, void LogSessionAndReadBack(size_t rtp_count, size_t rtcp_count, size_t playout_count, + size_t bwe_loss_count, uint32_t extensions_bitvector, uint32_t csrcs_count, unsigned int random_seed) { ASSERT_LE(rtcp_count, rtp_count); ASSERT_LE(playout_count, rtp_count); + ASSERT_LE(bwe_loss_count, rtp_count); std::vector rtp_packets; std::vector rtcp_packets; std::vector rtp_header_sizes; std::vector playout_ssrcs; + std::vector > bwe_loss_updates; VideoReceiveStream::Config receiver_config(nullptr); VideoSendStream::Config sender_config(nullptr); @@ -431,6 +449,10 @@ void LogSessionAndReadBack(size_t rtp_count, for (size_t i = 0; i < playout_count; i++) { playout_ssrcs.push_back(static_cast(rand())); } + // Create bwe_loss_count random bitrate updates for BwePacketLoss. + for (size_t i = 0; i < bwe_loss_count; i++) { + bwe_loss_updates.push_back(std::pair(rand(), rand())); + } // Create configurations for the video streams. GenerateVideoReceiveConfig(extensions_bitvector, &receiver_config); GenerateVideoSendConfig(extensions_bitvector, &sender_config); @@ -448,7 +470,9 @@ void LogSessionAndReadBack(size_t rtp_count, rtc::scoped_ptr log_dumper(RtcEventLog::Create()); log_dumper->LogVideoReceiveStreamConfig(receiver_config); log_dumper->LogVideoSendStreamConfig(sender_config); - size_t rtcp_index = 1, playout_index = 1; + size_t rtcp_index = 1; + size_t playout_index = 1; + size_t bwe_loss_index = 1; for (size_t i = 1; i <= rtp_count; i++) { log_dumper->LogRtpHeader( (i % 2 == 0), // Every second packet is incoming. @@ -466,6 +490,12 @@ void LogSessionAndReadBack(size_t rtp_count, log_dumper->LogAudioPlayout(playout_ssrcs[playout_index - 1]); playout_index++; } + if (i * bwe_loss_count >= bwe_loss_index * rtp_count) { + log_dumper->LogBwePacketLossEvent( + bwe_loss_updates[bwe_loss_index - 1].first, + bwe_loss_updates[bwe_loss_index - 1].second, i); + bwe_loss_index++; + } if (i == rtp_count / 2) { log_dumper->StartLogging(temp_filename, 10000000); } @@ -480,12 +510,15 @@ void LogSessionAndReadBack(size_t rtp_count, // Verify that what we read back from the event log is the same as // what we wrote down. For RTCP we log the full packets, but for // RTP we should only log the header. - const int event_count = - config_count + playout_count + rtcp_count + rtp_count + 1; + const int event_count = config_count + playout_count + bwe_loss_count + + rtcp_count + rtp_count + 1; EXPECT_EQ(event_count, parsed_stream.stream_size()); VerifyReceiveStreamConfig(parsed_stream.stream(0), receiver_config); VerifySendStreamConfig(parsed_stream.stream(1), sender_config); - size_t event_index = config_count, rtcp_index = 1, playout_index = 1; + size_t event_index = config_count; + size_t rtcp_index = 1; + size_t playout_index = 1; + size_t bwe_loss_index = 1; for (size_t i = 1; i <= rtp_count; i++) { VerifyRtpEvent(parsed_stream.stream(event_index), (i % 2 == 0), // Every second packet is incoming. @@ -508,6 +541,13 @@ void LogSessionAndReadBack(size_t rtp_count, event_index++; playout_index++; } + if (i * bwe_loss_count >= bwe_loss_index * rtp_count) { + VerifyBweLossEvent(parsed_stream.stream(event_index), + bwe_loss_updates[bwe_loss_index - 1].first, + bwe_loss_updates[bwe_loss_index - 1].second, i); + event_index++; + bwe_loss_index++; + } if (i == rtp_count / 2) { VerifyLogStartEvent(parsed_stream.stream(event_index)); event_index++; @@ -519,10 +559,11 @@ void LogSessionAndReadBack(size_t rtp_count, } TEST(RtcEventLogTest, LogSessionAndReadBack) { - // Log 5 RTP, 2 RTCP, and 0 playout events with no header extensions or CSRCS. - LogSessionAndReadBack(5, 2, 0, 0, 0, 321); + // Log 5 RTP, 2 RTCP, 0 playout events and 0 BWE events + // with no header extensions or CSRCS. + LogSessionAndReadBack(5, 2, 0, 0, 0, 0, 321); - // Enable AbsSendTime and TransportSequenceNumbers + // Enable AbsSendTime and TransportSequenceNumbers. uint32_t extensions = 0; for (uint32_t i = 0; i < kNumExtensions; i++) { if (kExtensionTypes[i] == RTPExtensionType::kRtpExtensionAbsoluteSendTime || @@ -531,19 +572,20 @@ TEST(RtcEventLogTest, LogSessionAndReadBack) { extensions |= 1u << i; } } - LogSessionAndReadBack(8, 2, 0, extensions, 0, 3141592653u); + LogSessionAndReadBack(8, 2, 0, 0, extensions, 0, 3141592653u); - extensions = (1u << kNumExtensions) - 1; // Enable all header extensions - LogSessionAndReadBack(9, 2, 3, extensions, 2, 2718281828u); + extensions = (1u << kNumExtensions) - 1; // Enable all header extensions. + LogSessionAndReadBack(9, 2, 3, 2, extensions, 2, 2718281828u); // Try all combinations of header extensions and up to 2 CSRCS. for (extensions = 0; extensions < (1u << kNumExtensions); extensions++) { for (uint32_t csrcs_count = 0; csrcs_count < 3; csrcs_count++) { LogSessionAndReadBack(5 + extensions, // Number of RTP packets. 2 + csrcs_count, // Number of RTCP packets. - 3 + csrcs_count, // Number of playout events - extensions, // Bit vector choosing extensions - csrcs_count, // Number of contributing sources + 3 + csrcs_count, // Number of playout events. + 1 + csrcs_count, // Number of BWE loss events. + extensions, // Bit vector choosing extensions. + csrcs_count, // Number of contributing sources. rand()); } } diff --git a/webrtc/modules/bitrate_controller/bitrate_controller_impl.cc b/webrtc/modules/bitrate_controller/bitrate_controller_impl.cc index d7795621af..f8fd2bb987 100644 --- a/webrtc/modules/bitrate_controller/bitrate_controller_impl.cc +++ b/webrtc/modules/bitrate_controller/bitrate_controller_impl.cc @@ -129,6 +129,11 @@ void BitrateControllerImpl::SetReservedBitrate(uint32_t reserved_bitrate_bps) { MaybeTriggerOnNetworkChanged(); } +void BitrateControllerImpl::SetEventLog(RtcEventLog* event_log) { + rtc::CritScope cs(&critsect_); + bandwidth_estimation_.SetEventLog(event_log); +} + void BitrateControllerImpl::OnReceivedEstimatedBitrate(uint32_t bitrate) { { rtc::CritScope cs(&critsect_); diff --git a/webrtc/modules/bitrate_controller/bitrate_controller_impl.h b/webrtc/modules/bitrate_controller/bitrate_controller_impl.h index a33a0e6f04..b601899631 100644 --- a/webrtc/modules/bitrate_controller/bitrate_controller_impl.h +++ b/webrtc/modules/bitrate_controller/bitrate_controller_impl.h @@ -41,6 +41,8 @@ class BitrateControllerImpl : public BitrateController { void SetReservedBitrate(uint32_t reserved_bitrate_bps) override; + void SetEventLog(RtcEventLog* event_log) override; + int64_t TimeUntilNextProcess() override; int32_t Process() override; diff --git a/webrtc/modules/bitrate_controller/include/bitrate_controller.h b/webrtc/modules/bitrate_controller/include/bitrate_controller.h index 5b20287c63..d1eca8e0fe 100644 --- a/webrtc/modules/bitrate_controller/include/bitrate_controller.h +++ b/webrtc/modules/bitrate_controller/include/bitrate_controller.h @@ -23,6 +23,7 @@ namespace webrtc { class CriticalSectionWrapper; +class RtcEventLog; struct PacketInfo; class BitrateObserver { @@ -56,6 +57,8 @@ class BitrateController : public Module { virtual void SetStartBitrate(int start_bitrate_bps) = 0; virtual void SetMinMaxBitrate(int min_bitrate_bps, int max_bitrate_bps) = 0; + virtual void SetEventLog(RtcEventLog* event_log) = 0; + // Gets the available payload bandwidth in bits per second. Note that // this bandwidth excludes packet headers. virtual bool AvailableBandwidth(uint32_t* bandwidth) const = 0; diff --git a/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.cc b/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.cc index 9fa7b0dfc0..c1c10e8262 100644 --- a/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.cc +++ b/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.cc @@ -16,6 +16,7 @@ #include "webrtc/system_wrappers/include/field_trial.h" #include "webrtc/system_wrappers/include/logging.h" #include "webrtc/system_wrappers/include/metrics.h" +#include "webrtc/call/rtc_event_log.h" namespace webrtc { namespace { @@ -59,7 +60,8 @@ SendSideBandwidthEstimation::SendSideBandwidthEstimation() initially_lost_packets_(0), bitrate_at_2_seconds_kbps_(0), uma_update_state_(kNoUpdate), - rampup_uma_stats_updated_(kNumUmaRampupMetrics, false) {} + rampup_uma_stats_updated_(kNumUmaRampupMetrics, false), + event_log_(nullptr) {} SendSideBandwidthEstimation::~SendSideBandwidthEstimation() {} @@ -206,6 +208,11 @@ void SendSideBandwidthEstimation::UpdateEstimate(int64_t now_ms) { // rates). bitrate_ += 1000; + if (event_log_) { + event_log_->LogBwePacketLossEvent( + bitrate_, last_fraction_loss_, + expected_packets_since_last_loss_update_); + } } else if (last_fraction_loss_ <= 26) { // Loss between 2% - 10%: Do nothing. } else { @@ -224,6 +231,11 @@ void SendSideBandwidthEstimation::UpdateEstimate(int64_t now_ms) { 512.0); has_decreased_since_last_fraction_loss_ = true; } + if (event_log_) { + event_log_->LogBwePacketLossEvent( + bitrate_, last_fraction_loss_, + expected_packets_since_last_loss_update_); + } } } bitrate_ = CapBitrateToThresholds(now_ms, bitrate_); @@ -274,4 +286,9 @@ uint32_t SendSideBandwidthEstimation::CapBitrateToThresholds( } return bitrate; } + +void SendSideBandwidthEstimation::SetEventLog(RtcEventLog* event_log) { + event_log_ = event_log; +} + } // namespace webrtc diff --git a/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.h b/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.h index baf8857559..7ffb42cb54 100644 --- a/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.h +++ b/webrtc/modules/bitrate_controller/send_side_bandwidth_estimation.h @@ -19,6 +19,9 @@ #include "webrtc/system_wrappers/include/critical_section_wrapper.h" namespace webrtc { + +class RtcEventLog; + class SendSideBandwidthEstimation { public: SendSideBandwidthEstimation(); @@ -42,6 +45,8 @@ class SendSideBandwidthEstimation { void SetMinMaxBitrate(int min_bitrate, int max_bitrate); int GetMinBitrate() const; + void SetEventLog(RtcEventLog* event_log); + private: enum UmaState { kNoUpdate, kFirstDone, kDone }; @@ -81,6 +86,7 @@ class SendSideBandwidthEstimation { int bitrate_at_2_seconds_kbps_; UmaState uma_update_state_; std::vector rampup_uma_stats_updated_; + RtcEventLog* event_log_; }; } // namespace webrtc #endif // WEBRTC_MODULES_BITRATE_CONTROLLER_SEND_SIDE_BANDWIDTH_ESTIMATION_H_