diff options
Diffstat (limited to '')
-rw-r--r-- | third_party/libwebrtc/rtc_tools/rtc_event_log_visualizer/analyzer.cc | 1831 |
1 files changed, 1831 insertions, 0 deletions
diff --git a/third_party/libwebrtc/rtc_tools/rtc_event_log_visualizer/analyzer.cc b/third_party/libwebrtc/rtc_tools/rtc_event_log_visualizer/analyzer.cc new file mode 100644 index 0000000000..a5b8b49302 --- /dev/null +++ b/third_party/libwebrtc/rtc_tools/rtc_event_log_visualizer/analyzer.cc @@ -0,0 +1,1831 @@ +/* + * Copyright (c) 2016 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/analyzer.h" + +#include <algorithm> +#include <cmath> +#include <limits> +#include <map> +#include <memory> +#include <string> +#include <utility> + +#include "absl/algorithm/container.h" +#include "absl/functional/bind_front.h" +#include "absl/strings/string_view.h" +#include "api/function_view.h" +#include "api/network_state_predictor.h" +#include "api/transport/field_trial_based_config.h" +#include "api/transport/goog_cc_factory.h" +#include "call/audio_receive_stream.h" +#include "call/audio_send_stream.h" +#include "call/call.h" +#include "call/video_receive_stream.h" +#include "call/video_send_stream.h" +#include "logging/rtc_event_log/rtc_event_processor.h" +#include "logging/rtc_event_log/rtc_stream_config.h" +#include "modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor.h" +#include "modules/congestion_controller/goog_cc/acknowledged_bitrate_estimator.h" +#include "modules/congestion_controller/goog_cc/bitrate_estimator.h" +#include "modules/congestion_controller/goog_cc/delay_based_bwe.h" +#include "modules/congestion_controller/include/receive_side_congestion_controller.h" +#include "modules/congestion_controller/rtp/transport_feedback_adapter.h" +#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h" +#include "modules/rtp_rtcp/source/rtcp_packet.h" +#include "modules/rtp_rtcp/source/rtcp_packet/common_header.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/sender_report.h" +#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h" +#include "modules/rtp_rtcp/source/rtp_header_extensions.h" +#include "modules/rtp_rtcp/source/rtp_rtcp_interface.h" +#include "rtc_base/checks.h" +#include "rtc_base/logging.h" +#include "rtc_base/numerics/sequence_number_unwrapper.h" +#include "rtc_base/rate_statistics.h" +#include "rtc_base/strings/string_builder.h" +#include "rtc_tools/rtc_event_log_visualizer/log_simulation.h" +#include "test/explicit_key_value_config.h" + +namespace webrtc { + +namespace { + +std::string SsrcToString(uint32_t ssrc) { + rtc::StringBuilder ss; + ss << "SSRC " << ssrc; + return ss.Release(); +} + +// Checks whether an SSRC is contained in the list of desired SSRCs. +// Note that an empty SSRC list matches every SSRC. +bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) { + if (desired_ssrc.empty()) + return true; + return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) != + desired_ssrc.end(); +} + +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<double>(kNumMicrosecsPerSec) / static_cast<double>(1ul << 18); + return abs_send_time * kTimestampToMicroSec; +} + +// Computes the difference `later` - `earlier` where `later` and `earlier` +// are counters that wrap at `modulus`. The difference is chosen to have the +// least absolute value. For example if `modulus` is 8, then the difference will +// be chosen in the range [-3, 4]. If `modulus` is 9, then the difference will +// be in [-4, 4]. +int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) { + RTC_DCHECK_LE(1, modulus); + RTC_DCHECK_LT(later, modulus); + RTC_DCHECK_LT(earlier, modulus); + int64_t difference = + static_cast<int64_t>(later) - static_cast<int64_t>(earlier); + int64_t max_difference = modulus / 2; + int64_t min_difference = max_difference - modulus + 1; + if (difference > max_difference) { + difference -= modulus; + } + if (difference < min_difference) { + difference += modulus; + } + if (difference > max_difference / 2 || difference < min_difference / 2) { + RTC_LOG(LS_WARNING) << "Difference between" << later << " and " << earlier + << " expected to be in the range (" + << min_difference / 2 << "," << max_difference / 2 + << ") but is " << difference + << ". Correct unwrapping is uncertain."; + } + return difference; +} + +// This is much more reliable for outgoing streams than for incoming streams. +template <typename RtpPacketContainer> +absl::optional<uint32_t> EstimateRtpClockFrequency( + const RtpPacketContainer& packets, + int64_t end_time_us) { + RTC_CHECK(packets.size() >= 2); + SeqNumUnwrapper<uint32_t> 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 absl::nullopt; + } + double duration = + static_cast<double>(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 absl::nullopt; +} + +absl::optional<double> 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 absl::nullopt; + } +} + +absl::optional<double> 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<double>(recv_time_diff) / 1000 - + static_cast<double>(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<double>(recv_time_diff) / + kNumMicrosecsPerSec + << "s"; + RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = " + << static_cast<double>(send_time_diff) / sample_rate + << "s"; + } + return delay_change; +} + +template <typename T> +TimeSeries CreateRtcpTypeTimeSeries(const std::vector<T>& rtcp_list, + AnalyzerConfig config, + std::string rtcp_name, + int category_id) { + TimeSeries time_series(rtcp_name, LineStyle::kNone, PointStyle::kHighlight); + for (const auto& rtcp : rtcp_list) { + float x = config.GetCallTimeSec(rtcp.timestamp); + float y = category_id; + time_series.points.emplace_back(x, y); + } + return time_series; +} + +const char kUnknownEnumValue[] = "unknown"; + +const char kIceCandidateTypeLocal[] = "local"; +const char kIceCandidateTypeStun[] = "stun"; +const char kIceCandidateTypePrflx[] = "prflx"; +const char kIceCandidateTypeRelay[] = "relay"; + +const char kProtocolUdp[] = "udp"; +const char kProtocolTcp[] = "tcp"; +const char kProtocolSsltcp[] = "ssltcp"; +const char kProtocolTls[] = "tls"; + +const char kAddressFamilyIpv4[] = "ipv4"; +const char kAddressFamilyIpv6[] = "ipv6"; + +const char kNetworkTypeEthernet[] = "ethernet"; +const char kNetworkTypeLoopback[] = "loopback"; +const char kNetworkTypeWifi[] = "wifi"; +const char kNetworkTypeVpn[] = "vpn"; +const char kNetworkTypeCellular[] = "cellular"; + +std::string GetIceCandidateTypeAsString(webrtc::IceCandidateType type) { + switch (type) { + case webrtc::IceCandidateType::kLocal: + return kIceCandidateTypeLocal; + case webrtc::IceCandidateType::kStun: + return kIceCandidateTypeStun; + case webrtc::IceCandidateType::kPrflx: + return kIceCandidateTypePrflx; + case webrtc::IceCandidateType::kRelay: + return kIceCandidateTypeRelay; + default: + return kUnknownEnumValue; + } +} + +std::string GetProtocolAsString(webrtc::IceCandidatePairProtocol protocol) { + switch (protocol) { + case webrtc::IceCandidatePairProtocol::kUdp: + return kProtocolUdp; + case webrtc::IceCandidatePairProtocol::kTcp: + return kProtocolTcp; + case webrtc::IceCandidatePairProtocol::kSsltcp: + return kProtocolSsltcp; + case webrtc::IceCandidatePairProtocol::kTls: + return kProtocolTls; + default: + return kUnknownEnumValue; + } +} + +std::string GetAddressFamilyAsString( + webrtc::IceCandidatePairAddressFamily family) { + switch (family) { + case webrtc::IceCandidatePairAddressFamily::kIpv4: + return kAddressFamilyIpv4; + case webrtc::IceCandidatePairAddressFamily::kIpv6: + return kAddressFamilyIpv6; + default: + return kUnknownEnumValue; + } +} + +std::string GetNetworkTypeAsString(webrtc::IceCandidateNetworkType type) { + switch (type) { + case webrtc::IceCandidateNetworkType::kEthernet: + return kNetworkTypeEthernet; + case webrtc::IceCandidateNetworkType::kLoopback: + return kNetworkTypeLoopback; + case webrtc::IceCandidateNetworkType::kWifi: + return kNetworkTypeWifi; + case webrtc::IceCandidateNetworkType::kVpn: + return kNetworkTypeVpn; + case webrtc::IceCandidateNetworkType::kCellular: + return kNetworkTypeCellular; + default: + return kUnknownEnumValue; + } +} + +std::string GetCandidatePairLogDescriptionAsString( + const LoggedIceCandidatePairConfig& config) { + // Example: stun:wifi->relay(tcp):cellular@udp:ipv4 + // represents a pair of a local server-reflexive candidate on a WiFi network + // and a remote relay candidate using TCP as the relay protocol on a cell + // network, when the candidate pair communicates over UDP using IPv4. + rtc::StringBuilder ss; + std::string local_candidate_type = + GetIceCandidateTypeAsString(config.local_candidate_type); + std::string remote_candidate_type = + GetIceCandidateTypeAsString(config.remote_candidate_type); + if (config.local_candidate_type == webrtc::IceCandidateType::kRelay) { + local_candidate_type += + "(" + GetProtocolAsString(config.local_relay_protocol) + ")"; + } + ss << local_candidate_type << ":" + << GetNetworkTypeAsString(config.local_network_type) << ":" + << GetAddressFamilyAsString(config.local_address_family) << "->" + << remote_candidate_type << ":" + << GetAddressFamilyAsString(config.remote_address_family) << "@" + << GetProtocolAsString(config.candidate_pair_protocol); + return ss.Release(); +} + +std::string GetDirectionAsString(PacketDirection direction) { + if (direction == kIncomingPacket) { + return "Incoming"; + } else { + return "Outgoing"; + } +} + +std::string GetDirectionAsShortString(PacketDirection direction) { + if (direction == kIncomingPacket) { + return "In"; + } else { + return "Out"; + } +} + +} // namespace + +EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log, + bool normalize_time) + : parsed_log_(log) { + config_.window_duration_ = TimeDelta::Millis(250); + config_.step_ = TimeDelta::Millis(10); + if (!log.start_log_events().empty()) { + config_.rtc_to_utc_offset_ = log.start_log_events()[0].utc_time() - + log.start_log_events()[0].log_time(); + } + config_.normalize_time_ = normalize_time; + config_.begin_time_ = parsed_log_.first_timestamp(); + config_.end_time_ = parsed_log_.last_timestamp(); + if (config_.end_time_ < config_.begin_time_) { + RTC_LOG(LS_WARNING) << "No useful events in the log."; + config_.begin_time_ = config_.end_time_ = Timestamp::Zero(); + } + + RTC_LOG(LS_INFO) << "Log is " + << (parsed_log_.last_timestamp().ms() - + parsed_log_.first_timestamp().ms()) / + 1000 + << " seconds long."; +} + +EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log, + const AnalyzerConfig& config) + : parsed_log_(log), config_(config) { + RTC_LOG(LS_INFO) << "Log is " + << (parsed_log_.last_timestamp().ms() - + parsed_log_.first_timestamp().ms()) / + 1000 + << " seconds long."; +} + +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<uint32_t>& 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 EventLogAnalyzer::CreatePacketGraph(PacketDirection direction, + Plot* plot) { + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + // Filter on SSRC. + if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) { + continue; + } + + TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc), + LineStyle::kBar); + auto GetPacketSize = [](const LoggedRtpPacket& packet) { + return absl::optional<float>(packet.total_length); + }; + auto ToCallTime = [this](const LoggedRtpPacket& packet) { + return this->config_.GetCallTimeSec(packet.timestamp); + }; + ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize, + stream.packet_view, &time_series); + plot->AppendTimeSeries(std::move(time_series)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin, + kTopMargin); + plot->SetTitle(GetDirectionAsString(direction) + " RTP packets"); +} + +void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction, + Plot* plot) { + plot->AppendTimeSeries(CreateRtcpTypeTimeSeries( + parsed_log_.transport_feedbacks(direction), config_, "TWCC", 1)); + plot->AppendTimeSeries(CreateRtcpTypeTimeSeries( + parsed_log_.receiver_reports(direction), config_, "RR", 2)); + plot->AppendTimeSeries(CreateRtcpTypeTimeSeries( + parsed_log_.sender_reports(direction), config_, "SR", 3)); + plot->AppendTimeSeries(CreateRtcpTypeTimeSeries( + parsed_log_.extended_reports(direction), config_, "XR", 4)); + plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.nacks(direction), + config_, "NACK", 5)); + plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.rembs(direction), + config_, "REMB", 6)); + plot->AppendTimeSeries( + CreateRtcpTypeTimeSeries(parsed_log_.firs(direction), config_, "FIR", 7)); + plot->AppendTimeSeries( + CreateRtcpTypeTimeSeries(parsed_log_.plis(direction), config_, "PLI", 8)); + plot->AppendTimeSeries( + CreateRtcpTypeTimeSeries(parsed_log_.byes(direction), config_, "BYE", 9)); + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "RTCP type", kBottomMargin, kTopMargin); + plot->SetTitle(GetDirectionAsString(direction) + " RTCP packets"); + plot->SetYAxisTickLabels({{1, "TWCC"}, + {2, "RR"}, + {3, "SR"}, + {4, "XR"}, + {5, "NACK"}, + {6, "REMB"}, + {7, "FIR"}, + {8, "PLI"}, + {9, "BYE"}}); +} + +template <typename IterableType> +void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries( + Plot* plot, + const IterableType& packets, + const std::string& label) { + TimeSeries time_series(label, LineStyle::kStep); + for (size_t i = 0; i < packets.size(); i++) { + float x = config_.GetCallTimeSec(packets[i].log_time()); + time_series.points.emplace_back(x, i + 1); + } + plot->AppendTimeSeries(std::move(time_series)); +} + +void EventLogAnalyzer::CreateAccumulatedPacketsGraph(PacketDirection direction, + Plot* plot) { + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) + continue; + std::string label = std::string("RTP ") + + GetStreamName(parsed_log_, direction, stream.ssrc); + CreateAccumulatedPacketsTimeSeries(plot, stream.packet_view, label); + } + std::string label = + std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")"; + if (direction == kIncomingPacket) { + CreateAccumulatedPacketsTimeSeries( + plot, parsed_log_.incoming_rtcp_packets(), label); + } else { + CreateAccumulatedPacketsTimeSeries( + plot, parsed_log_.outgoing_rtcp_packets(), label); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin); + plot->SetTitle(std::string("Accumulated ") + GetDirectionAsString(direction) + + " RTP/RTCP packets"); +} + +void EventLogAnalyzer::CreatePacketRateGraph(PacketDirection direction, + Plot* plot) { + auto CountPackets = [](auto packet) { return 1.0; }; + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + // Filter on SSRC. + if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) { + continue; + } + TimeSeries time_series( + std::string("RTP ") + + GetStreamName(parsed_log_, direction, stream.ssrc), + LineStyle::kLine); + MovingAverage<LoggedRtpPacket, double>(CountPackets, stream.packet_view, + config_, &time_series); + plot->AppendTimeSeries(std::move(time_series)); + } + TimeSeries time_series( + std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")", + LineStyle::kLine); + if (direction == kIncomingPacket) { + MovingAverage<LoggedRtcpPacketIncoming, double>( + CountPackets, parsed_log_.incoming_rtcp_packets(), config_, + &time_series); + } else { + MovingAverage<LoggedRtcpPacketOutgoing, double>( + CountPackets, parsed_log_.outgoing_rtcp_packets(), config_, + &time_series); + } + plot->AppendTimeSeries(std::move(time_series)); + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin, + kTopMargin); + plot->SetTitle("Rate of " + GetDirectionAsString(direction) + + " RTP/RTCP packets"); +} + +void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction, + Plot* plot) { + // Contains a log timestamp to enable counting logged events of different + // types using MovingAverage(). + class LogTime { + public: + explicit LogTime(Timestamp log_time) : log_time_(log_time) {} + Timestamp log_time() const { return log_time_; } + + private: + Timestamp log_time_; + }; + std::vector<LogTime> packet_times; + auto handle_rtp = [&](const LoggedRtpPacket& packet) { + packet_times.emplace_back(packet.log_time()); + }; + RtcEventProcessor process; + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + process.AddEvents(stream.packet_view, handle_rtp); + } + if (direction == kIncomingPacket) { + auto handle_incoming_rtcp = [&](const LoggedRtcpPacketIncoming& packet) { + packet_times.emplace_back(packet.log_time()); + }; + process.AddEvents(parsed_log_.incoming_rtcp_packets(), + handle_incoming_rtcp); + } else { + auto handle_outgoing_rtcp = [&](const LoggedRtcpPacketOutgoing& packet) { + packet_times.emplace_back(packet.log_time()); + }; + process.AddEvents(parsed_log_.outgoing_rtcp_packets(), + handle_outgoing_rtcp); + } + process.ProcessEventsInOrder(); + TimeSeries time_series(std::string("Total ") + "(" + + GetDirectionAsShortString(direction) + ") packets", + LineStyle::kLine); + MovingAverage<LogTime, uint64_t>([](auto packet) { return 1; }, packet_times, + config_, &time_series); + plot->AppendTimeSeries(std::move(time_series)); + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin, + kTopMargin); + plot->SetTitle("Rate of all " + GetDirectionAsString(direction) + + " RTP/RTCP packets"); +} + +// For each SSRC, plot the time between the consecutive playouts. +void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) { + for (const auto& playout_stream : parsed_log_.audio_playout_events()) { + uint32_t ssrc = playout_stream.first; + if (!MatchingSsrc(ssrc, desired_ssrc_)) + continue; + absl::optional<int64_t> last_playout_ms; + TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar); + for (const auto& playout_event : playout_stream.second) { + float x = config_.GetCallTimeSec(playout_event.log_time()); + int64_t playout_time_ms = playout_event.log_time_ms(); + // If there were no previous playouts, place the point on the x-axis. + float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms); + time_series.points.push_back(TimeSeriesPoint(x, y)); + last_playout_ms.emplace(playout_time_ms); + } + plot->AppendTimeSeries(std::move(time_series)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin, + kTopMargin); + plot->SetTitle("Audio playout"); +} + +void EventLogAnalyzer::CreateNetEqSetMinimumDelay(Plot* plot) { + for (const auto& playout_stream : + parsed_log_.neteq_set_minimum_delay_events()) { + uint32_t ssrc = playout_stream.first; + if (!MatchingSsrc(ssrc, desired_ssrc_)) + continue; + + TimeSeries time_series(SsrcToString(ssrc), LineStyle::kStep, + PointStyle::kHighlight); + for (const auto& event : playout_stream.second) { + float x = config_.GetCallTimeSec(event.log_time()); + float y = event.minimum_delay_ms; + time_series.points.push_back(TimeSeriesPoint(x, y)); + } + plot->AppendTimeSeries(std::move(time_series)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1000, "Minimum Delay (ms)", kBottomMargin, + kTopMargin); + plot->SetTitle("Set Minimum Delay"); +} + +// For audio SSRCs, plot the audio level. +void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction, + Plot* plot) { + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + if (!IsAudioSsrc(parsed_log_, direction, stream.ssrc)) + continue; + TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc), + LineStyle::kLine); + for (auto& packet : stream.packet_view) { + if (packet.header.extension.hasAudioLevel) { + float x = config_.GetCallTimeSec(packet.log_time()); + // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10) + // Here we convert it to dBov. + float y = static_cast<float>(-packet.header.extension.audioLevel); + time_series.points.emplace_back(TimeSeriesPoint(x, y)); + } + } + plot->AppendTimeSeries(std::move(time_series)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin, kTopMargin); + plot->SetTitle(GetDirectionAsString(direction) + " audio level"); +} + +// For each SSRC, plot the sequence number difference between consecutive +// incoming packets. +void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) { + for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) { + // Filter on SSRC. + if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) { + continue; + } + + TimeSeries time_series( + GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc), + LineStyle::kBar); + auto GetSequenceNumberDiff = [](const LoggedRtpPacketIncoming& old_packet, + const LoggedRtpPacketIncoming& new_packet) { + int64_t diff = + WrappingDifference(new_packet.rtp.header.sequenceNumber, + old_packet.rtp.header.sequenceNumber, 1ul << 16); + return diff; + }; + auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) { + return this->config_.GetCallTimeSec(packet.log_time()); + }; + ProcessPairs<LoggedRtpPacketIncoming, float>( + ToCallTime, GetSequenceNumberDiff, stream.incoming_packets, + &time_series); + plot->AppendTimeSeries(std::move(time_series)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin, + kTopMargin); + plot->SetTitle("Incoming sequence number delta"); +} + +void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) { + for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) { + const std::vector<LoggedRtpPacketIncoming>& packets = + stream.incoming_packets; + // Filter on SSRC. + if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || packets.empty()) { + continue; + } + + TimeSeries time_series( + GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc), + LineStyle::kLine, PointStyle::kHighlight); + // TODO(terelius): Should the window and step size be read from the class + // instead? + const TimeDelta kWindow = TimeDelta::Millis(1000); + const TimeDelta kStep = TimeDelta::Millis(1000); + SeqNumUnwrapper<uint16_t> unwrapper_; + SeqNumUnwrapper<uint16_t> prior_unwrapper_; + size_t window_index_begin = 0; + size_t window_index_end = 0; + uint64_t highest_seq_number = + unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1; + uint64_t highest_prior_seq_number = + prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1; + + for (Timestamp t = config_.begin_time_; t < config_.end_time_ + kStep; + t += kStep) { + while (window_index_end < packets.size() && + packets[window_index_end].rtp.log_time() < t) { + uint64_t sequence_number = unwrapper_.Unwrap( + packets[window_index_end].rtp.header.sequenceNumber); + highest_seq_number = std::max(highest_seq_number, sequence_number); + ++window_index_end; + } + while (window_index_begin < packets.size() && + packets[window_index_begin].rtp.log_time() < t - kWindow) { + uint64_t sequence_number = prior_unwrapper_.Unwrap( + packets[window_index_begin].rtp.header.sequenceNumber); + highest_prior_seq_number = + std::max(highest_prior_seq_number, sequence_number); + ++window_index_begin; + } + float x = config_.GetCallTimeSec(t); + uint64_t expected_packets = highest_seq_number - highest_prior_seq_number; + if (expected_packets > 0) { + int64_t received_packets = window_index_end - window_index_begin; + int64_t lost_packets = expected_packets - received_packets; + float y = static_cast<float>(lost_packets) / expected_packets * 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, 1, "Loss rate (in %)", kBottomMargin, kTopMargin); + plot->SetTitle("Incoming packet loss (derived from incoming packets)"); +} + +void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) { + for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) { + // Filter on SSRC. + if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || + IsRtxSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) { + continue; + } + + const std::vector<LoggedRtpPacketIncoming>& 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(); + absl::optional<uint32_t> 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 = [this](const LoggedRtpPacketIncoming& packet) { + return this->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<LoggedRtpPacketIncoming, double>( + 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<LoggedRtpPacketIncoming, double>( + 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 EventLogAnalyzer::CreateFractionLossGraph(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<float>(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 EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) { + // TODO(terelius): This could be provided by the parser. + std::multimap<Timestamp, size_t> 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<float>(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<float>(rtcp.remb.bitrate_bps()) / 1000; + remb_series.points.emplace_back(x, y); + } + plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series)); + + if (!parsed_log_.generic_packets_received().empty()) { + TimeSeries time_series("Incoming generic bitrate", LineStyle::kLine); + auto GetPacketSizeKilobits = [](const LoggedGenericPacketReceived& packet) { + return packet.packet_length * 8.0 / 1000.0; + }; + MovingAverage<LoggedGenericPacketReceived, double>( + GetPacketSizeKilobits, parsed_log_.generic_packets_received(), config_, + &time_series); + plot->AppendTimeSeries(std::move(time_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 EventLogAnalyzer::CreateTotalOutgoingBitrateGraph( + 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<Timestamp, size_t> 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<float>(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<float>(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<float>( + 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<float>( + 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<float>(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 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<float>(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<float>(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->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<float>(rtcp.remb.bitrate_bps()) / 1000; + remb_series.points.emplace_back(x, y); + } + plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series)); + + if (!parsed_log_.generic_packets_sent().empty()) { + { + TimeSeries time_series("Outgoing generic total bitrate", + LineStyle::kLine); + auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) { + return packet.packet_length() * 8.0 / 1000.0; + }; + MovingAverage<LoggedGenericPacketSent, double>( + GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_, + &time_series); + plot->AppendTimeSeries(std::move(time_series)); + } + + { + TimeSeries time_series("Outgoing generic payload bitrate", + LineStyle::kLine); + auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) { + return packet.payload_length * 8.0 / 1000.0; + }; + MovingAverage<LoggedGenericPacketSent, double>( + GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_, + &time_series); + plot->AppendTimeSeries(std::move(time_series)); + } + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin); + plot->SetTitle("Outgoing RTP bitrate"); +} + +// For each SSRC, plot the bandwidth used by that stream. +void EventLogAnalyzer::CreateStreamBitrateGraph(PacketDirection direction, + Plot* plot) { + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + // Filter on SSRC. + if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) { + continue; + } + + TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc), + LineStyle::kLine); + auto GetPacketSizeKilobits = [](const LoggedRtpPacket& packet) { + return packet.total_length * 8.0 / 1000.0; + }; + MovingAverage<LoggedRtpPacket, double>( + GetPacketSizeKilobits, stream.packet_view, config_, &time_series); + plot->AppendTimeSeries(std::move(time_series)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin); + plot->SetTitle(GetDirectionAsString(direction) + " bitrate per stream"); +} + +// Plot the bitrate allocation for each temporal and spatial layer. +// Computed from RTCP XR target bitrate block, so the graph is only populated if +// those are sent. +void EventLogAnalyzer::CreateBitrateAllocationGraph(PacketDirection direction, + Plot* plot) { + std::map<LayerDescription, TimeSeries> time_series; + const auto& xr_list = parsed_log_.extended_reports(direction); + for (const auto& rtcp : xr_list) { + const absl::optional<rtcp::TargetBitrate>& target_bitrate = + rtcp.xr.target_bitrate(); + if (!target_bitrate.has_value()) + continue; + for (const auto& bitrate_item : target_bitrate->GetTargetBitrates()) { + LayerDescription layer(rtcp.xr.sender_ssrc(), bitrate_item.spatial_layer, + bitrate_item.temporal_layer); + auto time_series_it = time_series.find(layer); + if (time_series_it == time_series.end()) { + std::string layer_name = GetLayerName(layer); + bool inserted; + std::tie(time_series_it, inserted) = time_series.insert( + std::make_pair(layer, TimeSeries(layer_name, LineStyle::kStep))); + RTC_DCHECK(inserted); + } + float x = config_.GetCallTimeSec(rtcp.log_time()); + float y = bitrate_item.target_bitrate_kbps; + time_series_it->second.points.emplace_back(x, y); + } + } + for (auto& layer : time_series) { + plot->AppendTimeSeries(std::move(layer.second)); + } + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin); + if (direction == kIncomingPacket) + plot->SetTitle("Target bitrate per incoming layer"); + else + plot->SetTitle("Target bitrate per outgoing layer"); +} + +void EventLogAnalyzer::CreateGoogCcSimulationGraph(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( + std::make_unique<GoogCcNetworkControllerFactory>(), + [&](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<float>()); + } + }); + + 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 EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) { + using RtpPacketType = LoggedRtpPacketOutgoing; + using TransportFeedbackType = LoggedRtcpPacketTransportFeedback; + + // TODO(terelius): This could be provided by the parser. + std::multimap<int64_t, const RtpPacketType*> 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<TransportFeedbackType>& incoming_rtcp = + parsed_log_.transport_feedbacks(kIncomingPacket); + + SimulatedClock clock(0); + BitrateObserver observer; + RtcEventLogNull null_event_log; + 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; + cc_config.constraints.at_time = Timestamp::Micros(clock.TimeInMicroseconds()); + cc_config.constraints.starting_rate = + DataRate::BitsPerSec(kDefaultStartBitrateBps); + cc_config.event_log = &null_event_log; + 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("Ackednowledged 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<int64_t>(rtp_iterator->first); + return std::numeric_limits<int64_t>::max(); + }; + + auto NextRtcpTime = [&]() { + if (rtcp_iterator != incoming_rtcp.end()) + return static_cast<int64_t>(rtcp_iterator->log_time_us()); + return std::numeric_limits<int64_t>::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<int64_t>::max(); + }; + + RateStatistics raw_acked_bitrate(750, 8000); + test::ExplicitKeyValueConfig throughput_config( + "WebRTC-Bwe-RobustThroughputEstimatorSettings/" + "enabled:true,required_packets:10," + "window_packets:25,window_duration:1000ms,unacked_weight:1.0/"); + std::unique_ptr<AcknowledgedBitrateEstimatorInterface> + robust_throughput_estimator( + AcknowledgedBitrateEstimatorInterface::Create(&throughput_config)); + FieldTrialBasedConfig field_trial_config; + std::unique_ptr<AcknowledgedBitrateEstimatorInterface> + acknowledged_bitrate_estimator( + AcknowledgedBitrateEstimatorInterface::Create(&field_trial_config)); + int64_t time_us = + std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()}); + int64_t last_update_us = 0; + while (time_us != std::numeric_limits<int64_t>::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) { + RtpPacketSendInfo packet_info; + packet_info.media_ssrc = rtp_packet.rtp.header.ssrc; + packet_info.transport_sequence_number = + rtp_packet.rtp.header.extension.transportSequenceNumber; + packet_info.rtp_sequence_number = rtp_packet.rtp.header.sequenceNumber; + packet_info.length = 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)) { + packet_info.packet_type = RtpPacketMediaType::kVideo; + } else if (IsAudioSsrc(parsed_log_, PacketDirection::kOutgoingPacket, + rtp_packet.rtp.header.ssrc)) { + packet_info.packet_type = RtpPacketMediaType::kAudio; + } + transport_feedback.AddPacket( + packet_info, + 0u, // Per packet overhead bytes. + Timestamp::Micros(rtp_packet.rtp.log_time_us())); + } + rtc::SentPacket 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, + Timestamp::Millis(clock.TimeInMilliseconds())); + if (feedback_msg) { + observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg)); + std::vector<PacketResult> 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()); + } + absl::optional<uint32_t> 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); + } + absl::optional<DataRate> robust_estimate = + robust_throughput_estimator->bitrate(); + if (robust_estimate) { + float y = robust_estimate.value().kbps(); + robust_time_series.points.emplace_back(x, y); + } + absl::optional<DataRate> 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 = Timestamp::Micros(clock.TimeInMicroseconds()); + 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 EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) { + using RtpPacketType = LoggedRtpPacketIncoming; + class RembInterceptor { + public: + void SendRemb(uint32_t bitrate_bps, std::vector<uint32_t> 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<int64_t, const RtpPacketType*> 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); + RembInterceptor remb_interceptor; + ReceiveSideCongestionController rscc( + &clock, [](auto...) {}, + absl::bind_front(&RembInterceptor::SendRemb, &remb_interceptor), nullptr); + // 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; + int64_t arrival_time_ms = packet.rtp.log_time_us() / 1000; + size_t payload = packet.rtp.total_length; /*Should subtract header?*/ + clock.AdvanceTimeMicroseconds(packet.rtp.log_time_us() - + clock.TimeInMicroseconds()); + rscc.OnReceivedPacket(arrival_time_ms, payload, packet.rtp.header); + acked_bitrate.Update(payload, arrival_time_ms); + absl::optional<uint32_t> 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 EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) { + TimeSeries time_series("Network delay", LineStyle::kLine, + PointStyle::kHighlight); + int64_t min_send_receive_diff_ms = std::numeric_limits<int64_t>::max(); + int64_t min_rtt_ms = std::numeric_limits<int64_t>::max(); + + std::vector<MatchedSendArrivalTimes> 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 EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) { + for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) { + const std::vector<LoggedRtpPacketOutgoing>& packets = + stream.outgoing_packets; + + if (IsRtxSsrc(parsed_log_, kOutgoingPacket, stream.ssrc)) { + continue; + } + + if (packets.size() < 2) { + RTC_LOG(LS_WARNING) + << "Can't estimate a 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(); + absl::optional<uint32_t> 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<uint32_t> 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<double>(timestamp_unwrapper.Unwrap( + packet.rtp.header.timestamp)) - + first_capture_timestamp) / + *estimated_frequency * 1000; + double send_time_ms = + static_cast<double>(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.)"); +} + +void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction, + Plot* plot) { + for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) { + TimeSeries rtp_timestamps( + GetStreamName(parsed_log_, direction, stream.ssrc) + " capture-time", + LineStyle::kLine, PointStyle::kHighlight); + for (const auto& packet : stream.packet_view) { + float x = config_.GetCallTimeSec(packet.log_time()); + float y = packet.header.timestamp; + rtp_timestamps.points.emplace_back(x, y); + } + plot->AppendTimeSeries(std::move(rtp_timestamps)); + + TimeSeries rtcp_timestamps( + GetStreamName(parsed_log_, direction, stream.ssrc) + + " rtcp capture-time", + LineStyle::kLine, PointStyle::kHighlight); + // TODO(terelius): Why only sender reports? + const auto& sender_reports = parsed_log_.sender_reports(direction); + for (const auto& rtcp : sender_reports) { + if (rtcp.sr.sender_ssrc() != stream.ssrc) + continue; + float x = config_.GetCallTimeSec(rtcp.log_time()); + float y = rtcp.sr.rtp_timestamp(); + rtcp_timestamps.points.emplace_back(x, y); + } + plot->AppendTimeSeriesIfNotEmpty(std::move(rtcp_timestamps)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "RTP timestamp", kBottomMargin, kTopMargin); + plot->SetTitle(GetDirectionAsString(direction) + " timestamps"); +} + +void EventLogAnalyzer::CreateSenderAndReceiverReportPlot( + PacketDirection direction, + rtc::FunctionView<float(const rtcp::ReportBlock&)> fy, + std::string title, + std::string yaxis_label, + Plot* plot) { + std::map<uint32_t, TimeSeries> sr_reports_by_ssrc; + const auto& sender_reports = parsed_log_.sender_reports(direction); + for (const auto& rtcp : sender_reports) { + float x = config_.GetCallTimeSec(rtcp.log_time()); + uint32_t ssrc = rtcp.sr.sender_ssrc(); + for (const auto& block : rtcp.sr.report_blocks()) { + float y = fy(block); + auto sr_report_it = sr_reports_by_ssrc.find(ssrc); + bool inserted; + if (sr_report_it == sr_reports_by_ssrc.end()) { + std::tie(sr_report_it, inserted) = sr_reports_by_ssrc.emplace( + ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) + + " Sender Reports", + LineStyle::kLine, PointStyle::kHighlight)); + } + sr_report_it->second.points.emplace_back(x, y); + } + } + for (auto& kv : sr_reports_by_ssrc) { + plot->AppendTimeSeries(std::move(kv.second)); + } + + std::map<uint32_t, TimeSeries> rr_reports_by_ssrc; + const auto& receiver_reports = parsed_log_.receiver_reports(direction); + for (const auto& rtcp : receiver_reports) { + float x = config_.GetCallTimeSec(rtcp.log_time()); + uint32_t ssrc = rtcp.rr.sender_ssrc(); + for (const auto& block : rtcp.rr.report_blocks()) { + float y = fy(block); + auto rr_report_it = rr_reports_by_ssrc.find(ssrc); + bool inserted; + if (rr_report_it == rr_reports_by_ssrc.end()) { + std::tie(rr_report_it, inserted) = rr_reports_by_ssrc.emplace( + ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) + + " Receiver Reports", + LineStyle::kLine, PointStyle::kHighlight)); + } + rr_report_it->second.points.emplace_back(x, y); + } + } + for (auto& kv : rr_reports_by_ssrc) { + plot->AppendTimeSeries(std::move(kv.second)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, yaxis_label, kBottomMargin, kTopMargin); + plot->SetTitle(title); +} + +void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) { + std::map<uint32_t, TimeSeries> configs_by_cp_id; + for (const auto& config : parsed_log_.ice_candidate_pair_configs()) { + if (configs_by_cp_id.find(config.candidate_pair_id) == + configs_by_cp_id.end()) { + const std::string candidate_pair_desc = + GetCandidatePairLogDescriptionAsString(config); + configs_by_cp_id[config.candidate_pair_id] = + TimeSeries("[" + std::to_string(config.candidate_pair_id) + "]" + + candidate_pair_desc, + LineStyle::kNone, PointStyle::kHighlight); + candidate_pair_desc_by_id_[config.candidate_pair_id] = + candidate_pair_desc; + } + float x = config_.GetCallTimeSec(config.log_time()); + float y = static_cast<float>(config.type); + configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y); + } + + // TODO(qingsi): There can be a large number of candidate pairs generated by + // certain calls and the frontend cannot render the chart in this case due to + // the failure of generating a palette with the same number of colors. + for (auto& kv : configs_by_cp_id) { + plot->AppendTimeSeries(std::move(kv.second)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 3, "Config Type", kBottomMargin, kTopMargin); + plot->SetTitle("[IceEventLog] ICE candidate pair configs"); + plot->SetYAxisTickLabels( + {{static_cast<float>(IceCandidatePairConfigType::kAdded), "ADDED"}, + {static_cast<float>(IceCandidatePairConfigType::kUpdated), "UPDATED"}, + {static_cast<float>(IceCandidatePairConfigType::kDestroyed), + "DESTROYED"}, + {static_cast<float>(IceCandidatePairConfigType::kSelected), + "SELECTED"}}); +} + +std::string EventLogAnalyzer::GetCandidatePairLogDescriptionFromId( + uint32_t candidate_pair_id) { + if (candidate_pair_desc_by_id_.find(candidate_pair_id) != + candidate_pair_desc_by_id_.end()) { + return candidate_pair_desc_by_id_[candidate_pair_id]; + } + for (const auto& config : parsed_log_.ice_candidate_pair_configs()) { + // TODO(qingsi): Add the handling of the "Updated" config event after the + // visualization of property change for candidate pairs is introduced. + if (candidate_pair_desc_by_id_.find(config.candidate_pair_id) == + candidate_pair_desc_by_id_.end()) { + const std::string candidate_pair_desc = + GetCandidatePairLogDescriptionAsString(config); + candidate_pair_desc_by_id_[config.candidate_pair_id] = + candidate_pair_desc; + } + } + return candidate_pair_desc_by_id_[candidate_pair_id]; +} + +void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) { + constexpr int kEventTypeOffset = + static_cast<int>(IceCandidatePairConfigType::kNumValues); + std::map<uint32_t, TimeSeries> checks_by_cp_id; + for (const auto& event : parsed_log_.ice_candidate_pair_events()) { + if (checks_by_cp_id.find(event.candidate_pair_id) == + checks_by_cp_id.end()) { + checks_by_cp_id[event.candidate_pair_id] = TimeSeries( + "[" + std::to_string(event.candidate_pair_id) + "]" + + GetCandidatePairLogDescriptionFromId(event.candidate_pair_id), + LineStyle::kNone, PointStyle::kHighlight); + } + float x = config_.GetCallTimeSec(event.log_time()); + float y = static_cast<float>(event.type) + kEventTypeOffset; + checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y); + } + + // TODO(qingsi): The same issue as in CreateIceCandidatePairConfigGraph. + for (auto& kv : checks_by_cp_id) { + plot->AppendTimeSeries(std::move(kv.second)); + } + + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 4, "Connectivity State", kBottomMargin, + kTopMargin); + plot->SetTitle("[IceEventLog] ICE connectivity checks"); + + plot->SetYAxisTickLabels( + {{static_cast<float>(IceCandidatePairEventType::kCheckSent) + + kEventTypeOffset, + "CHECK SENT"}, + {static_cast<float>(IceCandidatePairEventType::kCheckReceived) + + kEventTypeOffset, + "CHECK RECEIVED"}, + {static_cast<float>(IceCandidatePairEventType::kCheckResponseSent) + + kEventTypeOffset, + "RESPONSE SENT"}, + {static_cast<float>(IceCandidatePairEventType::kCheckResponseReceived) + + kEventTypeOffset, + "RESPONSE RECEIVED"}}); +} + +void EventLogAnalyzer::CreateDtlsTransportStateGraph(Plot* plot) { + TimeSeries states("DTLS Transport State", LineStyle::kNone, + PointStyle::kHighlight); + for (const auto& event : parsed_log_.dtls_transport_states()) { + float x = config_.GetCallTimeSec(event.log_time()); + float y = static_cast<float>(event.dtls_transport_state); + states.points.emplace_back(x, y); + } + plot->AppendTimeSeries(std::move(states)); + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, static_cast<float>(DtlsTransportState::kNumValues), + "Transport State", kBottomMargin, kTopMargin); + plot->SetTitle("DTLS Transport State"); + plot->SetYAxisTickLabels( + {{static_cast<float>(DtlsTransportState::kNew), "NEW"}, + {static_cast<float>(DtlsTransportState::kConnecting), "CONNECTING"}, + {static_cast<float>(DtlsTransportState::kConnected), "CONNECTED"}, + {static_cast<float>(DtlsTransportState::kClosed), "CLOSED"}, + {static_cast<float>(DtlsTransportState::kFailed), "FAILED"}}); +} + +void EventLogAnalyzer::CreateDtlsWritableStateGraph(Plot* plot) { + TimeSeries writable("DTLS Writable", LineStyle::kNone, + PointStyle::kHighlight); + for (const auto& event : parsed_log_.dtls_writable_states()) { + float x = config_.GetCallTimeSec(event.log_time()); + float y = static_cast<float>(event.writable); + writable.points.emplace_back(x, y); + } + plot->AppendTimeSeries(std::move(writable)); + plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), + "Time (s)", kLeftMargin, kRightMargin); + plot->SetSuggestedYAxis(0, 1, "Writable", kBottomMargin, kTopMargin); + plot->SetTitle("DTLS Writable State"); +} + +} // namespace webrtc |