blob: bd8cb99c1b755774b1c882f18e4358a3e4b99bdf [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 Bonadei92ea95e2017-09-15 06:47:31 +020011#include "rtc_tools/event_log_visualizer/analyzer.h"
terelius54ce6802016-07-13 06:44:41 -070012
13#include <algorithm>
14#include <limits>
15#include <map>
16#include <sstream>
17#include <string>
18#include <utility>
19
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020020#include "call/audio_receive_stream.h"
21#include "call/audio_send_stream.h"
22#include "call/call.h"
23#include "call/video_receive_stream.h"
24#include "call/video_send_stream.h"
Mirko Bonadei71207422017-09-15 13:58:09 +020025#include "common_types.h" // NOLINT(build/include)
Elad Alon99a81b62017-09-21 10:25:29 +020026#include "logging/rtc_event_log/rtc_stream_config.h"
Mirko Bonadei92ea95e2017-09-15 06:47:31 +020027#include "modules/audio_coding/neteq/tools/audio_sink.h"
28#include "modules/audio_coding/neteq/tools/fake_decode_from_file.h"
29#include "modules/audio_coding/neteq/tools/neteq_delay_analyzer.h"
30#include "modules/audio_coding/neteq/tools/neteq_replacement_input.h"
31#include "modules/audio_coding/neteq/tools/neteq_test.h"
32#include "modules/audio_coding/neteq/tools/resample_input_audio_file.h"
33#include "modules/congestion_controller/include/send_side_congestion_controller.h"
34#include "modules/include/module_common_types.h"
35#include "modules/rtp_rtcp/include/rtp_rtcp.h"
36#include "modules/rtp_rtcp/include/rtp_rtcp_defines.h"
37#include "modules/rtp_rtcp/source/rtcp_packet/common_header.h"
38#include "modules/rtp_rtcp/source/rtcp_packet/receiver_report.h"
39#include "modules/rtp_rtcp/source/rtcp_packet/remb.h"
40#include "modules/rtp_rtcp/source/rtcp_packet/sender_report.h"
41#include "modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
42#include "modules/rtp_rtcp/source/rtp_header_extensions.h"
43#include "modules/rtp_rtcp/source/rtp_utility.h"
44#include "rtc_base/checks.h"
45#include "rtc_base/format_macros.h"
46#include "rtc_base/logging.h"
47#include "rtc_base/ptr_util.h"
48#include "rtc_base/rate_statistics.h"
terelius54ce6802016-07-13 06:44:41 -070049
tereliusdc35dcd2016-08-01 12:03:27 -070050namespace webrtc {
51namespace plotting {
52
terelius54ce6802016-07-13 06:44:41 -070053namespace {
54
elad.alonec304f92017-03-08 05:03:53 -080055void SortPacketFeedbackVector(std::vector<PacketFeedback>* vec) {
56 auto pred = [](const PacketFeedback& packet_feedback) {
57 return packet_feedback.arrival_time_ms == PacketFeedback::kNotReceived;
58 };
59 vec->erase(std::remove_if(vec->begin(), vec->end(), pred), vec->end());
60 std::sort(vec->begin(), vec->end(), PacketFeedbackComparator());
61}
62
terelius54ce6802016-07-13 06:44:41 -070063std::string SsrcToString(uint32_t ssrc) {
64 std::stringstream ss;
65 ss << "SSRC " << ssrc;
66 return ss.str();
67}
68
69// Checks whether an SSRC is contained in the list of desired SSRCs.
70// Note that an empty SSRC list matches every SSRC.
71bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) {
72 if (desired_ssrc.size() == 0)
73 return true;
74 return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) !=
75 desired_ssrc.end();
76}
77
78double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
79 // The timestamp is a fixed point representation with 6 bits for seconds
80 // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the
81 // time in seconds and then multiply by 1000000 to convert to microseconds.
82 static constexpr double kTimestampToMicroSec =
tereliusccbbf8d2016-08-10 07:34:28 -070083 1000000.0 / static_cast<double>(1ul << 18);
terelius54ce6802016-07-13 06:44:41 -070084 return abs_send_time * kTimestampToMicroSec;
85}
86
87// Computes the difference |later| - |earlier| where |later| and |earlier|
88// are counters that wrap at |modulus|. The difference is chosen to have the
89// least absolute value. For example if |modulus| is 8, then the difference will
90// be chosen in the range [-3, 4]. If |modulus| is 9, then the difference will
91// be in [-4, 4].
92int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
93 RTC_DCHECK_LE(1, modulus);
94 RTC_DCHECK_LT(later, modulus);
95 RTC_DCHECK_LT(earlier, modulus);
96 int64_t difference =
97 static_cast<int64_t>(later) - static_cast<int64_t>(earlier);
98 int64_t max_difference = modulus / 2;
99 int64_t min_difference = max_difference - modulus + 1;
100 if (difference > max_difference) {
101 difference -= modulus;
102 }
103 if (difference < min_difference) {
104 difference += modulus;
105 }
terelius6addf492016-08-23 17:34:07 -0700106 if (difference > max_difference / 2 || difference < min_difference / 2) {
107 LOG(LS_WARNING) << "Difference between" << later << " and " << earlier
108 << " expected to be in the range (" << min_difference / 2
109 << "," << max_difference / 2 << ") but is " << difference
110 << ". Correct unwrapping is uncertain.";
111 }
terelius54ce6802016-07-13 06:44:41 -0700112 return difference;
113}
114
ivocaac9d6f2016-09-22 07:01:47 -0700115// Return default values for header extensions, to use on streams without stored
116// mapping data. Currently this only applies to audio streams, since the mapping
117// is not stored in the event log.
118// TODO(ivoc): Remove this once this mapping is stored in the event log for
119// audio streams. Tracking bug: webrtc:6399
120webrtc::RtpHeaderExtensionMap GetDefaultHeaderExtensionMap() {
121 webrtc::RtpHeaderExtensionMap default_map;
danilchap4aecc582016-11-15 09:21:00 -0800122 default_map.Register<AudioLevel>(webrtc::RtpExtension::kAudioLevelDefaultId);
terelius007d5622017-08-08 05:40:26 -0700123 default_map.Register<TransmissionOffset>(
124 webrtc::RtpExtension::kTimestampOffsetDefaultId);
danilchap4aecc582016-11-15 09:21:00 -0800125 default_map.Register<AbsoluteSendTime>(
ivocaac9d6f2016-09-22 07:01:47 -0700126 webrtc::RtpExtension::kAbsSendTimeDefaultId);
terelius007d5622017-08-08 05:40:26 -0700127 default_map.Register<VideoOrientation>(
128 webrtc::RtpExtension::kVideoRotationDefaultId);
129 default_map.Register<VideoContentTypeExtension>(
130 webrtc::RtpExtension::kVideoContentTypeDefaultId);
131 default_map.Register<VideoTimingExtension>(
132 webrtc::RtpExtension::kVideoTimingDefaultId);
133 default_map.Register<TransportSequenceNumber>(
134 webrtc::RtpExtension::kTransportSequenceNumberDefaultId);
135 default_map.Register<PlayoutDelayLimits>(
136 webrtc::RtpExtension::kPlayoutDelayDefaultId);
ivocaac9d6f2016-09-22 07:01:47 -0700137 return default_map;
138}
139
tereliusdc35dcd2016-08-01 12:03:27 -0700140constexpr float kLeftMargin = 0.01f;
141constexpr float kRightMargin = 0.02f;
142constexpr float kBottomMargin = 0.02f;
143constexpr float kTopMargin = 0.05f;
terelius54ce6802016-07-13 06:44:41 -0700144
terelius53dc23c2017-03-13 05:24:05 -0700145rtc::Optional<double> NetworkDelayDiff_AbsSendTime(
146 const LoggedRtpPacket& old_packet,
147 const LoggedRtpPacket& new_packet) {
148 if (old_packet.header.extension.hasAbsoluteSendTime &&
149 new_packet.header.extension.hasAbsoluteSendTime) {
150 int64_t send_time_diff = WrappingDifference(
151 new_packet.header.extension.absoluteSendTime,
152 old_packet.header.extension.absoluteSendTime, 1ul << 24);
153 int64_t recv_time_diff = new_packet.timestamp - old_packet.timestamp;
154 double delay_change_us =
155 recv_time_diff - AbsSendTimeToMicroseconds(send_time_diff);
156 return rtc::Optional<double>(delay_change_us / 1000);
157 } else {
158 return rtc::Optional<double>();
terelius6addf492016-08-23 17:34:07 -0700159 }
160}
161
terelius53dc23c2017-03-13 05:24:05 -0700162rtc::Optional<double> NetworkDelayDiff_CaptureTime(
163 const LoggedRtpPacket& old_packet,
164 const LoggedRtpPacket& new_packet) {
165 int64_t send_time_diff = WrappingDifference(
166 new_packet.header.timestamp, old_packet.header.timestamp, 1ull << 32);
167 int64_t recv_time_diff = new_packet.timestamp - old_packet.timestamp;
168
169 const double kVideoSampleRate = 90000;
170 // TODO(terelius): We treat all streams as video for now, even though
171 // audio might be sampled at e.g. 16kHz, because it is really difficult to
172 // figure out the true sampling rate of a stream. The effect is that the
173 // delay will be scaled incorrectly for non-video streams.
174
175 double delay_change =
176 static_cast<double>(recv_time_diff) / 1000 -
177 static_cast<double>(send_time_diff) / kVideoSampleRate * 1000;
178 if (delay_change < -10000 || 10000 < delay_change) {
179 LOG(LS_WARNING) << "Very large delay change. Timestamps correct?";
180 LOG(LS_WARNING) << "Old capture time " << old_packet.header.timestamp
181 << ", received time " << old_packet.timestamp;
182 LOG(LS_WARNING) << "New capture time " << new_packet.header.timestamp
183 << ", received time " << new_packet.timestamp;
184 LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = "
185 << static_cast<double>(recv_time_diff) / 1000000 << "s";
186 LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = "
187 << static_cast<double>(send_time_diff) / kVideoSampleRate
188 << "s";
189 }
190 return rtc::Optional<double>(delay_change);
191}
192
193// For each element in data, use |get_y()| to extract a y-coordinate and
194// store the result in a TimeSeries.
195template <typename DataType>
196void ProcessPoints(
197 rtc::FunctionView<rtc::Optional<float>(const DataType&)> get_y,
198 const std::vector<DataType>& data,
199 uint64_t begin_time,
200 TimeSeries* result) {
201 for (size_t i = 0; i < data.size(); i++) {
202 float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
203 rtc::Optional<float> y = get_y(data[i]);
204 if (y)
205 result->points.emplace_back(x, *y);
206 }
207}
208
209// For each pair of adjacent elements in |data|, use |get_y| to extract a
terelius6addf492016-08-23 17:34:07 -0700210// y-coordinate and store the result in a TimeSeries. Note that the x-coordinate
211// will be the time of the second element in the pair.
terelius53dc23c2017-03-13 05:24:05 -0700212template <typename DataType, typename ResultType>
213void ProcessPairs(
214 rtc::FunctionView<rtc::Optional<ResultType>(const DataType&,
215 const DataType&)> get_y,
216 const std::vector<DataType>& data,
217 uint64_t begin_time,
218 TimeSeries* result) {
tereliusccbbf8d2016-08-10 07:34:28 -0700219 for (size_t i = 1; i < data.size(); i++) {
220 float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
terelius53dc23c2017-03-13 05:24:05 -0700221 rtc::Optional<ResultType> y = get_y(data[i - 1], data[i]);
222 if (y)
223 result->points.emplace_back(x, static_cast<float>(*y));
224 }
225}
226
227// For each element in data, use |extract()| to extract a y-coordinate and
228// store the result in a TimeSeries.
229template <typename DataType, typename ResultType>
230void AccumulatePoints(
231 rtc::FunctionView<rtc::Optional<ResultType>(const DataType&)> extract,
232 const std::vector<DataType>& data,
233 uint64_t begin_time,
234 TimeSeries* result) {
235 ResultType sum = 0;
236 for (size_t i = 0; i < data.size(); i++) {
237 float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
238 rtc::Optional<ResultType> y = extract(data[i]);
239 if (y) {
240 sum += *y;
241 result->points.emplace_back(x, static_cast<float>(sum));
242 }
243 }
244}
245
246// For each pair of adjacent elements in |data|, use |extract()| to extract a
247// y-coordinate and store the result in a TimeSeries. Note that the x-coordinate
248// will be the time of the second element in the pair.
249template <typename DataType, typename ResultType>
250void AccumulatePairs(
251 rtc::FunctionView<rtc::Optional<ResultType>(const DataType&,
252 const DataType&)> extract,
253 const std::vector<DataType>& data,
254 uint64_t begin_time,
255 TimeSeries* result) {
256 ResultType sum = 0;
257 for (size_t i = 1; i < data.size(); i++) {
258 float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
259 rtc::Optional<ResultType> y = extract(data[i - 1], data[i]);
260 if (y)
261 sum += *y;
262 result->points.emplace_back(x, static_cast<float>(sum));
tereliusccbbf8d2016-08-10 07:34:28 -0700263 }
264}
265
terelius6addf492016-08-23 17:34:07 -0700266// Calculates a moving average of |data| and stores the result in a TimeSeries.
267// A data point is generated every |step| microseconds from |begin_time|
268// to |end_time|. The value of each data point is the average of the data
269// during the preceeding |window_duration_us| microseconds.
terelius53dc23c2017-03-13 05:24:05 -0700270template <typename DataType, typename ResultType>
271void MovingAverage(
272 rtc::FunctionView<rtc::Optional<ResultType>(const DataType&)> extract,
273 const std::vector<DataType>& data,
274 uint64_t begin_time,
275 uint64_t end_time,
276 uint64_t window_duration_us,
277 uint64_t step,
278 webrtc::plotting::TimeSeries* result) {
terelius6addf492016-08-23 17:34:07 -0700279 size_t window_index_begin = 0;
280 size_t window_index_end = 0;
terelius53dc23c2017-03-13 05:24:05 -0700281 ResultType sum_in_window = 0;
terelius6addf492016-08-23 17:34:07 -0700282
283 for (uint64_t t = begin_time; t < end_time + step; t += step) {
284 while (window_index_end < data.size() &&
285 data[window_index_end].timestamp < t) {
terelius53dc23c2017-03-13 05:24:05 -0700286 rtc::Optional<ResultType> value = extract(data[window_index_end]);
287 if (value)
288 sum_in_window += *value;
terelius6addf492016-08-23 17:34:07 -0700289 ++window_index_end;
290 }
291 while (window_index_begin < data.size() &&
292 data[window_index_begin].timestamp < t - window_duration_us) {
terelius53dc23c2017-03-13 05:24:05 -0700293 rtc::Optional<ResultType> value = extract(data[window_index_begin]);
294 if (value)
295 sum_in_window -= *value;
terelius6addf492016-08-23 17:34:07 -0700296 ++window_index_begin;
297 }
298 float window_duration_s = static_cast<float>(window_duration_us) / 1000000;
299 float x = static_cast<float>(t - begin_time) / 1000000;
terelius53dc23c2017-03-13 05:24:05 -0700300 float y = sum_in_window / window_duration_s;
terelius6addf492016-08-23 17:34:07 -0700301 result->points.emplace_back(x, y);
302 }
303}
304
terelius54ce6802016-07-13 06:44:41 -0700305} // namespace
306
terelius54ce6802016-07-13 06:44:41 -0700307EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log)
308 : parsed_log_(log), window_duration_(250000), step_(10000) {
309 uint64_t first_timestamp = std::numeric_limits<uint64_t>::max();
310 uint64_t last_timestamp = std::numeric_limits<uint64_t>::min();
terelius88e64e52016-07-19 01:51:06 -0700311
terelius88e64e52016-07-19 01:51:06 -0700312 PacketDirection direction;
terelius88e64e52016-07-19 01:51:06 -0700313 uint8_t header[IP_PACKET_SIZE];
314 size_t header_length;
315 size_t total_length;
316
perkjbbbad6d2017-05-19 06:30:28 -0700317 uint8_t last_incoming_rtcp_packet[IP_PACKET_SIZE];
318 uint8_t last_incoming_rtcp_packet_length = 0;
319
ivocaac9d6f2016-09-22 07:01:47 -0700320 // Make a default extension map for streams without configuration information.
321 // TODO(ivoc): Once configuration of audio streams is stored in the event log,
322 // this can be removed. Tracking bug: webrtc:6399
323 RtpHeaderExtensionMap default_extension_map = GetDefaultHeaderExtensionMap();
324
henrik.lundin3c938fc2017-06-14 06:09:58 -0700325 rtc::Optional<uint64_t> last_log_start;
326
terelius54ce6802016-07-13 06:44:41 -0700327 for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) {
328 ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i);
terelius88e64e52016-07-19 01:51:06 -0700329 if (event_type != ParsedRtcEventLog::VIDEO_RECEIVER_CONFIG_EVENT &&
330 event_type != ParsedRtcEventLog::VIDEO_SENDER_CONFIG_EVENT &&
331 event_type != ParsedRtcEventLog::AUDIO_RECEIVER_CONFIG_EVENT &&
terelius88c1d2b2016-08-01 05:20:33 -0700332 event_type != ParsedRtcEventLog::AUDIO_SENDER_CONFIG_EVENT &&
333 event_type != ParsedRtcEventLog::LOG_START &&
334 event_type != ParsedRtcEventLog::LOG_END) {
terelius88e64e52016-07-19 01:51:06 -0700335 uint64_t timestamp = parsed_log_.GetTimestamp(i);
336 first_timestamp = std::min(first_timestamp, timestamp);
337 last_timestamp = std::max(last_timestamp, timestamp);
338 }
339
340 switch (parsed_log_.GetEventType(i)) {
341 case ParsedRtcEventLog::VIDEO_RECEIVER_CONFIG_EVENT: {
terelius8fbc7652017-05-31 02:03:16 -0700342 rtclog::StreamConfig config = parsed_log_.GetVideoReceiveConfig(i);
perkj09e71da2017-05-22 03:26:49 -0700343 StreamId stream(config.remote_ssrc, kIncomingPacket);
terelius0740a202016-08-08 10:21:04 -0700344 video_ssrcs_.insert(stream);
perkj09e71da2017-05-22 03:26:49 -0700345 StreamId rtx_stream(config.rtx_ssrc, kIncomingPacket);
brandtr14742122017-01-27 04:53:07 -0800346 video_ssrcs_.insert(rtx_stream);
347 rtx_ssrcs_.insert(rtx_stream);
terelius88e64e52016-07-19 01:51:06 -0700348 break;
349 }
350 case ParsedRtcEventLog::VIDEO_SENDER_CONFIG_EVENT: {
terelius8fbc7652017-05-31 02:03:16 -0700351 std::vector<rtclog::StreamConfig> configs =
352 parsed_log_.GetVideoSendConfig(i);
terelius405f90c2017-06-01 03:50:31 -0700353 for (const auto& config : configs) {
354 StreamId stream(config.local_ssrc, kOutgoingPacket);
terelius8fbc7652017-05-31 02:03:16 -0700355 video_ssrcs_.insert(stream);
terelius405f90c2017-06-01 03:50:31 -0700356 StreamId rtx_stream(config.rtx_ssrc, kOutgoingPacket);
terelius8fbc7652017-05-31 02:03:16 -0700357 video_ssrcs_.insert(rtx_stream);
358 rtx_ssrcs_.insert(rtx_stream);
359 }
terelius88e64e52016-07-19 01:51:06 -0700360 break;
361 }
362 case ParsedRtcEventLog::AUDIO_RECEIVER_CONFIG_EVENT: {
terelius8fbc7652017-05-31 02:03:16 -0700363 rtclog::StreamConfig config = parsed_log_.GetAudioReceiveConfig(i);
perkjac8f52d2017-05-22 09:36:28 -0700364 StreamId stream(config.remote_ssrc, kIncomingPacket);
ivoce0928d82016-10-10 05:12:51 -0700365 audio_ssrcs_.insert(stream);
terelius88e64e52016-07-19 01:51:06 -0700366 break;
367 }
368 case ParsedRtcEventLog::AUDIO_SENDER_CONFIG_EVENT: {
terelius8fbc7652017-05-31 02:03:16 -0700369 rtclog::StreamConfig config = parsed_log_.GetAudioSendConfig(i);
perkjf4726992017-05-22 10:12:26 -0700370 StreamId stream(config.local_ssrc, kOutgoingPacket);
ivoce0928d82016-10-10 05:12:51 -0700371 audio_ssrcs_.insert(stream);
terelius88e64e52016-07-19 01:51:06 -0700372 break;
373 }
374 case ParsedRtcEventLog::RTP_EVENT: {
ilnika8e781a2017-06-12 01:02:46 -0700375 RtpHeaderExtensionMap* extension_map = parsed_log_.GetRtpHeader(
376 i, &direction, header, &header_length, &total_length);
terelius88e64e52016-07-19 01:51:06 -0700377 RtpUtility::RtpHeaderParser rtp_parser(header, header_length);
378 RTPHeader parsed_header;
ilnika8e781a2017-06-12 01:02:46 -0700379 if (extension_map != nullptr) {
terelius88e64e52016-07-19 01:51:06 -0700380 rtp_parser.Parse(&parsed_header, extension_map);
ivocaac9d6f2016-09-22 07:01:47 -0700381 } else {
382 // Use the default extension map.
383 // TODO(ivoc): Once configuration of audio streams is stored in the
384 // event log, this can be removed.
385 // Tracking bug: webrtc:6399
386 rtp_parser.Parse(&parsed_header, &default_extension_map);
terelius88e64e52016-07-19 01:51:06 -0700387 }
388 uint64_t timestamp = parsed_log_.GetTimestamp(i);
ilnika8e781a2017-06-12 01:02:46 -0700389 StreamId stream(parsed_header.ssrc, direction);
terelius88e64e52016-07-19 01:51:06 -0700390 rtp_packets_[stream].push_back(
Stefan Holmer13181032016-07-29 14:48:54 +0200391 LoggedRtpPacket(timestamp, parsed_header, total_length));
terelius88e64e52016-07-19 01:51:06 -0700392 break;
393 }
394 case ParsedRtcEventLog::RTCP_EVENT: {
Stefan Holmer13181032016-07-29 14:48:54 +0200395 uint8_t packet[IP_PACKET_SIZE];
perkj77cd58e2017-05-30 03:52:10 -0700396 parsed_log_.GetRtcpPacket(i, &direction, packet, &total_length);
perkjbbbad6d2017-05-19 06:30:28 -0700397 // Currently incoming RTCP packets are logged twice, both for audio and
398 // video. Only act on one of them. Compare against the previous parsed
399 // incoming RTCP packet.
400 if (direction == webrtc::kIncomingPacket) {
401 RTC_CHECK_LE(total_length, IP_PACKET_SIZE);
402 if (total_length == last_incoming_rtcp_packet_length &&
403 memcmp(last_incoming_rtcp_packet, packet, total_length) == 0) {
404 continue;
405 } else {
406 memcpy(last_incoming_rtcp_packet, packet, total_length);
407 last_incoming_rtcp_packet_length = total_length;
408 }
409 }
410 rtcp::CommonHeader header;
411 const uint8_t* packet_end = packet + total_length;
412 for (const uint8_t* block = packet; block < packet_end;
413 block = header.NextPacket()) {
414 RTC_CHECK(header.Parse(block, packet_end - block));
415 if (header.type() == rtcp::TransportFeedback::kPacketType &&
416 header.fmt() == rtcp::TransportFeedback::kFeedbackMessageType) {
417 std::unique_ptr<rtcp::TransportFeedback> rtcp_packet(
terelius2c8e8a32017-06-02 01:29:48 -0700418 rtc::MakeUnique<rtcp::TransportFeedback>());
perkjbbbad6d2017-05-19 06:30:28 -0700419 if (rtcp_packet->Parse(header)) {
420 uint32_t ssrc = rtcp_packet->sender_ssrc();
421 StreamId stream(ssrc, direction);
422 uint64_t timestamp = parsed_log_.GetTimestamp(i);
423 rtcp_packets_[stream].push_back(LoggedRtcpPacket(
424 timestamp, kRtcpTransportFeedback, std::move(rtcp_packet)));
425 }
426 } else if (header.type() == rtcp::SenderReport::kPacketType) {
427 std::unique_ptr<rtcp::SenderReport> rtcp_packet(
terelius2c8e8a32017-06-02 01:29:48 -0700428 rtc::MakeUnique<rtcp::SenderReport>());
perkjbbbad6d2017-05-19 06:30:28 -0700429 if (rtcp_packet->Parse(header)) {
430 uint32_t ssrc = rtcp_packet->sender_ssrc();
431 StreamId stream(ssrc, direction);
432 uint64_t timestamp = parsed_log_.GetTimestamp(i);
433 rtcp_packets_[stream].push_back(
434 LoggedRtcpPacket(timestamp, kRtcpSr, std::move(rtcp_packet)));
435 }
436 } else if (header.type() == rtcp::ReceiverReport::kPacketType) {
437 std::unique_ptr<rtcp::ReceiverReport> rtcp_packet(
terelius2c8e8a32017-06-02 01:29:48 -0700438 rtc::MakeUnique<rtcp::ReceiverReport>());
perkjbbbad6d2017-05-19 06:30:28 -0700439 if (rtcp_packet->Parse(header)) {
440 uint32_t ssrc = rtcp_packet->sender_ssrc();
441 StreamId stream(ssrc, direction);
442 uint64_t timestamp = parsed_log_.GetTimestamp(i);
443 rtcp_packets_[stream].push_back(
444 LoggedRtcpPacket(timestamp, kRtcpRr, std::move(rtcp_packet)));
Stefan Holmer13181032016-07-29 14:48:54 +0200445 }
terelius2c8e8a32017-06-02 01:29:48 -0700446 } else if (header.type() == rtcp::Remb::kPacketType &&
447 header.fmt() == rtcp::Remb::kFeedbackMessageType) {
448 std::unique_ptr<rtcp::Remb> rtcp_packet(
449 rtc::MakeUnique<rtcp::Remb>());
450 if (rtcp_packet->Parse(header)) {
451 uint32_t ssrc = rtcp_packet->sender_ssrc();
452 StreamId stream(ssrc, direction);
453 uint64_t timestamp = parsed_log_.GetTimestamp(i);
454 rtcp_packets_[stream].push_back(LoggedRtcpPacket(
455 timestamp, kRtcpRemb, std::move(rtcp_packet)));
456 }
Stefan Holmer13181032016-07-29 14:48:54 +0200457 }
Stefan Holmer13181032016-07-29 14:48:54 +0200458 }
terelius88e64e52016-07-19 01:51:06 -0700459 break;
460 }
461 case ParsedRtcEventLog::LOG_START: {
henrik.lundin3c938fc2017-06-14 06:09:58 -0700462 if (last_log_start) {
463 // A LOG_END event was missing. Use last_timestamp.
464 RTC_DCHECK_GE(last_timestamp, *last_log_start);
465 log_segments_.push_back(
466 std::make_pair(*last_log_start, last_timestamp));
467 }
468 last_log_start = rtc::Optional<uint64_t>(parsed_log_.GetTimestamp(i));
terelius88e64e52016-07-19 01:51:06 -0700469 break;
470 }
471 case ParsedRtcEventLog::LOG_END: {
henrik.lundin3c938fc2017-06-14 06:09:58 -0700472 RTC_DCHECK(last_log_start);
473 log_segments_.push_back(
474 std::make_pair(*last_log_start, parsed_log_.GetTimestamp(i)));
475 last_log_start.reset();
terelius88e64e52016-07-19 01:51:06 -0700476 break;
477 }
terelius424e6cf2017-02-20 05:14:41 -0800478 case ParsedRtcEventLog::AUDIO_PLAYOUT_EVENT: {
henrik.lundin3c938fc2017-06-14 06:09:58 -0700479 uint32_t this_ssrc;
480 parsed_log_.GetAudioPlayout(i, &this_ssrc);
481 audio_playout_events_[this_ssrc].push_back(parsed_log_.GetTimestamp(i));
terelius424e6cf2017-02-20 05:14:41 -0800482 break;
483 }
484 case ParsedRtcEventLog::LOSS_BASED_BWE_UPDATE: {
485 LossBasedBweUpdate bwe_update;
terelius8058e582016-07-25 01:32:41 -0700486 bwe_update.timestamp = parsed_log_.GetTimestamp(i);
terelius424e6cf2017-02-20 05:14:41 -0800487 parsed_log_.GetLossBasedBweUpdate(i, &bwe_update.new_bitrate,
488 &bwe_update.fraction_loss,
489 &bwe_update.expected_packets);
terelius8058e582016-07-25 01:32:41 -0700490 bwe_loss_updates_.push_back(bwe_update);
terelius88e64e52016-07-19 01:51:06 -0700491 break;
492 }
terelius424e6cf2017-02-20 05:14:41 -0800493 case ParsedRtcEventLog::DELAY_BASED_BWE_UPDATE: {
philipel10fc0e62017-04-11 01:50:23 -0700494 bwe_delay_updates_.push_back(parsed_log_.GetDelayBasedBweUpdate(i));
terelius424e6cf2017-02-20 05:14:41 -0800495 break;
496 }
minyue4b7c9522017-01-24 04:54:59 -0800497 case ParsedRtcEventLog::AUDIO_NETWORK_ADAPTATION_EVENT: {
michaelt6e5b2192017-02-22 07:33:27 -0800498 AudioNetworkAdaptationEvent ana_event;
499 ana_event.timestamp = parsed_log_.GetTimestamp(i);
500 parsed_log_.GetAudioNetworkAdaptation(i, &ana_event.config);
501 audio_network_adaptation_events_.push_back(ana_event);
minyue4b7c9522017-01-24 04:54:59 -0800502 break;
503 }
philipel32d00102017-02-27 02:18:46 -0800504 case ParsedRtcEventLog::BWE_PROBE_CLUSTER_CREATED_EVENT: {
philipele127e7a2017-03-29 16:28:53 +0200505 bwe_probe_cluster_created_events_.push_back(
506 parsed_log_.GetBweProbeClusterCreated(i));
philipel32d00102017-02-27 02:18:46 -0800507 break;
508 }
509 case ParsedRtcEventLog::BWE_PROBE_RESULT_EVENT: {
philipele127e7a2017-03-29 16:28:53 +0200510 bwe_probe_result_events_.push_back(parsed_log_.GetBweProbeResult(i));
philipel32d00102017-02-27 02:18:46 -0800511 break;
512 }
terelius88e64e52016-07-19 01:51:06 -0700513 case ParsedRtcEventLog::UNKNOWN_EVENT: {
514 break;
515 }
516 }
terelius54ce6802016-07-13 06:44:41 -0700517 }
terelius88e64e52016-07-19 01:51:06 -0700518
terelius54ce6802016-07-13 06:44:41 -0700519 if (last_timestamp < first_timestamp) {
520 // No useful events in the log.
521 first_timestamp = last_timestamp = 0;
522 }
523 begin_time_ = first_timestamp;
524 end_time_ = last_timestamp;
tereliusdc35dcd2016-08-01 12:03:27 -0700525 call_duration_s_ = static_cast<float>(end_time_ - begin_time_) / 1000000;
henrik.lundin3c938fc2017-06-14 06:09:58 -0700526 if (last_log_start) {
527 // The log was missing the last LOG_END event. Fake it.
528 log_segments_.push_back(std::make_pair(*last_log_start, end_time_));
529 }
terelius54ce6802016-07-13 06:44:41 -0700530}
531
Niels Möller245f17e2017-08-21 10:45:07 +0200532class BitrateObserver : public SendSideCongestionController::Observer,
Stefan Holmer13181032016-07-29 14:48:54 +0200533 public RemoteBitrateObserver {
534 public:
535 BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {}
536
537 void OnNetworkChanged(uint32_t bitrate_bps,
538 uint8_t fraction_loss,
minyue78b4d562016-11-30 04:47:39 -0800539 int64_t rtt_ms,
540 int64_t probing_interval_ms) override {
Stefan Holmer13181032016-07-29 14:48:54 +0200541 last_bitrate_bps_ = bitrate_bps;
542 bitrate_updated_ = true;
543 }
544
545 void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
546 uint32_t bitrate) override {}
547
548 uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
549 bool GetAndResetBitrateUpdated() {
550 bool bitrate_updated = bitrate_updated_;
551 bitrate_updated_ = false;
552 return bitrate_updated;
553 }
554
555 private:
556 uint32_t last_bitrate_bps_;
557 bool bitrate_updated_;
558};
559
Stefan Holmer99f8e082016-09-09 13:37:50 +0200560bool EventLogAnalyzer::IsRtxSsrc(StreamId stream_id) const {
terelius0740a202016-08-08 10:21:04 -0700561 return rtx_ssrcs_.count(stream_id) == 1;
562}
563
Stefan Holmer99f8e082016-09-09 13:37:50 +0200564bool EventLogAnalyzer::IsVideoSsrc(StreamId stream_id) const {
terelius0740a202016-08-08 10:21:04 -0700565 return video_ssrcs_.count(stream_id) == 1;
566}
567
Stefan Holmer99f8e082016-09-09 13:37:50 +0200568bool EventLogAnalyzer::IsAudioSsrc(StreamId stream_id) const {
terelius0740a202016-08-08 10:21:04 -0700569 return audio_ssrcs_.count(stream_id) == 1;
570}
571
Stefan Holmer99f8e082016-09-09 13:37:50 +0200572std::string EventLogAnalyzer::GetStreamName(StreamId stream_id) const {
573 std::stringstream name;
574 if (IsAudioSsrc(stream_id)) {
575 name << "Audio ";
576 } else if (IsVideoSsrc(stream_id)) {
577 name << "Video ";
578 } else {
579 name << "Unknown ";
580 }
581 if (IsRtxSsrc(stream_id))
582 name << "RTX ";
ivocaac9d6f2016-09-22 07:01:47 -0700583 if (stream_id.GetDirection() == kIncomingPacket) {
584 name << "(In) ";
585 } else {
586 name << "(Out) ";
587 }
Stefan Holmer99f8e082016-09-09 13:37:50 +0200588 name << SsrcToString(stream_id.GetSsrc());
589 return name.str();
590}
591
terelius54ce6802016-07-13 06:44:41 -0700592void EventLogAnalyzer::CreatePacketGraph(PacketDirection desired_direction,
593 Plot* plot) {
terelius6addf492016-08-23 17:34:07 -0700594 for (auto& kv : rtp_packets_) {
595 StreamId stream_id = kv.first;
596 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
597 // Filter on direction and SSRC.
598 if (stream_id.GetDirection() != desired_direction ||
599 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
600 continue;
terelius54ce6802016-07-13 06:44:41 -0700601 }
terelius54ce6802016-07-13 06:44:41 -0700602
terelius23c595a2017-03-15 01:59:12 -0700603 TimeSeries time_series(GetStreamName(stream_id), BAR_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -0700604 ProcessPoints<LoggedRtpPacket>(
605 [](const LoggedRtpPacket& packet) -> rtc::Optional<float> {
606 return rtc::Optional<float>(packet.total_length);
607 },
608 packet_stream, begin_time_, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700609 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700610 }
611
tereliusdc35dcd2016-08-01 12:03:27 -0700612 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
613 plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin,
614 kTopMargin);
terelius54ce6802016-07-13 06:44:41 -0700615 if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
tereliusdc35dcd2016-08-01 12:03:27 -0700616 plot->SetTitle("Incoming RTP packets");
terelius54ce6802016-07-13 06:44:41 -0700617 } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
tereliusdc35dcd2016-08-01 12:03:27 -0700618 plot->SetTitle("Outgoing RTP packets");
terelius54ce6802016-07-13 06:44:41 -0700619 }
620}
621
philipelccd74892016-09-05 02:46:25 -0700622template <typename T>
623void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
624 PacketDirection desired_direction,
625 Plot* plot,
626 const std::map<StreamId, std::vector<T>>& packets,
627 const std::string& label_prefix) {
628 for (auto& kv : packets) {
629 StreamId stream_id = kv.first;
630 const std::vector<T>& packet_stream = kv.second;
631 // Filter on direction and SSRC.
632 if (stream_id.GetDirection() != desired_direction ||
633 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
634 continue;
635 }
636
terelius23c595a2017-03-15 01:59:12 -0700637 std::string label = label_prefix + " " + GetStreamName(stream_id);
638 TimeSeries time_series(label, LINE_STEP_GRAPH);
philipelccd74892016-09-05 02:46:25 -0700639 for (size_t i = 0; i < packet_stream.size(); i++) {
640 float x = static_cast<float>(packet_stream[i].timestamp - begin_time_) /
641 1000000;
philipelccd74892016-09-05 02:46:25 -0700642 time_series.points.emplace_back(x, i + 1);
643 }
644
philipel35ba9bd2017-04-19 05:58:51 -0700645 plot->AppendTimeSeries(std::move(time_series));
philipelccd74892016-09-05 02:46:25 -0700646 }
647}
648
649void EventLogAnalyzer::CreateAccumulatedPacketsGraph(
650 PacketDirection desired_direction,
651 Plot* plot) {
652 CreateAccumulatedPacketsTimeSeries(desired_direction, plot, rtp_packets_,
653 "RTP");
654 CreateAccumulatedPacketsTimeSeries(desired_direction, plot, rtcp_packets_,
655 "RTCP");
656
657 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
658 plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin);
659 if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
660 plot->SetTitle("Accumulated Incoming RTP/RTCP packets");
661 } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
662 plot->SetTitle("Accumulated Outgoing RTP/RTCP packets");
663 }
664}
665
terelius54ce6802016-07-13 06:44:41 -0700666// For each SSRC, plot the time between the consecutive playouts.
667void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
668 std::map<uint32_t, TimeSeries> time_series;
669 std::map<uint32_t, uint64_t> last_playout;
670
671 uint32_t ssrc;
terelius54ce6802016-07-13 06:44:41 -0700672
673 for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) {
674 ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i);
675 if (event_type == ParsedRtcEventLog::AUDIO_PLAYOUT_EVENT) {
676 parsed_log_.GetAudioPlayout(i, &ssrc);
677 uint64_t timestamp = parsed_log_.GetTimestamp(i);
678 if (MatchingSsrc(ssrc, desired_ssrc_)) {
679 float x = static_cast<float>(timestamp - begin_time_) / 1000000;
680 float y = static_cast<float>(timestamp - last_playout[ssrc]) / 1000;
681 if (time_series[ssrc].points.size() == 0) {
682 // There were no previusly logged playout for this SSRC.
683 // Generate a point, but place it on the x-axis.
684 y = 0;
685 }
terelius54ce6802016-07-13 06:44:41 -0700686 time_series[ssrc].points.push_back(TimeSeriesPoint(x, y));
687 last_playout[ssrc] = timestamp;
688 }
689 }
690 }
691
692 // Set labels and put in graph.
693 for (auto& kv : time_series) {
694 kv.second.label = SsrcToString(kv.first);
695 kv.second.style = BAR_GRAPH;
philipel35ba9bd2017-04-19 05:58:51 -0700696 plot->AppendTimeSeries(std::move(kv.second));
terelius54ce6802016-07-13 06:44:41 -0700697 }
698
tereliusdc35dcd2016-08-01 12:03:27 -0700699 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
700 plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin,
701 kTopMargin);
702 plot->SetTitle("Audio playout");
terelius54ce6802016-07-13 06:44:41 -0700703}
704
ivocaac9d6f2016-09-22 07:01:47 -0700705// For audio SSRCs, plot the audio level.
706void EventLogAnalyzer::CreateAudioLevelGraph(Plot* plot) {
707 std::map<StreamId, TimeSeries> time_series;
708
709 for (auto& kv : rtp_packets_) {
710 StreamId stream_id = kv.first;
711 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
712 // TODO(ivoc): When audio send/receive configs are stored in the event
713 // log, a check should be added here to only process audio
714 // streams. Tracking bug: webrtc:6399
715 for (auto& packet : packet_stream) {
716 if (packet.header.extension.hasAudioLevel) {
717 float x = static_cast<float>(packet.timestamp - begin_time_) / 1000000;
718 // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
719 // Here we convert it to dBov.
720 float y = static_cast<float>(-packet.header.extension.audioLevel);
721 time_series[stream_id].points.emplace_back(TimeSeriesPoint(x, y));
722 }
723 }
724 }
725
726 for (auto& series : time_series) {
727 series.second.label = GetStreamName(series.first);
728 series.second.style = LINE_GRAPH;
philipel35ba9bd2017-04-19 05:58:51 -0700729 plot->AppendTimeSeries(std::move(series.second));
ivocaac9d6f2016-09-22 07:01:47 -0700730 }
731
732 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
ivocbf676632016-11-24 08:30:34 -0800733 plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin,
ivocaac9d6f2016-09-22 07:01:47 -0700734 kTopMargin);
735 plot->SetTitle("Audio level");
736}
737
terelius54ce6802016-07-13 06:44:41 -0700738// For each SSRC, plot the time between the consecutive playouts.
739void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
terelius6addf492016-08-23 17:34:07 -0700740 for (auto& kv : rtp_packets_) {
741 StreamId stream_id = kv.first;
742 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
743 // Filter on direction and SSRC.
744 if (stream_id.GetDirection() != kIncomingPacket ||
745 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
746 continue;
terelius54ce6802016-07-13 06:44:41 -0700747 }
terelius54ce6802016-07-13 06:44:41 -0700748
terelius23c595a2017-03-15 01:59:12 -0700749 TimeSeries time_series(GetStreamName(stream_id), BAR_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -0700750 ProcessPairs<LoggedRtpPacket, float>(
751 [](const LoggedRtpPacket& old_packet,
752 const LoggedRtpPacket& new_packet) {
753 int64_t diff =
754 WrappingDifference(new_packet.header.sequenceNumber,
755 old_packet.header.sequenceNumber, 1ul << 16);
756 return rtc::Optional<float>(diff);
757 },
758 packet_stream, begin_time_, &time_series);
philipel35ba9bd2017-04-19 05:58:51 -0700759 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -0700760 }
761
tereliusdc35dcd2016-08-01 12:03:27 -0700762 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
763 plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
764 kTopMargin);
765 plot->SetTitle("Sequence number");
terelius54ce6802016-07-13 06:44:41 -0700766}
767
Stefan Holmer99f8e082016-09-09 13:37:50 +0200768void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
769 for (auto& kv : rtp_packets_) {
770 StreamId stream_id = kv.first;
771 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
772 // Filter on direction and SSRC.
773 if (stream_id.GetDirection() != kIncomingPacket ||
terelius4c9b4af2017-01-30 08:44:51 -0800774 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_) ||
775 packet_stream.size() == 0) {
Stefan Holmer99f8e082016-09-09 13:37:50 +0200776 continue;
777 }
778
terelius23c595a2017-03-15 01:59:12 -0700779 TimeSeries time_series(GetStreamName(stream_id), LINE_DOT_GRAPH);
Stefan Holmer99f8e082016-09-09 13:37:50 +0200780 const uint64_t kWindowUs = 1000000;
terelius4c9b4af2017-01-30 08:44:51 -0800781 const uint64_t kStep = 1000000;
782 SequenceNumberUnwrapper unwrapper_;
783 SequenceNumberUnwrapper prior_unwrapper_;
784 size_t window_index_begin = 0;
785 size_t window_index_end = 0;
786 int64_t highest_seq_number =
787 unwrapper_.Unwrap(packet_stream[0].header.sequenceNumber) - 1;
788 int64_t highest_prior_seq_number =
789 prior_unwrapper_.Unwrap(packet_stream[0].header.sequenceNumber) - 1;
790
791 for (uint64_t t = begin_time_; t < end_time_ + kStep; t += kStep) {
792 while (window_index_end < packet_stream.size() &&
793 packet_stream[window_index_end].timestamp < t) {
794 int64_t sequence_number = unwrapper_.Unwrap(
795 packet_stream[window_index_end].header.sequenceNumber);
796 highest_seq_number = std::max(highest_seq_number, sequence_number);
797 ++window_index_end;
Stefan Holmer99f8e082016-09-09 13:37:50 +0200798 }
terelius4c9b4af2017-01-30 08:44:51 -0800799 while (window_index_begin < packet_stream.size() &&
800 packet_stream[window_index_begin].timestamp < t - kWindowUs) {
801 int64_t sequence_number = prior_unwrapper_.Unwrap(
802 packet_stream[window_index_begin].header.sequenceNumber);
803 highest_prior_seq_number =
804 std::max(highest_prior_seq_number, sequence_number);
805 ++window_index_begin;
806 }
807 float x = static_cast<float>(t - begin_time_) / 1000000;
808 int64_t expected_packets = highest_seq_number - highest_prior_seq_number;
809 if (expected_packets > 0) {
810 int64_t received_packets = window_index_end - window_index_begin;
811 int64_t lost_packets = expected_packets - received_packets;
812 float y = static_cast<float>(lost_packets) / expected_packets * 100;
813 time_series.points.emplace_back(x, y);
814 }
Stefan Holmer99f8e082016-09-09 13:37:50 +0200815 }
philipel35ba9bd2017-04-19 05:58:51 -0700816 plot->AppendTimeSeries(std::move(time_series));
Stefan Holmer99f8e082016-09-09 13:37:50 +0200817 }
818
819 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
820 plot->SetSuggestedYAxis(0, 1, "Estimated loss rate (%)", kBottomMargin,
821 kTopMargin);
822 plot->SetTitle("Estimated incoming loss rate");
823}
824
terelius2ee076d2017-08-15 02:04:02 -0700825void EventLogAnalyzer::CreateIncomingDelayDeltaGraph(Plot* plot) {
terelius88e64e52016-07-19 01:51:06 -0700826 for (auto& kv : rtp_packets_) {
827 StreamId stream_id = kv.first;
tereliusccbbf8d2016-08-10 07:34:28 -0700828 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
terelius88e64e52016-07-19 01:51:06 -0700829 // Filter on direction and SSRC.
830 if (stream_id.GetDirection() != kIncomingPacket ||
Stefan Holmer99f8e082016-09-09 13:37:50 +0200831 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_) ||
832 IsAudioSsrc(stream_id) || !IsVideoSsrc(stream_id) ||
833 IsRtxSsrc(stream_id)) {
terelius88e64e52016-07-19 01:51:06 -0700834 continue;
835 }
terelius54ce6802016-07-13 06:44:41 -0700836
terelius23c595a2017-03-15 01:59:12 -0700837 TimeSeries capture_time_data(GetStreamName(stream_id) + " capture-time",
838 BAR_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -0700839 ProcessPairs<LoggedRtpPacket, double>(NetworkDelayDiff_CaptureTime,
840 packet_stream, begin_time_,
841 &capture_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700842 plot->AppendTimeSeries(std::move(capture_time_data));
terelius88e64e52016-07-19 01:51:06 -0700843
terelius23c595a2017-03-15 01:59:12 -0700844 TimeSeries send_time_data(GetStreamName(stream_id) + " abs-send-time",
845 BAR_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -0700846 ProcessPairs<LoggedRtpPacket, double>(NetworkDelayDiff_AbsSendTime,
847 packet_stream, begin_time_,
848 &send_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700849 plot->AppendTimeSeries(std::move(send_time_data));
terelius54ce6802016-07-13 06:44:41 -0700850 }
851
tereliusdc35dcd2016-08-01 12:03:27 -0700852 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
853 plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin,
854 kTopMargin);
terelius2ee076d2017-08-15 02:04:02 -0700855 plot->SetTitle("Network latency difference between consecutive packets");
terelius54ce6802016-07-13 06:44:41 -0700856}
857
terelius2ee076d2017-08-15 02:04:02 -0700858void EventLogAnalyzer::CreateIncomingDelayGraph(Plot* plot) {
terelius88e64e52016-07-19 01:51:06 -0700859 for (auto& kv : rtp_packets_) {
860 StreamId stream_id = kv.first;
tereliusccbbf8d2016-08-10 07:34:28 -0700861 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
terelius88e64e52016-07-19 01:51:06 -0700862 // Filter on direction and SSRC.
863 if (stream_id.GetDirection() != kIncomingPacket ||
Stefan Holmer99f8e082016-09-09 13:37:50 +0200864 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_) ||
865 IsAudioSsrc(stream_id) || !IsVideoSsrc(stream_id) ||
866 IsRtxSsrc(stream_id)) {
terelius88e64e52016-07-19 01:51:06 -0700867 continue;
868 }
terelius54ce6802016-07-13 06:44:41 -0700869
terelius23c595a2017-03-15 01:59:12 -0700870 TimeSeries capture_time_data(GetStreamName(stream_id) + " capture-time",
871 LINE_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -0700872 AccumulatePairs<LoggedRtpPacket, double>(NetworkDelayDiff_CaptureTime,
873 packet_stream, begin_time_,
874 &capture_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700875 plot->AppendTimeSeries(std::move(capture_time_data));
terelius88e64e52016-07-19 01:51:06 -0700876
terelius23c595a2017-03-15 01:59:12 -0700877 TimeSeries send_time_data(GetStreamName(stream_id) + " abs-send-time",
878 LINE_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -0700879 AccumulatePairs<LoggedRtpPacket, double>(NetworkDelayDiff_AbsSendTime,
880 packet_stream, begin_time_,
881 &send_time_data);
philipel35ba9bd2017-04-19 05:58:51 -0700882 plot->AppendTimeSeries(std::move(send_time_data));
terelius54ce6802016-07-13 06:44:41 -0700883 }
884
tereliusdc35dcd2016-08-01 12:03:27 -0700885 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
886 plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin,
887 kTopMargin);
terelius2ee076d2017-08-15 02:04:02 -0700888 plot->SetTitle("Network latency (relative to first packet)");
terelius54ce6802016-07-13 06:44:41 -0700889}
890
tereliusf736d232016-08-04 10:00:11 -0700891// Plot the fraction of packets lost (as perceived by the loss-based BWE).
892void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -0700893 TimeSeries time_series("Fraction lost", LINE_DOT_GRAPH);
tereliusf736d232016-08-04 10:00:11 -0700894 for (auto& bwe_update : bwe_loss_updates_) {
895 float x = static_cast<float>(bwe_update.timestamp - begin_time_) / 1000000;
896 float y = static_cast<float>(bwe_update.fraction_loss) / 255 * 100;
philipel35ba9bd2017-04-19 05:58:51 -0700897 time_series.points.emplace_back(x, y);
tereliusf736d232016-08-04 10:00:11 -0700898 }
tereliusf736d232016-08-04 10:00:11 -0700899
900 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
901 plot->SetSuggestedYAxis(0, 10, "Percent lost packets", kBottomMargin,
902 kTopMargin);
903 plot->SetTitle("Reported packet loss");
philipel35ba9bd2017-04-19 05:58:51 -0700904 plot->AppendTimeSeries(std::move(time_series));
tereliusf736d232016-08-04 10:00:11 -0700905}
906
terelius54ce6802016-07-13 06:44:41 -0700907// Plot the total bandwidth used by all RTP streams.
908void EventLogAnalyzer::CreateTotalBitrateGraph(
909 PacketDirection desired_direction,
philipel23c7f252017-07-14 06:30:03 -0700910 Plot* plot,
911 bool show_detector_state) {
terelius54ce6802016-07-13 06:44:41 -0700912 struct TimestampSize {
913 TimestampSize(uint64_t t, size_t s) : timestamp(t), size(s) {}
914 uint64_t timestamp;
915 size_t size;
916 };
917 std::vector<TimestampSize> packets;
918
919 PacketDirection direction;
920 size_t total_length;
921
922 // Extract timestamps and sizes for the relevant packets.
923 for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) {
924 ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i);
925 if (event_type == ParsedRtcEventLog::RTP_EVENT) {
perkj77cd58e2017-05-30 03:52:10 -0700926 parsed_log_.GetRtpHeader(i, &direction, nullptr, nullptr, &total_length);
terelius54ce6802016-07-13 06:44:41 -0700927 if (direction == desired_direction) {
928 uint64_t timestamp = parsed_log_.GetTimestamp(i);
929 packets.push_back(TimestampSize(timestamp, total_length));
930 }
931 }
932 }
933
934 size_t window_index_begin = 0;
935 size_t window_index_end = 0;
936 size_t bytes_in_window = 0;
terelius54ce6802016-07-13 06:44:41 -0700937
938 // Calculate a moving average of the bitrate and store in a TimeSeries.
philipel35ba9bd2017-04-19 05:58:51 -0700939 TimeSeries bitrate_series("Bitrate", LINE_GRAPH);
terelius54ce6802016-07-13 06:44:41 -0700940 for (uint64_t time = begin_time_; time < end_time_ + step_; time += step_) {
941 while (window_index_end < packets.size() &&
942 packets[window_index_end].timestamp < time) {
943 bytes_in_window += packets[window_index_end].size;
terelius6addf492016-08-23 17:34:07 -0700944 ++window_index_end;
terelius54ce6802016-07-13 06:44:41 -0700945 }
946 while (window_index_begin < packets.size() &&
947 packets[window_index_begin].timestamp < time - window_duration_) {
948 RTC_DCHECK_LE(packets[window_index_begin].size, bytes_in_window);
949 bytes_in_window -= packets[window_index_begin].size;
terelius6addf492016-08-23 17:34:07 -0700950 ++window_index_begin;
terelius54ce6802016-07-13 06:44:41 -0700951 }
952 float window_duration_in_seconds =
953 static_cast<float>(window_duration_) / 1000000;
954 float x = static_cast<float>(time - begin_time_) / 1000000;
955 float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
philipel35ba9bd2017-04-19 05:58:51 -0700956 bitrate_series.points.emplace_back(x, y);
terelius54ce6802016-07-13 06:44:41 -0700957 }
philipel35ba9bd2017-04-19 05:58:51 -0700958 plot->AppendTimeSeries(std::move(bitrate_series));
terelius54ce6802016-07-13 06:44:41 -0700959
terelius8058e582016-07-25 01:32:41 -0700960 // Overlay the send-side bandwidth estimate over the outgoing bitrate.
961 if (desired_direction == kOutgoingPacket) {
philipel35ba9bd2017-04-19 05:58:51 -0700962 TimeSeries loss_series("Loss-based estimate", LINE_STEP_GRAPH);
philipel10fc0e62017-04-11 01:50:23 -0700963 for (auto& loss_update : bwe_loss_updates_) {
terelius8058e582016-07-25 01:32:41 -0700964 float x =
philipel10fc0e62017-04-11 01:50:23 -0700965 static_cast<float>(loss_update.timestamp - begin_time_) / 1000000;
966 float y = static_cast<float>(loss_update.new_bitrate) / 1000;
philipel35ba9bd2017-04-19 05:58:51 -0700967 loss_series.points.emplace_back(x, y);
philipel10fc0e62017-04-11 01:50:23 -0700968 }
969
philipel35ba9bd2017-04-19 05:58:51 -0700970 TimeSeries delay_series("Delay-based estimate", LINE_STEP_GRAPH);
philipel23c7f252017-07-14 06:30:03 -0700971 IntervalSeries overusing_series("Overusing", "#ff8e82",
972 IntervalSeries::kHorizontal);
973 IntervalSeries underusing_series("Underusing", "#5092fc",
974 IntervalSeries::kHorizontal);
975 IntervalSeries normal_series("Normal", "#c4ffc4",
976 IntervalSeries::kHorizontal);
977 IntervalSeries* last_series = &normal_series;
978 double last_detector_switch = 0.0;
979
980 BandwidthUsage last_detector_state = BandwidthUsage::kBwNormal;
981
philipel10fc0e62017-04-11 01:50:23 -0700982 for (auto& delay_update : bwe_delay_updates_) {
983 float x =
984 static_cast<float>(delay_update.timestamp - begin_time_) / 1000000;
985 float y = static_cast<float>(delay_update.bitrate_bps) / 1000;
philipel23c7f252017-07-14 06:30:03 -0700986
987 if (last_detector_state != delay_update.detector_state) {
988 last_series->intervals.emplace_back(last_detector_switch, x);
989 last_detector_state = delay_update.detector_state;
990 last_detector_switch = x;
991
992 switch (delay_update.detector_state) {
993 case BandwidthUsage::kBwNormal:
994 last_series = &normal_series;
995 break;
996 case BandwidthUsage::kBwUnderusing:
997 last_series = &underusing_series;
998 break;
999 case BandwidthUsage::kBwOverusing:
1000 last_series = &overusing_series;
1001 break;
1002 }
1003 }
1004
philipel35ba9bd2017-04-19 05:58:51 -07001005 delay_series.points.emplace_back(x, y);
terelius8058e582016-07-25 01:32:41 -07001006 }
philipele127e7a2017-03-29 16:28:53 +02001007
philipel23c7f252017-07-14 06:30:03 -07001008 RTC_CHECK(last_series);
1009 last_series->intervals.emplace_back(last_detector_switch, end_time_);
1010
philipel35ba9bd2017-04-19 05:58:51 -07001011 TimeSeries created_series("Probe cluster created.", DOT_GRAPH);
philipele127e7a2017-03-29 16:28:53 +02001012 for (auto& cluster : bwe_probe_cluster_created_events_) {
1013 float x = static_cast<float>(cluster.timestamp - begin_time_) / 1000000;
1014 float y = static_cast<float>(cluster.bitrate_bps) / 1000;
philipel35ba9bd2017-04-19 05:58:51 -07001015 created_series.points.emplace_back(x, y);
philipele127e7a2017-03-29 16:28:53 +02001016 }
1017
philipel35ba9bd2017-04-19 05:58:51 -07001018 TimeSeries result_series("Probing results.", DOT_GRAPH);
philipele127e7a2017-03-29 16:28:53 +02001019 for (auto& result : bwe_probe_result_events_) {
1020 if (result.bitrate_bps) {
1021 float x = static_cast<float>(result.timestamp - begin_time_) / 1000000;
1022 float y = static_cast<float>(*result.bitrate_bps) / 1000;
philipel35ba9bd2017-04-19 05:58:51 -07001023 result_series.points.emplace_back(x, y);
philipele127e7a2017-03-29 16:28:53 +02001024 }
1025 }
philipel23c7f252017-07-14 06:30:03 -07001026
1027 if (show_detector_state) {
1028 plot->AppendIntervalSeries(std::move(overusing_series));
1029 plot->AppendIntervalSeries(std::move(underusing_series));
1030 plot->AppendIntervalSeries(std::move(normal_series));
1031 }
1032
1033 plot->AppendTimeSeries(std::move(bitrate_series));
philipel35ba9bd2017-04-19 05:58:51 -07001034 plot->AppendTimeSeries(std::move(loss_series));
1035 plot->AppendTimeSeries(std::move(delay_series));
1036 plot->AppendTimeSeries(std::move(created_series));
1037 plot->AppendTimeSeries(std::move(result_series));
terelius8058e582016-07-25 01:32:41 -07001038 }
philipele127e7a2017-03-29 16:28:53 +02001039
terelius2c8e8a32017-06-02 01:29:48 -07001040 // Overlay the incoming REMB over the outgoing bitrate
1041 // and outgoing REMB over incoming bitrate.
1042 PacketDirection remb_direction =
1043 desired_direction == kOutgoingPacket ? kIncomingPacket : kOutgoingPacket;
1044 TimeSeries remb_series("Remb", LINE_STEP_GRAPH);
1045 std::multimap<uint64_t, const LoggedRtcpPacket*> remb_packets;
1046 for (const auto& kv : rtcp_packets_) {
1047 if (kv.first.GetDirection() == remb_direction) {
1048 for (const LoggedRtcpPacket& rtcp_packet : kv.second) {
1049 if (rtcp_packet.type == kRtcpRemb) {
1050 remb_packets.insert(
1051 std::make_pair(rtcp_packet.timestamp, &rtcp_packet));
1052 }
1053 }
1054 }
1055 }
1056
1057 for (const auto& kv : remb_packets) {
1058 const LoggedRtcpPacket* const rtcp = kv.second;
1059 const rtcp::Remb* const remb = static_cast<rtcp::Remb*>(rtcp->packet.get());
1060 float x = static_cast<float>(rtcp->timestamp - begin_time_) / 1000000;
1061 float y = static_cast<float>(remb->bitrate_bps()) / 1000;
1062 remb_series.points.emplace_back(x, y);
1063 }
1064 plot->AppendTimeSeriesIfNotEmpty(std::move(remb_series));
1065
tereliusdc35dcd2016-08-01 12:03:27 -07001066 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1067 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
terelius54ce6802016-07-13 06:44:41 -07001068 if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
tereliusdc35dcd2016-08-01 12:03:27 -07001069 plot->SetTitle("Incoming RTP bitrate");
terelius54ce6802016-07-13 06:44:41 -07001070 } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
tereliusdc35dcd2016-08-01 12:03:27 -07001071 plot->SetTitle("Outgoing RTP bitrate");
terelius54ce6802016-07-13 06:44:41 -07001072 }
1073}
1074
1075// For each SSRC, plot the bandwidth used by that stream.
1076void EventLogAnalyzer::CreateStreamBitrateGraph(
1077 PacketDirection desired_direction,
1078 Plot* plot) {
terelius6addf492016-08-23 17:34:07 -07001079 for (auto& kv : rtp_packets_) {
1080 StreamId stream_id = kv.first;
1081 const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
1082 // Filter on direction and SSRC.
1083 if (stream_id.GetDirection() != desired_direction ||
1084 !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
1085 continue;
terelius54ce6802016-07-13 06:44:41 -07001086 }
1087
terelius23c595a2017-03-15 01:59:12 -07001088 TimeSeries time_series(GetStreamName(stream_id), LINE_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001089 MovingAverage<LoggedRtpPacket, double>(
1090 [](const LoggedRtpPacket& packet) {
1091 return rtc::Optional<double>(packet.total_length * 8.0 / 1000.0);
1092 },
1093 packet_stream, begin_time_, end_time_, window_duration_, step_,
1094 &time_series);
philipel35ba9bd2017-04-19 05:58:51 -07001095 plot->AppendTimeSeries(std::move(time_series));
terelius54ce6802016-07-13 06:44:41 -07001096 }
1097
tereliusdc35dcd2016-08-01 12:03:27 -07001098 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1099 plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
terelius54ce6802016-07-13 06:44:41 -07001100 if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
tereliusdc35dcd2016-08-01 12:03:27 -07001101 plot->SetTitle("Incoming bitrate per stream");
terelius54ce6802016-07-13 06:44:41 -07001102 } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
tereliusdc35dcd2016-08-01 12:03:27 -07001103 plot->SetTitle("Outgoing bitrate per stream");
terelius54ce6802016-07-13 06:44:41 -07001104 }
1105}
1106
tereliuse34c19c2016-08-15 08:47:14 -07001107void EventLogAnalyzer::CreateBweSimulationGraph(Plot* plot) {
stefanff421622017-04-20 03:24:01 -07001108 std::multimap<uint64_t, const LoggedRtpPacket*> outgoing_rtp;
1109 std::multimap<uint64_t, const LoggedRtcpPacket*> incoming_rtcp;
Stefan Holmer13181032016-07-29 14:48:54 +02001110
1111 for (const auto& kv : rtp_packets_) {
1112 if (kv.first.GetDirection() == PacketDirection::kOutgoingPacket) {
1113 for (const LoggedRtpPacket& rtp_packet : kv.second)
1114 outgoing_rtp.insert(std::make_pair(rtp_packet.timestamp, &rtp_packet));
1115 }
1116 }
1117
1118 for (const auto& kv : rtcp_packets_) {
1119 if (kv.first.GetDirection() == PacketDirection::kIncomingPacket) {
1120 for (const LoggedRtcpPacket& rtcp_packet : kv.second)
1121 incoming_rtcp.insert(
1122 std::make_pair(rtcp_packet.timestamp, &rtcp_packet));
1123 }
1124 }
1125
1126 SimulatedClock clock(0);
1127 BitrateObserver observer;
1128 RtcEventLogNullImpl null_event_log;
nisse0245da02016-11-30 03:35:20 -08001129 PacketRouter packet_router;
Stefan Holmer5c8942a2017-08-22 16:16:44 +02001130 PacedSender pacer(&clock, &packet_router, &null_event_log);
1131 SendSideCongestionController cc(&clock, &observer, &null_event_log, &pacer);
Stefan Holmer13181032016-07-29 14:48:54 +02001132 // TODO(holmer): Log the call config and use that here instead.
1133 static const uint32_t kDefaultStartBitrateBps = 300000;
1134 cc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
1135
terelius23c595a2017-03-15 01:59:12 -07001136 TimeSeries time_series("Delay-based estimate", LINE_DOT_GRAPH);
1137 TimeSeries acked_time_series("Acked bitrate", LINE_DOT_GRAPH);
Stefan Holmer13181032016-07-29 14:48:54 +02001138
1139 auto rtp_iterator = outgoing_rtp.begin();
1140 auto rtcp_iterator = incoming_rtcp.begin();
1141
1142 auto NextRtpTime = [&]() {
1143 if (rtp_iterator != outgoing_rtp.end())
1144 return static_cast<int64_t>(rtp_iterator->first);
1145 return std::numeric_limits<int64_t>::max();
1146 };
1147
1148 auto NextRtcpTime = [&]() {
1149 if (rtcp_iterator != incoming_rtcp.end())
1150 return static_cast<int64_t>(rtcp_iterator->first);
1151 return std::numeric_limits<int64_t>::max();
1152 };
1153
1154 auto NextProcessTime = [&]() {
1155 if (rtcp_iterator != incoming_rtcp.end() ||
1156 rtp_iterator != outgoing_rtp.end()) {
1157 return clock.TimeInMicroseconds() +
1158 std::max<int64_t>(cc.TimeUntilNextProcess() * 1000, 0);
1159 }
1160 return std::numeric_limits<int64_t>::max();
1161 };
1162
Stefan Holmer492ee282016-10-27 17:19:20 +02001163 RateStatistics acked_bitrate(250, 8000);
Stefan Holmer60e43462016-09-07 09:58:20 +02001164
Stefan Holmer13181032016-07-29 14:48:54 +02001165 int64_t time_us = std::min(NextRtpTime(), NextRtcpTime());
Stefan Holmer492ee282016-10-27 17:19:20 +02001166 int64_t last_update_us = 0;
Stefan Holmer13181032016-07-29 14:48:54 +02001167 while (time_us != std::numeric_limits<int64_t>::max()) {
1168 clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
1169 if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
stefanc3de0332016-08-02 07:22:17 -07001170 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
Stefan Holmer13181032016-07-29 14:48:54 +02001171 const LoggedRtcpPacket& rtcp = *rtcp_iterator->second;
1172 if (rtcp.type == kRtcpTransportFeedback) {
elad.alon5bbf43f2017-03-09 06:40:08 -08001173 cc.OnTransportFeedback(
1174 *static_cast<rtcp::TransportFeedback*>(rtcp.packet.get()));
1175 std::vector<PacketFeedback> feedback = cc.GetTransportFeedbackVector();
elad.alonec304f92017-03-08 05:03:53 -08001176 SortPacketFeedbackVector(&feedback);
Stefan Holmer60e43462016-09-07 09:58:20 +02001177 rtc::Optional<uint32_t> bitrate_bps;
1178 if (!feedback.empty()) {
elad.alonf9490002017-03-06 05:32:21 -08001179 for (const PacketFeedback& packet : feedback)
Stefan Holmer60e43462016-09-07 09:58:20 +02001180 acked_bitrate.Update(packet.payload_size, packet.arrival_time_ms);
1181 bitrate_bps = acked_bitrate.Rate(feedback.back().arrival_time_ms);
1182 }
1183 uint32_t y = 0;
1184 if (bitrate_bps)
1185 y = *bitrate_bps / 1000;
1186 float x = static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
1187 1000000;
1188 acked_time_series.points.emplace_back(x, y);
Stefan Holmer13181032016-07-29 14:48:54 +02001189 }
1190 ++rtcp_iterator;
1191 }
1192 if (clock.TimeInMicroseconds() >= NextRtpTime()) {
stefanc3de0332016-08-02 07:22:17 -07001193 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
Stefan Holmer13181032016-07-29 14:48:54 +02001194 const LoggedRtpPacket& rtp = *rtp_iterator->second;
1195 if (rtp.header.extension.hasTransportSequenceNumber) {
1196 RTC_DCHECK(rtp.header.extension.hasTransportSequenceNumber);
elad.alond12a8e12017-03-23 11:04:48 -07001197 cc.AddPacket(rtp.header.ssrc,
1198 rtp.header.extension.transportSequenceNumber,
elad.alon5bbf43f2017-03-09 06:40:08 -08001199 rtp.total_length, PacedPacketInfo());
Stefan Holmer13181032016-07-29 14:48:54 +02001200 rtc::SentPacket sent_packet(
1201 rtp.header.extension.transportSequenceNumber, rtp.timestamp / 1000);
1202 cc.OnSentPacket(sent_packet);
1203 }
1204 ++rtp_iterator;
1205 }
stefanc3de0332016-08-02 07:22:17 -07001206 if (clock.TimeInMicroseconds() >= NextProcessTime()) {
1207 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
Stefan Holmer13181032016-07-29 14:48:54 +02001208 cc.Process();
stefanc3de0332016-08-02 07:22:17 -07001209 }
Stefan Holmer492ee282016-10-27 17:19:20 +02001210 if (observer.GetAndResetBitrateUpdated() ||
1211 time_us - last_update_us >= 1e6) {
Stefan Holmer13181032016-07-29 14:48:54 +02001212 uint32_t y = observer.last_bitrate_bps() / 1000;
Stefan Holmer13181032016-07-29 14:48:54 +02001213 float x = static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
1214 1000000;
1215 time_series.points.emplace_back(x, y);
Stefan Holmer492ee282016-10-27 17:19:20 +02001216 last_update_us = time_us;
Stefan Holmer13181032016-07-29 14:48:54 +02001217 }
1218 time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
1219 }
1220 // Add the data set to the plot.
philipel35ba9bd2017-04-19 05:58:51 -07001221 plot->AppendTimeSeries(std::move(time_series));
1222 plot->AppendTimeSeries(std::move(acked_time_series));
Stefan Holmer13181032016-07-29 14:48:54 +02001223
tereliusdc35dcd2016-08-01 12:03:27 -07001224 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1225 plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1226 plot->SetTitle("Simulated BWE behavior");
Stefan Holmer13181032016-07-29 14:48:54 +02001227}
1228
tereliuse34c19c2016-08-15 08:47:14 -07001229void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
stefanff421622017-04-20 03:24:01 -07001230 std::multimap<uint64_t, const LoggedRtpPacket*> outgoing_rtp;
1231 std::multimap<uint64_t, const LoggedRtcpPacket*> incoming_rtcp;
stefanc3de0332016-08-02 07:22:17 -07001232
1233 for (const auto& kv : rtp_packets_) {
1234 if (kv.first.GetDirection() == PacketDirection::kOutgoingPacket) {
1235 for (const LoggedRtpPacket& rtp_packet : kv.second)
1236 outgoing_rtp.insert(std::make_pair(rtp_packet.timestamp, &rtp_packet));
1237 }
1238 }
1239
1240 for (const auto& kv : rtcp_packets_) {
1241 if (kv.first.GetDirection() == PacketDirection::kIncomingPacket) {
1242 for (const LoggedRtcpPacket& rtcp_packet : kv.second)
1243 incoming_rtcp.insert(
1244 std::make_pair(rtcp_packet.timestamp, &rtcp_packet));
1245 }
1246 }
1247
1248 SimulatedClock clock(0);
elad.alon5bbf43f2017-03-09 06:40:08 -08001249 TransportFeedbackAdapter feedback_adapter(&clock);
stefanc3de0332016-08-02 07:22:17 -07001250
stefana0a8ed72017-09-06 02:06:32 -07001251 TimeSeries late_feedback_series("Late feedback results.", DOT_GRAPH);
terelius23c595a2017-03-15 01:59:12 -07001252 TimeSeries time_series("Network Delay Change", LINE_DOT_GRAPH);
stefanc3de0332016-08-02 07:22:17 -07001253 int64_t estimated_base_delay_ms = std::numeric_limits<int64_t>::max();
1254
1255 auto rtp_iterator = outgoing_rtp.begin();
1256 auto rtcp_iterator = incoming_rtcp.begin();
1257
1258 auto NextRtpTime = [&]() {
1259 if (rtp_iterator != outgoing_rtp.end())
1260 return static_cast<int64_t>(rtp_iterator->first);
1261 return std::numeric_limits<int64_t>::max();
1262 };
1263
1264 auto NextRtcpTime = [&]() {
1265 if (rtcp_iterator != incoming_rtcp.end())
1266 return static_cast<int64_t>(rtcp_iterator->first);
1267 return std::numeric_limits<int64_t>::max();
1268 };
1269
1270 int64_t time_us = std::min(NextRtpTime(), NextRtcpTime());
stefana0a8ed72017-09-06 02:06:32 -07001271 int64_t prev_y = 0;
stefanc3de0332016-08-02 07:22:17 -07001272 while (time_us != std::numeric_limits<int64_t>::max()) {
1273 clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
1274 if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
1275 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
1276 const LoggedRtcpPacket& rtcp = *rtcp_iterator->second;
1277 if (rtcp.type == kRtcpTransportFeedback) {
Stefan Holmer60e43462016-09-07 09:58:20 +02001278 feedback_adapter.OnTransportFeedback(
1279 *static_cast<rtcp::TransportFeedback*>(rtcp.packet.get()));
elad.alonf9490002017-03-06 05:32:21 -08001280 std::vector<PacketFeedback> feedback =
1281 feedback_adapter.GetTransportFeedbackVector();
elad.alonec304f92017-03-08 05:03:53 -08001282 SortPacketFeedbackVector(&feedback);
elad.alonf9490002017-03-06 05:32:21 -08001283 for (const PacketFeedback& packet : feedback) {
stefanc3de0332016-08-02 07:22:17 -07001284 float x =
1285 static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
1286 1000000;
stefana0a8ed72017-09-06 02:06:32 -07001287 if (packet.send_time_ms == -1) {
1288 late_feedback_series.points.emplace_back(x, prev_y);
1289 continue;
1290 }
1291 int64_t y = packet.arrival_time_ms - packet.send_time_ms;
1292 prev_y = y;
stefanc3de0332016-08-02 07:22:17 -07001293 estimated_base_delay_ms = std::min(y, estimated_base_delay_ms);
1294 time_series.points.emplace_back(x, y);
1295 }
1296 }
1297 ++rtcp_iterator;
1298 }
1299 if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1300 RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1301 const LoggedRtpPacket& rtp = *rtp_iterator->second;
1302 if (rtp.header.extension.hasTransportSequenceNumber) {
1303 RTC_DCHECK(rtp.header.extension.hasTransportSequenceNumber);
elad.alond12a8e12017-03-23 11:04:48 -07001304 feedback_adapter.AddPacket(rtp.header.ssrc,
1305 rtp.header.extension.transportSequenceNumber,
philipel8aadd502017-02-23 02:56:13 -08001306 rtp.total_length, PacedPacketInfo());
stefanc3de0332016-08-02 07:22:17 -07001307 feedback_adapter.OnSentPacket(
1308 rtp.header.extension.transportSequenceNumber, rtp.timestamp / 1000);
1309 }
1310 ++rtp_iterator;
1311 }
1312 time_us = std::min(NextRtpTime(), NextRtcpTime());
1313 }
1314 // We assume that the base network delay (w/o queues) is the min delay
1315 // observed during the call.
1316 for (TimeSeriesPoint& point : time_series.points)
1317 point.y -= estimated_base_delay_ms;
stefana0a8ed72017-09-06 02:06:32 -07001318 for (TimeSeriesPoint& point : late_feedback_series.points)
1319 point.y -= estimated_base_delay_ms;
stefanc3de0332016-08-02 07:22:17 -07001320 // Add the data set to the plot.
stefana0a8ed72017-09-06 02:06:32 -07001321 plot->AppendTimeSeriesIfNotEmpty(std::move(time_series));
1322 plot->AppendTimeSeriesIfNotEmpty(std::move(late_feedback_series));
stefanc3de0332016-08-02 07:22:17 -07001323
1324 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1325 plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
1326 plot->SetTitle("Network Delay Change.");
1327}
stefan08383272016-12-20 08:51:52 -08001328
1329std::vector<std::pair<int64_t, int64_t>> EventLogAnalyzer::GetFrameTimestamps()
1330 const {
1331 std::vector<std::pair<int64_t, int64_t>> timestamps;
1332 size_t largest_stream_size = 0;
1333 const std::vector<LoggedRtpPacket>* largest_video_stream = nullptr;
1334 // Find the incoming video stream with the most number of packets that is
1335 // not rtx.
1336 for (const auto& kv : rtp_packets_) {
1337 if (kv.first.GetDirection() == kIncomingPacket &&
1338 video_ssrcs_.find(kv.first) != video_ssrcs_.end() &&
1339 rtx_ssrcs_.find(kv.first) == rtx_ssrcs_.end() &&
1340 kv.second.size() > largest_stream_size) {
1341 largest_stream_size = kv.second.size();
1342 largest_video_stream = &kv.second;
1343 }
1344 }
1345 if (largest_video_stream == nullptr) {
1346 for (auto& packet : *largest_video_stream) {
1347 if (packet.header.markerBit) {
1348 int64_t capture_ms = packet.header.timestamp / 90.0;
1349 int64_t arrival_ms = packet.timestamp / 1000.0;
1350 timestamps.push_back(std::make_pair(capture_ms, arrival_ms));
1351 }
1352 }
1353 }
1354 return timestamps;
1355}
stefane372d3c2017-02-02 08:04:18 -08001356
1357void EventLogAnalyzer::CreateTimestampGraph(Plot* plot) {
1358 for (const auto& kv : rtp_packets_) {
1359 const std::vector<LoggedRtpPacket>& rtp_packets = kv.second;
1360 StreamId stream_id = kv.first;
1361
1362 {
terelius23c595a2017-03-15 01:59:12 -07001363 TimeSeries timestamp_data(GetStreamName(stream_id) + " capture-time",
1364 LINE_DOT_GRAPH);
stefane372d3c2017-02-02 08:04:18 -08001365 for (LoggedRtpPacket packet : rtp_packets) {
1366 float x = static_cast<float>(packet.timestamp - begin_time_) / 1000000;
1367 float y = packet.header.timestamp;
1368 timestamp_data.points.emplace_back(x, y);
1369 }
philipel35ba9bd2017-04-19 05:58:51 -07001370 plot->AppendTimeSeries(std::move(timestamp_data));
stefane372d3c2017-02-02 08:04:18 -08001371 }
1372
1373 {
1374 auto kv = rtcp_packets_.find(stream_id);
1375 if (kv != rtcp_packets_.end()) {
1376 const auto& packets = kv->second;
terelius23c595a2017-03-15 01:59:12 -07001377 TimeSeries timestamp_data(
1378 GetStreamName(stream_id) + " rtcp capture-time", LINE_DOT_GRAPH);
stefane372d3c2017-02-02 08:04:18 -08001379 for (const LoggedRtcpPacket& rtcp : packets) {
1380 if (rtcp.type != kRtcpSr)
1381 continue;
1382 rtcp::SenderReport* sr;
1383 sr = static_cast<rtcp::SenderReport*>(rtcp.packet.get());
1384 float x = static_cast<float>(rtcp.timestamp - begin_time_) / 1000000;
1385 float y = sr->rtp_timestamp();
1386 timestamp_data.points.emplace_back(x, y);
1387 }
philipel35ba9bd2017-04-19 05:58:51 -07001388 plot->AppendTimeSeries(std::move(timestamp_data));
stefane372d3c2017-02-02 08:04:18 -08001389 }
1390 }
1391 }
1392
1393 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1394 plot->SetSuggestedYAxis(0, 1, "Timestamp (90khz)", kBottomMargin, kTopMargin);
1395 plot->SetTitle("Timestamps");
1396}
michaelt6e5b2192017-02-22 07:33:27 -08001397
1398void EventLogAnalyzer::CreateAudioEncoderTargetBitrateGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -07001399 TimeSeries time_series("Audio encoder target bitrate", LINE_DOT_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001400 ProcessPoints<AudioNetworkAdaptationEvent>(
1401 [](const AudioNetworkAdaptationEvent& ana_event) -> rtc::Optional<float> {
michaelt6e5b2192017-02-22 07:33:27 -08001402 if (ana_event.config.bitrate_bps)
1403 return rtc::Optional<float>(
1404 static_cast<float>(*ana_event.config.bitrate_bps));
1405 return rtc::Optional<float>();
terelius53dc23c2017-03-13 05:24:05 -07001406 },
philipel35ba9bd2017-04-19 05:58:51 -07001407 audio_network_adaptation_events_, begin_time_, &time_series);
1408 plot->AppendTimeSeries(std::move(time_series));
michaelt6e5b2192017-02-22 07:33:27 -08001409 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1410 plot->SetSuggestedYAxis(0, 1, "Bitrate (bps)", kBottomMargin, kTopMargin);
1411 plot->SetTitle("Reported audio encoder target bitrate");
1412}
1413
1414void EventLogAnalyzer::CreateAudioEncoderFrameLengthGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -07001415 TimeSeries time_series("Audio encoder frame length", LINE_DOT_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001416 ProcessPoints<AudioNetworkAdaptationEvent>(
1417 [](const AudioNetworkAdaptationEvent& ana_event) {
michaelt6e5b2192017-02-22 07:33:27 -08001418 if (ana_event.config.frame_length_ms)
1419 return rtc::Optional<float>(
1420 static_cast<float>(*ana_event.config.frame_length_ms));
1421 return rtc::Optional<float>();
terelius53dc23c2017-03-13 05:24:05 -07001422 },
philipel35ba9bd2017-04-19 05:58:51 -07001423 audio_network_adaptation_events_, begin_time_, &time_series);
1424 plot->AppendTimeSeries(std::move(time_series));
michaelt6e5b2192017-02-22 07:33:27 -08001425 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1426 plot->SetSuggestedYAxis(0, 1, "Frame length (ms)", kBottomMargin, kTopMargin);
1427 plot->SetTitle("Reported audio encoder frame length");
1428}
1429
terelius2ee076d2017-08-15 02:04:02 -07001430void EventLogAnalyzer::CreateAudioEncoderPacketLossGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -07001431 TimeSeries time_series("Audio encoder uplink packet loss fraction",
1432 LINE_DOT_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001433 ProcessPoints<AudioNetworkAdaptationEvent>(
1434 [](const AudioNetworkAdaptationEvent& ana_event) {
michaelt6e5b2192017-02-22 07:33:27 -08001435 if (ana_event.config.uplink_packet_loss_fraction)
1436 return rtc::Optional<float>(static_cast<float>(
1437 *ana_event.config.uplink_packet_loss_fraction));
1438 return rtc::Optional<float>();
terelius53dc23c2017-03-13 05:24:05 -07001439 },
philipel35ba9bd2017-04-19 05:58:51 -07001440 audio_network_adaptation_events_, begin_time_, &time_series);
1441 plot->AppendTimeSeries(std::move(time_series));
michaelt6e5b2192017-02-22 07:33:27 -08001442 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1443 plot->SetSuggestedYAxis(0, 10, "Percent lost packets", kBottomMargin,
1444 kTopMargin);
1445 plot->SetTitle("Reported audio encoder lost packets");
1446}
1447
1448void EventLogAnalyzer::CreateAudioEncoderEnableFecGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -07001449 TimeSeries time_series("Audio encoder FEC", LINE_DOT_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001450 ProcessPoints<AudioNetworkAdaptationEvent>(
1451 [](const AudioNetworkAdaptationEvent& ana_event) {
michaelt6e5b2192017-02-22 07:33:27 -08001452 if (ana_event.config.enable_fec)
1453 return rtc::Optional<float>(
1454 static_cast<float>(*ana_event.config.enable_fec));
1455 return rtc::Optional<float>();
terelius53dc23c2017-03-13 05:24:05 -07001456 },
philipel35ba9bd2017-04-19 05:58:51 -07001457 audio_network_adaptation_events_, begin_time_, &time_series);
1458 plot->AppendTimeSeries(std::move(time_series));
michaelt6e5b2192017-02-22 07:33:27 -08001459 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1460 plot->SetSuggestedYAxis(0, 1, "FEC (false/true)", kBottomMargin, kTopMargin);
1461 plot->SetTitle("Reported audio encoder FEC");
1462}
1463
1464void EventLogAnalyzer::CreateAudioEncoderEnableDtxGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -07001465 TimeSeries time_series("Audio encoder DTX", LINE_DOT_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001466 ProcessPoints<AudioNetworkAdaptationEvent>(
1467 [](const AudioNetworkAdaptationEvent& ana_event) {
michaelt6e5b2192017-02-22 07:33:27 -08001468 if (ana_event.config.enable_dtx)
1469 return rtc::Optional<float>(
1470 static_cast<float>(*ana_event.config.enable_dtx));
1471 return rtc::Optional<float>();
terelius53dc23c2017-03-13 05:24:05 -07001472 },
philipel35ba9bd2017-04-19 05:58:51 -07001473 audio_network_adaptation_events_, begin_time_, &time_series);
1474 plot->AppendTimeSeries(std::move(time_series));
michaelt6e5b2192017-02-22 07:33:27 -08001475 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1476 plot->SetSuggestedYAxis(0, 1, "DTX (false/true)", kBottomMargin, kTopMargin);
1477 plot->SetTitle("Reported audio encoder DTX");
1478}
1479
1480void EventLogAnalyzer::CreateAudioEncoderNumChannelsGraph(Plot* plot) {
philipel35ba9bd2017-04-19 05:58:51 -07001481 TimeSeries time_series("Audio encoder number of channels", LINE_DOT_GRAPH);
terelius53dc23c2017-03-13 05:24:05 -07001482 ProcessPoints<AudioNetworkAdaptationEvent>(
1483 [](const AudioNetworkAdaptationEvent& ana_event) {
michaelt6e5b2192017-02-22 07:33:27 -08001484 if (ana_event.config.num_channels)
1485 return rtc::Optional<float>(
1486 static_cast<float>(*ana_event.config.num_channels));
1487 return rtc::Optional<float>();
terelius53dc23c2017-03-13 05:24:05 -07001488 },
philipel35ba9bd2017-04-19 05:58:51 -07001489 audio_network_adaptation_events_, begin_time_, &time_series);
1490 plot->AppendTimeSeries(std::move(time_series));
michaelt6e5b2192017-02-22 07:33:27 -08001491 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1492 plot->SetSuggestedYAxis(0, 1, "Number of channels (1 (mono)/2 (stereo))",
1493 kBottomMargin, kTopMargin);
1494 plot->SetTitle("Reported audio encoder number of channels");
1495}
henrik.lundin3c938fc2017-06-14 06:09:58 -07001496
1497class NetEqStreamInput : public test::NetEqInput {
1498 public:
1499 // Does not take any ownership, and all pointers must refer to valid objects
1500 // that outlive the one constructed.
1501 NetEqStreamInput(const std::vector<LoggedRtpPacket>* packet_stream,
1502 const std::vector<uint64_t>* output_events_us,
1503 rtc::Optional<uint64_t> end_time_us)
1504 : packet_stream_(*packet_stream),
1505 packet_stream_it_(packet_stream_.begin()),
1506 output_events_us_it_(output_events_us->begin()),
1507 output_events_us_end_(output_events_us->end()),
1508 end_time_us_(end_time_us) {
1509 RTC_DCHECK(packet_stream);
1510 RTC_DCHECK(output_events_us);
1511 }
1512
1513 rtc::Optional<int64_t> NextPacketTime() const override {
1514 if (packet_stream_it_ == packet_stream_.end()) {
1515 return rtc::Optional<int64_t>();
1516 }
1517 if (end_time_us_ && packet_stream_it_->timestamp > *end_time_us_) {
1518 return rtc::Optional<int64_t>();
1519 }
1520 // Convert from us to ms.
1521 return rtc::Optional<int64_t>(packet_stream_it_->timestamp / 1000);
1522 }
1523
1524 rtc::Optional<int64_t> NextOutputEventTime() const override {
1525 if (output_events_us_it_ == output_events_us_end_) {
1526 return rtc::Optional<int64_t>();
1527 }
1528 if (end_time_us_ && *output_events_us_it_ > *end_time_us_) {
1529 return rtc::Optional<int64_t>();
1530 }
1531 // Convert from us to ms.
1532 return rtc::Optional<int64_t>(
1533 rtc::checked_cast<int64_t>(*output_events_us_it_ / 1000));
1534 }
1535
1536 std::unique_ptr<PacketData> PopPacket() override {
1537 if (packet_stream_it_ == packet_stream_.end()) {
1538 return std::unique_ptr<PacketData>();
1539 }
1540 std::unique_ptr<PacketData> packet_data(new PacketData());
1541 packet_data->header = packet_stream_it_->header;
1542 // Convert from us to ms.
1543 packet_data->time_ms = packet_stream_it_->timestamp / 1000.0;
1544
1545 // This is a header-only "dummy" packet. Set the payload to all zeros, with
1546 // length according to the virtual length.
1547 packet_data->payload.SetSize(packet_stream_it_->total_length);
1548 std::fill_n(packet_data->payload.data(), packet_data->payload.size(), 0);
1549
1550 ++packet_stream_it_;
1551 return packet_data;
1552 }
1553
1554 void AdvanceOutputEvent() override {
1555 if (output_events_us_it_ != output_events_us_end_) {
1556 ++output_events_us_it_;
1557 }
1558 }
1559
1560 bool ended() const override { return !NextEventTime(); }
1561
1562 rtc::Optional<RTPHeader> NextHeader() const override {
1563 if (packet_stream_it_ == packet_stream_.end()) {
1564 return rtc::Optional<RTPHeader>();
1565 }
1566 return rtc::Optional<RTPHeader>(packet_stream_it_->header);
1567 }
1568
1569 private:
1570 const std::vector<LoggedRtpPacket>& packet_stream_;
1571 std::vector<LoggedRtpPacket>::const_iterator packet_stream_it_;
1572 std::vector<uint64_t>::const_iterator output_events_us_it_;
1573 const std::vector<uint64_t>::const_iterator output_events_us_end_;
1574 const rtc::Optional<uint64_t> end_time_us_;
1575};
1576
1577namespace {
1578// Creates a NetEq test object and all necessary input and output helpers. Runs
1579// the test and returns the NetEqDelayAnalyzer object that was used to
1580// instrument the test.
1581std::unique_ptr<test::NetEqDelayAnalyzer> CreateNetEqTestAndRun(
1582 const std::vector<LoggedRtpPacket>* packet_stream,
1583 const std::vector<uint64_t>* output_events_us,
1584 rtc::Optional<uint64_t> end_time_us,
1585 const std::string& replacement_file_name,
1586 int file_sample_rate_hz) {
1587 std::unique_ptr<test::NetEqInput> input(
1588 new NetEqStreamInput(packet_stream, output_events_us, end_time_us));
1589
1590 constexpr int kReplacementPt = 127;
1591 std::set<uint8_t> cn_types;
1592 std::set<uint8_t> forbidden_types;
1593 input.reset(new test::NetEqReplacementInput(std::move(input), kReplacementPt,
1594 cn_types, forbidden_types));
1595
1596 NetEq::Config config;
1597 config.max_packets_in_buffer = 200;
1598 config.enable_fast_accelerate = true;
1599
1600 std::unique_ptr<test::VoidAudioSink> output(new test::VoidAudioSink());
1601
1602 test::NetEqTest::DecoderMap codecs;
1603
1604 // Create a "replacement decoder" that produces the decoded audio by reading
1605 // from a file rather than from the encoded payloads.
1606 std::unique_ptr<test::ResampleInputAudioFile> replacement_file(
1607 new test::ResampleInputAudioFile(replacement_file_name,
1608 file_sample_rate_hz));
1609 replacement_file->set_output_rate_hz(48000);
1610 std::unique_ptr<AudioDecoder> replacement_decoder(
1611 new test::FakeDecodeFromFile(std::move(replacement_file), 48000, false));
1612 test::NetEqTest::ExtDecoderMap ext_codecs;
1613 ext_codecs[kReplacementPt] = {replacement_decoder.get(),
1614 NetEqDecoder::kDecoderArbitrary,
1615 "replacement codec"};
1616
1617 std::unique_ptr<test::NetEqDelayAnalyzer> delay_cb(
1618 new test::NetEqDelayAnalyzer);
1619 test::DefaultNetEqTestErrorCallback error_cb;
1620 test::NetEqTest::Callbacks callbacks;
1621 callbacks.error_callback = &error_cb;
1622 callbacks.post_insert_packet = delay_cb.get();
1623 callbacks.get_audio_callback = delay_cb.get();
1624
1625 test::NetEqTest test(config, codecs, ext_codecs, std::move(input),
1626 std::move(output), callbacks);
1627 test.Run();
1628 return delay_cb;
1629}
1630} // namespace
1631
1632// Plots the jitter buffer delay profile. This will plot only for the first
1633// incoming audio SSRC. If the stream contains more than one incoming audio
1634// SSRC, all but the first will be ignored.
1635void EventLogAnalyzer::CreateAudioJitterBufferGraph(
1636 const std::string& replacement_file_name,
1637 int file_sample_rate_hz,
1638 Plot* plot) {
1639 const auto& incoming_audio_kv = std::find_if(
1640 rtp_packets_.begin(), rtp_packets_.end(),
1641 [this](std::pair<StreamId, std::vector<LoggedRtpPacket>> kv) {
1642 return kv.first.GetDirection() == kIncomingPacket &&
1643 this->IsAudioSsrc(kv.first);
1644 });
1645 if (incoming_audio_kv == rtp_packets_.end()) {
1646 // No incoming audio stream found.
1647 return;
1648 }
1649
1650 const uint32_t ssrc = incoming_audio_kv->first.GetSsrc();
1651
1652 std::map<uint32_t, std::vector<uint64_t>>::const_iterator output_events_it =
1653 audio_playout_events_.find(ssrc);
1654 if (output_events_it == audio_playout_events_.end()) {
1655 // Could not find output events with SSRC matching the input audio stream.
1656 // Using the first available stream of output events.
1657 output_events_it = audio_playout_events_.cbegin();
1658 }
1659
1660 rtc::Optional<uint64_t> end_time_us =
1661 log_segments_.empty()
1662 ? rtc::Optional<uint64_t>()
1663 : rtc::Optional<uint64_t>(log_segments_.front().second);
1664
1665 auto delay_cb = CreateNetEqTestAndRun(
1666 &incoming_audio_kv->second, &output_events_it->second, end_time_us,
1667 replacement_file_name, file_sample_rate_hz);
1668
1669 std::vector<float> send_times_s;
1670 std::vector<float> arrival_delay_ms;
1671 std::vector<float> corrected_arrival_delay_ms;
1672 std::vector<rtc::Optional<float>> playout_delay_ms;
1673 std::vector<rtc::Optional<float>> target_delay_ms;
1674 delay_cb->CreateGraphs(&send_times_s, &arrival_delay_ms,
1675 &corrected_arrival_delay_ms, &playout_delay_ms,
1676 &target_delay_ms);
1677 RTC_DCHECK_EQ(send_times_s.size(), arrival_delay_ms.size());
1678 RTC_DCHECK_EQ(send_times_s.size(), corrected_arrival_delay_ms.size());
1679 RTC_DCHECK_EQ(send_times_s.size(), playout_delay_ms.size());
1680 RTC_DCHECK_EQ(send_times_s.size(), target_delay_ms.size());
1681
1682 std::map<StreamId, TimeSeries> time_series_packet_arrival;
1683 std::map<StreamId, TimeSeries> time_series_relative_packet_arrival;
1684 std::map<StreamId, TimeSeries> time_series_play_time;
1685 std::map<StreamId, TimeSeries> time_series_target_time;
1686 float min_y_axis = 0.f;
1687 float max_y_axis = 0.f;
1688 const StreamId stream_id = incoming_audio_kv->first;
1689 for (size_t i = 0; i < send_times_s.size(); ++i) {
1690 time_series_packet_arrival[stream_id].points.emplace_back(
1691 TimeSeriesPoint(send_times_s[i], arrival_delay_ms[i]));
1692 time_series_relative_packet_arrival[stream_id].points.emplace_back(
1693 TimeSeriesPoint(send_times_s[i], corrected_arrival_delay_ms[i]));
1694 min_y_axis = std::min(min_y_axis, corrected_arrival_delay_ms[i]);
1695 max_y_axis = std::max(max_y_axis, corrected_arrival_delay_ms[i]);
1696 if (playout_delay_ms[i]) {
1697 time_series_play_time[stream_id].points.emplace_back(
1698 TimeSeriesPoint(send_times_s[i], *playout_delay_ms[i]));
1699 min_y_axis = std::min(min_y_axis, *playout_delay_ms[i]);
1700 max_y_axis = std::max(max_y_axis, *playout_delay_ms[i]);
1701 }
1702 if (target_delay_ms[i]) {
1703 time_series_target_time[stream_id].points.emplace_back(
1704 TimeSeriesPoint(send_times_s[i], *target_delay_ms[i]));
1705 min_y_axis = std::min(min_y_axis, *target_delay_ms[i]);
1706 max_y_axis = std::max(max_y_axis, *target_delay_ms[i]);
1707 }
1708 }
1709
1710 // This code is adapted for a single stream. The creation of the streams above
1711 // guarantee that no more than one steam is included. If multiple streams are
1712 // to be plotted, they should likely be given distinct labels below.
1713 RTC_DCHECK_EQ(time_series_relative_packet_arrival.size(), 1);
1714 for (auto& series : time_series_relative_packet_arrival) {
1715 series.second.label = "Relative packet arrival delay";
1716 series.second.style = LINE_GRAPH;
1717 plot->AppendTimeSeries(std::move(series.second));
1718 }
1719 RTC_DCHECK_EQ(time_series_play_time.size(), 1);
1720 for (auto& series : time_series_play_time) {
1721 series.second.label = "Playout delay";
1722 series.second.style = LINE_GRAPH;
1723 plot->AppendTimeSeries(std::move(series.second));
1724 }
1725 RTC_DCHECK_EQ(time_series_target_time.size(), 1);
1726 for (auto& series : time_series_target_time) {
1727 series.second.label = "Target delay";
1728 series.second.style = LINE_DOT_GRAPH;
1729 plot->AppendTimeSeries(std::move(series.second));
1730 }
1731
1732 plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1733 plot->SetYAxis(min_y_axis, max_y_axis, "Relative delay (ms)", kBottomMargin,
1734 kTopMargin);
1735 plot->SetTitle("NetEq timing");
1736}
terelius54ce6802016-07-13 06:44:41 -07001737} // namespace plotting
1738} // namespace webrtc