blob: 6d84b1b5ca430dea8e7e47c0704e69905de821f5 [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"
Bjorn Terelius6c4b1b72019-01-11 13:01:29 +010022#include "absl/strings/string_view.h"
Artem Titov741daaf2019-03-21 14:37:36 +010023#include "api/function_view.h"
Sebastian Jansson95edb032019-01-17 16:24:12 +010024#include "api/transport/field_trial_based_config.h"
Sebastian Jansson5c94f552018-10-15 18:46:51 +020025#include "api/transport/goog_cc_factory.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020026#include "call/audio_receive_stream.h"
27#include "call/audio_send_stream.h"
28#include "call/call.h"
29#include "call/video_receive_stream.h"
30#include "call/video_send_stream.h"
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +020031#include "logging/rtc_event_log/rtc_event_processor.h"
Elad Alon99a81b62017-09-21 10:25:29 +020032#include "logging/rtc_event_log/rtc_stream_config.h"
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +020033#include "modules/audio_coding/audio_network_adaptor/include/audio_network_adaptor.h"
Sebastian Jansson172fd852018-05-24 14:17:06 +020034#include "modules/congestion_controller/goog_cc/acknowledged_bitrate_estimator.h"
35#include "modules/congestion_controller/goog_cc/bitrate_estimator.h"
Sebastian Jansson04b18cb2018-07-02 09:25:25 +020036#include "modules/congestion_controller/goog_cc/delay_based_bwe.h"
Bjorn Terelius28db2662017-10-04 14:22:43 +020037#include "modules/congestion_controller/include/receive_side_congestion_controller.h"
Sebastian Jansson5c94f552018-10-15 18:46:51 +020038#include "modules/congestion_controller/rtp/transport_feedback_adapter.h"
Erik Språnge7942432019-06-12 13:30:02 +020039#include "modules/pacing/paced_sender.h"
Niels Möllerfd6c0912017-10-31 10:19:10 +010040#include "modules/pacing/packet_router.h"
Sebastian Jansson5c94f552018-10-15 18:46:51 +020041#include "modules/remote_bitrate_estimator/include/bwe_defines.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020042#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h"
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +020043#include "modules/rtp_rtcp/source/rtcp_packet.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020044#include "modules/rtp_rtcp/source/rtcp_packet/common_header.h"
45#include "modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
46#include "modules/rtp_rtcp/source/rtcp_packet/remb.h"
47#include "modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
48#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
49#include "modules/rtp_rtcp/source/rtp_header_extensions.h"
Tomas Gunnarssonf25761d2020-06-03 22:55:33 +020050#include "modules/rtp_rtcp/source/rtp_rtcp_interface.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020051#include "modules/rtp_rtcp/source/rtp_utility.h"
52#include "rtc_base/checks.h"
53#include "rtc_base/format_macros.h"
54#include "rtc_base/logging.h"
Bjorn Terelius0295a962017-10-25 17:42:41 +020055#include "rtc_base/numerics/sequence_number_util.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020056#include "rtc_base/rate_statistics.h"
Jonas Olsson366a50c2018-09-06 13:41:30 +020057#include "rtc_base/strings/string_builder.h"
Mirko Bonadei575998c2019-07-25 13:57:41 +020058#include "rtc_tools/rtc_event_log_visualizer/log_simulation.h"
Björn Tereliusae1892d2020-06-17 11:55:55 +020059#include "test/explicit_key_value_config.h"
Bjorn Terelius6984ad22017-10-24 12:19:45 +020060
tereliusdc35dcd2016-08-01 12:03:27 -070061namespace webrtc {
tereliusdc35dcd2016-08-01 12:03:27 -070062
terelius54ce6802016-07-13 06:44:41 -070063namespace {
64
65std::string SsrcToString(uint32_t ssrc) {
Jonas Olsson366a50c2018-09-06 13:41:30 +020066 rtc::StringBuilder ss;
terelius54ce6802016-07-13 06:44:41 -070067 ss << "SSRC " << ssrc;
Jonas Olsson84df1c72018-09-14 16:59:32 +020068 return ss.Release();
terelius54ce6802016-07-13 06:44:41 -070069}
70
71// Checks whether an SSRC is contained in the list of desired SSRCs.
72// Note that an empty SSRC list matches every SSRC.
73bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) {
Mirko Bonadei1f173152019-07-25 15:28:14 +020074 if (desired_ssrc.empty())
terelius54ce6802016-07-13 06:44:41 -070075 return true;
76 return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) !=
77 desired_ssrc.end();
78}
79
80double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
81 // The timestamp is a fixed point representation with 6 bits for seconds
82 // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the
Qingsi Wang8eca1ff2018-02-02 11:49:44 -080083 // time in seconds and then multiply by kNumMicrosecsPerSec to convert to
84 // microseconds.
terelius54ce6802016-07-13 06:44:41 -070085 static constexpr double kTimestampToMicroSec =
Qingsi Wang8eca1ff2018-02-02 11:49:44 -080086 static_cast<double>(kNumMicrosecsPerSec) / static_cast<double>(1ul << 18);
terelius54ce6802016-07-13 06:44:41 -070087 return abs_send_time * kTimestampToMicroSec;
88}
89
90// Computes the difference |later| - |earlier| where |later| and |earlier|
91// are counters that wrap at |modulus|. The difference is chosen to have the
92// least absolute value. For example if |modulus| is 8, then the difference will
93// be chosen in the range [-3, 4]. If |modulus| is 9, then the difference will
94// be in [-4, 4].
95int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
96 RTC_DCHECK_LE(1, modulus);
97 RTC_DCHECK_LT(later, modulus);
98 RTC_DCHECK_LT(earlier, modulus);
99 int64_t difference =
100 static_cast<int64_t>(later) - static_cast<int64_t>(earlier);
101 int64_t max_difference = modulus / 2;
102 int64_t min_difference = max_difference - modulus + 1;
103 if (difference > max_difference) {
104 difference -= modulus;
105 }
106 if (difference < min_difference) {
107 difference += modulus;
108 }
terelius6addf492016-08-23 17:34:07 -0700109 if (difference > max_difference / 2 || difference < min_difference / 2) {
Mirko Bonadei675513b2017-11-09 11:09:25 +0100110 RTC_LOG(LS_WARNING) << "Difference between" << later << " and " << earlier
111 << " expected to be in the range ("
112 << min_difference / 2 << "," << max_difference / 2
113 << ") but is " << difference
114 << ". Correct unwrapping is uncertain.";
terelius6addf492016-08-23 17:34:07 -0700115 }
terelius54ce6802016-07-13 06:44:41 -0700116 return difference;
117}
118
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200119// This is much more reliable for outgoing streams than for incoming streams.
120template <typename RtpPacketContainer>
Danil Chapovalov431abd92018-06-18 12:54:17 +0200121absl::optional<uint32_t> EstimateRtpClockFrequency(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200122 const RtpPacketContainer& packets,
123 int64_t end_time_us) {
124 RTC_CHECK(packets.size() >= 2);
125 SeqNumUnwrapper<uint32_t> unwrapper;
Philip Eliasson1f850a62019-03-19 12:15:00 +0000126 int64_t first_rtp_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200127 unwrapper.Unwrap(packets[0].rtp.header.timestamp);
128 int64_t first_log_timestamp = packets[0].log_time_us();
Philip Eliasson1f850a62019-03-19 12:15:00 +0000129 int64_t last_rtp_timestamp = first_rtp_timestamp;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200130 int64_t last_log_timestamp = first_log_timestamp;
131 for (size_t i = 1; i < packets.size(); i++) {
132 if (packets[i].log_time_us() > end_time_us)
133 break;
134 last_rtp_timestamp = unwrapper.Unwrap(packets[i].rtp.header.timestamp);
135 last_log_timestamp = packets[i].log_time_us();
136 }
137 if (last_log_timestamp - first_log_timestamp < kNumMicrosecsPerSec) {
138 RTC_LOG(LS_WARNING)
139 << "Failed to estimate RTP clock frequency: Stream too short. ("
140 << packets.size() << " packets, "
141 << last_log_timestamp - first_log_timestamp << " us)";
Danil Chapovalov431abd92018-06-18 12:54:17 +0200142 return absl::nullopt;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200143 }
144 double duration =
145 static_cast<double>(last_log_timestamp - first_log_timestamp) /
146 kNumMicrosecsPerSec;
147 double estimated_frequency =
148 (last_rtp_timestamp - first_rtp_timestamp) / duration;
149 for (uint32_t f : {8000, 16000, 32000, 48000, 90000}) {
philipel3fa49382019-08-20 15:59:57 +0200150 if (std::fabs(estimated_frequency - f) < 0.15 * f) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200151 return f;
152 }
153 }
154 RTC_LOG(LS_WARNING) << "Failed to estimate RTP clock frequency: Estimate "
155 << estimated_frequency
philipel3fa49382019-08-20 15:59:57 +0200156 << " not close to any stardard RTP frequency.";
Danil Chapovalov431abd92018-06-18 12:54:17 +0200157 return absl::nullopt;
ivocaac9d6f2016-09-22 07:01:47 -0700158}
159
Danil Chapovalov431abd92018-06-18 12:54:17 +0200160absl::optional<double> NetworkDelayDiff_AbsSendTime(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100161 const LoggedRtpPacketIncoming& old_packet,
162 const LoggedRtpPacketIncoming& new_packet) {
163 if (old_packet.rtp.header.extension.hasAbsoluteSendTime &&
164 new_packet.rtp.header.extension.hasAbsoluteSendTime) {
terelius53dc23c2017-03-13 05:24:05 -0700165 int64_t send_time_diff = WrappingDifference(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100166 new_packet.rtp.header.extension.absoluteSendTime,
167 old_packet.rtp.header.extension.absoluteSendTime, 1ul << 24);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200168 int64_t recv_time_diff =
169 new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 05:24:05 -0700170 double delay_change_us =
171 recv_time_diff - AbsSendTimeToMicroseconds(send_time_diff);
Oskar Sundbom3928dbc2017-11-16 10:53:09 +0100172 return delay_change_us / 1000;
terelius53dc23c2017-03-13 05:24:05 -0700173 } else {
Danil Chapovalov431abd92018-06-18 12:54:17 +0200174 return absl::nullopt;
terelius6addf492016-08-23 17:34:07 -0700175 }
176}
177
Danil Chapovalov431abd92018-06-18 12:54:17 +0200178absl::optional<double> NetworkDelayDiff_CaptureTime(
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100179 const LoggedRtpPacketIncoming& old_packet,
180 const LoggedRtpPacketIncoming& new_packet,
181 const double sample_rate) {
182 int64_t send_time_diff =
183 WrappingDifference(new_packet.rtp.header.timestamp,
184 old_packet.rtp.header.timestamp, 1ull << 32);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200185 int64_t recv_time_diff = new_packet.log_time_us() - old_packet.log_time_us();
terelius53dc23c2017-03-13 05:24:05 -0700186
terelius53dc23c2017-03-13 05:24:05 -0700187 double delay_change =
188 static_cast<double>(recv_time_diff) / 1000 -
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100189 static_cast<double>(send_time_diff) / sample_rate * 1000;
terelius53dc23c2017-03-13 05:24:05 -0700190 if (delay_change < -10000 || 10000 < delay_change) {
Mirko Bonadei675513b2017-11-09 11:09:25 +0100191 RTC_LOG(LS_WARNING) << "Very large delay change. Timestamps correct?";
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100192 RTC_LOG(LS_WARNING) << "Old capture time "
193 << old_packet.rtp.header.timestamp << ", received time "
194 << old_packet.log_time_us();
195 RTC_LOG(LS_WARNING) << "New capture time "
196 << new_packet.rtp.header.timestamp << ", received time "
197 << new_packet.log_time_us();
Mirko Bonadei675513b2017-11-09 11:09:25 +0100198 RTC_LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = "
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800199 << static_cast<double>(recv_time_diff) /
200 kNumMicrosecsPerSec
201 << "s";
Mirko Bonadei675513b2017-11-09 11:09:25 +0100202 RTC_LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = "
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100203 << static_cast<double>(send_time_diff) / sample_rate
Mirko Bonadei675513b2017-11-09 11:09:25 +0100204 << "s";
terelius53dc23c2017-03-13 05:24:05 -0700205 }
Oskar Sundbom3928dbc2017-11-16 10:53:09 +0100206 return delay_change;
terelius53dc23c2017-03-13 05:24:05 -0700207}
208
terelius6addf492016-08-23 17:34:07 -0700209
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100210template <typename T>
211TimeSeries CreateRtcpTypeTimeSeries(const std::vector<T>& rtcp_list,
212 AnalyzerConfig config,
213 std::string rtcp_name,
214 int category_id) {
215 TimeSeries time_series(rtcp_name, LineStyle::kNone, PointStyle::kHighlight);
216 for (const auto& rtcp : rtcp_list) {
217 float x = config.GetCallTimeSec(rtcp.log_time_us());
218 float y = category_id;
219 time_series.points.emplace_back(x, y);
220 }
221 return time_series;
222}
223
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800224const char kUnknownEnumValue[] = "unknown";
225
226const char kIceCandidateTypeLocal[] = "local";
227const char kIceCandidateTypeStun[] = "stun";
228const char kIceCandidateTypePrflx[] = "prflx";
229const char kIceCandidateTypeRelay[] = "relay";
230
231const char kProtocolUdp[] = "udp";
232const char kProtocolTcp[] = "tcp";
233const char kProtocolSsltcp[] = "ssltcp";
234const char kProtocolTls[] = "tls";
235
236const char kAddressFamilyIpv4[] = "ipv4";
237const char kAddressFamilyIpv6[] = "ipv6";
238
239const char kNetworkTypeEthernet[] = "ethernet";
240const char kNetworkTypeLoopback[] = "loopback";
241const char kNetworkTypeWifi[] = "wifi";
242const char kNetworkTypeVpn[] = "vpn";
243const char kNetworkTypeCellular[] = "cellular";
244
245std::string GetIceCandidateTypeAsString(webrtc::IceCandidateType type) {
246 switch (type) {
247 case webrtc::IceCandidateType::kLocal:
248 return kIceCandidateTypeLocal;
249 case webrtc::IceCandidateType::kStun:
250 return kIceCandidateTypeStun;
251 case webrtc::IceCandidateType::kPrflx:
252 return kIceCandidateTypePrflx;
253 case webrtc::IceCandidateType::kRelay:
254 return kIceCandidateTypeRelay;
255 default:
256 return kUnknownEnumValue;
257 }
258}
259
260std::string GetProtocolAsString(webrtc::IceCandidatePairProtocol protocol) {
261 switch (protocol) {
262 case webrtc::IceCandidatePairProtocol::kUdp:
263 return kProtocolUdp;
264 case webrtc::IceCandidatePairProtocol::kTcp:
265 return kProtocolTcp;
266 case webrtc::IceCandidatePairProtocol::kSsltcp:
267 return kProtocolSsltcp;
268 case webrtc::IceCandidatePairProtocol::kTls:
269 return kProtocolTls;
270 default:
271 return kUnknownEnumValue;
272 }
273}
274
275std::string GetAddressFamilyAsString(
276 webrtc::IceCandidatePairAddressFamily family) {
277 switch (family) {
278 case webrtc::IceCandidatePairAddressFamily::kIpv4:
279 return kAddressFamilyIpv4;
280 case webrtc::IceCandidatePairAddressFamily::kIpv6:
281 return kAddressFamilyIpv6;
282 default:
283 return kUnknownEnumValue;
284 }
285}
286
287std::string GetNetworkTypeAsString(webrtc::IceCandidateNetworkType type) {
288 switch (type) {
289 case webrtc::IceCandidateNetworkType::kEthernet:
290 return kNetworkTypeEthernet;
291 case webrtc::IceCandidateNetworkType::kLoopback:
292 return kNetworkTypeLoopback;
293 case webrtc::IceCandidateNetworkType::kWifi:
294 return kNetworkTypeWifi;
295 case webrtc::IceCandidateNetworkType::kVpn:
296 return kNetworkTypeVpn;
297 case webrtc::IceCandidateNetworkType::kCellular:
298 return kNetworkTypeCellular;
299 default:
300 return kUnknownEnumValue;
301 }
302}
303
304std::string GetCandidatePairLogDescriptionAsString(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200305 const LoggedIceCandidatePairConfig& config) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800306 // Example: stun:wifi->relay(tcp):cellular@udp:ipv4
307 // represents a pair of a local server-reflexive candidate on a WiFi network
308 // and a remote relay candidate using TCP as the relay protocol on a cell
309 // network, when the candidate pair communicates over UDP using IPv4.
Jonas Olsson366a50c2018-09-06 13:41:30 +0200310 rtc::StringBuilder ss;
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800311 std::string local_candidate_type =
312 GetIceCandidateTypeAsString(config.local_candidate_type);
313 std::string remote_candidate_type =
314 GetIceCandidateTypeAsString(config.remote_candidate_type);
315 if (config.local_candidate_type == webrtc::IceCandidateType::kRelay) {
316 local_candidate_type +=
317 "(" + GetProtocolAsString(config.local_relay_protocol) + ")";
318 }
319 ss << local_candidate_type << ":"
320 << GetNetworkTypeAsString(config.local_network_type) << ":"
321 << GetAddressFamilyAsString(config.local_address_family) << "->"
322 << remote_candidate_type << ":"
323 << GetAddressFamilyAsString(config.remote_address_family) << "@"
324 << GetProtocolAsString(config.candidate_pair_protocol);
Jonas Olsson84df1c72018-09-14 16:59:32 +0200325 return ss.Release();
Qingsi Wang8eca1ff2018-02-02 11:49:44 -0800326}
327
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200328std::string GetDirectionAsString(PacketDirection direction) {
329 if (direction == kIncomingPacket) {
330 return "Incoming";
331 } else {
332 return "Outgoing";
333 }
334}
335
336std::string GetDirectionAsShortString(PacketDirection direction) {
337 if (direction == kIncomingPacket) {
338 return "In";
339 } else {
340 return "Out";
341 }
342}
343
terelius54ce6802016-07-13 06:44:41 -0700344} // namespace
345
Sebastian Janssonb290a6d2019-01-03 14:46:23 +0100346EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200347 bool normalize_time)
Bjorn Terelius068fc352019-02-13 22:38:25 +0100348 : parsed_log_(log) {
349 config_.window_duration_ = 250000;
350 config_.step_ = 10000;
351 config_.normalize_time_ = normalize_time;
352 config_.begin_time_ = parsed_log_.first_timestamp();
353 config_.end_time_ = parsed_log_.last_timestamp();
354 if (config_.end_time_ < config_.begin_time_) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200355 RTC_LOG(LS_WARNING) << "No useful events in the log.";
Bjorn Terelius068fc352019-02-13 22:38:25 +0100356 config_.begin_time_ = config_.end_time_ = 0;
Björn Tereliusff612732018-04-25 14:23:01 +0000357 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200358
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200359 RTC_LOG(LS_INFO) << "Log is "
360 << (parsed_log_.last_timestamp() -
361 parsed_log_.first_timestamp()) /
362 1000000
363 << " seconds long.";
Bjorn Terelius48b82792020-05-19 10:57:24 +0200364}
365
366EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log,
367 const AnalyzerConfig& config)
368 : parsed_log_(log), config_(config) {
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200369 RTC_LOG(LS_INFO) << "Log is "
370 << (parsed_log_.last_timestamp() -
371 parsed_log_.first_timestamp()) /
372 1000000
373 << " seconds long.";
terelius54ce6802016-07-13 06:44:41 -0700374}
375
Sebastian Jansson5c94f552018-10-15 18:46:51 +0200376class BitrateObserver : public RemoteBitrateObserver {
Stefan Holmer13181032016-07-29 14:48:54 +0200377 public:
378 BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {}
379
Sebastian Jansson5c94f552018-10-15 18:46:51 +0200380 void Update(NetworkControlUpdate update) {
381 if (update.target_rate) {
382 last_bitrate_bps_ = update.target_rate->target_rate.bps();
383 bitrate_updated_ = true;
384 }
Stefan Holmer13181032016-07-29 14:48:54 +0200385 }
386
387 void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
388 uint32_t bitrate) override {}
389
390 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
391 bool GetAndResetBitrateUpdated() {
392 bool bitrate_updated = bitrate_updated_;
393 bitrate_updated_ = false;
394 return bitrate_updated;
395 }
396
397 private:
398 uint32_t last_bitrate_bps_;
399 bool bitrate_updated_;
400};
401
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200402void EventLogAnalyzer::CreatePacketGraph(PacketDirection direction,
terelius54ce6802016-07-13 06:44:41 -0700403 Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200404 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
405 // Filter on SSRC.
406 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -0700407 continue;
terelius54ce6802016-07-13 06:44:41 -0700408 }
terelius54ce6802016-07-13 06:44:41 -0700409
Bjorn Terelius48b82792020-05-19 10:57:24 +0200410 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200411 LineStyle::kBar);
412 auto GetPacketSize = [](const LoggedRtpPacket& packet) {
Danil Chapovalov431abd92018-06-18 12:54:17 +0200413 return absl::optional<float>(packet.total_length);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200414 };
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200415 auto ToCallTime = [this](const LoggedRtpPacket& packet) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100416 return this->config_.GetCallTimeSec(packet.log_time_us());
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200417 };
418 ProcessPoints<LoggedRtpPacket>(ToCallTime, GetPacketSize,
419 stream.packet_view, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700420 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700421 }
422
Bjorn Terelius068fc352019-02-13 22:38:25 +0100423 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
424 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700425 plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin,
426 kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200427 plot->SetTitle(GetDirectionAsString(direction) + " RTP packets");
terelius54ce6802016-07-13 06:44:41 -0700428}
429
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100430void EventLogAnalyzer::CreateRtcpTypeGraph(PacketDirection direction,
431 Plot* plot) {
432 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
433 parsed_log_.transport_feedbacks(direction), config_, "TWCC", 1));
434 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
435 parsed_log_.receiver_reports(direction), config_, "RR", 2));
436 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
437 parsed_log_.sender_reports(direction), config_, "SR", 3));
438 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(
439 parsed_log_.extended_reports(direction), config_, "XR", 4));
440 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.nacks(direction),
441 config_, "NACK", 5));
442 plot->AppendTimeSeries(CreateRtcpTypeTimeSeries(parsed_log_.rembs(direction),
443 config_, "REMB", 6));
444 plot->AppendTimeSeries(
445 CreateRtcpTypeTimeSeries(parsed_log_.firs(direction), config_, "FIR", 7));
446 plot->AppendTimeSeries(
447 CreateRtcpTypeTimeSeries(parsed_log_.plis(direction), config_, "PLI", 8));
448 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
449 "Time (s)", kLeftMargin, kRightMargin);
450 plot->SetSuggestedYAxis(0, 1, "RTCP type", kBottomMargin, kTopMargin);
451 plot->SetTitle(GetDirectionAsString(direction) + " RTCP packets");
Bjorn Tereliusf640b872019-07-24 15:46:39 +0200452 plot->SetYAxisTickLabels({{1, "TWCC"},
453 {2, "RR"},
454 {3, "SR"},
455 {4, "XR"},
456 {5, "NACK"},
457 {6, "REMB"},
458 {7, "FIR"},
459 {8, "PLI"}});
Bjorn Terelius7c974e62019-02-15 17:20:12 +0100460}
461
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200462template <typename IterableType>
philipelccd74892016-09-05 02:46:25 -0700463void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
philipelccd74892016-09-05 02:46:25 -0700464 Plot* plot,
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200465 const IterableType& packets,
466 const std::string& label) {
467 TimeSeries time_series(label, LineStyle::kStep);
468 for (size_t i = 0; i < packets.size(); i++) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100469 float x = config_.GetCallTimeSec(packets[i].log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200470 time_series.points.emplace_back(x, i + 1);
philipelccd74892016-09-05 02:46:25 -0700471 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200472 plot->AppendTimeSeries(std::move(time_series));
philipelccd74892016-09-05 02:46:25 -0700473}
474
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200475void EventLogAnalyzer::CreateAccumulatedPacketsGraph(PacketDirection direction,
476 Plot* plot) {
477 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
478 if (!MatchingSsrc(stream.ssrc, desired_ssrc_))
479 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200480 std::string label = std::string("RTP ") +
481 GetStreamName(parsed_log_, direction, stream.ssrc);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200482 CreateAccumulatedPacketsTimeSeries(plot, stream.packet_view, label);
483 }
484 std::string label =
485 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")";
486 if (direction == kIncomingPacket) {
487 CreateAccumulatedPacketsTimeSeries(
488 plot, parsed_log_.incoming_rtcp_packets(), label);
489 } else {
490 CreateAccumulatedPacketsTimeSeries(
491 plot, parsed_log_.outgoing_rtcp_packets(), label);
492 }
philipelccd74892016-09-05 02:46:25 -0700493
Bjorn Terelius068fc352019-02-13 22:38:25 +0100494 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
495 "Time (s)", kLeftMargin, kRightMargin);
philipelccd74892016-09-05 02:46:25 -0700496 plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200497 plot->SetTitle(std::string("Accumulated ") + GetDirectionAsString(direction) +
498 " RTP/RTCP packets");
philipelccd74892016-09-05 02:46:25 -0700499}
500
Kristoffer Erlandsson283c1062020-03-30 13:01:37 +0200501void EventLogAnalyzer::CreatePacketRateGraph(PacketDirection direction,
502 Plot* plot) {
503 auto CountPackets = [](auto packet) { return 1.0; };
504 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
505 // Filter on SSRC.
506 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
507 continue;
508 }
509 TimeSeries time_series(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200510 std::string("RTP ") +
511 GetStreamName(parsed_log_, direction, stream.ssrc),
Kristoffer Erlandsson283c1062020-03-30 13:01:37 +0200512 LineStyle::kLine);
513 MovingAverage<LoggedRtpPacket, double>(CountPackets, stream.packet_view,
514 config_, &time_series);
515 plot->AppendTimeSeries(std::move(time_series));
516 }
517 TimeSeries time_series(
518 std::string("RTCP ") + "(" + GetDirectionAsShortString(direction) + ")",
519 LineStyle::kLine);
520 if (direction == kIncomingPacket) {
521 MovingAverage<LoggedRtcpPacketIncoming, double>(
522 CountPackets, parsed_log_.incoming_rtcp_packets(), config_,
523 &time_series);
524 } else {
525 MovingAverage<LoggedRtcpPacketOutgoing, double>(
526 CountPackets, parsed_log_.outgoing_rtcp_packets(), config_,
527 &time_series);
528 }
529 plot->AppendTimeSeries(std::move(time_series));
530
531 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
532 "Time (s)", kLeftMargin, kRightMargin);
533 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
534 kTopMargin);
535 plot->SetTitle("Rate of " + GetDirectionAsString(direction) +
536 " RTP/RTCP packets");
537}
538
Kristoffer Erlandssona2ce4232020-04-01 14:33:30 +0200539void EventLogAnalyzer::CreateTotalPacketRateGraph(PacketDirection direction,
540 Plot* plot) {
541 // Contains a log timestamp to enable counting logged events of different
542 // types using MovingAverage().
543 class LogTime {
544 public:
545 explicit LogTime(int64_t log_time_us) : log_time_us_(log_time_us) {}
546
547 int64_t log_time_us() const { return log_time_us_; }
548
549 private:
550 int64_t log_time_us_;
551 };
552
553 std::vector<LogTime> packet_times;
554 auto handle_rtp = [&](const LoggedRtpPacket& packet) {
555 packet_times.emplace_back(packet.log_time_us());
556 };
557 RtcEventProcessor process;
558 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
559 process.AddEvents(stream.packet_view, handle_rtp);
560 }
561 if (direction == kIncomingPacket) {
562 auto handle_incoming_rtcp = [&](const LoggedRtcpPacketIncoming& packet) {
563 packet_times.emplace_back(packet.log_time_us());
564 };
565 process.AddEvents(parsed_log_.incoming_rtcp_packets(),
566 handle_incoming_rtcp);
567 } else {
568 auto handle_outgoing_rtcp = [&](const LoggedRtcpPacketOutgoing& packet) {
569 packet_times.emplace_back(packet.log_time_us());
570 };
571 process.AddEvents(parsed_log_.outgoing_rtcp_packets(),
572 handle_outgoing_rtcp);
573 }
574 process.ProcessEventsInOrder();
575 TimeSeries time_series(std::string("Total ") + "(" +
576 GetDirectionAsShortString(direction) + ") packets",
577 LineStyle::kLine);
578 MovingAverage<LogTime, uint64_t>([](auto packet) { return 1; }, packet_times,
579 config_, &time_series);
580 plot->AppendTimeSeries(std::move(time_series));
581
582 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
583 "Time (s)", kLeftMargin, kRightMargin);
584 plot->SetSuggestedYAxis(0, 1, "Packet Rate (packets/s)", kBottomMargin,
585 kTopMargin);
586 plot->SetTitle("Rate of all " + GetDirectionAsString(direction) +
587 " RTP/RTCP packets");
588}
589
terelius54ce6802016-07-13 06:44:41 -0700590// For each SSRC, plot the time between the consecutive playouts.
591void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200592 for (const auto& playout_stream : parsed_log_.audio_playout_events()) {
593 uint32_t ssrc = playout_stream.first;
594 if (!MatchingSsrc(ssrc, desired_ssrc_))
595 continue;
Danil Chapovalov431abd92018-06-18 12:54:17 +0200596 absl::optional<int64_t> last_playout_ms;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200597 TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar);
Minyue Li27e2b7d2018-05-07 15:20:24 +0200598 for (const auto& playout_event : playout_stream.second) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100599 float x = config_.GetCallTimeSec(playout_event.log_time_us());
Minyue Li27e2b7d2018-05-07 15:20:24 +0200600 int64_t playout_time_ms = playout_event.log_time_ms();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200601 // If there were no previous playouts, place the point on the x-axis.
Minyue Li27e2b7d2018-05-07 15:20:24 +0200602 float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200603 time_series.points.push_back(TimeSeriesPoint(x, y));
Minyue Li27e2b7d2018-05-07 15:20:24 +0200604 last_playout_ms.emplace(playout_time_ms);
terelius54ce6802016-07-13 06:44:41 -0700605 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200606 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700607 }
608
Bjorn Terelius068fc352019-02-13 22:38:25 +0100609 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
610 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700611 plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin,
612 kTopMargin);
613 plot->SetTitle("Audio playout");
terelius54ce6802016-07-13 06:44:41 -0700614}
615
ivocaac9d6f2016-09-22 07:01:47 -0700616// For audio SSRCs, plot the audio level.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200617void EventLogAnalyzer::CreateAudioLevelGraph(PacketDirection direction,
618 Plot* plot) {
619 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
Bjorn Terelius48b82792020-05-19 10:57:24 +0200620 if (!IsAudioSsrc(parsed_log_, direction, stream.ssrc))
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200621 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200622 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200623 LineStyle::kLine);
624 for (auto& packet : stream.packet_view) {
ivocaac9d6f2016-09-22 07:01:47 -0700625 if (packet.header.extension.hasAudioLevel) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100626 float x = config_.GetCallTimeSec(packet.log_time_us());
ivocaac9d6f2016-09-22 07:01:47 -0700627 // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
628 // Here we convert it to dBov.
629 float y = static_cast<float>(-packet.header.extension.audioLevel);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200630 time_series.points.emplace_back(TimeSeriesPoint(x, y));
ivocaac9d6f2016-09-22 07:01:47 -0700631 }
632 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200633 plot->AppendTimeSeries(std::move(time_series));
ivocaac9d6f2016-09-22 07:01:47 -0700634 }
635
Bjorn Terelius068fc352019-02-13 22:38:25 +0100636 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
637 "Time (s)", kLeftMargin, kRightMargin);
Yves Gerey665174f2018-06-19 15:03:05 +0200638 plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200639 plot->SetTitle(GetDirectionAsString(direction) + " audio level");
ivocaac9d6f2016-09-22 07:01:47 -0700640}
641
Konrad Hofbauerca3c8012019-02-15 20:52:19 +0100642// For each SSRC, plot the sequence number difference between consecutive
643// incoming packets.
terelius54ce6802016-07-13 06:44:41 -0700644void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200645 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
646 // Filter on SSRC.
647 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -0700648 continue;
terelius54ce6802016-07-13 06:44:41 -0700649 }
terelius54ce6802016-07-13 06:44:41 -0700650
Bjorn Terelius48b82792020-05-19 10:57:24 +0200651 TimeSeries time_series(
652 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
653 LineStyle::kBar);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200654 auto GetSequenceNumberDiff = [](const LoggedRtpPacketIncoming& old_packet,
655 const LoggedRtpPacketIncoming& new_packet) {
656 int64_t diff =
657 WrappingDifference(new_packet.rtp.header.sequenceNumber,
658 old_packet.rtp.header.sequenceNumber, 1ul << 16);
659 return diff;
660 };
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200661 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100662 return this->config_.GetCallTimeSec(packet.log_time_us());
Stefan Holmer1d4a2272018-05-24 13:48:09 +0200663 };
664 ProcessPairs<LoggedRtpPacketIncoming, float>(
665 ToCallTime, GetSequenceNumberDiff, stream.incoming_packets,
666 &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700667 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700668 }
669
Bjorn Terelius068fc352019-02-13 22:38:25 +0100670 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
671 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -0700672 plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
673 kTopMargin);
Konrad Hofbauerca3c8012019-02-15 20:52:19 +0100674 plot->SetTitle("Incoming sequence number delta");
terelius54ce6802016-07-13 06:44:41 -0700675}
676
Stefan Holmer99f8e082016-09-09 13:37:50 +0200677void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200678 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
679 const std::vector<LoggedRtpPacketIncoming>& packets =
680 stream.incoming_packets;
681 // Filter on SSRC.
Mirko Bonadei1f173152019-07-25 15:28:14 +0200682 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) || packets.empty()) {
Stefan Holmer99f8e082016-09-09 13:37:50 +0200683 continue;
684 }
685
Bjorn Terelius48b82792020-05-19 10:57:24 +0200686 TimeSeries time_series(
687 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc),
688 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200689 // TODO(terelius): Should the window and step size be read from the class
690 // instead?
691 const int64_t kWindowUs = 1000000;
692 const int64_t kStep = 1000000;
Bjorn Terelius2eb31882017-11-30 15:15:25 +0100693 SeqNumUnwrapper<uint16_t> unwrapper_;
694 SeqNumUnwrapper<uint16_t> prior_unwrapper_;
terelius4c9b4af2017-01-30 08:44:51 -0800695 size_t window_index_begin = 0;
696 size_t window_index_end = 0;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200697 uint64_t highest_seq_number =
698 unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
699 uint64_t highest_prior_seq_number =
700 prior_unwrapper_.Unwrap(packets[0].rtp.header.sequenceNumber) - 1;
terelius4c9b4af2017-01-30 08:44:51 -0800701
Bjorn Terelius068fc352019-02-13 22:38:25 +0100702 for (int64_t t = config_.begin_time_; t < config_.end_time_ + kStep;
703 t += kStep) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200704 while (window_index_end < packets.size() &&
705 packets[window_index_end].rtp.log_time_us() < t) {
706 uint64_t sequence_number = unwrapper_.Unwrap(
707 packets[window_index_end].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 08:44:51 -0800708 highest_seq_number = std::max(highest_seq_number, sequence_number);
709 ++window_index_end;
Stefan Holmer99f8e082016-09-09 13:37:50 +0200710 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200711 while (window_index_begin < packets.size() &&
712 packets[window_index_begin].rtp.log_time_us() < t - kWindowUs) {
713 uint64_t sequence_number = prior_unwrapper_.Unwrap(
714 packets[window_index_begin].rtp.header.sequenceNumber);
terelius4c9b4af2017-01-30 08:44:51 -0800715 highest_prior_seq_number =
716 std::max(highest_prior_seq_number, sequence_number);
717 ++window_index_begin;
718 }
Bjorn Terelius068fc352019-02-13 22:38:25 +0100719 float x = config_.GetCallTimeSec(t);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200720 uint64_t expected_packets = highest_seq_number - highest_prior_seq_number;
terelius4c9b4af2017-01-30 08:44:51 -0800721 if (expected_packets > 0) {
722 int64_t received_packets = window_index_end - window_index_begin;
723 int64_t lost_packets = expected_packets - received_packets;
724 float y = static_cast<float>(lost_packets) / expected_packets * 100;
725 time_series.points.emplace_back(x, y);
726 }
Stefan Holmer99f8e082016-09-09 13:37:50 +0200727 }
philipel35ba9bd2017-04-19 05:58:51 -0700728 plot->AppendTimeSeries(std::move(time_series));
Stefan Holmer99f8e082016-09-09 13:37:50 +0200729 }
730
Bjorn Terelius068fc352019-02-13 22:38:25 +0100731 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
732 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 16:17:28 +0100733 plot->SetSuggestedYAxis(0, 1, "Loss rate (in %)", kBottomMargin, kTopMargin);
734 plot->SetTitle("Incoming packet loss (derived from incoming packets)");
Stefan Holmer99f8e082016-09-09 13:37:50 +0200735}
736
terelius2ee076d2017-08-15 02:04:02 -0700737void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100738 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200739 // Filter on SSRC.
740 if (!MatchingSsrc(stream.ssrc, desired_ssrc_) ||
Bjorn Terelius48b82792020-05-19 10:57:24 +0200741 IsRtxSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
terelius88e64e52016-07-19 01:51:06 -0700742 continue;
743 }
terelius54ce6802016-07-13 06:44:41 -0700744
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100745 const std::vector<LoggedRtpPacketIncoming>& packets =
746 stream.incoming_packets;
747 if (packets.size() < 100) {
748 RTC_LOG(LS_WARNING) << "Can't estimate the RTP clock frequency with "
749 << packets.size() << " packets in the stream.";
750 continue;
751 }
Björn Terelius0d1b28c2020-05-27 20:25:06 +0200752 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100753 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 10:57:24 +0200754 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100755 if (!estimated_frequency)
756 continue;
757 const double frequency_hz = *estimated_frequency;
Bjorn Terelius48b82792020-05-19 10:57:24 +0200758 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc) &&
759 frequency_hz != 90000) {
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100760 RTC_LOG(LS_WARNING)
761 << "Video stream should use a 90 kHz clock but appears to use "
762 << frequency_hz / 1000 << ". Discarding.";
763 continue;
764 }
765
766 auto ToCallTime = [this](const LoggedRtpPacketIncoming& packet) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100767 return this->config_.GetCallTimeSec(packet.log_time_us());
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100768 };
769 auto ToNetworkDelay = [frequency_hz](
770 const LoggedRtpPacketIncoming& old_packet,
771 const LoggedRtpPacketIncoming& new_packet) {
772 return NetworkDelayDiff_CaptureTime(old_packet, new_packet, frequency_hz);
773 };
774
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200775 TimeSeries capture_time_data(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200776 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
777 " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200778 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100779 AccumulatePairs<LoggedRtpPacketIncoming, double>(
780 ToCallTime, ToNetworkDelay, packets, &capture_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700781 plot->AppendTimeSeries(std::move(capture_time_data));
terelius88e64e52016-07-19 01:51:06 -0700782
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200783 TimeSeries send_time_data(
Bjorn Terelius48b82792020-05-19 10:57:24 +0200784 GetStreamName(parsed_log_, kIncomingPacket, stream.ssrc) +
785 " abs-send-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200786 LineStyle::kLine);
Bjorn Terelius6c373cc2018-11-01 14:31:10 +0100787 AccumulatePairs<LoggedRtpPacketIncoming, double>(
788 ToCallTime, NetworkDelayDiff_AbsSendTime, packets, &send_time_data);
789 plot->AppendTimeSeriesIfNotEmpty(std::move(send_time_data));
terelius54ce6802016-07-13 06:44:41 -0700790 }
791
Bjorn Terelius068fc352019-02-13 22:38:25 +0100792 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
793 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauer5be3bbd2019-01-21 12:31:07 +0100794 plot->SetSuggestedYAxis(0, 1, "Delay (ms)", kBottomMargin, kTopMargin);
795 plot->SetTitle("Incoming network delay (relative to first packet)");
terelius54ce6802016-07-13 06:44:41 -0700796}
797
tereliusf736d232016-08-04 10:00:11 -0700798// Plot the fraction of packets lost (as perceived by the loss-based BWE).
799void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +0100800 TimeSeries time_series("Fraction lost", LineStyle::kLine,
801 PointStyle::kHighlight);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200802 for (auto& bwe_update : parsed_log_.bwe_loss_updates()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100803 float x = config_.GetCallTimeSec(bwe_update.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200804 float y = static_cast<float>(bwe_update.fraction_lost) / 255 * 100;
philipel35ba9bd2017-04-19 05:58:51 -0700805 time_series.points.emplace_back(x, y);
tereliusf736d232016-08-04 10:00:11 -0700806 }
tereliusf736d232016-08-04 10:00:11 -0700807
Bjorn Terelius19f5be32017-10-18 12:39:49 +0200808 plot->AppendTimeSeries(std::move(time_series));
Bjorn Terelius068fc352019-02-13 22:38:25 +0100809 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
810 "Time (s)", kLeftMargin, kRightMargin);
Konrad Hofbauerd036c652019-02-14 16:17:28 +0100811 plot->SetSuggestedYAxis(0, 10, "Loss rate (in %)", kBottomMargin, kTopMargin);
812 plot->SetTitle("Outgoing packet loss (as reported by BWE)");
tereliusf736d232016-08-04 10:00:11 -0700813}
814
terelius54ce6802016-07-13 06:44:41 -0700815// Plot the total bandwidth used by all RTP streams.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200816void EventLogAnalyzer::CreateTotalIncomingBitrateGraph(Plot* plot) {
817 // TODO(terelius): This could be provided by the parser.
818 std::multimap<int64_t, size_t> packets_in_order;
819 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
820 for (const LoggedRtpPacketIncoming& packet : stream.incoming_packets)
821 packets_in_order.insert(
822 std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
terelius54ce6802016-07-13 06:44:41 -0700823 }
824
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200825 auto window_begin = packets_in_order.begin();
826 auto window_end = packets_in_order.begin();
terelius54ce6802016-07-13 06:44:41 -0700827 size_t bytes_in_window = 0;
terelius54ce6802016-07-13 06:44:41 -0700828
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800829 if (!packets_in_order.empty()) {
830 // Calculate a moving average of the bitrate and store in a TimeSeries.
831 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
832 for (int64_t time = config_.begin_time_;
833 time < config_.end_time_ + config_.step_; time += config_.step_) {
834 while (window_end != packets_in_order.end() && window_end->first < time) {
835 bytes_in_window += window_end->second;
836 ++window_end;
837 }
838 while (window_begin != packets_in_order.end() &&
839 window_begin->first < time - config_.window_duration_) {
840 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
841 bytes_in_window -= window_begin->second;
842 ++window_begin;
843 }
844 float window_duration_in_seconds =
845 static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
846 float x = config_.GetCallTimeSec(time);
847 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
848 bitrate_series.points.emplace_back(x, y);
terelius54ce6802016-07-13 06:44:41 -0700849 }
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800850 plot->AppendTimeSeries(std::move(bitrate_series));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200851 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200852
853 // Overlay the outgoing REMB over incoming bitrate.
854 TimeSeries remb_series("Remb", LineStyle::kStep);
855 for (const auto& rtcp : parsed_log_.rembs(kOutgoingPacket)) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100856 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200857 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
858 remb_series.points.emplace_back(x, y);
859 }
860 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
861
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800862 if (!parsed_log_.generic_packets_received().empty()) {
863 TimeSeries time_series("Incoming generic bitrate", LineStyle::kLine);
864 auto GetPacketSizeKilobits = [](const LoggedGenericPacketReceived& packet) {
865 return packet.packet_length * 8.0 / 1000.0;
866 };
867 MovingAverage<LoggedGenericPacketReceived, double>(
868 GetPacketSizeKilobits, parsed_log_.generic_packets_received(), config_,
869 &time_series);
870 plot->AppendTimeSeries(std::move(time_series));
871 }
872
Bjorn Terelius068fc352019-02-13 22:38:25 +0100873 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
874 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200875 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
876 plot->SetTitle("Incoming RTP bitrate");
877}
878
879// Plot the total bandwidth used by all RTP streams.
880void EventLogAnalyzer::CreateTotalOutgoingBitrateGraph(Plot* plot,
881 bool show_detector_state,
882 bool show_alr_state) {
883 // TODO(terelius): This could be provided by the parser.
884 std::multimap<int64_t, size_t> packets_in_order;
885 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
886 for (const LoggedRtpPacketOutgoing& packet : stream.outgoing_packets)
887 packets_in_order.insert(
888 std::make_pair(packet.rtp.log_time_us(), packet.rtp.total_length));
889 }
890
891 auto window_begin = packets_in_order.begin();
892 auto window_end = packets_in_order.begin();
893 size_t bytes_in_window = 0;
894
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800895 if (!packets_in_order.empty()) {
896 // Calculate a moving average of the bitrate and store in a TimeSeries.
897 TimeSeries bitrate_series("Bitrate", LineStyle::kLine);
898 for (int64_t time = config_.begin_time_;
899 time < config_.end_time_ + config_.step_; time += config_.step_) {
900 while (window_end != packets_in_order.end() && window_end->first < time) {
901 bytes_in_window += window_end->second;
902 ++window_end;
903 }
904 while (window_begin != packets_in_order.end() &&
905 window_begin->first < time - config_.window_duration_) {
906 RTC_DCHECK_LE(window_begin->second, bytes_in_window);
907 bytes_in_window -= window_begin->second;
908 ++window_begin;
909 }
910 float window_duration_in_seconds =
911 static_cast<float>(config_.window_duration_) / kNumMicrosecsPerSec;
912 float x = config_.GetCallTimeSec(time);
913 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
914 bitrate_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200915 }
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -0800916 plot->AppendTimeSeries(std::move(bitrate_series));
terelius54ce6802016-07-13 06:44:41 -0700917 }
918
terelius8058e582016-07-25 01:32:41 -0700919 // Overlay the send-side bandwidth estimate over the outgoing bitrate.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200920 TimeSeries loss_series("Loss-based estimate", LineStyle::kStep);
921 for (auto& loss_update : parsed_log_.bwe_loss_updates()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100922 float x = config_.GetCallTimeSec(loss_update.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200923 float y = static_cast<float>(loss_update.bitrate_bps) / 1000;
924 loss_series.points.emplace_back(x, y);
925 }
philipel10fc0e62017-04-11 01:50:23 -0700926
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200927 TimeSeries delay_series("Delay-based estimate", LineStyle::kStep);
928 IntervalSeries overusing_series("Overusing", "#ff8e82",
929 IntervalSeries::kHorizontal);
930 IntervalSeries underusing_series("Underusing", "#5092fc",
931 IntervalSeries::kHorizontal);
932 IntervalSeries normal_series("Normal", "#c4ffc4",
933 IntervalSeries::kHorizontal);
934 IntervalSeries* last_series = &normal_series;
935 double last_detector_switch = 0.0;
philipel23c7f252017-07-14 06:30:03 -0700936
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200937 BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal;
philipel23c7f252017-07-14 06:30:03 -0700938
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200939 for (auto& delay_update : parsed_log_.bwe_delay_updates()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100940 float x = config_.GetCallTimeSec(delay_update.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200941 float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
philipel23c7f252017-07-14 06:30:03 -0700942
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200943 if (last_detector_state != delay_update.detector_state) {
944 last_series->intervals.emplace_back(last_detector_switch, x);
945 last_detector_state = delay_update.detector_state;
946 last_detector_switch = x;
philipel23c7f252017-07-14 06:30:03 -0700947
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200948 switch (delay_update.detector_state) {
949 case BandwidthUsage::kBwNormal:
950 last_series = &normal_series;
951 break;
952 case BandwidthUsage::kBwUnderusing:
953 last_series = &underusing_series;
954 break;
955 case BandwidthUsage::kBwOverusing:
956 last_series = &overusing_series;
957 break;
958 case BandwidthUsage::kLast:
959 RTC_NOTREACHED();
philipele127e7a2017-03-29 16:28:53 +0200960 }
961 }
philipel23c7f252017-07-14 06:30:03 -0700962
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200963 delay_series.points.emplace_back(x, y);
964 }
Bjorn Terelius9e336ec2018-04-24 16:28:35 +0200965
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200966 RTC_CHECK(last_series);
Bjorn Terelius068fc352019-02-13 22:38:25 +0100967 last_series->intervals.emplace_back(last_detector_switch, config_.end_time_);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200968
969 TimeSeries created_series("Probe cluster created.", LineStyle::kNone,
970 PointStyle::kHighlight);
971 for (auto& cluster : parsed_log_.bwe_probe_cluster_created_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100972 float x = config_.GetCallTimeSec(cluster.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200973 float y = static_cast<float>(cluster.bitrate_bps) / 1000;
974 created_series.points.emplace_back(x, y);
975 }
976
977 TimeSeries result_series("Probing results.", LineStyle::kNone,
978 PointStyle::kHighlight);
Bjorn Terelius7a0bb002018-05-29 14:45:53 +0200979 for (auto& result : parsed_log_.bwe_probe_success_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100980 float x = config_.GetCallTimeSec(result.log_time_us());
Bjorn Terelius7a0bb002018-05-29 14:45:53 +0200981 float y = static_cast<float>(result.bitrate_bps) / 1000;
982 result_series.points.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200983 }
984
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -0800985 TimeSeries probe_failures_series("Probe failed", LineStyle::kNone,
986 PointStyle::kHighlight);
987 for (auto& failure : parsed_log_.bwe_probe_failure_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100988 float x = config_.GetCallTimeSec(failure.log_time_us());
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -0800989 probe_failures_series.points.emplace_back(x, 0);
990 }
991
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200992 IntervalSeries alr_state("ALR", "#555555", IntervalSeries::kHorizontal);
993 bool previously_in_alr = false;
994 int64_t alr_start = 0;
995 for (auto& alr : parsed_log_.alr_state_events()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +0100996 float y = config_.GetCallTimeSec(alr.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +0200997 if (!previously_in_alr && alr.in_alr) {
998 alr_start = alr.log_time_us();
999 previously_in_alr = true;
1000 } else if (previously_in_alr && !alr.in_alr) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001001 float x = config_.GetCallTimeSec(alr_start);
Ilya Nikolaevskiya4259f62017-12-05 13:19:45 +01001002 alr_state.intervals.emplace_back(x, y);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001003 previously_in_alr = false;
Björn Tereliusff612732018-04-25 14:23:01 +00001004 }
Björn Tereliusff612732018-04-25 14:23:01 +00001005 }
1006
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001007 if (previously_in_alr) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001008 float x = config_.GetCallTimeSec(alr_start);
1009 float y = config_.GetCallTimeSec(config_.end_time_);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001010 alr_state.intervals.emplace_back(x, y);
1011 }
1012
1013 if (show_detector_state) {
1014 plot->AppendIntervalSeries(std::move(overusing_series));
1015 plot->AppendIntervalSeries(std::move(underusing_series));
1016 plot->AppendIntervalSeries(std::move(normal_series));
1017 }
1018
1019 if (show_alr_state) {
1020 plot->AppendIntervalSeries(std::move(alr_state));
1021 }
1022 plot->AppendTimeSeries(std::move(loss_series));
Piotr (Peter) Slatalaf996c842019-01-04 06:54:22 -08001023 plot->AppendTimeSeriesIfNotEmpty(std::move(probe_failures_series));
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001024 plot->AppendTimeSeries(std::move(delay_series));
1025 plot->AppendTimeSeries(std::move(created_series));
1026 plot->AppendTimeSeries(std::move(result_series));
1027
1028 // Overlay the incoming REMB over the outgoing bitrate.
Björn Tereliusff612732018-04-25 14:23:01 +00001029 TimeSeries remb_series("Remb", LineStyle::kStep);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001030 for (const auto& rtcp : parsed_log_.rembs(kIncomingPacket)) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001031 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001032 float y = static_cast<float>(rtcp.remb.bitrate_bps()) / 1000;
terelius2c8e8a32017-06-02 01:29:48 -07001033 remb_series.points.emplace_back(x, y);
1034 }
1035 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
1036
Piotr (Peter) Slatalacf8405e2019-02-14 13:44:57 -08001037 if (!parsed_log_.generic_packets_sent().empty()) {
1038 {
1039 TimeSeries time_series("Outgoing generic total bitrate",
1040 LineStyle::kLine);
1041 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1042 return packet.packet_length() * 8.0 / 1000.0;
1043 };
1044 MovingAverage<LoggedGenericPacketSent, double>(
1045 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1046 &time_series);
1047 plot->AppendTimeSeries(std::move(time_series));
1048 }
1049
1050 {
1051 TimeSeries time_series("Outgoing generic payload bitrate",
1052 LineStyle::kLine);
1053 auto GetPacketSizeKilobits = [](const LoggedGenericPacketSent& packet) {
1054 return packet.payload_length * 8.0 / 1000.0;
1055 };
1056 MovingAverage<LoggedGenericPacketSent, double>(
1057 GetPacketSizeKilobits, parsed_log_.generic_packets_sent(), config_,
1058 &time_series);
1059 plot->AppendTimeSeries(std::move(time_series));
1060 }
1061 }
1062
Bjorn Terelius068fc352019-02-13 22:38:25 +01001063 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1064 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001065 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001066 plot->SetTitle("Outgoing RTP bitrate");
terelius54ce6802016-07-13 06:44:41 -07001067}
1068
1069// For each SSRC, plot the bandwidth used by that stream.
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001070void EventLogAnalyzer::CreateStreamBitrateGraph(PacketDirection direction,
1071 Plot* plot) {
1072 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1073 // Filter on SSRC.
1074 if (!MatchingSsrc(stream.ssrc, desired_ssrc_)) {
terelius6addf492016-08-23 17:34:07 -07001075 continue;
terelius54ce6802016-07-13 06:44:41 -07001076 }
1077
Bjorn Terelius48b82792020-05-19 10:57:24 +02001078 TimeSeries time_series(GetStreamName(parsed_log_, direction, stream.ssrc),
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001079 LineStyle::kLine);
1080 auto GetPacketSizeKilobits = [](const LoggedRtpPacket& packet) {
1081 return packet.total_length * 8.0 / 1000.0;
1082 };
terelius53dc23c2017-03-13 05:24:05 -07001083 MovingAverage<LoggedRtpPacket, double>(
Bjorn Terelius068fc352019-02-13 22:38:25 +01001084 GetPacketSizeKilobits, stream.packet_view, config_, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -07001085 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -07001086 }
1087
Bjorn Terelius068fc352019-02-13 22:38:25 +01001088 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1089 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001090 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001091 plot->SetTitle(GetDirectionAsString(direction) + " bitrate per stream");
terelius54ce6802016-07-13 06:44:41 -07001092}
1093
Bjorn Terelius9775a582019-02-15 17:29:58 +01001094// Plot the bitrate allocation for each temporal and spatial layer.
1095// Computed from RTCP XR target bitrate block, so the graph is only populated if
1096// those are sent.
1097void EventLogAnalyzer::CreateBitrateAllocationGraph(PacketDirection direction,
1098 Plot* plot) {
1099 std::map<LayerDescription, TimeSeries> time_series;
1100 const auto& xr_list = parsed_log_.extended_reports(direction);
1101 for (const auto& rtcp : xr_list) {
1102 const absl::optional<rtcp::TargetBitrate>& target_bitrate =
1103 rtcp.xr.target_bitrate();
1104 if (!target_bitrate.has_value())
1105 continue;
1106 for (const auto& bitrate_item : target_bitrate->GetTargetBitrates()) {
1107 LayerDescription layer(rtcp.xr.sender_ssrc(), bitrate_item.spatial_layer,
1108 bitrate_item.temporal_layer);
1109 auto time_series_it = time_series.find(layer);
1110 if (time_series_it == time_series.end()) {
1111 std::string layer_name = GetLayerName(layer);
1112 bool inserted;
1113 std::tie(time_series_it, inserted) = time_series.insert(
1114 std::make_pair(layer, TimeSeries(layer_name, LineStyle::kStep)));
1115 RTC_DCHECK(inserted);
1116 }
1117 float x = config_.GetCallTimeSec(rtcp.log_time_us());
1118 float y = bitrate_item.target_bitrate_kbps;
1119 time_series_it->second.points.emplace_back(x, y);
1120 }
1121 }
1122 for (auto& layer : time_series) {
1123 plot->AppendTimeSeries(std::move(layer.second));
1124 }
1125 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1126 "Time (s)", kLeftMargin, kRightMargin);
1127 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1128 if (direction == kIncomingPacket)
1129 plot->SetTitle("Target bitrate per incoming layer");
1130 else
1131 plot->SetTitle("Target bitrate per outgoing layer");
1132}
1133
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001134void EventLogAnalyzer::CreateGoogCcSimulationGraph(Plot* plot) {
1135 TimeSeries target_rates("Simulated target rate", LineStyle::kStep,
1136 PointStyle::kHighlight);
1137 TimeSeries delay_based("Logged delay-based estimate", LineStyle::kStep,
1138 PointStyle::kHighlight);
1139 TimeSeries loss_based("Logged loss-based estimate", LineStyle::kStep,
1140 PointStyle::kHighlight);
1141 TimeSeries probe_results("Logged probe success", LineStyle::kNone,
1142 PointStyle::kHighlight);
1143
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001144 LogBasedNetworkControllerSimulation simulation(
Mirko Bonadei317a1f02019-09-17 17:06:18 +02001145 std::make_unique<GoogCcNetworkControllerFactory>(),
Sebastian Jansson1175ae02019-03-13 08:56:58 +01001146 [&](const NetworkControlUpdate& update, Timestamp at_time) {
1147 if (update.target_rate) {
1148 target_rates.points.emplace_back(
1149 config_.GetCallTimeSec(at_time.us()),
1150 update.target_rate->target_rate.kbps<float>());
1151 }
1152 });
1153
1154 simulation.ProcessEventsInLog(parsed_log_);
1155 for (const auto& logged : parsed_log_.bwe_delay_updates())
1156 delay_based.points.emplace_back(
1157 config_.GetCallTimeSec(logged.log_time_us()),
1158 logged.bitrate_bps / 1000);
1159 for (const auto& logged : parsed_log_.bwe_probe_success_events())
1160 probe_results.points.emplace_back(
1161 config_.GetCallTimeSec(logged.log_time_us()),
1162 logged.bitrate_bps / 1000);
1163 for (const auto& logged : parsed_log_.bwe_loss_updates())
1164 loss_based.points.emplace_back(config_.GetCallTimeSec(logged.log_time_us()),
1165 logged.bitrate_bps / 1000);
1166
1167 plot->AppendTimeSeries(std::move(delay_based));
1168 plot->AppendTimeSeries(std::move(loss_based));
1169 plot->AppendTimeSeries(std::move(probe_results));
1170 plot->AppendTimeSeries(std::move(target_rates));
1171
1172 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1173 "Time (s)", kLeftMargin, kRightMargin);
1174 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1175 plot->SetTitle("Simulated BWE behavior");
1176}
1177
Bjorn Terelius28db2662017-10-04 14:22:43 +02001178void EventLogAnalyzer::CreateSendSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001179 using RtpPacketType = LoggedRtpPacketOutgoing;
1180 using TransportFeedbackType = LoggedRtcpPacketTransportFeedback;
Stefan Holmer13181032016-07-29 14:48:54 +02001181
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001182 // TODO(terelius): This could be provided by the parser.
1183 std::multimap<int64_t, const RtpPacketType*> outgoing_rtp;
1184 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1185 for (const RtpPacketType& rtp_packet : stream.outgoing_packets)
1186 outgoing_rtp.insert(
1187 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Stefan Holmer13181032016-07-29 14:48:54 +02001188 }
1189
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001190 const std::vector<TransportFeedbackType>& incoming_rtcp =
1191 parsed_log_.transport_feedbacks(kIncomingPacket);
Stefan Holmer13181032016-07-29 14:48:54 +02001192
1193 SimulatedClock clock(0);
1194 BitrateObserver observer;
Danil Chapovalov83bbe912019-08-07 12:24:53 +02001195 RtcEventLogNull null_event_log;
nisse0245da02016-11-30 03:35:20 -08001196 PacketRouter packet_router;
Stefan Holmer5c8942a2017-08-22 16:16:44 +02001197 PacedSender pacer(&clock, &packet_router, &null_event_log);
Sebastian Jansson05acd2b2019-01-21 13:07:47 +01001198 TransportFeedbackAdapter transport_feedback;
Sebastian Jansson2db5fc02019-04-30 14:17:45 +02001199 auto factory = GoogCcNetworkControllerFactory();
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001200 TimeDelta process_interval = factory.GetProcessInterval();
Stefan Holmer13181032016-07-29 14:48:54 +02001201 // TODO(holmer): Log the call config and use that here instead.
1202 static const uint32_t kDefaultStartBitrateBps = 300000;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001203 NetworkControllerConfig cc_config;
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001204 cc_config.constraints.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Danil Chapovalovcad3e0e2020-02-17 18:46:07 +01001205 cc_config.constraints.starting_rate =
1206 DataRate::BitsPerSec(kDefaultStartBitrateBps);
Sebastian Jansson2db5fc02019-04-30 14:17:45 +02001207 cc_config.event_log = &null_event_log;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001208 auto goog_cc = factory.Create(cc_config);
Stefan Holmer13181032016-07-29 14:48:54 +02001209
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001210 TimeSeries time_series("Delay-based estimate", LineStyle::kStep,
1211 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001212 TimeSeries acked_time_series("Raw acked bitrate", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001213 PointStyle::kHighlight);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001214 TimeSeries robust_time_series("Robust throughput estimate", LineStyle::kLine,
1215 PointStyle::kHighlight);
1216 TimeSeries acked_estimate_time_series("Ackednowledged bitrate estimate",
1217 LineStyle::kLine,
1218 PointStyle::kHighlight);
Stefan Holmer13181032016-07-29 14:48:54 +02001219
1220 auto rtp_iterator = outgoing_rtp.begin();
1221 auto rtcp_iterator = incoming_rtcp.begin();
1222
1223 auto NextRtpTime = [&]() {
1224 if (rtp_iterator != outgoing_rtp.end())
1225 return static_cast<int64_t>(rtp_iterator->first);
1226 return std::numeric_limits<int64_t>::max();
1227 };
1228
1229 auto NextRtcpTime = [&]() {
1230 if (rtcp_iterator != incoming_rtcp.end())
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001231 return static_cast<int64_t>(rtcp_iterator->log_time_us());
Stefan Holmer13181032016-07-29 14:48:54 +02001232 return std::numeric_limits<int64_t>::max();
1233 };
Bjorn Tereliusa728c912018-12-06 12:26:30 +01001234 int64_t next_process_time_us_ = std::min({NextRtpTime(), NextRtcpTime()});
Stefan Holmer13181032016-07-29 14:48:54 +02001235
1236 auto NextProcessTime = [&]() {
1237 if (rtcp_iterator != incoming_rtcp.end() ||
1238 rtp_iterator != outgoing_rtp.end()) {
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001239 return next_process_time_us_;
Stefan Holmer13181032016-07-29 14:48:54 +02001240 }
1241 return std::numeric_limits<int64_t>::max();
1242 };
1243
Björn Tereliusae1892d2020-06-17 11:55:55 +02001244 RateStatistics acked_bitrate(750, 8000);
1245 test::ExplicitKeyValueConfig throughput_config(
1246 "WebRTC-Bwe-RobustThroughputEstimatorSettings/"
1247 "enabled:true,reduce_bias:true,assume_shared_link:false,initial_packets:"
1248 "10,min_packets:25,window_duration:750ms,unacked_weight:0.5/");
1249 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1250 robust_throughput_estimator(
1251 AcknowledgedBitrateEstimatorInterface::Create(&throughput_config));
1252 FieldTrialBasedConfig field_trial_config;
Björn Terelius251b0dc2019-11-11 21:00:18 +01001253 std::unique_ptr<AcknowledgedBitrateEstimatorInterface>
1254 acknowledged_bitrate_estimator(
Björn Tereliusae1892d2020-06-17 11:55:55 +02001255 AcknowledgedBitrateEstimatorInterface::Create(&field_trial_config));
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001256 int64_t time_us =
1257 std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
Stefan Holmer492ee282016-10-27 17:19:20 +02001258 int64_t last_update_us = 0;
Stefan Holmer13181032016-07-29 14:48:54 +02001259 while (time_us != std::numeric_limits<int64_t>::max()) {
1260 clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001261 if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1262 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1263 const RtpPacketType& rtp_packet = *rtp_iterator->second;
1264 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
Erik Språng30a276b2019-04-23 12:00:11 +02001265 RtpPacketSendInfo packet_info;
1266 packet_info.ssrc = rtp_packet.rtp.header.ssrc;
Bjorn Tereliusf2e9cab2019-05-27 16:44:09 +02001267 packet_info.transport_sequence_number =
Erik Språng30a276b2019-04-23 12:00:11 +02001268 rtp_packet.rtp.header.extension.transportSequenceNumber;
1269 packet_info.rtp_sequence_number = rtp_packet.rtp.header.sequenceNumber;
Erik Språng30a276b2019-04-23 12:00:11 +02001270 packet_info.length = rtp_packet.rtp.total_length;
Björn Tereliusae1892d2020-06-17 11:55:55 +02001271 if (IsRtxSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1272 rtp_packet.rtp.header.ssrc)) {
1273 // Don't set the optional media type as we don't know if it is
1274 // a retransmission, FEC or padding.
1275 } else if (IsVideoSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1276 rtp_packet.rtp.header.ssrc)) {
1277 packet_info.packet_type = RtpPacketMediaType::kVideo;
1278 } else if (IsAudioSsrc(parsed_log_, PacketDirection::kOutgoingPacket,
1279 rtp_packet.rtp.header.ssrc)) {
1280 packet_info.packet_type = RtpPacketMediaType::kAudio;
1281 }
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001282 transport_feedback.AddPacket(
Erik Språng30a276b2019-04-23 12:00:11 +02001283 packet_info,
1284 0u, // Per packet overhead bytes.
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001285 Timestamp::Micros(rtp_packet.rtp.log_time_us()));
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001286 }
Björn Tereliusae1892d2020-06-17 11:55:55 +02001287 rtc::SentPacket sent_packet;
1288 sent_packet.send_time_ms = rtp_packet.rtp.log_time_ms();
1289 sent_packet.info.included_in_allocation = true;
1290 sent_packet.info.packet_size_bytes = rtp_packet.rtp.total_length;
1291 if (rtp_packet.rtp.header.extension.hasTransportSequenceNumber) {
1292 sent_packet.packet_id =
1293 rtp_packet.rtp.header.extension.transportSequenceNumber;
1294 sent_packet.info.included_in_feedback = true;
1295 }
1296 auto sent_msg = transport_feedback.ProcessSentPacket(sent_packet);
1297 if (sent_msg)
1298 observer.Update(goog_cc->OnSentPacket(*sent_msg));
Bjorn Tereliusc60a7772018-12-05 21:15:30 +01001299 ++rtp_iterator;
1300 }
Stefan Holmer13181032016-07-29 14:48:54 +02001301 if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
stefanc3de0332016-08-02 07:22:17 -07001302 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001303
1304 auto feedback_msg = transport_feedback.ProcessTransportFeedback(
Sebastian Jansson05acd2b2019-01-21 13:07:47 +01001305 rtcp_iterator->transport_feedback,
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001306 Timestamp::Millis(clock.TimeInMilliseconds()));
Danil Chapovalov431abd92018-06-18 12:54:17 +02001307 absl::optional<uint32_t> bitrate_bps;
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001308 if (feedback_msg) {
1309 observer.Update(goog_cc->OnTransportPacketsFeedback(*feedback_msg));
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001310 std::vector<PacketResult> feedback =
1311 feedback_msg->SortedByReceiveTime();
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001312 if (!feedback.empty()) {
Björn Terelius251b0dc2019-11-11 21:00:18 +01001313 acknowledged_bitrate_estimator->IncomingPacketFeedbackVector(
1314 feedback);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001315 robust_throughput_estimator->IncomingPacketFeedbackVector(feedback);
1316 for (const PacketResult& packet : feedback) {
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001317 acked_bitrate.Update(packet.sent_packet.size.bytes(),
1318 packet.receive_time.ms());
Björn Tereliusae1892d2020-06-17 11:55:55 +02001319 }
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001320 bitrate_bps = acked_bitrate.Rate(feedback.back().receive_time.ms());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001321 }
Stefan Holmer13181032016-07-29 14:48:54 +02001322 }
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001323
Bjorn Terelius068fc352019-02-13 22:38:25 +01001324 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001325 float y = bitrate_bps.value_or(0) / 1000;
1326 acked_time_series.points.emplace_back(x, y);
Björn Tereliusae1892d2020-06-17 11:55:55 +02001327 y = robust_throughput_estimator->bitrate()
1328 .value_or(DataRate::Zero())
1329 .kbps();
1330 robust_time_series.points.emplace_back(x, y);
Björn Terelius251b0dc2019-11-11 21:00:18 +01001331 y = acknowledged_bitrate_estimator->bitrate()
Sebastian Jansson88290ae2019-06-20 12:26:31 +02001332 .value_or(DataRate::Zero())
1333 .kbps();
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001334 acked_estimate_time_series.points.emplace_back(x, y);
Stefan Holmer13181032016-07-29 14:48:54 +02001335 ++rtcp_iterator;
1336 }
stefanc3de0332016-08-02 07:22:17 -07001337 if (clock.TimeInMicroseconds() >= NextProcessTime()) {
1338 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001339 ProcessInterval msg;
Danil Chapovalov0c626af2020-02-10 11:16:00 +01001340 msg.at_time = Timestamp::Micros(clock.TimeInMicroseconds());
Sebastian Jansson5c94f552018-10-15 18:46:51 +02001341 observer.Update(goog_cc->OnProcessInterval(msg));
1342 next_process_time_us_ += process_interval.us();
stefanc3de0332016-08-02 07:22:17 -07001343 }
Stefan Holmer492ee282016-10-27 17:19:20 +02001344 if (observer.GetAndResetBitrateUpdated() ||
1345 time_us - last_update_us >= 1e6) {
Stefan Holmer13181032016-07-29 14:48:54 +02001346 uint32_t y = observer.last_bitrate_bps() / 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001347 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Stefan Holmer13181032016-07-29 14:48:54 +02001348 time_series.points.emplace_back(x, y);
Stefan Holmer492ee282016-10-27 17:19:20 +02001349 last_update_us = time_us;
Stefan Holmer13181032016-07-29 14:48:54 +02001350 }
1351 time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
1352 }
1353 // Add the data set to the plot.
philipel35ba9bd2017-04-19 05:58:51 -07001354 plot->AppendTimeSeries(std::move(time_series));
Björn Tereliusae1892d2020-06-17 11:55:55 +02001355 plot->AppendTimeSeries(std::move(robust_time_series));
philipel35ba9bd2017-04-19 05:58:51 -07001356 plot->AppendTimeSeries(std::move(acked_time_series));
Bjorn Terelius6984ad22017-10-24 12:19:45 +02001357 plot->AppendTimeSeriesIfNotEmpty(std::move(acked_estimate_time_series));
Stefan Holmer13181032016-07-29 14:48:54 +02001358
Bjorn Terelius068fc352019-02-13 22:38:25 +01001359 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1360 "Time (s)", kLeftMargin, kRightMargin);
tereliusdc35dcd2016-08-01 12:03:27 -07001361 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001362 plot->SetTitle("Simulated send-side BWE behavior");
1363}
1364
1365void EventLogAnalyzer::CreateReceiveSideBweSimulationGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001366 using RtpPacketType = LoggedRtpPacketIncoming;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001367 class RembInterceptingPacketRouter : public PacketRouter {
1368 public:
1369 void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
1370 uint32_t bitrate_bps) override {
1371 last_bitrate_bps_ = bitrate_bps;
1372 bitrate_updated_ = true;
1373 PacketRouter::OnReceiveBitrateChanged(ssrcs, bitrate_bps);
1374 }
1375 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
1376 bool GetAndResetBitrateUpdated() {
1377 bool bitrate_updated = bitrate_updated_;
1378 bitrate_updated_ = false;
1379 return bitrate_updated;
1380 }
1381
1382 private:
Bjorn Terelius571e1302020-06-09 10:29:09 +02001383 // We don't know the start bitrate, but assume that it is the default 300
1384 // kbps.
1385 uint32_t last_bitrate_bps_ = 300000;
1386 bool bitrate_updated_ = false;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001387 };
1388
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001389 std::multimap<int64_t, const RtpPacketType*> incoming_rtp;
Bjorn Terelius28db2662017-10-04 14:22:43 +02001390
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001391 for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
Bjorn Terelius48b82792020-05-19 10:57:24 +02001392 if (IsVideoSsrc(parsed_log_, kIncomingPacket, stream.ssrc)) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001393 for (const auto& rtp_packet : stream.incoming_packets)
1394 incoming_rtp.insert(
1395 std::make_pair(rtp_packet.rtp.log_time_us(), &rtp_packet));
Bjorn Terelius28db2662017-10-04 14:22:43 +02001396 }
1397 }
1398
1399 SimulatedClock clock(0);
1400 RembInterceptingPacketRouter packet_router;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001401 // TODO(terelius): The PacketRouter is used as the RemoteBitrateObserver.
Bjorn Terelius28db2662017-10-04 14:22:43 +02001402 // Is this intentional?
1403 ReceiveSideCongestionController rscc(&clock, &packet_router);
1404 // TODO(holmer): Log the call config and use that here instead.
1405 // static const uint32_t kDefaultStartBitrateBps = 300000;
1406 // rscc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
1407
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001408 TimeSeries time_series("Receive side estimate", LineStyle::kLine,
1409 PointStyle::kHighlight);
1410 TimeSeries acked_time_series("Received bitrate", LineStyle::kLine);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001411
1412 RateStatistics acked_bitrate(250, 8000);
1413 int64_t last_update_us = 0;
1414 for (const auto& kv : incoming_rtp) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001415 const RtpPacketType& packet = *kv.second;
1416 int64_t arrival_time_ms = packet.rtp.log_time_us() / 1000;
1417 size_t payload = packet.rtp.total_length; /*Should subtract header?*/
1418 clock.AdvanceTimeMicroseconds(packet.rtp.log_time_us() -
Bjorn Terelius28db2662017-10-04 14:22:43 +02001419 clock.TimeInMicroseconds());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001420 rscc.OnReceivedPacket(arrival_time_ms, payload, packet.rtp.header);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001421 acked_bitrate.Update(payload, arrival_time_ms);
Danil Chapovalov431abd92018-06-18 12:54:17 +02001422 absl::optional<uint32_t> bitrate_bps = acked_bitrate.Rate(arrival_time_ms);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001423 if (bitrate_bps) {
1424 uint32_t y = *bitrate_bps / 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001425 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Bjorn Terelius28db2662017-10-04 14:22:43 +02001426 acked_time_series.points.emplace_back(x, y);
1427 }
1428 if (packet_router.GetAndResetBitrateUpdated() ||
1429 clock.TimeInMicroseconds() - last_update_us >= 1e6) {
1430 uint32_t y = packet_router.last_bitrate_bps() / 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001431 float x = config_.GetCallTimeSec(clock.TimeInMicroseconds());
Bjorn Terelius28db2662017-10-04 14:22:43 +02001432 time_series.points.emplace_back(x, y);
1433 last_update_us = clock.TimeInMicroseconds();
1434 }
1435 }
1436 // Add the data set to the plot.
1437 plot->AppendTimeSeries(std::move(time_series));
1438 plot->AppendTimeSeries(std::move(acked_time_series));
1439
Bjorn Terelius068fc352019-02-13 22:38:25 +01001440 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1441 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius28db2662017-10-04 14:22:43 +02001442 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1443 plot->SetTitle("Simulated receive-side BWE behavior");
Stefan Holmer13181032016-07-29 14:48:54 +02001444}
1445
tereliuse34c19c2016-08-15 08:47:14 -07001446void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001447 TimeSeries time_series("Network delay", LineStyle::kLine,
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001448 PointStyle::kHighlight);
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001449 int64_t min_send_receive_diff_ms = std::numeric_limits<int64_t>::max();
1450 int64_t min_rtt_ms = std::numeric_limits<int64_t>::max();
stefanc3de0332016-08-02 07:22:17 -07001451
stefana0a8ed72017-09-06 02:06:32 -07001452 int64_t prev_y = 0;
Björn Tereliusc69c1bb2019-10-11 15:06:58 +02001453 std::vector<MatchedSendArrivalTimes> matched_rtp_rtcp =
1454 GetNetworkTrace(parsed_log_);
1455 absl::c_stable_sort(matched_rtp_rtcp, [](const MatchedSendArrivalTimes& a,
1456 const MatchedSendArrivalTimes& b) {
philipel3574d052019-11-18 14:38:13 +01001457 return a.feedback_arrival_time_ms < b.feedback_arrival_time_ms ||
1458 (a.feedback_arrival_time_ms == b.feedback_arrival_time_ms &&
1459 a.arrival_time_ms < b.arrival_time_ms);
Björn Tereliusc69c1bb2019-10-11 15:06:58 +02001460 });
1461 for (const auto& packet : matched_rtp_rtcp) {
Sebastian Jansson74f96ec2019-10-29 12:57:54 +01001462 if (packet.arrival_time_ms == MatchedSendArrivalTimes::kNotReceived)
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001463 continue;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001464 float x = config_.GetCallTimeSec(1000 * packet.feedback_arrival_time_ms);
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001465 int64_t y = packet.arrival_time_ms - packet.send_time_ms;
1466 prev_y = y;
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001467 int64_t rtt_ms = packet.feedback_arrival_time_ms - packet.send_time_ms;
1468 min_rtt_ms = std::min(rtt_ms, min_rtt_ms);
1469 min_send_receive_diff_ms = std::min(y, min_send_receive_diff_ms);
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001470 time_series.points.emplace_back(x, y);
stefanc3de0332016-08-02 07:22:17 -07001471 }
Christoffer Rodbro89f64d32018-09-27 14:29:35 +02001472
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001473 // We assume that the base network delay (w/o queues) is equal to half
1474 // the minimum RTT. Therefore rescale the delays by subtracting the minimum
Mirko Bonadei604e75c2019-07-25 11:55:47 +02001475 // observed 1-ways delay and add half the minimum RTT.
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001476 const int64_t estimated_clock_offset_ms =
1477 min_send_receive_diff_ms - min_rtt_ms / 2;
stefanc3de0332016-08-02 07:22:17 -07001478 for (TimeSeriesPoint& point : time_series.points)
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001479 point.y -= estimated_clock_offset_ms;
Bjorn Terelius57ba7e12018-10-25 15:31:35 +02001480
stefanc3de0332016-08-02 07:22:17 -07001481 // Add the data set to the plot.
stefana0a8ed72017-09-06 02:06:32 -07001482 plot->AppendTimeSeriesIfNotEmpty(std::move(time_series));
stefanc3de0332016-08-02 07:22:17 -07001483
Bjorn Terelius068fc352019-02-13 22:38:25 +01001484 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1485 "Time (s)", kLeftMargin, kRightMargin);
stefanc3de0332016-08-02 07:22:17 -07001486 plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
Konrad Hofbauer5be3bbd2019-01-21 12:31:07 +01001487 plot->SetTitle("Outgoing network delay (based on per-packet feedback)");
stefanc3de0332016-08-02 07:22:17 -07001488}
stefan08383272016-12-20 08:51:52 -08001489
Bjorn Terelius0295a962017-10-25 17:42:41 +02001490void EventLogAnalyzer::CreatePacerDelayGraph(Plot* plot) {
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001491 for (const auto& stream : parsed_log_.outgoing_rtp_packets_by_ssrc()) {
1492 const std::vector<LoggedRtpPacketOutgoing>& packets =
1493 stream.outgoing_packets;
Bjorn Terelius0295a962017-10-25 17:42:41 +02001494
Bjorn Terelius48b82792020-05-19 10:57:24 +02001495 if (IsRtxSsrc(parsed_log_, kOutgoingPacket, stream.ssrc)) {
Konrad Hofbauerbfb735b2019-04-16 11:12:11 +02001496 continue;
1497 }
1498
Bjorn Terelius0295a962017-10-25 17:42:41 +02001499 if (packets.size() < 2) {
Mirko Bonadei675513b2017-11-09 11:09:25 +01001500 RTC_LOG(LS_WARNING)
1501 << "Can't estimate a the RTP clock frequency or the "
1502 "pacer delay with less than 2 packets in the stream";
Bjorn Terelius0295a962017-10-25 17:42:41 +02001503 continue;
1504 }
Björn Terelius0d1b28c2020-05-27 20:25:06 +02001505 int64_t segment_end_us = parsed_log_.first_log_segment().stop_time_us();
Danil Chapovalov431abd92018-06-18 12:54:17 +02001506 absl::optional<uint32_t> estimated_frequency =
Bjorn Terelius48b82792020-05-19 10:57:24 +02001507 EstimateRtpClockFrequency(packets, segment_end_us);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001508 if (!estimated_frequency)
1509 continue;
Bjorn Terelius48b82792020-05-19 10:57:24 +02001510 if (IsVideoSsrc(parsed_log_, kOutgoingPacket, stream.ssrc) &&
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001511 *estimated_frequency != 90000) {
Mirko Bonadei675513b2017-11-09 11:09:25 +01001512 RTC_LOG(LS_WARNING)
Bjorn Terelius0295a962017-10-25 17:42:41 +02001513 << "Video stream should use a 90 kHz clock but appears to use "
1514 << *estimated_frequency / 1000 << ". Discarding.";
1515 continue;
1516 }
1517
1518 TimeSeries pacer_delay_series(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001519 GetStreamName(parsed_log_, kOutgoingPacket, stream.ssrc) + "(" +
Bjorn Terelius0295a962017-10-25 17:42:41 +02001520 std::to_string(*estimated_frequency / 1000) + " kHz)",
Bjorn Tereliusb577d5e2017-11-10 16:21:34 +01001521 LineStyle::kLine, PointStyle::kHighlight);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001522 SeqNumUnwrapper<uint32_t> timestamp_unwrapper;
1523 uint64_t first_capture_timestamp =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001524 timestamp_unwrapper.Unwrap(packets.front().rtp.header.timestamp);
1525 uint64_t first_send_timestamp = packets.front().rtp.log_time_us();
1526 for (const auto& packet : packets) {
Bjorn Terelius0295a962017-10-25 17:42:41 +02001527 double capture_time_ms = (static_cast<double>(timestamp_unwrapper.Unwrap(
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001528 packet.rtp.header.timestamp)) -
Bjorn Terelius0295a962017-10-25 17:42:41 +02001529 first_capture_timestamp) /
1530 *estimated_frequency * 1000;
1531 double send_time_ms =
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001532 static_cast<double>(packet.rtp.log_time_us() - first_send_timestamp) /
1533 1000;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001534 float x = config_.GetCallTimeSec(packet.rtp.log_time_us());
Bjorn Terelius0295a962017-10-25 17:42:41 +02001535 float y = send_time_ms - capture_time_ms;
1536 pacer_delay_series.points.emplace_back(x, y);
1537 }
1538 plot->AppendTimeSeries(std::move(pacer_delay_series));
1539 }
1540
Bjorn Terelius068fc352019-02-13 22:38:25 +01001541 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1542 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Terelius0295a962017-10-25 17:42:41 +02001543 plot->SetSuggestedYAxis(0, 10, "Pacer delay (ms)", kBottomMargin, kTopMargin);
1544 plot->SetTitle(
1545 "Delay from capture to send time. (First packet normalized to 0.)");
1546}
1547
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001548void EventLogAnalyzer::CreateTimestampGraph(PacketDirection direction,
1549 Plot* plot) {
1550 for (const auto& stream : parsed_log_.rtp_packets_by_ssrc(direction)) {
1551 TimeSeries rtp_timestamps(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001552 GetStreamName(parsed_log_, direction, stream.ssrc) + " capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001553 LineStyle::kLine, PointStyle::kHighlight);
1554 for (const auto& packet : stream.packet_view) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001555 float x = config_.GetCallTimeSec(packet.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001556 float y = packet.header.timestamp;
1557 rtp_timestamps.points.emplace_back(x, y);
stefane372d3c2017-02-02 08:04:18 -08001558 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001559 plot->AppendTimeSeries(std::move(rtp_timestamps));
Björn Tereliusff612732018-04-25 14:23:01 +00001560
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001561 TimeSeries rtcp_timestamps(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001562 GetStreamName(parsed_log_, direction, stream.ssrc) +
1563 " rtcp capture-time",
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001564 LineStyle::kLine, PointStyle::kHighlight);
1565 // TODO(terelius): Why only sender reports?
1566 const auto& sender_reports = parsed_log_.sender_reports(direction);
1567 for (const auto& rtcp : sender_reports) {
1568 if (rtcp.sr.sender_ssrc() != stream.ssrc)
1569 continue;
Bjorn Terelius068fc352019-02-13 22:38:25 +01001570 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001571 float y = rtcp.sr.rtp_timestamp();
1572 rtcp_timestamps.points.emplace_back(x, y);
Björn Tereliusff612732018-04-25 14:23:01 +00001573 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001574 plot->AppendTimeSeriesIfNotEmpty(std::move(rtcp_timestamps));
stefane372d3c2017-02-02 08:04:18 -08001575 }
1576
Bjorn Terelius068fc352019-02-13 22:38:25 +01001577 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1578 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001579 plot->SetSuggestedYAxis(0, 1, "RTP timestamp", kBottomMargin, kTopMargin);
1580 plot->SetTitle(GetDirectionAsString(direction) + " timestamps");
stefane372d3c2017-02-02 08:04:18 -08001581}
michaelt6e5b2192017-02-22 07:33:27 -08001582
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001583void EventLogAnalyzer::CreateSenderAndReceiverReportPlot(
1584 PacketDirection direction,
1585 rtc::FunctionView<float(const rtcp::ReportBlock&)> fy,
1586 std::string title,
1587 std::string yaxis_label,
1588 Plot* plot) {
1589 std::map<uint32_t, TimeSeries> sr_reports_by_ssrc;
1590 const auto& sender_reports = parsed_log_.sender_reports(direction);
1591 for (const auto& rtcp : sender_reports) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001592 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001593 uint32_t ssrc = rtcp.sr.sender_ssrc();
1594 for (const auto& block : rtcp.sr.report_blocks()) {
1595 float y = fy(block);
1596 auto sr_report_it = sr_reports_by_ssrc.find(ssrc);
1597 bool inserted;
1598 if (sr_report_it == sr_reports_by_ssrc.end()) {
1599 std::tie(sr_report_it, inserted) = sr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001600 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1601 " Sender Reports",
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001602 LineStyle::kLine, PointStyle::kHighlight));
1603 }
1604 sr_report_it->second.points.emplace_back(x, y);
1605 }
1606 }
1607 for (auto& kv : sr_reports_by_ssrc) {
1608 plot->AppendTimeSeries(std::move(kv.second));
1609 }
1610
1611 std::map<uint32_t, TimeSeries> rr_reports_by_ssrc;
1612 const auto& receiver_reports = parsed_log_.receiver_reports(direction);
1613 for (const auto& rtcp : receiver_reports) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001614 float x = config_.GetCallTimeSec(rtcp.log_time_us());
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001615 uint32_t ssrc = rtcp.rr.sender_ssrc();
1616 for (const auto& block : rtcp.rr.report_blocks()) {
1617 float y = fy(block);
1618 auto rr_report_it = rr_reports_by_ssrc.find(ssrc);
1619 bool inserted;
1620 if (rr_report_it == rr_reports_by_ssrc.end()) {
1621 std::tie(rr_report_it, inserted) = rr_reports_by_ssrc.emplace(
Bjorn Terelius48b82792020-05-19 10:57:24 +02001622 ssrc, TimeSeries(GetStreamName(parsed_log_, direction, ssrc) +
1623 " Receiver Reports",
1624 LineStyle::kLine, PointStyle::kHighlight));
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001625 }
1626 rr_report_it->second.points.emplace_back(x, y);
1627 }
1628 }
1629 for (auto& kv : rr_reports_by_ssrc) {
1630 plot->AppendTimeSeries(std::move(kv.second));
1631 }
1632
Bjorn Terelius068fc352019-02-13 22:38:25 +01001633 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1634 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusb1222c22018-07-24 13:45:31 +02001635 plot->SetSuggestedYAxis(0, 1, yaxis_label, kBottomMargin, kTopMargin);
1636 plot->SetTitle(title);
1637}
1638
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001639void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) {
1640 std::map<uint32_t, TimeSeries> configs_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001641 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001642 if (configs_by_cp_id.find(config.candidate_pair_id) ==
1643 configs_by_cp_id.end()) {
1644 const std::string candidate_pair_desc =
1645 GetCandidatePairLogDescriptionAsString(config);
Qingsi Wang93a84392018-01-30 17:13:09 -08001646 configs_by_cp_id[config.candidate_pair_id] =
1647 TimeSeries("[" + std::to_string(config.candidate_pair_id) + "]" +
1648 candidate_pair_desc,
1649 LineStyle::kNone, PointStyle::kHighlight);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001650 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1651 candidate_pair_desc;
1652 }
Bjorn Terelius068fc352019-02-13 22:38:25 +01001653 float x = config_.GetCallTimeSec(config.log_time_us());
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001654 float y = static_cast<float>(config.type);
1655 configs_by_cp_id[config.candidate_pair_id].points.emplace_back(x, y);
1656 }
1657
1658 // TODO(qingsi): There can be a large number of candidate pairs generated by
1659 // certain calls and the frontend cannot render the chart in this case due to
1660 // the failure of generating a palette with the same number of colors.
1661 for (auto& kv : configs_by_cp_id) {
1662 plot->AppendTimeSeries(std::move(kv.second));
1663 }
1664
Bjorn Terelius068fc352019-02-13 22:38:25 +01001665 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1666 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001667 plot->SetSuggestedYAxis(0, 3, "Config Type", kBottomMargin, kTopMargin);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001668 plot->SetTitle("[IceEventLog] ICE candidate pair configs");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001669 plot->SetYAxisTickLabels(
1670 {{static_cast<float>(IceCandidatePairConfigType::kAdded), "ADDED"},
1671 {static_cast<float>(IceCandidatePairConfigType::kUpdated), "UPDATED"},
1672 {static_cast<float>(IceCandidatePairConfigType::kDestroyed),
1673 "DESTROYED"},
1674 {static_cast<float>(IceCandidatePairConfigType::kSelected),
1675 "SELECTED"}});
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001676}
1677
1678std::string EventLogAnalyzer::GetCandidatePairLogDescriptionFromId(
1679 uint32_t candidate_pair_id) {
1680 if (candidate_pair_desc_by_id_.find(candidate_pair_id) !=
1681 candidate_pair_desc_by_id_.end()) {
1682 return candidate_pair_desc_by_id_[candidate_pair_id];
1683 }
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001684 for (const auto& config : parsed_log_.ice_candidate_pair_configs()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001685 // TODO(qingsi): Add the handling of the "Updated" config event after the
1686 // visualization of property change for candidate pairs is introduced.
1687 if (candidate_pair_desc_by_id_.find(config.candidate_pair_id) ==
1688 candidate_pair_desc_by_id_.end()) {
1689 const std::string candidate_pair_desc =
1690 GetCandidatePairLogDescriptionAsString(config);
1691 candidate_pair_desc_by_id_[config.candidate_pair_id] =
1692 candidate_pair_desc;
1693 }
1694 }
1695 return candidate_pair_desc_by_id_[candidate_pair_id];
1696}
1697
1698void EventLogAnalyzer::CreateIceConnectivityCheckGraph(Plot* plot) {
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001699 constexpr int kEventTypeOffset =
1700 static_cast<int>(IceCandidatePairConfigType::kNumValues);
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001701 std::map<uint32_t, TimeSeries> checks_by_cp_id;
Bjorn Tereliusc4ca1d32018-04-27 14:33:34 +02001702 for (const auto& event : parsed_log_.ice_candidate_pair_events()) {
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001703 if (checks_by_cp_id.find(event.candidate_pair_id) ==
1704 checks_by_cp_id.end()) {
1705 checks_by_cp_id[event.candidate_pair_id] = TimeSeries(
Qingsi Wang93a84392018-01-30 17:13:09 -08001706 "[" + std::to_string(event.candidate_pair_id) + "]" +
1707 GetCandidatePairLogDescriptionFromId(event.candidate_pair_id),
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001708 LineStyle::kNone, PointStyle::kHighlight);
1709 }
Bjorn Terelius068fc352019-02-13 22:38:25 +01001710 float x = config_.GetCallTimeSec(event.log_time_us());
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001711 float y = static_cast<float>(event.type) + kEventTypeOffset;
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001712 checks_by_cp_id[event.candidate_pair_id].points.emplace_back(x, y);
1713 }
1714
1715 // TODO(qingsi): The same issue as in CreateIceCandidatePairConfigGraph.
1716 for (auto& kv : checks_by_cp_id) {
1717 plot->AppendTimeSeries(std::move(kv.second));
1718 }
1719
Bjorn Terelius068fc352019-02-13 22:38:25 +01001720 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1721 "Time (s)", kLeftMargin, kRightMargin);
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001722 plot->SetSuggestedYAxis(0, 4, "Connectivity State", kBottomMargin,
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001723 kTopMargin);
1724 plot->SetTitle("[IceEventLog] ICE connectivity checks");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001725
1726 plot->SetYAxisTickLabels(
1727 {{static_cast<float>(IceCandidatePairEventType::kCheckSent) +
1728 kEventTypeOffset,
1729 "CHECK SENT"},
1730 {static_cast<float>(IceCandidatePairEventType::kCheckReceived) +
1731 kEventTypeOffset,
1732 "CHECK RECEIVED"},
1733 {static_cast<float>(IceCandidatePairEventType::kCheckResponseSent) +
1734 kEventTypeOffset,
1735 "RESPONSE SENT"},
1736 {static_cast<float>(IceCandidatePairEventType::kCheckResponseReceived) +
1737 kEventTypeOffset,
1738 "RESPONSE RECEIVED"}});
Qingsi Wang8eca1ff2018-02-02 11:49:44 -08001739}
1740
Zach Stein10a58012018-12-07 12:26:28 -08001741void EventLogAnalyzer::CreateDtlsTransportStateGraph(Plot* plot) {
1742 TimeSeries states("DTLS Transport State", LineStyle::kNone,
1743 PointStyle::kHighlight);
1744 for (const auto& event : parsed_log_.dtls_transport_states()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001745 float x = config_.GetCallTimeSec(event.log_time_us());
Zach Stein10a58012018-12-07 12:26:28 -08001746 float y = static_cast<float>(event.dtls_transport_state);
1747 states.points.emplace_back(x, y);
1748 }
1749 plot->AppendTimeSeries(std::move(states));
Bjorn Terelius068fc352019-02-13 22:38:25 +01001750 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1751 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001752 plot->SetSuggestedYAxis(0, static_cast<float>(DtlsTransportState::kNumValues),
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001753 "Transport State", kBottomMargin, kTopMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001754 plot->SetTitle("DTLS Transport State");
Bjorn Tereliusf640b872019-07-24 15:46:39 +02001755 plot->SetYAxisTickLabels(
1756 {{static_cast<float>(DtlsTransportState::kNew), "NEW"},
1757 {static_cast<float>(DtlsTransportState::kConnecting), "CONNECTING"},
1758 {static_cast<float>(DtlsTransportState::kConnected), "CONNECTED"},
1759 {static_cast<float>(DtlsTransportState::kClosed), "CLOSED"},
1760 {static_cast<float>(DtlsTransportState::kFailed), "FAILED"}});
Zach Stein10a58012018-12-07 12:26:28 -08001761}
1762
1763void EventLogAnalyzer::CreateDtlsWritableStateGraph(Plot* plot) {
1764 TimeSeries writable("DTLS Writable", LineStyle::kNone,
1765 PointStyle::kHighlight);
1766 for (const auto& event : parsed_log_.dtls_writable_states()) {
Bjorn Terelius068fc352019-02-13 22:38:25 +01001767 float x = config_.GetCallTimeSec(event.log_time_us());
Zach Stein10a58012018-12-07 12:26:28 -08001768 float y = static_cast<float>(event.writable);
1769 writable.points.emplace_back(x, y);
1770 }
1771 plot->AppendTimeSeries(std::move(writable));
Bjorn Terelius068fc352019-02-13 22:38:25 +01001772 plot->SetXAxis(config_.CallBeginTimeSec(), config_.CallEndTimeSec(),
1773 "Time (s)", kLeftMargin, kRightMargin);
Zach Stein10a58012018-12-07 12:26:28 -08001774 plot->SetSuggestedYAxis(0, 1, "Writable", kBottomMargin, kTopMargin);
1775 plot->SetTitle("DTLS Writable State");
1776}
1777
terelius54ce6802016-07-13 06:44:41 -07001778} // namespace webrtc