From 0baf55d23b6986c210006393e0fb1f8564204291 Mon Sep 17 00:00:00 2001 From: terelius Date: Fri, 17 Feb 2017 03:38:28 -0800 Subject: [PATCH] Add logging of delay-based bandwidth estimate. BUG=webrtc:6423 Review-Url: https://codereview.webrtc.org/2695923004 Cr-Commit-Position: refs/heads/master@{#16663} --- webrtc/logging/rtc_event_log/DEPS | 1 + .../rtc_event_log/mock/mock_rtc_event_log.h | 4 + webrtc/logging/rtc_event_log/rtc_event_log.cc | 27 ++++++ webrtc/logging/rtc_event_log/rtc_event_log.h | 9 +- .../logging/rtc_event_log/rtc_event_log.proto | 19 +++- .../rtc_event_log/rtc_event_log_parser.cc | 35 ++++++++ .../rtc_event_log/rtc_event_log_parser.h | 23 +++-- .../rtc_event_log/rtc_event_log_unittest.cc | 88 +++++++++++++++++++ .../rtc_event_log_unittest_helper.cc | 58 ++++++++++++ .../rtc_event_log_unittest_helper.h | 4 + webrtc/modules/congestion_controller/BUILD.gn | 1 + .../congestion_controller.cc | 2 +- .../congestion_controller/delay_based_bwe.cc | 15 +++- .../congestion_controller/delay_based_bwe.h | 7 +- .../delay_based_bwe_unittest.cc | 6 +- .../delay_based_bwe_unittest_helper.cc | 2 +- .../transport_feedback_adapter.cc | 5 +- .../transport_feedback_adapter.h | 6 +- .../transport_feedback_adapter_unittest.cc | 3 +- .../test/estimators/send_side.cc | 2 +- webrtc/tools/event_log_visualizer/analyzer.cc | 2 +- webrtc/voice_engine/channel.cc | 8 ++ 22 files changed, 305 insertions(+), 22 deletions(-) diff --git a/webrtc/logging/rtc_event_log/DEPS b/webrtc/logging/rtc_event_log/DEPS index e340150be7..58257f5ad8 100644 --- a/webrtc/logging/rtc_event_log/DEPS +++ b/webrtc/logging/rtc_event_log/DEPS @@ -2,6 +2,7 @@ include_rules = [ "+webrtc/base", "+webrtc/call", "+webrtc/modules/audio_coding/audio_network_adaptor", + "+webrtc/modules/remote_bitrate_estimator/include", "+webrtc/modules/rtp_rtcp", "+webrtc/system_wrappers", ] diff --git a/webrtc/logging/rtc_event_log/mock/mock_rtc_event_log.h b/webrtc/logging/rtc_event_log/mock/mock_rtc_event_log.h index 4db33a13ec..a47aa65cc8 100644 --- a/webrtc/logging/rtc_event_log/mock/mock_rtc_event_log.h +++ b/webrtc/logging/rtc_event_log/mock/mock_rtc_event_log.h @@ -58,6 +58,10 @@ class MockRtcEventLog : public RtcEventLog { void(int32_t bitrate, uint8_t fraction_loss, int32_t total_packets)); + + MOCK_METHOD2(LogBwePacketDelayEvent, + void(int32_t bitrate, BandwidthUsage detector_state)); + MOCK_METHOD1(LogAudioNetworkAdaptation, void(const AudioNetworkAdaptor::EncoderRuntimeConfig& config)); }; diff --git a/webrtc/logging/rtc_event_log/rtc_event_log.cc b/webrtc/logging/rtc_event_log/rtc_event_log.cc index b545d6453d..96f1ea1d80 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log.cc @@ -77,6 +77,8 @@ class RtcEventLogImpl final : public RtcEventLog { void LogBwePacketLossEvent(int32_t bitrate, uint8_t fraction_loss, int32_t total_packets) override; + void LogBwePacketDelayEvent(int32_t bitrate, + BandwidthUsage detector_state) override; void LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override; @@ -129,6 +131,20 @@ rtclog::MediaType ConvertMediaType(MediaType media_type) { return rtclog::ANY; } +rtclog::BwePacketDelayEvent::DetectorState ConvertDetectorState( + BandwidthUsage state) { + switch (state) { + case BandwidthUsage::kBwNormal: + return rtclog::BwePacketDelayEvent::BWE_NORMAL; + case BandwidthUsage::kBwUnderusing: + return rtclog::BwePacketDelayEvent::BWE_UNDERUSING; + case BandwidthUsage::kBwOverusing: + return rtclog::BwePacketDelayEvent::BWE_OVERUSING; + } + RTC_NOTREACHED(); + return rtclog::BwePacketDelayEvent::BWE_NORMAL; +} + // The RTP and RTCP buffers reserve space for twice the expected number of // sent packets because they also contain received packets. static const int kEventsPerSecond = 1000; @@ -436,6 +452,17 @@ void RtcEventLogImpl::LogBwePacketLossEvent(int32_t bitrate, StoreEvent(&event); } +void RtcEventLogImpl::LogBwePacketDelayEvent(int32_t bitrate, + BandwidthUsage detector_state) { + std::unique_ptr event(new rtclog::Event()); + event->set_timestamp_us(rtc::TimeMicros()); + event->set_type(rtclog::Event::BWE_PACKET_DELAY_EVENT); + auto bwe_event = event->mutable_bwe_packet_delay_event(); + bwe_event->set_bitrate(bitrate); + bwe_event->set_detector_state(ConvertDetectorState(detector_state)); + StoreEvent(&event); +} + void RtcEventLogImpl::LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) { std::unique_ptr event(new rtclog::Event()); diff --git a/webrtc/logging/rtc_event_log/rtc_event_log.h b/webrtc/logging/rtc_event_log/rtc_event_log.h index 5d221d4ef8..766fd89bc2 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log.h +++ b/webrtc/logging/rtc_event_log/rtc_event_log.h @@ -18,6 +18,7 @@ #include "webrtc/call/audio_receive_stream.h" #include "webrtc/call/audio_send_stream.h" #include "webrtc/modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor.h" +#include "webrtc/modules/remote_bitrate_estimator/include/bwe_defines.h" #include "webrtc/video_receive_stream.h" #include "webrtc/video_send_stream.h" @@ -115,6 +116,10 @@ class RtcEventLog { uint8_t fraction_loss, int32_t total_packets) = 0; + // Logs a bitrate update from the bandwidth estimator based on delay changes. + virtual void LogBwePacketDelayEvent(int32_t bitrate, + BandwidthUsage detector_state) = 0; + // Logs audio encoder re-configuration driven by audio network adaptor. virtual void LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) = 0; @@ -160,8 +165,10 @@ class RtcEventLogNullImpl final : public RtcEventLog { void LogBwePacketLossEvent(int32_t bitrate, uint8_t fraction_loss, int32_t total_packets) override {} + void LogBwePacketDelayEvent(int32_t bitrate, + BandwidthUsage detector_state) override {} void LogAudioNetworkAdaptation( - const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override{}; + const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override {} }; } // namespace webrtc diff --git a/webrtc/logging/rtc_event_log/rtc_event_log.proto b/webrtc/logging/rtc_event_log/rtc_event_log.proto index e807722979..0da910a29f 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log.proto +++ b/webrtc/logging/rtc_event_log/rtc_event_log.proto @@ -55,6 +55,9 @@ message Event { // optional - but required if type == BWE_PACKET_LOSS_EVENT optional BwePacketLossEvent bwe_packet_loss_event = 6; + // optional - but required if type == BWE_PACKET_DELAY_EVENT + optional BwePacketDelayEvent bwe_packet_delay_event = 7; + // optional - but required if type == VIDEO_RECEIVER_CONFIG_EVENT optional VideoReceiveConfig video_receiver_config = 8; @@ -117,6 +120,20 @@ message BwePacketLossEvent { optional int32 total_packets = 3; } +message BwePacketDelayEvent { + enum DetectorState { + BWE_NORMAL = 0; + BWE_UNDERUSING = 1; + BWE_OVERUSING = 2; + } + + // required - Bandwidth estimate (in bps) after the update. + optional int32 bitrate = 1; + + // required - The state of the overuse detector. + optional DetectorState detector_state = 2; +} + // TODO(terelius): Video and audio streams could in principle share SSRC, // so identifying a stream based only on SSRC might not work. // It might be better to use a combination of SSRC and media type @@ -251,4 +268,4 @@ message AudioNetworkAdaptation { // Number of audio channels that each encoded packet consists of. optional uint32 num_channels = 6; -} \ No newline at end of file +} diff --git a/webrtc/logging/rtc_event_log/rtc_event_log_parser.cc b/webrtc/logging/rtc_event_log/rtc_event_log_parser.cc index c1bf94458d..012b7e19da 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_parser.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log_parser.cc @@ -88,6 +88,20 @@ ParsedRtcEventLog::EventType GetRuntimeEventType( return ParsedRtcEventLog::EventType::UNKNOWN_EVENT; } +BandwidthUsage GetRuntimeDetectorState( + rtclog::BwePacketDelayEvent::DetectorState detector_state) { + switch (detector_state) { + case rtclog::BwePacketDelayEvent::BWE_NORMAL: + return kBwNormal; + case rtclog::BwePacketDelayEvent::BWE_UNDERUSING: + return kBwUnderusing; + case rtclog::BwePacketDelayEvent::BWE_OVERUSING: + return kBwOverusing; + } + RTC_NOTREACHED(); + return kBwNormal; +} + std::pair ParseVarInt(std::istream& stream) { uint64_t varint = 0; for (size_t bytes_read = 0; bytes_read < 10; ++bytes_read) { @@ -471,6 +485,27 @@ void ParsedRtcEventLog::GetBwePacketLossEvent(size_t index, } } +void ParsedRtcEventLog::GetBwePacketDelayEvent( + size_t index, + int32_t* bitrate, + BandwidthUsage* detector_state) const { + RTC_CHECK_LT(index, GetNumberOfEvents()); + const rtclog::Event& event = events_[index]; + RTC_CHECK(event.has_type()); + RTC_CHECK_EQ(event.type(), rtclog::Event::BWE_PACKET_DELAY_EVENT); + RTC_CHECK(event.has_bwe_packet_delay_event()); + const rtclog::BwePacketDelayEvent& delay_event = + event.bwe_packet_delay_event(); + RTC_CHECK(delay_event.has_bitrate()); + if (bitrate != nullptr) { + *bitrate = delay_event.bitrate(); + } + RTC_CHECK(delay_event.has_detector_state()); + if (detector_state != nullptr) { + *detector_state = GetRuntimeDetectorState(delay_event.detector_state()); + } +} + void ParsedRtcEventLog::GetAudioNetworkAdaptation( size_t index, AudioNetworkAdaptor::EncoderRuntimeConfig* config) const { diff --git a/webrtc/logging/rtc_event_log/rtc_event_log_parser.h b/webrtc/logging/rtc_event_log/rtc_event_log_parser.h index 8472668d75..c81b8fb10e 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_parser.h +++ b/webrtc/logging/rtc_event_log/rtc_event_log_parser.h @@ -71,8 +71,8 @@ class ParsedRtcEventLog { // Reads the header, direction, media type, header length and packet length // from the RTP event at |index|, and stores the values in the corresponding - // output parameters. The output parameters can be set to nullptr if those - // values aren't needed. + // output parameters. Each output parameter can be set to nullptr if that + // value isn't needed. // NB: The header must have space for at least IP_PACKET_SIZE bytes. void GetRtpHeader(size_t index, PacketDirection* incoming, @@ -83,7 +83,7 @@ class ParsedRtcEventLog { // Reads packet, direction, media type and packet length from the RTCP event // at |index|, and stores the values in the corresponding output parameters. - // The output parameters can be set to nullptr if those values aren't needed. + // Each output parameter can be set to nullptr if that value isn't needed. // NB: The packet must have space for at least IP_PACKET_SIZE bytes. void GetRtcpPacket(size_t index, PacketDirection* incoming, @@ -115,15 +115,24 @@ class ParsedRtcEventLog { void GetAudioPlayout(size_t index, uint32_t* ssrc) const; // Reads bitrate, fraction loss (as defined in RFC 1889) and total number of - // expected packets from the BWE event at |index| and stores the values in - // the corresponding output parameters. The output parameters can be set to - // nullptr if those values aren't needed. - // NB: The packet must have space for at least IP_PACKET_SIZE bytes. + // expected packets from the loss based BWE event at |index| and stores the + // values in + // the corresponding output parameters. Each output parameter can be set to + // nullptr if that + // value isn't needed. void GetBwePacketLossEvent(size_t index, int32_t* bitrate, uint8_t* fraction_loss, int32_t* total_packets) const; + // Reads bitrate and detector_state from the delay based BWE event at |index| + // and stores the values in the corresponding output parameters. Each output + // parameter can be set to nullptr if that + // value isn't needed. + void GetBwePacketDelayEvent(size_t index, + int32_t* bitrate, + BandwidthUsage* detector_state) const; + // Reads a audio network adaptation event to a (non-NULL) // AudioNetworkAdaptor::EncoderRuntimeConfig struct. Only the fields that are // stored in the protobuf will be written. diff --git a/webrtc/logging/rtc_event_log/rtc_event_log_unittest.cc b/webrtc/logging/rtc_event_log/rtc_event_log_unittest.cc index 97c82b3609..1173bf57df 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_unittest.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log_unittest.cc @@ -500,6 +500,94 @@ TEST(RtcEventLogTest, LogEventAndReadBack) { remove(temp_filename.c_str()); } +TEST(RtcEventLogTest, LogPacketLossEventAndReadBack) { + Random prng(1234); + + // Generate a random packet loss event. + int32_t bitrate = prng.Rand(0, 10000000); + uint8_t fraction_lost = prng.Rand(); + int32_t total_packets = prng.Rand(1, 1000); + + // Find the name of the current test, in order to use it as a temporary + // filename. + auto test_info = ::testing::UnitTest::GetInstance()->current_test_info(); + const std::string temp_filename = + test::OutputPath() + test_info->test_case_name() + test_info->name(); + + // Start logging, add the packet loss event and then stop logging. + rtc::ScopedFakeClock fake_clock; + fake_clock.SetTimeMicros(prng.Rand()); + std::unique_ptr log_dumper(RtcEventLog::Create()); + log_dumper->StartLogging(temp_filename, 10000000); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogBwePacketLossEvent(bitrate, fraction_lost, total_packets); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->StopLogging(); + + // Read the generated file from disk. + ParsedRtcEventLog parsed_log; + ASSERT_TRUE(parsed_log.ParseFile(temp_filename)); + + // Verify that what we read back from the event log is the same as + // what we wrote down. + EXPECT_EQ(3u, parsed_log.GetNumberOfEvents()); + RtcEventLogTestHelper::VerifyLogStartEvent(parsed_log, 0); + RtcEventLogTestHelper::VerifyBweLossEvent(parsed_log, 1, bitrate, + fraction_lost, total_packets); + RtcEventLogTestHelper::VerifyLogEndEvent(parsed_log, 2); + + // Clean up temporary file - can be pretty slow. + remove(temp_filename.c_str()); +} + +TEST(RtcEventLogTest, LogPacketDelayEventAndReadBack) { + Random prng(1234); + + // Generate 3 random packet delay event. + int32_t bitrate1 = prng.Rand(0, 10000000); + int32_t bitrate2 = prng.Rand(0, 10000000); + int32_t bitrate3 = prng.Rand(0, 10000000); + + // Find the name of the current test, in order to use it as a temporary + // filename. + auto test_info = ::testing::UnitTest::GetInstance()->current_test_info(); + const std::string temp_filename = + test::OutputPath() + test_info->test_case_name() + test_info->name(); + + // Start logging, add the packet delay events and then stop logging. + rtc::ScopedFakeClock fake_clock; + fake_clock.SetTimeMicros(prng.Rand()); + std::unique_ptr log_dumper(RtcEventLog::Create()); + log_dumper->StartLogging(temp_filename, 10000000); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogBwePacketDelayEvent(bitrate1, kBwNormal); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogBwePacketDelayEvent(bitrate2, kBwOverusing); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogBwePacketDelayEvent(bitrate3, kBwUnderusing); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->StopLogging(); + + // Read the generated file from disk. + ParsedRtcEventLog parsed_log; + ASSERT_TRUE(parsed_log.ParseFile(temp_filename)); + + // Verify that what we read back from the event log is the same as + // what we wrote down. + EXPECT_EQ(5u, parsed_log.GetNumberOfEvents()); + RtcEventLogTestHelper::VerifyLogStartEvent(parsed_log, 0); + RtcEventLogTestHelper::VerifyBweDelayEvent(parsed_log, 1, bitrate1, + kBwNormal); + RtcEventLogTestHelper::VerifyBweDelayEvent(parsed_log, 2, bitrate2, + kBwOverusing); + RtcEventLogTestHelper::VerifyBweDelayEvent(parsed_log, 3, bitrate3, + kBwUnderusing); + RtcEventLogTestHelper::VerifyLogEndEvent(parsed_log, 4); + + // Clean up temporary file - can be pretty slow. + remove(temp_filename.c_str()); +} + class ConfigReadWriteTest { public: ConfigReadWriteTest() : prng(987654321) {} diff --git a/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.cc b/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.cc index 5bd8e4d060..6d92b46ce4 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.cc @@ -42,6 +42,20 @@ MediaType GetRuntimeMediaType(rtclog::MediaType media_type) { RTC_NOTREACHED(); return MediaType::ANY; } + +BandwidthUsage GetRuntimeDetectorState( + rtclog::BwePacketDelayEvent::DetectorState detector_state) { + switch (detector_state) { + case rtclog::BwePacketDelayEvent::BWE_NORMAL: + return kBwNormal; + case rtclog::BwePacketDelayEvent::BWE_UNDERUSING: + return kBwUnderusing; + case rtclog::BwePacketDelayEvent::BWE_OVERUSING: + return kBwOverusing; + } + RTC_NOTREACHED(); + return kBwNormal; +} } // namespace // Checks that the event has a timestamp, a type and exactly the data field @@ -64,6 +78,19 @@ MediaType GetRuntimeMediaType(rtclog::MediaType media_type) { << "Event of type " << type << " has " << (event.has_rtcp_packet() ? "" : "no ") << "RTCP packet"; } + if ((type == rtclog::Event::BWE_PACKET_LOSS_EVENT) != + event.has_bwe_packet_loss_event()) { + return ::testing::AssertionFailure() + << "Event of type " << type << " has " + << (event.has_bwe_packet_loss_event() ? "" : "no ") << "packet loss"; + } + if ((type == rtclog::Event::BWE_PACKET_DELAY_EVENT) != + event.has_bwe_packet_delay_event()) { + return ::testing::AssertionFailure() + << "Event of type " << type << " has " + << (event.has_bwe_packet_delay_event() ? "" : "no ") + << "packet delay"; + } if ((type == rtclog::Event::AUDIO_PLAYOUT_EVENT) != event.has_audio_playout_event()) { return ::testing::AssertionFailure() @@ -98,6 +125,13 @@ MediaType GetRuntimeMediaType(rtclog::MediaType media_type) { << (event.has_audio_sender_config() ? "" : "no ") << "audio sender config"; } + if ((type == rtclog::Event::AUDIO_NETWORK_ADAPTATION_EVENT) != + event.has_audio_network_adaptation()) { + return ::testing::AssertionFailure() + << "Event of type " << type << " has " + << (event.has_audio_network_adaptation() ? "" : "no ") + << "audio network adaptation"; + } return ::testing::AssertionSuccess(); } @@ -461,6 +495,30 @@ void RtcEventLogTestHelper::VerifyBweLossEvent( EXPECT_EQ(total_packets, parsed_total_packets); } +void RtcEventLogTestHelper::VerifyBweDelayEvent( + const ParsedRtcEventLog& parsed_log, + size_t index, + int32_t bitrate, + BandwidthUsage detector_state) { + const rtclog::Event& event = parsed_log.events_[index]; + ASSERT_TRUE(IsValidBasicEvent(event)); + ASSERT_EQ(rtclog::Event::BWE_PACKET_DELAY_EVENT, event.type()); + const rtclog::BwePacketDelayEvent& bwe_event = event.bwe_packet_delay_event(); + ASSERT_TRUE(bwe_event.has_bitrate()); + EXPECT_EQ(bitrate, bwe_event.bitrate()); + ASSERT_TRUE(bwe_event.has_detector_state()); + EXPECT_EQ(detector_state, + GetRuntimeDetectorState(bwe_event.detector_state())); + + // Check consistency of the parser. + int32_t parsed_bitrate; + BandwidthUsage parsed_detector_state; + parsed_log.GetBwePacketDelayEvent(index, &parsed_bitrate, + &parsed_detector_state); + EXPECT_EQ(bitrate, parsed_bitrate); + EXPECT_EQ(detector_state, parsed_detector_state); +} + void RtcEventLogTestHelper::VerifyAudioNetworkAdaptation( const ParsedRtcEventLog& parsed_log, size_t index, diff --git a/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.h b/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.h index 2f4e17703b..5efb8c8bda 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.h +++ b/webrtc/logging/rtc_event_log/rtc_event_log_unittest_helper.h @@ -55,6 +55,10 @@ class RtcEventLogTestHelper { int32_t bitrate, uint8_t fraction_loss, int32_t total_packets); + static void VerifyBweDelayEvent(const ParsedRtcEventLog& parsed_log, + size_t index, + int32_t bitrate, + BandwidthUsage detector_state); static void VerifyAudioNetworkAdaptation( const ParsedRtcEventLog& parsed_log, diff --git a/webrtc/modules/congestion_controller/BUILD.gn b/webrtc/modules/congestion_controller/BUILD.gn index a20339cd78..787464aae2 100644 --- a/webrtc/modules/congestion_controller/BUILD.gn +++ b/webrtc/modules/congestion_controller/BUILD.gn @@ -47,6 +47,7 @@ rtc_static_library("congestion_controller") { "../../base:rtc_base", "../../base:rtc_base_approved", "../../base:rtc_numerics", + "../../logging:rtc_event_log_api", "../../system_wrappers", "../bitrate_controller", "../pacing", diff --git a/webrtc/modules/congestion_controller/congestion_controller.cc b/webrtc/modules/congestion_controller/congestion_controller.cc index 81fe916e04..34b174ebc6 100644 --- a/webrtc/modules/congestion_controller/congestion_controller.cc +++ b/webrtc/modules/congestion_controller/congestion_controller.cc @@ -169,7 +169,7 @@ CongestionController::CongestionController( new RateLimiter(clock, kRetransmitWindowSizeMs)), remote_bitrate_estimator_(remote_bitrate_observer, clock_), remote_estimator_proxy_(clock_, packet_router_), - transport_feedback_adapter_(clock_, bitrate_controller_.get()), + transport_feedback_adapter_(event_log, clock_, bitrate_controller_.get()), min_bitrate_bps_(congestion_controller::GetMinBitrateBps()), max_bitrate_bps_(0), last_reported_bitrate_bps_(0), diff --git a/webrtc/modules/congestion_controller/delay_based_bwe.cc b/webrtc/modules/congestion_controller/delay_based_bwe.cc index fb914828dc..b89daab7d1 100644 --- a/webrtc/modules/congestion_controller/delay_based_bwe.cc +++ b/webrtc/modules/congestion_controller/delay_based_bwe.cc @@ -18,6 +18,7 @@ #include "webrtc/base/constructormagic.h" #include "webrtc/base/logging.h" #include "webrtc/base/thread_annotations.h" +#include "webrtc/logging/rtc_event_log/rtc_event_log.h" #include "webrtc/modules/congestion_controller/include/congestion_controller.h" #include "webrtc/modules/pacing/paced_sender.h" #include "webrtc/modules/remote_bitrate_estimator/include/remote_bitrate_estimator.h" @@ -208,9 +209,10 @@ rtc::Optional DelayBasedBwe::BitrateEstimator::bitrate_bps() const { return rtc::Optional(bitrate_estimate_ * 1000); } -DelayBasedBwe::DelayBasedBwe(Clock* clock) +DelayBasedBwe::DelayBasedBwe(RtcEventLog* event_log, Clock* clock) : in_trendline_experiment_(TrendlineFilterExperimentIsEnabled()), in_median_slope_experiment_(MedianSlopeFilterExperimentIsEnabled()), + event_log_(event_log), clock_(clock), inter_arrival_(), kalman_estimator_(), @@ -226,7 +228,9 @@ DelayBasedBwe::DelayBasedBwe(Clock* clock) probing_interval_estimator_(&rate_control_), median_slope_window_size_(kDefaultMedianSlopeWindowSize), median_slope_threshold_gain_(kDefaultMedianSlopeThresholdGain), - consecutive_delayed_feedbacks_(0) { + consecutive_delayed_feedbacks_(0), + last_logged_bitrate_(0), + last_logged_state_(kBwNormal) { if (in_trendline_experiment_) { ReadTrendlineFilterExperimentParameters(&trendline_window_size_, &trendline_smoothing_coeff_, @@ -389,6 +393,13 @@ DelayBasedBwe::Result DelayBasedBwe::IncomingPacketInfo( last_update_ms_ = now_ms; BWE_TEST_LOGGING_PLOT(1, "target_bitrate_bps", now_ms, result.target_bitrate_bps); + if (event_log_ && (result.target_bitrate_bps != last_logged_bitrate_ || + detector_.State() != last_logged_state_)) { + event_log_->LogBwePacketDelayEvent(result.target_bitrate_bps, + detector_.State()); + last_logged_bitrate_ = result.target_bitrate_bps; + last_logged_state_ = detector_.State(); + } } return result; diff --git a/webrtc/modules/congestion_controller/delay_based_bwe.h b/webrtc/modules/congestion_controller/delay_based_bwe.h index d1a9676d59..c02182bdd3 100644 --- a/webrtc/modules/congestion_controller/delay_based_bwe.h +++ b/webrtc/modules/congestion_controller/delay_based_bwe.h @@ -31,6 +31,8 @@ namespace webrtc { +class RtcEventLog; + class DelayBasedBwe { public: static const int64_t kStreamTimeOutMs = 2000; @@ -44,7 +46,7 @@ class DelayBasedBwe { uint32_t target_bitrate_bps; }; - explicit DelayBasedBwe(Clock* clock); + DelayBasedBwe(RtcEventLog* event_log, Clock* clock); virtual ~DelayBasedBwe() {} Result IncomingPacketFeedbackVector( @@ -91,6 +93,7 @@ class DelayBasedBwe { const bool in_median_slope_experiment_; rtc::ThreadChecker network_thread_; + RtcEventLog* const event_log_; Clock* const clock_; std::unique_ptr inter_arrival_; std::unique_ptr kalman_estimator_; @@ -110,6 +113,8 @@ class DelayBasedBwe { size_t median_slope_window_size_; double median_slope_threshold_gain_; int consecutive_delayed_feedbacks_; + uint32_t last_logged_bitrate_; + BandwidthUsage last_logged_state_; RTC_DISALLOW_IMPLICIT_CONSTRUCTORS(DelayBasedBwe); }; diff --git a/webrtc/modules/congestion_controller/delay_based_bwe_unittest.cc b/webrtc/modules/congestion_controller/delay_based_bwe_unittest.cc index 4f0829ac62..dd24b53272 100644 --- a/webrtc/modules/congestion_controller/delay_based_bwe_unittest.cc +++ b/webrtc/modules/congestion_controller/delay_based_bwe_unittest.cc @@ -174,7 +174,7 @@ class DelayBasedBweExperimentTest : public DelayBasedBweTest { public: DelayBasedBweExperimentTest() : override_field_trials_("WebRTC-ImprovedBitrateEstimate/Enabled/") { - bitrate_estimator_.reset(new DelayBasedBwe(&clock_)); + bitrate_estimator_.reset(new DelayBasedBwe(nullptr, &clock_)); } private: @@ -205,7 +205,7 @@ class DelayBasedBweTrendlineExperimentTest : public DelayBasedBweTest { public: DelayBasedBweTrendlineExperimentTest() : override_field_trials_("WebRTC-BweTrendlineFilter/Enabled-15,0.9,4/") { - bitrate_estimator_.reset(new DelayBasedBwe(&clock_)); + bitrate_estimator_.reset(new DelayBasedBwe(nullptr, &clock_)); } private: @@ -236,7 +236,7 @@ class DelayBasedBweMedianSlopeExperimentTest : public DelayBasedBweTest { public: DelayBasedBweMedianSlopeExperimentTest() : override_field_trials_("WebRTC-BweMedianSlopeFilter/Enabled-20,4/") { - bitrate_estimator_.reset(new DelayBasedBwe(&clock_)); + bitrate_estimator_.reset(new DelayBasedBwe(nullptr, &clock_)); } private: diff --git a/webrtc/modules/congestion_controller/delay_based_bwe_unittest_helper.cc b/webrtc/modules/congestion_controller/delay_based_bwe_unittest_helper.cc index 9aafc7b516..4eaaad2920 100644 --- a/webrtc/modules/congestion_controller/delay_based_bwe_unittest_helper.cc +++ b/webrtc/modules/congestion_controller/delay_based_bwe_unittest_helper.cc @@ -150,7 +150,7 @@ int64_t StreamGenerator::GenerateFrame(std::vector* packets, DelayBasedBweTest::DelayBasedBweTest() : clock_(100000000), - bitrate_estimator_(new DelayBasedBwe(&clock_)), + bitrate_estimator_(new DelayBasedBwe(nullptr, &clock_)), stream_generator_(new test::StreamGenerator(1e6, // Capacity. clock_.TimeInMicroseconds())), arrival_time_offset_ms_(0), diff --git a/webrtc/modules/congestion_controller/transport_feedback_adapter.cc b/webrtc/modules/congestion_controller/transport_feedback_adapter.cc index c4be2b1c0b..e0d7da0901 100644 --- a/webrtc/modules/congestion_controller/transport_feedback_adapter.cc +++ b/webrtc/modules/congestion_controller/transport_feedback_adapter.cc @@ -15,6 +15,7 @@ #include "webrtc/base/checks.h" #include "webrtc/base/logging.h" +#include "webrtc/logging/rtc_event_log/rtc_event_log.h" #include "webrtc/modules/bitrate_controller/include/bitrate_controller.h" #include "webrtc/modules/congestion_controller/delay_based_bwe.h" #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h" @@ -41,6 +42,7 @@ class PacketInfoComparator { }; TransportFeedbackAdapter::TransportFeedbackAdapter( + RtcEventLog* event_log, Clock* clock, BitrateController* bitrate_controller) : send_side_bwe_with_overhead_(webrtc::field_trial::FindFullName( @@ -48,6 +50,7 @@ TransportFeedbackAdapter::TransportFeedbackAdapter( "Enabled"), transport_overhead_bytes_per_packet_(0), send_time_history_(clock, kSendTimeHistoryWindowMs), + event_log_(event_log), clock_(clock), current_offset_ms_(kNoTimestamp), last_timestamp_us_(kNoTimestamp), @@ -57,7 +60,7 @@ TransportFeedbackAdapter::~TransportFeedbackAdapter() {} void TransportFeedbackAdapter::InitBwe() { rtc::CritScope cs(&bwe_lock_); - delay_based_bwe_.reset(new DelayBasedBwe(clock_)); + delay_based_bwe_.reset(new DelayBasedBwe(event_log_, clock_)); } void TransportFeedbackAdapter::AddPacket(uint16_t sequence_number, diff --git a/webrtc/modules/congestion_controller/transport_feedback_adapter.h b/webrtc/modules/congestion_controller/transport_feedback_adapter.h index 632f125aa6..f68d2af926 100644 --- a/webrtc/modules/congestion_controller/transport_feedback_adapter.h +++ b/webrtc/modules/congestion_controller/transport_feedback_adapter.h @@ -24,12 +24,15 @@ namespace webrtc { class BitrateController; +class RtcEventLog; class ProcessThread; class TransportFeedbackAdapter : public TransportFeedbackObserver, public CallStatsObserver { public: - TransportFeedbackAdapter(Clock* clock, BitrateController* bitrate_controller); + TransportFeedbackAdapter(RtcEventLog* event_log, + Clock* clock, + BitrateController* bitrate_controller); virtual ~TransportFeedbackAdapter(); void InitBwe(); @@ -64,6 +67,7 @@ class TransportFeedbackAdapter : public TransportFeedbackObserver, int transport_overhead_bytes_per_packet_ GUARDED_BY(&lock_); SendTimeHistory send_time_history_ GUARDED_BY(&lock_); std::unique_ptr delay_based_bwe_ GUARDED_BY(&bwe_lock_); + RtcEventLog* const event_log_; Clock* const clock_; int64_t current_offset_ms_; int64_t last_timestamp_us_; diff --git a/webrtc/modules/congestion_controller/transport_feedback_adapter_unittest.cc b/webrtc/modules/congestion_controller/transport_feedback_adapter_unittest.cc index 438a0fccc0..184b416e3b 100644 --- a/webrtc/modules/congestion_controller/transport_feedback_adapter_unittest.cc +++ b/webrtc/modules/congestion_controller/transport_feedback_adapter_unittest.cc @@ -36,7 +36,8 @@ class TransportFeedbackAdapterTest : public ::testing::Test { virtual ~TransportFeedbackAdapterTest() {} virtual void SetUp() { - adapter_.reset(new TransportFeedbackAdapter(&clock_, &bitrate_controller_)); + adapter_.reset( + new TransportFeedbackAdapter(nullptr, &clock_, &bitrate_controller_)); adapter_->InitBwe(); adapter_->SetStartBitrate(300000); } diff --git a/webrtc/modules/remote_bitrate_estimator/test/estimators/send_side.cc b/webrtc/modules/remote_bitrate_estimator/test/estimators/send_side.cc index 0203a910d8..4a384a0705 100644 --- a/webrtc/modules/remote_bitrate_estimator/test/estimators/send_side.cc +++ b/webrtc/modules/remote_bitrate_estimator/test/estimators/send_side.cc @@ -29,7 +29,7 @@ SendSideBweSender::SendSideBweSender(int kbps, BitrateController::CreateBitrateController(clock, observer, &event_log_)), - bwe_(new DelayBasedBwe(clock)), + bwe_(new DelayBasedBwe(nullptr, clock)), feedback_observer_(bitrate_controller_->CreateRtcpBandwidthObserver()), clock_(clock), send_time_history_(clock_, 10000), diff --git a/webrtc/tools/event_log_visualizer/analyzer.cc b/webrtc/tools/event_log_visualizer/analyzer.cc index 90eb5b3f12..f49356e2a5 100644 --- a/webrtc/tools/event_log_visualizer/analyzer.cc +++ b/webrtc/tools/event_log_visualizer/analyzer.cc @@ -1133,7 +1133,7 @@ void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) { SimulatedClock clock(0); NullBitrateController null_controller; - TransportFeedbackAdapter feedback_adapter(&clock, &null_controller); + TransportFeedbackAdapter feedback_adapter(nullptr, &clock, &null_controller); feedback_adapter.InitBwe(); TimeSeries time_series; diff --git a/webrtc/voice_engine/channel.cc b/webrtc/voice_engine/channel.cc index 006e3db69b..b0aa654f27 100644 --- a/webrtc/voice_engine/channel.cc +++ b/webrtc/voice_engine/channel.cc @@ -139,6 +139,14 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { } } + void LogBwePacketDelayEvent(int32_t bitrate, + BandwidthUsage detector_state) override { + rtc::CritScope lock(&crit_); + if (event_log_) { + event_log_->LogBwePacketDelayEvent(bitrate, detector_state); + } + } + void LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override { rtc::CritScope lock(&crit_);