blob: 1d8d5f12c09cab693c041b0def6e7e1569496d8d [file] [log] [blame]
terelius54ce6802016-07-13 13:44:411/*
2 * Copyright (c) 2016 The WebRTC project authors. All Rights Reserved.
3 *
4 * Use of this source code is governed by a BSD-style license
5 * that can be found in the LICENSE file in the root of the source
6 * tree. An additional intellectual property rights grant can be found
7 * in the file PATENTS. All contributing project authors may
8 * be found in the AUTHORS file in the root of the source tree.
9 */
10
Mirko Bonadei575998c2019-07-25 11:57:4111#include "rtc_tools/rtc_event_log_visualizer/analyzer.h"
terelius54ce6802016-07-13 13:44:4112
13#include <algorithm>
Oleh Prypin6581f212017-11-15 23:17:0514#include <cmath>
Björn Terelius2ea77ca2023-10-30 10:33:2115#include <cstddef>
16#include <cstdint>
Diep Bui636c3f22023-10-13 09:29:3017#include <deque>
terelius54ce6802016-07-13 13:44:4118#include <limits>
19#include <map>
Mirko Bonadei317a1f02019-09-17 15:06:1820#include <memory>
terelius54ce6802016-07-13 13:44:4121#include <string>
Björn Terelius2ea77ca2023-10-30 10:33:2122#include <tuple>
terelius54ce6802016-07-13 13:44:4123#include <utility>
Björn Terelius2ea77ca2023-10-30 10:33:2124#include <vector>
terelius54ce6802016-07-13 13:44:4125
Björn Tereliusc69c1bb2019-10-11 13:06:5826#include "absl/algorithm/container.h"
Per Kjellanderfe2063e2021-05-12 07:02:4327#include "absl/functional/bind_front.h"
Bjorn Terelius6c4b1b72019-01-11 12:01:2928#include "absl/strings/string_view.h"
Björn Terelius2ea77ca2023-10-30 10:33:2129#include "absl/types/optional.h"
30#include "api/dtls_transport_interface.h"
Artem Titov741daaf2019-03-21 13:37:3631#include "api/function_view.h"
Björn Terelius2ea77ca2023-10-30 10:33:2132#include "api/media_types.h"
Niels Möller0d863f72020-11-24 16:50:3133#include "api/network_state_predictor.h"
Björn Terelius2ea77ca2023-10-30 10:33:2134#include "api/rtc_event_log/rtc_event_log.h"
35#include "api/rtp_headers.h"
Sebastian Jansson5c94f552018-10-15 16:46:5136#include "api/transport/goog_cc_factory.h"
Björn Terelius2ea77ca2023-10-30 10:33:2137#include "api/transport/network_control.h"
38#include "api/transport/network_types.h"
39#include "api/units/data_rate.h"
40#include "api/units/time_delta.h"
41#include "api/units/timestamp.h"
42#include "logging/rtc_event_log/events/logged_rtp_rtcp.h"
43#include "logging/rtc_event_log/events/rtc_event_generic_packet_received.h"
44#include "logging/rtc_event_log/events/rtc_event_generic_packet_sent.h"
45#include "logging/rtc_event_log/events/rtc_event_ice_candidate_pair.h"
46#include "logging/rtc_event_log/events/rtc_event_ice_candidate_pair_config.h"
47#include "logging/rtc_event_log/rtc_event_log_parser.h"
Kristoffer Erlandssona2ce4232020-04-01 12:33:3048#include "logging/rtc_event_log/rtc_event_processor.h"
Björn Terelius2ea77ca2023-10-30 10:33:2149#include "modules/congestion_controller/goog_cc/acknowledged_bitrate_estimator_interface.h"
Bjorn Terelius28db2662017-10-04 12:22:4350#include "modules/congestion_controller/include/receive_side_congestion_controller.h"
Sebastian Jansson5c94f552018-10-15 16:46:5151#include "modules/congestion_controller/rtp/transport_feedback_adapter.h"
Björn Terelius2ea77ca2023-10-30 10:33:2152#include "modules/remote_bitrate_estimator/include/remote_bitrate_estimator.h"
53#include "modules/rtp_rtcp/include/rtp_header_extension_map.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3154#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3155#include "modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
56#include "modules/rtp_rtcp/source/rtcp_packet/remb.h"
Björn Terelius2ea77ca2023-10-30 10:33:2157#include "modules/rtp_rtcp/source/rtcp_packet/report_block.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3158#include "modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
Björn Terelius2ea77ca2023-10-30 10:33:2159#include "modules/rtp_rtcp/source/rtcp_packet/target_bitrate.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3160#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
61#include "modules/rtp_rtcp/source/rtp_header_extensions.h"
Danil Chapovalov4b61f3a2023-03-30 12:17:1962#include "modules/rtp_rtcp/source/rtp_packet_received.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3163#include "rtc_base/checks.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3164#include "rtc_base/logging.h"
Björn Terelius2ea77ca2023-10-30 10:33:2165#include "rtc_base/network/sent_packet.h"
Evan Shrubsole097fc342023-01-09 10:21:4366#include "rtc_base/numerics/sequence_number_unwrapper.h"
Mirko Bonadei92ea95e2017-09-15 04:47:3167#include "rtc_base/rate_statistics.h"
Jonas Olsson366a50c2018-09-06 11:41:3068#include "rtc_base/strings/string_builder.h"
Björn Terelius2ea77ca2023-10-30 10:33:2169#include "rtc_tools/rtc_event_log_visualizer/analyzer_common.h"
Mirko Bonadei575998c2019-07-25 11:57:4170#include "rtc_tools/rtc_event_log_visualizer/log_simulation.h"
Björn Terelius2ea77ca2023-10-30 10:33:2171#include "rtc_tools/rtc_event_log_visualizer/plot_base.h"
72#include "system_wrappers/include/clock.h"
Björn Tereliusae1892d2020-06-17 09:55:5573#include "test/explicit_key_value_config.h"
Bjorn Terelius6984ad22017-10-24 10:19:4574
tereliusdc35dcd2016-08-01 19:03:2775namespace webrtc {
tereliusdc35dcd2016-08-01 19:03:2776
terelius54ce6802016-07-13 13:44:4177namespace {
78
79std::string SsrcToString(uint32_t ssrc) {
Jonas Olsson366a50c2018-09-06 11:41:3080 rtc::StringBuilder ss;
terelius54ce6802016-07-13 13:44:4181 ss << "SSRC " << ssrc;
Jonas Olsson84df1c72018-09-14 14:59:3282 return ss.Release();
terelius54ce6802016-07-13 13:44:4183}
84
85// Checks whether an SSRC is contained in the list of desired SSRCs.
86// Note that an empty SSRC list matches every SSRC.
87bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) {
Mirko Bonadei1f173152019-07-25 13:28:1488 if (desired_ssrc.empty())
terelius54ce6802016-07-13 13:44:4189 return true;
90 return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) !=
91 desired_ssrc.end();
92}
93
94double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
95 // The timestamp is a fixed point representation with 6 bits for seconds
96 // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the
Qingsi Wang8eca1ff2018-02-02 19:49:4497 // time in seconds and then multiply by kNumMicrosecsPerSec to convert to
98 // microseconds.
terelius54ce6802016-07-13 13:44:4199 static constexpr double kTimestampToMicroSec =
Qingsi Wang8eca1ff2018-02-02 19:49:44100 static_cast<double>(kNumMicrosecsPerSec) / static_cast<double>(1ul << 18);
terelius54ce6802016-07-13 13:44:41101 return abs_send_time * kTimestampToMicroSec;
102}
103
Artem Titov54500ad2021-07-26 13:51:27104// Computes the difference `later` - `earlier` where `later` and `earlier`
105// are counters that wrap at `modulus`. The difference is chosen to have the
106// least absolute value. For example if `modulus` is 8, then the difference will
107// be chosen in the range [-3, 4]. If `modulus` is 9, then the difference will
terelius54ce6802016-07-13 13:44:41108// be in [-4, 4].
109int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
110 RTC_DCHECK_LE(1, modulus);
111 RTC_DCHECK_LT(later, modulus);
112 RTC_DCHECK_LT(earlier, modulus);
113 int64_t difference =
114 static_cast<int64_t>(later) - static_cast<int64_t>(earlier);
115 int64_t max_difference = modulus / 2;
116 int64_t min_difference = max_difference - modulus + 1;
117 if (difference > max_difference) {
118 difference -= modulus;
119 }
120 if (difference < min_difference) {
121 difference += modulus;
122 }
terelius6addf492016-08-24 00:34:07123 if (difference > max_difference / 2 || difference < min_difference / 2) {
Mirko Bonadei675513b2017-11-09 10:09:25124 RTC_LOG(LS_WARNING) << "Difference between" << later << " and " << earlier
125 << " expected to be in the range ("
126 << min_difference / 2 << "," << max_difference / 2
127 << ") but is " << difference
128 << ". Correct unwrapping is uncertain.";
terelius6addf492016-08-24 00:34:07129 }
terelius54ce6802016-07-13 13:44:41130 return difference;
131}
132
Bjorn Tereliusc4ca1d32018-04-27 12:33:34133// This is much more reliable for outgoing streams than for incoming streams.
134template <typename RtpPacketContainer>
Danil Chapovalov431abd92018-06-18 10:54:17135absl::optional<uint32_t> EstimateRtpClockFrequency(
Bjorn Tereliusc4ca1d32018-04-27 12:33:34136 const RtpPacketContainer& packets,
137 int64_t end_time_us) {
138 RTC_CHECK(packets.size() >= 2);
139 SeqNumUnwrapper<uint32_t> unwrapper;
Philip Eliasson1f850a62019-03-19 12:15:00140 int64_t first_rtp_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 12:33:34141 unwrapper.Unwrap(packets[0].rtp.header.timestamp);
142 int64_t first_log_timestamp = packets[0].log_time_us();
Philip Eliasson1f850a62019-03-19 12:15:00143 int64_t last_rtp_timestamp = first_rtp_timestamp;
Bjorn Tereliusc4ca1d32018-04-27 12:33:34144 int64_t last_log_timestamp = first_log_timestamp;
145 for (size_t i = 1; i < packets.size(); i++) {
146 if (packets[i].log_time_us() > end_time_us)
147 break;
148 last_rtp_timestamp = unwrapper.Unwrap(packets[i].rtp.header.timestamp);
149 last_log_timestamp = packets[i].log_time_us();
150 }
151 if (last_log_timestamp - first_log_timestamp < kNumMicrosecsPerSec) {
152 RTC_LOG(LS_WARNING)
153 << "Failed to estimate RTP clock frequency: Stream too short. ("
154 << packets.size() << " packets, "
155 << last_log_timestamp - first_log_timestamp << " us)";
Danil Chapovalov431abd92018-06-18 10:54:17156 return absl::nullopt;
Bjorn Tereliusc4ca1d32018-04-27 12:33:34157 }
158 double duration =
159 static_cast<double>(last_log_timestamp - first_log_timestamp) /
160 kNumMicrosecsPerSec;
161 double estimated_frequency =
162 (last_rtp_timestamp - first_rtp_timestamp) / duration;
163 for (uint32_t f : {8000, 16000, 32000, 48000, 90000}) {
philipel3fa49382019-08-20 13:59:57164 if (std::fabs(estimated_frequency - f) < 0.15 * f) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34165 return f;
166 }
167 }
168 RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Estimate "
169 << estimated_frequency
Philipp Hanckebc07d402022-05-27 16:46:23170 << " not close to any standard RTP frequency."
171 << " Last timestamp " << last_rtp_timestamp
172 << " first timestamp " << first_rtp_timestamp;
Danil Chapovalov431abd92018-06-18 10:54:17173 return absl::nullopt;
ivocaac9d6f2016-09-22 14:01:47174}
175
Danil Chapovalov431abd92018-06-18 10:54:17176absl::optional<double> NetworkDelayDiff_AbsSendTime(
Bjorn Terelius6c373cc2018-11-01 13:31:10177 const LoggedRtpPacketIncoming& old_packet,
178 const LoggedRtpPacketIncoming& new_packet) {
179 if (old_packet.rtp.header.extension.hasAbsoluteSendTime &&
180 new_packet.rtp.header.extension.hasAbsoluteSendTime) {
terelius53dc23c2017-03-13 12:24:05181 int64_t send_time_diff = WrappingDifference(
Bjorn Terelius6c373cc2018-11-01 13:31:10182 new_packet.rtp.header.extension.absoluteSendTime,
183 old_packet.rtp.header.extension.absoluteSendTime, 1ul << 24);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34184 int64_t recv_time_diff =
185 new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 12:24:05186 double delay_change_us =
187 recv_time_diff - AbsSendTimeToMicroseconds(send_time_diff);
Oskar Sundbom3928dbc2017-11-16 09:53:09188 return delay_change_us / 1000;
terelius53dc23c2017-03-13 12:24:05189 } else {
Danil Chapovalov431abd92018-06-18 10:54:17190 return absl::nullopt;
terelius6addf492016-08-24 00:34:07191 }
192}
193
Danil Chapovalov431abd92018-06-18 10:54:17194absl::optional<double> NetworkDelayDiff_CaptureTime(
Bjorn Terelius6c373cc2018-11-01 13:31:10195 const LoggedRtpPacketIncoming& old_packet,
196 const LoggedRtpPacketIncoming& new_packet,
197 const double sample_rate) {
198 int64_t send_time_diff =
199 WrappingDifference(new_packet.rtp.header.timestamp,
200 old_packet.rtp.header.timestamp, 1ull << 32);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34201 int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 12:24:05202
terelius53dc23c2017-03-13 12:24:05203 double delay_change =
204 static_cast<double>(recv_time_diff) / 1000 -
Bjorn Terelius6c373cc2018-11-01 13:31:10205 static_cast<double>(send_time_diff) / sample_rate * 1000;
terelius53dc23c2017-03-13 12:24:05206 if (delay_change < -10000 || 10000 < delay_change) {
Mirko Bonadei675513b2017-11-09 10:09:25207 RTC_LOG(LS_WARNING) << "Very large delay change. Timestamps correct?";
Bjorn Terelius6c373cc2018-11-01 13:31:10208 RTC_LOG(LS_WARNING) << "Old capture time "
209 << old_packet.rtp.header.timestamp << ", received time "
210 << old_packet.log_time_us();
211 RTC_LOG(LS_WARNING) << "New capture time "
212 << new_packet.rtp.header.timestamp << ", received time "
213 << new_packet.log_time_us();
Mirko Bonadei675513b2017-11-09 10:09:25214 RTC_LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = "
Qingsi Wang8eca1ff2018-02-02 19:49:44215 << static_cast<double>(recv_time_diff) /
216 kNumMicrosecsPerSec
217 << "s";
Mirko Bonadei675513b2017-11-09 10:09:25218 RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = "
Bjorn Terelius6c373cc2018-11-01 13:31:10219 << static_cast<double>(send_time_diff) / sample_rate
Mirko Bonadei675513b2017-11-09 10:09:25220 << "s";
terelius53dc23c2017-03-13 12:24:05221 }
Oskar Sundbom3928dbc2017-11-16 09:53:09222 return delay_change;
terelius53dc23c2017-03-13 12:24:05223}
224
Bjorn Terelius7c974e62019-02-15 16:20:12225template <typename T>
226TimeSeries CreateRtcpTypeTimeSeries(const std::vector<T>& rtcp_list,
227 AnalyzerConfig config,
228 std::string rtcp_name,
229 int category_id) {
230 TimeSeries time_series(rtcp_name, LineStyle::kNone, PointStyle::kHighlight);
231 for (const auto& rtcp : rtcp_list) {
Björn Tereliuscb241582022-02-25 08:22:38232 float x = config.GetCallTimeSec(rtcp.timestamp);
Bjorn Terelius7c974e62019-02-15 16:20:12233 float y = category_id;
234 time_series.points.emplace_back(x, y);
235 }
236 return time_series;
237}
238
Qingsi Wang8eca1ff2018-02-02 19:49:44239const char kUnknownEnumValue[] = "unknown";
240
241const char kIceCandidateTypeLocal[] = "local";
242const char kIceCandidateTypeStun[] = "stun";
243const char kIceCandidateTypePrflx[] = "prflx";
244const char kIceCandidateTypeRelay[] = "relay";
245
246const char kProtocolUdp[] = "udp";
247const char kProtocolTcp[] = "tcp";
248const char kProtocolSsltcp[] = "ssltcp";
249const char kProtocolTls[] = "tls";
250
251const char kAddressFamilyIpv4[] = "ipv4";
252const char kAddressFamilyIpv6[] = "ipv6";
253
254const char kNetworkTypeEthernet[] = "ethernet";
255const char kNetworkTypeLoopback[] = "loopback";
256const char kNetworkTypeWifi[] = "wifi";
257const char kNetworkTypeVpn[] = "vpn";
258const char kNetworkTypeCellular[] = "cellular";
259
260std::string GetIceCandidateTypeAsString(webrtc::IceCandidateType type) {
261 switch (type) {
262 case webrtc::IceCandidateType::kLocal:
263 return kIceCandidateTypeLocal;
264 case webrtc::IceCandidateType::kStun:
265 return kIceCandidateTypeStun;
266 case webrtc::IceCandidateType::kPrflx:
267 return kIceCandidateTypePrflx;
268 case webrtc::IceCandidateType::kRelay:
269 return kIceCandidateTypeRelay;
270 default:
271 return kUnknownEnumValue;
272 }
273}
274
275std::string GetProtocolAsString(webrtc::IceCandidatePairProtocol protocol) {
276 switch (protocol) {
277 case webrtc::IceCandidatePairProtocol::kUdp:
278 return kProtocolUdp;
279 case webrtc::IceCandidatePairProtocol::kTcp:
280 return kProtocolTcp;
281 case webrtc::IceCandidatePairProtocol::kSsltcp:
282 return kProtocolSsltcp;
283 case webrtc::IceCandidatePairProtocol::kTls:
284 return kProtocolTls;
285 default:
286 return kUnknownEnumValue;
287 }
288}
289
290std::string GetAddressFamilyAsString(
291 webrtc::IceCandidatePairAddressFamily family) {
292 switch (family) {
293 case webrtc::IceCandidatePairAddressFamily::kIpv4:
294 return kAddressFamilyIpv4;
295 case webrtc::IceCandidatePairAddressFamily::kIpv6:
296 return kAddressFamilyIpv6;
297 default:
298 return kUnknownEnumValue;
299 }
300}
301
302std::string GetNetworkTypeAsString(webrtc::IceCandidateNetworkType type) {
303 switch (type) {
304 case webrtc::IceCandidateNetworkType::kEthernet:
305 return kNetworkTypeEthernet;
306 case webrtc::IceCandidateNetworkType::kLoopback:
307 return kNetworkTypeLoopback;
308 case webrtc::IceCandidateNetworkType::kWifi:
309 return kNetworkTypeWifi;
310 case webrtc::IceCandidateNetworkType::kVpn:
311 return kNetworkTypeVpn;
312 case webrtc::IceCandidateNetworkType::kCellular:
313 return kNetworkTypeCellular;
314 default:
315 return kUnknownEnumValue;
316 }
317}
318
319std::string GetCandidatePairLogDescriptionAsString(
Bjorn Tereliusc4ca1d32018-04-27 12:33:34320 const LoggedIceCandidatePairConfig& config) {
Qingsi Wang8eca1ff2018-02-02 19:49:44321 // Example: stun:wifi->relay(tcp):cellular@udp:ipv4
322 // represents a pair of a local server-reflexive candidate on a WiFi network
323 // and a remote relay candidate using TCP as the relay protocol on a cell
324 // network, when the candidate pair communicates over UDP using IPv4.
Jonas Olsson366a50c2018-09-06 11:41:30325 rtc::StringBuilder ss;
Qingsi Wang8eca1ff2018-02-02 19:49:44326 std::string local_candidate_type =
327 GetIceCandidateTypeAsString(config.local_candidate_type);
328 std::string remote_candidate_type =
329 GetIceCandidateTypeAsString(config.remote_candidate_type);
330 if (config.local_candidate_type == webrtc::IceCandidateType::kRelay) {
331 local_candidate_type +=
332 "(" + GetProtocolAsString(config.local_relay_protocol) + ")";
333 }
334 ss << local_candidate_type << ":"
335 << GetNetworkTypeAsString(config.local_network_type) << ":"
336 << GetAddressFamilyAsString(config.local_address_family) << "->"
337 << remote_candidate_type << ":"
338 << GetAddressFamilyAsString(config.remote_address_family) << "@"
339 << GetProtocolAsString(config.candidate_pair_protocol);
Jonas Olsson84df1c72018-09-14 14:59:32340 return ss.Release();
Qingsi Wang8eca1ff2018-02-02 19:49:44341}
342
Bjorn Tereliusc4ca1d32018-04-27 12:33:34343std::string GetDirectionAsString(PacketDirection direction) {
344 if (direction == kIncomingPacket) {
345 return "Incoming";
346 } else {
347 return "Outgoing";
348 }
349}
350
351std::string GetDirectionAsShortString(PacketDirection direction) {
352 if (direction == kIncomingPacket) {
353 return "In";
354 } else {
355 return "Out";
356 }
357}
358
Danil Chapovalov4b61f3a2023-03-30 12:17:19359struct FakeExtensionSmall {
360 static constexpr RTPExtensionType kId = kRtpExtensionMid;
361 static constexpr absl::string_view Uri() { return "fake-extension-small"; }
362};
363struct FakeExtensionLarge {
364 static constexpr RTPExtensionType kId = kRtpExtensionRtpStreamId;
365 static constexpr absl::string_view Uri() { return "fake-extension-large"; }
366};
367
368RtpPacketReceived RtpPacketForBWEFromHeader(const RTPHeader& header) {
369 RtpHeaderExtensionMap rtp_header_extensions(/*extmap_allow_mixed=*/true);
370 // ReceiveSideCongestionController doesn't need to know extensions ids as
371 // long as it able to get extensions by type. So any ids would work here.
372 rtp_header_extensions.Register<TransmissionOffset>(1);
373 rtp_header_extensions.Register<AbsoluteSendTime>(2);
374 rtp_header_extensions.Register<TransportSequenceNumber>(3);
375 rtp_header_extensions.Register<FakeExtensionSmall>(4);
376 // Use id > 14 to force two byte header per rtp header when this one is used.
377 rtp_header_extensions.Register<FakeExtensionLarge>(16);
378
379 RtpPacketReceived rtp_packet(&rtp_header_extensions);
380 // Set only fields that might be relevant for the bandwidth estimatior.
381 rtp_packet.SetSsrc(header.ssrc);
382 rtp_packet.SetTimestamp(header.timestamp);
383 size_t num_bwe_extensions = 0;
384 if (header.extension.hasTransmissionTimeOffset) {
385 rtp_packet.SetExtension<TransmissionOffset>(
386 header.extension.transmissionTimeOffset);
387 ++num_bwe_extensions;
388 }
389 if (header.extension.hasAbsoluteSendTime) {
390 rtp_packet.SetExtension<AbsoluteSendTime>(
391 header.extension.absoluteSendTime);
392 ++num_bwe_extensions;
393 }
394 if (header.extension.hasTransportSequenceNumber) {
395 rtp_packet.SetExtension<TransportSequenceNumber>(
396 header.extension.transportSequenceNumber);
397 ++num_bwe_extensions;
398 }
399
400 // All parts of the RTP header are 32bit aligned.
401 RTC_CHECK_EQ(header.headerLength % 4, 0);
402
403 // Original packet could have more extensions, there could be csrcs that are
404 // not propagated by the rtc event log, i.e. logged header size might be
405 // larger that rtp_packet.header_size(). Increase it by setting an extra fake
406 // extension.
407 RTC_CHECK_GE(header.headerLength, rtp_packet.headers_size());
408 size_t bytes_to_add = header.headerLength - rtp_packet.headers_size();
409 if (bytes_to_add > 0) {
410 if (bytes_to_add <= 16) {
411 // one-byte header rtp header extension allows to add up to 16 bytes.
412 rtp_packet.AllocateExtension(FakeExtensionSmall::kId, bytes_to_add - 1);
413 } else {
414 // two-byte header rtp header extension would also add one byte per
415 // already set extension.
416 rtp_packet.AllocateExtension(FakeExtensionLarge::kId,
417 bytes_to_add - 2 - num_bwe_extensions);
418 }
419 }
420 RTC_CHECK_EQ(rtp_packet.headers_size(), header.headerLength);
421
422 return rtp_packet;
423}
424
Diep Bui636c3f22023-10-13 09:29:30425struct PacketLossSummary {
426 size_t num_packets = 0;
427 size_t num_lost_packets = 0;
428 Timestamp base_time = Timestamp::MinusInfinity();
429};
430
terelius54ce6802016-07-13 13:44:41431} // namespace
432
Sebastian Janssonb290a6d2019-01-03 13:46:23433EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
Stefan Holmer1d4a2272018-05-24 11:48:09434 bool normalize_time)
Bjorn Terelius068fc352019-02-13 21:38:25435 : parsed_log_(log) {
Björn Tereliuscb241582022-02-25 08:22:38436 config_.window_duration_ = TimeDelta::Millis(250);
437 config_.step_ = TimeDelta::Millis(10);
438 if (!log.start_log_events().empty()) {
439 config_.rtc_to_utc_offset_ = log.start_log_events()[0].utc_time() -
440 log.start_log_events()[0].log_time();
441 }
Bjorn Terelius068fc352019-02-13 21:38:25442 config_.normalize_time_ = normalize_time;
443 config_.begin_time_ = parsed_log_.first_timestamp();
444 config_.end_time_ = parsed_log_.last_timestamp();
445 if (config_.end_time_ < config_.begin_time_) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34446 RTC_LOG(LS_WARNING) << "No useful events in the log.";
Björn Tereliuscb241582022-02-25 08:22:38447 config_.begin_time_ = config_.end_time_ = Timestamp::Zero();
Björn Tereliusff612732018-04-25 14:23:01448 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:34449
Björn Terelius0d1b28c2020-05-27 18:25:06450 RTC_LOG(LS_INFO) << "Log is "
Björn Tereliuscb241582022-02-25 08:22:38451 << (parsed_log_.last_timestamp().ms() -
452 parsed_log_.first_timestamp().ms()) /
453 1000
Björn Terelius0d1b28c2020-05-27 18:25:06454 << " seconds long.";
Bjorn Terelius48b82792020-05-19 08:57:24455}
456
457EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
458 const AnalyzerConfig& config)
459 : parsed_log_(log), config_(config) {
Björn Terelius0d1b28c2020-05-27 18:25:06460 RTC_LOG(LS_INFO) << "Log is "
Björn Tereliuscb241582022-02-25 08:22:38461 << (parsed_log_.last_timestamp().ms() -
462 parsed_log_.first_timestamp().ms()) /
463 1000
Björn Terelius0d1b28c2020-05-27 18:25:06464 << " seconds long.";
terelius54ce6802016-07-13 13:44:41465}
466
Sebastian Jansson5c94f552018-10-15 16:46:51467class BitrateObserver : public RemoteBitrateObserver {
Stefan Holmer13181032016-07-29 12:48:54468 public:
469 BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {}
470
Sebastian Jansson5c94f552018-10-15 16:46:51471 void Update(NetworkControlUpdate update) {
472 if (update.target_rate) {
473 last_bitrate_bps_ = update.target_rate->target_rate.bps();
474 bitrate_updated_ = true;
475 }
Stefan Holmer13181032016-07-29 12:48:54476 }
477
478 void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
479 uint32_t bitrate) override {}
480
481 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
482 bool GetAndResetBitrateUpdated() {
483 bool bitrate_updated = bitrate_updated_;
484 bitrate_updated_ = false;
485 return bitrate_updated;
486 }
487
488 private:
489 uint32_t last_bitrate_bps_;
490 bool bitrate_updated_;
491};
492
Bjorn Tereliusc4ca1d32018-04-27 12:33:34493void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction,
terelius54ce6802016-07-13 13:44:41494 Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34495 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
496 // Filter on SSRC.
497 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-24 00:34:07498 continue;
terelius54ce6802016-07-13 13:44:41499 }
terelius54ce6802016-07-13 13:44:41500
Bjorn Terelius48b82792020-05-19 08:57:24501 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 12:33:34502 LineStyle::kBar);
503 auto GetPacketSize = [](const LoggedRtpPacket& packet) {
Danil Chapovalov431abd92018-06-18 10:54:17504 return absl::optional<float>(packet.total_length);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34505 };
Stefan Holmer1d4a2272018-05-24 11:48:09506 auto ToCallTime = [this](const LoggedRtpPacket& packet) {
Björn Tereliuscb241582022-02-25 08:22:38507 return this->config_.GetCallTimeSec(packet.timestamp);
Stefan Holmer1d4a2272018-05-24 11:48:09508 };
509 ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize,
510 stream.packet_view, &time_series);
philipel35ba9bd2017-04-19 12:58:51511 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 13:44:41512 }
513
Bjorn Terelius068fc352019-02-13 21:38:25514 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
515 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 19:03:27516 plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin,
517 kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34518 plot->SetTitle(GetDirectionAsString(direction) + " RTP packets");
terelius54ce6802016-07-13 13:44:41519}
520
Bjorn Terelius7c974e62019-02-15 16:20:12521void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction,
522 Plot* plot) {
523 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
524 parsed_log_.transport_feedbacks(direction), config_, "TWCC", 1));
525 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
526 parsed_log_.receiver_reports(direction), config_, "RR", 2));
527 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
528 parsed_log_.sender_reports(direction), config_, "SR", 3));
529 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
530 parsed_log_.extended_reports(direction), config_, "XR", 4));
531 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.nacks(direction),
532 config_, "NACK", 5));
533 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.rembs(direction),
534 config_, "REMB", 6));
535 plot->AppendTimeSeries(
536 CreateRtcpTypeTimeSeries(parsed_log_.firs(direction), config_, "FIR", 7));
537 plot->AppendTimeSeries(
538 CreateRtcpTypeTimeSeries(parsed_log_.plis(direction), config_, "PLI", 8));
Björn Terelius4ef56382021-02-03 13:12:24539 plot->AppendTimeSeries(
540 CreateRtcpTypeTimeSeries(parsed_log_.byes(direction), config_, "BYE", 9));
Bjorn Terelius7c974e62019-02-15 16:20:12541 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
542 "Time (s)", kLeftMargin, kRightMargin);
543 plot->SetSuggestedYAxis(0, 1, "RTCP type", kBottomMargin, kTopMargin);
544 plot->SetTitle(GetDirectionAsString(direction) + " RTCP packets");
Bjorn Tereliusf640b872019-07-24 13:46:39545 plot->SetYAxisTickLabels({{1, "TWCC"},
546 {2, "RR"},
547 {3, "SR"},
548 {4, "XR"},
549 {5, "NACK"},
550 {6, "REMB"},
551 {7, "FIR"},
Björn Terelius4ef56382021-02-03 13:12:24552 {8, "PLI"},
553 {9, "BYE"}});
Bjorn Terelius7c974e62019-02-15 16:20:12554}
555
Bjorn Tereliusc4ca1d32018-04-27 12:33:34556template <typename IterableType>
philipelccd74892016-09-05 09:46:25557void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
philipelccd74892016-09-05 09:46:25558 Plot* plot,
Bjorn Tereliusc4ca1d32018-04-27 12:33:34559 const IterableType& packets,
560 const std::string& label) {
561 TimeSeries time_series(label, LineStyle::kStep);
562 for (size_t i = 0; i < packets.size(); i++) {
Björn Tereliuscb241582022-02-25 08:22:38563 float x = config_.GetCallTimeSec(packets[i].log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:34564 time_series.points.emplace_back(x, i + 1);
philipelccd74892016-09-05 09:46:25565 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:34566 plot->AppendTimeSeries(std::move(time_series));
philipelccd74892016-09-05 09:46:25567}
568
Bjorn Tereliusc4ca1d32018-04-27 12:33:34569void EventLogAnalyzer::CreateAccumulatedPacketsGraph(PacketDirection direction,
570 Plot* plot) {
571 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
572 if (!MatchingSsrc(stream.ssrc, desired_ssrc_))
573 continue;
Bjorn Terelius48b82792020-05-19 08:57:24574 std::string label = std::string("RTP ") +
575 GetStreamName(parsed_log_, direction, stream.ssrc);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34576 CreateAccumulatedPacketsTimeSeries(plot, stream.packet_view, label);
577 }
578 std::string label =
579 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")";
580 if (direction == kIncomingPacket) {
581 CreateAccumulatedPacketsTimeSeries(
582 plot, parsed_log_.incoming_rtcp_packets(), label);
583 } else {
584 CreateAccumulatedPacketsTimeSeries(
585 plot, parsed_log_.outgoing_rtcp_packets(), label);
586 }
philipelccd74892016-09-05 09:46:25587
Bjorn Terelius068fc352019-02-13 21:38:25588 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
589 "Time (s)", kLeftMargin, kRightMargin);
philipelccd74892016-09-05 09:46:25590 plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34591 plot->SetTitle(std::string("Accumulated ") + GetDirectionAsString(direction) +
592 " RTP/RTCP packets");
philipelccd74892016-09-05 09:46:25593}
594
Kristoffer Erlandsson283c1062020-03-30 11:01:37595void EventLogAnalyzer::CreatePacketRateGraph(PacketDirection direction,
596 Plot* plot) {
597 auto CountPackets = [](auto packet) { return 1.0; };
598 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
599 // Filter on SSRC.
600 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
601 continue;
602 }
603 TimeSeries time_series(
Bjorn Terelius48b82792020-05-19 08:57:24604 std::string("RTP ") +
605 GetStreamName(parsed_log_, direction, stream.ssrc),
Kristoffer Erlandsson283c1062020-03-30 11:01:37606 LineStyle::kLine);
607 MovingAverage<LoggedRtpPacket, double>(CountPackets, stream.packet_view,
608 config_, &time_series);
609 plot->AppendTimeSeries(std::move(time_series));
610 }
611 TimeSeries time_series(
612 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")",
613 LineStyle::kLine);
614 if (direction == kIncomingPacket) {
615 MovingAverage<LoggedRtcpPacketIncoming, double>(
616 CountPackets, parsed_log_.incoming_rtcp_packets(), config_,
617 &time_series);
618 } else {
619 MovingAverage<LoggedRtcpPacketOutgoing, double>(
620 CountPackets, parsed_log_.outgoing_rtcp_packets(), config_,
621 &time_series);
622 }
623 plot->AppendTimeSeries(std::move(time_series));
624
625 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
626 "Time (s)", kLeftMargin, kRightMargin);
627 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
628 kTopMargin);
629 plot->SetTitle("Rate of " + GetDirectionAsString(direction) +
630 " RTP/RTCP packets");
631}
632
Kristoffer Erlandssona2ce4232020-04-01 12:33:30633void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
634 Plot* plot) {
635 // Contains a log timestamp to enable counting logged events of different
636 // types using MovingAverage().
637 class LogTime {
638 public:
Björn Tereliuscb241582022-02-25 08:22:38639 explicit LogTime(Timestamp log_time) : log_time_(log_time) {}
640 Timestamp log_time() const { return log_time_; }
Kristoffer Erlandssona2ce4232020-04-01 12:33:30641
642 private:
Björn Tereliuscb241582022-02-25 08:22:38643 Timestamp log_time_;
Kristoffer Erlandssona2ce4232020-04-01 12:33:30644 };
Kristoffer Erlandssona2ce4232020-04-01 12:33:30645 std::vector<LogTime> packet_times;
Björn Tereliusff58aed2023-06-20 12:08:04646 auto handle_rtp = [&packet_times](const LoggedRtpPacket& packet) {
Björn Tereliuscb241582022-02-25 08:22:38647 packet_times.emplace_back(packet.log_time());
Kristoffer Erlandssona2ce4232020-04-01 12:33:30648 };
649 RtcEventProcessor process;
650 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
Björn Tereliusff58aed2023-06-20 12:08:04651 process.AddEvents(stream.packet_view, handle_rtp, direction);
Kristoffer Erlandssona2ce4232020-04-01 12:33:30652 }
653 if (direction == kIncomingPacket) {
Björn Tereliusff58aed2023-06-20 12:08:04654 auto handle_incoming_rtcp =
655 [&packet_times](const LoggedRtcpPacketIncoming& packet) {
656 packet_times.emplace_back(packet.log_time());
657 };
Kristoffer Erlandssona2ce4232020-04-01 12:33:30658 process.AddEvents(parsed_log_.incoming_rtcp_packets(),
659 handle_incoming_rtcp);
660 } else {
Björn Tereliusff58aed2023-06-20 12:08:04661 auto handle_outgoing_rtcp =
662 [&packet_times](const LoggedRtcpPacketOutgoing& packet) {
663 packet_times.emplace_back(packet.log_time());
664 };
Kristoffer Erlandssona2ce4232020-04-01 12:33:30665 process.AddEvents(parsed_log_.outgoing_rtcp_packets(),
666 handle_outgoing_rtcp);
667 }
668 process.ProcessEventsInOrder();
669 TimeSeries time_series(std::string("Total ") + "(" +
670 GetDirectionAsShortString(direction) + ") packets",
671 LineStyle::kLine);
672 MovingAverage<LogTime, uint64_t>([](auto packet) { return 1; }, packet_times,
673 config_, &time_series);
674 plot->AppendTimeSeries(std::move(time_series));
675
676 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
677 "Time (s)", kLeftMargin, kRightMargin);
678 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
679 kTopMargin);
680 plot->SetTitle("Rate of all " + GetDirectionAsString(direction) +
681 " RTP/RTCP packets");
682}
683
terelius54ce6802016-07-13 13:44:41684// For each SSRC, plot the time between the consecutive playouts.
685void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34686 for (const auto& playout_stream : parsed_log_.audio_playout_events()) {
687 uint32_t ssrc = playout_stream.first;
688 if (!MatchingSsrc(ssrc, desired_ssrc_))
689 continue;
Danil Chapovalov431abd92018-06-18 10:54:17690 absl::optional<int64_t> last_playout_ms;
Bjorn Tereliusc4ca1d32018-04-27 12:33:34691 TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar);
Minyue Li27e2b7d2018-05-07 13:20:24692 for (const auto& playout_event : playout_stream.second) {
Björn Tereliuscb241582022-02-25 08:22:38693 float x = config_.GetCallTimeSec(playout_event.log_time());
Minyue Li27e2b7d2018-05-07 13:20:24694 int64_t playout_time_ms = playout_event.log_time_ms();
Bjorn Tereliusc4ca1d32018-04-27 12:33:34695 // If there were no previous playouts, place the point on the x-axis.
Minyue Li27e2b7d2018-05-07 13:20:24696 float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34697 time_series.points.push_back(TimeSeriesPoint(x, y));
Minyue Li27e2b7d2018-05-07 13:20:24698 last_playout_ms.emplace(playout_time_ms);
terelius54ce6802016-07-13 13:44:41699 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:34700 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 13:44:41701 }
702
Bjorn Terelius068fc352019-02-13 21:38:25703 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
704 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 19:03:27705 plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin,
706 kTopMargin);
707 plot->SetTitle("Audio playout");
terelius54ce6802016-07-13 13:44:41708}
709
Lionel Koenig6afa92a2023-01-16 10:23:36710void EventLogAnalyzer::CreateNetEqSetMinimumDelay(Plot* plot) {
711 for (const auto& playout_stream :
712 parsed_log_.neteq_set_minimum_delay_events()) {
713 uint32_t ssrc = playout_stream.first;
714 if (!MatchingSsrc(ssrc, desired_ssrc_))
715 continue;
716
717 TimeSeries time_series(SsrcToString(ssrc), LineStyle::kStep,
718 PointStyle::kHighlight);
719 for (const auto& event : playout_stream.second) {
720 float x = config_.GetCallTimeSec(event.log_time());
721 float y = event.minimum_delay_ms;
722 time_series.points.push_back(TimeSeriesPoint(x, y));
723 }
724 plot->AppendTimeSeries(std::move(time_series));
725 }
726
727 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
728 "Time (s)", kLeftMargin, kRightMargin);
729 plot->SetSuggestedYAxis(0, 1000, "Minimum Delay (ms)", kBottomMargin,
730 kTopMargin);
731 plot->SetTitle("Set Minimum Delay");
732}
733
ivocaac9d6f2016-09-22 14:01:47734// For audio SSRCs, plot the audio level.
Bjorn Tereliusc4ca1d32018-04-27 12:33:34735void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction,
736 Plot* plot) {
737 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
Bjorn Terelius48b82792020-05-19 08:57:24738 if (!IsAudioSsrc(parsed_log_, direction, stream.ssrc))
Bjorn Tereliusc4ca1d32018-04-27 12:33:34739 continue;
Bjorn Terelius48b82792020-05-19 08:57:24740 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 12:33:34741 LineStyle::kLine);
742 for (auto& packet : stream.packet_view) {
ivocaac9d6f2016-09-22 14:01:47743 if (packet.header.extension.hasAudioLevel) {
Björn Tereliuscb241582022-02-25 08:22:38744 float x = config_.GetCallTimeSec(packet.log_time());
ivocaac9d6f2016-09-22 14:01:47745 // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
746 // Here we convert it to dBov.
747 float y = static_cast<float>(-packet.header.extension.audioLevel);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34748 time_series.points.emplace_back(TimeSeriesPoint(x, y));
ivocaac9d6f2016-09-22 14:01:47749 }
750 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:34751 plot->AppendTimeSeries(std::move(time_series));
ivocaac9d6f2016-09-22 14:01:47752 }
753
Bjorn Terelius068fc352019-02-13 21:38:25754 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
755 "Time (s)", kLeftMargin, kRightMargin);
Yves Gerey665174f2018-06-19 13:03:05756 plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34757 plot->SetTitle(GetDirectionAsString(direction) + " audio level");
ivocaac9d6f2016-09-22 14:01:47758}
759
Konrad Hofbauerca3c8012019-02-15 19:52:19760// For each SSRC, plot the sequence number difference between consecutive
761// incoming packets.
terelius54ce6802016-07-13 13:44:41762void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34763 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
764 // Filter on SSRC.
765 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-24 00:34:07766 continue;
terelius54ce6802016-07-13 13:44:41767 }
terelius54ce6802016-07-13 13:44:41768
Bjorn Terelius48b82792020-05-19 08:57:24769 TimeSeries time_series(
770 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
771 LineStyle::kBar);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34772 auto GetSequenceNumberDiff = [](const LoggedRtpPacketIncoming& old_packet,
773 const LoggedRtpPacketIncoming& new_packet) {
774 int64_t diff =
775 WrappingDifference(new_packet.rtp.header.sequenceNumber,
776 old_packet.rtp.header.sequenceNumber, 1ul << 16);
777 return diff;
778 };
Stefan Holmer1d4a2272018-05-24 11:48:09779 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Björn Tereliuscb241582022-02-25 08:22:38780 return this->config_.GetCallTimeSec(packet.log_time());
Stefan Holmer1d4a2272018-05-24 11:48:09781 };
782 ProcessPairs<LoggedRtpPacketIncoming, float>(
783 ToCallTime, GetSequenceNumberDiff, stream.incoming_packets,
784 &time_series);
philipel35ba9bd2017-04-19 12:58:51785 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 13:44:41786 }
787
Bjorn Terelius068fc352019-02-13 21:38:25788 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
789 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 19:03:27790 plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
791 kTopMargin);
Konrad Hofbauerca3c8012019-02-15 19:52:19792 plot->SetTitle("Incoming sequence number delta");
terelius54ce6802016-07-13 13:44:41793}
794
Stefan Holmer99f8e082016-09-09 11:37:50795void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34796 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
797 const std::vector<LoggedRtpPacketIncoming>& packets =
798 stream.incoming_packets;
799 // Filter on SSRC.
Mirko Bonadei1f173152019-07-25 13:28:14800 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || packets.empty()) {
Stefan Holmer99f8e082016-09-09 11:37:50801 continue;
802 }
803
Bjorn Terelius48b82792020-05-19 08:57:24804 TimeSeries time_series(
805 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
806 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34807 // TODO(terelius): Should the window and step size be read from the class
808 // instead?
Björn Tereliuscb241582022-02-25 08:22:38809 const TimeDelta kWindow = TimeDelta::Millis(1000);
810 const TimeDelta kStep = TimeDelta::Millis(1000);
Bjorn Terelius2eb31882017-11-30 14:15:25811 SeqNumUnwrapper<uint16_t> unwrapper_;
812 SeqNumUnwrapper<uint16_t> prior_unwrapper_;
terelius4c9b4af2017-01-30 16:44:51813 size_t window_index_begin = 0;
814 size_t window_index_end = 0;
Bjorn Tereliusc4ca1d32018-04-27 12:33:34815 uint64_t highest_seq_number =
816 unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
817 uint64_t highest_prior_seq_number =
818 prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
terelius4c9b4af2017-01-30 16:44:51819
Björn Tereliuscb241582022-02-25 08:22:38820 for (Timestamp t = config_.begin_time_; t < config_.end_time_ + kStep;
Bjorn Terelius068fc352019-02-13 21:38:25821 t += kStep) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34822 while (window_index_end < packets.size() &&
Björn Tereliuscb241582022-02-25 08:22:38823 packets[window_index_end].rtp.log_time() < t) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34824 uint64_t sequence_number = unwrapper_.Unwrap(
825 packets[window_index_end].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 16:44:51826 highest_seq_number = std::max(highest_seq_number, sequence_number);
827 ++window_index_end;
Stefan Holmer99f8e082016-09-09 11:37:50828 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:34829 while (window_index_begin < packets.size() &&
Björn Tereliuscb241582022-02-25 08:22:38830 packets[window_index_begin].rtp.log_time() < t - kWindow) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34831 uint64_t sequence_number = prior_unwrapper_.Unwrap(
832 packets[window_index_begin].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 16:44:51833 highest_prior_seq_number =
834 std::max(highest_prior_seq_number, sequence_number);
835 ++window_index_begin;
836 }
Bjorn Terelius068fc352019-02-13 21:38:25837 float x = config_.GetCallTimeSec(t);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34838 uint64_t expected_packets = highest_seq_number - highest_prior_seq_number;
terelius4c9b4af2017-01-30 16:44:51839 if (expected_packets > 0) {
840 int64_t received_packets = window_index_end - window_index_begin;
841 int64_t lost_packets = expected_packets - received_packets;
842 float y = static_cast<float>(lost_packets) / expected_packets * 100;
843 time_series.points.emplace_back(x, y);
844 }
Stefan Holmer99f8e082016-09-09 11:37:50845 }
philipel35ba9bd2017-04-19 12:58:51846 plot->AppendTimeSeries(std::move(time_series));
Stefan Holmer99f8e082016-09-09 11:37:50847 }
848
Bjorn Terelius068fc352019-02-13 21:38:25849 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
850 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 15:17:28851 plot->SetSuggestedYAxis(0, 1, "Loss rate (in %)", kBottomMargin, kTopMargin);
852 plot->SetTitle("Incoming packet loss (derived from incoming packets)");
Stefan Holmer99f8e082016-09-09 11:37:50853}
854
terelius2ee076d2017-08-15 09:04:02855void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
Bjorn Terelius6c373cc2018-11-01 13:31:10856 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:34857 // Filter on SSRC.
858 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) ||
Bjorn Terelius48b82792020-05-19 08:57:24859 IsRtxSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
terelius88e64e52016-07-19 08:51:06860 continue;
861 }
terelius54ce6802016-07-13 13:44:41862
Bjorn Terelius6c373cc2018-11-01 13:31:10863 const std::vector<LoggedRtpPacketIncoming>& packets =
864 stream.incoming_packets;
865 if (packets.size() < 100) {
866 RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency with "
867 << packets.size() << " packets in the stream.";
868 continue;
869 }
Björn Terelius0d1b28c2020-05-27 18:25:06870 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Bjorn Terelius6c373cc2018-11-01 13:31:10871 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 08:57:24872 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius6c373cc2018-11-01 13:31:10873 if (!estimated_frequency)
874 continue;
875 const double frequency_hz = *estimated_frequency;
Bjorn Terelius48b82792020-05-19 08:57:24876 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc) &&
877 frequency_hz != 90000) {
Bjorn Terelius6c373cc2018-11-01 13:31:10878 RTC_LOG(LS_WARNING)
879 << "Video stream should use a 90 kHz clock but appears to use "
880 << frequency_hz / 1000 << ". Discarding.";
881 continue;
882 }
883
884 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Björn Tereliuscb241582022-02-25 08:22:38885 return this->config_.GetCallTimeSec(packet.log_time());
Bjorn Terelius6c373cc2018-11-01 13:31:10886 };
887 auto ToNetworkDelay = [frequency_hz](
888 const LoggedRtpPacketIncoming& old_packet,
889 const LoggedRtpPacketIncoming& new_packet) {
890 return NetworkDelayDiff_CaptureTime(old_packet, new_packet, frequency_hz);
891 };
892
Bjorn Tereliusc4ca1d32018-04-27 12:33:34893 TimeSeries capture_time_data(
Bjorn Terelius48b82792020-05-19 08:57:24894 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
895 " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 12:33:34896 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 13:31:10897 AccumulatePairs<LoggedRtpPacketIncoming, double>(
898 ToCallTime, ToNetworkDelay, packets, &capture_time_data);
philipel35ba9bd2017-04-19 12:58:51899 plot->AppendTimeSeries(std::move(capture_time_data));
terelius88e64e52016-07-19 08:51:06900
Bjorn Tereliusc4ca1d32018-04-27 12:33:34901 TimeSeries send_time_data(
Bjorn Terelius48b82792020-05-19 08:57:24902 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
903 " abs-send-time",
Bjorn Tereliusc4ca1d32018-04-27 12:33:34904 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 13:31:10905 AccumulatePairs<LoggedRtpPacketIncoming, double>(
906 ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data);
907 plot->AppendTimeSeriesIfNotEmpty(std::move(send_time_data));
terelius54ce6802016-07-13 13:44:41908 }
909
Bjorn Terelius068fc352019-02-13 21:38:25910 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
911 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauer5be3bbd2019-01-21 11:31:07912 plot->SetSuggestedYAxis(0, 1, "Delay (ms)", kBottomMargin, kTopMargin);
913 plot->SetTitle("Incoming network delay (relative to first packet)");
terelius54ce6802016-07-13 13:44:41914}
915
tereliusf736d232016-08-04 17:00:11916// Plot the fraction of packets lost (as perceived by the loss-based BWE).
917void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
Bjorn Tereliusb577d5e2017-11-10 15:21:34918 TimeSeries time_series("Fraction lost", LineStyle::kLine,
919 PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34920 for (auto& bwe_update : parsed_log_.bwe_loss_updates()) {
Björn Tereliuscb241582022-02-25 08:22:38921 float x = config_.GetCallTimeSec(bwe_update.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:34922 float y = static_cast<float>(bwe_update.fraction_lost) / 255 * 100;
philipel35ba9bd2017-04-19 12:58:51923 time_series.points.emplace_back(x, y);
tereliusf736d232016-08-04 17:00:11924 }
tereliusf736d232016-08-04 17:00:11925
Bjorn Terelius19f5be32017-10-18 10:39:49926 plot->AppendTimeSeries(std::move(time_series));
Bjorn Terelius068fc352019-02-13 21:38:25927 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
928 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 15:17:28929 plot->SetSuggestedYAxis(0, 10, "Loss rate (in %)", kBottomMargin, kTopMargin);
930 plot->SetTitle("Outgoing packet loss (as reported by BWE)");
tereliusf736d232016-08-04 17:00:11931}
932
terelius54ce6802016-07-13 13:44:41933// Plot the total bandwidth used by all RTP streams.
Bjorn Tereliusc4ca1d32018-04-27 12:33:34934void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
935 // TODO(terelius): This could be provided by the parser.
Björn Tereliuscb241582022-02-25 08:22:38936 std::multimap<Timestamp, size_t> packets_in_order;
Bjorn Tereliusc4ca1d32018-04-27 12:33:34937 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
938 for (const LoggedRtpPacketIncoming& packet : stream.incoming_packets)
939 packets_in_order.insert(
Björn Tereliuscb241582022-02-25 08:22:38940 std::make_pair(packet.rtp.log_time(), packet.rtp.total_length));
terelius54ce6802016-07-13 13:44:41941 }
942
Bjorn Tereliusc4ca1d32018-04-27 12:33:34943 auto window_begin = packets_in_order.begin();
944 auto window_end = packets_in_order.begin();
terelius54ce6802016-07-13 13:44:41945 size_t bytes_in_window = 0;
terelius54ce6802016-07-13 13:44:41946
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:57947 if (!packets_in_order.empty()) {
948 // Calculate a moving average of the bitrate and store in a TimeSeries.
949 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
Björn Tereliuscb241582022-02-25 08:22:38950 for (Timestamp time = config_.begin_time_;
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:57951 time < config_.end_time_ + config_.step_; time += config_.step_) {
952 while (window_end != packets_in_order.end() && window_end->first < time) {
953 bytes_in_window += window_end->second;
954 ++window_end;
955 }
956 while (window_begin != packets_in_order.end() &&
957 window_begin->first < time - config_.window_duration_) {
958 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
959 bytes_in_window -= window_begin->second;
960 ++window_begin;
961 }
962 float window_duration_in_seconds =
Björn Tereliuscb241582022-02-25 08:22:38963 static_cast<float>(config_.window_duration_.us()) /
964 kNumMicrosecsPerSec;
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:57965 float x = config_.GetCallTimeSec(time);
966 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
967 bitrate_series.points.emplace_back(x, y);
terelius54ce6802016-07-13 13:44:41968 }
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:57969 plot->AppendTimeSeries(std::move(bitrate_series));
Bjorn Tereliusc4ca1d32018-04-27 12:33:34970 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:34971
972 // Overlay the outgoing REMB over incoming bitrate.
973 TimeSeries remb_series("Remb", LineStyle::kStep);
974 for (const auto& rtcp : parsed_log_.rembs(kOutgoingPacket)) {
Björn Tereliuscb241582022-02-25 08:22:38975 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:34976 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
977 remb_series.points.emplace_back(x, y);
978 }
979 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
980
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:57981 if (!parsed_log_.generic_packets_received().empty()) {
982 TimeSeries time_series("Incoming generic bitrate", LineStyle::kLine);
983 auto GetPacketSizeKilobits = [](const LoggedGenericPacketReceived& packet) {
984 return packet.packet_length * 8.0 / 1000.0;
985 };
986 MovingAverage<LoggedGenericPacketReceived, double>(
987 GetPacketSizeKilobits, parsed_log_.generic_packets_received(), config_,
988 &time_series);
989 plot->AppendTimeSeries(std::move(time_series));
990 }
991
Bjorn Terelius068fc352019-02-13 21:38:25992 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
993 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:34994 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
995 plot->SetTitle("Incoming RTP bitrate");
996}
997
998// Plot the total bandwidth used by all RTP streams.
Diep Bui38b3cf02022-07-19 12:09:45999void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(
1000 Plot* plot,
1001 bool show_detector_state,
1002 bool show_alr_state,
1003 bool show_link_capacity) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:341004 // TODO(terelius): This could be provided by the parser.
Björn Tereliuscb241582022-02-25 08:22:381005 std::multimap<Timestamp, size_t> packets_in_order;
Bjorn Tereliusc4ca1d32018-04-27 12:33:341006 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1007 for (const LoggedRtpPacketOutgoing& packet : stream.outgoing_packets)
1008 packets_in_order.insert(
Björn Tereliuscb241582022-02-25 08:22:381009 std::make_pair(packet.rtp.log_time(), packet.rtp.total_length));
Bjorn Tereliusc4ca1d32018-04-27 12:33:341010 }
1011
1012 auto window_begin = packets_in_order.begin();
1013 auto window_end = packets_in_order.begin();
1014 size_t bytes_in_window = 0;
1015
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:571016 if (!packets_in_order.empty()) {
1017 // Calculate a moving average of the bitrate and store in a TimeSeries.
1018 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
Björn Tereliuscb241582022-02-25 08:22:381019 for (Timestamp time = config_.begin_time_;
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:571020 time < config_.end_time_ + config_.step_; time += config_.step_) {
1021 while (window_end != packets_in_order.end() && window_end->first < time) {
1022 bytes_in_window += window_end->second;
1023 ++window_end;
1024 }
1025 while (window_begin != packets_in_order.end() &&
1026 window_begin->first < time - config_.window_duration_) {
1027 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
1028 bytes_in_window -= window_begin->second;
1029 ++window_begin;
1030 }
1031 float window_duration_in_seconds =
Björn Tereliuscb241582022-02-25 08:22:381032 static_cast<float>(config_.window_duration_.us()) /
1033 kNumMicrosecsPerSec;
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:571034 float x = config_.GetCallTimeSec(time);
1035 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
1036 bitrate_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341037 }
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:571038 plot->AppendTimeSeries(std::move(bitrate_series));
terelius54ce6802016-07-13 13:44:411039 }
1040
terelius8058e58d2016-07-25 08:32:411041 // Overlay the send-side bandwidth estimate over the outgoing bitrate.
Bjorn Tereliusc4ca1d32018-04-27 12:33:341042 TimeSeries loss_series("Loss-based estimate", LineStyle::kStep);
1043 for (auto& loss_update : parsed_log_.bwe_loss_updates()) {
Björn Tereliuscb241582022-02-25 08:22:381044 float x = config_.GetCallTimeSec(loss_update.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341045 float y = static_cast<float>(loss_update.bitrate_bps) / 1000;
1046 loss_series.points.emplace_back(x, y);
1047 }
philipel10fc0e62017-04-11 08:50:231048
Diep Bui38b3cf02022-07-19 12:09:451049 TimeSeries link_capacity_lower_series("Link-capacity-lower",
1050 LineStyle::kStep);
1051 TimeSeries link_capacity_upper_series("Link-capacity-upper",
1052 LineStyle::kStep);
1053 for (auto& remote_estimate_event : parsed_log_.remote_estimate_events()) {
1054 float x = config_.GetCallTimeSec(remote_estimate_event.log_time());
1055 if (remote_estimate_event.link_capacity_lower.has_value()) {
1056 float link_capacity_lower = static_cast<float>(
1057 remote_estimate_event.link_capacity_lower.value().kbps());
1058 link_capacity_lower_series.points.emplace_back(x, link_capacity_lower);
1059 }
1060 if (remote_estimate_event.link_capacity_upper.has_value()) {
1061 float link_capacity_upper = static_cast<float>(
1062 remote_estimate_event.link_capacity_upper.value().kbps());
1063 link_capacity_upper_series.points.emplace_back(x, link_capacity_upper);
1064 }
1065 }
1066
Bjorn Tereliusc4ca1d32018-04-27 12:33:341067 TimeSeries delay_series("Delay-based estimate", LineStyle::kStep);
1068 IntervalSeries overusing_series("Overusing", "#ff8e82",
1069 IntervalSeries::kHorizontal);
1070 IntervalSeries underusing_series("Underusing", "#5092fc",
1071 IntervalSeries::kHorizontal);
1072 IntervalSeries normal_series("Normal", "#c4ffc4",
1073 IntervalSeries::kHorizontal);
1074 IntervalSeries* last_series = &normal_series;
Björn Tereliuscb241582022-02-25 08:22:381075 float last_detector_switch = 0.0;
philipel23c7f252017-07-14 13:30:031076
Bjorn Tereliusc4ca1d32018-04-27 12:33:341077 BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal;
philipel23c7f252017-07-14 13:30:031078
Bjorn Tereliusc4ca1d32018-04-27 12:33:341079 for (auto& delay_update : parsed_log_.bwe_delay_updates()) {
Björn Tereliuscb241582022-02-25 08:22:381080 float x = config_.GetCallTimeSec(delay_update.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341081 float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
philipel23c7f252017-07-14 13:30:031082
Bjorn Tereliusc4ca1d32018-04-27 12:33:341083 if (last_detector_state != delay_update.detector_state) {
1084 last_series->intervals.emplace_back(last_detector_switch, x);
1085 last_detector_state = delay_update.detector_state;
1086 last_detector_switch = x;
philipel23c7f252017-07-14 13:30:031087
Bjorn Tereliusc4ca1d32018-04-27 12:33:341088 switch (delay_update.detector_state) {
1089 case BandwidthUsage::kBwNormal:
1090 last_series = &normal_series;
1091 break;
1092 case BandwidthUsage::kBwUnderusing:
1093 last_series = &underusing_series;
1094 break;
1095 case BandwidthUsage::kBwOverusing:
1096 last_series = &overusing_series;
1097 break;
1098 case BandwidthUsage::kLast:
Artem Titovd3251962021-11-15 15:57:071099 RTC_DCHECK_NOTREACHED();
philipele127e7a2017-03-29 14:28:531100 }
1101 }
philipel23c7f252017-07-14 13:30:031102
Bjorn Tereliusc4ca1d32018-04-27 12:33:341103 delay_series.points.emplace_back(x, y);
1104 }
Bjorn Terelius9e336ec2018-04-24 14:28:351105
Bjorn Tereliusc4ca1d32018-04-27 12:33:341106 RTC_CHECK(last_series);
Björn Tereliuscb241582022-02-25 08:22:381107 last_series->intervals.emplace_back(last_detector_switch,
1108 config_.CallEndTimeSec());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341109
1110 TimeSeries created_series("Probe cluster created.", LineStyle::kNone,
1111 PointStyle::kHighlight);
1112 for (auto& cluster : parsed_log_.bwe_probe_cluster_created_events()) {
Björn Tereliuscb241582022-02-25 08:22:381113 float x = config_.GetCallTimeSec(cluster.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341114 float y = static_cast<float>(cluster.bitrate_bps) / 1000;
1115 created_series.points.emplace_back(x, y);
1116 }
1117
1118 TimeSeries result_series("Probing results.", LineStyle::kNone,
1119 PointStyle::kHighlight);
Bjorn Terelius7a0bb002018-05-29 12:45:531120 for (auto& result : parsed_log_.bwe_probe_success_events()) {
Björn Tereliuscb241582022-02-25 08:22:381121 float x = config_.GetCallTimeSec(result.log_time());
Bjorn Terelius7a0bb002018-05-29 12:45:531122 float y = static_cast<float>(result.bitrate_bps) / 1000;
1123 result_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341124 }
1125
Piotr (Peter) Slatalaf996c842019-01-04 14:54:221126 TimeSeries probe_failures_series("Probe failed", LineStyle::kNone,
1127 PointStyle::kHighlight);
1128 for (auto& failure : parsed_log_.bwe_probe_failure_events()) {
Björn Tereliuscb241582022-02-25 08:22:381129 float x = config_.GetCallTimeSec(failure.log_time());
Piotr (Peter) Slatalaf996c842019-01-04 14:54:221130 probe_failures_series.points.emplace_back(x, 0);
1131 }
1132
Bjorn Tereliusc4ca1d32018-04-27 12:33:341133 IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
1134 bool previously_in_alr = false;
Björn Tereliuscb241582022-02-25 08:22:381135 Timestamp alr_start = Timestamp::Zero();
Bjorn Tereliusc4ca1d32018-04-27 12:33:341136 for (auto& alr : parsed_log_.alr_state_events()) {
Björn Tereliuscb241582022-02-25 08:22:381137 float y = config_.GetCallTimeSec(alr.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341138 if (!previously_in_alr && alr.in_alr) {
Björn Tereliuscb241582022-02-25 08:22:381139 alr_start = alr.log_time();
Bjorn Tereliusc4ca1d32018-04-27 12:33:341140 previously_in_alr = true;
1141 } else if (previously_in_alr && !alr.in_alr) {
Bjorn Terelius068fc352019-02-13 21:38:251142 float x = config_.GetCallTimeSec(alr_start);
Ilya Nikolaevskiya4259f62017-12-05 12:19:451143 alr_state.intervals.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341144 previously_in_alr = false;
Björn Tereliusff612732018-04-25 14:23:011145 }
Björn Tereliusff612732018-04-25 14:23:011146 }
1147
Bjorn Tereliusc4ca1d32018-04-27 12:33:341148 if (previously_in_alr) {
Bjorn Terelius068fc352019-02-13 21:38:251149 float x = config_.GetCallTimeSec(alr_start);
1150 float y = config_.GetCallTimeSec(config_.end_time_);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341151 alr_state.intervals.emplace_back(x, y);
1152 }
1153
1154 if (show_detector_state) {
1155 plot->AppendIntervalSeries(std::move(overusing_series));
1156 plot->AppendIntervalSeries(std::move(underusing_series));
1157 plot->AppendIntervalSeries(std::move(normal_series));
1158 }
1159
1160 if (show_alr_state) {
1161 plot->AppendIntervalSeries(std::move(alr_state));
1162 }
Diep Bui38b3cf02022-07-19 12:09:451163
1164 if (show_link_capacity) {
1165 plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_lower_series));
1166 plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_upper_series));
1167 }
1168
Bjorn Tereliusc4ca1d32018-04-27 12:33:341169 plot->AppendTimeSeries(std::move(loss_series));
Piotr (Peter) Slatalaf996c842019-01-04 14:54:221170 plot->AppendTimeSeriesIfNotEmpty(std::move(probe_failures_series));
Bjorn Tereliusc4ca1d32018-04-27 12:33:341171 plot->AppendTimeSeries(std::move(delay_series));
1172 plot->AppendTimeSeries(std::move(created_series));
1173 plot->AppendTimeSeries(std::move(result_series));
1174
1175 // Overlay the incoming REMB over the outgoing bitrate.
Björn Tereliusff612732018-04-25 14:23:011176 TimeSeries remb_series("Remb", LineStyle::kStep);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341177 for (const auto& rtcp : parsed_log_.rembs(kIncomingPacket)) {
Björn Tereliuscb241582022-02-25 08:22:381178 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341179 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
terelius2c8e8a32017-06-02 08:29:481180 remb_series.points.emplace_back(x, y);
1181 }
1182 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
1183
Piotr (Peter) Slatalacf8405e2019-02-14 21:44:571184 if (!parsed_log_.generic_packets_sent().empty()) {
1185 {
1186 TimeSeries time_series("Outgoing generic total bitrate",
1187 LineStyle::kLine);
1188 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1189 return packet.packet_length() * 8.0 / 1000.0;
1190 };
1191 MovingAverage<LoggedGenericPacketSent, double>(
1192 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1193 &time_series);
1194 plot->AppendTimeSeries(std::move(time_series));
1195 }
1196
1197 {
1198 TimeSeries time_series("Outgoing generic payload bitrate",
1199 LineStyle::kLine);
1200 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1201 return packet.payload_length * 8.0 / 1000.0;
1202 };
1203 MovingAverage<LoggedGenericPacketSent, double>(
1204 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1205 &time_series);
1206 plot->AppendTimeSeries(std::move(time_series));
1207 }
1208 }
1209
Bjorn Terelius068fc352019-02-13 21:38:251210 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1211 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 19:03:271212 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341213 plot->SetTitle("Outgoing RTP bitrate");
terelius54ce6802016-07-13 13:44:411214}
1215
1216// For each SSRC, plot the bandwidth used by that stream.
Bjorn Tereliusc4ca1d32018-04-27 12:33:341217void EventLogAnalyzer::CreateStreamBitrateGraph(PacketDirection direction,
1218 Plot* plot) {
1219 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1220 // Filter on SSRC.
1221 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-24 00:34:071222 continue;
terelius54ce6802016-07-13 13:44:411223 }
1224
Bjorn Terelius48b82792020-05-19 08:57:241225 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 12:33:341226 LineStyle::kLine);
1227 auto GetPacketSizeKilobits = [](const LoggedRtpPacket& packet) {
1228 return packet.total_length * 8.0 / 1000.0;
1229 };
terelius53dc23c2017-03-13 12:24:051230 MovingAverage<LoggedRtpPacket, double>(
Bjorn Terelius068fc352019-02-13 21:38:251231 GetPacketSizeKilobits, stream.packet_view, config_, &time_series);
philipel35ba9bd2017-04-19 12:58:511232 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 13:44:411233 }
1234
Bjorn Terelius068fc352019-02-13 21:38:251235 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1236 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 19:03:271237 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341238 plot->SetTitle(GetDirectionAsString(direction) + " bitrate per stream");
terelius54ce6802016-07-13 13:44:411239}
1240
Bjorn Terelius9775a582019-02-15 16:29:581241// Plot the bitrate allocation for each temporal and spatial layer.
1242// Computed from RTCP XR target bitrate block, so the graph is only populated if
1243// those are sent.
1244void EventLogAnalyzer::CreateBitrateAllocationGraph(PacketDirection direction,
1245 Plot* plot) {
1246 std::map<LayerDescription, TimeSeries> time_series;
1247 const auto& xr_list = parsed_log_.extended_reports(direction);
1248 for (const auto& rtcp : xr_list) {
1249 const absl::optional<rtcp::TargetBitrate>& target_bitrate =
1250 rtcp.xr.target_bitrate();
1251 if (!target_bitrate.has_value())
1252 continue;
1253 for (const auto& bitrate_item : target_bitrate->GetTargetBitrates()) {
1254 LayerDescription layer(rtcp.xr.sender_ssrc(), bitrate_item.spatial_layer,
1255 bitrate_item.temporal_layer);
1256 auto time_series_it = time_series.find(layer);
1257 if (time_series_it == time_series.end()) {
1258 std::string layer_name = GetLayerName(layer);
1259 bool inserted;
1260 std::tie(time_series_it, inserted) = time_series.insert(
1261 std::make_pair(layer, TimeSeries(layer_name, LineStyle::kStep)));
1262 RTC_DCHECK(inserted);
1263 }
Björn Tereliuscb241582022-02-25 08:22:381264 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Terelius9775a582019-02-15 16:29:581265 float y = bitrate_item.target_bitrate_kbps;
1266 time_series_it->second.points.emplace_back(x, y);
1267 }
1268 }
1269 for (auto& layer : time_series) {
1270 plot->AppendTimeSeries(std::move(layer.second));
1271 }
1272 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1273 "Time (s)", kLeftMargin, kRightMargin);
1274 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1275 if (direction == kIncomingPacket)
1276 plot->SetTitle("Target bitrate per incoming layer");
1277 else
1278 plot->SetTitle("Target bitrate per outgoing layer");
1279}
1280
Sebastian Jansson1175ae02019-03-13 07:56:581281void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) {
1282 TimeSeries target_rates("Simulated target rate", LineStyle::kStep,
1283 PointStyle::kHighlight);
1284 TimeSeries delay_based("Logged delay-based estimate", LineStyle::kStep,
1285 PointStyle::kHighlight);
1286 TimeSeries loss_based("Logged loss-based estimate", LineStyle::kStep,
1287 PointStyle::kHighlight);
1288 TimeSeries probe_results("Logged probe success", LineStyle::kNone,
1289 PointStyle::kHighlight);
1290
Sebastian Jansson1175ae02019-03-13 07:56:581291 LogBasedNetworkControllerSimulation simulation(
Mirko Bonadei317a1f02019-09-17 15:06:181292 std::make_unique<GoogCcNetworkControllerFactory>(),
Sebastian Jansson1175ae02019-03-13 07:56:581293 [&](const NetworkControlUpdate& update, Timestamp at_time) {
1294 if (update.target_rate) {
1295 target_rates.points.emplace_back(
Björn Tereliuscb241582022-02-25 08:22:381296 config_.GetCallTimeSec(at_time),
Sebastian Jansson1175ae02019-03-13 07:56:581297 update.target_rate->target_rate.kbps<float>());
1298 }
1299 });
1300
1301 simulation.ProcessEventsInLog(parsed_log_);
1302 for (const auto& logged : parsed_log_.bwe_delay_updates())
Björn Tereliuscb241582022-02-25 08:22:381303 delay_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
1304 logged.bitrate_bps / 1000);
Sebastian Jansson1175ae02019-03-13 07:56:581305 for (const auto& logged : parsed_log_.bwe_probe_success_events())
Björn Tereliuscb241582022-02-25 08:22:381306 probe_results.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
1307 logged.bitrate_bps / 1000);
Sebastian Jansson1175ae02019-03-13 07:56:581308 for (const auto& logged : parsed_log_.bwe_loss_updates())
Björn Tereliuscb241582022-02-25 08:22:381309 loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
Sebastian Jansson1175ae02019-03-13 07:56:581310 logged.bitrate_bps / 1000);
1311
1312 plot->AppendTimeSeries(std::move(delay_based));
1313 plot->AppendTimeSeries(std::move(loss_based));
1314 plot->AppendTimeSeries(std::move(probe_results));
1315 plot->AppendTimeSeries(std::move(target_rates));
1316
1317 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1318 "Time (s)", kLeftMargin, kRightMargin);
1319 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1320 plot->SetTitle("Simulated BWE behavior");
1321}
1322
Diep Bui636c3f22023-10-13 09:29:301323void EventLogAnalyzer::CreateOutgoingTWCCLossRateGraph(Plot* plot) {
1324 TimeSeries loss_rate_series("Loss rate (from packet feedback)",
1325 LineStyle::kLine, PointStyle::kHighlight);
1326 TimeSeries average_loss_rate_series("Average loss rate last 5s",
1327 LineStyle::kLine, PointStyle::kHighlight);
1328 TimeSeries missing_feedback_series("Missing feedback", LineStyle::kNone,
1329 PointStyle::kHighlight);
1330 PacketLossSummary window_summary;
1331 Timestamp last_observation_receive_time = Timestamp::Zero();
1332
1333 // Use loss based bwe 2 observation duration and observation window size.
1334 constexpr TimeDelta kObservationDuration = TimeDelta::Millis(250);
1335 constexpr uint32_t kObservationWindowSize = 20;
1336 std::deque<PacketLossSummary> observations;
1337 SeqNumUnwrapper<uint16_t> unwrapper;
1338 int64_t last_acked = 1;
1339 if (!parsed_log_.transport_feedbacks(kIncomingPacket).empty()) {
1340 last_acked =
1341 unwrapper.Unwrap(parsed_log_.transport_feedbacks(kIncomingPacket)[0]
1342 .transport_feedback.GetBaseSequence());
1343 }
1344 for (auto& feedback : parsed_log_.transport_feedbacks(kIncomingPacket)) {
1345 const rtcp::TransportFeedback& transport_feedback =
1346 feedback.transport_feedback;
1347 size_t base_seq_num =
1348 unwrapper.Unwrap(transport_feedback.GetBaseSequence());
1349 // Collect packets that do not have feedback, which are from the last acked
1350 // packet, to the current base packet.
1351 for (size_t seq_num = last_acked; seq_num < base_seq_num; ++seq_num) {
1352 missing_feedback_series.points.emplace_back(
1353 config_.GetCallTimeSec(feedback.timestamp),
1354 100 + seq_num - last_acked);
1355 }
1356 last_acked = base_seq_num + transport_feedback.GetPacketStatusCount();
1357
1358 // Compute loss rate from the transport feedback.
1359 auto loss_rate =
1360 static_cast<float>((transport_feedback.GetPacketStatusCount() -
1361 transport_feedback.GetReceivedPackets().size()) *
1362 100.0 / transport_feedback.GetPacketStatusCount());
1363 loss_rate_series.points.emplace_back(
1364 config_.GetCallTimeSec(feedback.timestamp), loss_rate);
1365
1366 // Compute loss rate in a window of kObservationWindowSize.
1367 if (window_summary.num_packets == 0) {
1368 window_summary.base_time = feedback.log_time();
1369 }
1370 window_summary.num_packets += transport_feedback.GetPacketStatusCount();
1371 window_summary.num_lost_packets +=
1372 transport_feedback.GetPacketStatusCount() -
1373 transport_feedback.GetReceivedPackets().size();
1374
1375 const Timestamp last_received_time = feedback.log_time();
1376 const TimeDelta observation_duration =
1377 window_summary.base_time == Timestamp::Zero()
1378 ? TimeDelta::Zero()
1379 : last_received_time - window_summary.base_time;
1380 if (observation_duration > kObservationDuration) {
1381 last_observation_receive_time = last_received_time;
1382 observations.push_back(window_summary);
1383 if (observations.size() > kObservationWindowSize) {
1384 observations.pop_front();
1385 }
1386
1387 // Compute average loss rate in a number of windows.
1388 int total_packets = 0;
1389 int total_loss = 0;
1390 for (const auto& observation : observations) {
1391 total_loss += observation.num_lost_packets;
1392 total_packets += observation.num_packets;
1393 }
1394 if (total_packets > 0) {
1395 float average_loss_rate = total_loss * 100.0 / total_packets;
1396 average_loss_rate_series.points.emplace_back(
1397 config_.GetCallTimeSec(feedback.timestamp), average_loss_rate);
1398 } else {
1399 average_loss_rate_series.points.emplace_back(
1400 config_.GetCallTimeSec(feedback.timestamp), 0);
1401 }
1402 window_summary = PacketLossSummary();
1403 }
1404 }
1405 // Add the data set to the plot.
1406 plot->AppendTimeSeriesIfNotEmpty(std::move(loss_rate_series));
1407 plot->AppendTimeSeriesIfNotEmpty(std::move(average_loss_rate_series));
1408 plot->AppendTimeSeriesIfNotEmpty(std::move(missing_feedback_series));
1409
1410 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1411 "Time (s)", kLeftMargin, kRightMargin);
1412 plot->SetSuggestedYAxis(0, 100, "Loss rate (percent)", kBottomMargin,
1413 kTopMargin);
1414 plot->SetTitle("Outgoing loss rate (from TWCC feedback)");
1415}
1416
Bjorn Terelius28db2662017-10-04 12:22:431417void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:341418 using RtpPacketType = LoggedRtpPacketOutgoing;
1419 using TransportFeedbackType = LoggedRtcpPacketTransportFeedback;
Stefan Holmer13181032016-07-29 12:48:541420
Bjorn Tereliusc4ca1d32018-04-27 12:33:341421 // TODO(terelius): This could be provided by the parser.
1422 std::multimap<int64_t, const RtpPacketType*> outgoing_rtp;
1423 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1424 for (const RtpPacketType& rtp_packet : stream.outgoing_packets)
1425 outgoing_rtp.insert(
1426 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Stefan Holmer13181032016-07-29 12:48:541427 }
1428
Bjorn Tereliusc4ca1d32018-04-27 12:33:341429 const std::vector<TransportFeedbackType>& incoming_rtcp =
1430 parsed_log_.transport_feedbacks(kIncomingPacket);
Stefan Holmer13181032016-07-29 12:48:541431
1432 SimulatedClock clock(0);
1433 BitrateObserver observer;
Danil Chapovalov83bbe912019-08-07 10:24:531434 RtcEventLogNull null_event_log;
Sebastian Jansson05acd2b2019-01-21 12:07:471435 TransportFeedbackAdapter transport_feedback;
Sebastian Jansson2db5fc02019-04-30 12:17:451436 auto factory = GoogCcNetworkControllerFactory();
Sebastian Jansson5c94f552018-10-15 16:46:511437 TimeDelta process_interval = factory.GetProcessInterval();
Stefan Holmer13181032016-07-29 12:48:541438 // TODO(holmer): Log the call config and use that here instead.
1439 static const uint32_t kDefaultStartBitrateBps = 300000;
Sebastian Jansson5c94f552018-10-15 16:46:511440 NetworkControllerConfig cc_config;
Danil Chapovalov0c626af2020-02-10 10:16:001441 cc_config.constraints.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Danil Chapovalovcad3e0e2020-02-17 17:46:071442 cc_config.constraints.starting_rate =
1443 DataRate::BitsPerSec(kDefaultStartBitrateBps);
Sebastian Jansson2db5fc02019-04-30 12:17:451444 cc_config.event_log = &null_event_log;
Sebastian Jansson5c94f552018-10-15 16:46:511445 auto goog_cc = factory.Create(cc_config);
Stefan Holmer13181032016-07-29 12:48:541446
Bjorn Tereliusb577d5e2017-11-10 15:21:341447 TimeSeries time_series("Delay-based estimate", LineStyle::kStep,
1448 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 09:55:551449 TimeSeries acked_time_series("Raw acked bitrate", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 15:21:341450 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 09:55:551451 TimeSeries robust_time_series("Robust throughput estimate", LineStyle::kLine,
1452 PointStyle::kHighlight);
1453 TimeSeries acked_estimate_time_series("Ackednowledged bitrate estimate",
1454 LineStyle::kLine,
1455 PointStyle::kHighlight);
Stefan Holmer13181032016-07-29 12:48:541456
1457 auto rtp_iterator = outgoing_rtp.begin();
1458 auto rtcp_iterator = incoming_rtcp.begin();
1459
1460 auto NextRtpTime = [&]() {
1461 if (rtp_iterator != outgoing_rtp.end())
1462 return static_cast<int64_t>(rtp_iterator->first);
1463 return std::numeric_limits<int64_t>::max();
1464 };
1465
1466 auto NextRtcpTime = [&]() {
1467 if (rtcp_iterator != incoming_rtcp.end())
Bjorn Tereliusc4ca1d32018-04-27 12:33:341468 return static_cast<int64_t>(rtcp_iterator->log_time_us());
Stefan Holmer13181032016-07-29 12:48:541469 return std::numeric_limits<int64_t>::max();
1470 };
Bjorn Tereliusa728c912018-12-06 11:26:301471 int64_t next_process_time_us_ = std::min({NextRtpTime(), NextRtcpTime()});
Stefan Holmer13181032016-07-29 12:48:541472
1473 auto NextProcessTime = [&]() {
1474 if (rtcp_iterator != incoming_rtcp.end() ||
1475 rtp_iterator != outgoing_rtp.end()) {
Sebastian Jansson5c94f552018-10-15 16:46:511476 return next_process_time_us_;
Stefan Holmer13181032016-07-29 12:48:541477 }
1478 return std::numeric_limits<int64_t>::max();
1479 };
1480
Björn Tereliuseb9af842022-05-05 13:54:491481 RateStatistics raw_acked_bitrate(750, 8000);
Björn Tereliusae1892d2020-06-17 09:55:551482 test::ExplicitKeyValueConfig throughput_config(
Björn Tereliuse31315b2023-09-04 14:21:501483 "WebRTC-Bwe-RobustThroughputEstimatorSettings/enabled:true/");
Björn Tereliusae1892d2020-06-17 09:55:551484 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1485 robust_throughput_estimator(
1486 AcknowledgedBitrateEstimatorInterface::Create(&throughput_config));
Björn Tereliuse31315b2023-09-04 14:21:501487 test::ExplicitKeyValueConfig acked_bitrate_config(
1488 "WebRTC-Bwe-RobustThroughputEstimatorSettings/enabled:false/");
Björn Terelius251b0dc2019-11-11 20:00:181489 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1490 acknowledged_bitrate_estimator(
Björn Tereliuse31315b2023-09-04 14:21:501491 AcknowledgedBitrateEstimatorInterface::Create(&acked_bitrate_config));
Sebastian Jansson5c94f552018-10-15 16:46:511492 int64_t time_us =
1493 std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
Stefan Holmer492ee282016-10-27 15:19:201494 int64_t last_update_us = 0;
Stefan Holmer13181032016-07-29 12:48:541495 while (time_us != std::numeric_limits<int64_t>::max()) {
1496 clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
Bjorn Tereliusc60a7772018-12-05 20:15:301497 if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1498 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1499 const RtpPacketType& rtp_packet = *rtp_iterator->second;
1500 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
Erik Språng30a276b2019-04-23 10:00:111501 RtpPacketSendInfo packet_info;
Erik Språng6a0a5592021-06-15 17:04:241502 packet_info.media_ssrc = rtp_packet.rtp.header.ssrc;
Bjorn Tereliusf2e9cab2019-05-27 14:44:091503 packet_info.transport_sequence_number =
Erik Språng30a276b2019-04-23 10:00:111504 rtp_packet.rtp.header.extension.transportSequenceNumber;
1505 packet_info.rtp_sequence_number = rtp_packet.rtp.header.sequenceNumber;
Erik Språng30a276b2019-04-23 10:00:111506 packet_info.length = rtp_packet.rtp.total_length;
Björn Tereliusae1892d2020-06-17 09:55:551507 if (IsRtxSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1508 rtp_packet.rtp.header.ssrc)) {
1509 // Don't set the optional media type as we don't know if it is
1510 // a retransmission, FEC or padding.
1511 } else if (IsVideoSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1512 rtp_packet.rtp.header.ssrc)) {
1513 packet_info.packet_type = RtpPacketMediaType::kVideo;
1514 } else if (IsAudioSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1515 rtp_packet.rtp.header.ssrc)) {
1516 packet_info.packet_type = RtpPacketMediaType::kAudio;
1517 }
Bjorn Tereliusc60a7772018-12-05 20:15:301518 transport_feedback.AddPacket(
Erik Språng30a276b2019-04-23 10:00:111519 packet_info,
1520 0u, // Per packet overhead bytes.
Danil Chapovalov0c626af2020-02-10 10:16:001521 Timestamp::Micros(rtp_packet.rtp.log_time_us()));
Bjorn Tereliusc60a7772018-12-05 20:15:301522 }
Björn Tereliusae1892d2020-06-17 09:55:551523 rtc::SentPacket sent_packet;
1524 sent_packet.send_time_ms = rtp_packet.rtp.log_time_ms();
1525 sent_packet.info.included_in_allocation = true;
1526 sent_packet.info.packet_size_bytes = rtp_packet.rtp.total_length;
1527 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
1528 sent_packet.packet_id =
1529 rtp_packet.rtp.header.extension.transportSequenceNumber;
1530 sent_packet.info.included_in_feedback = true;
1531 }
1532 auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet);
1533 if (sent_msg)
1534 observer.Update(goog_cc->OnSentPacket(*sent_msg));
Bjorn Tereliusc60a7772018-12-05 20:15:301535 ++rtp_iterator;
1536 }
Stefan Holmer13181032016-07-29 12:48:541537 if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
stefanc3de0332016-08-02 14:22:171538 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
Sebastian Jansson5c94f552018-10-15 16:46:511539
1540 auto feedback_msg = transport_feedback.ProcessTransportFeedback(
Sebastian Jansson05acd2b2019-01-21 12:07:471541 rtcp_iterator->transport_feedback,
Danil Chapovalov0c626af2020-02-10 10:16:001542 Timestamp::Millis(clock.TimeInMilliseconds()));
Sebastian Jansson5c94f552018-10-15 16:46:511543 if (feedback_msg) {
1544 observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg));
Sebastian Jansson88290ae2019-06-20 10:26:311545 std::vector<PacketResult> feedback =
1546 feedback_msg->SortedByReceiveTime();
Sebastian Jansson5c94f552018-10-15 16:46:511547 if (!feedback.empty()) {
Björn Terelius251b0dc2019-11-11 20:00:181548 acknowledged_bitrate_estimator->IncomingPacketFeedbackVector(
1549 feedback);
Björn Tereliusae1892d2020-06-17 09:55:551550 robust_throughput_estimator->IncomingPacketFeedbackVector(feedback);
1551 for (const PacketResult& packet : feedback) {
Björn Tereliuseb9af842022-05-05 13:54:491552 raw_acked_bitrate.Update(packet.sent_packet.size.bytes(),
1553 packet.receive_time.ms());
Björn Tereliusae1892d2020-06-17 09:55:551554 }
Björn Tereliuseb9af842022-05-05 13:54:491555 absl::optional<uint32_t> raw_bitrate_bps =
1556 raw_acked_bitrate.Rate(feedback.back().receive_time.ms());
1557 float x = config_.GetCallTimeSec(clock.CurrentTime());
1558 if (raw_bitrate_bps) {
1559 float y = raw_bitrate_bps.value() / 1000;
1560 acked_time_series.points.emplace_back(x, y);
1561 }
1562 absl::optional<DataRate> robust_estimate =
1563 robust_throughput_estimator->bitrate();
1564 if (robust_estimate) {
1565 float y = robust_estimate.value().kbps();
1566 robust_time_series.points.emplace_back(x, y);
1567 }
1568 absl::optional<DataRate> acked_estimate =
1569 acknowledged_bitrate_estimator->bitrate();
1570 if (acked_estimate) {
1571 float y = acked_estimate.value().kbps();
1572 acked_estimate_time_series.points.emplace_back(x, y);
1573 }
Sebastian Jansson5c94f552018-10-15 16:46:511574 }
Stefan Holmer13181032016-07-29 12:48:541575 }
1576 ++rtcp_iterator;
1577 }
stefanc3de0332016-08-02 14:22:171578 if (clock.TimeInMicroseconds() >= NextProcessTime()) {
1579 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
Sebastian Jansson5c94f552018-10-15 16:46:511580 ProcessInterval msg;
Danil Chapovalov0c626af2020-02-10 10:16:001581 msg.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Sebastian Jansson5c94f552018-10-15 16:46:511582 observer.Update(goog_cc->OnProcessInterval(msg));
1583 next_process_time_us_ += process_interval.us();
stefanc3de0332016-08-02 14:22:171584 }
Stefan Holmer492ee282016-10-27 15:19:201585 if (observer.GetAndResetBitrateUpdated() ||
1586 time_us - last_update_us >= 1e6) {
Stefan Holmer13181032016-07-29 12:48:541587 uint32_t y = observer.last_bitrate_bps() / 1000;
Björn Tereliuscb241582022-02-25 08:22:381588 float x = config_.GetCallTimeSec(clock.CurrentTime());
Stefan Holmer13181032016-07-29 12:48:541589 time_series.points.emplace_back(x, y);
Stefan Holmer492ee282016-10-27 15:19:201590 last_update_us = time_us;
Stefan Holmer13181032016-07-29 12:48:541591 }
1592 time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
1593 }
1594 // Add the data set to the plot.
philipel35ba9bd2017-04-19 12:58:511595 plot->AppendTimeSeries(std::move(time_series));
Björn Tereliusae1892d2020-06-17 09:55:551596 plot->AppendTimeSeries(std::move(robust_time_series));
philipel35ba9bd2017-04-19 12:58:511597 plot->AppendTimeSeries(std::move(acked_time_series));
Bjorn Terelius6984ad22017-10-24 10:19:451598 plot->AppendTimeSeriesIfNotEmpty(std::move(acked_estimate_time_series));
Stefan Holmer13181032016-07-29 12:48:541599
Bjorn Terelius068fc352019-02-13 21:38:251600 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1601 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 19:03:271602 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Terelius28db2662017-10-04 12:22:431603 plot->SetTitle("Simulated send-side BWE behavior");
1604}
1605
1606void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:341607 using RtpPacketType = LoggedRtpPacketIncoming;
Per Kjellanderfe2063e2021-05-12 07:02:431608 class RembInterceptor {
Bjorn Terelius28db2662017-10-04 12:22:431609 public:
Per Kjellanderfe2063e2021-05-12 07:02:431610 void SendRemb(uint32_t bitrate_bps, std::vector<uint32_t> ssrcs) {
Bjorn Terelius28db2662017-10-04 12:22:431611 last_bitrate_bps_ = bitrate_bps;
1612 bitrate_updated_ = true;
Bjorn Terelius28db2662017-10-04 12:22:431613 }
1614 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
1615 bool GetAndResetBitrateUpdated() {
1616 bool bitrate_updated = bitrate_updated_;
1617 bitrate_updated_ = false;
1618 return bitrate_updated;
1619 }
1620
1621 private:
Bjorn Terelius571e1302020-06-09 08:29:091622 // We don't know the start bitrate, but assume that it is the default 300
1623 // kbps.
1624 uint32_t last_bitrate_bps_ = 300000;
1625 bool bitrate_updated_ = false;
Bjorn Terelius28db2662017-10-04 12:22:431626 };
1627
Bjorn Tereliusc4ca1d32018-04-27 12:33:341628 std::multimap<int64_t, const RtpPacketType*> incoming_rtp;
Bjorn Terelius28db2662017-10-04 12:22:431629
Bjorn Tereliusc4ca1d32018-04-27 12:33:341630 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Terelius48b82792020-05-19 08:57:241631 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:341632 for (const auto& rtp_packet : stream.incoming_packets)
1633 incoming_rtp.insert(
1634 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Bjorn Terelius28db2662017-10-04 12:22:431635 }
1636 }
1637
1638 SimulatedClock clock(0);
Per Kjellanderfe2063e2021-05-12 07:02:431639 RembInterceptor remb_interceptor;
1640 ReceiveSideCongestionController rscc(
1641 &clock, [](auto...) {},
1642 absl::bind_front(&RembInterceptor::SendRemb, &remb_interceptor), nullptr);
Bjorn Terelius28db2662017-10-04 12:22:431643 // TODO(holmer): Log the call config and use that here instead.
1644 // static const uint32_t kDefaultStartBitrateBps = 300000;
1645 // rscc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
1646
Bjorn Tereliusb577d5e2017-11-10 15:21:341647 TimeSeries time_series("Receive side estimate", LineStyle::kLine,
1648 PointStyle::kHighlight);
1649 TimeSeries acked_time_series("Received bitrate", LineStyle::kLine);
Bjorn Terelius28db2662017-10-04 12:22:431650
1651 RateStatistics acked_bitrate(250, 8000);
1652 int64_t last_update_us = 0;
1653 for (const auto& kv : incoming_rtp) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:341654 const RtpPacketType& packet = *kv.second;
Danil Chapovalov4b61f3a2023-03-30 12:17:191655
1656 RtpPacketReceived rtp_packet = RtpPacketForBWEFromHeader(packet.rtp.header);
1657 rtp_packet.set_arrival_time(packet.rtp.log_time());
1658 rtp_packet.SetPayloadSize(packet.rtp.total_length -
1659 rtp_packet.headers_size());
1660
1661 clock.AdvanceTime(rtp_packet.arrival_time() - clock.CurrentTime());
1662 rscc.OnReceivedPacket(rtp_packet, MediaType::VIDEO);
1663 int64_t arrival_time_ms = packet.rtp.log_time().ms();
1664 acked_bitrate.Update(packet.rtp.total_length, arrival_time_ms);
Danil Chapovalov431abd92018-06-18 10:54:171665 absl::optional<uint32_t> bitrate_bps = acked_bitrate.Rate(arrival_time_ms);
Bjorn Terelius28db2662017-10-04 12:22:431666 if (bitrate_bps) {
1667 uint32_t y = *bitrate_bps / 1000;
Björn Tereliuscb241582022-02-25 08:22:381668 float x = config_.GetCallTimeSec(clock.CurrentTime());
Bjorn Terelius28db2662017-10-04 12:22:431669 acked_time_series.points.emplace_back(x, y);
1670 }
Per Kjellanderfe2063e2021-05-12 07:02:431671 if (remb_interceptor.GetAndResetBitrateUpdated() ||
Bjorn Terelius28db2662017-10-04 12:22:431672 clock.TimeInMicroseconds() - last_update_us >= 1e6) {
Per Kjellanderfe2063e2021-05-12 07:02:431673 uint32_t y = remb_interceptor.last_bitrate_bps() / 1000;
Björn Tereliuscb241582022-02-25 08:22:381674 float x = config_.GetCallTimeSec(clock.CurrentTime());
Bjorn Terelius28db2662017-10-04 12:22:431675 time_series.points.emplace_back(x, y);
1676 last_update_us = clock.TimeInMicroseconds();
1677 }
1678 }
1679 // Add the data set to the plot.
1680 plot->AppendTimeSeries(std::move(time_series));
1681 plot->AppendTimeSeries(std::move(acked_time_series));
1682
Bjorn Terelius068fc352019-02-13 21:38:251683 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1684 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius28db2662017-10-04 12:22:431685 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1686 plot->SetTitle("Simulated receive-side BWE behavior");
Stefan Holmer13181032016-07-29 12:48:541687}
1688
tereliuse34c19c2016-08-15 15:47:141689void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
Bjorn Terelius57ba7e12018-10-25 13:31:351690 TimeSeries time_series("Network delay", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 15:21:341691 PointStyle::kHighlight);
Bjorn Terelius57ba7e12018-10-25 13:31:351692 int64_t min_send_receive_diff_ms = std::numeric_limits<int64_t>::max();
1693 int64_t min_rtt_ms = std::numeric_limits<int64_t>::max();
stefanc3de0332016-08-02 14:22:171694
Björn Tereliusc69c1bb2019-10-11 13:06:581695 std::vector<MatchedSendArrivalTimes> matched_rtp_rtcp =
1696 GetNetworkTrace(parsed_log_);
1697 absl::c_stable_sort(matched_rtp_rtcp, [](const MatchedSendArrivalTimes& a,
1698 const MatchedSendArrivalTimes& b) {
philipel3574d052019-11-18 13:38:131699 return a.feedback_arrival_time_ms < b.feedback_arrival_time_ms ||
1700 (a.feedback_arrival_time_ms == b.feedback_arrival_time_ms &&
1701 a.arrival_time_ms < b.arrival_time_ms);
Björn Tereliusc69c1bb2019-10-11 13:06:581702 });
1703 for (const auto& packet : matched_rtp_rtcp) {
Sebastian Jansson74f96ec2019-10-29 11:57:541704 if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived)
Christoffer Rodbro89f64d32018-09-27 12:29:351705 continue;
Björn Tereliuscb241582022-02-25 08:22:381706 float x = config_.GetCallTimeSecFromMs(packet.feedback_arrival_time_ms);
Christoffer Rodbro89f64d32018-09-27 12:29:351707 int64_t y = packet.arrival_time_ms - packet.send_time_ms;
Bjorn Terelius57ba7e12018-10-25 13:31:351708 int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms;
1709 min_rtt_ms = std::min(rtt_ms, min_rtt_ms);
1710 min_send_receive_diff_ms = std::min(y, min_send_receive_diff_ms);
Christoffer Rodbro89f64d32018-09-27 12:29:351711 time_series.points.emplace_back(x, y);
stefanc3de0332016-08-02 14:22:171712 }
Christoffer Rodbro89f64d32018-09-27 12:29:351713
Bjorn Terelius57ba7e12018-10-25 13:31:351714 // We assume that the base network delay (w/o queues) is equal to half
1715 // the minimum RTT. Therefore rescale the delays by subtracting the minimum
Mirko Bonadei604e75c2019-07-25 09:55:471716 // observed 1-ways delay and add half the minimum RTT.
Bjorn Terelius57ba7e12018-10-25 13:31:351717 const int64_t estimated_clock_offset_ms =
1718 min_send_receive_diff_ms - min_rtt_ms / 2;
stefanc3de0332016-08-02 14:22:171719 for (TimeSeriesPoint& point : time_series.points)
Bjorn Terelius57ba7e12018-10-25 13:31:351720 point.y -= estimated_clock_offset_ms;
Bjorn Terelius57ba7e12018-10-25 13:31:351721
stefanc3de0332016-08-02 14:22:171722 // Add the data set to the plot.
stefana0a8ed72017-09-06 09:06:321723 plot->AppendTimeSeriesIfNotEmpty(std::move(time_series));
stefanc3de0332016-08-02 14:22:171724
Bjorn Terelius068fc352019-02-13 21:38:251725 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1726 "Time (s)", kLeftMargin, kRightMargin);
stefanc3de0332016-08-02 14:22:171727 plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
Konrad Hofbauer5be3bbd2019-01-21 11:31:071728 plot->SetTitle("Outgoing network delay (based on per-packet feedback)");
stefanc3de0332016-08-02 14:22:171729}
stefan08383272016-12-20 16:51:521730
Bjorn Terelius0295a962017-10-25 15:42:411731void EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 12:33:341732 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1733 const std::vector<LoggedRtpPacketOutgoing>& packets =
1734 stream.outgoing_packets;
Bjorn Terelius0295a962017-10-25 15:42:411735
Bjorn Terelius48b82792020-05-19 08:57:241736 if (IsRtxSsrc(parsed_log_, kOutgoingPacket, stream.ssrc)) {
Konrad Hofbauerbfb735b2019-04-16 09:12:111737 continue;
1738 }
1739
Bjorn Terelius0295a962017-10-25 15:42:411740 if (packets.size() < 2) {
Mirko Bonadei675513b2017-11-09 10:09:251741 RTC_LOG(LS_WARNING)
1742 << "Can't estimate a the RTP clock frequency or the "
1743 "pacer delay with less than 2 packets in the stream";
Bjorn Terelius0295a962017-10-25 15:42:411744 continue;
1745 }
Björn Terelius0d1b28c2020-05-27 18:25:061746 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Danil Chapovalov431abd92018-06-18 10:54:171747 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 08:57:241748 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius0295a962017-10-25 15:42:411749 if (!estimated_frequency)
1750 continue;
Bjorn Terelius48b82792020-05-19 08:57:241751 if (IsVideoSsrc(parsed_log_, kOutgoingPacket, stream.ssrc) &&
Bjorn Tereliusc4ca1d32018-04-27 12:33:341752 *estimated_frequency != 90000) {
Mirko Bonadei675513b2017-11-09 10:09:251753 RTC_LOG(LS_WARNING)
Bjorn Terelius0295a962017-10-25 15:42:411754 << "Video stream should use a 90 kHz clock but appears to use "
1755 << *estimated_frequency / 1000 << ". Discarding.";
1756 continue;
1757 }
1758
1759 TimeSeries pacer_delay_series(
Bjorn Terelius48b82792020-05-19 08:57:241760 GetStreamName(parsed_log_, kOutgoingPacket, stream.ssrc) + "(" +
Bjorn Terelius0295a962017-10-25 15:42:411761 std::to_string(*estimated_frequency / 1000) + " kHz)",
Bjorn Tereliusb577d5e2017-11-10 15:21:341762 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Terelius0295a962017-10-25 15:42:411763 SeqNumUnwrapper<uint32_t> timestamp_unwrapper;
1764 uint64_t first_capture_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 12:33:341765 timestamp_unwrapper.Unwrap(packets.front().rtp.header.timestamp);
1766 uint64_t first_send_timestamp = packets.front().rtp.log_time_us();
1767 for (const auto& packet : packets) {
Bjorn Terelius0295a962017-10-25 15:42:411768 double capture_time_ms = (static_cast<double>(timestamp_unwrapper.Unwrap(
Bjorn Tereliusc4ca1d32018-04-27 12:33:341769 packet.rtp.header.timestamp)) -
Bjorn Terelius0295a962017-10-25 15:42:411770 first_capture_timestamp) /
1771 *estimated_frequency * 1000;
1772 double send_time_ms =
Bjorn Tereliusc4ca1d32018-04-27 12:33:341773 static_cast<double>(packet.rtp.log_time_us() - first_send_timestamp) /
1774 1000;
Björn Tereliuscb241582022-02-25 08:22:381775 float x = config_.GetCallTimeSec(packet.rtp.log_time());
Bjorn Terelius0295a962017-10-25 15:42:411776 float y = send_time_ms - capture_time_ms;
1777 pacer_delay_series.points.emplace_back(x, y);
1778 }
1779 plot->AppendTimeSeries(std::move(pacer_delay_series));
1780 }
1781
Bjorn Terelius068fc352019-02-13 21:38:251782 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1783 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius0295a962017-10-25 15:42:411784 plot->SetSuggestedYAxis(0, 10, "Pacer delay (ms)", kBottomMargin, kTopMargin);
1785 plot->SetTitle(
1786 "Delay from capture to send time. (First packet normalized to 0.)");
1787}
1788
Bjorn Tereliusc4ca1d32018-04-27 12:33:341789void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction,
1790 Plot* plot) {
1791 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1792 TimeSeries rtp_timestamps(
Bjorn Terelius48b82792020-05-19 08:57:241793 GetStreamName(parsed_log_, direction, stream.ssrc) + " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 12:33:341794 LineStyle::kLine, PointStyle::kHighlight);
1795 for (const auto& packet : stream.packet_view) {
Björn Tereliuscb241582022-02-25 08:22:381796 float x = config_.GetCallTimeSec(packet.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341797 float y = packet.header.timestamp;
1798 rtp_timestamps.points.emplace_back(x, y);
stefane372d3c2017-02-02 16:04:181799 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:341800 plot->AppendTimeSeries(std::move(rtp_timestamps));
Björn Tereliusff612732018-04-25 14:23:011801
Bjorn Tereliusc4ca1d32018-04-27 12:33:341802 TimeSeries rtcp_timestamps(
Bjorn Terelius48b82792020-05-19 08:57:241803 GetStreamName(parsed_log_, direction, stream.ssrc) +
1804 " rtcp capture-time",
Bjorn Tereliusc4ca1d32018-04-27 12:33:341805 LineStyle::kLine, PointStyle::kHighlight);
1806 // TODO(terelius): Why only sender reports?
1807 const auto& sender_reports = parsed_log_.sender_reports(direction);
1808 for (const auto& rtcp : sender_reports) {
1809 if (rtcp.sr.sender_ssrc() != stream.ssrc)
1810 continue;
Björn Tereliuscb241582022-02-25 08:22:381811 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusc4ca1d32018-04-27 12:33:341812 float y = rtcp.sr.rtp_timestamp();
1813 rtcp_timestamps.points.emplace_back(x, y);
Björn Tereliusff612732018-04-25 14:23:011814 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:341815 plot->AppendTimeSeriesIfNotEmpty(std::move(rtcp_timestamps));
stefane372d3c2017-02-02 16:04:181816 }
1817
Bjorn Terelius068fc352019-02-13 21:38:251818 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1819 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 12:33:341820 plot->SetSuggestedYAxis(0, 1, "RTP timestamp", kBottomMargin, kTopMargin);
1821 plot->SetTitle(GetDirectionAsString(direction) + " timestamps");
stefane372d3c2017-02-02 16:04:181822}
michaelt6e5b2192017-02-22 15:33:271823
Bjorn Tereliusb1222c22018-07-24 11:45:311824void EventLogAnalyzer::CreateSenderAndReceiverReportPlot(
1825 PacketDirection direction,
1826 rtc::FunctionView<float(const rtcp::ReportBlock&)> fy,
1827 std::string title,
1828 std::string yaxis_label,
1829 Plot* plot) {
1830 std::map<uint32_t, TimeSeries> sr_reports_by_ssrc;
1831 const auto& sender_reports = parsed_log_.sender_reports(direction);
1832 for (const auto& rtcp : sender_reports) {
Björn Tereliuscb241582022-02-25 08:22:381833 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusb1222c22018-07-24 11:45:311834 uint32_t ssrc = rtcp.sr.sender_ssrc();
1835 for (const auto& block : rtcp.sr.report_blocks()) {
1836 float y = fy(block);
1837 auto sr_report_it = sr_reports_by_ssrc.find(ssrc);
1838 bool inserted;
1839 if (sr_report_it == sr_reports_by_ssrc.end()) {
1840 std::tie(sr_report_it, inserted) = sr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 08:57:241841 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1842 " Sender Reports",
Bjorn Tereliusb1222c22018-07-24 11:45:311843 LineStyle::kLine, PointStyle::kHighlight));
1844 }
1845 sr_report_it->second.points.emplace_back(x, y);
1846 }
1847 }
1848 for (auto& kv : sr_reports_by_ssrc) {
1849 plot->AppendTimeSeries(std::move(kv.second));
1850 }
1851
1852 std::map<uint32_t, TimeSeries> rr_reports_by_ssrc;
1853 const auto& receiver_reports = parsed_log_.receiver_reports(direction);
1854 for (const auto& rtcp : receiver_reports) {
Björn Tereliuscb241582022-02-25 08:22:381855 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusb1222c22018-07-24 11:45:311856 uint32_t ssrc = rtcp.rr.sender_ssrc();
1857 for (const auto& block : rtcp.rr.report_blocks()) {
1858 float y = fy(block);
1859 auto rr_report_it = rr_reports_by_ssrc.find(ssrc);
1860 bool inserted;
1861 if (rr_report_it == rr_reports_by_ssrc.end()) {
1862 std::tie(rr_report_it, inserted) = rr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 08:57:241863 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1864 " Receiver Reports",
1865 LineStyle::kLine, PointStyle::kHighlight));
Bjorn Tereliusb1222c22018-07-24 11:45:311866 }
1867 rr_report_it->second.points.emplace_back(x, y);
1868 }
1869 }
1870 for (auto& kv : rr_reports_by_ssrc) {
1871 plot->AppendTimeSeries(std::move(kv.second));
1872 }
1873
Bjorn Terelius068fc352019-02-13 21:38:251874 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1875 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusb1222c22018-07-24 11:45:311876 plot->SetSuggestedYAxis(0, 1, yaxis_label, kBottomMargin, kTopMargin);
1877 plot->SetTitle(title);
1878}
1879
Qingsi Wang8eca1ff2018-02-02 19:49:441880void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) {
1881 std::map<uint32_t, TimeSeries> configs_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 12:33:341882 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 19:49:441883 if (configs_by_cp_id.find(config.candidate_pair_id) ==
1884 configs_by_cp_id.end()) {
1885 const std::string candidate_pair_desc =
1886 GetCandidatePairLogDescriptionAsString(config);
Qingsi Wang93a84392018-01-31 01:13:091887 configs_by_cp_id[config.candidate_pair_id] =
1888 TimeSeries("[" + std::to_string(config.candidate_pair_id) + "]" +
1889 candidate_pair_desc,
1890 LineStyle::kNone, PointStyle::kHighlight);
Qingsi Wang8eca1ff2018-02-02 19:49:441891 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1892 candidate_pair_desc;
1893 }
Björn Tereliuscb241582022-02-25 08:22:381894 float x = config_.GetCallTimeSec(config.log_time());
Qingsi Wang8eca1ff2018-02-02 19:49:441895 float y = static_cast<float>(config.type);
1896 configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y);
1897 }
1898
1899 // TODO(qingsi): There can be a large number of candidate pairs generated by
1900 // certain calls and the frontend cannot render the chart in this case due to
1901 // the failure of generating a palette with the same number of colors.
1902 for (auto& kv : configs_by_cp_id) {
1903 plot->AppendTimeSeries(std::move(kv.second));
1904 }
1905
Bjorn Terelius068fc352019-02-13 21:38:251906 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1907 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 13:46:391908 plot->SetSuggestedYAxis(0, 3, "Config Type", kBottomMargin, kTopMargin);
Qingsi Wang8eca1ff2018-02-02 19:49:441909 plot->SetTitle("[IceEventLog] ICE candidate pair configs");
Bjorn Tereliusf640b872019-07-24 13:46:391910 plot->SetYAxisTickLabels(
1911 {{static_cast<float>(IceCandidatePairConfigType::kAdded), "ADDED"},
1912 {static_cast<float>(IceCandidatePairConfigType::kUpdated), "UPDATED"},
1913 {static_cast<float>(IceCandidatePairConfigType::kDestroyed),
1914 "DESTROYED"},
1915 {static_cast<float>(IceCandidatePairConfigType::kSelected),
1916 "SELECTED"}});
Qingsi Wang8eca1ff2018-02-02 19:49:441917}
1918
1919std::string EventLogAnalyzer::GetCandidatePairLogDescriptionFromId(
1920 uint32_t candidate_pair_id) {
1921 if (candidate_pair_desc_by_id_.find(candidate_pair_id) !=
1922 candidate_pair_desc_by_id_.end()) {
1923 return candidate_pair_desc_by_id_[candidate_pair_id];
1924 }
Bjorn Tereliusc4ca1d32018-04-27 12:33:341925 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 19:49:441926 // TODO(qingsi): Add the handling of the "Updated" config event after the
1927 // visualization of property change for candidate pairs is introduced.
1928 if (candidate_pair_desc_by_id_.find(config.candidate_pair_id) ==
1929 candidate_pair_desc_by_id_.end()) {
1930 const std::string candidate_pair_desc =
1931 GetCandidatePairLogDescriptionAsString(config);
1932 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1933 candidate_pair_desc;
1934 }
1935 }
1936 return candidate_pair_desc_by_id_[candidate_pair_id];
1937}
1938
1939void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) {
Bjorn Tereliusf640b872019-07-24 13:46:391940 constexpr int kEventTypeOffset =
1941 static_cast<int>(IceCandidatePairConfigType::kNumValues);
Qingsi Wang8eca1ff2018-02-02 19:49:441942 std::map<uint32_t, TimeSeries> checks_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 12:33:341943 for (const auto& event : parsed_log_.ice_candidate_pair_events()) {
Qingsi Wang8eca1ff2018-02-02 19:49:441944 if (checks_by_cp_id.find(event.candidate_pair_id) ==
1945 checks_by_cp_id.end()) {
1946 checks_by_cp_id[event.candidate_pair_id] = TimeSeries(
Qingsi Wang93a84392018-01-31 01:13:091947 "[" + std::to_string(event.candidate_pair_id) + "]" +
1948 GetCandidatePairLogDescriptionFromId(event.candidate_pair_id),
Qingsi Wang8eca1ff2018-02-02 19:49:441949 LineStyle::kNone, PointStyle::kHighlight);
1950 }
Björn Tereliuscb241582022-02-25 08:22:381951 float x = config_.GetCallTimeSec(event.log_time());
Bjorn Tereliusf640b872019-07-24 13:46:391952 float y = static_cast<float>(event.type) + kEventTypeOffset;
Qingsi Wang8eca1ff2018-02-02 19:49:441953 checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y);
1954 }
1955
1956 // TODO(qingsi): The same issue as in CreateIceCandidatePairConfigGraph.
1957 for (auto& kv : checks_by_cp_id) {
1958 plot->AppendTimeSeries(std::move(kv.second));
1959 }
1960
Bjorn Terelius068fc352019-02-13 21:38:251961 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1962 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 13:46:391963 plot->SetSuggestedYAxis(0, 4, "Connectivity State", kBottomMargin,
Qingsi Wang8eca1ff2018-02-02 19:49:441964 kTopMargin);
1965 plot->SetTitle("[IceEventLog] ICE connectivity checks");
Bjorn Tereliusf640b872019-07-24 13:46:391966
1967 plot->SetYAxisTickLabels(
1968 {{static_cast<float>(IceCandidatePairEventType::kCheckSent) +
1969 kEventTypeOffset,
1970 "CHECK SENT"},
1971 {static_cast<float>(IceCandidatePairEventType::kCheckReceived) +
1972 kEventTypeOffset,
1973 "CHECK RECEIVED"},
1974 {static_cast<float>(IceCandidatePairEventType::kCheckResponseSent) +
1975 kEventTypeOffset,
1976 "RESPONSE SENT"},
1977 {static_cast<float>(IceCandidatePairEventType::kCheckResponseReceived) +
1978 kEventTypeOffset,
1979 "RESPONSE RECEIVED"}});
Qingsi Wang8eca1ff2018-02-02 19:49:441980}
1981
Zach Stein10a58012018-12-07 20:26:281982void EventLogAnalyzer::CreateDtlsTransportStateGraph(Plot* plot) {
1983 TimeSeries states("DTLS Transport State", LineStyle::kNone,
1984 PointStyle::kHighlight);
1985 for (const auto& event : parsed_log_.dtls_transport_states()) {
Björn Tereliuscb241582022-02-25 08:22:381986 float x = config_.GetCallTimeSec(event.log_time());
Zach Stein10a58012018-12-07 20:26:281987 float y = static_cast<float>(event.dtls_transport_state);
1988 states.points.emplace_back(x, y);
1989 }
1990 plot->AppendTimeSeries(std::move(states));
Bjorn Terelius068fc352019-02-13 21:38:251991 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1992 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 20:26:281993 plot->SetSuggestedYAxis(0, static_cast<float>(DtlsTransportState::kNumValues),
Bjorn Tereliusf640b872019-07-24 13:46:391994 "Transport State", kBottomMargin, kTopMargin);
Zach Stein10a58012018-12-07 20:26:281995 plot->SetTitle("DTLS Transport State");
Bjorn Tereliusf640b872019-07-24 13:46:391996 plot->SetYAxisTickLabels(
1997 {{static_cast<float>(DtlsTransportState::kNew), "NEW"},
1998 {static_cast<float>(DtlsTransportState::kConnecting), "CONNECTING"},
1999 {static_cast<float>(DtlsTransportState::kConnected), "CONNECTED"},
2000 {static_cast<float>(DtlsTransportState::kClosed), "CLOSED"},
2001 {static_cast<float>(DtlsTransportState::kFailed), "FAILED"}});
Zach Stein10a58012018-12-07 20:26:282002}
2003
2004void EventLogAnalyzer::CreateDtlsWritableStateGraph(Plot* plot) {
2005 TimeSeries writable("DTLS Writable", LineStyle::kNone,
2006 PointStyle::kHighlight);
2007 for (const auto& event : parsed_log_.dtls_writable_states()) {
Björn Tereliuscb241582022-02-25 08:22:382008 float x = config_.GetCallTimeSec(event.log_time());
Zach Stein10a58012018-12-07 20:26:282009 float y = static_cast<float>(event.writable);
2010 writable.points.emplace_back(x, y);
2011 }
2012 plot->AppendTimeSeries(std::move(writable));
Bjorn Terelius068fc352019-02-13 21:38:252013 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
2014 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 20:26:282015 plot->SetSuggestedYAxis(0, 1, "Writable", kBottomMargin, kTopMargin);
2016 plot->SetTitle("DTLS Writable State");
2017}
2018
terelius54ce6802016-07-13 13:44:412019} // namespace webrtc