blob: 0f727f28159d9b702f1ca0f398cd935e61e50cd1 [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"
Erik Språnge7942432019-06-12 13:30:02 +020041#include "modules/pacing/paced_sender.h"
Niels Möllerfd6c0912017-10-31 10:19:10 +010042#include "modules/pacing/packet_router.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020043#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h"
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +020044#include "modules/rtp_rtcp/source/rtcp_packet.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020045#include "modules/rtp_rtcp/source/rtcp_packet/common_header.h"
46#include "modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
47#include "modules/rtp_rtcp/source/rtcp_packet/remb.h"
48#include "modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
49#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
50#include "modules/rtp_rtcp/source/rtp_header_extensions.h"
Tomas Gunnarssonf25761d2020-06-03 22:55:33 +020051#include "modules/rtp_rtcp/source/rtp_rtcp_interface.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020052#include "modules/rtp_rtcp/source/rtp_utility.h"
53#include "rtc_base/checks.h"
54#include "rtc_base/format_macros.h"
55#include "rtc_base/logging.h"
Bjorn Terelius0295a962017-10-25 17:42:41 +020056#include "rtc_base/numerics/sequence_number_util.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020057#include "rtc_base/rate_statistics.h"
Jonas Olsson366a50c2018-09-06 13:41:30 +020058#include "rtc_base/strings/string_builder.h"
Mirko Bonadei575998c2019-07-25 13:57:41 +020059#include "rtc_tools/rtc_event_log_visualizer/log_simulation.h"
Björn Tereliusae1892d2020-06-17 11:55:55 +020060#include "test/explicit_key_value_config.h"
Bjorn Terelius6984ad22017-10-24 12:19:45 +020061
tereliusdc35dcd2016-08-01 12:03:27 -070062namespace webrtc {
tereliusdc35dcd2016-08-01 12:03:27 -070063
terelius54ce6802016-07-13 06:44:41 -070064namespace {
65
66std::string SsrcToString(uint32_t ssrc) {
Jonas Olsson366a50c2018-09-06 13:41:30 +020067 rtc::StringBuilder ss;
terelius54ce6802016-07-13 06:44:41 -070068 ss << "SSRC " << ssrc;
Jonas Olsson84df1c72018-09-14 16:59:32 +020069 return ss.Release();
terelius54ce6802016-07-13 06:44:41 -070070}
71
72// Checks whether an SSRC is contained in the list of desired SSRCs.
73// Note that an empty SSRC list matches every SSRC.
74bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) {
Mirko Bonadei1f173152019-07-25 15:28:14 +020075 if (desired_ssrc.empty())
terelius54ce6802016-07-13 06:44:41 -070076 return true;
77 return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) !=
78 desired_ssrc.end();
79}
80
81double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
82 // The timestamp is a fixed point representation with 6 bits for seconds
83 // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the
Qingsi Wang8eca1ff2018-02-02 11:49:44 -080084 // time in seconds and then multiply by kNumMicrosecsPerSec to convert to
85 // microseconds.
terelius54ce6802016-07-13 06:44:41 -070086 static constexpr double kTimestampToMicroSec =
Qingsi Wang8eca1ff2018-02-02 11:49:44 -080087 static_cast<double>(kNumMicrosecsPerSec) / static_cast<double>(1ul << 18);
terelius54ce6802016-07-13 06:44:41 -070088 return abs_send_time * kTimestampToMicroSec;
89}
90
91// Computes the difference |later| - |earlier| where |later| and |earlier|
92// are counters that wrap at |modulus|. The difference is chosen to have the
93// least absolute value. For example if |modulus| is 8, then the difference will
94// be chosen in the range [-3, 4]. If |modulus| is 9, then the difference will
95// be in [-4, 4].
96int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
97 RTC_DCHECK_LE(1, modulus);
98 RTC_DCHECK_LT(later, modulus);
99 RTC_DCHECK_LT(earlier, modulus);
100 int64_t difference =
101 static_cast<int64_t>(later) - static_cast<int64_t>(earlier);
102 int64_t max_difference = modulus / 2;
103 int64_t min_difference = max_difference - modulus + 1;
104 if (difference > max_difference) {
105 difference -= modulus;
106 }
107 if (difference < min_difference) {
108 difference += modulus;
109 }
terelius6addf492016-08-23 17:34:07 -0700110 if (difference > max_difference / 2 || difference < min_difference / 2) {
Mirko Bonadei675513b2017-11-09 11:09:25 +0100111 RTC_LOG(LS_WARNING) << "Difference between" << later << " and " << earlier
112 << " expected to be in the range ("
113 << min_difference / 2 << "," << max_difference / 2
114 << ") but is " << difference
115 << ". Correct unwrapping is uncertain.";
terelius6addf492016-08-23 17:34:07 -0700116 }
terelius54ce6802016-07-13 06:44:41 -0700117 return difference;
118}
119
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200120// This is much more reliable for outgoing streams than for incoming streams.
121template <typename RtpPacketContainer>
Danil Chapovalov431abd92018-06-18 12:54:17 +0200122absl::optional<uint32_t> EstimateRtpClockFrequency(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200123 const RtpPacketContainer& packets,
124 int64_t end_time_us) {
125 RTC_CHECK(packets.size() >= 2);
126 SeqNumUnwrapper<uint32_t> unwrapper;
Philip Eliasson1f850a62019-03-19 12:15:00 +0000127 int64_t first_rtp_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200128 unwrapper.Unwrap(packets[0].rtp.header.timestamp);
129 int64_t first_log_timestamp = packets[0].log_time_us();
Philip Eliasson1f850a62019-03-19 12:15:00 +0000130 int64_t last_rtp_timestamp = first_rtp_timestamp;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200131 int64_t last_log_timestamp = first_log_timestamp;
132 for (size_t i = 1; i < packets.size(); i++) {
133 if (packets[i].log_time_us() > end_time_us)
134 break;
135 last_rtp_timestamp = unwrapper.Unwrap(packets[i].rtp.header.timestamp);
136 last_log_timestamp = packets[i].log_time_us();
137 }
138 if (last_log_timestamp - first_log_timestamp < kNumMicrosecsPerSec) {
139 RTC_LOG(LS_WARNING)
140 << "Failed to estimate RTP clock frequency: Stream too short. ("
141 << packets.size() << " packets, "
142 << last_log_timestamp - first_log_timestamp << " us)";
Danil Chapovalov431abd92018-06-18 12:54:17 +0200143 return absl::nullopt;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200144 }
145 double duration =
146 static_cast<double>(last_log_timestamp - first_log_timestamp) /
147 kNumMicrosecsPerSec;
148 double estimated_frequency =
149 (last_rtp_timestamp - first_rtp_timestamp) / duration;
150 for (uint32_t f : {8000, 16000, 32000, 48000, 90000}) {
philipel3fa49382019-08-20 15:59:57 +0200151 if (std::fabs(estimated_frequency - f) < 0.15 * f) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200152 return f;
153 }
154 }
155 RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Estimate "
156 << estimated_frequency
philipel3fa49382019-08-20 15:59:57 +0200157 << " not close to any stardard RTP frequency.";
Danil Chapovalov431abd92018-06-18 12:54:17 +0200158 return absl::nullopt;
ivocaac9d6f2016-09-22 07:01:47 -0700159}
160
Danil Chapovalov431abd92018-06-18 12:54:17 +0200161absl::optional<double> NetworkDelayDiff_AbsSendTime(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100162 const LoggedRtpPacketIncoming& old_packet,
163 const LoggedRtpPacketIncoming& new_packet) {
164 if (old_packet.rtp.header.extension.hasAbsoluteSendTime &&
165 new_packet.rtp.header.extension.hasAbsoluteSendTime) {
terelius53dc23c2017-03-13 05:24:05 -0700166 int64_t send_time_diff = WrappingDifference(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100167 new_packet.rtp.header.extension.absoluteSendTime,
168 old_packet.rtp.header.extension.absoluteSendTime, 1ul << 24);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200169 int64_t recv_time_diff =
170 new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 05:24:05 -0700171 double delay_change_us =
172 recv_time_diff - AbsSendTimeToMicroseconds(send_time_diff);
Oskar Sundbom3928dbc2017-11-16 10:53:09 +0100173 return delay_change_us / 1000;
terelius53dc23c2017-03-13 05:24:05 -0700174 } else {
Danil Chapovalov431abd92018-06-18 12:54:17 +0200175 return absl::nullopt;
terelius6addf492016-08-23 17:34:07 -0700176 }
177}
178
Danil Chapovalov431abd92018-06-18 12:54:17 +0200179absl::optional<double> NetworkDelayDiff_CaptureTime(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100180 const LoggedRtpPacketIncoming& old_packet,
181 const LoggedRtpPacketIncoming& new_packet,
182 const double sample_rate) {
183 int64_t send_time_diff =
184 WrappingDifference(new_packet.rtp.header.timestamp,
185 old_packet.rtp.header.timestamp, 1ull << 32);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200186 int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 05:24:05 -0700187
terelius53dc23c2017-03-13 05:24:05 -0700188 double delay_change =
189 static_cast<double>(recv_time_diff) / 1000 -
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100190 static_cast<double>(send_time_diff) / sample_rate * 1000;
terelius53dc23c2017-03-13 05:24:05 -0700191 if (delay_change < -10000 || 10000 < delay_change) {
Mirko Bonadei675513b2017-11-09 11:09:25 +0100192 RTC_LOG(LS_WARNING) << "Very large delay change. Timestamps correct?";
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100193 RTC_LOG(LS_WARNING) << "Old capture time "
194 << old_packet.rtp.header.timestamp << ", received time "
195 << old_packet.log_time_us();
196 RTC_LOG(LS_WARNING) << "New capture time "
197 << new_packet.rtp.header.timestamp << ", received time "
198 << new_packet.log_time_us();
Mirko Bonadei675513b2017-11-09 11:09:25 +0100199 RTC_LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = "
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800200 << static_cast<double>(recv_time_diff) /
201 kNumMicrosecsPerSec
202 << "s";
Mirko Bonadei675513b2017-11-09 11:09:25 +0100203 RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = "
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100204 << static_cast<double>(send_time_diff) / sample_rate
Mirko Bonadei675513b2017-11-09 11:09:25 +0100205 << "s";
terelius53dc23c2017-03-13 05:24:05 -0700206 }
Oskar Sundbom3928dbc2017-11-16 10:53:09 +0100207 return delay_change;
terelius53dc23c2017-03-13 05:24:05 -0700208}
209
terelius6addf492016-08-23 17:34:07 -0700210
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100211template <typename T>
212TimeSeries CreateRtcpTypeTimeSeries(const std::vector<T>& rtcp_list,
213 AnalyzerConfig config,
214 std::string rtcp_name,
215 int category_id) {
216 TimeSeries time_series(rtcp_name, LineStyle::kNone, PointStyle::kHighlight);
217 for (const auto& rtcp : rtcp_list) {
218 float x = config.GetCallTimeSec(rtcp.log_time_us());
219 float y = category_id;
220 time_series.points.emplace_back(x, y);
221 }
222 return time_series;
223}
224
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800225const char kUnknownEnumValue[] = "unknown";
226
227const char kIceCandidateTypeLocal[] = "local";
228const char kIceCandidateTypeStun[] = "stun";
229const char kIceCandidateTypePrflx[] = "prflx";
230const char kIceCandidateTypeRelay[] = "relay";
231
232const char kProtocolUdp[] = "udp";
233const char kProtocolTcp[] = "tcp";
234const char kProtocolSsltcp[] = "ssltcp";
235const char kProtocolTls[] = "tls";
236
237const char kAddressFamilyIpv4[] = "ipv4";
238const char kAddressFamilyIpv6[] = "ipv6";
239
240const char kNetworkTypeEthernet[] = "ethernet";
241const char kNetworkTypeLoopback[] = "loopback";
242const char kNetworkTypeWifi[] = "wifi";
243const char kNetworkTypeVpn[] = "vpn";
244const char kNetworkTypeCellular[] = "cellular";
245
246std::string GetIceCandidateTypeAsString(webrtc::IceCandidateType type) {
247 switch (type) {
248 case webrtc::IceCandidateType::kLocal:
249 return kIceCandidateTypeLocal;
250 case webrtc::IceCandidateType::kStun:
251 return kIceCandidateTypeStun;
252 case webrtc::IceCandidateType::kPrflx:
253 return kIceCandidateTypePrflx;
254 case webrtc::IceCandidateType::kRelay:
255 return kIceCandidateTypeRelay;
256 default:
257 return kUnknownEnumValue;
258 }
259}
260
261std::string GetProtocolAsString(webrtc::IceCandidatePairProtocol protocol) {
262 switch (protocol) {
263 case webrtc::IceCandidatePairProtocol::kUdp:
264 return kProtocolUdp;
265 case webrtc::IceCandidatePairProtocol::kTcp:
266 return kProtocolTcp;
267 case webrtc::IceCandidatePairProtocol::kSsltcp:
268 return kProtocolSsltcp;
269 case webrtc::IceCandidatePairProtocol::kTls:
270 return kProtocolTls;
271 default:
272 return kUnknownEnumValue;
273 }
274}
275
276std::string GetAddressFamilyAsString(
277 webrtc::IceCandidatePairAddressFamily family) {
278 switch (family) {
279 case webrtc::IceCandidatePairAddressFamily::kIpv4:
280 return kAddressFamilyIpv4;
281 case webrtc::IceCandidatePairAddressFamily::kIpv6:
282 return kAddressFamilyIpv6;
283 default:
284 return kUnknownEnumValue;
285 }
286}
287
288std::string GetNetworkTypeAsString(webrtc::IceCandidateNetworkType type) {
289 switch (type) {
290 case webrtc::IceCandidateNetworkType::kEthernet:
291 return kNetworkTypeEthernet;
292 case webrtc::IceCandidateNetworkType::kLoopback:
293 return kNetworkTypeLoopback;
294 case webrtc::IceCandidateNetworkType::kWifi:
295 return kNetworkTypeWifi;
296 case webrtc::IceCandidateNetworkType::kVpn:
297 return kNetworkTypeVpn;
298 case webrtc::IceCandidateNetworkType::kCellular:
299 return kNetworkTypeCellular;
300 default:
301 return kUnknownEnumValue;
302 }
303}
304
305std::string GetCandidatePairLogDescriptionAsString(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200306 const LoggedIceCandidatePairConfig& config) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800307 // Example: stun:wifi->relay(tcp):cellular@udp:ipv4
308 // represents a pair of a local server-reflexive candidate on a WiFi network
309 // and a remote relay candidate using TCP as the relay protocol on a cell
310 // network, when the candidate pair communicates over UDP using IPv4.
Jonas Olsson366a50c2018-09-06 13:41:30 +0200311 rtc::StringBuilder ss;
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800312 std::string local_candidate_type =
313 GetIceCandidateTypeAsString(config.local_candidate_type);
314 std::string remote_candidate_type =
315 GetIceCandidateTypeAsString(config.remote_candidate_type);
316 if (config.local_candidate_type == webrtc::IceCandidateType::kRelay) {
317 local_candidate_type +=
318 "(" + GetProtocolAsString(config.local_relay_protocol) + ")";
319 }
320 ss << local_candidate_type << ":"
321 << GetNetworkTypeAsString(config.local_network_type) << ":"
322 << GetAddressFamilyAsString(config.local_address_family) << "->"
323 << remote_candidate_type << ":"
324 << GetAddressFamilyAsString(config.remote_address_family) << "@"
325 << GetProtocolAsString(config.candidate_pair_protocol);
Jonas Olsson84df1c72018-09-14 16:59:32 +0200326 return ss.Release();
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800327}
328
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200329std::string GetDirectionAsString(PacketDirection direction) {
330 if (direction == kIncomingPacket) {
331 return "Incoming";
332 } else {
333 return "Outgoing";
334 }
335}
336
337std::string GetDirectionAsShortString(PacketDirection direction) {
338 if (direction == kIncomingPacket) {
339 return "In";
340 } else {
341 return "Out";
342 }
343}
344
terelius54ce6802016-07-13 06:44:41 -0700345} // namespace
346
Sebastian Janssonb290a6d2019-01-03 14:46:23 +0100347EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200348 bool normalize_time)
Bjorn Terelius068fc352019-02-13 22:38:25 +0100349 : parsed_log_(log) {
350 config_.window_duration_ = 250000;
351 config_.step_ = 10000;
352 config_.normalize_time_ = normalize_time;
353 config_.begin_time_ = parsed_log_.first_timestamp();
354 config_.end_time_ = parsed_log_.last_timestamp();
355 if (config_.end_time_ < config_.begin_time_) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200356 RTC_LOG(LS_WARNING) << "No useful events in the log.";
Bjorn Terelius068fc352019-02-13 22:38:25 +0100357 config_.begin_time_ = config_.end_time_ = 0;
Björn Tereliusff612732018-04-25 14:23:01 +0000358 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200359
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200360 RTC_LOG(LS_INFO) << "Log is "
361 << (parsed_log_.last_timestamp() -
362 parsed_log_.first_timestamp()) /
363 1000000
364 << " seconds long.";
Bjorn Terelius48b82792020-05-19 10:57:24 +0200365}
366
367EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
368 const AnalyzerConfig& config)
369 : parsed_log_(log), config_(config) {
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200370 RTC_LOG(LS_INFO) << "Log is "
371 << (parsed_log_.last_timestamp() -
372 parsed_log_.first_timestamp()) /
373 1000000
374 << " seconds long.";
terelius54ce6802016-07-13 06:44:41 -0700375}
376
Sebastian Jansson5c94f552018-10-15 18:46:51 +0200377class BitrateObserver : public RemoteBitrateObserver {
Stefan Holmer13181032016-07-29 14:48:54 +0200378 public:
379 BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {}
380
Sebastian Jansson5c94f552018-10-15 18:46:51 +0200381 void Update(NetworkControlUpdate update) {
382 if (update.target_rate) {
383 last_bitrate_bps_ = update.target_rate->target_rate.bps();
384 bitrate_updated_ = true;
385 }
Stefan Holmer13181032016-07-29 14:48:54 +0200386 }
387
388 void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
389 uint32_t bitrate) override {}
390
391 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
392 bool GetAndResetBitrateUpdated() {
393 bool bitrate_updated = bitrate_updated_;
394 bitrate_updated_ = false;
395 return bitrate_updated;
396 }
397
398 private:
399 uint32_t last_bitrate_bps_;
400 bool bitrate_updated_;
401};
402
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200403void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction,
terelius54ce6802016-07-13 06:44:41 -0700404 Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200405 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
406 // Filter on SSRC.
407 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -0700408 continue;
terelius54ce6802016-07-13 06:44:41 -0700409 }
terelius54ce6802016-07-13 06:44:41 -0700410
Bjorn Terelius48b82792020-05-19 10:57:24 +0200411 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200412 LineStyle::kBar);
413 auto GetPacketSize = [](const LoggedRtpPacket& packet) {
Danil Chapovalov431abd92018-06-18 12:54:17 +0200414 return absl::optional<float>(packet.total_length);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200415 };
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200416 auto ToCallTime = [this](const LoggedRtpPacket& packet) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100417 return this->config_.GetCallTimeSec(packet.log_time_us());
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200418 };
419 ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize,
420 stream.packet_view, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700421 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700422 }
423
Bjorn Terelius068fc352019-02-13 22:38:25 +0100424 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
425 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700426 plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin,
427 kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200428 plot->SetTitle(GetDirectionAsString(direction) + " RTP packets");
terelius54ce6802016-07-13 06:44:41 -0700429}
430
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100431void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction,
432 Plot* plot) {
433 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
434 parsed_log_.transport_feedbacks(direction), config_, "TWCC", 1));
435 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
436 parsed_log_.receiver_reports(direction), config_, "RR", 2));
437 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
438 parsed_log_.sender_reports(direction), config_, "SR", 3));
439 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
440 parsed_log_.extended_reports(direction), config_, "XR", 4));
441 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.nacks(direction),
442 config_, "NACK", 5));
443 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.rembs(direction),
444 config_, "REMB", 6));
445 plot->AppendTimeSeries(
446 CreateRtcpTypeTimeSeries(parsed_log_.firs(direction), config_, "FIR", 7));
447 plot->AppendTimeSeries(
448 CreateRtcpTypeTimeSeries(parsed_log_.plis(direction), config_, "PLI", 8));
Björn Terelius4ef56382021-02-03 14:12:24 +0100449 plot->AppendTimeSeries(
450 CreateRtcpTypeTimeSeries(parsed_log_.byes(direction), config_, "BYE", 9));
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100451 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
452 "Time (s)", kLeftMargin, kRightMargin);
453 plot->SetSuggestedYAxis(0, 1, "RTCP type", kBottomMargin, kTopMargin);
454 plot->SetTitle(GetDirectionAsString(direction) + " RTCP packets");
Bjorn Tereliusf640b872019-07-24 15:46:39 +0200455 plot->SetYAxisTickLabels({{1, "TWCC"},
456 {2, "RR"},
457 {3, "SR"},
458 {4, "XR"},
459 {5, "NACK"},
460 {6, "REMB"},
461 {7, "FIR"},
Björn Terelius4ef56382021-02-03 14:12:24 +0100462 {8, "PLI"},
463 {9, "BYE"}});
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100464}
465
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200466template <typename IterableType>
philipelccd74892016-09-05 02:46:25 -0700467void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
philipelccd74892016-09-05 02:46:25 -0700468 Plot* plot,
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200469 const IterableType& packets,
470 const std::string& label) {
471 TimeSeries time_series(label, LineStyle::kStep);
472 for (size_t i = 0; i < packets.size(); i++) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100473 float x = config_.GetCallTimeSec(packets[i].log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200474 time_series.points.emplace_back(x, i + 1);
philipelccd74892016-09-05 02:46:25 -0700475 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200476 plot->AppendTimeSeries(std::move(time_series));
philipelccd74892016-09-05 02:46:25 -0700477}
478
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200479void EventLogAnalyzer::CreateAccumulatedPacketsGraph(PacketDirection direction,
480 Plot* plot) {
481 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
482 if (!MatchingSsrc(stream.ssrc, desired_ssrc_))
483 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200484 std::string label = std::string("RTP ") +
485 GetStreamName(parsed_log_, direction, stream.ssrc);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200486 CreateAccumulatedPacketsTimeSeries(plot, stream.packet_view, label);
487 }
488 std::string label =
489 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")";
490 if (direction == kIncomingPacket) {
491 CreateAccumulatedPacketsTimeSeries(
492 plot, parsed_log_.incoming_rtcp_packets(), label);
493 } else {
494 CreateAccumulatedPacketsTimeSeries(
495 plot, parsed_log_.outgoing_rtcp_packets(), label);
496 }
philipelccd74892016-09-05 02:46:25 -0700497
Bjorn Terelius068fc352019-02-13 22:38:25 +0100498 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
499 "Time (s)", kLeftMargin, kRightMargin);
philipelccd74892016-09-05 02:46:25 -0700500 plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200501 plot->SetTitle(std::string("Accumulated ") + GetDirectionAsString(direction) +
502 " RTP/RTCP packets");
philipelccd74892016-09-05 02:46:25 -0700503}
504
Kristoffer Erlandsson283c1062020-03-30 13:01:37 +0200505void EventLogAnalyzer::CreatePacketRateGraph(PacketDirection direction,
506 Plot* plot) {
507 auto CountPackets = [](auto packet) { return 1.0; };
508 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
509 // Filter on SSRC.
510 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
511 continue;
512 }
513 TimeSeries time_series(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200514 std::string("RTP ") +
515 GetStreamName(parsed_log_, direction, stream.ssrc),
Kristoffer Erlandsson283c1062020-03-30 13:01:37 +0200516 LineStyle::kLine);
517 MovingAverage<LoggedRtpPacket, double>(CountPackets, stream.packet_view,
518 config_, &time_series);
519 plot->AppendTimeSeries(std::move(time_series));
520 }
521 TimeSeries time_series(
522 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")",
523 LineStyle::kLine);
524 if (direction == kIncomingPacket) {
525 MovingAverage<LoggedRtcpPacketIncoming, double>(
526 CountPackets, parsed_log_.incoming_rtcp_packets(), config_,
527 &time_series);
528 } else {
529 MovingAverage<LoggedRtcpPacketOutgoing, double>(
530 CountPackets, parsed_log_.outgoing_rtcp_packets(), config_,
531 &time_series);
532 }
533 plot->AppendTimeSeries(std::move(time_series));
534
535 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
536 "Time (s)", kLeftMargin, kRightMargin);
537 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
538 kTopMargin);
539 plot->SetTitle("Rate of " + GetDirectionAsString(direction) +
540 " RTP/RTCP packets");
541}
542
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200543void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
544 Plot* plot) {
545 // Contains a log timestamp to enable counting logged events of different
546 // types using MovingAverage().
547 class LogTime {
548 public:
549 explicit LogTime(int64_t log_time_us) : log_time_us_(log_time_us) {}
550
551 int64_t log_time_us() const { return log_time_us_; }
552
553 private:
554 int64_t log_time_us_;
555 };
556
557 std::vector<LogTime> packet_times;
558 auto handle_rtp = [&](const LoggedRtpPacket& packet) {
559 packet_times.emplace_back(packet.log_time_us());
560 };
561 RtcEventProcessor process;
562 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
563 process.AddEvents(stream.packet_view, handle_rtp);
564 }
565 if (direction == kIncomingPacket) {
566 auto handle_incoming_rtcp = [&](const LoggedRtcpPacketIncoming& packet) {
567 packet_times.emplace_back(packet.log_time_us());
568 };
569 process.AddEvents(parsed_log_.incoming_rtcp_packets(),
570 handle_incoming_rtcp);
571 } else {
572 auto handle_outgoing_rtcp = [&](const LoggedRtcpPacketOutgoing& packet) {
573 packet_times.emplace_back(packet.log_time_us());
574 };
575 process.AddEvents(parsed_log_.outgoing_rtcp_packets(),
576 handle_outgoing_rtcp);
577 }
578 process.ProcessEventsInOrder();
579 TimeSeries time_series(std::string("Total ") + "(" +
580 GetDirectionAsShortString(direction) + ") packets",
581 LineStyle::kLine);
582 MovingAverage<LogTime, uint64_t>([](auto packet) { return 1; }, packet_times,
583 config_, &time_series);
584 plot->AppendTimeSeries(std::move(time_series));
585
586 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
587 "Time (s)", kLeftMargin, kRightMargin);
588 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
589 kTopMargin);
590 plot->SetTitle("Rate of all " + GetDirectionAsString(direction) +
591 " RTP/RTCP packets");
592}
593
terelius54ce6802016-07-13 06:44:41 -0700594// For each SSRC, plot the time between the consecutive playouts.
595void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200596 for (const auto& playout_stream : parsed_log_.audio_playout_events()) {
597 uint32_t ssrc = playout_stream.first;
598 if (!MatchingSsrc(ssrc, desired_ssrc_))
599 continue;
Danil Chapovalov431abd92018-06-18 12:54:17 +0200600 absl::optional<int64_t> last_playout_ms;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200601 TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar);
Minyue Li27e2b7d2018-05-07 15:20:24 +0200602 for (const auto& playout_event : playout_stream.second) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100603 float x = config_.GetCallTimeSec(playout_event.log_time_us());
Minyue Li27e2b7d2018-05-07 15:20:24 +0200604 int64_t playout_time_ms = playout_event.log_time_ms();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200605 // If there were no previous playouts, place the point on the x-axis.
Minyue Li27e2b7d2018-05-07 15:20:24 +0200606 float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200607 time_series.points.push_back(TimeSeriesPoint(x, y));
Minyue Li27e2b7d2018-05-07 15:20:24 +0200608 last_playout_ms.emplace(playout_time_ms);
terelius54ce6802016-07-13 06:44:41 -0700609 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200610 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700611 }
612
Bjorn Terelius068fc352019-02-13 22:38:25 +0100613 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
614 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700615 plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin,
616 kTopMargin);
617 plot->SetTitle("Audio playout");
terelius54ce6802016-07-13 06:44:41 -0700618}
619
ivocaac9d6f2016-09-22 07:01:47 -0700620// For audio SSRCs, plot the audio level.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200621void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction,
622 Plot* plot) {
623 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
Bjorn Terelius48b82792020-05-19 10:57:24 +0200624 if (!IsAudioSsrc(parsed_log_, direction, stream.ssrc))
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200625 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200626 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200627 LineStyle::kLine);
628 for (auto& packet : stream.packet_view) {
ivocaac9d6f2016-09-22 07:01:47 -0700629 if (packet.header.extension.hasAudioLevel) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100630 float x = config_.GetCallTimeSec(packet.log_time_us());
ivocaac9d6f2016-09-22 07:01:47 -0700631 // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
632 // Here we convert it to dBov.
633 float y = static_cast<float>(-packet.header.extension.audioLevel);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200634 time_series.points.emplace_back(TimeSeriesPoint(x, y));
ivocaac9d6f2016-09-22 07:01:47 -0700635 }
636 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200637 plot->AppendTimeSeries(std::move(time_series));
ivocaac9d6f2016-09-22 07:01:47 -0700638 }
639
Bjorn Terelius068fc352019-02-13 22:38:25 +0100640 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
641 "Time (s)", kLeftMargin, kRightMargin);
Yves Gerey665174f2018-06-19 15:03:05 +0200642 plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200643 plot->SetTitle(GetDirectionAsString(direction) + " audio level");
ivocaac9d6f2016-09-22 07:01:47 -0700644}
645
Konrad Hofbauerca3c8012019-02-15 20:52:19 +0100646// For each SSRC, plot the sequence number difference between consecutive
647// incoming packets.
terelius54ce6802016-07-13 06:44:41 -0700648void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200649 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
650 // Filter on SSRC.
651 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -0700652 continue;
terelius54ce6802016-07-13 06:44:41 -0700653 }
terelius54ce6802016-07-13 06:44:41 -0700654
Bjorn Terelius48b82792020-05-19 10:57:24 +0200655 TimeSeries time_series(
656 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
657 LineStyle::kBar);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200658 auto GetSequenceNumberDiff = [](const LoggedRtpPacketIncoming& old_packet,
659 const LoggedRtpPacketIncoming& new_packet) {
660 int64_t diff =
661 WrappingDifference(new_packet.rtp.header.sequenceNumber,
662 old_packet.rtp.header.sequenceNumber, 1ul << 16);
663 return diff;
664 };
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200665 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100666 return this->config_.GetCallTimeSec(packet.log_time_us());
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200667 };
668 ProcessPairs<LoggedRtpPacketIncoming, float>(
669 ToCallTime, GetSequenceNumberDiff, stream.incoming_packets,
670 &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700671 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700672 }
673
Bjorn Terelius068fc352019-02-13 22:38:25 +0100674 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
675 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700676 plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
677 kTopMargin);
Konrad Hofbauerca3c8012019-02-15 20:52:19 +0100678 plot->SetTitle("Incoming sequence number delta");
terelius54ce6802016-07-13 06:44:41 -0700679}
680
Stefan Holmer99f8e082016-09-09 13:37:50 +0200681void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200682 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
683 const std::vector<LoggedRtpPacketIncoming>& packets =
684 stream.incoming_packets;
685 // Filter on SSRC.
Mirko Bonadei1f173152019-07-25 15:28:14 +0200686 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || packets.empty()) {
Stefan Holmer99f8e082016-09-09 13:37:50 +0200687 continue;
688 }
689
Bjorn Terelius48b82792020-05-19 10:57:24 +0200690 TimeSeries time_series(
691 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
692 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200693 // TODO(terelius): Should the window and step size be read from the class
694 // instead?
695 const int64_t kWindowUs = 1000000;
696 const int64_t kStep = 1000000;
Bjorn Terelius2eb31882017-11-30 15:15:25 +0100697 SeqNumUnwrapper<uint16_t> unwrapper_;
698 SeqNumUnwrapper<uint16_t> prior_unwrapper_;
terelius4c9b4af2017-01-30 08:44:51 -0800699 size_t window_index_begin = 0;
700 size_t window_index_end = 0;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200701 uint64_t highest_seq_number =
702 unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
703 uint64_t highest_prior_seq_number =
704 prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
terelius4c9b4af2017-01-30 08:44:51 -0800705
Bjorn Terelius068fc352019-02-13 22:38:25 +0100706 for (int64_t t = config_.begin_time_; t < config_.end_time_ + kStep;
707 t += kStep) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200708 while (window_index_end < packets.size() &&
709 packets[window_index_end].rtp.log_time_us() < t) {
710 uint64_t sequence_number = unwrapper_.Unwrap(
711 packets[window_index_end].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 08:44:51 -0800712 highest_seq_number = std::max(highest_seq_number, sequence_number);
713 ++window_index_end;
Stefan Holmer99f8e082016-09-09 13:37:50 +0200714 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200715 while (window_index_begin < packets.size() &&
716 packets[window_index_begin].rtp.log_time_us() < t - kWindowUs) {
717 uint64_t sequence_number = prior_unwrapper_.Unwrap(
718 packets[window_index_begin].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 08:44:51 -0800719 highest_prior_seq_number =
720 std::max(highest_prior_seq_number, sequence_number);
721 ++window_index_begin;
722 }
Bjorn Terelius068fc352019-02-13 22:38:25 +0100723 float x = config_.GetCallTimeSec(t);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200724 uint64_t expected_packets = highest_seq_number - highest_prior_seq_number;
terelius4c9b4af2017-01-30 08:44:51 -0800725 if (expected_packets > 0) {
726 int64_t received_packets = window_index_end - window_index_begin;
727 int64_t lost_packets = expected_packets - received_packets;
728 float y = static_cast<float>(lost_packets) / expected_packets * 100;
729 time_series.points.emplace_back(x, y);
730 }
Stefan Holmer99f8e082016-09-09 13:37:50 +0200731 }
philipel35ba9bd2017-04-19 05:58:51 -0700732 plot->AppendTimeSeries(std::move(time_series));
Stefan Holmer99f8e082016-09-09 13:37:50 +0200733 }
734
Bjorn Terelius068fc352019-02-13 22:38:25 +0100735 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
736 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 16:17:28 +0100737 plot->SetSuggestedYAxis(0, 1, "Loss rate (in %)", kBottomMargin, kTopMargin);
738 plot->SetTitle("Incoming packet loss (derived from incoming packets)");
Stefan Holmer99f8e082016-09-09 13:37:50 +0200739}
740
terelius2ee076d2017-08-15 02:04:02 -0700741void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100742 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200743 // Filter on SSRC.
744 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) ||
Bjorn Terelius48b82792020-05-19 10:57:24 +0200745 IsRtxSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
terelius88e64e52016-07-19 01:51:06 -0700746 continue;
747 }
terelius54ce6802016-07-13 06:44:41 -0700748
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100749 const std::vector<LoggedRtpPacketIncoming>& packets =
750 stream.incoming_packets;
751 if (packets.size() < 100) {
752 RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency with "
753 << packets.size() << " packets in the stream.";
754 continue;
755 }
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200756 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100757 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 10:57:24 +0200758 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100759 if (!estimated_frequency)
760 continue;
761 const double frequency_hz = *estimated_frequency;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200762 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc) &&
763 frequency_hz != 90000) {
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100764 RTC_LOG(LS_WARNING)
765 << "Video stream should use a 90 kHz clock but appears to use "
766 << frequency_hz / 1000 << ". Discarding.";
767 continue;
768 }
769
770 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100771 return this->config_.GetCallTimeSec(packet.log_time_us());
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100772 };
773 auto ToNetworkDelay = [frequency_hz](
774 const LoggedRtpPacketIncoming& old_packet,
775 const LoggedRtpPacketIncoming& new_packet) {
776 return NetworkDelayDiff_CaptureTime(old_packet, new_packet, frequency_hz);
777 };
778
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200779 TimeSeries capture_time_data(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200780 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
781 " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200782 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100783 AccumulatePairs<LoggedRtpPacketIncoming, double>(
784 ToCallTime, ToNetworkDelay, packets, &capture_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700785 plot->AppendTimeSeries(std::move(capture_time_data));
terelius88e64e52016-07-19 01:51:06 -0700786
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200787 TimeSeries send_time_data(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200788 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
789 " abs-send-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200790 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100791 AccumulatePairs<LoggedRtpPacketIncoming, double>(
792 ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data);
793 plot->AppendTimeSeriesIfNotEmpty(std::move(send_time_data));
terelius54ce6802016-07-13 06:44:41 -0700794 }
795
Bjorn Terelius068fc352019-02-13 22:38:25 +0100796 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
797 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauer5be3bbd2019-01-21 12:31:07 +0100798 plot->SetSuggestedYAxis(0, 1, "Delay (ms)", kBottomMargin, kTopMargin);
799 plot->SetTitle("Incoming network delay (relative to first packet)");
terelius54ce6802016-07-13 06:44:41 -0700800}
801
tereliusf736d232016-08-04 10:00:11 -0700802// Plot the fraction of packets lost (as perceived by the loss-based BWE).
803void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +0100804 TimeSeries time_series("Fraction lost", LineStyle::kLine,
805 PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200806 for (auto& bwe_update : parsed_log_.bwe_loss_updates()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100807 float x = config_.GetCallTimeSec(bwe_update.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200808 float y = static_cast<float>(bwe_update.fraction_lost) / 255 * 100;
philipel35ba9bd2017-04-19 05:58:51 -0700809 time_series.points.emplace_back(x, y);
tereliusf736d232016-08-04 10:00:11 -0700810 }
tereliusf736d232016-08-04 10:00:11 -0700811
Bjorn Terelius19f5be32017-10-18 12:39:49 +0200812 plot->AppendTimeSeries(std::move(time_series));
Bjorn Terelius068fc352019-02-13 22:38:25 +0100813 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
814 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 16:17:28 +0100815 plot->SetSuggestedYAxis(0, 10, "Loss rate (in %)", kBottomMargin, kTopMargin);
816 plot->SetTitle("Outgoing packet loss (as reported by BWE)");
tereliusf736d232016-08-04 10:00:11 -0700817}
818
terelius54ce6802016-07-13 06:44:41 -0700819// Plot the total bandwidth used by all RTP streams.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200820void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
821 // TODO(terelius): This could be provided by the parser.
822 std::multimap<int64_t, size_t> packets_in_order;
823 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
824 for (const LoggedRtpPacketIncoming& packet : stream.incoming_packets)
825 packets_in_order.insert(
826 std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
terelius54ce6802016-07-13 06:44:41 -0700827 }
828
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200829 auto window_begin = packets_in_order.begin();
830 auto window_end = packets_in_order.begin();
terelius54ce6802016-07-13 06:44:41 -0700831 size_t bytes_in_window = 0;
terelius54ce6802016-07-13 06:44:41 -0700832
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800833 if (!packets_in_order.empty()) {
834 // Calculate a moving average of the bitrate and store in a TimeSeries.
835 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
836 for (int64_t time = config_.begin_time_;
837 time < config_.end_time_ + config_.step_; time += config_.step_) {
838 while (window_end != packets_in_order.end() && window_end->first < time) {
839 bytes_in_window += window_end->second;
840 ++window_end;
841 }
842 while (window_begin != packets_in_order.end() &&
843 window_begin->first < time - config_.window_duration_) {
844 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
845 bytes_in_window -= window_begin->second;
846 ++window_begin;
847 }
848 float window_duration_in_seconds =
849 static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
850 float x = config_.GetCallTimeSec(time);
851 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
852 bitrate_series.points.emplace_back(x, y);
terelius54ce6802016-07-13 06:44:41 -0700853 }
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800854 plot->AppendTimeSeries(std::move(bitrate_series));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200855 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200856
857 // Overlay the outgoing REMB over incoming bitrate.
858 TimeSeries remb_series("Remb", LineStyle::kStep);
859 for (const auto& rtcp : parsed_log_.rembs(kOutgoingPacket)) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100860 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200861 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
862 remb_series.points.emplace_back(x, y);
863 }
864 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
865
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800866 if (!parsed_log_.generic_packets_received().empty()) {
867 TimeSeries time_series("Incoming generic bitrate", LineStyle::kLine);
868 auto GetPacketSizeKilobits = [](const LoggedGenericPacketReceived& packet) {
869 return packet.packet_length * 8.0 / 1000.0;
870 };
871 MovingAverage<LoggedGenericPacketReceived, double>(
872 GetPacketSizeKilobits, parsed_log_.generic_packets_received(), config_,
873 &time_series);
874 plot->AppendTimeSeries(std::move(time_series));
875 }
876
Bjorn Terelius068fc352019-02-13 22:38:25 +0100877 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
878 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200879 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
880 plot->SetTitle("Incoming RTP bitrate");
881}
882
883// Plot the total bandwidth used by all RTP streams.
884void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
885 bool show_detector_state,
886 bool show_alr_state) {
887 // TODO(terelius): This could be provided by the parser.
888 std::multimap<int64_t, size_t> packets_in_order;
889 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
890 for (const LoggedRtpPacketOutgoing& packet : stream.outgoing_packets)
891 packets_in_order.insert(
892 std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
893 }
894
895 auto window_begin = packets_in_order.begin();
896 auto window_end = packets_in_order.begin();
897 size_t bytes_in_window = 0;
898
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800899 if (!packets_in_order.empty()) {
900 // Calculate a moving average of the bitrate and store in a TimeSeries.
901 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
902 for (int64_t time = config_.begin_time_;
903 time < config_.end_time_ + config_.step_; time += config_.step_) {
904 while (window_end != packets_in_order.end() && window_end->first < time) {
905 bytes_in_window += window_end->second;
906 ++window_end;
907 }
908 while (window_begin != packets_in_order.end() &&
909 window_begin->first < time - config_.window_duration_) {
910 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
911 bytes_in_window -= window_begin->second;
912 ++window_begin;
913 }
914 float window_duration_in_seconds =
915 static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
916 float x = config_.GetCallTimeSec(time);
917 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
918 bitrate_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200919 }
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800920 plot->AppendTimeSeries(std::move(bitrate_series));
terelius54ce6802016-07-13 06:44:41 -0700921 }
922
terelius8058e582016-07-25 01:32:41 -0700923 // Overlay the send-side bandwidth estimate over the outgoing bitrate.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200924 TimeSeries loss_series("Loss-based estimate", LineStyle::kStep);
925 for (auto& loss_update : parsed_log_.bwe_loss_updates()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100926 float x = config_.GetCallTimeSec(loss_update.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200927 float y = static_cast<float>(loss_update.bitrate_bps) / 1000;
928 loss_series.points.emplace_back(x, y);
929 }
philipel10fc0e62017-04-11 01:50:23 -0700930
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200931 TimeSeries delay_series("Delay-based estimate", LineStyle::kStep);
932 IntervalSeries overusing_series("Overusing", "#ff8e82",
933 IntervalSeries::kHorizontal);
934 IntervalSeries underusing_series("Underusing", "#5092fc",
935 IntervalSeries::kHorizontal);
936 IntervalSeries normal_series("Normal", "#c4ffc4",
937 IntervalSeries::kHorizontal);
938 IntervalSeries* last_series = &normal_series;
939 double last_detector_switch = 0.0;
philipel23c7f252017-07-14 06:30:03 -0700940
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200941 BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal;
philipel23c7f252017-07-14 06:30:03 -0700942
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200943 for (auto& delay_update : parsed_log_.bwe_delay_updates()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100944 float x = config_.GetCallTimeSec(delay_update.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200945 float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
philipel23c7f252017-07-14 06:30:03 -0700946
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200947 if (last_detector_state != delay_update.detector_state) {
948 last_series->intervals.emplace_back(last_detector_switch, x);
949 last_detector_state = delay_update.detector_state;
950 last_detector_switch = x;
philipel23c7f252017-07-14 06:30:03 -0700951
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200952 switch (delay_update.detector_state) {
953 case BandwidthUsage::kBwNormal:
954 last_series = &normal_series;
955 break;
956 case BandwidthUsage::kBwUnderusing:
957 last_series = &underusing_series;
958 break;
959 case BandwidthUsage::kBwOverusing:
960 last_series = &overusing_series;
961 break;
962 case BandwidthUsage::kLast:
963 RTC_NOTREACHED();
philipele127e7a2017-03-29 16:28:53 +0200964 }
965 }
philipel23c7f252017-07-14 06:30:03 -0700966
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200967 delay_series.points.emplace_back(x, y);
968 }
Bjorn Terelius9e336ec2018-04-24 16:28:35 +0200969
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200970 RTC_CHECK(last_series);
Bjorn Terelius068fc352019-02-13 22:38:25 +0100971 last_series->intervals.emplace_back(last_detector_switch, config_.end_time_);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200972
973 TimeSeries created_series("Probe cluster created.", LineStyle::kNone,
974 PointStyle::kHighlight);
975 for (auto& cluster : parsed_log_.bwe_probe_cluster_created_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100976 float x = config_.GetCallTimeSec(cluster.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200977 float y = static_cast<float>(cluster.bitrate_bps) / 1000;
978 created_series.points.emplace_back(x, y);
979 }
980
981 TimeSeries result_series("Probing results.", LineStyle::kNone,
982 PointStyle::kHighlight);
Bjorn Terelius7a0bb002018-05-29 14:45:53 +0200983 for (auto& result : parsed_log_.bwe_probe_success_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100984 float x = config_.GetCallTimeSec(result.log_time_us());
Bjorn Terelius7a0bb002018-05-29 14:45:53 +0200985 float y = static_cast<float>(result.bitrate_bps) / 1000;
986 result_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200987 }
988
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -0800989 TimeSeries probe_failures_series("Probe failed", LineStyle::kNone,
990 PointStyle::kHighlight);
991 for (auto& failure : parsed_log_.bwe_probe_failure_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100992 float x = config_.GetCallTimeSec(failure.log_time_us());
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -0800993 probe_failures_series.points.emplace_back(x, 0);
994 }
995
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200996 IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
997 bool previously_in_alr = false;
998 int64_t alr_start = 0;
999 for (auto& alr : parsed_log_.alr_state_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001000 float y = config_.GetCallTimeSec(alr.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001001 if (!previously_in_alr && alr.in_alr) {
1002 alr_start = alr.log_time_us();
1003 previously_in_alr = true;
1004 } else if (previously_in_alr && !alr.in_alr) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001005 float x = config_.GetCallTimeSec(alr_start);
Ilya Nikolaevskiya4259f62017-12-05 13:19:45 +01001006 alr_state.intervals.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001007 previously_in_alr = false;
Björn Tereliusff612732018-04-25 14:23:01 +00001008 }
Björn Tereliusff612732018-04-25 14:23:01 +00001009 }
1010
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001011 if (previously_in_alr) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001012 float x = config_.GetCallTimeSec(alr_start);
1013 float y = config_.GetCallTimeSec(config_.end_time_);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001014 alr_state.intervals.emplace_back(x, y);
1015 }
1016
1017 if (show_detector_state) {
1018 plot->AppendIntervalSeries(std::move(overusing_series));
1019 plot->AppendIntervalSeries(std::move(underusing_series));
1020 plot->AppendIntervalSeries(std::move(normal_series));
1021 }
1022
1023 if (show_alr_state) {
1024 plot->AppendIntervalSeries(std::move(alr_state));
1025 }
1026 plot->AppendTimeSeries(std::move(loss_series));
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -08001027 plot->AppendTimeSeriesIfNotEmpty(std::move(probe_failures_series));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001028 plot->AppendTimeSeries(std::move(delay_series));
1029 plot->AppendTimeSeries(std::move(created_series));
1030 plot->AppendTimeSeries(std::move(result_series));
1031
1032 // Overlay the incoming REMB over the outgoing bitrate.
Björn Tereliusff612732018-04-25 14:23:01 +00001033 TimeSeries remb_series("Remb", LineStyle::kStep);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001034 for (const auto& rtcp : parsed_log_.rembs(kIncomingPacket)) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001035 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001036 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
terelius2c8e8a32017-06-02 01:29:48 -07001037 remb_series.points.emplace_back(x, y);
1038 }
1039 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
1040
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -08001041 if (!parsed_log_.generic_packets_sent().empty()) {
1042 {
1043 TimeSeries time_series("Outgoing generic total bitrate",
1044 LineStyle::kLine);
1045 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1046 return packet.packet_length() * 8.0 / 1000.0;
1047 };
1048 MovingAverage<LoggedGenericPacketSent, double>(
1049 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1050 &time_series);
1051 plot->AppendTimeSeries(std::move(time_series));
1052 }
1053
1054 {
1055 TimeSeries time_series("Outgoing generic payload bitrate",
1056 LineStyle::kLine);
1057 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1058 return packet.payload_length * 8.0 / 1000.0;
1059 };
1060 MovingAverage<LoggedGenericPacketSent, double>(
1061 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1062 &time_series);
1063 plot->AppendTimeSeries(std::move(time_series));
1064 }
1065 }
1066
Bjorn Terelius068fc352019-02-13 22:38:25 +01001067 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1068 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001069 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001070 plot->SetTitle("Outgoing RTP bitrate");
terelius54ce6802016-07-13 06:44:41 -07001071}
1072
1073// For each SSRC, plot the bandwidth used by that stream.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001074void EventLogAnalyzer::CreateStreamBitrateGraph(PacketDirection direction,
1075 Plot* plot) {
1076 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1077 // Filter on SSRC.
1078 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -07001079 continue;
terelius54ce6802016-07-13 06:44:41 -07001080 }
1081
Bjorn Terelius48b82792020-05-19 10:57:24 +02001082 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001083 LineStyle::kLine);
1084 auto GetPacketSizeKilobits = [](const LoggedRtpPacket& packet) {
1085 return packet.total_length * 8.0 / 1000.0;
1086 };
terelius53dc23c2017-03-13 05:24:05 -07001087 MovingAverage<LoggedRtpPacket, double>(
Bjorn Terelius068fc352019-02-13 22:38:25 +01001088 GetPacketSizeKilobits, stream.packet_view, config_, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -07001089 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -07001090 }
1091
Bjorn Terelius068fc352019-02-13 22:38:25 +01001092 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1093 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001094 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001095 plot->SetTitle(GetDirectionAsString(direction) + " bitrate per stream");
terelius54ce6802016-07-13 06:44:41 -07001096}
1097
Bjorn Terelius9775a582019-02-15 17:29:58 +01001098// Plot the bitrate allocation for each temporal and spatial layer.
1099// Computed from RTCP XR target bitrate block, so the graph is only populated if
1100// those are sent.
1101void EventLogAnalyzer::CreateBitrateAllocationGraph(PacketDirection direction,
1102 Plot* plot) {
1103 std::map<LayerDescription, TimeSeries> time_series;
1104 const auto& xr_list = parsed_log_.extended_reports(direction);
1105 for (const auto& rtcp : xr_list) {
1106 const absl::optional<rtcp::TargetBitrate>& target_bitrate =
1107 rtcp.xr.target_bitrate();
1108 if (!target_bitrate.has_value())
1109 continue;
1110 for (const auto& bitrate_item : target_bitrate->GetTargetBitrates()) {
1111 LayerDescription layer(rtcp.xr.sender_ssrc(), bitrate_item.spatial_layer,
1112 bitrate_item.temporal_layer);
1113 auto time_series_it = time_series.find(layer);
1114 if (time_series_it == time_series.end()) {
1115 std::string layer_name = GetLayerName(layer);
1116 bool inserted;
1117 std::tie(time_series_it, inserted) = time_series.insert(
1118 std::make_pair(layer, TimeSeries(layer_name, LineStyle::kStep)));
1119 RTC_DCHECK(inserted);
1120 }
1121 float x = config_.GetCallTimeSec(rtcp.log_time_us());
1122 float y = bitrate_item.target_bitrate_kbps;
1123 time_series_it->second.points.emplace_back(x, y);
1124 }
1125 }
1126 for (auto& layer : time_series) {
1127 plot->AppendTimeSeries(std::move(layer.second));
1128 }
1129 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1130 "Time (s)", kLeftMargin, kRightMargin);
1131 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1132 if (direction == kIncomingPacket)
1133 plot->SetTitle("Target bitrate per incoming layer");
1134 else
1135 plot->SetTitle("Target bitrate per outgoing layer");
1136}
1137
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001138void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) {
1139 TimeSeries target_rates("Simulated target rate", LineStyle::kStep,
1140 PointStyle::kHighlight);
1141 TimeSeries delay_based("Logged delay-based estimate", LineStyle::kStep,
1142 PointStyle::kHighlight);
1143 TimeSeries loss_based("Logged loss-based estimate", LineStyle::kStep,
1144 PointStyle::kHighlight);
1145 TimeSeries probe_results("Logged probe success", LineStyle::kNone,
1146 PointStyle::kHighlight);
1147
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001148 LogBasedNetworkControllerSimulation simulation(
Mirko Bonadei317a1f02019-09-17 17:06:18 +02001149 std::make_unique<GoogCcNetworkControllerFactory>(),
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001150 [&](const NetworkControlUpdate& update, Timestamp at_time) {
1151 if (update.target_rate) {
1152 target_rates.points.emplace_back(
1153 config_.GetCallTimeSec(at_time.us()),
1154 update.target_rate->target_rate.kbps<float>());
1155 }
1156 });
1157
1158 simulation.ProcessEventsInLog(parsed_log_);
1159 for (const auto& logged : parsed_log_.bwe_delay_updates())
1160 delay_based.points.emplace_back(
1161 config_.GetCallTimeSec(logged.log_time_us()),
1162 logged.bitrate_bps / 1000);
1163 for (const auto& logged : parsed_log_.bwe_probe_success_events())
1164 probe_results.points.emplace_back(
1165 config_.GetCallTimeSec(logged.log_time_us()),
1166 logged.bitrate_bps / 1000);
1167 for (const auto& logged : parsed_log_.bwe_loss_updates())
1168 loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time_us()),
1169 logged.bitrate_bps / 1000);
1170
1171 plot->AppendTimeSeries(std::move(delay_based));
1172 plot->AppendTimeSeries(std::move(loss_based));
1173 plot->AppendTimeSeries(std::move(probe_results));
1174 plot->AppendTimeSeries(std::move(target_rates));
1175
1176 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1177 "Time (s)", kLeftMargin, kRightMargin);
1178 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1179 plot->SetTitle("Simulated BWE behavior");
1180}
1181
Bjorn Terelius28db2662017-10-04 14:22:43 +02001182void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001183 using RtpPacketType = LoggedRtpPacketOutgoing;
1184 using TransportFeedbackType = LoggedRtcpPacketTransportFeedback;
Stefan Holmer13181032016-07-29 14:48:54 +02001185
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001186 // TODO(terelius): This could be provided by the parser.
1187 std::multimap<int64_t, const RtpPacketType*> outgoing_rtp;
1188 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1189 for (const RtpPacketType& rtp_packet : stream.outgoing_packets)
1190 outgoing_rtp.insert(
1191 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Stefan Holmer13181032016-07-29 14:48:54 +02001192 }
1193
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001194 const std::vector<TransportFeedbackType>& incoming_rtcp =
1195 parsed_log_.transport_feedbacks(kIncomingPacket);
Stefan Holmer13181032016-07-29 14:48:54 +02001196
1197 SimulatedClock clock(0);
1198 BitrateObserver observer;
Danil Chapovalov83bbe912019-08-07 12:24:53 +02001199 RtcEventLogNull null_event_log;
nisse0245da02016-11-30 03:35:20 -08001200 PacketRouter packet_router;
Stefan Holmer5c8942a2017-08-22 16:16:44 +02001201 PacedSender pacer(&clock, &packet_router, &null_event_log);
Sebastian Jansson05acd2b2019-01-21 13:07:47 +01001202 TransportFeedbackAdapter transport_feedback;
Sebastian Jansson2db5fc02019-04-30 14:17:45 +02001203 auto factory = GoogCcNetworkControllerFactory();
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001204 TimeDelta process_interval = factory.GetProcessInterval();
Stefan Holmer13181032016-07-29 14:48:54 +02001205 // TODO(holmer): Log the call config and use that here instead.
1206 static const uint32_t kDefaultStartBitrateBps = 300000;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001207 NetworkControllerConfig cc_config;
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001208 cc_config.constraints.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Danil Chapovalovcad3e0e2020-02-17 18:46:07 +01001209 cc_config.constraints.starting_rate =
1210 DataRate::BitsPerSec(kDefaultStartBitrateBps);
Sebastian Jansson2db5fc02019-04-30 14:17:45 +02001211 cc_config.event_log = &null_event_log;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001212 auto goog_cc = factory.Create(cc_config);
Stefan Holmer13181032016-07-29 14:48:54 +02001213
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001214 TimeSeries time_series("Delay-based estimate", LineStyle::kStep,
1215 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001216 TimeSeries acked_time_series("Raw acked bitrate", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001217 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001218 TimeSeries robust_time_series("Robust throughput estimate", LineStyle::kLine,
1219 PointStyle::kHighlight);
1220 TimeSeries acked_estimate_time_series("Ackednowledged bitrate estimate",
1221 LineStyle::kLine,
1222 PointStyle::kHighlight);
Stefan Holmer13181032016-07-29 14:48:54 +02001223
1224 auto rtp_iterator = outgoing_rtp.begin();
1225 auto rtcp_iterator = incoming_rtcp.begin();
1226
1227 auto NextRtpTime = [&]() {
1228 if (rtp_iterator != outgoing_rtp.end())
1229 return static_cast<int64_t>(rtp_iterator->first);
1230 return std::numeric_limits<int64_t>::max();
1231 };
1232
1233 auto NextRtcpTime = [&]() {
1234 if (rtcp_iterator != incoming_rtcp.end())
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001235 return static_cast<int64_t>(rtcp_iterator->log_time_us());
Stefan Holmer13181032016-07-29 14:48:54 +02001236 return std::numeric_limits<int64_t>::max();
1237 };
Bjorn Tereliusa728c912018-12-06 12:26:30 +01001238 int64_t next_process_time_us_ = std::min({NextRtpTime(), NextRtcpTime()});
Stefan Holmer13181032016-07-29 14:48:54 +02001239
1240 auto NextProcessTime = [&]() {
1241 if (rtcp_iterator != incoming_rtcp.end() ||
1242 rtp_iterator != outgoing_rtp.end()) {
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001243 return next_process_time_us_;
Stefan Holmer13181032016-07-29 14:48:54 +02001244 }
1245 return std::numeric_limits<int64_t>::max();
1246 };
1247
Björn Tereliusae1892d2020-06-17 11:55:55 +02001248 RateStatistics acked_bitrate(750, 8000);
1249 test::ExplicitKeyValueConfig throughput_config(
1250 "WebRTC-Bwe-RobustThroughputEstimatorSettings/"
1251 "enabled:true,reduce_bias:true,assume_shared_link:false,initial_packets:"
1252 "10,min_packets:25,window_duration:750ms,unacked_weight:0.5/");
1253 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1254 robust_throughput_estimator(
1255 AcknowledgedBitrateEstimatorInterface::Create(&throughput_config));
1256 FieldTrialBasedConfig field_trial_config;
Björn Terelius251b0dc2019-11-11 21:00:18 +01001257 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1258 acknowledged_bitrate_estimator(
Björn Tereliusae1892d2020-06-17 11:55:55 +02001259 AcknowledgedBitrateEstimatorInterface::Create(&field_trial_config));
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001260 int64_t time_us =
1261 std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
Stefan Holmer492ee282016-10-27 17:19:20 +02001262 int64_t last_update_us = 0;
Stefan Holmer13181032016-07-29 14:48:54 +02001263 while (time_us != std::numeric_limits<int64_t>::max()) {
1264 clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001265 if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1266 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1267 const RtpPacketType& rtp_packet = *rtp_iterator->second;
1268 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
Erik Språng30a276b2019-04-23 12:00:11 +02001269 RtpPacketSendInfo packet_info;
Erik Språng6a0a5592021-06-15 19:04:24 +02001270 packet_info.media_ssrc = rtp_packet.rtp.header.ssrc;
Bjorn Tereliusf2e9cab2019-05-27 16:44:09 +02001271 packet_info.transport_sequence_number =
Erik Språng30a276b2019-04-23 12:00:11 +02001272 rtp_packet.rtp.header.extension.transportSequenceNumber;
1273 packet_info.rtp_sequence_number = rtp_packet.rtp.header.sequenceNumber;
Erik Språng30a276b2019-04-23 12:00:11 +02001274 packet_info.length = rtp_packet.rtp.total_length;
Björn Tereliusae1892d2020-06-17 11:55:55 +02001275 if (IsRtxSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1276 rtp_packet.rtp.header.ssrc)) {
1277 // Don't set the optional media type as we don't know if it is
1278 // a retransmission, FEC or padding.
1279 } else if (IsVideoSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1280 rtp_packet.rtp.header.ssrc)) {
1281 packet_info.packet_type = RtpPacketMediaType::kVideo;
1282 } else if (IsAudioSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1283 rtp_packet.rtp.header.ssrc)) {
1284 packet_info.packet_type = RtpPacketMediaType::kAudio;
1285 }
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001286 transport_feedback.AddPacket(
Erik Språng30a276b2019-04-23 12:00:11 +02001287 packet_info,
1288 0u, // Per packet overhead bytes.
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001289 Timestamp::Micros(rtp_packet.rtp.log_time_us()));
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001290 }
Björn Tereliusae1892d2020-06-17 11:55:55 +02001291 rtc::SentPacket sent_packet;
1292 sent_packet.send_time_ms = rtp_packet.rtp.log_time_ms();
1293 sent_packet.info.included_in_allocation = true;
1294 sent_packet.info.packet_size_bytes = rtp_packet.rtp.total_length;
1295 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
1296 sent_packet.packet_id =
1297 rtp_packet.rtp.header.extension.transportSequenceNumber;
1298 sent_packet.info.included_in_feedback = true;
1299 }
1300 auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet);
1301 if (sent_msg)
1302 observer.Update(goog_cc->OnSentPacket(*sent_msg));
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001303 ++rtp_iterator;
1304 }
Stefan Holmer13181032016-07-29 14:48:54 +02001305 if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
stefanc3de0332016-08-02 07:22:17 -07001306 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001307
1308 auto feedback_msg = transport_feedback.ProcessTransportFeedback(
Sebastian Jansson05acd2b2019-01-21 13:07:47 +01001309 rtcp_iterator->transport_feedback,
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001310 Timestamp::Millis(clock.TimeInMilliseconds()));
Danil Chapovalov431abd92018-06-18 12:54:17 +02001311 absl::optional<uint32_t> bitrate_bps;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001312 if (feedback_msg) {
1313 observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg));
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001314 std::vector<PacketResult> feedback =
1315 feedback_msg->SortedByReceiveTime();
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001316 if (!feedback.empty()) {
Björn Terelius251b0dc2019-11-11 21:00:18 +01001317 acknowledged_bitrate_estimator->IncomingPacketFeedbackVector(
1318 feedback);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001319 robust_throughput_estimator->IncomingPacketFeedbackVector(feedback);
1320 for (const PacketResult& packet : feedback) {
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001321 acked_bitrate.Update(packet.sent_packet.size.bytes(),
1322 packet.receive_time.ms());
Björn Tereliusae1892d2020-06-17 11:55:55 +02001323 }
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001324 bitrate_bps = acked_bitrate.Rate(feedback.back().receive_time.ms());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001325 }
Stefan Holmer13181032016-07-29 14:48:54 +02001326 }
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001327
Bjorn Terelius068fc352019-02-13 22:38:25 +01001328 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001329 float y = bitrate_bps.value_or(0) / 1000;
1330 acked_time_series.points.emplace_back(x, y);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001331 y = robust_throughput_estimator->bitrate()
1332 .value_or(DataRate::Zero())
1333 .kbps();
1334 robust_time_series.points.emplace_back(x, y);
Björn Terelius251b0dc2019-11-11 21:00:18 +01001335 y = acknowledged_bitrate_estimator->bitrate()
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001336 .value_or(DataRate::Zero())
1337 .kbps();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001338 acked_estimate_time_series.points.emplace_back(x, y);
Stefan Holmer13181032016-07-29 14:48:54 +02001339 ++rtcp_iterator;
1340 }
stefanc3de0332016-08-02 07:22:17 -07001341 if (clock.TimeInMicroseconds() >= NextProcessTime()) {
1342 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001343 ProcessInterval msg;
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001344 msg.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001345 observer.Update(goog_cc->OnProcessInterval(msg));
1346 next_process_time_us_ += process_interval.us();
stefanc3de0332016-08-02 07:22:17 -07001347 }
Stefan Holmer492ee282016-10-27 17:19:20 +02001348 if (observer.GetAndResetBitrateUpdated() ||
1349 time_us - last_update_us >= 1e6) {
Stefan Holmer13181032016-07-29 14:48:54 +02001350 uint32_t y = observer.last_bitrate_bps() / 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001351 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Stefan Holmer13181032016-07-29 14:48:54 +02001352 time_series.points.emplace_back(x, y);
Stefan Holmer492ee282016-10-27 17:19:20 +02001353 last_update_us = time_us;
Stefan Holmer13181032016-07-29 14:48:54 +02001354 }
1355 time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
1356 }
1357 // Add the data set to the plot.
philipel35ba9bd2017-04-19 05:58:51 -07001358 plot->AppendTimeSeries(std::move(time_series));
Björn Tereliusae1892d2020-06-17 11:55:55 +02001359 plot->AppendTimeSeries(std::move(robust_time_series));
philipel35ba9bd2017-04-19 05:58:51 -07001360 plot->AppendTimeSeries(std::move(acked_time_series));
Bjorn Terelius6984ad22017-10-24 12:19:45 +02001361 plot->AppendTimeSeriesIfNotEmpty(std::move(acked_estimate_time_series));
Stefan Holmer13181032016-07-29 14:48:54 +02001362
Bjorn Terelius068fc352019-02-13 22:38:25 +01001363 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1364 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001365 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001366 plot->SetTitle("Simulated send-side BWE behavior");
1367}
1368
1369void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001370 using RtpPacketType = LoggedRtpPacketIncoming;
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001371 class RembInterceptor {
Bjorn Terelius28db2662017-10-04 14:22:43 +02001372 public:
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001373 void SendRemb(uint32_t bitrate_bps, std::vector<uint32_t> ssrcs) {
Bjorn Terelius28db2662017-10-04 14:22:43 +02001374 last_bitrate_bps_ = bitrate_bps;
1375 bitrate_updated_ = true;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001376 }
1377 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
1378 bool GetAndResetBitrateUpdated() {
1379 bool bitrate_updated = bitrate_updated_;
1380 bitrate_updated_ = false;
1381 return bitrate_updated;
1382 }
1383
1384 private:
Bjorn Terelius571e1302020-06-09 10:29:09 +02001385 // We don't know the start bitrate, but assume that it is the default 300
1386 // kbps.
1387 uint32_t last_bitrate_bps_ = 300000;
1388 bool bitrate_updated_ = false;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001389 };
1390
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001391 std::multimap<int64_t, const RtpPacketType*> incoming_rtp;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001392
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001393 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Terelius48b82792020-05-19 10:57:24 +02001394 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001395 for (const auto& rtp_packet : stream.incoming_packets)
1396 incoming_rtp.insert(
1397 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Bjorn Terelius28db2662017-10-04 14:22:43 +02001398 }
1399 }
1400
1401 SimulatedClock clock(0);
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001402 RembInterceptor remb_interceptor;
1403 ReceiveSideCongestionController rscc(
1404 &clock, [](auto...) {},
1405 absl::bind_front(&RembInterceptor::SendRemb, &remb_interceptor), nullptr);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001406 // TODO(holmer): Log the call config and use that here instead.
1407 // static const uint32_t kDefaultStartBitrateBps = 300000;
1408 // rscc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
1409
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001410 TimeSeries time_series("Receive side estimate", LineStyle::kLine,
1411 PointStyle::kHighlight);
1412 TimeSeries acked_time_series("Received bitrate", LineStyle::kLine);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001413
1414 RateStatistics acked_bitrate(250, 8000);
1415 int64_t last_update_us = 0;
1416 for (const auto& kv : incoming_rtp) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001417 const RtpPacketType& packet = *kv.second;
1418 int64_t arrival_time_ms = packet.rtp.log_time_us() / 1000;
1419 size_t payload = packet.rtp.total_length; /*Should subtract header?*/
1420 clock.AdvanceTimeMicroseconds(packet.rtp.log_time_us() -
Bjorn Terelius28db2662017-10-04 14:22:43 +02001421 clock.TimeInMicroseconds());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001422 rscc.OnReceivedPacket(arrival_time_ms, payload, packet.rtp.header);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001423 acked_bitrate.Update(payload, arrival_time_ms);
Danil Chapovalov431abd92018-06-18 12:54:17 +02001424 absl::optional<uint32_t> bitrate_bps = acked_bitrate.Rate(arrival_time_ms);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001425 if (bitrate_bps) {
1426 uint32_t y = *bitrate_bps / 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001427 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Bjorn Terelius28db2662017-10-04 14:22:43 +02001428 acked_time_series.points.emplace_back(x, y);
1429 }
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001430 if (remb_interceptor.GetAndResetBitrateUpdated() ||
Bjorn Terelius28db2662017-10-04 14:22:43 +02001431 clock.TimeInMicroseconds() - last_update_us >= 1e6) {
Per Kjellanderfe2063e2021-05-12 09:02:43 +02001432 uint32_t y = remb_interceptor.last_bitrate_bps() / 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001433 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Bjorn Terelius28db2662017-10-04 14:22:43 +02001434 time_series.points.emplace_back(x, y);
1435 last_update_us = clock.TimeInMicroseconds();
1436 }
1437 }
1438 // Add the data set to the plot.
1439 plot->AppendTimeSeries(std::move(time_series));
1440 plot->AppendTimeSeries(std::move(acked_time_series));
1441
Bjorn Terelius068fc352019-02-13 22:38:25 +01001442 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1443 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001444 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1445 plot->SetTitle("Simulated receive-side BWE behavior");
Stefan Holmer13181032016-07-29 14:48:54 +02001446}
1447
tereliuse34c19c2016-08-15 08:47:14 -07001448void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001449 TimeSeries time_series("Network delay", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001450 PointStyle::kHighlight);
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001451 int64_t min_send_receive_diff_ms = std::numeric_limits<int64_t>::max();
1452 int64_t min_rtt_ms = std::numeric_limits<int64_t>::max();
stefanc3de0332016-08-02 07:22:17 -07001453
stefana0a8ed72017-09-06 02:06:32 -07001454 int64_t prev_y = 0;
Björn Tereliusc69c1bb2019-10-11 15:06:58 +02001455 std::vector<MatchedSendArrivalTimes> matched_rtp_rtcp =
1456 GetNetworkTrace(parsed_log_);
1457 absl::c_stable_sort(matched_rtp_rtcp, [](const MatchedSendArrivalTimes& a,
1458 const MatchedSendArrivalTimes& b) {
philipel3574d052019-11-18 14:38:13 +01001459 return a.feedback_arrival_time_ms < b.feedback_arrival_time_ms ||
1460 (a.feedback_arrival_time_ms == b.feedback_arrival_time_ms &&
1461 a.arrival_time_ms < b.arrival_time_ms);
Björn Tereliusc69c1bb2019-10-11 15:06:58 +02001462 });
1463 for (const auto& packet : matched_rtp_rtcp) {
Sebastian Jansson74f96ec2019-10-29 12:57:54 +01001464 if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived)
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001465 continue;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001466 float x = config_.GetCallTimeSec(1000 * packet.feedback_arrival_time_ms);
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001467 int64_t y = packet.arrival_time_ms - packet.send_time_ms;
1468 prev_y = y;
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001469 int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms;
1470 min_rtt_ms = std::min(rtt_ms, min_rtt_ms);
1471 min_send_receive_diff_ms = std::min(y, min_send_receive_diff_ms);
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001472 time_series.points.emplace_back(x, y);
stefanc3de0332016-08-02 07:22:17 -07001473 }
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001474
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001475 // We assume that the base network delay (w/o queues) is equal to half
1476 // the minimum RTT. Therefore rescale the delays by subtracting the minimum
Mirko Bonadei604e75c2019-07-25 11:55:47 +02001477 // observed 1-ways delay and add half the minimum RTT.
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001478 const int64_t estimated_clock_offset_ms =
1479 min_send_receive_diff_ms - min_rtt_ms / 2;
stefanc3de0332016-08-02 07:22:17 -07001480 for (TimeSeriesPoint& point : time_series.points)
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001481 point.y -= estimated_clock_offset_ms;
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001482
stefanc3de0332016-08-02 07:22:17 -07001483 // Add the data set to the plot.
stefana0a8ed72017-09-06 02:06:32 -07001484 plot->AppendTimeSeriesIfNotEmpty(std::move(time_series));
stefanc3de0332016-08-02 07:22:17 -07001485
Bjorn Terelius068fc352019-02-13 22:38:25 +01001486 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1487 "Time (s)", kLeftMargin, kRightMargin);
stefanc3de0332016-08-02 07:22:17 -07001488 plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
Konrad Hofbauer5be3bbd2019-01-21 12:31:07 +01001489 plot->SetTitle("Outgoing network delay (based on per-packet feedback)");
stefanc3de0332016-08-02 07:22:17 -07001490}
stefan08383272016-12-20 08:51:52 -08001491
Bjorn Terelius0295a962017-10-25 17:42:41 +02001492void EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001493 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1494 const std::vector<LoggedRtpPacketOutgoing>& packets =
1495 stream.outgoing_packets;
Bjorn Terelius0295a962017-10-25 17:42:41 +02001496
Bjorn Terelius48b82792020-05-19 10:57:24 +02001497 if (IsRtxSsrc(parsed_log_, kOutgoingPacket, stream.ssrc)) {
Konrad Hofbauerbfb735b2019-04-16 11:12:11 +02001498 continue;
1499 }
1500
Bjorn Terelius0295a962017-10-25 17:42:41 +02001501 if (packets.size() < 2) {
Mirko Bonadei675513b2017-11-09 11:09:25 +01001502 RTC_LOG(LS_WARNING)
1503 << "Can't estimate a the RTP clock frequency or the "
1504 "pacer delay with less than 2 packets in the stream";
Bjorn Terelius0295a962017-10-25 17:42:41 +02001505 continue;
1506 }
Björn Terelius0d1b28c2020-05-27 20:25:06 +02001507 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Danil Chapovalov431abd92018-06-18 12:54:17 +02001508 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 10:57:24 +02001509 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001510 if (!estimated_frequency)
1511 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +02001512 if (IsVideoSsrc(parsed_log_, kOutgoingPacket, stream.ssrc) &&
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001513 *estimated_frequency != 90000) {
Mirko Bonadei675513b2017-11-09 11:09:25 +01001514 RTC_LOG(LS_WARNING)
Bjorn Terelius0295a962017-10-25 17:42:41 +02001515 << "Video stream should use a 90 kHz clock but appears to use "
1516 << *estimated_frequency / 1000 << ". Discarding.";
1517 continue;
1518 }
1519
1520 TimeSeries pacer_delay_series(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001521 GetStreamName(parsed_log_, kOutgoingPacket, stream.ssrc) + "(" +
Bjorn Terelius0295a962017-10-25 17:42:41 +02001522 std::to_string(*estimated_frequency / 1000) + " kHz)",
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001523 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001524 SeqNumUnwrapper<uint32_t> timestamp_unwrapper;
1525 uint64_t first_capture_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001526 timestamp_unwrapper.Unwrap(packets.front().rtp.header.timestamp);
1527 uint64_t first_send_timestamp = packets.front().rtp.log_time_us();
1528 for (const auto& packet : packets) {
Bjorn Terelius0295a962017-10-25 17:42:41 +02001529 double capture_time_ms = (static_cast<double>(timestamp_unwrapper.Unwrap(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001530 packet.rtp.header.timestamp)) -
Bjorn Terelius0295a962017-10-25 17:42:41 +02001531 first_capture_timestamp) /
1532 *estimated_frequency * 1000;
1533 double send_time_ms =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001534 static_cast<double>(packet.rtp.log_time_us() - first_send_timestamp) /
1535 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001536 float x = config_.GetCallTimeSec(packet.rtp.log_time_us());
Bjorn Terelius0295a962017-10-25 17:42:41 +02001537 float y = send_time_ms - capture_time_ms;
1538 pacer_delay_series.points.emplace_back(x, y);
1539 }
1540 plot->AppendTimeSeries(std::move(pacer_delay_series));
1541 }
1542
Bjorn Terelius068fc352019-02-13 22:38:25 +01001543 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1544 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001545 plot->SetSuggestedYAxis(0, 10, "Pacer delay (ms)", kBottomMargin, kTopMargin);
1546 plot->SetTitle(
1547 "Delay from capture to send time. (First packet normalized to 0.)");
1548}
1549
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001550void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction,
1551 Plot* plot) {
1552 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1553 TimeSeries rtp_timestamps(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001554 GetStreamName(parsed_log_, direction, stream.ssrc) + " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001555 LineStyle::kLine, PointStyle::kHighlight);
1556 for (const auto& packet : stream.packet_view) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001557 float x = config_.GetCallTimeSec(packet.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001558 float y = packet.header.timestamp;
1559 rtp_timestamps.points.emplace_back(x, y);
stefane372d3c2017-02-02 08:04:18 -08001560 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001561 plot->AppendTimeSeries(std::move(rtp_timestamps));
Björn Tereliusff612732018-04-25 14:23:01 +00001562
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001563 TimeSeries rtcp_timestamps(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001564 GetStreamName(parsed_log_, direction, stream.ssrc) +
1565 " rtcp capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001566 LineStyle::kLine, PointStyle::kHighlight);
1567 // TODO(terelius): Why only sender reports?
1568 const auto& sender_reports = parsed_log_.sender_reports(direction);
1569 for (const auto& rtcp : sender_reports) {
1570 if (rtcp.sr.sender_ssrc() != stream.ssrc)
1571 continue;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001572 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001573 float y = rtcp.sr.rtp_timestamp();
1574 rtcp_timestamps.points.emplace_back(x, y);
Björn Tereliusff612732018-04-25 14:23:01 +00001575 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001576 plot->AppendTimeSeriesIfNotEmpty(std::move(rtcp_timestamps));
stefane372d3c2017-02-02 08:04:18 -08001577 }
1578
Bjorn Terelius068fc352019-02-13 22:38:25 +01001579 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1580 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001581 plot->SetSuggestedYAxis(0, 1, "RTP timestamp", kBottomMargin, kTopMargin);
1582 plot->SetTitle(GetDirectionAsString(direction) + " timestamps");
stefane372d3c2017-02-02 08:04:18 -08001583}
michaelt6e5b2192017-02-22 07:33:27 -08001584
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001585void EventLogAnalyzer::CreateSenderAndReceiverReportPlot(
1586 PacketDirection direction,
1587 rtc::FunctionView<float(const rtcp::ReportBlock&)> fy,
1588 std::string title,
1589 std::string yaxis_label,
1590 Plot* plot) {
1591 std::map<uint32_t, TimeSeries> sr_reports_by_ssrc;
1592 const auto& sender_reports = parsed_log_.sender_reports(direction);
1593 for (const auto& rtcp : sender_reports) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001594 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001595 uint32_t ssrc = rtcp.sr.sender_ssrc();
1596 for (const auto& block : rtcp.sr.report_blocks()) {
1597 float y = fy(block);
1598 auto sr_report_it = sr_reports_by_ssrc.find(ssrc);
1599 bool inserted;
1600 if (sr_report_it == sr_reports_by_ssrc.end()) {
1601 std::tie(sr_report_it, inserted) = sr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001602 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1603 " Sender Reports",
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001604 LineStyle::kLine, PointStyle::kHighlight));
1605 }
1606 sr_report_it->second.points.emplace_back(x, y);
1607 }
1608 }
1609 for (auto& kv : sr_reports_by_ssrc) {
1610 plot->AppendTimeSeries(std::move(kv.second));
1611 }
1612
1613 std::map<uint32_t, TimeSeries> rr_reports_by_ssrc;
1614 const auto& receiver_reports = parsed_log_.receiver_reports(direction);
1615 for (const auto& rtcp : receiver_reports) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001616 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001617 uint32_t ssrc = rtcp.rr.sender_ssrc();
1618 for (const auto& block : rtcp.rr.report_blocks()) {
1619 float y = fy(block);
1620 auto rr_report_it = rr_reports_by_ssrc.find(ssrc);
1621 bool inserted;
1622 if (rr_report_it == rr_reports_by_ssrc.end()) {
1623 std::tie(rr_report_it, inserted) = rr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001624 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1625 " Receiver Reports",
1626 LineStyle::kLine, PointStyle::kHighlight));
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001627 }
1628 rr_report_it->second.points.emplace_back(x, y);
1629 }
1630 }
1631 for (auto& kv : rr_reports_by_ssrc) {
1632 plot->AppendTimeSeries(std::move(kv.second));
1633 }
1634
Bjorn Terelius068fc352019-02-13 22:38:25 +01001635 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1636 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001637 plot->SetSuggestedYAxis(0, 1, yaxis_label, kBottomMargin, kTopMargin);
1638 plot->SetTitle(title);
1639}
1640
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001641void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) {
1642 std::map<uint32_t, TimeSeries> configs_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001643 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001644 if (configs_by_cp_id.find(config.candidate_pair_id) ==
1645 configs_by_cp_id.end()) {
1646 const std::string candidate_pair_desc =
1647 GetCandidatePairLogDescriptionAsString(config);
Qingsi Wang93a84392018-01-30 17:13:09 -08001648 configs_by_cp_id[config.candidate_pair_id] =
1649 TimeSeries("[" + std::to_string(config.candidate_pair_id) + "]" +
1650 candidate_pair_desc,
1651 LineStyle::kNone, PointStyle::kHighlight);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001652 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1653 candidate_pair_desc;
1654 }
Bjorn Terelius068fc352019-02-13 22:38:25 +01001655 float x = config_.GetCallTimeSec(config.log_time_us());
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001656 float y = static_cast<float>(config.type);
1657 configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y);
1658 }
1659
1660 // TODO(qingsi): There can be a large number of candidate pairs generated by
1661 // certain calls and the frontend cannot render the chart in this case due to
1662 // the failure of generating a palette with the same number of colors.
1663 for (auto& kv : configs_by_cp_id) {
1664 plot->AppendTimeSeries(std::move(kv.second));
1665 }
1666
Bjorn Terelius068fc352019-02-13 22:38:25 +01001667 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1668 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001669 plot->SetSuggestedYAxis(0, 3, "Config Type", kBottomMargin, kTopMargin);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001670 plot->SetTitle("[IceEventLog] ICE candidate pair configs");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001671 plot->SetYAxisTickLabels(
1672 {{static_cast<float>(IceCandidatePairConfigType::kAdded), "ADDED"},
1673 {static_cast<float>(IceCandidatePairConfigType::kUpdated), "UPDATED"},
1674 {static_cast<float>(IceCandidatePairConfigType::kDestroyed),
1675 "DESTROYED"},
1676 {static_cast<float>(IceCandidatePairConfigType::kSelected),
1677 "SELECTED"}});
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001678}
1679
1680std::string EventLogAnalyzer::GetCandidatePairLogDescriptionFromId(
1681 uint32_t candidate_pair_id) {
1682 if (candidate_pair_desc_by_id_.find(candidate_pair_id) !=
1683 candidate_pair_desc_by_id_.end()) {
1684 return candidate_pair_desc_by_id_[candidate_pair_id];
1685 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001686 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001687 // TODO(qingsi): Add the handling of the "Updated" config event after the
1688 // visualization of property change for candidate pairs is introduced.
1689 if (candidate_pair_desc_by_id_.find(config.candidate_pair_id) ==
1690 candidate_pair_desc_by_id_.end()) {
1691 const std::string candidate_pair_desc =
1692 GetCandidatePairLogDescriptionAsString(config);
1693 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1694 candidate_pair_desc;
1695 }
1696 }
1697 return candidate_pair_desc_by_id_[candidate_pair_id];
1698}
1699
1700void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) {
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001701 constexpr int kEventTypeOffset =
1702 static_cast<int>(IceCandidatePairConfigType::kNumValues);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001703 std::map<uint32_t, TimeSeries> checks_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001704 for (const auto& event : parsed_log_.ice_candidate_pair_events()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001705 if (checks_by_cp_id.find(event.candidate_pair_id) ==
1706 checks_by_cp_id.end()) {
1707 checks_by_cp_id[event.candidate_pair_id] = TimeSeries(
Qingsi Wang93a84392018-01-30 17:13:09 -08001708 "[" + std::to_string(event.candidate_pair_id) + "]" +
1709 GetCandidatePairLogDescriptionFromId(event.candidate_pair_id),
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001710 LineStyle::kNone, PointStyle::kHighlight);
1711 }
Bjorn Terelius068fc352019-02-13 22:38:25 +01001712 float x = config_.GetCallTimeSec(event.log_time_us());
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001713 float y = static_cast<float>(event.type) + kEventTypeOffset;
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001714 checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y);
1715 }
1716
1717 // TODO(qingsi): The same issue as in CreateIceCandidatePairConfigGraph.
1718 for (auto& kv : checks_by_cp_id) {
1719 plot->AppendTimeSeries(std::move(kv.second));
1720 }
1721
Bjorn Terelius068fc352019-02-13 22:38:25 +01001722 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1723 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001724 plot->SetSuggestedYAxis(0, 4, "Connectivity State", kBottomMargin,
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001725 kTopMargin);
1726 plot->SetTitle("[IceEventLog] ICE connectivity checks");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001727
1728 plot->SetYAxisTickLabels(
1729 {{static_cast<float>(IceCandidatePairEventType::kCheckSent) +
1730 kEventTypeOffset,
1731 "CHECK SENT"},
1732 {static_cast<float>(IceCandidatePairEventType::kCheckReceived) +
1733 kEventTypeOffset,
1734 "CHECK RECEIVED"},
1735 {static_cast<float>(IceCandidatePairEventType::kCheckResponseSent) +
1736 kEventTypeOffset,
1737 "RESPONSE SENT"},
1738 {static_cast<float>(IceCandidatePairEventType::kCheckResponseReceived) +
1739 kEventTypeOffset,
1740 "RESPONSE RECEIVED"}});
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001741}
1742
Zach Stein10a58012018-12-07 12:26:28 -08001743void EventLogAnalyzer::CreateDtlsTransportStateGraph(Plot* plot) {
1744 TimeSeries states("DTLS Transport State", LineStyle::kNone,
1745 PointStyle::kHighlight);
1746 for (const auto& event : parsed_log_.dtls_transport_states()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001747 float x = config_.GetCallTimeSec(event.log_time_us());
Zach Stein10a58012018-12-07 12:26:28 -08001748 float y = static_cast<float>(event.dtls_transport_state);
1749 states.points.emplace_back(x, y);
1750 }
1751 plot->AppendTimeSeries(std::move(states));
Bjorn Terelius068fc352019-02-13 22:38:25 +01001752 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1753 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001754 plot->SetSuggestedYAxis(0, static_cast<float>(DtlsTransportState::kNumValues),
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001755 "Transport State", kBottomMargin, kTopMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001756 plot->SetTitle("DTLS Transport State");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001757 plot->SetYAxisTickLabels(
1758 {{static_cast<float>(DtlsTransportState::kNew), "NEW"},
1759 {static_cast<float>(DtlsTransportState::kConnecting), "CONNECTING"},
1760 {static_cast<float>(DtlsTransportState::kConnected), "CONNECTED"},
1761 {static_cast<float>(DtlsTransportState::kClosed), "CLOSED"},
1762 {static_cast<float>(DtlsTransportState::kFailed), "FAILED"}});
Zach Stein10a58012018-12-07 12:26:28 -08001763}
1764
1765void EventLogAnalyzer::CreateDtlsWritableStateGraph(Plot* plot) {
1766 TimeSeries writable("DTLS Writable", LineStyle::kNone,
1767 PointStyle::kHighlight);
1768 for (const auto& event : parsed_log_.dtls_writable_states()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001769 float x = config_.GetCallTimeSec(event.log_time_us());
Zach Stein10a58012018-12-07 12:26:28 -08001770 float y = static_cast<float>(event.writable);
1771 writable.points.emplace_back(x, y);
1772 }
1773 plot->AppendTimeSeries(std::move(writable));
Bjorn Terelius068fc352019-02-13 22:38:25 +01001774 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1775 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001776 plot->SetSuggestedYAxis(0, 1, "Writable", kBottomMargin, kTopMargin);
1777 plot->SetTitle("DTLS Writable State");
1778}
1779
terelius54ce6802016-07-13 06:44:41 -07001780} // namespace webrtc