From 17554c1c4ce06f4aec3d4d49b11efc23bbb7f3ab Mon Sep 17 00:00:00 2001 From: Per Kjellander Date: Mon, 18 Nov 2024 12:40:41 +0000 Subject: [PATCH] Add graph for ecn packet count in incoming/outgoing CCFB MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Also add a plot group l4s. Usage: event_log_visualizer --plot=l4s filename |python3 Bug: webrtc:42225697 Change-Id: I5e1ee7028b9fb0707d5cabfe6d6f27c348e70a22 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/367199 Commit-Queue: Per Kjellander Reviewed-by: Björn Terelius Cr-Commit-Position: refs/heads/main@{#43416} --- .../rtc_event_log/events/logged_rtp_rtcp.h | 15 +++++ logging/rtc_event_log/rtc_event_log_parser.cc | 12 +++- logging/rtc_event_log/rtc_event_log_parser.h | 13 ++++ rtc_tools/BUILD.gn | 1 + .../rtc_event_log_visualizer/analyzer.cc | 67 +++++++++++++++++++ rtc_tools/rtc_event_log_visualizer/analyzer.h | 3 + rtc_tools/rtc_event_log_visualizer/main.cc | 5 +- 7 files changed, 113 insertions(+), 3 deletions(-) diff --git a/logging/rtc_event_log/events/logged_rtp_rtcp.h b/logging/rtc_event_log/events/logged_rtp_rtcp.h index b0f2ec3324..f52664e37b 100644 --- a/logging/rtc_event_log/events/logged_rtp_rtcp.h +++ b/logging/rtc_event_log/events/logged_rtp_rtcp.h @@ -20,6 +20,7 @@ #include "api/rtp_headers.h" #include "api/units/timestamp.h" #include "modules/rtp_rtcp/source/rtcp_packet/bye.h" +#include "modules/rtp_rtcp/source/rtcp_packet/congestion_control_feedback.h" #include "modules/rtp_rtcp/source/rtcp_packet/extended_reports.h" #include "modules/rtp_rtcp/source/rtcp_packet/fir.h" #include "modules/rtp_rtcp/source/rtcp_packet/loss_notification.h" @@ -232,6 +233,20 @@ struct LoggedRtcpPacketTransportFeedback { rtcp::TransportFeedback transport_feedback; }; +struct LoggedRtcpCongestionControlFeedback { + LoggedRtcpCongestionControlFeedback( + Timestamp timestamp, + const rtcp::CongestionControlFeedback& congestion_feedback) + : timestamp(timestamp), congestion_feedback(congestion_feedback) {} + + int64_t log_time_us() const { return timestamp.us(); } + int64_t log_time_ms() const { return timestamp.ms(); } + Timestamp log_time() const { return timestamp; } + + Timestamp timestamp; + rtcp::CongestionControlFeedback congestion_feedback; +}; + struct LoggedRtcpPacketLossNotification { LoggedRtcpPacketLossNotification() = default; LoggedRtcpPacketLossNotification( diff --git a/logging/rtc_event_log/rtc_event_log_parser.cc b/logging/rtc_event_log/rtc_event_log_parser.cc index 241853bb30..1daf661100 100644 --- a/logging/rtc_event_log/rtc_event_log_parser.cc +++ b/logging/rtc_event_log/rtc_event_log_parser.cc @@ -80,6 +80,7 @@ #include "modules/rtp_rtcp/include/rtp_rtcp_defines.h" #include "modules/rtp_rtcp/source/rtcp_packet/bye.h" #include "modules/rtp_rtcp/source/rtcp_packet/common_header.h" +#include "modules/rtp_rtcp/source/rtcp_packet/congestion_control_feedback.h" #include "modules/rtp_rtcp/source/rtcp_packet/extended_reports.h" #include "modules/rtp_rtcp/source/rtcp_packet/fir.h" #include "modules/rtp_rtcp/source/rtcp_packet/nack.h" @@ -753,6 +754,7 @@ ParsedRtcEventLog::ParseStatus StoreRtcpBlocks( std::vector* pli_list, std::vector* bye_list, std::vector* transport_feedback_list, + std::vector* congestion_feedback_list, std::vector* loss_notification_list) { Timestamp timestamp = Timestamp::Micros(timestamp_us); rtcp::CommonHeader header; @@ -765,6 +767,12 @@ ParsedRtcEventLog::ParseStatus StoreRtcpBlocks( parsed_block.timestamp = timestamp; RTC_PARSE_CHECK_OR_RETURN(parsed_block.transport_feedback.Parse(header)); transport_feedback_list->push_back(std::move(parsed_block)); + } else if (header.type() == rtcp::Rtpfb::kPacketType && + header.fmt() == + rtcp::CongestionControlFeedback::kFeedbackMessageType) { + rtcp::CongestionControlFeedback feedback; + RTC_PARSE_CHECK_OR_RETURN(feedback.Parse(header)); + congestion_feedback_list->emplace_back(timestamp, std::move(feedback)); } else if (header.type() == rtcp::SenderReport::kPacketType) { LoggedRtcpPacketSenderReport parsed_block; parsed_block.timestamp = timestamp; @@ -1309,7 +1317,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream( timestamp_us, packet_begin, packet_end, &incoming_sr_, &incoming_rr_, &incoming_xr_, &incoming_remb_, &incoming_nack_, &incoming_fir_, &incoming_pli_, &incoming_bye_, &incoming_transport_feedback_, - &incoming_loss_notification_); + &incoming_congestion_feedback_, &incoming_loss_notification_); RTC_RETURN_IF_ERROR(store_rtcp_status); } @@ -1321,7 +1329,7 @@ ParsedRtcEventLog::ParseStatus ParsedRtcEventLog::ParseStream( timestamp_us, packet_begin, packet_end, &outgoing_sr_, &outgoing_rr_, &outgoing_xr_, &outgoing_remb_, &outgoing_nack_, &outgoing_fir_, &outgoing_pli_, &outgoing_bye_, &outgoing_transport_feedback_, - &outgoing_loss_notification_); + &outgoing_congestion_feedback_, &outgoing_loss_notification_); RTC_RETURN_IF_ERROR(store_rtcp_status); } diff --git a/logging/rtc_event_log/rtc_event_log_parser.h b/logging/rtc_event_log/rtc_event_log_parser.h index 1dd65e7953..4fdeba6f59 100644 --- a/logging/rtc_event_log/rtc_event_log_parser.h +++ b/logging/rtc_event_log/rtc_event_log_parser.h @@ -632,6 +632,15 @@ class ParsedRtcEventLog { } } + const std::vector& congestion_feedback( + PacketDirection direction) const { + if (direction == kIncomingPacket) { + return incoming_congestion_feedback_; + } else { + return outgoing_congestion_feedback_; + } + } + const std::vector& loss_notifications( PacketDirection direction) { if (direction == kIncomingPacket) { @@ -865,6 +874,10 @@ class ParsedRtcEventLog { std::vector outgoing_bye_; std::vector incoming_transport_feedback_; std::vector outgoing_transport_feedback_; + std::vector + incoming_congestion_feedback_; + std::vector + outgoing_congestion_feedback_; std::vector incoming_loss_notification_; std::vector outgoing_loss_notification_; diff --git a/rtc_tools/BUILD.gn b/rtc_tools/BUILD.gn index a5fa6c84b6..68521ba2bd 100644 --- a/rtc_tools/BUILD.gn +++ b/rtc_tools/BUILD.gn @@ -365,6 +365,7 @@ if (!build_with_chromium) { "../api/neteq:neteq_api", "../api/rtc_event_log:rtc_event_log", "../api/transport:bandwidth_usage", + "../api/transport:ecn_marking", "../api/transport:field_trial_based_config", "../api/transport:goog_cc", "../api/transport:network_control", diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer.cc b/rtc_tools/rtc_event_log_visualizer/analyzer.cc index cc51c79fd2..f6acc90b23 100644 --- a/rtc_tools/rtc_event_log_visualizer/analyzer.cc +++ b/rtc_tools/rtc_event_log_visualizer/analyzer.cc @@ -36,6 +36,7 @@ #include "api/rtc_event_log/rtc_event_log.h" #include "api/rtp_headers.h" #include "api/transport/bandwidth_usage.h" +#include "api/transport/ecn_marking.h" #include "api/transport/goog_cc_factory.h" #include "api/transport/network_control.h" #include "api/transport/network_types.h" @@ -55,6 +56,7 @@ #include "modules/remote_bitrate_estimator/include/remote_bitrate_estimator.h" #include "modules/rtp_rtcp/include/rtp_header_extension_map.h" #include "modules/rtp_rtcp/include/rtp_rtcp_defines.h" +#include "modules/rtp_rtcp/source/rtcp_packet/congestion_control_feedback.h" #include "modules/rtp_rtcp/source/rtcp_packet/receiver_report.h" #include "modules/rtp_rtcp/source/rtcp_packet/remb.h" #include "modules/rtp_rtcp/source/rtcp_packet/report_block.h" @@ -617,6 +619,12 @@ void EventLogAnalyzer::InitializeMapOfNamedGraphs(bool show_detector_state, plots_.RegisterPlot("outgoing_twcc_loss", [this](Plot* plot) { this->CreateOutgoingTWCCLossRateGraph(plot); }); + plots_.RegisterPlot("outgoing_ecn_feedback", [this](Plot* plot) { + this->CreateOutgoingEcnFeedbackGraph(plot); + }); + plots_.RegisterPlot("incoming_ecn_feedback", [this](Plot* plot) { + this->CreateIncomingEcnFeedbackGraph(plot); + }); plots_.RegisterPlot("network_delay_feedback", [this](Plot* plot) { this->CreateNetworkDelayFeedbackGraph(plot); }); @@ -1557,6 +1565,65 @@ void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) const { plot->SetTitle("Simulated BWE behavior"); } +void EventLogAnalyzer::CreateOutgoingEcnFeedbackGraph(Plot* plot) const { + CreateEcnFeedbackGraph(plot, kOutgoingPacket); + plot->SetTitle("Outgoing ECN count per feedback"); +} + +void EventLogAnalyzer::CreateIncomingEcnFeedbackGraph(Plot* plot) const { + CreateEcnFeedbackGraph(plot, kIncomingPacket); + plot->SetTitle("Incoming ECN count per feedback"); +} + +void EventLogAnalyzer::CreateEcnFeedbackGraph(Plot* plot, + PacketDirection direction) const { + TimeSeries not_ect("Not ECN capable", LineStyle::kBar, + PointStyle::kHighlight); + TimeSeries ect_1("ECN capable", LineStyle::kBar, PointStyle::kHighlight); + TimeSeries ce("Congestion experienced", LineStyle::kBar, + PointStyle::kHighlight); + + for (const LoggedRtcpCongestionControlFeedback& feedback : + parsed_log_.congestion_feedback(direction)) { + int ect_1_count = 0; + int not_ect_count = 0; + int ce_count = 0; + + for (const rtcp::CongestionControlFeedback::PacketInfo& info : + feedback.congestion_feedback.packets()) { + switch (info.ecn) { + case webrtc::EcnMarking::kNotEct: + ++not_ect_count; + break; + case webrtc::EcnMarking::kEct1: + ++ect_1_count; + break; + case webrtc::EcnMarking::kEct0: + RTC_LOG(LS_ERROR) << "unexpected ect(0)"; + break; + case webrtc::EcnMarking::kCe: + ++ce_count; + break; + } + } + ect_1.points.emplace_back(config_.GetCallTimeSec(feedback.timestamp), + ect_1_count); + not_ect.points.emplace_back(config_.GetCallTimeSec(feedback.timestamp), + not_ect_count); + ce.points.emplace_back(config_.GetCallTimeSec(feedback.timestamp), + ce_count); + } + + plot->AppendTimeSeriesIfNotEmpty(std::move(ect_1)); + plot->AppendTimeSeriesIfNotEmpty(std::move(not_ect)); + plot->AppendTimeSeriesIfNotEmpty(std::move(ce)); + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 10, "Count per feedback", kBottomMargin, + kTopMargin); +} + void EventLogAnalyzer::CreateOutgoingTWCCLossRateGraph(Plot* plot) const { TimeSeries loss_rate_series("Loss rate (from packet feedback)", LineStyle::kLine, PointStyle::kHighlight); diff --git a/rtc_tools/rtc_event_log_visualizer/analyzer.h b/rtc_tools/rtc_event_log_visualizer/analyzer.h index c055a127fb..5432cb576e 100644 --- a/rtc_tools/rtc_event_log_visualizer/analyzer.h +++ b/rtc_tools/rtc_event_log_visualizer/analyzer.h @@ -115,6 +115,8 @@ class EventLogAnalyzer { Plot* plot) const; void CreateOutgoingTWCCLossRateGraph(Plot* plot) const; + void CreateOutgoingEcnFeedbackGraph(Plot* plot) const; + void CreateIncomingEcnFeedbackGraph(Plot* plot) const; void CreateGoogCcSimulationGraph(Plot* plot) const; void CreateSendSideBweSimulationGraph(Plot* plot) const; void CreateReceiveSideBweSimulationGraph(Plot* plot) const; @@ -144,6 +146,7 @@ class EventLogAnalyzer { void CreateAccumulatedPacketsTimeSeries(Plot* plot, const IterableType& packets, const std::string& label) const; + void CreateEcnFeedbackGraph(Plot* plot, PacketDirection direction) const; const ParsedRtcEventLog& parsed_log_; diff --git a/rtc_tools/rtc_event_log_visualizer/main.cc b/rtc_tools/rtc_event_log_visualizer/main.cc index 78c09d3445..ed865b3510 100644 --- a/rtc_tools/rtc_event_log_visualizer/main.cc +++ b/rtc_tools/rtc_event_log_visualizer/main.cc @@ -244,7 +244,10 @@ int main(int argc, char* argv[]) { "simulated_neteq_preferred_buffer_size", "simulated_neteq_concealment_events", "simulated_neteq_preemptive_rate", "simulated_neteq_accelerate_rate", "simulated_neteq_speech_expand_rate", - "simulated_neteq_expand_rate"}}}; + "simulated_neteq_expand_rate"}}, + {"l4s", + {"incoming_bitrate", "outgoing_bitrate", "incoming_ecn_feedback", + "outgoing_ecn_feedback"}}}; if (absl::GetFlag(FLAGS_list_plots)) { std::cerr << "List of registered plots (for use with the --plot flag):"