/* * Copyright (c) 2026 The WebRTC project authors. All Rights Reserved. * * Use of this source code is governed by a BSD-style license * that can be found in the LICENSE file in the root of the source * tree. An additional intellectual property rights grant can be found * in the file PATENTS. All contributing project authors may * be found in the AUTHORS file in the root of the source tree. */ #include "rtc_tools/rtc_event_log_visualizer/analyze_bwe.h" #include #include #include #include #include #include #include #include #include #include #include #include "absl/algorithm/container.h" #include "absl/functional/bind_front.h" #include "absl/strings/string_view.h" #include "api/environment/environment.h" #include "api/environment/environment_factory.h" #include "api/field_trials.h" #include "api/function_view.h" #include "api/media_types.h" #include "api/rtp_headers.h" #include "api/transport/bandwidth_usage.h" #include "api/transport/goog_cc_factory.h" #include "api/transport/network_control.h" #include "api/transport/network_types.h" #include "api/units/data_rate.h" #include "api/units/time_delta.h" #include "api/units/timestamp.h" #include "logging/rtc_event_log/events/logged_rtp_rtcp.h" #include "logging/rtc_event_log/rtc_event_log_parser.h" #include "modules/congestion_controller/goog_cc/acknowledged_bitrate_estimator_interface.h" #include "modules/congestion_controller/include/receive_side_congestion_controller.h" #include "modules/congestion_controller/rtp/transport_feedback_adapter.h" #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/remb.h" #include "modules/rtp_rtcp/source/rtp_header_extensions.h" #include "modules/rtp_rtcp/source/rtp_packet_received.h" #include "modules/rtp_rtcp/source/rtp_packet_to_send.h" #include "rtc_base/checks.h" #include "rtc_base/logging.h" #include "rtc_base/network/sent_packet.h" #include "rtc_base/numerics/sequence_number_unwrapper.h" #include "rtc_base/rate_statistics.h" #include "rtc_tools/rtc_event_log_visualizer/analyzer_common.h" #include "rtc_tools/rtc_event_log_visualizer/log_scream_simulation.h" #include "rtc_tools/rtc_event_log_visualizer/log_simulation.h" #include "rtc_tools/rtc_event_log_visualizer/plot_base.h" #include "system_wrappers/include/clock.h" namespace webrtc { namespace { double AbsSendTimeToMicroseconds(int64_t abs_send_time) { // The timestamp is a fixed point representation with 6 bits for seconds // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the // time in seconds and then multiply by kNumMicrosecsPerSec to convert to // microseconds. static constexpr double kTimestampToMicroSec = static_cast(kNumMicrosecsPerSec) / static_cast(1ul << 18); return abs_send_time * kTimestampToMicroSec; } // This is much more reliable for outgoing streams than for incoming streams. template std::optional EstimateRtpClockFrequency( const RtpPacketContainer& packets, int64_t end_time_us) { RTC_CHECK(packets.size() >= 2); SeqNumUnwrapper unwrapper; int64_t first_rtp_timestamp = unwrapper.Unwrap(packets[0].rtp.header.timestamp); int64_t first_log_timestamp = packets[0].log_time_us(); int64_t last_rtp_timestamp = first_rtp_timestamp; int64_t last_log_timestamp = first_log_timestamp; for (size_t i = 1; i < packets.size(); i++) { if (packets[i].log_time_us() > end_time_us) break; last_rtp_timestamp = unwrapper.Unwrap(packets[i].rtp.header.timestamp); last_log_timestamp = packets[i].log_time_us(); } if (last_log_timestamp - first_log_timestamp < kNumMicrosecsPerSec) { RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Stream too short. (" << packets.size() << " packets, " << last_log_timestamp - first_log_timestamp << " us)"; return std::nullopt; } double duration = static_cast(last_log_timestamp - first_log_timestamp) / kNumMicrosecsPerSec; double estimated_frequency = (last_rtp_timestamp - first_rtp_timestamp) / duration; for (uint32_t f : {8000, 16000, 32000, 48000, 90000}) { if (std::fabs(estimated_frequency - f) < 0.15 * f) { return f; } } RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Estimate " << estimated_frequency << " not close to any standard RTP frequency." << " Last timestamp " << last_rtp_timestamp << " first timestamp " << first_rtp_timestamp; return std::nullopt; } std::optional NetworkDelayDiff_AbsSendTime( const LoggedRtpPacketIncoming& old_packet, const LoggedRtpPacketIncoming& new_packet) { if (old_packet.rtp.header.extension.hasAbsoluteSendTime && new_packet.rtp.header.extension.hasAbsoluteSendTime) { int64_t send_time_diff = WrappingDifference( new_packet.rtp.header.extension.absoluteSendTime, old_packet.rtp.header.extension.absoluteSendTime, 1ul << 24); int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us(); double delay_change_us = recv_time_diff - AbsSendTimeToMicroseconds(send_time_diff); return delay_change_us / 1000; } else { return std::nullopt; } } std::optional NetworkDelayDiff_CaptureTime( const LoggedRtpPacketIncoming& old_packet, const LoggedRtpPacketIncoming& new_packet, const double sample_rate) { int64_t send_time_diff = WrappingDifference(new_packet.rtp.header.timestamp, old_packet.rtp.header.timestamp, 1ull << 32); int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us(); double delay_change = static_cast(recv_time_diff) / 1000 - static_cast(send_time_diff) / sample_rate * 1000; if (delay_change < -10000 || 10000 < delay_change) { RTC_LOG(LS_WARNING) << "Very large delay change. Timestamps correct?"; RTC_LOG(LS_WARNING) << "Old capture time " << old_packet.rtp.header.timestamp << ", received time " << old_packet.log_time_us(); RTC_LOG(LS_WARNING) << "New capture time " << new_packet.rtp.header.timestamp << ", received time " << new_packet.log_time_us(); RTC_LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = " << static_cast(recv_time_diff) / kNumMicrosecsPerSec << "s"; RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = " << static_cast(send_time_diff) / sample_rate << "s"; } return delay_change; } struct FakeExtensionSmall { static constexpr RTPExtensionType kId = kRtpExtensionMid; static constexpr absl::string_view Uri() { return "fake-extension-small"; } }; struct FakeExtensionLarge { static constexpr RTPExtensionType kId = kRtpExtensionRtpStreamId; static constexpr absl::string_view Uri() { return "fake-extension-large"; } }; RtpPacketReceived RtpPacketForBWEFromHeader(const RTPHeader& header) { RtpHeaderExtensionMap rtp_header_extensions(/*extmap_allow_mixed=*/true); // ReceiveSideCongestionController doesn't need to know extensions ids as // long as it able to get extensions by type. So any ids would work here. rtp_header_extensions.Register(1); rtp_header_extensions.Register(2); rtp_header_extensions.Register(3); rtp_header_extensions.Register(4); // Use id > 14 to force two byte header per rtp header when this one is used. rtp_header_extensions.Register(16); RtpPacketReceived rtp_packet(&rtp_header_extensions); // Set only fields that might be relevant for the bandwidth estimatior. rtp_packet.SetSsrc(header.ssrc); rtp_packet.SetTimestamp(header.timestamp); size_t num_bwe_extensions = 0; if (header.extension.hasTransmissionTimeOffset) { rtp_packet.SetExtension( header.extension.transmissionTimeOffset); ++num_bwe_extensions; } if (header.extension.hasAbsoluteSendTime) { rtp_packet.SetExtension( header.extension.absoluteSendTime); ++num_bwe_extensions; } if (header.extension.hasTransportSequenceNumber) { rtp_packet.SetExtension( header.extension.transportSequenceNumber); ++num_bwe_extensions; } // All parts of the RTP header are 32bit aligned. RTC_CHECK_EQ(header.headerLength % 4, 0); // Original packet could have more extensions, there could be csrcs that are // not propagated by the rtc event log, i.e. logged header size might be // larger that rtp_packet.header_size(). Increase it by setting an extra fake // extension. RTC_CHECK_GE(header.headerLength, rtp_packet.headers_size()); size_t bytes_to_add = header.headerLength - rtp_packet.headers_size(); if (bytes_to_add > 0) { if (bytes_to_add <= 16) { // one-byte header rtp header extension allows to add up to 16 bytes. rtp_packet.AllocateExtension(FakeExtensionSmall::kId, bytes_to_add - 1); } else { // two-byte header rtp header extension would also add one byte per // already set extension. rtp_packet.AllocateExtension(FakeExtensionLarge::kId, bytes_to_add - 2 - num_bwe_extensions); } } RTC_CHECK_EQ(rtp_packet.headers_size(), header.headerLength); return rtp_packet; } } // namespace class BitrateObserver : public RemoteBitrateObserver { public: BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {} void Update(NetworkControlUpdate update) { if (update.target_rate) { last_bitrate_bps_ = update.target_rate->target_rate.bps(); bitrate_updated_ = true; } } void OnReceiveBitrateChanged(const std::vector& ssrcs, uint32_t bitrate) override {} uint32_t last_bitrate_bps() const { return last_bitrate_bps_; } bool GetAndResetBitrateUpdated() { bool bitrate_updated = bitrate_updated_; bitrate_updated_ = false; return bitrate_updated; } private: uint32_t last_bitrate_bps_; bool bitrate_updated_; }; void CreateIncomingDelayGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { for (const auto& stream : parsed_log.incoming_rtp_packets_by_ssrc()) { // Filter on SSRC. if (!MatchingSsrc(stream.ssrc, config.desired_ssrc_) || IsRtxSsrc(parsed_log, kIncomingPacket, stream.ssrc)) { continue; } const std::vector& packets = stream.incoming_packets; if (packets.size() < 100) { RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency with " << packets.size() << " packets in the stream."; continue; } int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us(); std::optional estimated_frequency = EstimateRtpClockFrequency(packets, segment_end_us); if (!estimated_frequency) continue; const double frequency_hz = *estimated_frequency; if (IsVideoSsrc(parsed_log, kIncomingPacket, stream.ssrc) && frequency_hz != 90000) { RTC_LOG(LS_WARNING) << "Video stream should use a 90 kHz clock but appears to use " << frequency_hz / 1000 << ". Discarding."; continue; } auto ToCallTime = [&config](const LoggedRtpPacketIncoming& packet) { return config.GetCallTimeSec(packet.log_time()); }; auto ToNetworkDelay = [frequency_hz]( const LoggedRtpPacketIncoming& old_packet, const LoggedRtpPacketIncoming& new_packet) { return NetworkDelayDiff_CaptureTime(old_packet, new_packet, frequency_hz); }; TimeSeries capture_time_data( GetStreamName(parsed_log, kIncomingPacket, stream.ssrc) + " capture-time", LineStyle::kLine); AccumulatePairs( ToCallTime, ToNetworkDelay, packets, &capture_time_data); plot->AppendTimeSeries(std::move(capture_time_data)); TimeSeries send_time_data( GetStreamName(parsed_log, kIncomingPacket, stream.ssrc) + " abs-send-time", LineStyle::kLine); AccumulatePairs( ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data); plot->AppendTimeSeriesIfNotEmpty(std::move(send_time_data)); } plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 1, "Delay (ms)", kBottomMargin, kTopMargin); plot->SetTitle("Incoming network delay (relative to first packet)"); } // Plot the fraction of packets lost (as perceived by the loss-based BWE). void CreateFractionLossGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries time_series("Fraction lost", LineStyle::kLine, PointStyle::kHighlight); for (auto& bwe_update : parsed_log.bwe_loss_updates()) { float x = config.GetCallTimeSec(bwe_update.log_time()); float y = static_cast(bwe_update.fraction_lost) / 255 * 100; time_series.points.emplace_back(x, y); } plot->AppendTimeSeries(std::move(time_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Loss rate (in %)", kBottomMargin, kTopMargin); plot->SetTitle("Outgoing packet loss (as reported by BWE)"); } // Plot the total bandwidth used by all RTP streams. void CreateTotalIncomingBitrateGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { // TODO(terelius): This could be provided by the parser. std::multimap packets_in_order; for (const auto& stream : parsed_log.incoming_rtp_packets_by_ssrc()) { for (const LoggedRtpPacketIncoming& packet : stream.incoming_packets) packets_in_order.insert( std::make_pair(packet.rtp.log_time(), packet.rtp.total_length)); } auto window_begin = packets_in_order.begin(); auto window_end = packets_in_order.begin(); size_t bytes_in_window = 0; if (!packets_in_order.empty()) { // Calculate a moving average of the bitrate and store in a TimeSeries. TimeSeries bitrate_series("Bitrate", LineStyle::kLine); for (Timestamp time = config.begin_time_; time < config.end_time_ + config.step_; time += config.step_) { while (window_end != packets_in_order.end() && window_end->first < time) { bytes_in_window += window_end->second; ++window_end; } while (window_begin != packets_in_order.end() && window_begin->first < time - config.window_duration_) { RTC_DCHECK_LE(window_begin->second, bytes_in_window); bytes_in_window -= window_begin->second; ++window_begin; } float window_duration_in_seconds = static_cast(config.window_duration_.us()) / kNumMicrosecsPerSec; float x = config.GetCallTimeSec(time); float y = bytes_in_window * 8 / window_duration_in_seconds / 1000; bitrate_series.points.emplace_back(x, y); } plot->AppendTimeSeries(std::move(bitrate_series)); } // Overlay the outgoing REMB over incoming bitrate. TimeSeries remb_series("Remb", LineStyle::kStep); for (const auto& rtcp : parsed_log.rembs(kOutgoingPacket)) { float x = config.GetCallTimeSec(rtcp.log_time()); float y = static_cast(rtcp.remb.bitrate_bps()) / 1000; remb_series.points.emplace_back(x, y); } plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin); plot->SetTitle("Incoming RTP bitrate"); } // Plot the total bandwidth used by all RTP streams. void CreateTotalOutgoingBitrateGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot, bool show_detector_state, bool show_alr_state, bool show_link_capacity) { // TODO(terelius): This could be provided by the parser. std::multimap packets_in_order; for (const auto& stream : parsed_log.outgoing_rtp_packets_by_ssrc()) { for (const LoggedRtpPacketOutgoing& packet : stream.outgoing_packets) packets_in_order.insert( std::make_pair(packet.rtp.log_time(), packet.rtp.total_length)); } auto window_begin = packets_in_order.begin(); auto window_end = packets_in_order.begin(); size_t bytes_in_window = 0; if (!packets_in_order.empty()) { // Calculate a moving average of the bitrate and store in a TimeSeries. TimeSeries bitrate_series("Bitrate", LineStyle::kLine); for (Timestamp time = config.begin_time_; time < config.end_time_ + config.step_; time += config.step_) { while (window_end != packets_in_order.end() && window_end->first < time) { bytes_in_window += window_end->second; ++window_end; } while (window_begin != packets_in_order.end() && window_begin->first < time - config.window_duration_) { RTC_DCHECK_LE(window_begin->second, bytes_in_window); bytes_in_window -= window_begin->second; ++window_begin; } float window_duration_in_seconds = static_cast(config.window_duration_.us()) / kNumMicrosecsPerSec; float x = config.GetCallTimeSec(time); float y = bytes_in_window * 8 / window_duration_in_seconds / 1000; bitrate_series.points.emplace_back(x, y); } plot->AppendTimeSeries(std::move(bitrate_series)); } // Overlay the send-side bandwidth estimate over the outgoing bitrate. TimeSeries loss_series("Loss-based estimate", LineStyle::kStep); for (auto& loss_update : parsed_log.bwe_loss_updates()) { float x = config.GetCallTimeSec(loss_update.log_time()); float y = static_cast(loss_update.bitrate_bps) / 1000; loss_series.points.emplace_back(x, y); } TimeSeries link_capacity_lower_series("Link-capacity-lower", LineStyle::kStep); TimeSeries link_capacity_upper_series("Link-capacity-upper", LineStyle::kStep); for (auto& remote_estimate_event : parsed_log.remote_estimate_events()) { float x = config.GetCallTimeSec(remote_estimate_event.log_time()); if (remote_estimate_event.link_capacity_lower.has_value()) { float link_capacity_lower = static_cast( remote_estimate_event.link_capacity_lower.value().kbps()); link_capacity_lower_series.points.emplace_back(x, link_capacity_lower); } if (remote_estimate_event.link_capacity_upper.has_value()) { float link_capacity_upper = static_cast( remote_estimate_event.link_capacity_upper.value().kbps()); link_capacity_upper_series.points.emplace_back(x, link_capacity_upper); } } TimeSeries delay_series("Delay-based estimate", LineStyle::kStep); IntervalSeries overusing_series("Overusing", "#ff8e82", IntervalSeries::kHorizontal); IntervalSeries underusing_series("Underusing", "#5092fc", IntervalSeries::kHorizontal); IntervalSeries normal_series("Normal", "#c4ffc4", IntervalSeries::kHorizontal); IntervalSeries* last_series = &normal_series; float last_detector_switch = 0.0; BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal; for (auto& delay_update : parsed_log.bwe_delay_updates()) { float x = config.GetCallTimeSec(delay_update.log_time()); float y = static_cast(delay_update.bitrate_bps) / 1000; if (last_detector_state != delay_update.detector_state) { last_series->intervals.emplace_back(last_detector_switch, x); last_detector_state = delay_update.detector_state; last_detector_switch = x; switch (delay_update.detector_state) { case BandwidthUsage::kBwNormal: last_series = &normal_series; break; case BandwidthUsage::kBwUnderusing: last_series = &underusing_series; break; case BandwidthUsage::kBwOverusing: last_series = &overusing_series; break; case BandwidthUsage::kLast: RTC_DCHECK_NOTREACHED(); } } delay_series.points.emplace_back(x, y); } RTC_CHECK(last_series); last_series->intervals.emplace_back(last_detector_switch, config.CallEndTimeSec()); TimeSeries scream_series("Scream target rate", LineStyle::kStep); for (auto& scream_update : parsed_log.bwe_scream_updates()) { float x = config.GetCallTimeSec(scream_update.log_time()); float y = static_cast(scream_update.target_rate.kbps()); scream_series.points.emplace_back(x, y); } TimeSeries created_series("Probe cluster created.", LineStyle::kNone, PointStyle::kHighlight); for (auto& cluster : parsed_log.bwe_probe_cluster_created_events()) { float x = config.GetCallTimeSec(cluster.log_time()); float y = static_cast(cluster.bitrate_bps) / 1000; created_series.points.emplace_back(x, y); } TimeSeries result_series("Probing results.", LineStyle::kNone, PointStyle::kHighlight); for (auto& result : parsed_log.bwe_probe_success_events()) { float x = config.GetCallTimeSec(result.log_time()); float y = static_cast(result.bitrate_bps) / 1000; result_series.points.emplace_back(x, y); } TimeSeries probe_failures_series("Probe failed", LineStyle::kNone, PointStyle::kHighlight); for (auto& failure : parsed_log.bwe_probe_failure_events()) { float x = config.GetCallTimeSec(failure.log_time()); probe_failures_series.points.emplace_back(x, 0); } IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal); bool previously_in_alr = false; Timestamp alr_start = Timestamp::Zero(); for (auto& alr : parsed_log.alr_state_events()) { float y = config.GetCallTimeSec(alr.log_time()); if (!previously_in_alr && alr.in_alr) { alr_start = alr.log_time(); previously_in_alr = true; } else if (previously_in_alr && !alr.in_alr) { float x = config.GetCallTimeSec(alr_start); alr_state.intervals.emplace_back(x, y); previously_in_alr = false; } } if (previously_in_alr) { float x = config.GetCallTimeSec(alr_start); float y = config.GetCallTimeSec(config.end_time_); alr_state.intervals.emplace_back(x, y); } if (show_detector_state) { plot->AppendIntervalSeries(std::move(overusing_series)); plot->AppendIntervalSeries(std::move(underusing_series)); plot->AppendIntervalSeries(std::move(normal_series)); } if (show_alr_state) { plot->AppendIntervalSeries(std::move(alr_state)); } if (show_link_capacity) { plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_lower_series)); plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_upper_series)); } plot->AppendTimeSeries(std::move(loss_series)); plot->AppendTimeSeriesIfNotEmpty(std::move(probe_failures_series)); plot->AppendTimeSeries(std::move(delay_series)); plot->AppendTimeSeriesIfNotEmpty(std::move(scream_series)); plot->AppendTimeSeries(std::move(created_series)); plot->AppendTimeSeries(std::move(result_series)); // Overlay the incoming REMB over the outgoing bitrate. TimeSeries remb_series("Remb", LineStyle::kStep); for (const auto& rtcp : parsed_log.rembs(kIncomingPacket)) { float x = config.GetCallTimeSec(rtcp.log_time()); float y = static_cast(rtcp.remb.bitrate_bps()) / 1000; remb_series.points.emplace_back(x, y); } plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin); plot->SetTitle("Outgoing RTP bitrate"); } void CreateGoogCcSimulationGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries target_rates("Simulated target rate", LineStyle::kStep, PointStyle::kHighlight); TimeSeries delay_based("Logged delay-based estimate", LineStyle::kStep, PointStyle::kHighlight); TimeSeries loss_based("Logged loss-based estimate", LineStyle::kStep, PointStyle::kHighlight); TimeSeries probe_results("Logged probe success", LineStyle::kNone, PointStyle::kHighlight); LogBasedNetworkControllerSimulation simulation( config.env_, std::make_unique(), [&](const NetworkControlUpdate& update, Timestamp at_time) { if (update.target_rate) { target_rates.points.emplace_back( config.GetCallTimeSec(at_time), update.target_rate->target_rate.kbps()); } }); simulation.ProcessEventsInLog(parsed_log); for (const auto& logged : parsed_log.bwe_delay_updates()) delay_based.points.emplace_back(config.GetCallTimeSec(logged.log_time()), logged.bitrate_bps / 1000); for (const auto& logged : parsed_log.bwe_probe_success_events()) probe_results.points.emplace_back(config.GetCallTimeSec(logged.log_time()), logged.bitrate_bps / 1000); for (const auto& logged : parsed_log.bwe_loss_updates()) loss_based.points.emplace_back(config.GetCallTimeSec(logged.log_time()), logged.bitrate_bps / 1000); plot->AppendTimeSeries(std::move(delay_based)); plot->AppendTimeSeries(std::move(loss_based)); plot->AppendTimeSeries(std::move(probe_results)); plot->AppendTimeSeries(std::move(target_rates)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin); plot->SetTitle("Simulated BWE behavior"); } void CreateScreamSimulationDelayGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries smoothed_rtt_series("Smoothed RTT", LineStyle::kStep); TimeSeries queue_delay_series("Queue delay", LineStyle::kStep); TimeSeries queue_delay_min_avg_series("Queue delay min avg", LineStyle::kStep); TimeSeries latency_difference_avg_series("Latency difference avg", LineStyle::kStep); LogScreamSimulation simulation({.rate_window = config.window_duration_}, config.env_); simulation.ProcessEventsInLog(parsed_log); for (const LogScreamSimulation::State& state : simulation.updates()) { smoothed_rtt_series.points.emplace_back(config.GetCallTimeSec(state.time), state.smoothed_rtt.ms()); queue_delay_series.points.emplace_back(config.GetCallTimeSec(state.time), state.queue_delay.ms()); queue_delay_min_avg_series.points.emplace_back( config.GetCallTimeSec(state.time), state.queue_delay_min_avg.ms()); latency_difference_avg_series.points.emplace_back( config.GetCallTimeSec(state.time), state.latency_difference_avg.ms()); } plot->AppendTimeSeries(std::move(smoothed_rtt_series)); plot->AppendTimeSeries(std::move(queue_delay_series)); plot->AppendTimeSeries(std::move(queue_delay_min_avg_series)); plot->AppendTimeSeries(std::move(latency_difference_avg_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 50, "Delay (ms)", kBottomMargin, kTopMargin); plot->SetTitle("Simulated Scream delays"); } void CreateScreamSimulationBitrateGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries target_rate_series("Target rate", LineStyle::kStep); TimeSeries pacing_rate_series("Pacing rate", LineStyle::kStep); TimeSeries send_rate_series("Send rate", LineStyle::kStep); LogScreamSimulation simulation({.rate_window = config.window_duration_}, config.env_); simulation.ProcessEventsInLog(parsed_log); for (const LogScreamSimulation::State& state : simulation.updates()) { target_rate_series.points.emplace_back(config.GetCallTimeSec(state.time), state.target_rate.bps() / 1000); pacing_rate_series.points.emplace_back(config.GetCallTimeSec(state.time), state.pacing_rate.bps() / 1000); send_rate_series.points.emplace_back(config.GetCallTimeSec(state.time), state.send_rate.bps() / 1000); } plot->AppendTimeSeries(std::move(target_rate_series)); plot->AppendTimeSeries(std::move(pacing_rate_series)); plot->AppendTimeSeries(std::move(send_rate_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 100, "Kbps", kBottomMargin, kTopMargin); plot->SetTitle("Simulated Scream rates"); } void CreateScreamSimulationRefWindowGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { using SendWindowUsage = LogScreamSimulation::State::SendWindowUsage; TimeSeries ref_window_series("RefWindow", LineStyle::kStep); TimeSeries ref_window_i_series("RefWindowI", LineStyle::kStep); TimeSeries max_data_in_flight("Max allowed data in flight", LineStyle::kStep); TimeSeries max_allowed_ref_window_series("Max allowed ref window", LineStyle::kStep); TimeSeries data_in_flight("Data in flight", LineStyle::kStep); IntervalSeries send_window_above_max_series( "Data in flight > Max allowed", "#ff8e82", IntervalSeries::kHorizontal); IntervalSeries send_window_below_ref_window_series( "Data in flight < RefWindow", "#c5dff2", IntervalSeries::kHorizontal); IntervalSeries send_window_above_ref_window_series( "Data in flight >= RefWindow", "#b9fad8", IntervalSeries::kHorizontal); IntervalSeries* last_series = &send_window_below_ref_window_series; LogScreamSimulation simulation({.rate_window = config.window_duration_}, config.env_); simulation.ProcessEventsInLog(parsed_log); if (simulation.updates().empty()) { RTC_LOG(LS_ERROR) << "Empty simulation."; return; } float send_window_state_switch = config.GetCallTimeSec(simulation.updates().front().time); SendWindowUsage send_window_usage = SendWindowUsage::kBelowRefWindow; float last_time = config.CallBeginTimeSec(); for (const LogScreamSimulation::State& state : simulation.updates()) { ref_window_series.points.emplace_back(config.GetCallTimeSec(state.time), state.ref_window.bytes()); ref_window_i_series.points.emplace_back(config.GetCallTimeSec(state.time), state.ref_window_i.bytes()); max_data_in_flight.points.emplace_back(config.GetCallTimeSec(state.time), state.max_data_in_flight.bytes()); max_allowed_ref_window_series.points.emplace_back( config.GetCallTimeSec(state.time), state.max_allowed_ref_window.bytes()); // Plot the max data in flight before the feedback. data_in_flight.points.emplace_back(last_time, state.data_in_flight.bytes()); if (state.send_window_usage != send_window_usage) { last_series->intervals.emplace_back(send_window_state_switch, config.GetCallTimeSec(state.time)); send_window_usage = state.send_window_usage; send_window_state_switch = config.GetCallTimeSec(state.time); switch (send_window_usage) { case SendWindowUsage::kAboveRefWindow: last_series = &send_window_above_ref_window_series; break; case SendWindowUsage::kBelowRefWindow: last_series = &send_window_below_ref_window_series; break; case SendWindowUsage::kAboveScreamMax: last_series = &send_window_above_max_series; break; } } last_time = config.GetCallTimeSec(state.time); } last_series->intervals.emplace_back(send_window_state_switch, config.CallEndTimeSec()); plot->AppendTimeSeries(std::move(ref_window_series)); plot->AppendTimeSeries(std::move(ref_window_i_series)); plot->AppendTimeSeries(std::move(max_data_in_flight)); plot->AppendTimeSeries(std::move(max_allowed_ref_window_series)); plot->AppendTimeSeries(std::move(data_in_flight)); plot->AppendIntervalSeries(std::move(send_window_above_max_series)); plot->AppendIntervalSeries(std::move(send_window_below_ref_window_series)); plot->AppendIntervalSeries(std::move(send_window_above_ref_window_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Bytes", kBottomMargin, kTopMargin); plot->SetTitle("Simulated Scream RefWindow"); } void CreateScreamSimulationRatiosGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries queue_delay_dev_norm_series("QueueDelayDevNorm", LineStyle::kStep); TimeSeries l4s_alpha_series("L4sAlpha", LineStyle::kStep); TimeSeries l4s_alpha_v_series("L4sAlphaV", LineStyle::kStep); TimeSeries ref_window_scale_factor_due_to_min_delay_variation( "RefWindowScaleFactorDueToAvgMinQueueDelay", LineStyle::kStep); TimeSeries ref_window_scale_factor_due_to_latency_difference( "RefWindowScaleFactorDueToAvgLatencyDifference", LineStyle::kStep); TimeSeries ref_window_scale_factor_close_to_ref_window_i( "RefWindowScaleFactorCloseToRefWindowI", LineStyle::kStep); TimeSeries ref_window_combined_increase_scale_factor( "RefWindowCombinedIncreaseScaleFactor", LineStyle::kStep); LogScreamSimulation simulation({.rate_window = config.window_duration_}, config.env_); simulation.ProcessEventsInLog(parsed_log); for (const LogScreamSimulation::State& state : simulation.updates()) { queue_delay_dev_norm_series.points.emplace_back( config.GetCallTimeSec(state.time), state.queue_delay_dev_norm); l4s_alpha_series.points.emplace_back(config.GetCallTimeSec(state.time), state.l4s_alpha); l4s_alpha_v_series.points.emplace_back(config.GetCallTimeSec(state.time), state.l4s_alpha_v); ref_window_scale_factor_due_to_min_delay_variation.points.emplace_back( config.GetCallTimeSec(state.time), state.ref_window_scale_factor_due_to_avg_min_delay); ref_window_scale_factor_due_to_latency_difference.points.emplace_back( config.GetCallTimeSec(state.time), state.ref_window_scale_factor_due_to_latency_difference); ref_window_scale_factor_close_to_ref_window_i.points.emplace_back( config.GetCallTimeSec(state.time), state.ref_window_scale_factor_close_to_ref_window_i); ref_window_combined_increase_scale_factor.points.emplace_back( config.GetCallTimeSec(state.time), state.ref_window_combined_increase_scale_factor); } plot->AppendTimeSeries(std::move(queue_delay_dev_norm_series)); plot->AppendTimeSeries(std::move(l4s_alpha_series)); plot->AppendTimeSeries(std::move(l4s_alpha_v_series)); plot->AppendTimeSeries( std::move(ref_window_scale_factor_due_to_min_delay_variation)); plot->AppendTimeSeries( std::move(ref_window_scale_factor_due_to_latency_difference)); plot->AppendTimeSeries( std::move(ref_window_scale_factor_close_to_ref_window_i)); plot->AppendTimeSeries(std::move(ref_window_combined_increase_scale_factor)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 1, "Ratios", kBottomMargin, kTopMargin); plot->SetTitle("Simulated Scream Ratios"); } void CreateScreamRefWindowGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries ref_window_series("RefWindow", LineStyle::kStep); for (auto& scream_update : parsed_log.bwe_scream_updates()) { float x = config.GetCallTimeSec(scream_update.log_time()); float y = static_cast(scream_update.ref_window.bytes()); ref_window_series.points.emplace_back(x, y); } plot->AppendTimeSeries(std::move(ref_window_series)); TimeSeries data_in_flight_series("Data in flight", LineStyle::kLine); for (auto& scream_update : parsed_log.bwe_scream_updates()) { float x = config.GetCallTimeSec(scream_update.log_time()); float y = static_cast(scream_update.data_in_flight.bytes()); data_in_flight_series.points.emplace_back(x, y); } plot->AppendTimeSeries(std::move(data_in_flight_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 3000, "Bytes", kBottomMargin, kTopMargin); plot->SetTitle("Scream Ref Window"); } void CreateScreamDelayEstimateGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries smoothed_rtt_series("Smoothed RTT", LineStyle::kStep); TimeSeries avg_queue_delay_series("Avg queue delay", LineStyle::kStep); for (auto& scream_update : parsed_log.bwe_scream_updates()) { float x = config.GetCallTimeSec(scream_update.log_time()); float smoothed_rtt_ms = static_cast(scream_update.smoothed_rtt.ms()); smoothed_rtt_series.points.emplace_back(x, smoothed_rtt_ms); float avg_queue_delay_ms = static_cast(scream_update.avg_queue_delay.ms()); avg_queue_delay_series.points.emplace_back(x, avg_queue_delay_ms); } plot->AppendTimeSeries(std::move(smoothed_rtt_series)); plot->AppendTimeSeries(std::move(avg_queue_delay_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 50, "Delay (ms)", kBottomMargin, kTopMargin); plot->SetTitle("Scream delay estimates"); } void CreateSendSideBweSimulationGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { using RtpPacketType = LoggedRtpPacketOutgoing; using TransportFeedbackType = LoggedRtcpPacketTransportFeedback; // TODO(terelius): The parser could provide a clearer view of the // streams, so that we don't have to recalculate it. std::multimap outgoing_rtp; for (const auto& stream : parsed_log.outgoing_rtp_packets_by_ssrc()) { for (const RtpPacketType& rtp_packet : stream.outgoing_packets) outgoing_rtp.insert( std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet)); } const std::vector& incoming_rtcp = parsed_log.transport_feedbacks(kIncomingPacket); SimulatedClock clock(0); BitrateObserver observer; TransportFeedbackAdapter transport_feedback; auto factory = GoogCcNetworkControllerFactory(); TimeDelta process_interval = factory.GetProcessInterval(); // TODO(holmer): Log the call config and use that here instead. static const uint32_t kDefaultStartBitrateBps = 300000; NetworkControllerConfig cc_config(config.env_); cc_config.constraints.at_time = clock.CurrentTime(); cc_config.constraints.starting_rate = DataRate::BitsPerSec(kDefaultStartBitrateBps); auto goog_cc = factory.Create(cc_config); TimeSeries time_series("Delay-based estimate", LineStyle::kStep, PointStyle::kHighlight); TimeSeries acked_time_series("Raw acked bitrate", LineStyle::kLine, PointStyle::kHighlight); TimeSeries robust_time_series("Robust throughput estimate", LineStyle::kLine, PointStyle::kHighlight); TimeSeries acked_estimate_time_series("Acknowledged bitrate estimate", LineStyle::kLine, PointStyle::kHighlight); auto rtp_iterator = outgoing_rtp.begin(); auto rtcp_iterator = incoming_rtcp.begin(); auto NextRtpTime = [&]() { if (rtp_iterator != outgoing_rtp.end()) return static_cast(rtp_iterator->first); return std::numeric_limits::max(); }; auto NextRtcpTime = [&]() { if (rtcp_iterator != incoming_rtcp.end()) return static_cast(rtcp_iterator->log_time_us()); return std::numeric_limits::max(); }; int64_t next_process_time_us_ = std::min({NextRtpTime(), NextRtcpTime()}); auto NextProcessTime = [&]() { if (rtcp_iterator != incoming_rtcp.end() || rtp_iterator != outgoing_rtp.end()) { return next_process_time_us_; } return std::numeric_limits::max(); }; RateStatistics raw_acked_bitrate(750, 8000); FieldTrials throughput_config( "WebRTC-Bwe-RobustThroughputEstimatorSettings/enabled:true/"); std::unique_ptr robust_throughput_estimator( AcknowledgedBitrateEstimatorInterface::Create(&throughput_config)); FieldTrials acked_bitrate_config( "WebRTC-Bwe-RobustThroughputEstimatorSettings/enabled:false/"); std::unique_ptr acknowledged_bitrate_estimator( AcknowledgedBitrateEstimatorInterface::Create(&acked_bitrate_config)); int64_t time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()}); int64_t last_update_us = 0; while (time_us != std::numeric_limits::max()) { clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds()); if (clock.TimeInMicroseconds() >= NextRtpTime()) { RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime()); const RtpPacketType& rtp_packet = *rtp_iterator->second; if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) { RtpPacketToSend send_packet(/*extensions=*/nullptr); send_packet.set_transport_sequence_number( rtp_packet.rtp.header.extension.transportSequenceNumber); send_packet.SetSsrc(rtp_packet.rtp.header.ssrc); send_packet.SetSequenceNumber(rtp_packet.rtp.header.sequenceNumber); send_packet.SetPayloadSize(rtp_packet.rtp.total_length - send_packet.headers_size()); RTC_DCHECK_EQ(send_packet.size(), rtp_packet.rtp.total_length); if (IsRtxSsrc(parsed_log, PacketDirection::kOutgoingPacket, rtp_packet.rtp.header.ssrc)) { // Don't set the optional media type as we don't know if it is // a retransmission, FEC or padding. } else if (IsVideoSsrc(parsed_log, PacketDirection::kOutgoingPacket, rtp_packet.rtp.header.ssrc)) { send_packet.set_packet_type(RtpPacketMediaType::kVideo); } else if (IsAudioSsrc(parsed_log, PacketDirection::kOutgoingPacket, rtp_packet.rtp.header.ssrc)) { send_packet.set_packet_type(RtpPacketMediaType::kAudio); } transport_feedback.AddPacket( send_packet, PacedPacketInfo(), 0u, // Per packet overhead bytes., Timestamp::Micros(rtp_packet.rtp.log_time_us())); } SentPacketInfo sent_packet; sent_packet.send_time_ms = rtp_packet.rtp.log_time_ms(); sent_packet.info.included_in_allocation = true; sent_packet.info.packet_size_bytes = rtp_packet.rtp.total_length; if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) { sent_packet.packet_id = rtp_packet.rtp.header.extension.transportSequenceNumber; sent_packet.info.included_in_feedback = true; } auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet); if (sent_msg) observer.Update(goog_cc->OnSentPacket(*sent_msg)); ++rtp_iterator; } if (clock.TimeInMicroseconds() >= NextRtcpTime()) { RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime()); auto feedback_msg = transport_feedback.ProcessTransportFeedback( rtcp_iterator->transport_feedback, clock.CurrentTime()); if (feedback_msg) { observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg)); std::vector feedback = feedback_msg->SortedByReceiveTime(); if (!feedback.empty()) { acknowledged_bitrate_estimator->IncomingPacketFeedbackVector( feedback); robust_throughput_estimator->IncomingPacketFeedbackVector(feedback); for (const PacketResult& packet : feedback) { raw_acked_bitrate.Update(packet.sent_packet.size.bytes(), packet.receive_time.ms()); } std::optional raw_bitrate_bps = raw_acked_bitrate.Rate(feedback.back().receive_time.ms()); float x = config.GetCallTimeSec(clock.CurrentTime()); if (raw_bitrate_bps) { float y = raw_bitrate_bps.value() / 1000; acked_time_series.points.emplace_back(x, y); } std::optional robust_estimate = robust_throughput_estimator->bitrate(); if (robust_estimate) { float y = robust_estimate.value().kbps(); robust_time_series.points.emplace_back(x, y); } std::optional acked_estimate = acknowledged_bitrate_estimator->bitrate(); if (acked_estimate) { float y = acked_estimate.value().kbps(); acked_estimate_time_series.points.emplace_back(x, y); } } } ++rtcp_iterator; } if (clock.TimeInMicroseconds() >= NextProcessTime()) { RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime()); ProcessInterval msg; msg.at_time = clock.CurrentTime(); observer.Update(goog_cc->OnProcessInterval(msg)); next_process_time_us_ += process_interval.us(); } if (observer.GetAndResetBitrateUpdated() || time_us - last_update_us >= 1e6) { uint32_t y = observer.last_bitrate_bps() / 1000; float x = config.GetCallTimeSec(clock.CurrentTime()); time_series.points.emplace_back(x, y); last_update_us = time_us; } time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()}); } // Add the data set to the plot. plot->AppendTimeSeries(std::move(time_series)); plot->AppendTimeSeries(std::move(robust_time_series)); plot->AppendTimeSeries(std::move(acked_time_series)); plot->AppendTimeSeriesIfNotEmpty(std::move(acked_estimate_time_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin); plot->SetTitle("Simulated send-side BWE behavior"); } void CreateReceiveSideBweSimulationGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { using RtpPacketType = LoggedRtpPacketIncoming; class RembInterceptor { public: void SendRemb(uint32_t bitrate_bps, std::vector ssrcs) { last_bitrate_bps_ = bitrate_bps; bitrate_updated_ = true; } uint32_t last_bitrate_bps() const { return last_bitrate_bps_; } bool GetAndResetBitrateUpdated() { bool bitrate_updated = bitrate_updated_; bitrate_updated_ = false; return bitrate_updated; } private: // We don't know the start bitrate, but assume that it is the default 300 // kbps. uint32_t last_bitrate_bps_ = 300000; bool bitrate_updated_ = false; }; std::multimap incoming_rtp; for (const auto& stream : parsed_log.incoming_rtp_packets_by_ssrc()) { if (IsVideoSsrc(parsed_log, kIncomingPacket, stream.ssrc)) { for (const auto& rtp_packet : stream.incoming_packets) incoming_rtp.insert( std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet)); } } SimulatedClock clock(0); EnvironmentFactory env_factory(config.env_); env_factory.Set(&clock); RembInterceptor remb_interceptor; ReceiveSideCongestionController rscc( env_factory.Create(), [](auto...) {}, absl::bind_front(&RembInterceptor::SendRemb, &remb_interceptor)); // TODO(holmer): Log the call config and use that here instead. // static const uint32_t kDefaultStartBitrateBps = 300000; // rscc.SetBweBitrates(0, kDefaultStartBitrateBps, -1); TimeSeries time_series("Receive side estimate", LineStyle::kLine, PointStyle::kHighlight); TimeSeries acked_time_series("Received bitrate", LineStyle::kLine); RateStatistics acked_bitrate(250, 8000); int64_t last_update_us = 0; for (const auto& kv : incoming_rtp) { const RtpPacketType& packet = *kv.second; RtpPacketReceived rtp_packet = RtpPacketForBWEFromHeader(packet.rtp.header); rtp_packet.set_arrival_time(packet.rtp.log_time()); rtp_packet.SetPayloadSize(packet.rtp.total_length - rtp_packet.headers_size()); clock.AdvanceTime(rtp_packet.arrival_time() - clock.CurrentTime()); rscc.OnReceivedPacket(rtp_packet, MediaType::VIDEO); int64_t arrival_time_ms = packet.rtp.log_time().ms(); acked_bitrate.Update(packet.rtp.total_length, arrival_time_ms); std::optional bitrate_bps = acked_bitrate.Rate(arrival_time_ms); if (bitrate_bps) { uint32_t y = *bitrate_bps / 1000; float x = config.GetCallTimeSec(clock.CurrentTime()); acked_time_series.points.emplace_back(x, y); } if (remb_interceptor.GetAndResetBitrateUpdated() || clock.TimeInMicroseconds() - last_update_us >= 1e6) { uint32_t y = remb_interceptor.last_bitrate_bps() / 1000; float x = config.GetCallTimeSec(clock.CurrentTime()); time_series.points.emplace_back(x, y); last_update_us = clock.TimeInMicroseconds(); } } // Add the data set to the plot. plot->AppendTimeSeries(std::move(time_series)); plot->AppendTimeSeries(std::move(acked_time_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin); plot->SetTitle("Simulated receive-side BWE behavior"); } void CreateNetworkDelayFeedbackGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { TimeSeries time_series("Network delay", LineStyle::kLine, PointStyle::kHighlight); int64_t min_send_receive_diff_ms = std::numeric_limits::max(); int64_t min_rtt_ms = std::numeric_limits::max(); std::vector matched_rtp_rtcp = GetNetworkTrace(parsed_log); absl::c_stable_sort(matched_rtp_rtcp, [](const MatchedSendArrivalTimes& a, const MatchedSendArrivalTimes& b) { return a.feedback_arrival_time_ms < b.feedback_arrival_time_ms || (a.feedback_arrival_time_ms == b.feedback_arrival_time_ms && a.arrival_time_ms < b.arrival_time_ms); }); for (const auto& packet : matched_rtp_rtcp) { if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived) continue; float x = config.GetCallTimeSecFromMs(packet.feedback_arrival_time_ms); int64_t y = packet.arrival_time_ms - packet.send_time_ms; int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms; min_rtt_ms = std::min(rtt_ms, min_rtt_ms); min_send_receive_diff_ms = std::min(y, min_send_receive_diff_ms); time_series.points.emplace_back(x, y); } // We assume that the base network delay (w/o queues) is equal to half // the minimum RTT. Therefore rescale the delays by subtracting the minimum // observed 1-ways delay and add half the minimum RTT. const int64_t estimated_clock_offset_ms = min_send_receive_diff_ms - min_rtt_ms / 2; for (TimeSeriesPoint& point : time_series.points) point.y -= estimated_clock_offset_ms; // Add the data set to the plot. plot->AppendTimeSeriesIfNotEmpty(std::move(time_series)); plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin); plot->SetTitle("Outgoing network delay (based on per-packet feedback)"); } void CreatePacerDelayGraph(const ParsedRtcEventLog& parsed_log, const AnalyzerConfig& config, Plot* plot) { for (const auto& stream : parsed_log.outgoing_rtp_packets_by_ssrc()) { const std::vector& packets = stream.outgoing_packets; if (IsRtxSsrc(parsed_log, kOutgoingPacket, stream.ssrc)) { continue; } if (packets.size() < 2) { RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency or the " "pacer delay with less than 2 packets in the stream"; continue; } int64_t segment_end_us = parsed_log.first_log_segment().stop_time_us(); std::optional estimated_frequency = EstimateRtpClockFrequency(packets, segment_end_us); if (!estimated_frequency) continue; if (IsVideoSsrc(parsed_log, kOutgoingPacket, stream.ssrc) && *estimated_frequency != 90000) { RTC_LOG(LS_WARNING) << "Video stream should use a 90 kHz clock but appears to use " << *estimated_frequency / 1000 << ". Discarding."; continue; } TimeSeries pacer_delay_series( GetStreamName(parsed_log, kOutgoingPacket, stream.ssrc) + "(" + std::to_string(*estimated_frequency / 1000) + " kHz)", LineStyle::kLine, PointStyle::kHighlight); SeqNumUnwrapper timestamp_unwrapper; uint64_t first_capture_timestamp = timestamp_unwrapper.Unwrap(packets.front().rtp.header.timestamp); uint64_t first_send_timestamp = packets.front().rtp.log_time_us(); for (const auto& packet : packets) { double capture_time_ms = (static_cast(timestamp_unwrapper.Unwrap( packet.rtp.header.timestamp)) - first_capture_timestamp) / *estimated_frequency * 1000; double send_time_ms = static_cast(packet.rtp.log_time_us() - first_send_timestamp) / 1000; float x = config.GetCallTimeSec(packet.rtp.log_time()); float y = send_time_ms - capture_time_ms; pacer_delay_series.points.emplace_back(x, y); } plot->AppendTimeSeries(std::move(pacer_delay_series)); } plot->SetXAxis(config.CallBeginTimeSec(), config.CallEndTimeSec(), "Time (s)", kLeftMargin, kRightMargin); plot->SetSuggestedYAxis(0, 10, "Pacer delay (ms)", kBottomMargin, kTopMargin); plot->SetTitle( "Delay from capture to send time. (First packet normalized to 0.)"); } } // namespace webrtc