| /* |
| * 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 <cstddef> |
| #include <cstdint> |
| #include <deque> |
| #include <limits> |
| #include <map> |
| #include <memory> |
| #include <optional> |
| #include <string> |
| #include <tuple> |
| #include <unordered_set> |
| #include <utility> |
| #include <vector> |
| |
| #include "absl/algorithm/container.h" |
| #include "absl/functional/bind_front.h" |
| #include "absl/strings/string_view.h" |
| #include "api/candidate.h" |
| #include "api/dtls_transport_interface.h" |
| #include "api/environment/environment_factory.h" |
| #include "api/function_view.h" |
| #include "api/media_types.h" |
| #include "api/rtc_event_log/rtc_event_log.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/events/rtc_event_generic_packet_received.h" |
| #include "logging/rtc_event_log/events/rtc_event_generic_packet_sent.h" |
| #include "logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h" |
| #include "logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h" |
| #include "logging/rtc_event_log/rtc_event_log_parser.h" |
| #include "logging/rtc_event_log/rtc_event_processor.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/receiver_report.h" |
| #include "modules/rtp_rtcp/source/rtcp_packet/remb.h" |
| #include "modules/rtp_rtcp/source/rtcp_packet/report_block.h" |
| #include "modules/rtp_rtcp/source/rtcp_packet/sender_report.h" |
| #include "modules/rtp_rtcp/source/rtcp_packet/target_bitrate.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_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_base/strings/string_builder.h" |
| #include "rtc_tools/rtc_event_log_visualizer/analyze_audio.h" |
| #include "rtc_tools/rtc_event_log_visualizer/analyzer_common.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" |
| #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> |
| std::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 std::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 std::nullopt; |
| } |
| |
| std::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 std::nullopt; |
| } |
| } |
| |
| std::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"; |
| |
| // TODO(tommi): This should be "host". |
| const char kIceCandidateTypeLocal[] = "local"; |
| // TODO(tommi): This should be "srflx". |
| 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"; |
| |
| absl::string_view GetIceCandidateTypeAsString(IceCandidateType type) { |
| switch (type) { |
| case IceCandidateType::kHost: |
| return kIceCandidateTypeLocal; |
| case IceCandidateType::kSrflx: |
| return kIceCandidateTypeStun; |
| case IceCandidateType::kPrflx: |
| return kIceCandidateTypePrflx; |
| case IceCandidateType::kRelay: |
| return kIceCandidateTypeRelay; |
| default: |
| RTC_DCHECK_NOTREACHED(); |
| 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; |
| ss << GetIceCandidateTypeAsString(config.local_candidate_type); |
| |
| if (config.local_candidate_type == IceCandidateType::kRelay) { |
| ss << "(" << GetProtocolAsString(config.local_relay_protocol) << ")"; |
| } |
| |
| ss << ":" << GetNetworkTypeAsString(config.local_network_type) << ":" |
| << GetAddressFamilyAsString(config.local_address_family) << "->" |
| << GetIceCandidateTypeAsString(config.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"; |
| } |
| } |
| |
| 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<TransmissionOffset>(1); |
| rtp_header_extensions.Register<AbsoluteSendTime>(2); |
| rtp_header_extensions.Register<TransportSequenceNumber>(3); |
| rtp_header_extensions.Register<FakeExtensionSmall>(4); |
| // Use id > 14 to force two byte header per rtp header when this one is used. |
| rtp_header_extensions.Register<FakeExtensionLarge>(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<TransmissionOffset>( |
| header.extension.transmissionTimeOffset); |
| ++num_bwe_extensions; |
| } |
| if (header.extension.hasAbsoluteSendTime) { |
| rtp_packet.SetExtension<AbsoluteSendTime>( |
| header.extension.absoluteSendTime); |
| ++num_bwe_extensions; |
| } |
| if (header.extension.hasTransportSequenceNumber) { |
| rtp_packet.SetExtension<TransportSequenceNumber>( |
| 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; |
| } |
| |
| struct PacketLossSummary { |
| size_t num_packets = 0; |
| size_t num_lost_packets = 0; |
| Timestamp base_time = Timestamp::MinusInfinity(); |
| }; |
| |
| float GetHighestSeqNumber(const webrtc::rtcp::ReportBlock& block) { |
| return block.extended_high_seq_num(); |
| } |
| |
| float GetFractionLost(const webrtc::rtcp::ReportBlock& block) { |
| return static_cast<double>(block.fraction_lost()) / 256 * 100; |
| } |
| |
| float GetCumulativeLost(const webrtc::rtcp::ReportBlock& block) { |
| return block.cumulative_lost(); |
| } |
| |
| float DelaySinceLastSr(const webrtc::rtcp::ReportBlock& block) { |
| return static_cast<double>(block.delay_since_last_sr()) / 65536; |
| } |
| |
| } // 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::InitializeMapOfNamedGraphs(bool show_detector_state, |
| bool show_alr_state, |
| bool show_link_capacity) { |
| plots_.RegisterPlot("incoming_packet_sizes", [this](Plot* plot) { |
| this->CreatePacketGraph(webrtc::kIncomingPacket, plot); |
| }); |
| |
| plots_.RegisterPlot("outgoing_packet_sizes", [this](Plot* plot) { |
| this->CreatePacketGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("incoming_rtcp_types", [this](Plot* plot) { |
| this->CreateRtcpTypeGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_rtcp_types", [this](Plot* plot) { |
| this->CreateRtcpTypeGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("incoming_packet_count", [this](Plot* plot) { |
| this->CreateAccumulatedPacketsGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_packet_count", [this](Plot* plot) { |
| this->CreateAccumulatedPacketsGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("incoming_packet_rate", [this](Plot* plot) { |
| this->CreatePacketRateGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_packet_rate", [this](Plot* plot) { |
| this->CreatePacketRateGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("total_incoming_packet_rate", [this](Plot* plot) { |
| this->CreateTotalPacketRateGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("total_outgoing_packet_rate", [this](Plot* plot) { |
| this->CreateTotalPacketRateGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("audio_playout", |
| [this](Plot* plot) { this->CreatePlayoutGraph(plot); }); |
| |
| plots_.RegisterPlot("neteq_set_minimum_delay", [this](Plot* plot) { |
| this->CreateNetEqSetMinimumDelay(plot); |
| }); |
| |
| plots_.RegisterPlot("incoming_audio_level", [this](Plot* plot) { |
| this->CreateAudioLevelGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_audio_level", [this](Plot* plot) { |
| this->CreateAudioLevelGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("incoming_sequence_number_delta", [this](Plot* plot) { |
| this->CreateSequenceNumberGraph(plot); |
| }); |
| plots_.RegisterPlot("incoming_delay", [this](Plot* plot) { |
| this->CreateIncomingDelayGraph(plot); |
| }); |
| plots_.RegisterPlot("incoming_loss_rate", [this](Plot* plot) { |
| this->CreateIncomingPacketLossGraph(plot); |
| }); |
| plots_.RegisterPlot("incoming_bitrate", [this](Plot* plot) { |
| this->CreateTotalIncomingBitrateGraph(plot); |
| }); |
| plots_.RegisterPlot( |
| "outgoing_bitrate", [this, show_detector_state, show_alr_state, |
| show_link_capacity](Plot* plot) { |
| this->CreateTotalOutgoingBitrateGraph( |
| plot, show_detector_state, show_alr_state, show_link_capacity); |
| }); |
| plots_.RegisterPlot("incoming_stream_bitrate", [this](Plot* plot) { |
| this->CreateStreamBitrateGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_stream_bitrate", [this](Plot* plot) { |
| this->CreateStreamBitrateGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("incoming_layer_bitrate_allocation", [this](Plot* plot) { |
| this->CreateBitrateAllocationGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_layer_bitrate_allocation", [this](Plot* plot) { |
| this->CreateBitrateAllocationGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| plots_.RegisterPlot("simulated_receiveside_bwe", [this](Plot* plot) { |
| this->CreateReceiveSideBweSimulationGraph(plot); |
| }); |
| plots_.RegisterPlot("simulated_sendside_bwe", [this](Plot* plot) { |
| this->CreateSendSideBweSimulationGraph(plot); |
| }); |
| plots_.RegisterPlot("simulated_goog_cc", [this](Plot* plot) { |
| this->CreateGoogCcSimulationGraph(plot); |
| }); |
| plots_.RegisterPlot("outgoing_twcc_loss", [this](Plot* plot) { |
| this->CreateOutgoingTWCCLossRateGraph(plot); |
| }); |
| plots_.RegisterPlot("network_delay_feedback", [this](Plot* plot) { |
| this->CreateNetworkDelayFeedbackGraph(plot); |
| }); |
| plots_.RegisterPlot("fraction_loss_feedback", [this](Plot* plot) { |
| this->CreateFractionLossGraph(plot); |
| }); |
| plots_.RegisterPlot("incoming_timestamps", [this](Plot* plot) { |
| this->CreateTimestampGraph(webrtc::kIncomingPacket, plot); |
| }); |
| plots_.RegisterPlot("outgoing_timestamps", [this](Plot* plot) { |
| this->CreateTimestampGraph(webrtc::kOutgoingPacket, plot); |
| }); |
| |
| plots_.RegisterPlot("incoming_rtcp_fraction_lost", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kIncomingPacket, GetFractionLost, |
| "Fraction lost (incoming RTCP)", "Loss rate (percent)", plot); |
| }); |
| plots_.RegisterPlot("outgoing_rtcp_fraction_lost", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kOutgoingPacket, GetFractionLost, |
| "Fraction lost (outgoing RTCP)", "Loss rate (percent)", plot); |
| }); |
| |
| plots_.RegisterPlot("incoming_rtcp_cumulative_lost", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kIncomingPacket, GetCumulativeLost, |
| "Cumulative lost packets (incoming RTCP)", "Packets", plot); |
| }); |
| plots_.RegisterPlot("outgoing_rtcp_cumulative_lost", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kOutgoingPacket, GetCumulativeLost, |
| "Cumulative lost packets (outgoing RTCP)", "Packets", plot); |
| }); |
| |
| plots_.RegisterPlot("incoming_rtcp_highest_seq_number", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kIncomingPacket, GetHighestSeqNumber, |
| "Highest sequence number (incoming RTCP)", "Sequence number", plot); |
| }); |
| plots_.RegisterPlot("outgoing_rtcp_highest_seq_number", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kOutgoingPacket, GetHighestSeqNumber, |
| "Highest sequence number (outgoing RTCP)", "Sequence number", plot); |
| }); |
| |
| plots_.RegisterPlot("incoming_rtcp_delay_since_last_sr", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kIncomingPacket, DelaySinceLastSr, |
| "Delay since last received sender report (incoming RTCP)", "Time (s)", |
| plot); |
| }); |
| plots_.RegisterPlot("outgoing_rtcp_delay_since_last_sr", [this](Plot* plot) { |
| this->CreateSenderAndReceiverReportPlot( |
| webrtc::kOutgoingPacket, DelaySinceLastSr, |
| "Delay since last received sender report (outgoing RTCP)", "Time (s)", |
| plot); |
| }); |
| |
| plots_.RegisterPlot( |
| "pacer_delay", [this](Plot* plot) { this->CreatePacerDelayGraph(plot); }); |
| |
| plots_.RegisterPlot("audio_encoder_bitrate", [this](Plot* plot) { |
| CreateAudioEncoderTargetBitrateGraph(this->parsed_log_, this->config_, |
| plot); |
| }); |
| plots_.RegisterPlot("audio_encoder_frame_length", [this](Plot* plot) { |
| CreateAudioEncoderFrameLengthGraph(this->parsed_log_, this->config_, plot); |
| }); |
| plots_.RegisterPlot("audio_encoder_packet_loss", [this](Plot* plot) { |
| CreateAudioEncoderPacketLossGraph(this->parsed_log_, this->config_, plot); |
| }); |
| plots_.RegisterPlot("audio_encoder_fec", [this](Plot* plot) { |
| CreateAudioEncoderEnableFecGraph(this->parsed_log_, this->config_, plot); |
| }); |
| plots_.RegisterPlot("audio_encoder_dtx", [this](Plot* plot) { |
| CreateAudioEncoderEnableDtxGraph(this->parsed_log_, this->config_, plot); |
| }); |
| plots_.RegisterPlot("audio_encoder_num_channels", [this](Plot* plot) { |
| CreateAudioEncoderNumChannelsGraph(this->parsed_log_, this->config_, plot); |
| }); |
| |
| plots_.RegisterPlot("ice_candidate_pair_config", [this](Plot* plot) { |
| this->CreateIceCandidatePairConfigGraph(plot); |
| }); |
| plots_.RegisterPlot("ice_connectivity_check", [this](Plot* plot) { |
| this->CreateIceConnectivityCheckGraph(plot); |
| }); |
| plots_.RegisterPlot("dtls_transport_state", [this](Plot* plot) { |
| this->CreateDtlsTransportStateGraph(plot); |
| }); |
| plots_.RegisterPlot("dtls_writable_state", [this](Plot* plot) { |
| this->CreateDtlsWritableStateGraph(plot); |
| }); |
| } |
| |
| void EventLogAnalyzer::CreateGraphsByName(const std::vector<std::string>& names, |
| PlotCollection* collection) { |
| for (absl::string_view name : names) { |
| auto plot = absl::c_find_if(plots_, [name](const PlotDeclaration& plot) { |
| return plot.label == name; |
| }); |
| if (plot != plots_.end()) { |
| Plot* output = collection->AppendNewPlot(plot->label); |
| plot->plot_func(output); |
| } |
| } |
| } |
| |
| 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 std::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 = [&packet_times](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, direction); |
| } |
| if (direction == kIncomingPacket) { |
| auto handle_incoming_rtcp = |
| [&packet_times](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 = |
| [&packet_times](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; |
| std::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.audio_level()) { |
| 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.audio_level()->level()); |
| 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(); |
| std::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 std::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::CreateOutgoingTWCCLossRateGraph(Plot* plot) { |
| TimeSeries loss_rate_series("Loss rate (from packet feedback)", |
| LineStyle::kLine, PointStyle::kHighlight); |
| TimeSeries reordered_packets_between_feedback( |
| "Ratio of reordered packets from last feedback", LineStyle::kLine, |
| PointStyle::kHighlight); |
| TimeSeries average_loss_rate_series("Average loss rate last 5s", |
| LineStyle::kLine, PointStyle::kHighlight); |
| TimeSeries missing_feedback_series("Missing feedback", LineStyle::kNone, |
| PointStyle::kHighlight); |
| PacketLossSummary window_summary; |
| Timestamp last_observation_receive_time = Timestamp::Zero(); |
| |
| // Use loss based bwe 2 observation duration and observation window size. |
| constexpr TimeDelta kObservationDuration = TimeDelta::Millis(250); |
| constexpr uint32_t kObservationWindowSize = 20; |
| std::deque<PacketLossSummary> observations; |
| SeqNumUnwrapper<uint16_t> unwrapper; |
| int64_t last_acked = 1; |
| if (!parsed_log_.transport_feedbacks(kIncomingPacket).empty()) { |
| last_acked = |
| unwrapper.Unwrap(parsed_log_.transport_feedbacks(kIncomingPacket)[0] |
| .transport_feedback.GetBaseSequence()); |
| } |
| std::unordered_set<int64_t> previous_feedback_lost_sequence_numbers; |
| size_t previous_feedback_size = 0; |
| for (auto& feedback : parsed_log_.transport_feedbacks(kIncomingPacket)) { |
| const rtcp::TransportFeedback& transport_feedback = |
| feedback.transport_feedback; |
| int64_t base_seq_num = |
| unwrapper.Unwrap(transport_feedback.GetBaseSequence()); |
| // Collect packets that do not have feedback, which are from the last acked |
| // packet, to the current base packet. |
| for (int64_t seq_num = last_acked; seq_num < base_seq_num; ++seq_num) { |
| missing_feedback_series.points.emplace_back( |
| config_.GetCallTimeSec(feedback.timestamp), |
| 100 + seq_num - last_acked); |
| } |
| last_acked = base_seq_num + transport_feedback.GetPacketStatusCount(); |
| |
| int num_reordered_packets = 0; |
| std::unordered_set<int64_t> lost_sequence_numbers; |
| transport_feedback.ForAllPackets( |
| [&](uint16_t sequence_number, TimeDelta receive_time_delta) { |
| int64_t unwrapped_seq = unwrapper.Unwrap(sequence_number); |
| if (receive_time_delta.IsInfinite()) { |
| lost_sequence_numbers.insert(unwrapped_seq); |
| } else { |
| num_reordered_packets += |
| previous_feedback_lost_sequence_numbers.count(unwrapped_seq); |
| } |
| }); |
| |
| // Compute loss rate from the transport feedback. |
| float loss_rate = |
| static_cast<float>(lost_sequence_numbers.size() * 100.0 / |
| transport_feedback.GetPacketStatusCount()); |
| |
| loss_rate_series.points.emplace_back( |
| config_.GetCallTimeSec(feedback.timestamp), loss_rate); |
| float reordered_rate = |
| previous_feedback_size == 0 |
| ? 0 |
| : static_cast<float>(num_reordered_packets * 100.0 / |
| previous_feedback_size); |
| reordered_packets_between_feedback.points.emplace_back( |
| config_.GetCallTimeSec(feedback.timestamp), reordered_rate); |
| |
| // Compute loss rate in a window of kObservationWindowSize. |
| if (window_summary.num_packets == 0) { |
| window_summary.base_time = feedback.log_time(); |
| } |
| window_summary.num_packets += transport_feedback.GetPacketStatusCount(); |
| window_summary.num_lost_packets += |
| lost_sequence_numbers.size() - num_reordered_packets; |
| |
| const Timestamp last_received_time = feedback.log_time(); |
| const TimeDelta observation_duration = |
| window_summary.base_time == Timestamp::Zero() |
| ? TimeDelta::Zero() |
| : last_received_time - window_summary.base_time; |
| if (observation_duration > kObservationDuration) { |
| last_observation_receive_time = last_received_time; |
| observations.push_back(window_summary); |
| if (observations.size() > kObservationWindowSize) { |
| observations.pop_front(); |
| } |
| |
| // Compute average loss rate in a number of windows. |
| int total_packets = 0; |
| int total_loss = 0; |
| for (const auto& observation : observations) { |
| total_loss += observation.num_lost_packets; |
| total_packets += observation.num_packets; |
| } |
| if (total_packets > 0) { |
| float average_loss_rate = total_loss * 100.0 / total_packets; |
| average_loss_rate_series.points.emplace_back( |
| config_.GetCallTimeSec(feedback.timestamp), average_loss_rate); |
| } else { |
| average_loss_rate_series.points.emplace_back( |
| config_.GetCallTimeSec(feedback.timestamp), 0); |
| } |
| window_summary = PacketLossSummary(); |
| } |
| std::swap(previous_feedback_lost_sequence_numbers, lost_sequence_numbers); |
| previous_feedback_size = transport_feedback.GetPacketStatusCount(); |
| } |
| // Add the data set to the plot. |
| plot->AppendTimeSeriesIfNotEmpty(std::move(loss_rate_series)); |
| plot->AppendTimeSeriesIfNotEmpty( |
| std::move(reordered_packets_between_feedback)); |
| plot->AppendTimeSeriesIfNotEmpty(std::move(average_loss_rate_series)); |
| plot->AppendTimeSeriesIfNotEmpty(std::move(missing_feedback_series)); |
| |
| plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(), |
| "Time (s)", kLeftMargin, kRightMargin); |
| plot->SetSuggestedYAxis(0, 100, "Loss rate (percent)", kBottomMargin, |
| kTopMargin); |
| plot->SetTitle("Outgoing loss rate (from TWCC feedback)"); |
| } |
| |
| 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(CreateEnvironment(&null_event_log)); |
| cc_config.constraints.at_time = Timestamp::Micros(clock.TimeInMicroseconds()); |
| 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("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/"); |
| std::unique_ptr<AcknowledgedBitrateEstimatorInterface> |
| robust_throughput_estimator( |
| AcknowledgedBitrateEstimatorInterface::Create(&throughput_config)); |
| test::ExplicitKeyValueConfig acked_bitrate_config( |
| "WebRTC-Bwe-RobustThroughputEstimatorSettings/enabled:false/"); |
| std::unique_ptr<AcknowledgedBitrateEstimatorInterface> |
| 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<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) { |
| 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())); |
| } |
| 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()); |
| } |
| std::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); |
| } |
| std::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); |
| } |
| std::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( |
| CreateEnvironment(&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; |
| |
| 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<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(); |
| std::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 |