blob: a5b8b49302176bfee26a6c9af2897cab4729ffd7 [file] [log] [blame]
terelius54ce6802016-07-13 06:44:41 -07001/*
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 13:57:41 +020011#include "rtc_tools/rtc_event_log_visualizer/analyzer.h"
terelius54ce6802016-07-13 06:44:41 -070012
13#include <algorithm>
Oleh Prypin6581f212017-11-16 00:17:05 +010014#include <cmath>
terelius54ce6802016-07-13 06:44:41 -070015#include <limits>
16#include <map>
Mirko Bonadei317a1f02019-09-17 17:06:18 +020017#include <memory>
terelius54ce6802016-07-13 06:44:41 -070018#include <string>
19#include <utility>
20
Björn Tereliusc69c1bb2019-10-11 15:06:58 +020021#include "absl/algorithm/container.h"
Per Kjellanderfe2063e2021-05-12 09:02:43 +020022#include "absl/functional/bind_front.h"
Bjorn Terelius6c4b1b72019-01-11 13:01:29 +010023#include "absl/strings/string_view.h"
Artem Titov741daaf2019-03-21 14:37:36 +010024#include "api/function_view.h"
Niels Möller0d863f72020-11-24 17:50:31 +010025#include "api/network_state_predictor.h"
Sebastian Jansson95edb032019-01-17 16:24:12 +010026#include "api/transport/field_trial_based_config.h"
Sebastian Jansson5c94f552018-10-15 18:46:51 +020027#include "api/transport/goog_cc_factory.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020028#include "call/audio_receive_stream.h"
29#include "call/audio_send_stream.h"
30#include "call/call.h"
31#include "call/video_receive_stream.h"
32#include "call/video_send_stream.h"
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +020033#include "logging/rtc_event_log/rtc_event_processor.h"
Elad Alon99a81b62017-09-21 10:25:29 +020034#include "logging/rtc_event_log/rtc_stream_config.h"
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +020035#include "modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor.h"
Sebastian Jansson172fd852018-05-24 14:17:06 +020036#include "modules/congestion_controller/goog_cc/acknowledged_bitrate_estimator.h"
37#include "modules/congestion_controller/goog_cc/bitrate_estimator.h"
Sebastian Jansson04b18cb2018-07-02 09:25:25 +020038#include "modules/congestion_controller/goog_cc/delay_based_bwe.h"
Bjorn Terelius28db2662017-10-04 14:22:43 +020039#include "modules/congestion_controller/include/receive_side_congestion_controller.h"
Sebastian Jansson5c94f552018-10-15 18:46:51 +020040#include "modules/congestion_controller/rtp/transport_feedback_adapter.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020041#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h"
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +020042#include "modules/rtp_rtcp/source/rtcp_packet.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020043#include "modules/rtp_rtcp/source/rtcp_packet/common_header.h"
44#include "modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
45#include "modules/rtp_rtcp/source/rtcp_packet/remb.h"
46#include "modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
47#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
48#include "modules/rtp_rtcp/source/rtp_header_extensions.h"
Tomas Gunnarssonf25761d2020-06-03 22:55:33 +020049#include "modules/rtp_rtcp/source/rtp_rtcp_interface.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020050#include "rtc_base/checks.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020051#include "rtc_base/logging.h"
Evan Shrubsole097fc342023-01-09 10:21:43 +000052#include "rtc_base/numerics/sequence_number_unwrapper.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020053#include "rtc_base/rate_statistics.h"
Jonas Olsson366a50c2018-09-06 13:41:30 +020054#include "rtc_base/strings/string_builder.h"
Mirko Bonadei575998c2019-07-25 13:57:41 +020055#include "rtc_tools/rtc_event_log_visualizer/log_simulation.h"
Björn Tereliusae1892d2020-06-17 11:55:55 +020056#include "test/explicit_key_value_config.h"
Bjorn Terelius6984ad22017-10-24 12:19:45 +020057
tereliusdc35dcd2016-08-01 12:03:27 -070058namespace webrtc {
tereliusdc35dcd2016-08-01 12:03:27 -070059
terelius54ce6802016-07-13 06:44:41 -070060namespace {
61
62std::string SsrcToString(uint32_t ssrc) {
Jonas Olsson366a50c2018-09-06 13:41:30 +020063 rtc::StringBuilder ss;
terelius54ce6802016-07-13 06:44:41 -070064 ss << "SSRC " << ssrc;
Jonas Olsson84df1c72018-09-14 16:59:32 +020065 return ss.Release();
terelius54ce6802016-07-13 06:44:41 -070066}
67
68// Checks whether an SSRC is contained in the list of desired SSRCs.
69// Note that an empty SSRC list matches every SSRC.
70bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) {
Mirko Bonadei1f173152019-07-25 15:28:14 +020071 if (desired_ssrc.empty())
terelius54ce6802016-07-13 06:44:41 -070072 return true;
73 return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) !=
74 desired_ssrc.end();
75}
76
77double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
78 // The timestamp is a fixed point representation with 6 bits for seconds
79 // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the
Qingsi Wang8eca1ff2018-02-02 11:49:44 -080080 // time in seconds and then multiply by kNumMicrosecsPerSec to convert to
81 // microseconds.
terelius54ce6802016-07-13 06:44:41 -070082 static constexpr double kTimestampToMicroSec =
Qingsi Wang8eca1ff2018-02-02 11:49:44 -080083 static_cast<double>(kNumMicrosecsPerSec) / static_cast<double>(1ul << 18);
terelius54ce6802016-07-13 06:44:41 -070084 return abs_send_time * kTimestampToMicroSec;
85}
86
Artem Titov54500ad2021-07-26 15:51:27 +020087// Computes the difference `later` - `earlier` where `later` and `earlier`
88// are counters that wrap at `modulus`. The difference is chosen to have the
89// least absolute value. For example if `modulus` is 8, then the difference will
90// be chosen in the range [-3, 4]. If `modulus` is 9, then the difference will
terelius54ce6802016-07-13 06:44:41 -070091// be in [-4, 4].
92int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
93 RTC_DCHECK_LE(1, modulus);
94 RTC_DCHECK_LT(later, modulus);
95 RTC_DCHECK_LT(earlier, modulus);
96 int64_t difference =
97 static_cast<int64_t>(later) - static_cast<int64_t>(earlier);
98 int64_t max_difference = modulus / 2;
99 int64_t min_difference = max_difference - modulus + 1;
100 if (difference > max_difference) {
101 difference -= modulus;
102 }
103 if (difference < min_difference) {
104 difference += modulus;
105 }
terelius6addf492016-08-23 17:34:07 -0700106 if (difference > max_difference / 2 || difference < min_difference / 2) {
Mirko Bonadei675513b2017-11-09 11:09:25 +0100107 RTC_LOG(LS_WARNING) << "Difference between" << later << " and " << earlier
108 << " expected to be in the range ("
109 << min_difference / 2 << "," << max_difference / 2
110 << ") but is " << difference
111 << ". Correct unwrapping is uncertain.";
terelius6addf492016-08-23 17:34:07 -0700112 }
terelius54ce6802016-07-13 06:44:41 -0700113 return difference;
114}
115
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200116// This is much more reliable for outgoing streams than for incoming streams.
117template <typename RtpPacketContainer>
Danil Chapovalov431abd92018-06-18 12:54:17 +0200118absl::optional<uint32_t> EstimateRtpClockFrequency(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200119 const RtpPacketContainer& packets,
120 int64_t end_time_us) {
121 RTC_CHECK(packets.size() >= 2);
122 SeqNumUnwrapper<uint32_t> unwrapper;
Philip Eliasson1f850a62019-03-19 12:15:00 +0000123 int64_t first_rtp_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200124 unwrapper.Unwrap(packets[0].rtp.header.timestamp);
125 int64_t first_log_timestamp = packets[0].log_time_us();
Philip Eliasson1f850a62019-03-19 12:15:00 +0000126 int64_t last_rtp_timestamp = first_rtp_timestamp;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200127 int64_t last_log_timestamp = first_log_timestamp;
128 for (size_t i = 1; i < packets.size(); i++) {
129 if (packets[i].log_time_us() > end_time_us)
130 break;
131 last_rtp_timestamp = unwrapper.Unwrap(packets[i].rtp.header.timestamp);
132 last_log_timestamp = packets[i].log_time_us();
133 }
134 if (last_log_timestamp - first_log_timestamp < kNumMicrosecsPerSec) {
135 RTC_LOG(LS_WARNING)
136 << "Failed to estimate RTP clock frequency: Stream too short. ("
137 << packets.size() << " packets, "
138 << last_log_timestamp - first_log_timestamp << " us)";
Danil Chapovalov431abd92018-06-18 12:54:17 +0200139 return absl::nullopt;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200140 }
141 double duration =
142 static_cast<double>(last_log_timestamp - first_log_timestamp) /
143 kNumMicrosecsPerSec;
144 double estimated_frequency =
145 (last_rtp_timestamp - first_rtp_timestamp) / duration;
146 for (uint32_t f : {8000, 16000, 32000, 48000, 90000}) {
philipel3fa49382019-08-20 15:59:57 +0200147 if (std::fabs(estimated_frequency - f) < 0.15 * f) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200148 return f;
149 }
150 }
151 RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Estimate "
152 << estimated_frequency
Philipp Hanckebc07d402022-05-27 18:46:23 +0200153 << " not close to any standard RTP frequency."
154 << " Last timestamp " << last_rtp_timestamp
155 << " first timestamp " << first_rtp_timestamp;
Danil Chapovalov431abd92018-06-18 12:54:17 +0200156 return absl::nullopt;
ivocaac9d6f2016-09-22 07:01:47 -0700157}
158
Danil Chapovalov431abd92018-06-18 12:54:17 +0200159absl::optional<double> NetworkDelayDiff_AbsSendTime(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100160 const LoggedRtpPacketIncoming& old_packet,
161 const LoggedRtpPacketIncoming& new_packet) {
162 if (old_packet.rtp.header.extension.hasAbsoluteSendTime &&
163 new_packet.rtp.header.extension.hasAbsoluteSendTime) {
terelius53dc23c2017-03-13 05:24:05 -0700164 int64_t send_time_diff = WrappingDifference(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100165 new_packet.rtp.header.extension.absoluteSendTime,
166 old_packet.rtp.header.extension.absoluteSendTime, 1ul << 24);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200167 int64_t recv_time_diff =
168 new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 05:24:05 -0700169 double delay_change_us =
170 recv_time_diff - AbsSendTimeToMicroseconds(send_time_diff);
Oskar Sundbom3928dbc2017-11-16 10:53:09 +0100171 return delay_change_us / 1000;
terelius53dc23c2017-03-13 05:24:05 -0700172 } else {
Danil Chapovalov431abd92018-06-18 12:54:17 +0200173 return absl::nullopt;
terelius6addf492016-08-23 17:34:07 -0700174 }
175}
176
Danil Chapovalov431abd92018-06-18 12:54:17 +0200177absl::optional<double> NetworkDelayDiff_CaptureTime(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100178 const LoggedRtpPacketIncoming& old_packet,
179 const LoggedRtpPacketIncoming& new_packet,
180 const double sample_rate) {
181 int64_t send_time_diff =
182 WrappingDifference(new_packet.rtp.header.timestamp,
183 old_packet.rtp.header.timestamp, 1ull << 32);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200184 int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 05:24:05 -0700185
terelius53dc23c2017-03-13 05:24:05 -0700186 double delay_change =
187 static_cast<double>(recv_time_diff) / 1000 -
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100188 static_cast<double>(send_time_diff) / sample_rate * 1000;
terelius53dc23c2017-03-13 05:24:05 -0700189 if (delay_change < -10000 || 10000 < delay_change) {
Mirko Bonadei675513b2017-11-09 11:09:25 +0100190 RTC_LOG(LS_WARNING) << "Very large delay change. Timestamps correct?";
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100191 RTC_LOG(LS_WARNING) << "Old capture time "
192 << old_packet.rtp.header.timestamp << ", received time "
193 << old_packet.log_time_us();
194 RTC_LOG(LS_WARNING) << "New capture time "
195 << new_packet.rtp.header.timestamp << ", received time "
196 << new_packet.log_time_us();
Mirko Bonadei675513b2017-11-09 11:09:25 +0100197 RTC_LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = "
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800198 << static_cast<double>(recv_time_diff) /
199 kNumMicrosecsPerSec
200 << "s";
Mirko Bonadei675513b2017-11-09 11:09:25 +0100201 RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = "
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100202 << static_cast<double>(send_time_diff) / sample_rate
Mirko Bonadei675513b2017-11-09 11:09:25 +0100203 << "s";
terelius53dc23c2017-03-13 05:24:05 -0700204 }
Oskar Sundbom3928dbc2017-11-16 10:53:09 +0100205 return delay_change;
terelius53dc23c2017-03-13 05:24:05 -0700206}
207
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100208template <typename T>
209TimeSeries CreateRtcpTypeTimeSeries(const std::vector<T>& rtcp_list,
210 AnalyzerConfig config,
211 std::string rtcp_name,
212 int category_id) {
213 TimeSeries time_series(rtcp_name, LineStyle::kNone, PointStyle::kHighlight);
214 for (const auto& rtcp : rtcp_list) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000215 float x = config.GetCallTimeSec(rtcp.timestamp);
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100216 float y = category_id;
217 time_series.points.emplace_back(x, y);
218 }
219 return time_series;
220}
221
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800222const char kUnknownEnumValue[] = "unknown";
223
224const char kIceCandidateTypeLocal[] = "local";
225const char kIceCandidateTypeStun[] = "stun";
226const char kIceCandidateTypePrflx[] = "prflx";
227const char kIceCandidateTypeRelay[] = "relay";
228
229const char kProtocolUdp[] = "udp";
230const char kProtocolTcp[] = "tcp";
231const char kProtocolSsltcp[] = "ssltcp";
232const char kProtocolTls[] = "tls";
233
234const char kAddressFamilyIpv4[] = "ipv4";
235const char kAddressFamilyIpv6[] = "ipv6";
236
237const char kNetworkTypeEthernet[] = "ethernet";
238const char kNetworkTypeLoopback[] = "loopback";
239const char kNetworkTypeWifi[] = "wifi";
240const char kNetworkTypeVpn[] = "vpn";
241const char kNetworkTypeCellular[] = "cellular";
242
243std::string GetIceCandidateTypeAsString(webrtc::IceCandidateType type) {
244 switch (type) {
245 case webrtc::IceCandidateType::kLocal:
246 return kIceCandidateTypeLocal;
247 case webrtc::IceCandidateType::kStun:
248 return kIceCandidateTypeStun;
249 case webrtc::IceCandidateType::kPrflx:
250 return kIceCandidateTypePrflx;
251 case webrtc::IceCandidateType::kRelay:
252 return kIceCandidateTypeRelay;
253 default:
254 return kUnknownEnumValue;
255 }
256}
257
258std::string GetProtocolAsString(webrtc::IceCandidatePairProtocol protocol) {
259 switch (protocol) {
260 case webrtc::IceCandidatePairProtocol::kUdp:
261 return kProtocolUdp;
262 case webrtc::IceCandidatePairProtocol::kTcp:
263 return kProtocolTcp;
264 case webrtc::IceCandidatePairProtocol::kSsltcp:
265 return kProtocolSsltcp;
266 case webrtc::IceCandidatePairProtocol::kTls:
267 return kProtocolTls;
268 default:
269 return kUnknownEnumValue;
270 }
271}
272
273std::string GetAddressFamilyAsString(
274 webrtc::IceCandidatePairAddressFamily family) {
275 switch (family) {
276 case webrtc::IceCandidatePairAddressFamily::kIpv4:
277 return kAddressFamilyIpv4;
278 case webrtc::IceCandidatePairAddressFamily::kIpv6:
279 return kAddressFamilyIpv6;
280 default:
281 return kUnknownEnumValue;
282 }
283}
284
285std::string GetNetworkTypeAsString(webrtc::IceCandidateNetworkType type) {
286 switch (type) {
287 case webrtc::IceCandidateNetworkType::kEthernet:
288 return kNetworkTypeEthernet;
289 case webrtc::IceCandidateNetworkType::kLoopback:
290 return kNetworkTypeLoopback;
291 case webrtc::IceCandidateNetworkType::kWifi:
292 return kNetworkTypeWifi;
293 case webrtc::IceCandidateNetworkType::kVpn:
294 return kNetworkTypeVpn;
295 case webrtc::IceCandidateNetworkType::kCellular:
296 return kNetworkTypeCellular;
297 default:
298 return kUnknownEnumValue;
299 }
300}
301
302std::string GetCandidatePairLogDescriptionAsString(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200303 const LoggedIceCandidatePairConfig& config) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800304 // Example: stun:wifi->relay(tcp):cellular@udp:ipv4
305 // represents a pair of a local server-reflexive candidate on a WiFi network
306 // and a remote relay candidate using TCP as the relay protocol on a cell
307 // network, when the candidate pair communicates over UDP using IPv4.
Jonas Olsson366a50c2018-09-06 13:41:30 +0200308 rtc::StringBuilder ss;
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800309 std::string local_candidate_type =
310 GetIceCandidateTypeAsString(config.local_candidate_type);
311 std::string remote_candidate_type =
312 GetIceCandidateTypeAsString(config.remote_candidate_type);
313 if (config.local_candidate_type == webrtc::IceCandidateType::kRelay) {
314 local_candidate_type +=
315 "(" + GetProtocolAsString(config.local_relay_protocol) + ")";
316 }
317 ss << local_candidate_type << ":"
318 << GetNetworkTypeAsString(config.local_network_type) << ":"
319 << GetAddressFamilyAsString(config.local_address_family) << "->"
320 << remote_candidate_type << ":"
321 << GetAddressFamilyAsString(config.remote_address_family) << "@"
322 << GetProtocolAsString(config.candidate_pair_protocol);
Jonas Olsson84df1c72018-09-14 16:59:32 +0200323 return ss.Release();
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800324}
325
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200326std::string GetDirectionAsString(PacketDirection direction) {
327 if (direction == kIncomingPacket) {
328 return "Incoming";
329 } else {
330 return "Outgoing";
331 }
332}
333
334std::string GetDirectionAsShortString(PacketDirection direction) {
335 if (direction == kIncomingPacket) {
336 return "In";
337 } else {
338 return "Out";
339 }
340}
341
terelius54ce6802016-07-13 06:44:41 -0700342} // namespace
343
Sebastian Janssonb290a6d2019-01-03 14:46:23 +0100344EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200345 bool normalize_time)
Bjorn Terelius068fc352019-02-13 22:38:25 +0100346 : parsed_log_(log) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000347 config_.window_duration_ = TimeDelta::Millis(250);
348 config_.step_ = TimeDelta::Millis(10);
349 if (!log.start_log_events().empty()) {
350 config_.rtc_to_utc_offset_ = log.start_log_events()[0].utc_time() -
351 log.start_log_events()[0].log_time();
352 }
Bjorn Terelius068fc352019-02-13 22:38:25 +0100353 config_.normalize_time_ = normalize_time;
354 config_.begin_time_ = parsed_log_.first_timestamp();
355 config_.end_time_ = parsed_log_.last_timestamp();
356 if (config_.end_time_ < config_.begin_time_) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200357 RTC_LOG(LS_WARNING) << "No useful events in the log.";
Björn Tereliuscb241582022-02-25 08:22:38 +0000358 config_.begin_time_ = config_.end_time_ = Timestamp::Zero();
Björn Tereliusff612732018-04-25 14:23:01 +0000359 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200360
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200361 RTC_LOG(LS_INFO) << "Log is "
Björn Tereliuscb241582022-02-25 08:22:38 +0000362 << (parsed_log_.last_timestamp().ms() -
363 parsed_log_.first_timestamp().ms()) /
364 1000
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200365 << " seconds long.";
Bjorn Terelius48b82792020-05-19 10:57:24 +0200366}
367
368EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
369 const AnalyzerConfig& config)
370 : parsed_log_(log), config_(config) {
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200371 RTC_LOG(LS_INFO) << "Log is "
Björn Tereliuscb241582022-02-25 08:22:38 +0000372 << (parsed_log_.last_timestamp().ms() -
373 parsed_log_.first_timestamp().ms()) /
374 1000
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200375 << " seconds long.";
terelius54ce6802016-07-13 06:44:41 -0700376}
377
Sebastian Jansson5c94f552018-10-15 18:46:51 +0200378class BitrateObserver : public RemoteBitrateObserver {
Stefan Holmer13181032016-07-29 14:48:54 +0200379 public:
380 BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {}
381
Sebastian Jansson5c94f552018-10-15 18:46:51 +0200382 void Update(NetworkControlUpdate update) {
383 if (update.target_rate) {
384 last_bitrate_bps_ = update.target_rate->target_rate.bps();
385 bitrate_updated_ = true;
386 }
Stefan Holmer13181032016-07-29 14:48:54 +0200387 }
388
389 void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
390 uint32_t bitrate) override {}
391
392 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
393 bool GetAndResetBitrateUpdated() {
394 bool bitrate_updated = bitrate_updated_;
395 bitrate_updated_ = false;
396 return bitrate_updated;
397 }
398
399 private:
400 uint32_t last_bitrate_bps_;
401 bool bitrate_updated_;
402};
403
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200404void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction,
terelius54ce6802016-07-13 06:44:41 -0700405 Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200406 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
407 // Filter on SSRC.
408 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -0700409 continue;
terelius54ce6802016-07-13 06:44:41 -0700410 }
terelius54ce6802016-07-13 06:44:41 -0700411
Bjorn Terelius48b82792020-05-19 10:57:24 +0200412 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200413 LineStyle::kBar);
414 auto GetPacketSize = [](const LoggedRtpPacket& packet) {
Danil Chapovalov431abd92018-06-18 12:54:17 +0200415 return absl::optional<float>(packet.total_length);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200416 };
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200417 auto ToCallTime = [this](const LoggedRtpPacket& packet) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000418 return this->config_.GetCallTimeSec(packet.timestamp);
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200419 };
420 ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize,
421 stream.packet_view, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700422 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700423 }
424
Bjorn Terelius068fc352019-02-13 22:38:25 +0100425 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
426 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700427 plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin,
428 kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200429 plot->SetTitle(GetDirectionAsString(direction) + " RTP packets");
terelius54ce6802016-07-13 06:44:41 -0700430}
431
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100432void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction,
433 Plot* plot) {
434 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
435 parsed_log_.transport_feedbacks(direction), config_, "TWCC", 1));
436 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
437 parsed_log_.receiver_reports(direction), config_, "RR", 2));
438 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
439 parsed_log_.sender_reports(direction), config_, "SR", 3));
440 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
441 parsed_log_.extended_reports(direction), config_, "XR", 4));
442 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.nacks(direction),
443 config_, "NACK", 5));
444 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.rembs(direction),
445 config_, "REMB", 6));
446 plot->AppendTimeSeries(
447 CreateRtcpTypeTimeSeries(parsed_log_.firs(direction), config_, "FIR", 7));
448 plot->AppendTimeSeries(
449 CreateRtcpTypeTimeSeries(parsed_log_.plis(direction), config_, "PLI", 8));
Björn Terelius4ef56382021-02-03 14:12:24 +0100450 plot->AppendTimeSeries(
451 CreateRtcpTypeTimeSeries(parsed_log_.byes(direction), config_, "BYE", 9));
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100452 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
453 "Time (s)", kLeftMargin, kRightMargin);
454 plot->SetSuggestedYAxis(0, 1, "RTCP type", kBottomMargin, kTopMargin);
455 plot->SetTitle(GetDirectionAsString(direction) + " RTCP packets");
Bjorn Tereliusf640b872019-07-24 15:46:39 +0200456 plot->SetYAxisTickLabels({{1, "TWCC"},
457 {2, "RR"},
458 {3, "SR"},
459 {4, "XR"},
460 {5, "NACK"},
461 {6, "REMB"},
462 {7, "FIR"},
Björn Terelius4ef56382021-02-03 14:12:24 +0100463 {8, "PLI"},
464 {9, "BYE"}});
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100465}
466
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200467template <typename IterableType>
philipelccd74892016-09-05 02:46:25 -0700468void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
philipelccd74892016-09-05 02:46:25 -0700469 Plot* plot,
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200470 const IterableType& packets,
471 const std::string& label) {
472 TimeSeries time_series(label, LineStyle::kStep);
473 for (size_t i = 0; i < packets.size(); i++) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000474 float x = config_.GetCallTimeSec(packets[i].log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200475 time_series.points.emplace_back(x, i + 1);
philipelccd74892016-09-05 02:46:25 -0700476 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200477 plot->AppendTimeSeries(std::move(time_series));
philipelccd74892016-09-05 02:46:25 -0700478}
479
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200480void EventLogAnalyzer::CreateAccumulatedPacketsGraph(PacketDirection direction,
481 Plot* plot) {
482 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
483 if (!MatchingSsrc(stream.ssrc, desired_ssrc_))
484 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200485 std::string label = std::string("RTP ") +
486 GetStreamName(parsed_log_, direction, stream.ssrc);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200487 CreateAccumulatedPacketsTimeSeries(plot, stream.packet_view, label);
488 }
489 std::string label =
490 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")";
491 if (direction == kIncomingPacket) {
492 CreateAccumulatedPacketsTimeSeries(
493 plot, parsed_log_.incoming_rtcp_packets(), label);
494 } else {
495 CreateAccumulatedPacketsTimeSeries(
496 plot, parsed_log_.outgoing_rtcp_packets(), label);
497 }
philipelccd74892016-09-05 02:46:25 -0700498
Bjorn Terelius068fc352019-02-13 22:38:25 +0100499 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
500 "Time (s)", kLeftMargin, kRightMargin);
philipelccd74892016-09-05 02:46:25 -0700501 plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200502 plot->SetTitle(std::string("Accumulated ") + GetDirectionAsString(direction) +
503 " RTP/RTCP packets");
philipelccd74892016-09-05 02:46:25 -0700504}
505
Kristoffer Erlandsson283c1062020-03-30 13:01:37 +0200506void EventLogAnalyzer::CreatePacketRateGraph(PacketDirection direction,
507 Plot* plot) {
508 auto CountPackets = [](auto packet) { return 1.0; };
509 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
510 // Filter on SSRC.
511 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
512 continue;
513 }
514 TimeSeries time_series(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200515 std::string("RTP ") +
516 GetStreamName(parsed_log_, direction, stream.ssrc),
Kristoffer Erlandsson283c1062020-03-30 13:01:37 +0200517 LineStyle::kLine);
518 MovingAverage<LoggedRtpPacket, double>(CountPackets, stream.packet_view,
519 config_, &time_series);
520 plot->AppendTimeSeries(std::move(time_series));
521 }
522 TimeSeries time_series(
523 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")",
524 LineStyle::kLine);
525 if (direction == kIncomingPacket) {
526 MovingAverage<LoggedRtcpPacketIncoming, double>(
527 CountPackets, parsed_log_.incoming_rtcp_packets(), config_,
528 &time_series);
529 } else {
530 MovingAverage<LoggedRtcpPacketOutgoing, double>(
531 CountPackets, parsed_log_.outgoing_rtcp_packets(), config_,
532 &time_series);
533 }
534 plot->AppendTimeSeries(std::move(time_series));
535
536 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
537 "Time (s)", kLeftMargin, kRightMargin);
538 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
539 kTopMargin);
540 plot->SetTitle("Rate of " + GetDirectionAsString(direction) +
541 " RTP/RTCP packets");
542}
543
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200544void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
545 Plot* plot) {
546 // Contains a log timestamp to enable counting logged events of different
547 // types using MovingAverage().
548 class LogTime {
549 public:
Björn Tereliuscb241582022-02-25 08:22:38 +0000550 explicit LogTime(Timestamp log_time) : log_time_(log_time) {}
551 Timestamp log_time() const { return log_time_; }
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200552
553 private:
Björn Tereliuscb241582022-02-25 08:22:38 +0000554 Timestamp log_time_;
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200555 };
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200556 std::vector<LogTime> packet_times;
557 auto handle_rtp = [&](const LoggedRtpPacket& packet) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000558 packet_times.emplace_back(packet.log_time());
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200559 };
560 RtcEventProcessor process;
561 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
562 process.AddEvents(stream.packet_view, handle_rtp);
563 }
564 if (direction == kIncomingPacket) {
565 auto handle_incoming_rtcp = [&](const LoggedRtcpPacketIncoming& packet) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000566 packet_times.emplace_back(packet.log_time());
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200567 };
568 process.AddEvents(parsed_log_.incoming_rtcp_packets(),
569 handle_incoming_rtcp);
570 } else {
571 auto handle_outgoing_rtcp = [&](const LoggedRtcpPacketOutgoing& packet) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000572 packet_times.emplace_back(packet.log_time());
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200573 };
574 process.AddEvents(parsed_log_.outgoing_rtcp_packets(),
575 handle_outgoing_rtcp);
576 }
577 process.ProcessEventsInOrder();
578 TimeSeries time_series(std::string("Total ") + "(" +
579 GetDirectionAsShortString(direction) + ") packets",
580 LineStyle::kLine);
581 MovingAverage<LogTime, uint64_t>([](auto packet) { return 1; }, packet_times,
582 config_, &time_series);
583 plot->AppendTimeSeries(std::move(time_series));
584
585 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
586 "Time (s)", kLeftMargin, kRightMargin);
587 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
588 kTopMargin);
589 plot->SetTitle("Rate of all " + GetDirectionAsString(direction) +
590 " RTP/RTCP packets");
591}
592
terelius54ce6802016-07-13 06:44:41 -0700593// For each SSRC, plot the time between the consecutive playouts.
594void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200595 for (const auto& playout_stream : parsed_log_.audio_playout_events()) {
596 uint32_t ssrc = playout_stream.first;
597 if (!MatchingSsrc(ssrc, desired_ssrc_))
598 continue;
Danil Chapovalov431abd92018-06-18 12:54:17 +0200599 absl::optional<int64_t> last_playout_ms;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200600 TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar);
Minyue Li27e2b7d2018-05-07 15:20:24 +0200601 for (const auto& playout_event : playout_stream.second) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000602 float x = config_.GetCallTimeSec(playout_event.log_time());
Minyue Li27e2b7d2018-05-07 15:20:24 +0200603 int64_t playout_time_ms = playout_event.log_time_ms();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200604 // If there were no previous playouts, place the point on the x-axis.
Minyue Li27e2b7d2018-05-07 15:20:24 +0200605 float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200606 time_series.points.push_back(TimeSeriesPoint(x, y));
Minyue Li27e2b7d2018-05-07 15:20:24 +0200607 last_playout_ms.emplace(playout_time_ms);
terelius54ce6802016-07-13 06:44:41 -0700608 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200609 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700610 }
611
Bjorn Terelius068fc352019-02-13 22:38:25 +0100612 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
613 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700614 plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin,
615 kTopMargin);
616 plot->SetTitle("Audio playout");
terelius54ce6802016-07-13 06:44:41 -0700617}
618
Lionel Koenig6afa92a2023-01-16 11:23:36 +0100619void EventLogAnalyzer::CreateNetEqSetMinimumDelay(Plot* plot) {
620 for (const auto& playout_stream :
621 parsed_log_.neteq_set_minimum_delay_events()) {
622 uint32_t ssrc = playout_stream.first;
623 if (!MatchingSsrc(ssrc, desired_ssrc_))
624 continue;
625
626 TimeSeries time_series(SsrcToString(ssrc), LineStyle::kStep,
627 PointStyle::kHighlight);
628 for (const auto& event : playout_stream.second) {
629 float x = config_.GetCallTimeSec(event.log_time());
630 float y = event.minimum_delay_ms;
631 time_series.points.push_back(TimeSeriesPoint(x, y));
632 }
633 plot->AppendTimeSeries(std::move(time_series));
634 }
635
636 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
637 "Time (s)", kLeftMargin, kRightMargin);
638 plot->SetSuggestedYAxis(0, 1000, "Minimum Delay (ms)", kBottomMargin,
639 kTopMargin);
640 plot->SetTitle("Set Minimum Delay");
641}
642
ivocaac9d6f2016-09-22 07:01:47 -0700643// For audio SSRCs, plot the audio level.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200644void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction,
645 Plot* plot) {
646 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
Bjorn Terelius48b82792020-05-19 10:57:24 +0200647 if (!IsAudioSsrc(parsed_log_, direction, stream.ssrc))
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200648 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200649 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200650 LineStyle::kLine);
651 for (auto& packet : stream.packet_view) {
ivocaac9d6f2016-09-22 07:01:47 -0700652 if (packet.header.extension.hasAudioLevel) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000653 float x = config_.GetCallTimeSec(packet.log_time());
ivocaac9d6f2016-09-22 07:01:47 -0700654 // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
655 // Here we convert it to dBov.
656 float y = static_cast<float>(-packet.header.extension.audioLevel);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200657 time_series.points.emplace_back(TimeSeriesPoint(x, y));
ivocaac9d6f2016-09-22 07:01:47 -0700658 }
659 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200660 plot->AppendTimeSeries(std::move(time_series));
ivocaac9d6f2016-09-22 07:01:47 -0700661 }
662
Bjorn Terelius068fc352019-02-13 22:38:25 +0100663 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
664 "Time (s)", kLeftMargin, kRightMargin);
Yves Gerey665174f2018-06-19 15:03:05 +0200665 plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200666 plot->SetTitle(GetDirectionAsString(direction) + " audio level");
ivocaac9d6f2016-09-22 07:01:47 -0700667}
668
Konrad Hofbauerca3c8012019-02-15 20:52:19 +0100669// For each SSRC, plot the sequence number difference between consecutive
670// incoming packets.
terelius54ce6802016-07-13 06:44:41 -0700671void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200672 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
673 // Filter on SSRC.
674 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -0700675 continue;
terelius54ce6802016-07-13 06:44:41 -0700676 }
terelius54ce6802016-07-13 06:44:41 -0700677
Bjorn Terelius48b82792020-05-19 10:57:24 +0200678 TimeSeries time_series(
679 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
680 LineStyle::kBar);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200681 auto GetSequenceNumberDiff = [](const LoggedRtpPacketIncoming& old_packet,
682 const LoggedRtpPacketIncoming& new_packet) {
683 int64_t diff =
684 WrappingDifference(new_packet.rtp.header.sequenceNumber,
685 old_packet.rtp.header.sequenceNumber, 1ul << 16);
686 return diff;
687 };
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200688 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000689 return this->config_.GetCallTimeSec(packet.log_time());
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200690 };
691 ProcessPairs<LoggedRtpPacketIncoming, float>(
692 ToCallTime, GetSequenceNumberDiff, stream.incoming_packets,
693 &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700694 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700695 }
696
Bjorn Terelius068fc352019-02-13 22:38:25 +0100697 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
698 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700699 plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
700 kTopMargin);
Konrad Hofbauerca3c8012019-02-15 20:52:19 +0100701 plot->SetTitle("Incoming sequence number delta");
terelius54ce6802016-07-13 06:44:41 -0700702}
703
Stefan Holmer99f8e082016-09-09 13:37:50 +0200704void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200705 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
706 const std::vector<LoggedRtpPacketIncoming>& packets =
707 stream.incoming_packets;
708 // Filter on SSRC.
Mirko Bonadei1f173152019-07-25 15:28:14 +0200709 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || packets.empty()) {
Stefan Holmer99f8e082016-09-09 13:37:50 +0200710 continue;
711 }
712
Bjorn Terelius48b82792020-05-19 10:57:24 +0200713 TimeSeries time_series(
714 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
715 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200716 // TODO(terelius): Should the window and step size be read from the class
717 // instead?
Björn Tereliuscb241582022-02-25 08:22:38 +0000718 const TimeDelta kWindow = TimeDelta::Millis(1000);
719 const TimeDelta kStep = TimeDelta::Millis(1000);
Bjorn Terelius2eb31882017-11-30 15:15:25 +0100720 SeqNumUnwrapper<uint16_t> unwrapper_;
721 SeqNumUnwrapper<uint16_t> prior_unwrapper_;
terelius4c9b4af2017-01-30 08:44:51 -0800722 size_t window_index_begin = 0;
723 size_t window_index_end = 0;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200724 uint64_t highest_seq_number =
725 unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
726 uint64_t highest_prior_seq_number =
727 prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
terelius4c9b4af2017-01-30 08:44:51 -0800728
Björn Tereliuscb241582022-02-25 08:22:38 +0000729 for (Timestamp t = config_.begin_time_; t < config_.end_time_ + kStep;
Bjorn Terelius068fc352019-02-13 22:38:25 +0100730 t += kStep) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200731 while (window_index_end < packets.size() &&
Björn Tereliuscb241582022-02-25 08:22:38 +0000732 packets[window_index_end].rtp.log_time() < t) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200733 uint64_t sequence_number = unwrapper_.Unwrap(
734 packets[window_index_end].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 08:44:51 -0800735 highest_seq_number = std::max(highest_seq_number, sequence_number);
736 ++window_index_end;
Stefan Holmer99f8e082016-09-09 13:37:50 +0200737 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200738 while (window_index_begin < packets.size() &&
Björn Tereliuscb241582022-02-25 08:22:38 +0000739 packets[window_index_begin].rtp.log_time() < t - kWindow) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200740 uint64_t sequence_number = prior_unwrapper_.Unwrap(
741 packets[window_index_begin].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 08:44:51 -0800742 highest_prior_seq_number =
743 std::max(highest_prior_seq_number, sequence_number);
744 ++window_index_begin;
745 }
Bjorn Terelius068fc352019-02-13 22:38:25 +0100746 float x = config_.GetCallTimeSec(t);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200747 uint64_t expected_packets = highest_seq_number - highest_prior_seq_number;
terelius4c9b4af2017-01-30 08:44:51 -0800748 if (expected_packets > 0) {
749 int64_t received_packets = window_index_end - window_index_begin;
750 int64_t lost_packets = expected_packets - received_packets;
751 float y = static_cast<float>(lost_packets) / expected_packets * 100;
752 time_series.points.emplace_back(x, y);
753 }
Stefan Holmer99f8e082016-09-09 13:37:50 +0200754 }
philipel35ba9bd2017-04-19 05:58:51 -0700755 plot->AppendTimeSeries(std::move(time_series));
Stefan Holmer99f8e082016-09-09 13:37:50 +0200756 }
757
Bjorn Terelius068fc352019-02-13 22:38:25 +0100758 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
759 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 16:17:28 +0100760 plot->SetSuggestedYAxis(0, 1, "Loss rate (in %)", kBottomMargin, kTopMargin);
761 plot->SetTitle("Incoming packet loss (derived from incoming packets)");
Stefan Holmer99f8e082016-09-09 13:37:50 +0200762}
763
terelius2ee076d2017-08-15 02:04:02 -0700764void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100765 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200766 // Filter on SSRC.
767 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) ||
Bjorn Terelius48b82792020-05-19 10:57:24 +0200768 IsRtxSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
terelius88e64e52016-07-19 01:51:06 -0700769 continue;
770 }
terelius54ce6802016-07-13 06:44:41 -0700771
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100772 const std::vector<LoggedRtpPacketIncoming>& packets =
773 stream.incoming_packets;
774 if (packets.size() < 100) {
775 RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency with "
776 << packets.size() << " packets in the stream.";
777 continue;
778 }
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200779 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100780 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 10:57:24 +0200781 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100782 if (!estimated_frequency)
783 continue;
784 const double frequency_hz = *estimated_frequency;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200785 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc) &&
786 frequency_hz != 90000) {
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100787 RTC_LOG(LS_WARNING)
788 << "Video stream should use a 90 kHz clock but appears to use "
789 << frequency_hz / 1000 << ". Discarding.";
790 continue;
791 }
792
793 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000794 return this->config_.GetCallTimeSec(packet.log_time());
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100795 };
796 auto ToNetworkDelay = [frequency_hz](
797 const LoggedRtpPacketIncoming& old_packet,
798 const LoggedRtpPacketIncoming& new_packet) {
799 return NetworkDelayDiff_CaptureTime(old_packet, new_packet, frequency_hz);
800 };
801
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200802 TimeSeries capture_time_data(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200803 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
804 " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200805 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100806 AccumulatePairs<LoggedRtpPacketIncoming, double>(
807 ToCallTime, ToNetworkDelay, packets, &capture_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700808 plot->AppendTimeSeries(std::move(capture_time_data));
terelius88e64e52016-07-19 01:51:06 -0700809
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200810 TimeSeries send_time_data(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200811 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
812 " abs-send-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200813 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100814 AccumulatePairs<LoggedRtpPacketIncoming, double>(
815 ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data);
816 plot->AppendTimeSeriesIfNotEmpty(std::move(send_time_data));
terelius54ce6802016-07-13 06:44:41 -0700817 }
818
Bjorn Terelius068fc352019-02-13 22:38:25 +0100819 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
820 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauer5be3bbd2019-01-21 12:31:07 +0100821 plot->SetSuggestedYAxis(0, 1, "Delay (ms)", kBottomMargin, kTopMargin);
822 plot->SetTitle("Incoming network delay (relative to first packet)");
terelius54ce6802016-07-13 06:44:41 -0700823}
824
tereliusf736d232016-08-04 10:00:11 -0700825// Plot the fraction of packets lost (as perceived by the loss-based BWE).
826void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +0100827 TimeSeries time_series("Fraction lost", LineStyle::kLine,
828 PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200829 for (auto& bwe_update : parsed_log_.bwe_loss_updates()) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000830 float x = config_.GetCallTimeSec(bwe_update.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200831 float y = static_cast<float>(bwe_update.fraction_lost) / 255 * 100;
philipel35ba9bd2017-04-19 05:58:51 -0700832 time_series.points.emplace_back(x, y);
tereliusf736d232016-08-04 10:00:11 -0700833 }
tereliusf736d232016-08-04 10:00:11 -0700834
Bjorn Terelius19f5be32017-10-18 12:39:49 +0200835 plot->AppendTimeSeries(std::move(time_series));
Bjorn Terelius068fc352019-02-13 22:38:25 +0100836 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
837 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 16:17:28 +0100838 plot->SetSuggestedYAxis(0, 10, "Loss rate (in %)", kBottomMargin, kTopMargin);
839 plot->SetTitle("Outgoing packet loss (as reported by BWE)");
tereliusf736d232016-08-04 10:00:11 -0700840}
841
terelius54ce6802016-07-13 06:44:41 -0700842// Plot the total bandwidth used by all RTP streams.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200843void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
844 // TODO(terelius): This could be provided by the parser.
Björn Tereliuscb241582022-02-25 08:22:38 +0000845 std::multimap<Timestamp, size_t> packets_in_order;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200846 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
847 for (const LoggedRtpPacketIncoming& packet : stream.incoming_packets)
848 packets_in_order.insert(
Björn Tereliuscb241582022-02-25 08:22:38 +0000849 std::make_pair(packet.rtp.log_time(), packet.rtp.total_length));
terelius54ce6802016-07-13 06:44:41 -0700850 }
851
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200852 auto window_begin = packets_in_order.begin();
853 auto window_end = packets_in_order.begin();
terelius54ce6802016-07-13 06:44:41 -0700854 size_t bytes_in_window = 0;
terelius54ce6802016-07-13 06:44:41 -0700855
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800856 if (!packets_in_order.empty()) {
857 // Calculate a moving average of the bitrate and store in a TimeSeries.
858 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
Björn Tereliuscb241582022-02-25 08:22:38 +0000859 for (Timestamp time = config_.begin_time_;
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800860 time < config_.end_time_ + config_.step_; time += config_.step_) {
861 while (window_end != packets_in_order.end() && window_end->first < time) {
862 bytes_in_window += window_end->second;
863 ++window_end;
864 }
865 while (window_begin != packets_in_order.end() &&
866 window_begin->first < time - config_.window_duration_) {
867 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
868 bytes_in_window -= window_begin->second;
869 ++window_begin;
870 }
871 float window_duration_in_seconds =
Björn Tereliuscb241582022-02-25 08:22:38 +0000872 static_cast<float>(config_.window_duration_.us()) /
873 kNumMicrosecsPerSec;
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800874 float x = config_.GetCallTimeSec(time);
875 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
876 bitrate_series.points.emplace_back(x, y);
terelius54ce6802016-07-13 06:44:41 -0700877 }
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800878 plot->AppendTimeSeries(std::move(bitrate_series));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200879 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200880
881 // Overlay the outgoing REMB over incoming bitrate.
882 TimeSeries remb_series("Remb", LineStyle::kStep);
883 for (const auto& rtcp : parsed_log_.rembs(kOutgoingPacket)) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000884 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200885 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
886 remb_series.points.emplace_back(x, y);
887 }
888 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
889
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800890 if (!parsed_log_.generic_packets_received().empty()) {
891 TimeSeries time_series("Incoming generic bitrate", LineStyle::kLine);
892 auto GetPacketSizeKilobits = [](const LoggedGenericPacketReceived& packet) {
893 return packet.packet_length * 8.0 / 1000.0;
894 };
895 MovingAverage<LoggedGenericPacketReceived, double>(
896 GetPacketSizeKilobits, parsed_log_.generic_packets_received(), config_,
897 &time_series);
898 plot->AppendTimeSeries(std::move(time_series));
899 }
900
Bjorn Terelius068fc352019-02-13 22:38:25 +0100901 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
902 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200903 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
904 plot->SetTitle("Incoming RTP bitrate");
905}
906
907// Plot the total bandwidth used by all RTP streams.
Diep Bui38b3cf02022-07-19 14:09:45 +0200908void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(
909 Plot* plot,
910 bool show_detector_state,
911 bool show_alr_state,
912 bool show_link_capacity) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200913 // TODO(terelius): This could be provided by the parser.
Björn Tereliuscb241582022-02-25 08:22:38 +0000914 std::multimap<Timestamp, size_t> packets_in_order;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200915 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
916 for (const LoggedRtpPacketOutgoing& packet : stream.outgoing_packets)
917 packets_in_order.insert(
Björn Tereliuscb241582022-02-25 08:22:38 +0000918 std::make_pair(packet.rtp.log_time(), packet.rtp.total_length));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200919 }
920
921 auto window_begin = packets_in_order.begin();
922 auto window_end = packets_in_order.begin();
923 size_t bytes_in_window = 0;
924
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800925 if (!packets_in_order.empty()) {
926 // Calculate a moving average of the bitrate and store in a TimeSeries.
927 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
Björn Tereliuscb241582022-02-25 08:22:38 +0000928 for (Timestamp time = config_.begin_time_;
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800929 time < config_.end_time_ + config_.step_; time += config_.step_) {
930 while (window_end != packets_in_order.end() && window_end->first < time) {
931 bytes_in_window += window_end->second;
932 ++window_end;
933 }
934 while (window_begin != packets_in_order.end() &&
935 window_begin->first < time - config_.window_duration_) {
936 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
937 bytes_in_window -= window_begin->second;
938 ++window_begin;
939 }
940 float window_duration_in_seconds =
Björn Tereliuscb241582022-02-25 08:22:38 +0000941 static_cast<float>(config_.window_duration_.us()) /
942 kNumMicrosecsPerSec;
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800943 float x = config_.GetCallTimeSec(time);
944 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
945 bitrate_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200946 }
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800947 plot->AppendTimeSeries(std::move(bitrate_series));
terelius54ce6802016-07-13 06:44:41 -0700948 }
949
terelius8058e582016-07-25 01:32:41 -0700950 // Overlay the send-side bandwidth estimate over the outgoing bitrate.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200951 TimeSeries loss_series("Loss-based estimate", LineStyle::kStep);
952 for (auto& loss_update : parsed_log_.bwe_loss_updates()) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000953 float x = config_.GetCallTimeSec(loss_update.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200954 float y = static_cast<float>(loss_update.bitrate_bps) / 1000;
955 loss_series.points.emplace_back(x, y);
956 }
philipel10fc0e62017-04-11 01:50:23 -0700957
Diep Bui38b3cf02022-07-19 14:09:45 +0200958 TimeSeries link_capacity_lower_series("Link-capacity-lower",
959 LineStyle::kStep);
960 TimeSeries link_capacity_upper_series("Link-capacity-upper",
961 LineStyle::kStep);
962 for (auto& remote_estimate_event : parsed_log_.remote_estimate_events()) {
963 float x = config_.GetCallTimeSec(remote_estimate_event.log_time());
964 if (remote_estimate_event.link_capacity_lower.has_value()) {
965 float link_capacity_lower = static_cast<float>(
966 remote_estimate_event.link_capacity_lower.value().kbps());
967 link_capacity_lower_series.points.emplace_back(x, link_capacity_lower);
968 }
969 if (remote_estimate_event.link_capacity_upper.has_value()) {
970 float link_capacity_upper = static_cast<float>(
971 remote_estimate_event.link_capacity_upper.value().kbps());
972 link_capacity_upper_series.points.emplace_back(x, link_capacity_upper);
973 }
974 }
975
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200976 TimeSeries delay_series("Delay-based estimate", LineStyle::kStep);
977 IntervalSeries overusing_series("Overusing", "#ff8e82",
978 IntervalSeries::kHorizontal);
979 IntervalSeries underusing_series("Underusing", "#5092fc",
980 IntervalSeries::kHorizontal);
981 IntervalSeries normal_series("Normal", "#c4ffc4",
982 IntervalSeries::kHorizontal);
983 IntervalSeries* last_series = &normal_series;
Björn Tereliuscb241582022-02-25 08:22:38 +0000984 float last_detector_switch = 0.0;
philipel23c7f252017-07-14 06:30:03 -0700985
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200986 BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal;
philipel23c7f252017-07-14 06:30:03 -0700987
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200988 for (auto& delay_update : parsed_log_.bwe_delay_updates()) {
Björn Tereliuscb241582022-02-25 08:22:38 +0000989 float x = config_.GetCallTimeSec(delay_update.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200990 float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
philipel23c7f252017-07-14 06:30:03 -0700991
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200992 if (last_detector_state != delay_update.detector_state) {
993 last_series->intervals.emplace_back(last_detector_switch, x);
994 last_detector_state = delay_update.detector_state;
995 last_detector_switch = x;
philipel23c7f252017-07-14 06:30:03 -0700996
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200997 switch (delay_update.detector_state) {
998 case BandwidthUsage::kBwNormal:
999 last_series = &normal_series;
1000 break;
1001 case BandwidthUsage::kBwUnderusing:
1002 last_series = &underusing_series;
1003 break;
1004 case BandwidthUsage::kBwOverusing:
1005 last_series = &overusing_series;
1006 break;
1007 case BandwidthUsage::kLast:
Artem Titovd3251962021-11-15 16:57:07 +01001008 RTC_DCHECK_NOTREACHED();
philipele127e7a2017-03-29 16:28:53 +02001009 }
1010 }
philipel23c7f252017-07-14 06:30:03 -07001011
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001012 delay_series.points.emplace_back(x, y);
1013 }
Bjorn Terelius9e336ec2018-04-24 16:28:35 +02001014
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001015 RTC_CHECK(last_series);
Björn Tereliuscb241582022-02-25 08:22:38 +00001016 last_series->intervals.emplace_back(last_detector_switch,
1017 config_.CallEndTimeSec());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001018
1019 TimeSeries created_series("Probe cluster created.", LineStyle::kNone,
1020 PointStyle::kHighlight);
1021 for (auto& cluster : parsed_log_.bwe_probe_cluster_created_events()) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001022 float x = config_.GetCallTimeSec(cluster.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001023 float y = static_cast<float>(cluster.bitrate_bps) / 1000;
1024 created_series.points.emplace_back(x, y);
1025 }
1026
1027 TimeSeries result_series("Probing results.", LineStyle::kNone,
1028 PointStyle::kHighlight);
Bjorn Terelius7a0bb002018-05-29 14:45:53 +02001029 for (auto& result : parsed_log_.bwe_probe_success_events()) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001030 float x = config_.GetCallTimeSec(result.log_time());
Bjorn Terelius7a0bb002018-05-29 14:45:53 +02001031 float y = static_cast<float>(result.bitrate_bps) / 1000;
1032 result_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001033 }
1034
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -08001035 TimeSeries probe_failures_series("Probe failed", LineStyle::kNone,
1036 PointStyle::kHighlight);
1037 for (auto& failure : parsed_log_.bwe_probe_failure_events()) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001038 float x = config_.GetCallTimeSec(failure.log_time());
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -08001039 probe_failures_series.points.emplace_back(x, 0);
1040 }
1041
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001042 IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
1043 bool previously_in_alr = false;
Björn Tereliuscb241582022-02-25 08:22:38 +00001044 Timestamp alr_start = Timestamp::Zero();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001045 for (auto& alr : parsed_log_.alr_state_events()) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001046 float y = config_.GetCallTimeSec(alr.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001047 if (!previously_in_alr && alr.in_alr) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001048 alr_start = alr.log_time();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001049 previously_in_alr = true;
1050 } else if (previously_in_alr && !alr.in_alr) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001051 float x = config_.GetCallTimeSec(alr_start);
Ilya Nikolaevskiya4259f62017-12-05 13:19:45 +01001052 alr_state.intervals.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001053 previously_in_alr = false;
Björn Tereliusff612732018-04-25 14:23:01 +00001054 }
Björn Tereliusff612732018-04-25 14:23:01 +00001055 }
1056
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001057 if (previously_in_alr) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001058 float x = config_.GetCallTimeSec(alr_start);
1059 float y = config_.GetCallTimeSec(config_.end_time_);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001060 alr_state.intervals.emplace_back(x, y);
1061 }
1062
1063 if (show_detector_state) {
1064 plot->AppendIntervalSeries(std::move(overusing_series));
1065 plot->AppendIntervalSeries(std::move(underusing_series));
1066 plot->AppendIntervalSeries(std::move(normal_series));
1067 }
1068
1069 if (show_alr_state) {
1070 plot->AppendIntervalSeries(std::move(alr_state));
1071 }
Diep Bui38b3cf02022-07-19 14:09:45 +02001072
1073 if (show_link_capacity) {
1074 plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_lower_series));
1075 plot->AppendTimeSeriesIfNotEmpty(std::move(link_capacity_upper_series));
1076 }
1077
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001078 plot->AppendTimeSeries(std::move(loss_series));
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -08001079 plot->AppendTimeSeriesIfNotEmpty(std::move(probe_failures_series));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001080 plot->AppendTimeSeries(std::move(delay_series));
1081 plot->AppendTimeSeries(std::move(created_series));
1082 plot->AppendTimeSeries(std::move(result_series));
1083
1084 // Overlay the incoming REMB over the outgoing bitrate.
Björn Tereliusff612732018-04-25 14:23:01 +00001085 TimeSeries remb_series("Remb", LineStyle::kStep);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001086 for (const auto& rtcp : parsed_log_.rembs(kIncomingPacket)) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001087 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001088 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
terelius2c8e8a32017-06-02 01:29:48 -07001089 remb_series.points.emplace_back(x, y);
1090 }
1091 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
1092
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -08001093 if (!parsed_log_.generic_packets_sent().empty()) {
1094 {
1095 TimeSeries time_series("Outgoing generic total bitrate",
1096 LineStyle::kLine);
1097 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1098 return packet.packet_length() * 8.0 / 1000.0;
1099 };
1100 MovingAverage<LoggedGenericPacketSent, double>(
1101 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1102 &time_series);
1103 plot->AppendTimeSeries(std::move(time_series));
1104 }
1105
1106 {
1107 TimeSeries time_series("Outgoing generic payload bitrate",
1108 LineStyle::kLine);
1109 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1110 return packet.payload_length * 8.0 / 1000.0;
1111 };
1112 MovingAverage<LoggedGenericPacketSent, double>(
1113 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1114 &time_series);
1115 plot->AppendTimeSeries(std::move(time_series));
1116 }
1117 }
1118
Bjorn Terelius068fc352019-02-13 22:38:25 +01001119 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1120 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001121 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001122 plot->SetTitle("Outgoing RTP bitrate");
terelius54ce6802016-07-13 06:44:41 -07001123}
1124
1125// For each SSRC, plot the bandwidth used by that stream.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001126void EventLogAnalyzer::CreateStreamBitrateGraph(PacketDirection direction,
1127 Plot* plot) {
1128 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1129 // Filter on SSRC.
1130 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -07001131 continue;
terelius54ce6802016-07-13 06:44:41 -07001132 }
1133
Bjorn Terelius48b82792020-05-19 10:57:24 +02001134 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001135 LineStyle::kLine);
1136 auto GetPacketSizeKilobits = [](const LoggedRtpPacket& packet) {
1137 return packet.total_length * 8.0 / 1000.0;
1138 };
terelius53dc23c2017-03-13 05:24:05 -07001139 MovingAverage<LoggedRtpPacket, double>(
Bjorn Terelius068fc352019-02-13 22:38:25 +01001140 GetPacketSizeKilobits, stream.packet_view, config_, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -07001141 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -07001142 }
1143
Bjorn Terelius068fc352019-02-13 22:38:25 +01001144 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1145 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001146 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001147 plot->SetTitle(GetDirectionAsString(direction) + " bitrate per stream");
terelius54ce6802016-07-13 06:44:41 -07001148}
1149
Bjorn Terelius9775a582019-02-15 17:29:58 +01001150// Plot the bitrate allocation for each temporal and spatial layer.
1151// Computed from RTCP XR target bitrate block, so the graph is only populated if
1152// those are sent.
1153void EventLogAnalyzer::CreateBitrateAllocationGraph(PacketDirection direction,
1154 Plot* plot) {
1155 std::map<LayerDescription, TimeSeries> time_series;
1156 const auto& xr_list = parsed_log_.extended_reports(direction);
1157 for (const auto& rtcp : xr_list) {
1158 const absl::optional<rtcp::TargetBitrate>& target_bitrate =
1159 rtcp.xr.target_bitrate();
1160 if (!target_bitrate.has_value())
1161 continue;
1162 for (const auto& bitrate_item : target_bitrate->GetTargetBitrates()) {
1163 LayerDescription layer(rtcp.xr.sender_ssrc(), bitrate_item.spatial_layer,
1164 bitrate_item.temporal_layer);
1165 auto time_series_it = time_series.find(layer);
1166 if (time_series_it == time_series.end()) {
1167 std::string layer_name = GetLayerName(layer);
1168 bool inserted;
1169 std::tie(time_series_it, inserted) = time_series.insert(
1170 std::make_pair(layer, TimeSeries(layer_name, LineStyle::kStep)));
1171 RTC_DCHECK(inserted);
1172 }
Björn Tereliuscb241582022-02-25 08:22:38 +00001173 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Terelius9775a582019-02-15 17:29:58 +01001174 float y = bitrate_item.target_bitrate_kbps;
1175 time_series_it->second.points.emplace_back(x, y);
1176 }
1177 }
1178 for (auto& layer : time_series) {
1179 plot->AppendTimeSeries(std::move(layer.second));
1180 }
1181 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1182 "Time (s)", kLeftMargin, kRightMargin);
1183 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1184 if (direction == kIncomingPacket)
1185 plot->SetTitle("Target bitrate per incoming layer");
1186 else
1187 plot->SetTitle("Target bitrate per outgoing layer");
1188}
1189
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001190void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) {
1191 TimeSeries target_rates("Simulated target rate", LineStyle::kStep,
1192 PointStyle::kHighlight);
1193 TimeSeries delay_based("Logged delay-based estimate", LineStyle::kStep,
1194 PointStyle::kHighlight);
1195 TimeSeries loss_based("Logged loss-based estimate", LineStyle::kStep,
1196 PointStyle::kHighlight);
1197 TimeSeries probe_results("Logged probe success", LineStyle::kNone,
1198 PointStyle::kHighlight);
1199
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001200 LogBasedNetworkControllerSimulation simulation(
Mirko Bonadei317a1f02019-09-17 17:06:18 +02001201 std::make_unique<GoogCcNetworkControllerFactory>(),
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001202 [&](const NetworkControlUpdate& update, Timestamp at_time) {
1203 if (update.target_rate) {
1204 target_rates.points.emplace_back(
Björn Tereliuscb241582022-02-25 08:22:38 +00001205 config_.GetCallTimeSec(at_time),
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001206 update.target_rate->target_rate.kbps<float>());
1207 }
1208 });
1209
1210 simulation.ProcessEventsInLog(parsed_log_);
1211 for (const auto& logged : parsed_log_.bwe_delay_updates())
Björn Tereliuscb241582022-02-25 08:22:38 +00001212 delay_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
1213 logged.bitrate_bps / 1000);
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001214 for (const auto& logged : parsed_log_.bwe_probe_success_events())
Björn Tereliuscb241582022-02-25 08:22:38 +00001215 probe_results.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
1216 logged.bitrate_bps / 1000);
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001217 for (const auto& logged : parsed_log_.bwe_loss_updates())
Björn Tereliuscb241582022-02-25 08:22:38 +00001218 loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time()),
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001219 logged.bitrate_bps / 1000);
1220
1221 plot->AppendTimeSeries(std::move(delay_based));
1222 plot->AppendTimeSeries(std::move(loss_based));
1223 plot->AppendTimeSeries(std::move(probe_results));
1224 plot->AppendTimeSeries(std::move(target_rates));
1225
1226 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1227 "Time (s)", kLeftMargin, kRightMargin);
1228 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1229 plot->SetTitle("Simulated BWE behavior");
1230}
1231
Bjorn Terelius28db2662017-10-04 14:22:43 +02001232void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001233 using RtpPacketType = LoggedRtpPacketOutgoing;
1234 using TransportFeedbackType = LoggedRtcpPacketTransportFeedback;
Stefan Holmer13181032016-07-29 14:48:54 +02001235
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001236 // TODO(terelius): This could be provided by the parser.
1237 std::multimap<int64_t, const RtpPacketType*> outgoing_rtp;
1238 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1239 for (const RtpPacketType& rtp_packet : stream.outgoing_packets)
1240 outgoing_rtp.insert(
1241 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Stefan Holmer13181032016-07-29 14:48:54 +02001242 }
1243
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001244 const std::vector<TransportFeedbackType>& incoming_rtcp =
1245 parsed_log_.transport_feedbacks(kIncomingPacket);
Stefan Holmer13181032016-07-29 14:48:54 +02001246
1247 SimulatedClock clock(0);
1248 BitrateObserver observer;
Danil Chapovalov83bbe912019-08-07 12:24:53 +02001249 RtcEventLogNull null_event_log;
Sebastian Jansson05acd2b2019-01-21 13:07:47 +01001250 TransportFeedbackAdapter transport_feedback;
Sebastian Jansson2db5fc02019-04-30 14:17:45 +02001251 auto factory = GoogCcNetworkControllerFactory();
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001252 TimeDelta process_interval = factory.GetProcessInterval();
Stefan Holmer13181032016-07-29 14:48:54 +02001253 // TODO(holmer): Log the call config and use that here instead.
1254 static const uint32_t kDefaultStartBitrateBps = 300000;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001255 NetworkControllerConfig cc_config;
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001256 cc_config.constraints.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Danil Chapovalovcad3e0e2020-02-17 18:46:07 +01001257 cc_config.constraints.starting_rate =
1258 DataRate::BitsPerSec(kDefaultStartBitrateBps);
Sebastian Jansson2db5fc02019-04-30 14:17:45 +02001259 cc_config.event_log = &null_event_log;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001260 auto goog_cc = factory.Create(cc_config);
Stefan Holmer13181032016-07-29 14:48:54 +02001261
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001262 TimeSeries time_series("Delay-based estimate", LineStyle::kStep,
1263 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001264 TimeSeries acked_time_series("Raw acked bitrate", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001265 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001266 TimeSeries robust_time_series("Robust throughput estimate", LineStyle::kLine,
1267 PointStyle::kHighlight);
1268 TimeSeries acked_estimate_time_series("Ackednowledged bitrate estimate",
1269 LineStyle::kLine,
1270 PointStyle::kHighlight);
Stefan Holmer13181032016-07-29 14:48:54 +02001271
1272 auto rtp_iterator = outgoing_rtp.begin();
1273 auto rtcp_iterator = incoming_rtcp.begin();
1274
1275 auto NextRtpTime = [&]() {
1276 if (rtp_iterator != outgoing_rtp.end())
1277 return static_cast<int64_t>(rtp_iterator->first);
1278 return std::numeric_limits<int64_t>::max();
1279 };
1280
1281 auto NextRtcpTime = [&]() {
1282 if (rtcp_iterator != incoming_rtcp.end())
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001283 return static_cast<int64_t>(rtcp_iterator->log_time_us());
Stefan Holmer13181032016-07-29 14:48:54 +02001284 return std::numeric_limits<int64_t>::max();
1285 };
Bjorn Tereliusa728c912018-12-06 12:26:30 +01001286 int64_t next_process_time_us_ = std::min({NextRtpTime(), NextRtcpTime()});
Stefan Holmer13181032016-07-29 14:48:54 +02001287
1288 auto NextProcessTime = [&]() {
1289 if (rtcp_iterator != incoming_rtcp.end() ||
1290 rtp_iterator != outgoing_rtp.end()) {
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001291 return next_process_time_us_;
Stefan Holmer13181032016-07-29 14:48:54 +02001292 }
1293 return std::numeric_limits<int64_t>::max();
1294 };
1295
Björn Tereliuseb9af842022-05-05 15:54:49 +02001296 RateStatistics raw_acked_bitrate(750, 8000);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001297 test::ExplicitKeyValueConfig throughput_config(
1298 "WebRTC-Bwe-RobustThroughputEstimatorSettings/"
Björn Tereliuseb9af842022-05-05 15:54:49 +02001299 "enabled:true,required_packets:10,"
1300 "window_packets:25,window_duration:1000ms,unacked_weight:1.0/");
Björn Tereliusae1892d2020-06-17 11:55:55 +02001301 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1302 robust_throughput_estimator(
1303 AcknowledgedBitrateEstimatorInterface::Create(&throughput_config));
1304 FieldTrialBasedConfig field_trial_config;
Björn Terelius251b0dc2019-11-11 21:00:18 +01001305 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1306 acknowledged_bitrate_estimator(
Björn Tereliusae1892d2020-06-17 11:55:55 +02001307 AcknowledgedBitrateEstimatorInterface::Create(&field_trial_config));
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001308 int64_t time_us =
1309 std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
Stefan Holmer492ee282016-10-27 17:19:20 +02001310 int64_t last_update_us = 0;
Stefan Holmer13181032016-07-29 14:48:54 +02001311 while (time_us != std::numeric_limits<int64_t>::max()) {
1312 clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001313 if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1314 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1315 const RtpPacketType& rtp_packet = *rtp_iterator->second;
1316 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
Erik Språng30a276b2019-04-23 12:00:11 +02001317 RtpPacketSendInfo packet_info;
Erik Språng6a0a5592021-06-15 19:04:24 +02001318 packet_info.media_ssrc = rtp_packet.rtp.header.ssrc;
Bjorn Tereliusf2e9cab2019-05-27 16:44:09 +02001319 packet_info.transport_sequence_number =
Erik Språng30a276b2019-04-23 12:00:11 +02001320 rtp_packet.rtp.header.extension.transportSequenceNumber;
1321 packet_info.rtp_sequence_number = rtp_packet.rtp.header.sequenceNumber;
Erik Språng30a276b2019-04-23 12:00:11 +02001322 packet_info.length = rtp_packet.rtp.total_length;
Björn Tereliusae1892d2020-06-17 11:55:55 +02001323 if (IsRtxSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1324 rtp_packet.rtp.header.ssrc)) {
1325 // Don't set the optional media type as we don't know if it is
1326 // a retransmission, FEC or padding.
1327 } else if (IsVideoSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1328 rtp_packet.rtp.header.ssrc)) {
1329 packet_info.packet_type = RtpPacketMediaType::kVideo;
1330 } else if (IsAudioSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1331 rtp_packet.rtp.header.ssrc)) {
1332 packet_info.packet_type = RtpPacketMediaType::kAudio;
1333 }
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001334 transport_feedback.AddPacket(
Erik Språng30a276b2019-04-23 12:00:11 +02001335 packet_info,
1336 0u, // Per packet overhead bytes.
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001337 Timestamp::Micros(rtp_packet.rtp.log_time_us()));
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001338 }
Björn Tereliusae1892d2020-06-17 11:55:55 +02001339 rtc::SentPacket sent_packet;
1340 sent_packet.send_time_ms = rtp_packet.rtp.log_time_ms();
1341 sent_packet.info.included_in_allocation = true;
1342 sent_packet.info.packet_size_bytes = rtp_packet.rtp.total_length;
1343 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
1344 sent_packet.packet_id =
1345 rtp_packet.rtp.header.extension.transportSequenceNumber;
1346 sent_packet.info.included_in_feedback = true;
1347 }
1348 auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet);
1349 if (sent_msg)
1350 observer.Update(goog_cc->OnSentPacket(*sent_msg));
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001351 ++rtp_iterator;
1352 }
Stefan Holmer13181032016-07-29 14:48:54 +02001353 if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
stefanc3de0332016-08-02 07:22:17 -07001354 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001355
1356 auto feedback_msg = transport_feedback.ProcessTransportFeedback(
Sebastian Jansson05acd2b2019-01-21 13:07:47 +01001357 rtcp_iterator->transport_feedback,
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001358 Timestamp::Millis(clock.TimeInMilliseconds()));
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001359 if (feedback_msg) {
1360 observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg));
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001361 std::vector<PacketResult> feedback =
1362 feedback_msg->SortedByReceiveTime();
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001363 if (!feedback.empty()) {
Björn Terelius251b0dc2019-11-11 21:00:18 +01001364 acknowledged_bitrate_estimator->IncomingPacketFeedbackVector(
1365 feedback);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001366 robust_throughput_estimator->IncomingPacketFeedbackVector(feedback);
1367 for (const PacketResult& packet : feedback) {
Björn Tereliuseb9af842022-05-05 15:54:49 +02001368 raw_acked_bitrate.Update(packet.sent_packet.size.bytes(),
1369 packet.receive_time.ms());
Björn Tereliusae1892d2020-06-17 11:55:55 +02001370 }
Björn Tereliuseb9af842022-05-05 15:54:49 +02001371 absl::optional<uint32_t> raw_bitrate_bps =
1372 raw_acked_bitrate.Rate(feedback.back().receive_time.ms());
1373 float x = config_.GetCallTimeSec(clock.CurrentTime());
1374 if (raw_bitrate_bps) {
1375 float y = raw_bitrate_bps.value() / 1000;
1376 acked_time_series.points.emplace_back(x, y);
1377 }
1378 absl::optional<DataRate> robust_estimate =
1379 robust_throughput_estimator->bitrate();
1380 if (robust_estimate) {
1381 float y = robust_estimate.value().kbps();
1382 robust_time_series.points.emplace_back(x, y);
1383 }
1384 absl::optional<DataRate> acked_estimate =
1385 acknowledged_bitrate_estimator->bitrate();
1386 if (acked_estimate) {
1387 float y = acked_estimate.value().kbps();
1388 acked_estimate_time_series.points.emplace_back(x, y);
1389 }
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001390 }
Stefan Holmer13181032016-07-29 14:48:54 +02001391 }
1392 ++rtcp_iterator;
1393 }
stefanc3de0332016-08-02 07:22:17 -07001394 if (clock.TimeInMicroseconds() >= NextProcessTime()) {
1395 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001396 ProcessInterval msg;
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001397 msg.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001398 observer.Update(goog_cc->OnProcessInterval(msg));
1399 next_process_time_us_ += process_interval.us();
stefanc3de0332016-08-02 07:22:17 -07001400 }
Stefan Holmer492ee282016-10-27 17:19:20 +02001401 if (observer.GetAndResetBitrateUpdated() ||
1402 time_us - last_update_us >= 1e6) {
Stefan Holmer13181032016-07-29 14:48:54 +02001403 uint32_t y = observer.last_bitrate_bps() / 1000;
Björn Tereliuscb241582022-02-25 08:22:38 +00001404 float x = config_.GetCallTimeSec(clock.CurrentTime());
Stefan Holmer13181032016-07-29 14:48:54 +02001405 time_series.points.emplace_back(x, y);
Stefan Holmer492ee282016-10-27 17:19:20 +02001406 last_update_us = time_us;
Stefan Holmer13181032016-07-29 14:48:54 +02001407 }
1408 time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
1409 }
1410 // Add the data set to the plot.
philipel35ba9bd2017-04-19 05:58:51 -07001411 plot->AppendTimeSeries(std::move(time_series));
Björn Tereliusae1892d2020-06-17 11:55:55 +02001412 plot->AppendTimeSeries(std::move(robust_time_series));
philipel35ba9bd2017-04-19 05:58:51 -07001413 plot->AppendTimeSeries(std::move(acked_time_series));
Bjorn Terelius6984ad22017-10-24 12:19:45 +02001414 plot->AppendTimeSeriesIfNotEmpty(std::move(acked_estimate_time_series));
Stefan Holmer13181032016-07-29 14:48:54 +02001415
Bjorn Terelius068fc352019-02-13 22:38:25 +01001416 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1417 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001418 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001419 plot->SetTitle("Simulated send-side BWE behavior");
1420}
1421
1422void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001423 using RtpPacketType = LoggedRtpPacketIncoming;
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001424 class RembInterceptor {
Bjorn Terelius28db2662017-10-04 14:22:43 +02001425 public:
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001426 void SendRemb(uint32_t bitrate_bps, std::vector<uint32_t> ssrcs) {
Bjorn Terelius28db2662017-10-04 14:22:43 +02001427 last_bitrate_bps_ = bitrate_bps;
1428 bitrate_updated_ = true;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001429 }
1430 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
1431 bool GetAndResetBitrateUpdated() {
1432 bool bitrate_updated = bitrate_updated_;
1433 bitrate_updated_ = false;
1434 return bitrate_updated;
1435 }
1436
1437 private:
Bjorn Terelius571e1302020-06-09 10:29:09 +02001438 // We don't know the start bitrate, but assume that it is the default 300
1439 // kbps.
1440 uint32_t last_bitrate_bps_ = 300000;
1441 bool bitrate_updated_ = false;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001442 };
1443
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001444 std::multimap<int64_t, const RtpPacketType*> incoming_rtp;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001445
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001446 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Terelius48b82792020-05-19 10:57:24 +02001447 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001448 for (const auto& rtp_packet : stream.incoming_packets)
1449 incoming_rtp.insert(
1450 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Bjorn Terelius28db2662017-10-04 14:22:43 +02001451 }
1452 }
1453
1454 SimulatedClock clock(0);
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001455 RembInterceptor remb_interceptor;
1456 ReceiveSideCongestionController rscc(
1457 &clock, [](auto...) {},
1458 absl::bind_front(&RembInterceptor::SendRemb, &remb_interceptor), nullptr);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001459 // TODO(holmer): Log the call config and use that here instead.
1460 // static const uint32_t kDefaultStartBitrateBps = 300000;
1461 // rscc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
1462
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001463 TimeSeries time_series("Receive side estimate", LineStyle::kLine,
1464 PointStyle::kHighlight);
1465 TimeSeries acked_time_series("Received bitrate", LineStyle::kLine);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001466
1467 RateStatistics acked_bitrate(250, 8000);
1468 int64_t last_update_us = 0;
1469 for (const auto& kv : incoming_rtp) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001470 const RtpPacketType& packet = *kv.second;
1471 int64_t arrival_time_ms = packet.rtp.log_time_us() / 1000;
1472 size_t payload = packet.rtp.total_length; /*Should subtract header?*/
1473 clock.AdvanceTimeMicroseconds(packet.rtp.log_time_us() -
Bjorn Terelius28db2662017-10-04 14:22:43 +02001474 clock.TimeInMicroseconds());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001475 rscc.OnReceivedPacket(arrival_time_ms, payload, packet.rtp.header);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001476 acked_bitrate.Update(payload, arrival_time_ms);
Danil Chapovalov431abd92018-06-18 12:54:17 +02001477 absl::optional<uint32_t> bitrate_bps = acked_bitrate.Rate(arrival_time_ms);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001478 if (bitrate_bps) {
1479 uint32_t y = *bitrate_bps / 1000;
Björn Tereliuscb241582022-02-25 08:22:38 +00001480 float x = config_.GetCallTimeSec(clock.CurrentTime());
Bjorn Terelius28db2662017-10-04 14:22:43 +02001481 acked_time_series.points.emplace_back(x, y);
1482 }
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001483 if (remb_interceptor.GetAndResetBitrateUpdated() ||
Bjorn Terelius28db2662017-10-04 14:22:43 +02001484 clock.TimeInMicroseconds() - last_update_us >= 1e6) {
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001485 uint32_t y = remb_interceptor.last_bitrate_bps() / 1000;
Björn Tereliuscb241582022-02-25 08:22:38 +00001486 float x = config_.GetCallTimeSec(clock.CurrentTime());
Bjorn Terelius28db2662017-10-04 14:22:43 +02001487 time_series.points.emplace_back(x, y);
1488 last_update_us = clock.TimeInMicroseconds();
1489 }
1490 }
1491 // Add the data set to the plot.
1492 plot->AppendTimeSeries(std::move(time_series));
1493 plot->AppendTimeSeries(std::move(acked_time_series));
1494
Bjorn Terelius068fc352019-02-13 22:38:25 +01001495 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1496 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001497 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1498 plot->SetTitle("Simulated receive-side BWE behavior");
Stefan Holmer13181032016-07-29 14:48:54 +02001499}
1500
tereliuse34c19c2016-08-15 08:47:14 -07001501void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001502 TimeSeries time_series("Network delay", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001503 PointStyle::kHighlight);
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001504 int64_t min_send_receive_diff_ms = std::numeric_limits<int64_t>::max();
1505 int64_t min_rtt_ms = std::numeric_limits<int64_t>::max();
stefanc3de0332016-08-02 07:22:17 -07001506
Björn Tereliusc69c1bb2019-10-11 15:06:58 +02001507 std::vector<MatchedSendArrivalTimes> matched_rtp_rtcp =
1508 GetNetworkTrace(parsed_log_);
1509 absl::c_stable_sort(matched_rtp_rtcp, [](const MatchedSendArrivalTimes& a,
1510 const MatchedSendArrivalTimes& b) {
philipel3574d052019-11-18 14:38:13 +01001511 return a.feedback_arrival_time_ms < b.feedback_arrival_time_ms ||
1512 (a.feedback_arrival_time_ms == b.feedback_arrival_time_ms &&
1513 a.arrival_time_ms < b.arrival_time_ms);
Björn Tereliusc69c1bb2019-10-11 15:06:58 +02001514 });
1515 for (const auto& packet : matched_rtp_rtcp) {
Sebastian Jansson74f96ec2019-10-29 12:57:54 +01001516 if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived)
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001517 continue;
Björn Tereliuscb241582022-02-25 08:22:38 +00001518 float x = config_.GetCallTimeSecFromMs(packet.feedback_arrival_time_ms);
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001519 int64_t y = packet.arrival_time_ms - packet.send_time_ms;
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001520 int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms;
1521 min_rtt_ms = std::min(rtt_ms, min_rtt_ms);
1522 min_send_receive_diff_ms = std::min(y, min_send_receive_diff_ms);
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001523 time_series.points.emplace_back(x, y);
stefanc3de0332016-08-02 07:22:17 -07001524 }
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001525
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001526 // We assume that the base network delay (w/o queues) is equal to half
1527 // the minimum RTT. Therefore rescale the delays by subtracting the minimum
Mirko Bonadei604e75c2019-07-25 11:55:47 +02001528 // observed 1-ways delay and add half the minimum RTT.
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001529 const int64_t estimated_clock_offset_ms =
1530 min_send_receive_diff_ms - min_rtt_ms / 2;
stefanc3de0332016-08-02 07:22:17 -07001531 for (TimeSeriesPoint& point : time_series.points)
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001532 point.y -= estimated_clock_offset_ms;
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001533
stefanc3de0332016-08-02 07:22:17 -07001534 // Add the data set to the plot.
stefana0a8ed72017-09-06 02:06:32 -07001535 plot->AppendTimeSeriesIfNotEmpty(std::move(time_series));
stefanc3de0332016-08-02 07:22:17 -07001536
Bjorn Terelius068fc352019-02-13 22:38:25 +01001537 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1538 "Time (s)", kLeftMargin, kRightMargin);
stefanc3de0332016-08-02 07:22:17 -07001539 plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
Konrad Hofbauer5be3bbd2019-01-21 12:31:07 +01001540 plot->SetTitle("Outgoing network delay (based on per-packet feedback)");
stefanc3de0332016-08-02 07:22:17 -07001541}
stefan08383272016-12-20 08:51:52 -08001542
Bjorn Terelius0295a962017-10-25 17:42:41 +02001543void EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001544 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1545 const std::vector<LoggedRtpPacketOutgoing>& packets =
1546 stream.outgoing_packets;
Bjorn Terelius0295a962017-10-25 17:42:41 +02001547
Bjorn Terelius48b82792020-05-19 10:57:24 +02001548 if (IsRtxSsrc(parsed_log_, kOutgoingPacket, stream.ssrc)) {
Konrad Hofbauerbfb735b2019-04-16 11:12:11 +02001549 continue;
1550 }
1551
Bjorn Terelius0295a962017-10-25 17:42:41 +02001552 if (packets.size() < 2) {
Mirko Bonadei675513b2017-11-09 11:09:25 +01001553 RTC_LOG(LS_WARNING)
1554 << "Can't estimate a the RTP clock frequency or the "
1555 "pacer delay with less than 2 packets in the stream";
Bjorn Terelius0295a962017-10-25 17:42:41 +02001556 continue;
1557 }
Björn Terelius0d1b28c2020-05-27 20:25:06 +02001558 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Danil Chapovalov431abd92018-06-18 12:54:17 +02001559 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 10:57:24 +02001560 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001561 if (!estimated_frequency)
1562 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +02001563 if (IsVideoSsrc(parsed_log_, kOutgoingPacket, stream.ssrc) &&
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001564 *estimated_frequency != 90000) {
Mirko Bonadei675513b2017-11-09 11:09:25 +01001565 RTC_LOG(LS_WARNING)
Bjorn Terelius0295a962017-10-25 17:42:41 +02001566 << "Video stream should use a 90 kHz clock but appears to use "
1567 << *estimated_frequency / 1000 << ". Discarding.";
1568 continue;
1569 }
1570
1571 TimeSeries pacer_delay_series(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001572 GetStreamName(parsed_log_, kOutgoingPacket, stream.ssrc) + "(" +
Bjorn Terelius0295a962017-10-25 17:42:41 +02001573 std::to_string(*estimated_frequency / 1000) + " kHz)",
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001574 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001575 SeqNumUnwrapper<uint32_t> timestamp_unwrapper;
1576 uint64_t first_capture_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001577 timestamp_unwrapper.Unwrap(packets.front().rtp.header.timestamp);
1578 uint64_t first_send_timestamp = packets.front().rtp.log_time_us();
1579 for (const auto& packet : packets) {
Bjorn Terelius0295a962017-10-25 17:42:41 +02001580 double capture_time_ms = (static_cast<double>(timestamp_unwrapper.Unwrap(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001581 packet.rtp.header.timestamp)) -
Bjorn Terelius0295a962017-10-25 17:42:41 +02001582 first_capture_timestamp) /
1583 *estimated_frequency * 1000;
1584 double send_time_ms =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001585 static_cast<double>(packet.rtp.log_time_us() - first_send_timestamp) /
1586 1000;
Björn Tereliuscb241582022-02-25 08:22:38 +00001587 float x = config_.GetCallTimeSec(packet.rtp.log_time());
Bjorn Terelius0295a962017-10-25 17:42:41 +02001588 float y = send_time_ms - capture_time_ms;
1589 pacer_delay_series.points.emplace_back(x, y);
1590 }
1591 plot->AppendTimeSeries(std::move(pacer_delay_series));
1592 }
1593
Bjorn Terelius068fc352019-02-13 22:38:25 +01001594 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1595 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001596 plot->SetSuggestedYAxis(0, 10, "Pacer delay (ms)", kBottomMargin, kTopMargin);
1597 plot->SetTitle(
1598 "Delay from capture to send time. (First packet normalized to 0.)");
1599}
1600
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001601void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction,
1602 Plot* plot) {
1603 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1604 TimeSeries rtp_timestamps(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001605 GetStreamName(parsed_log_, direction, stream.ssrc) + " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001606 LineStyle::kLine, PointStyle::kHighlight);
1607 for (const auto& packet : stream.packet_view) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001608 float x = config_.GetCallTimeSec(packet.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001609 float y = packet.header.timestamp;
1610 rtp_timestamps.points.emplace_back(x, y);
stefane372d3c2017-02-02 08:04:18 -08001611 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001612 plot->AppendTimeSeries(std::move(rtp_timestamps));
Björn Tereliusff612732018-04-25 14:23:01 +00001613
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001614 TimeSeries rtcp_timestamps(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001615 GetStreamName(parsed_log_, direction, stream.ssrc) +
1616 " rtcp capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001617 LineStyle::kLine, PointStyle::kHighlight);
1618 // TODO(terelius): Why only sender reports?
1619 const auto& sender_reports = parsed_log_.sender_reports(direction);
1620 for (const auto& rtcp : sender_reports) {
1621 if (rtcp.sr.sender_ssrc() != stream.ssrc)
1622 continue;
Björn Tereliuscb241582022-02-25 08:22:38 +00001623 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001624 float y = rtcp.sr.rtp_timestamp();
1625 rtcp_timestamps.points.emplace_back(x, y);
Björn Tereliusff612732018-04-25 14:23:01 +00001626 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001627 plot->AppendTimeSeriesIfNotEmpty(std::move(rtcp_timestamps));
stefane372d3c2017-02-02 08:04:18 -08001628 }
1629
Bjorn Terelius068fc352019-02-13 22:38:25 +01001630 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1631 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001632 plot->SetSuggestedYAxis(0, 1, "RTP timestamp", kBottomMargin, kTopMargin);
1633 plot->SetTitle(GetDirectionAsString(direction) + " timestamps");
stefane372d3c2017-02-02 08:04:18 -08001634}
michaelt6e5b2192017-02-22 07:33:27 -08001635
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001636void EventLogAnalyzer::CreateSenderAndReceiverReportPlot(
1637 PacketDirection direction,
1638 rtc::FunctionView<float(const rtcp::ReportBlock&)> fy,
1639 std::string title,
1640 std::string yaxis_label,
1641 Plot* plot) {
1642 std::map<uint32_t, TimeSeries> sr_reports_by_ssrc;
1643 const auto& sender_reports = parsed_log_.sender_reports(direction);
1644 for (const auto& rtcp : sender_reports) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001645 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001646 uint32_t ssrc = rtcp.sr.sender_ssrc();
1647 for (const auto& block : rtcp.sr.report_blocks()) {
1648 float y = fy(block);
1649 auto sr_report_it = sr_reports_by_ssrc.find(ssrc);
1650 bool inserted;
1651 if (sr_report_it == sr_reports_by_ssrc.end()) {
1652 std::tie(sr_report_it, inserted) = sr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001653 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1654 " Sender Reports",
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001655 LineStyle::kLine, PointStyle::kHighlight));
1656 }
1657 sr_report_it->second.points.emplace_back(x, y);
1658 }
1659 }
1660 for (auto& kv : sr_reports_by_ssrc) {
1661 plot->AppendTimeSeries(std::move(kv.second));
1662 }
1663
1664 std::map<uint32_t, TimeSeries> rr_reports_by_ssrc;
1665 const auto& receiver_reports = parsed_log_.receiver_reports(direction);
1666 for (const auto& rtcp : receiver_reports) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001667 float x = config_.GetCallTimeSec(rtcp.log_time());
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001668 uint32_t ssrc = rtcp.rr.sender_ssrc();
1669 for (const auto& block : rtcp.rr.report_blocks()) {
1670 float y = fy(block);
1671 auto rr_report_it = rr_reports_by_ssrc.find(ssrc);
1672 bool inserted;
1673 if (rr_report_it == rr_reports_by_ssrc.end()) {
1674 std::tie(rr_report_it, inserted) = rr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001675 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1676 " Receiver Reports",
1677 LineStyle::kLine, PointStyle::kHighlight));
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001678 }
1679 rr_report_it->second.points.emplace_back(x, y);
1680 }
1681 }
1682 for (auto& kv : rr_reports_by_ssrc) {
1683 plot->AppendTimeSeries(std::move(kv.second));
1684 }
1685
Bjorn Terelius068fc352019-02-13 22:38:25 +01001686 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1687 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001688 plot->SetSuggestedYAxis(0, 1, yaxis_label, kBottomMargin, kTopMargin);
1689 plot->SetTitle(title);
1690}
1691
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001692void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) {
1693 std::map<uint32_t, TimeSeries> configs_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001694 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001695 if (configs_by_cp_id.find(config.candidate_pair_id) ==
1696 configs_by_cp_id.end()) {
1697 const std::string candidate_pair_desc =
1698 GetCandidatePairLogDescriptionAsString(config);
Qingsi Wang93a84392018-01-30 17:13:09 -08001699 configs_by_cp_id[config.candidate_pair_id] =
1700 TimeSeries("[" + std::to_string(config.candidate_pair_id) + "]" +
1701 candidate_pair_desc,
1702 LineStyle::kNone, PointStyle::kHighlight);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001703 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1704 candidate_pair_desc;
1705 }
Björn Tereliuscb241582022-02-25 08:22:38 +00001706 float x = config_.GetCallTimeSec(config.log_time());
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001707 float y = static_cast<float>(config.type);
1708 configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y);
1709 }
1710
1711 // TODO(qingsi): There can be a large number of candidate pairs generated by
1712 // certain calls and the frontend cannot render the chart in this case due to
1713 // the failure of generating a palette with the same number of colors.
1714 for (auto& kv : configs_by_cp_id) {
1715 plot->AppendTimeSeries(std::move(kv.second));
1716 }
1717
Bjorn Terelius068fc352019-02-13 22:38:25 +01001718 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1719 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001720 plot->SetSuggestedYAxis(0, 3, "Config Type", kBottomMargin, kTopMargin);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001721 plot->SetTitle("[IceEventLog] ICE candidate pair configs");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001722 plot->SetYAxisTickLabels(
1723 {{static_cast<float>(IceCandidatePairConfigType::kAdded), "ADDED"},
1724 {static_cast<float>(IceCandidatePairConfigType::kUpdated), "UPDATED"},
1725 {static_cast<float>(IceCandidatePairConfigType::kDestroyed),
1726 "DESTROYED"},
1727 {static_cast<float>(IceCandidatePairConfigType::kSelected),
1728 "SELECTED"}});
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001729}
1730
1731std::string EventLogAnalyzer::GetCandidatePairLogDescriptionFromId(
1732 uint32_t candidate_pair_id) {
1733 if (candidate_pair_desc_by_id_.find(candidate_pair_id) !=
1734 candidate_pair_desc_by_id_.end()) {
1735 return candidate_pair_desc_by_id_[candidate_pair_id];
1736 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001737 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001738 // TODO(qingsi): Add the handling of the "Updated" config event after the
1739 // visualization of property change for candidate pairs is introduced.
1740 if (candidate_pair_desc_by_id_.find(config.candidate_pair_id) ==
1741 candidate_pair_desc_by_id_.end()) {
1742 const std::string candidate_pair_desc =
1743 GetCandidatePairLogDescriptionAsString(config);
1744 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1745 candidate_pair_desc;
1746 }
1747 }
1748 return candidate_pair_desc_by_id_[candidate_pair_id];
1749}
1750
1751void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) {
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001752 constexpr int kEventTypeOffset =
1753 static_cast<int>(IceCandidatePairConfigType::kNumValues);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001754 std::map<uint32_t, TimeSeries> checks_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001755 for (const auto& event : parsed_log_.ice_candidate_pair_events()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001756 if (checks_by_cp_id.find(event.candidate_pair_id) ==
1757 checks_by_cp_id.end()) {
1758 checks_by_cp_id[event.candidate_pair_id] = TimeSeries(
Qingsi Wang93a84392018-01-30 17:13:09 -08001759 "[" + std::to_string(event.candidate_pair_id) + "]" +
1760 GetCandidatePairLogDescriptionFromId(event.candidate_pair_id),
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001761 LineStyle::kNone, PointStyle::kHighlight);
1762 }
Björn Tereliuscb241582022-02-25 08:22:38 +00001763 float x = config_.GetCallTimeSec(event.log_time());
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001764 float y = static_cast<float>(event.type) + kEventTypeOffset;
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001765 checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y);
1766 }
1767
1768 // TODO(qingsi): The same issue as in CreateIceCandidatePairConfigGraph.
1769 for (auto& kv : checks_by_cp_id) {
1770 plot->AppendTimeSeries(std::move(kv.second));
1771 }
1772
Bjorn Terelius068fc352019-02-13 22:38:25 +01001773 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1774 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001775 plot->SetSuggestedYAxis(0, 4, "Connectivity State", kBottomMargin,
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001776 kTopMargin);
1777 plot->SetTitle("[IceEventLog] ICE connectivity checks");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001778
1779 plot->SetYAxisTickLabels(
1780 {{static_cast<float>(IceCandidatePairEventType::kCheckSent) +
1781 kEventTypeOffset,
1782 "CHECK SENT"},
1783 {static_cast<float>(IceCandidatePairEventType::kCheckReceived) +
1784 kEventTypeOffset,
1785 "CHECK RECEIVED"},
1786 {static_cast<float>(IceCandidatePairEventType::kCheckResponseSent) +
1787 kEventTypeOffset,
1788 "RESPONSE SENT"},
1789 {static_cast<float>(IceCandidatePairEventType::kCheckResponseReceived) +
1790 kEventTypeOffset,
1791 "RESPONSE RECEIVED"}});
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001792}
1793
Zach Stein10a58012018-12-07 12:26:28 -08001794void EventLogAnalyzer::CreateDtlsTransportStateGraph(Plot* plot) {
1795 TimeSeries states("DTLS Transport State", LineStyle::kNone,
1796 PointStyle::kHighlight);
1797 for (const auto& event : parsed_log_.dtls_transport_states()) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001798 float x = config_.GetCallTimeSec(event.log_time());
Zach Stein10a58012018-12-07 12:26:28 -08001799 float y = static_cast<float>(event.dtls_transport_state);
1800 states.points.emplace_back(x, y);
1801 }
1802 plot->AppendTimeSeries(std::move(states));
Bjorn Terelius068fc352019-02-13 22:38:25 +01001803 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1804 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001805 plot->SetSuggestedYAxis(0, static_cast<float>(DtlsTransportState::kNumValues),
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001806 "Transport State", kBottomMargin, kTopMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001807 plot->SetTitle("DTLS Transport State");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001808 plot->SetYAxisTickLabels(
1809 {{static_cast<float>(DtlsTransportState::kNew), "NEW"},
1810 {static_cast<float>(DtlsTransportState::kConnecting), "CONNECTING"},
1811 {static_cast<float>(DtlsTransportState::kConnected), "CONNECTED"},
1812 {static_cast<float>(DtlsTransportState::kClosed), "CLOSED"},
1813 {static_cast<float>(DtlsTransportState::kFailed), "FAILED"}});
Zach Stein10a58012018-12-07 12:26:28 -08001814}
1815
1816void EventLogAnalyzer::CreateDtlsWritableStateGraph(Plot* plot) {
1817 TimeSeries writable("DTLS Writable", LineStyle::kNone,
1818 PointStyle::kHighlight);
1819 for (const auto& event : parsed_log_.dtls_writable_states()) {
Björn Tereliuscb241582022-02-25 08:22:38 +00001820 float x = config_.GetCallTimeSec(event.log_time());
Zach Stein10a58012018-12-07 12:26:28 -08001821 float y = static_cast<float>(event.writable);
1822 writable.points.emplace_back(x, y);
1823 }
1824 plot->AppendTimeSeries(std::move(writable));
Bjorn Terelius068fc352019-02-13 22:38:25 +01001825 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1826 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001827 plot->SetSuggestedYAxis(0, 1, "Writable", kBottomMargin, kTopMargin);
1828 plot->SetTitle("DTLS Writable State");
1829}
1830
terelius54ce6802016-07-13 06:44:41 -07001831} // namespace webrtc