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 7366c2947b..fcc57004f0 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 @@ -46,6 +46,13 @@ class MockRtcEventLog : public RtcEventLog { const uint8_t* header, size_t packet_length)); + MOCK_METHOD5(LogRtpHeader, + void(PacketDirection direction, + MediaType media_type, + const uint8_t* header, + size_t packet_length, + int probe_cluster_id)); + MOCK_METHOD4(LogRtcpPacket, void(PacketDirection direction, MediaType media_type, @@ -64,6 +71,13 @@ class MockRtcEventLog : public RtcEventLog { MOCK_METHOD1(LogAudioNetworkAdaptation, void(const AudioNetworkAdaptor::EncoderRuntimeConfig& config)); + + MOCK_METHOD4(LogProbeClusterCreated, + void(int id, int bitrate_bps, int min_probes, int min_bytes)); + + MOCK_METHOD2(LogProbeResultSuccess, void(int id, int bitrate_bps)); + MOCK_METHOD2(LogProbeResultFailure, + void(int id, ProbeFailureReason failure_reason)); }; } // namespace webrtc diff --git a/webrtc/logging/rtc_event_log/rtc_event_log.cc b/webrtc/logging/rtc_event_log/rtc_event_log.cc index 88f6b3a5d3..902ce42343 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log.cc @@ -69,6 +69,11 @@ class RtcEventLogImpl final : public RtcEventLog { MediaType media_type, const uint8_t* header, size_t packet_length) override; + void LogRtpHeader(PacketDirection direction, + MediaType media_type, + const uint8_t* header, + size_t packet_length, + int probe_cluster_id) override; void LogRtcpPacket(PacketDirection direction, MediaType media_type, const uint8_t* packet, @@ -81,9 +86,19 @@ class RtcEventLogImpl final : public RtcEventLog { BandwidthUsage detector_state) override; void LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override; + void LogProbeClusterCreated(int id, + int bitrate_bps, + int min_probes, + int min_bytes) override; + void LogProbeResultSuccess(int id, int bitrate_bps) override; + void LogProbeResultFailure(int id, + ProbeFailureReason failure_reason) override; private: void StoreEvent(std::unique_ptr* event); + void LogProbeResult(int id, + rtclog::BweProbeResult::ResultType result, + int bitrate_bps); // Message queue for passing control messages to the logging thread. SwapQueue message_queue_; @@ -145,6 +160,20 @@ rtclog::DelayBasedBweUpdate::DetectorState ConvertDetectorState( return rtclog::DelayBasedBweUpdate::BWE_NORMAL; } +rtclog::BweProbeResult::ResultType ConvertProbeResultType( + ProbeFailureReason failure_reason) { + switch (failure_reason) { + case kInvalidSendReceiveInterval: + return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL; + case kInvalidSendReceiveRatio: + return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO; + case kTimeout: + return rtclog::BweProbeResult::TIMEOUT; + } + RTC_NOTREACHED(); + return rtclog::BweProbeResult::SUCCESS; +} + // 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; @@ -354,6 +383,15 @@ void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, MediaType media_type, const uint8_t* header, size_t packet_length) { + LogRtpHeader(direction, media_type, header, packet_length, + PacedPacketInfo::kNotAProbe); +} + +void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, + MediaType media_type, + const uint8_t* header, + size_t packet_length, + int probe_cluster_id) { // Read header length (in bytes) from packet data. if (packet_length < 12u) { return; // Don't read outside the packet. @@ -377,6 +415,8 @@ void RtcEventLogImpl::LogRtpHeader(PacketDirection direction, rtp_event->mutable_rtp_packet()->set_type(ConvertMediaType(media_type)); rtp_event->mutable_rtp_packet()->set_packet_length(packet_length); rtp_event->mutable_rtp_packet()->set_header(header, header_length); + if (probe_cluster_id != PacedPacketInfo::kNotAProbe) + rtp_event->mutable_rtp_packet()->set_probe_cluster_id(probe_cluster_id); StoreEvent(&rtp_event); } @@ -486,6 +526,48 @@ void RtcEventLogImpl::LogAudioNetworkAdaptation( StoreEvent(&event); } +void RtcEventLogImpl::LogProbeClusterCreated(int id, + int bitrate_bps, + int min_probes, + int min_bytes) { + std::unique_ptr event(new rtclog::Event()); + event->set_timestamp_us(rtc::TimeMicros()); + event->set_type(rtclog::Event::BWE_PROBE_CLUSTER_CREATED_EVENT); + + auto probe_cluster = event->mutable_probe_cluster(); + probe_cluster->set_id(id); + probe_cluster->set_bitrate_bps(bitrate_bps); + probe_cluster->set_min_packets(min_probes); + probe_cluster->set_min_bytes(min_bytes); + StoreEvent(&event); +} + +void RtcEventLogImpl::LogProbeResultSuccess(int id, int bitrate_bps) { + LogProbeResult(id, rtclog::BweProbeResult::SUCCESS, bitrate_bps); +} + +void RtcEventLogImpl::LogProbeResultFailure(int id, + ProbeFailureReason failure_reason) { + rtclog::BweProbeResult::ResultType result = + ConvertProbeResultType(failure_reason); + LogProbeResult(id, result, -1); +} + +void RtcEventLogImpl::LogProbeResult(int id, + rtclog::BweProbeResult::ResultType result, + int bitrate_bps) { + std::unique_ptr event(new rtclog::Event()); + event->set_timestamp_us(rtc::TimeMicros()); + event->set_type(rtclog::Event::BWE_PROBE_RESULT_EVENT); + + auto probe_result = event->mutable_probe_result(); + probe_result->set_id(id); + probe_result->set_result(result); + if (result == rtclog::BweProbeResult::SUCCESS) + probe_result->set_bitrate_bps(bitrate_bps); + StoreEvent(&event); +} + void RtcEventLogImpl::StoreEvent(std::unique_ptr* event) { if (!event_queue_.Insert(event)) { LOG(LS_ERROR) << "WebRTC event log queue full. Dropping event."; diff --git a/webrtc/logging/rtc_event_log/rtc_event_log.h b/webrtc/logging/rtc_event_log/rtc_event_log.h index f1bbcbba78..ccb37b32f3 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log.h +++ b/webrtc/logging/rtc_event_log/rtc_event_log.h @@ -36,6 +36,11 @@ class RtcEventLogImpl; enum class MediaType; enum PacketDirection { kIncomingPacket = 0, kOutgoingPacket }; +enum ProbeFailureReason { + kInvalidSendReceiveInterval, + kInvalidSendReceiveRatio, + kTimeout +}; class RtcEventLog { public: @@ -102,6 +107,14 @@ class RtcEventLog { const uint8_t* header, size_t packet_length) = 0; + // Same as above but used on the sender side to log packets that are part of + // a probe cluster. + virtual void LogRtpHeader(PacketDirection direction, + MediaType media_type, + const uint8_t* header, + size_t packet_length, + int probe_cluster_id) = 0; + // Logs an incoming or outgoing RTCP packet. virtual void LogRtcpPacket(PacketDirection direction, MediaType media_type, @@ -124,6 +137,19 @@ class RtcEventLog { virtual void LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) = 0; + // Logs when a probe cluster is created. + virtual void LogProbeClusterCreated(int id, + int bitrate_bps, + int min_probes, + int min_bytes) = 0; + + // Logs the result of a successful probing attempt. + virtual void LogProbeResultSuccess(int id, int bitrate_bps) = 0; + + // Logs the result of an unsuccessful probing attempt. + virtual void LogProbeResultFailure(int id, + ProbeFailureReason failure_reason) = 0; + // Reads an RtcEventLog file and returns true when reading was successful. // The result is stored in the given EventStream object. // The order of the events in the EventStream is implementation defined. @@ -157,6 +183,11 @@ class RtcEventLogNullImpl final : public RtcEventLog { MediaType media_type, const uint8_t* header, size_t packet_length) override {} + void LogRtpHeader(PacketDirection direction, + MediaType media_type, + const uint8_t* header, + size_t packet_length, + int probe_cluster_id) override {} void LogRtcpPacket(PacketDirection direction, MediaType media_type, const uint8_t* packet, @@ -169,6 +200,13 @@ class RtcEventLogNullImpl final : public RtcEventLog { BandwidthUsage detector_state) override {} void LogAudioNetworkAdaptation( const AudioNetworkAdaptor::EncoderRuntimeConfig& config) override {} + void LogProbeClusterCreated(int id, + int bitrate_bps, + int min_probes, + int min_bytes) override{}; + void LogProbeResultSuccess(int id, int bitrate_bps) override{}; + void LogProbeResultFailure(int id, + ProbeFailureReason failure_reason) 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 21f642235b..26d55a7c16 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log.proto +++ b/webrtc/logging/rtc_event_log/rtc_event_log.proto @@ -38,6 +38,8 @@ message Event { AUDIO_RECEIVER_CONFIG_EVENT = 10; AUDIO_SENDER_CONFIG_EVENT = 11; AUDIO_NETWORK_ADAPTATION_EVENT = 16; + BWE_PROBE_CLUSTER_CREATED_EVENT = 17; + BWE_PROBE_RESULT_EVENT = 18; } // required - Indicates the type of this event @@ -72,6 +74,12 @@ message Event { // optional - but required if type == AUDIO_NETWORK_ADAPTATION_EVENT optional AudioNetworkAdaptation audio_network_adaptation = 16; + + // optional - but required if type == BWE_PROBE_CLUSTER_CREATED_EVENT + optional BweProbeCluster probe_cluster = 17; + + // optional - but required if type == BWE_PROBE_RESULT_EVENT + optional BweProbeResult probe_result = 18; } message RtpPacket { @@ -87,6 +95,9 @@ message RtpPacket { // required - The RTP header only. optional bytes header = 4; + // optional - The probe cluster id. + optional uint32 probe_cluster_id = 5; + // Do not add code to log user payload data without a privacy review! } @@ -271,3 +282,35 @@ message AudioNetworkAdaptation { // Number of audio channels that each encoded packet consists of. optional uint32 num_channels = 6; } + +message BweProbeCluster { + // required - The id of this probe cluster. + optional uint32 id = 1; + + // required - The bitrate in bps that this probe cluster is meant to probe. + optional uint64 bitrate_bps = 2; + + // required - The minimum number of packets used to probe the given bitrate. + optional uint32 min_packets = 3; + + // required - The minimum number of bytes used to probe the given bitrate. + optional uint32 min_bytes = 4; +} + +message BweProbeResult { + // required - The id of this probe cluster. + optional uint32 id = 1; + + enum ResultType { + SUCCESS = 0; + INVALID_SEND_RECEIVE_INTERVAL = 1; + INVALID_SEND_RECEIVE_RATIO = 2; + TIMEOUT = 3; + } + + // required - The result of this probing attempt. + optional ResultType result = 2; + + // optional - but required if result == SUCCESS. The resulting bitrate in bps. + optional uint64 bitrate_bps = 3; +} 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 713d4fc78a..a0cc642165 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_parser.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log_parser.cc @@ -83,6 +83,10 @@ ParsedRtcEventLog::EventType GetRuntimeEventType( return ParsedRtcEventLog::EventType::AUDIO_SENDER_CONFIG_EVENT; case rtclog::Event::AUDIO_NETWORK_ADAPTATION_EVENT: return ParsedRtcEventLog::EventType::AUDIO_NETWORK_ADAPTATION_EVENT; + case rtclog::Event::BWE_PROBE_CLUSTER_CREATED_EVENT: + return ParsedRtcEventLog::EventType::BWE_PROBE_CLUSTER_CREATED_EVENT; + case rtclog::Event::BWE_PROBE_RESULT_EVENT: + return ParsedRtcEventLog::EventType::BWE_PROBE_RESULT_EVENT; } RTC_NOTREACHED(); return ParsedRtcEventLog::EventType::UNKNOWN_EVENT; 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 739ccee220..1460a4ca83 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_parser.h +++ b/webrtc/logging/rtc_event_log/rtc_event_log_parser.h @@ -48,7 +48,9 @@ class ParsedRtcEventLog { VIDEO_SENDER_CONFIG_EVENT = 9, AUDIO_RECEIVER_CONFIG_EVENT = 10, AUDIO_SENDER_CONFIG_EVENT = 11, - AUDIO_NETWORK_ADAPTATION_EVENT = 16 + AUDIO_NETWORK_ADAPTATION_EVENT = 16, + BWE_PROBE_CLUSTER_CREATED_EVENT = 17, + BWE_PROBE_RESULT_EVENT = 18 }; // Reads an RtcEventLog file and returns true if parsing was successful. 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 ae264aaf4b..71c588c21b 100644 --- a/webrtc/logging/rtc_event_log/rtc_event_log_unittest.cc +++ b/webrtc/logging/rtc_event_log/rtc_event_log_unittest.cc @@ -588,6 +588,148 @@ TEST(RtcEventLogTest, LogDelayBasedBweUpdateAndReadBack) { remove(temp_filename.c_str()); } +TEST(RtcEventLogTest, LogProbeClusterCreatedAndReadBack) { + Random prng(794613); + + int bitrate_bps0 = prng.Rand(0, 10000000); + int bitrate_bps1 = prng.Rand(0, 10000000); + int bitrate_bps2 = prng.Rand(0, 10000000); + int min_probes0 = prng.Rand(0, 100); + int min_probes1 = prng.Rand(0, 100); + int min_probes2 = prng.Rand(0, 100); + int min_bytes0 = prng.Rand(0, 10000); + int min_bytes1 = prng.Rand(0, 10000); + int min_bytes2 = prng.Rand(0, 10000); + + // 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(); + + rtc::ScopedFakeClock fake_clock; + fake_clock.SetTimeMicros(prng.Rand()); + std::unique_ptr log_dumper(RtcEventLog::Create()); + + log_dumper->StartLogging(temp_filename, 10000000); + log_dumper->LogProbeClusterCreated(0, bitrate_bps0, min_probes0, min_bytes0); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogProbeClusterCreated(1, bitrate_bps1, min_probes1, min_bytes1); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogProbeClusterCreated(2, bitrate_bps2, min_probes2, min_bytes2); + 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::VerifyBweProbeCluster(parsed_log, 1, 0, bitrate_bps0, + min_probes0, min_bytes0); + RtcEventLogTestHelper::VerifyBweProbeCluster(parsed_log, 2, 1, bitrate_bps1, + min_probes1, min_bytes1); + RtcEventLogTestHelper::VerifyBweProbeCluster(parsed_log, 3, 2, bitrate_bps2, + min_probes2, min_bytes2); + RtcEventLogTestHelper::VerifyLogEndEvent(parsed_log, 4); + + // Clean up temporary file - can be pretty slow. + remove(temp_filename.c_str()); +} + +TEST(RtcEventLogTest, LogProbeResultSuccessAndReadBack) { + Random prng(192837); + + int bitrate_bps0 = prng.Rand(0, 10000000); + int bitrate_bps1 = prng.Rand(0, 10000000); + int bitrate_bps2 = 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(); + + rtc::ScopedFakeClock fake_clock; + fake_clock.SetTimeMicros(prng.Rand()); + std::unique_ptr log_dumper(RtcEventLog::Create()); + + log_dumper->StartLogging(temp_filename, 10000000); + log_dumper->LogProbeResultSuccess(0, bitrate_bps0); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogProbeResultSuccess(1, bitrate_bps1); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogProbeResultSuccess(2, bitrate_bps2); + 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::VerifyProbeResultSuccess(parsed_log, 1, 0, + bitrate_bps0); + RtcEventLogTestHelper::VerifyProbeResultSuccess(parsed_log, 2, 1, + bitrate_bps1); + RtcEventLogTestHelper::VerifyProbeResultSuccess(parsed_log, 3, 2, + bitrate_bps2); + RtcEventLogTestHelper::VerifyLogEndEvent(parsed_log, 4); + + // Clean up temporary file - can be pretty slow. + remove(temp_filename.c_str()); +} + +TEST(RtcEventLogTest, LogProbeResultFailureAndReadBack) { + Random prng(192837); + + // 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(); + + rtc::ScopedFakeClock fake_clock; + fake_clock.SetTimeMicros(prng.Rand()); + std::unique_ptr log_dumper(RtcEventLog::Create()); + + log_dumper->StartLogging(temp_filename, 10000000); + log_dumper->LogProbeResultFailure( + 0, ProbeFailureReason::kInvalidSendReceiveInterval); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogProbeResultFailure( + 1, ProbeFailureReason::kInvalidSendReceiveRatio); + fake_clock.AdvanceTimeMicros(prng.Rand(1, 1000)); + log_dumper->LogProbeResultFailure(2, ProbeFailureReason::kTimeout); + 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::VerifyProbeResultFailure( + parsed_log, 1, 0, ProbeFailureReason::kInvalidSendReceiveInterval); + RtcEventLogTestHelper::VerifyProbeResultFailure( + parsed_log, 2, 1, ProbeFailureReason::kInvalidSendReceiveRatio); + RtcEventLogTestHelper::VerifyProbeResultFailure(parsed_log, 3, 2, + ProbeFailureReason::kTimeout); + 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 e7db5930f7..e66c090744 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 @@ -56,6 +56,20 @@ BandwidthUsage GetRuntimeDetectorState( RTC_NOTREACHED(); return kBwNormal; } + +rtclog::BweProbeResult::ResultType GetProbeResultType( + ProbeFailureReason failure_reason) { + switch (failure_reason) { + case kInvalidSendReceiveInterval: + return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_INTERVAL; + case kInvalidSendReceiveRatio: + return rtclog::BweProbeResult::INVALID_SEND_RECEIVE_RATIO; + case kTimeout: + return rtclog::BweProbeResult::TIMEOUT; + } + RTC_NOTREACHED(); + return rtclog::BweProbeResult::SUCCESS; +} } // namespace // Checks that the event has a timestamp, a type and exactly the data field @@ -132,6 +146,18 @@ BandwidthUsage GetRuntimeDetectorState( << (event.has_audio_network_adaptation() ? "" : "no ") << "audio network adaptation"; } + if ((type == rtclog::Event::BWE_PROBE_CLUSTER_CREATED_EVENT) != + event.has_probe_cluster()) { + return ::testing::AssertionFailure() + << "Event of type " << type << " has " + << (event.has_probe_cluster() ? "" : "no ") << "bwe probe cluster"; + } + if ((type == rtclog::Event::BWE_PROBE_RESULT_EVENT) != + event.has_probe_result()) { + return ::testing::AssertionFailure() + << "Event of type " << type << " has " + << (event.has_probe_result() ? "" : "no ") << "bwe probe result"; + } return ::testing::AssertionSuccess(); } @@ -550,4 +576,67 @@ void RtcEventLogTestHelper::VerifyLogEndEvent( EXPECT_EQ(rtclog::Event::LOG_END, event.type()); } +void RtcEventLogTestHelper::VerifyBweProbeCluster( + const ParsedRtcEventLog& parsed_log, + size_t index, + uint32_t id, + uint32_t bitrate_bps, + uint32_t min_probes, + uint32_t min_bytes) { + const rtclog::Event& event = parsed_log.events_[index]; + ASSERT_TRUE(IsValidBasicEvent(event)); + EXPECT_EQ(rtclog::Event::BWE_PROBE_CLUSTER_CREATED_EVENT, event.type()); + + const rtclog::BweProbeCluster& bwe_event = event.probe_cluster(); + ASSERT_TRUE(bwe_event.has_id()); + EXPECT_EQ(id, bwe_event.id()); + ASSERT_TRUE(bwe_event.has_bitrate_bps()); + EXPECT_EQ(bitrate_bps, bwe_event.bitrate_bps()); + ASSERT_TRUE(bwe_event.has_min_packets()); + EXPECT_EQ(min_probes, bwe_event.min_packets()); + ASSERT_TRUE(bwe_event.has_min_bytes()); + EXPECT_EQ(min_bytes, bwe_event.min_bytes()); + + // TODO(philipel): Verify the parser when parsing has been implemented. +} + +void RtcEventLogTestHelper::VerifyProbeResultSuccess( + const ParsedRtcEventLog& parsed_log, + size_t index, + uint32_t id, + uint32_t bitrate_bps) { + const rtclog::Event& event = parsed_log.events_[index]; + ASSERT_TRUE(IsValidBasicEvent(event)); + EXPECT_EQ(rtclog::Event::BWE_PROBE_RESULT_EVENT, event.type()); + + const rtclog::BweProbeResult& bwe_event = event.probe_result(); + ASSERT_TRUE(bwe_event.has_id()); + EXPECT_EQ(id, bwe_event.id()); + ASSERT_TRUE(bwe_event.has_bitrate_bps()); + EXPECT_EQ(bitrate_bps, bwe_event.bitrate_bps()); + ASSERT_TRUE(bwe_event.has_result()); + EXPECT_EQ(rtclog::BweProbeResult::SUCCESS, bwe_event.result()); + + // TODO(philipel): Verify the parser when parsing has been implemented. +} + +void RtcEventLogTestHelper::VerifyProbeResultFailure( + const ParsedRtcEventLog& parsed_log, + size_t index, + uint32_t id, + ProbeFailureReason failure_reason) { + const rtclog::Event& event = parsed_log.events_[index]; + ASSERT_TRUE(IsValidBasicEvent(event)); + EXPECT_EQ(rtclog::Event::BWE_PROBE_RESULT_EVENT, event.type()); + + const rtclog::BweProbeResult& bwe_event = event.probe_result(); + ASSERT_TRUE(bwe_event.has_id()); + EXPECT_EQ(id, bwe_event.id()); + ASSERT_TRUE(bwe_event.has_result()); + EXPECT_EQ(GetProbeResultType(failure_reason), bwe_event.result()); + ASSERT_FALSE(bwe_event.has_bitrate_bps()); + + // TODO(philipel): Verify the parser when parsing has been implemented. +} + } // namespace webrtc 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 5efb8c8bda..0ca2d62d26 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 @@ -69,6 +69,23 @@ class RtcEventLogTestHelper { size_t index); static void VerifyLogEndEvent(const ParsedRtcEventLog& parsed_log, size_t index); + + static void VerifyBweProbeCluster(const ParsedRtcEventLog& parsed_log, + size_t index, + uint32_t id, + uint32_t bitrate_bps, + uint32_t min_probes, + uint32_t min_bytes); + + static void VerifyProbeResultSuccess(const ParsedRtcEventLog& parsed_log, + size_t index, + uint32_t id, + uint32_t bitrate_bps); + + static void VerifyProbeResultFailure(const ParsedRtcEventLog& parsed_log, + size_t index, + uint32_t id, + ProbeFailureReason failure_reason); }; } // namespace webrtc diff --git a/webrtc/modules/rtp_rtcp/source/rtp_sender.cc b/webrtc/modules/rtp_rtcp/source/rtp_sender.cc index a84b4be018..12be6d622e 100644 --- a/webrtc/modules/rtp_rtcp/source/rtp_sender.cc +++ b/webrtc/modules/rtp_rtcp/source/rtp_sender.cc @@ -578,7 +578,7 @@ size_t RTPSender::SendPadData(size_t bytes, pacing_info); } - if (!SendPacketToNetwork(padding_packet, options)) + if (!SendPacketToNetwork(padding_packet, options, pacing_info)) break; bytes_sent += padding_bytes_in_packet; @@ -630,7 +630,8 @@ int32_t RTPSender::ReSendPacket(uint16_t packet_id, int64_t min_resend_time) { } bool RTPSender::SendPacketToNetwork(const RtpPacketToSend& packet, - const PacketOptions& options) { + const PacketOptions& options, + const PacedPacketInfo& pacing_info) { int bytes_sent = -1; if (transport_) { UpdateRtpOverhead(packet); @@ -639,7 +640,7 @@ bool RTPSender::SendPacketToNetwork(const RtpPacketToSend& packet, : -1; if (event_log_ && bytes_sent > 0) { event_log_->LogRtpHeader(kOutgoingPacket, MediaType::ANY, packet.data(), - packet.size()); + packet.size(), pacing_info.probe_cluster_id); } } TRACE_EVENT_INSTANT2(TRACE_DISABLED_BY_DEFAULT("webrtc_rtp"), @@ -760,7 +761,7 @@ bool RTPSender::PrepareAndSendPacket(std::unique_ptr packet, packet->Ssrc()); } - if (!SendPacketToNetwork(*packet_to_send, options)) + if (!SendPacketToNetwork(*packet_to_send, options, pacing_info)) return false; { @@ -890,7 +891,7 @@ bool RTPSender::SendToNetwork(std::unique_ptr packet, UpdateOnSendPacket(options.packet_id, packet->capture_time_ms(), packet->Ssrc()); - bool sent = SendPacketToNetwork(*packet, options); + bool sent = SendPacketToNetwork(*packet, options, PacedPacketInfo()); if (sent) { { diff --git a/webrtc/modules/rtp_rtcp/source/rtp_sender.h b/webrtc/modules/rtp_rtcp/source/rtp_sender.h index 1fd491707f..64eb679220 100644 --- a/webrtc/modules/rtp_rtcp/source/rtp_sender.h +++ b/webrtc/modules/rtp_rtcp/source/rtp_sender.h @@ -230,7 +230,8 @@ class RTPSender { const RtpPacketToSend& packet); bool SendPacketToNetwork(const RtpPacketToSend& packet, - const PacketOptions& options); + const PacketOptions& options, + const PacedPacketInfo& pacing_info); void UpdateDelayStatistics(int64_t capture_time_ms, int64_t now_ms); void UpdateOnSendPacket(int packet_id, diff --git a/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc b/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc index 93aeae84cc..e349a70a74 100644 --- a/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc +++ b/webrtc/modules/rtp_rtcp/source/rtp_sender_unittest.cc @@ -426,7 +426,7 @@ TEST_F(RtpSenderTest, TrafficSmoothingWithExtensions) { EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, kSeqNum, _, _, _)); EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)); + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)); rtp_sender_->SetStorePacketsStatus(true, 10); EXPECT_EQ(0, rtp_sender_->RegisterRtpHeaderExtension( @@ -471,7 +471,7 @@ TEST_F(RtpSenderTest, TrafficSmoothingRetransmits) { EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, kSeqNum, _, _, _)); EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)); + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)); rtp_sender_->SetStorePacketsStatus(true, 10); EXPECT_EQ(0, rtp_sender_->RegisterRtpHeaderExtension( @@ -525,7 +525,7 @@ TEST_F(RtpSenderTest, SendPadding) { EXPECT_CALL(mock_paced_sender_, InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, kSeqNum, _, _, _)); EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)) + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)) .Times(1 + 4 + 1); uint16_t seq_num = kSeqNum; @@ -726,7 +726,7 @@ TEST_F(RtpSenderTest, SendRedundantPayloads) { InsertPacket(RtpPacketSender::kNormalPriority, kSsrc, _, _, _, _)) .Times(kNumPayloadSizes); EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)) + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)) .Times(kNumPayloadSizes); // Send 10 packets of increasing size. @@ -740,7 +740,7 @@ TEST_F(RtpSenderTest, SendRedundantPayloads) { } EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)) + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)) .Times(::testing::AtLeast(4)); // The amount of padding to send it too small to send a payload packet. @@ -835,7 +835,7 @@ TEST_F(RtpSenderTest, SendFlexfecPackets) { .WillOnce(testing::SaveArg<2>(&flexfec_seq_num)); SendGenericPayload(); EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)) + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)) .Times(2); EXPECT_TRUE(rtp_sender_->TimeToSendPacket(kMediaSsrc, kSeqNum, fake_clock_.TimeInMilliseconds(), @@ -881,7 +881,7 @@ TEST_F(RtpSenderTestWithoutPacer, SendFlexfecPackets) { rtp_sender_->SetFecParameters(params, params); EXPECT_CALL(mock_rtc_event_log_, - LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _)) + LogRtpHeader(PacketDirection::kOutgoingPacket, _, _, _, _)) .Times(2); SendGenericPayload(); ASSERT_EQ(2, transport_.packets_sent()); diff --git a/webrtc/tools/event_log_visualizer/analyzer.cc b/webrtc/tools/event_log_visualizer/analyzer.cc index 428c55ca57..564357c0ee 100644 --- a/webrtc/tools/event_log_visualizer/analyzer.cc +++ b/webrtc/tools/event_log_visualizer/analyzer.cc @@ -457,6 +457,12 @@ EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log) audio_network_adaptation_events_.push_back(ana_event); break; } + case ParsedRtcEventLog::BWE_PROBE_CLUSTER_CREATED_EVENT: { + break; + } + case ParsedRtcEventLog::BWE_PROBE_RESULT_EVENT: { + break; + } case ParsedRtcEventLog::UNKNOWN_EVENT: { break; } diff --git a/webrtc/voice_engine/channel.cc b/webrtc/voice_engine/channel.cc index 5f29fe401e..1d54821a50 100644 --- a/webrtc/voice_engine/channel.cc +++ b/webrtc/voice_engine/channel.cc @@ -108,9 +108,19 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { webrtc::MediaType media_type, const uint8_t* header, size_t packet_length) override { + LogRtpHeader(direction, media_type, header, packet_length, + PacedPacketInfo::kNotAProbe); + } + + void LogRtpHeader(webrtc::PacketDirection direction, + webrtc::MediaType media_type, + const uint8_t* header, + size_t packet_length, + int probe_cluster_id) override { rtc::CritScope lock(&crit_); if (event_log_) { - event_log_->LogRtpHeader(direction, media_type, header, packet_length); + event_log_->LogRtpHeader(direction, media_type, header, packet_length, + probe_cluster_id); } } @@ -157,6 +167,32 @@ class RtcEventLogProxy final : public webrtc::RtcEventLog { } } + void LogProbeClusterCreated(int id, + int bitrate_bps, + int min_probes, + int min_bytes) override { + rtc::CritScope lock(&crit_); + if (event_log_) { + event_log_->LogProbeClusterCreated(id, bitrate_bps, min_probes, + min_bytes); + } + }; + + void LogProbeResultSuccess(int id, int bitrate_bps) override { + rtc::CritScope lock(&crit_); + if (event_log_) { + event_log_->LogProbeResultSuccess(id, bitrate_bps); + } + }; + + void LogProbeResultFailure(int id, + ProbeFailureReason failure_reason) override { + rtc::CritScope lock(&crit_); + if (event_log_) { + event_log_->LogProbeResultFailure(id, failure_reason); + } + }; + void SetEventLog(RtcEventLog* event_log) { rtc::CritScope lock(&crit_); event_log_ = event_log;