1 /*
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 
11 #include "webrtc/tools/event_log_visualizer/analyzer.h"
12 
13 #include <algorithm>
14 #include <limits>
15 #include <map>
16 #include <sstream>
17 #include <string>
18 #include <utility>
19 
20 #include "webrtc/base/checks.h"
21 #include "webrtc/base/logging.h"
22 #include "webrtc/base/rate_statistics.h"
23 #include "webrtc/call/audio_receive_stream.h"
24 #include "webrtc/call/audio_send_stream.h"
25 #include "webrtc/call/call.h"
26 #include "webrtc/common_types.h"
27 #include "webrtc/modules/bitrate_controller/include/bitrate_controller.h"
28 #include "webrtc/modules/congestion_controller/include/congestion_controller.h"
29 #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp.h"
30 #include "webrtc/modules/rtp_rtcp/include/rtp_rtcp_defines.h"
31 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/common_header.h"
32 #include "webrtc/modules/rtp_rtcp/source/rtcp_packet/transport_feedback.h"
33 #include "webrtc/modules/rtp_rtcp/source/rtp_header_extensions.h"
34 #include "webrtc/modules/rtp_rtcp/source/rtp_utility.h"
35 #include "webrtc/video_receive_stream.h"
36 #include "webrtc/video_send_stream.h"
37 
38 namespace webrtc {
39 namespace plotting {
40 
41 namespace {
42 
SsrcToString(uint32_t ssrc)43 std::string SsrcToString(uint32_t ssrc) {
44   std::stringstream ss;
45   ss << "SSRC " << ssrc;
46   return ss.str();
47 }
48 
49 // Checks whether an SSRC is contained in the list of desired SSRCs.
50 // Note that an empty SSRC list matches every SSRC.
MatchingSsrc(uint32_t ssrc,const std::vector<uint32_t> & desired_ssrc)51 bool MatchingSsrc(uint32_t ssrc, const std::vector<uint32_t>& desired_ssrc) {
52   if (desired_ssrc.size() == 0)
53     return true;
54   return std::find(desired_ssrc.begin(), desired_ssrc.end(), ssrc) !=
55          desired_ssrc.end();
56 }
57 
AbsSendTimeToMicroseconds(int64_t abs_send_time)58 double AbsSendTimeToMicroseconds(int64_t abs_send_time) {
59   // The timestamp is a fixed point representation with 6 bits for seconds
60   // and 18 bits for fractions of a second. Thus, we divide by 2^18 to get the
61   // time in seconds and then multiply by 1000000 to convert to microseconds.
62   static constexpr double kTimestampToMicroSec =
63       1000000.0 / static_cast<double>(1ul << 18);
64   return abs_send_time * kTimestampToMicroSec;
65 }
66 
67 // Computes the difference |later| - |earlier| where |later| and |earlier|
68 // are counters that wrap at |modulus|. The difference is chosen to have the
69 // least absolute value. For example if |modulus| is 8, then the difference will
70 // be chosen in the range [-3, 4]. If |modulus| is 9, then the difference will
71 // be in [-4, 4].
WrappingDifference(uint32_t later,uint32_t earlier,int64_t modulus)72 int64_t WrappingDifference(uint32_t later, uint32_t earlier, int64_t modulus) {
73   RTC_DCHECK_LE(1, modulus);
74   RTC_DCHECK_LT(later, modulus);
75   RTC_DCHECK_LT(earlier, modulus);
76   int64_t difference =
77       static_cast<int64_t>(later) - static_cast<int64_t>(earlier);
78   int64_t max_difference = modulus / 2;
79   int64_t min_difference = max_difference - modulus + 1;
80   if (difference > max_difference) {
81     difference -= modulus;
82   }
83   if (difference < min_difference) {
84     difference += modulus;
85   }
86   if (difference > max_difference / 2 || difference < min_difference / 2) {
87     LOG(LS_WARNING) << "Difference between" << later << " and " << earlier
88                     << " expected to be in the range (" << min_difference / 2
89                     << "," << max_difference / 2 << ") but is " << difference
90                     << ". Correct unwrapping is uncertain.";
91   }
92   return difference;
93 }
94 
95 // Return default values for header extensions, to use on streams without stored
96 // mapping data. Currently this only applies to audio streams, since the mapping
97 // is not stored in the event log.
98 // TODO(ivoc): Remove this once this mapping is stored in the event log for
99 //             audio streams. Tracking bug: webrtc:6399
GetDefaultHeaderExtensionMap()100 webrtc::RtpHeaderExtensionMap GetDefaultHeaderExtensionMap() {
101   webrtc::RtpHeaderExtensionMap default_map;
102   default_map.Register<AudioLevel>(webrtc::RtpExtension::kAudioLevelDefaultId);
103   default_map.Register<AbsoluteSendTime>(
104       webrtc::RtpExtension::kAbsSendTimeDefaultId);
105   return default_map;
106 }
107 
108 constexpr float kLeftMargin = 0.01f;
109 constexpr float kRightMargin = 0.02f;
110 constexpr float kBottomMargin = 0.02f;
111 constexpr float kTopMargin = 0.05f;
112 
113 class PacketSizeBytes {
114  public:
115   using DataType = LoggedRtpPacket;
116   using ResultType = size_t;
operator ()(const LoggedRtpPacket & packet)117   size_t operator()(const LoggedRtpPacket& packet) {
118     return packet.total_length;
119   }
120 };
121 
122 class SequenceNumberDiff {
123  public:
124   using DataType = LoggedRtpPacket;
125   using ResultType = int64_t;
operator ()(const LoggedRtpPacket & old_packet,const LoggedRtpPacket & new_packet)126   int64_t operator()(const LoggedRtpPacket& old_packet,
127                      const LoggedRtpPacket& new_packet) {
128     return WrappingDifference(new_packet.header.sequenceNumber,
129                               old_packet.header.sequenceNumber, 1ul << 16);
130   }
131 };
132 
133 class NetworkDelayDiff {
134  public:
135   class AbsSendTime {
136    public:
137     using DataType = LoggedRtpPacket;
138     using ResultType = double;
operator ()(const LoggedRtpPacket & old_packet,const LoggedRtpPacket & new_packet)139     double operator()(const LoggedRtpPacket& old_packet,
140                       const LoggedRtpPacket& new_packet) {
141       if (old_packet.header.extension.hasAbsoluteSendTime &&
142           new_packet.header.extension.hasAbsoluteSendTime) {
143         int64_t send_time_diff = WrappingDifference(
144             new_packet.header.extension.absoluteSendTime,
145             old_packet.header.extension.absoluteSendTime, 1ul << 24);
146         int64_t recv_time_diff = new_packet.timestamp - old_packet.timestamp;
147         return static_cast<double>(recv_time_diff -
148                                    AbsSendTimeToMicroseconds(send_time_diff)) /
149                1000;
150       } else {
151         return 0;
152       }
153     }
154   };
155 
156   class CaptureTime {
157    public:
158     using DataType = LoggedRtpPacket;
159     using ResultType = double;
operator ()(const LoggedRtpPacket & old_packet,const LoggedRtpPacket & new_packet)160     double operator()(const LoggedRtpPacket& old_packet,
161                       const LoggedRtpPacket& new_packet) {
162       int64_t send_time_diff = WrappingDifference(
163           new_packet.header.timestamp, old_packet.header.timestamp, 1ull << 32);
164       int64_t recv_time_diff = new_packet.timestamp - old_packet.timestamp;
165 
166       const double kVideoSampleRate = 90000;
167       // TODO(terelius): We treat all streams as video for now, even though
168       // audio might be sampled at e.g. 16kHz, because it is really difficult to
169       // figure out the true sampling rate of a stream. The effect is that the
170       // delay will be scaled incorrectly for non-video streams.
171 
172       double delay_change =
173           static_cast<double>(recv_time_diff) / 1000 -
174           static_cast<double>(send_time_diff) / kVideoSampleRate * 1000;
175       if (delay_change < -10000 || 10000 < delay_change) {
176         LOG(LS_WARNING) << "Very large delay change. Timestamps correct?";
177         LOG(LS_WARNING) << "Old capture time " << old_packet.header.timestamp
178                         << ", received time " << old_packet.timestamp;
179         LOG(LS_WARNING) << "New capture time " << new_packet.header.timestamp
180                         << ", received time " << new_packet.timestamp;
181         LOG(LS_WARNING) << "Receive time difference " << recv_time_diff << " = "
182                         << static_cast<double>(recv_time_diff) / 1000000 << "s";
183         LOG(LS_WARNING) << "Send time difference " << send_time_diff << " = "
184                         << static_cast<double>(send_time_diff) /
185                                kVideoSampleRate
186                         << "s";
187       }
188       return delay_change;
189     }
190   };
191 };
192 
193 template <typename Extractor>
194 class Accumulated {
195  public:
196   using DataType = typename Extractor::DataType;
197   using ResultType = typename Extractor::ResultType;
operator ()(const DataType & old_packet,const DataType & new_packet)198   ResultType operator()(const DataType& old_packet,
199                         const DataType& new_packet) {
200     sum += extract(old_packet, new_packet);
201     return sum;
202   }
203 
204  private:
205   Extractor extract;
206   ResultType sum = 0;
207 };
208 
209 // For each element in data, use |Extractor| to extract a y-coordinate and
210 // store the result in a TimeSeries.
211 template <typename Extractor>
Pointwise(const std::vector<typename Extractor::DataType> & data,uint64_t begin_time,TimeSeries * result)212 void Pointwise(const std::vector<typename Extractor::DataType>& data,
213                uint64_t begin_time,
214                TimeSeries* result) {
215   Extractor extract;
216   for (size_t i = 0; i < data.size(); i++) {
217     float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
218     float y = extract(data[i]);
219     result->points.emplace_back(x, y);
220   }
221 }
222 
223 // For each pair of adjacent elements in |data|, use |Extractor| to extract a
224 // y-coordinate and store the result in a TimeSeries. Note that the x-coordinate
225 // will be the time of the second element in the pair.
226 template <typename Extractor>
Pairwise(const std::vector<typename Extractor::DataType> & data,uint64_t begin_time,TimeSeries * result)227 void Pairwise(const std::vector<typename Extractor::DataType>& data,
228               uint64_t begin_time,
229               TimeSeries* result) {
230   Extractor extract;
231   for (size_t i = 1; i < data.size(); i++) {
232     float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
233     float y = extract(data[i - 1], data[i]);
234     result->points.emplace_back(x, y);
235   }
236 }
237 
238 // Calculates a moving average of |data| and stores the result in a TimeSeries.
239 // A data point is generated every |step| microseconds from |begin_time|
240 // to |end_time|. The value of each data point is the average of the data
241 // during the preceeding |window_duration_us| microseconds.
242 template <typename Extractor>
MovingAverage(const std::vector<typename Extractor::DataType> & data,uint64_t begin_time,uint64_t end_time,uint64_t window_duration_us,uint64_t step,float y_scaling,webrtc::plotting::TimeSeries * result)243 void MovingAverage(const std::vector<typename Extractor::DataType>& data,
244                    uint64_t begin_time,
245                    uint64_t end_time,
246                    uint64_t window_duration_us,
247                    uint64_t step,
248                    float y_scaling,
249                    webrtc::plotting::TimeSeries* result) {
250   size_t window_index_begin = 0;
251   size_t window_index_end = 0;
252   typename Extractor::ResultType sum_in_window = 0;
253   Extractor extract;
254 
255   for (uint64_t t = begin_time; t < end_time + step; t += step) {
256     while (window_index_end < data.size() &&
257            data[window_index_end].timestamp < t) {
258       sum_in_window += extract(data[window_index_end]);
259       ++window_index_end;
260     }
261     while (window_index_begin < data.size() &&
262            data[window_index_begin].timestamp < t - window_duration_us) {
263       sum_in_window -= extract(data[window_index_begin]);
264       ++window_index_begin;
265     }
266     float window_duration_s = static_cast<float>(window_duration_us) / 1000000;
267     float x = static_cast<float>(t - begin_time) / 1000000;
268     float y = sum_in_window / window_duration_s * y_scaling;
269     result->points.emplace_back(x, y);
270   }
271 }
272 
273 }  // namespace
274 
EventLogAnalyzer(const ParsedRtcEventLog & log)275 EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log)
276     : parsed_log_(log), window_duration_(250000), step_(10000) {
277   uint64_t first_timestamp = std::numeric_limits<uint64_t>::max();
278   uint64_t last_timestamp = std::numeric_limits<uint64_t>::min();
279 
280   // Maps a stream identifier consisting of ssrc and direction
281   // to the header extensions used by that stream,
282   std::map<StreamId, RtpHeaderExtensionMap> extension_maps;
283 
284   PacketDirection direction;
285   uint8_t header[IP_PACKET_SIZE];
286   size_t header_length;
287   size_t total_length;
288 
289   // Make a default extension map for streams without configuration information.
290   // TODO(ivoc): Once configuration of audio streams is stored in the event log,
291   //             this can be removed. Tracking bug: webrtc:6399
292   RtpHeaderExtensionMap default_extension_map = GetDefaultHeaderExtensionMap();
293 
294   for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) {
295     ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i);
296     if (event_type != ParsedRtcEventLog::VIDEO_RECEIVER_CONFIG_EVENT &&
297         event_type != ParsedRtcEventLog::VIDEO_SENDER_CONFIG_EVENT &&
298         event_type != ParsedRtcEventLog::AUDIO_RECEIVER_CONFIG_EVENT &&
299         event_type != ParsedRtcEventLog::AUDIO_SENDER_CONFIG_EVENT &&
300         event_type != ParsedRtcEventLog::LOG_START &&
301         event_type != ParsedRtcEventLog::LOG_END) {
302       uint64_t timestamp = parsed_log_.GetTimestamp(i);
303       first_timestamp = std::min(first_timestamp, timestamp);
304       last_timestamp = std::max(last_timestamp, timestamp);
305     }
306 
307     switch (parsed_log_.GetEventType(i)) {
308       case ParsedRtcEventLog::VIDEO_RECEIVER_CONFIG_EVENT: {
309         VideoReceiveStream::Config config(nullptr);
310         parsed_log_.GetVideoReceiveConfig(i, &config);
311         StreamId stream(config.rtp.remote_ssrc, kIncomingPacket);
312         extension_maps[stream] = RtpHeaderExtensionMap(config.rtp.extensions);
313         video_ssrcs_.insert(stream);
314         for (auto kv : config.rtp.rtx) {
315           StreamId rtx_stream(kv.second.ssrc, kIncomingPacket);
316           extension_maps[rtx_stream] =
317               RtpHeaderExtensionMap(config.rtp.extensions);
318           video_ssrcs_.insert(rtx_stream);
319           rtx_ssrcs_.insert(rtx_stream);
320         }
321         break;
322       }
323       case ParsedRtcEventLog::VIDEO_SENDER_CONFIG_EVENT: {
324         VideoSendStream::Config config(nullptr);
325         parsed_log_.GetVideoSendConfig(i, &config);
326         for (auto ssrc : config.rtp.ssrcs) {
327           StreamId stream(ssrc, kOutgoingPacket);
328           extension_maps[stream] = RtpHeaderExtensionMap(config.rtp.extensions);
329           video_ssrcs_.insert(stream);
330         }
331         for (auto ssrc : config.rtp.rtx.ssrcs) {
332           StreamId rtx_stream(ssrc, kOutgoingPacket);
333           extension_maps[rtx_stream] =
334               RtpHeaderExtensionMap(config.rtp.extensions);
335           video_ssrcs_.insert(rtx_stream);
336           rtx_ssrcs_.insert(rtx_stream);
337         }
338         break;
339       }
340       case ParsedRtcEventLog::AUDIO_RECEIVER_CONFIG_EVENT: {
341         AudioReceiveStream::Config config;
342         parsed_log_.GetAudioReceiveConfig(i, &config);
343         StreamId stream(config.rtp.remote_ssrc, kIncomingPacket);
344         extension_maps[stream] = RtpHeaderExtensionMap(config.rtp.extensions);
345         audio_ssrcs_.insert(stream);
346         break;
347       }
348       case ParsedRtcEventLog::AUDIO_SENDER_CONFIG_EVENT: {
349         AudioSendStream::Config config(nullptr);
350         parsed_log_.GetAudioSendConfig(i, &config);
351         StreamId stream(config.rtp.ssrc, kOutgoingPacket);
352         extension_maps[stream] = RtpHeaderExtensionMap(config.rtp.extensions);
353         audio_ssrcs_.insert(stream);
354         break;
355       }
356       case ParsedRtcEventLog::RTP_EVENT: {
357         MediaType media_type;
358         parsed_log_.GetRtpHeader(i, &direction, &media_type, header,
359                                  &header_length, &total_length);
360         // Parse header to get SSRC.
361         RtpUtility::RtpHeaderParser rtp_parser(header, header_length);
362         RTPHeader parsed_header;
363         rtp_parser.Parse(&parsed_header);
364         StreamId stream(parsed_header.ssrc, direction);
365         // Look up the extension_map and parse it again to get the extensions.
366         if (extension_maps.count(stream) == 1) {
367           RtpHeaderExtensionMap* extension_map = &extension_maps[stream];
368           rtp_parser.Parse(&parsed_header, extension_map);
369         } else {
370           // Use the default extension map.
371           // TODO(ivoc): Once configuration of audio streams is stored in the
372           //             event log, this can be removed.
373           //             Tracking bug: webrtc:6399
374           rtp_parser.Parse(&parsed_header, &default_extension_map);
375         }
376         uint64_t timestamp = parsed_log_.GetTimestamp(i);
377         rtp_packets_[stream].push_back(
378             LoggedRtpPacket(timestamp, parsed_header, total_length));
379         break;
380       }
381       case ParsedRtcEventLog::RTCP_EVENT: {
382         uint8_t packet[IP_PACKET_SIZE];
383         MediaType media_type;
384         parsed_log_.GetRtcpPacket(i, &direction, &media_type, packet,
385                                   &total_length);
386 
387         // Currently feedback is logged twice, both for audio and video.
388         // Only act on one of them.
389         if (media_type == MediaType::VIDEO) {
390           rtcp::CommonHeader header;
391           const uint8_t* packet_end = packet + total_length;
392           for (const uint8_t* block = packet; block < packet_end;
393                block = header.NextPacket()) {
394             RTC_CHECK(header.Parse(block, packet_end - block));
395             if (header.type() == rtcp::TransportFeedback::kPacketType &&
396                 header.fmt() == rtcp::TransportFeedback::kFeedbackMessageType) {
397               std::unique_ptr<rtcp::TransportFeedback> rtcp_packet(
398                   new rtcp::TransportFeedback());
399               if (rtcp_packet->Parse(header)) {
400                 uint32_t ssrc = rtcp_packet->sender_ssrc();
401                 StreamId stream(ssrc, direction);
402                 uint64_t timestamp = parsed_log_.GetTimestamp(i);
403                 rtcp_packets_[stream].push_back(LoggedRtcpPacket(
404                     timestamp, kRtcpTransportFeedback, std::move(rtcp_packet)));
405               }
406             }
407           }
408         }
409         break;
410       }
411       case ParsedRtcEventLog::LOG_START: {
412         break;
413       }
414       case ParsedRtcEventLog::LOG_END: {
415         break;
416       }
417       case ParsedRtcEventLog::BWE_PACKET_LOSS_EVENT: {
418         BwePacketLossEvent bwe_update;
419         bwe_update.timestamp = parsed_log_.GetTimestamp(i);
420         parsed_log_.GetBwePacketLossEvent(i, &bwe_update.new_bitrate,
421                                              &bwe_update.fraction_loss,
422                                              &bwe_update.expected_packets);
423         bwe_loss_updates_.push_back(bwe_update);
424         break;
425       }
426       case ParsedRtcEventLog::BWE_PACKET_DELAY_EVENT: {
427         break;
428       }
429       case ParsedRtcEventLog::AUDIO_PLAYOUT_EVENT: {
430         break;
431       }
432       case ParsedRtcEventLog::UNKNOWN_EVENT: {
433         break;
434       }
435     }
436   }
437 
438   if (last_timestamp < first_timestamp) {
439     // No useful events in the log.
440     first_timestamp = last_timestamp = 0;
441   }
442   begin_time_ = first_timestamp;
443   end_time_ = last_timestamp;
444   call_duration_s_ = static_cast<float>(end_time_ - begin_time_) / 1000000;
445 }
446 
447 class BitrateObserver : public CongestionController::Observer,
448                         public RemoteBitrateObserver {
449  public:
BitrateObserver()450   BitrateObserver() : last_bitrate_bps_(0), bitrate_updated_(false) {}
451 
452   // TODO(minyue): remove this when old OnNetworkChanged is deprecated. See
453   // https://bugs.chromium.org/p/webrtc/issues/detail?id=6796
454   using CongestionController::Observer::OnNetworkChanged;
455 
OnNetworkChanged(uint32_t bitrate_bps,uint8_t fraction_loss,int64_t rtt_ms,int64_t probing_interval_ms)456   void OnNetworkChanged(uint32_t bitrate_bps,
457                         uint8_t fraction_loss,
458                         int64_t rtt_ms,
459                         int64_t probing_interval_ms) override {
460     last_bitrate_bps_ = bitrate_bps;
461     bitrate_updated_ = true;
462   }
463 
OnReceiveBitrateChanged(const std::vector<uint32_t> & ssrcs,uint32_t bitrate)464   void OnReceiveBitrateChanged(const std::vector<uint32_t>& ssrcs,
465                                uint32_t bitrate) override {}
466 
last_bitrate_bps() const467   uint32_t last_bitrate_bps() const { return last_bitrate_bps_; }
GetAndResetBitrateUpdated()468   bool GetAndResetBitrateUpdated() {
469     bool bitrate_updated = bitrate_updated_;
470     bitrate_updated_ = false;
471     return bitrate_updated;
472   }
473 
474  private:
475   uint32_t last_bitrate_bps_;
476   bool bitrate_updated_;
477 };
478 
IsRtxSsrc(StreamId stream_id) const479 bool EventLogAnalyzer::IsRtxSsrc(StreamId stream_id) const {
480   return rtx_ssrcs_.count(stream_id) == 1;
481 }
482 
IsVideoSsrc(StreamId stream_id) const483 bool EventLogAnalyzer::IsVideoSsrc(StreamId stream_id) const {
484   return video_ssrcs_.count(stream_id) == 1;
485 }
486 
IsAudioSsrc(StreamId stream_id) const487 bool EventLogAnalyzer::IsAudioSsrc(StreamId stream_id) const {
488   return audio_ssrcs_.count(stream_id) == 1;
489 }
490 
GetStreamName(StreamId stream_id) const491 std::string EventLogAnalyzer::GetStreamName(StreamId stream_id) const {
492   std::stringstream name;
493   if (IsAudioSsrc(stream_id)) {
494     name << "Audio ";
495   } else if (IsVideoSsrc(stream_id)) {
496     name << "Video ";
497   } else {
498     name << "Unknown ";
499   }
500   if (IsRtxSsrc(stream_id))
501     name << "RTX ";
502   if (stream_id.GetDirection() == kIncomingPacket) {
503     name << "(In) ";
504   } else {
505     name << "(Out) ";
506   }
507   name << SsrcToString(stream_id.GetSsrc());
508   return name.str();
509 }
510 
CreatePacketGraph(PacketDirection desired_direction,Plot * plot)511 void EventLogAnalyzer::CreatePacketGraph(PacketDirection desired_direction,
512                                          Plot* plot) {
513   for (auto& kv : rtp_packets_) {
514     StreamId stream_id = kv.first;
515     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
516     // Filter on direction and SSRC.
517     if (stream_id.GetDirection() != desired_direction ||
518         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
519       continue;
520     }
521 
522     TimeSeries time_series;
523     time_series.label = GetStreamName(stream_id);
524     time_series.style = BAR_GRAPH;
525     Pointwise<PacketSizeBytes>(packet_stream, begin_time_, &time_series);
526     plot->series_list_.push_back(std::move(time_series));
527   }
528 
529   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
530   plot->SetSuggestedYAxis(0, 1, "Packet size (bytes)", kBottomMargin,
531                           kTopMargin);
532   if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
533     plot->SetTitle("Incoming RTP packets");
534   } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
535     plot->SetTitle("Outgoing RTP packets");
536   }
537 }
538 
539 template <typename T>
CreateAccumulatedPacketsTimeSeries(PacketDirection desired_direction,Plot * plot,const std::map<StreamId,std::vector<T>> & packets,const std::string & label_prefix)540 void EventLogAnalyzer::CreateAccumulatedPacketsTimeSeries(
541     PacketDirection desired_direction,
542     Plot* plot,
543     const std::map<StreamId, std::vector<T>>& packets,
544     const std::string& label_prefix) {
545   for (auto& kv : packets) {
546     StreamId stream_id = kv.first;
547     const std::vector<T>& packet_stream = kv.second;
548     // Filter on direction and SSRC.
549     if (stream_id.GetDirection() != desired_direction ||
550         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
551       continue;
552     }
553 
554     TimeSeries time_series;
555     time_series.label = label_prefix + " " + GetStreamName(stream_id);
556     time_series.style = LINE_GRAPH;
557 
558     for (size_t i = 0; i < packet_stream.size(); i++) {
559       float x = static_cast<float>(packet_stream[i].timestamp - begin_time_) /
560                 1000000;
561       time_series.points.emplace_back(x, i);
562       time_series.points.emplace_back(x, i + 1);
563     }
564 
565     plot->series_list_.push_back(std::move(time_series));
566   }
567 }
568 
CreateAccumulatedPacketsGraph(PacketDirection desired_direction,Plot * plot)569 void EventLogAnalyzer::CreateAccumulatedPacketsGraph(
570     PacketDirection desired_direction,
571     Plot* plot) {
572   CreateAccumulatedPacketsTimeSeries(desired_direction, plot, rtp_packets_,
573                                      "RTP");
574   CreateAccumulatedPacketsTimeSeries(desired_direction, plot, rtcp_packets_,
575                                      "RTCP");
576 
577   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
578   plot->SetSuggestedYAxis(0, 1, "Received Packets", kBottomMargin, kTopMargin);
579   if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
580     plot->SetTitle("Accumulated Incoming RTP/RTCP packets");
581   } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
582     plot->SetTitle("Accumulated Outgoing RTP/RTCP packets");
583   }
584 }
585 
586 // For each SSRC, plot the time between the consecutive playouts.
CreatePlayoutGraph(Plot * plot)587 void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
588   std::map<uint32_t, TimeSeries> time_series;
589   std::map<uint32_t, uint64_t> last_playout;
590 
591   uint32_t ssrc;
592 
593   for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) {
594     ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i);
595     if (event_type == ParsedRtcEventLog::AUDIO_PLAYOUT_EVENT) {
596       parsed_log_.GetAudioPlayout(i, &ssrc);
597       uint64_t timestamp = parsed_log_.GetTimestamp(i);
598       if (MatchingSsrc(ssrc, desired_ssrc_)) {
599         float x = static_cast<float>(timestamp - begin_time_) / 1000000;
600         float y = static_cast<float>(timestamp - last_playout[ssrc]) / 1000;
601         if (time_series[ssrc].points.size() == 0) {
602           // There were no previusly logged playout for this SSRC.
603           // Generate a point, but place it on the x-axis.
604           y = 0;
605         }
606         time_series[ssrc].points.push_back(TimeSeriesPoint(x, y));
607         last_playout[ssrc] = timestamp;
608       }
609     }
610   }
611 
612   // Set labels and put in graph.
613   for (auto& kv : time_series) {
614     kv.second.label = SsrcToString(kv.first);
615     kv.second.style = BAR_GRAPH;
616     plot->series_list_.push_back(std::move(kv.second));
617   }
618 
619   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
620   plot->SetSuggestedYAxis(0, 1, "Time since last playout (ms)", kBottomMargin,
621                           kTopMargin);
622   plot->SetTitle("Audio playout");
623 }
624 
625 // For audio SSRCs, plot the audio level.
CreateAudioLevelGraph(Plot * plot)626 void EventLogAnalyzer::CreateAudioLevelGraph(Plot* plot) {
627   std::map<StreamId, TimeSeries> time_series;
628 
629   for (auto& kv : rtp_packets_) {
630     StreamId stream_id = kv.first;
631     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
632     // TODO(ivoc): When audio send/receive configs are stored in the event
633     //             log, a check should be added here to only process audio
634     //             streams. Tracking bug: webrtc:6399
635     for (auto& packet : packet_stream) {
636       if (packet.header.extension.hasAudioLevel) {
637         float x = static_cast<float>(packet.timestamp - begin_time_) / 1000000;
638         // The audio level is stored in -dBov (so e.g. -10 dBov is stored as 10)
639         // Here we convert it to dBov.
640         float y = static_cast<float>(-packet.header.extension.audioLevel);
641         time_series[stream_id].points.emplace_back(TimeSeriesPoint(x, y));
642       }
643     }
644   }
645 
646   for (auto& series : time_series) {
647     series.second.label = GetStreamName(series.first);
648     series.second.style = LINE_GRAPH;
649     plot->series_list_.push_back(std::move(series.second));
650   }
651 
652   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
653   plot->SetYAxis(-127, 0, "Audio level (dBov)", kBottomMargin,
654                  kTopMargin);
655   plot->SetTitle("Audio level");
656 }
657 
658 // For each SSRC, plot the time between the consecutive playouts.
CreateSequenceNumberGraph(Plot * plot)659 void EventLogAnalyzer::CreateSequenceNumberGraph(Plot* plot) {
660   for (auto& kv : rtp_packets_) {
661     StreamId stream_id = kv.first;
662     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
663     // Filter on direction and SSRC.
664     if (stream_id.GetDirection() != kIncomingPacket ||
665         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
666       continue;
667     }
668 
669     TimeSeries time_series;
670     time_series.label = GetStreamName(stream_id);
671     time_series.style = BAR_GRAPH;
672     Pairwise<SequenceNumberDiff>(packet_stream, begin_time_, &time_series);
673     plot->series_list_.push_back(std::move(time_series));
674   }
675 
676   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
677   plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
678                           kTopMargin);
679   plot->SetTitle("Sequence number");
680 }
681 
CreateIncomingPacketLossGraph(Plot * plot)682 void EventLogAnalyzer::CreateIncomingPacketLossGraph(Plot* plot) {
683   for (auto& kv : rtp_packets_) {
684     StreamId stream_id = kv.first;
685     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
686     // Filter on direction and SSRC.
687     if (stream_id.GetDirection() != kIncomingPacket ||
688         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
689       continue;
690     }
691 
692     TimeSeries time_series;
693     time_series.label = GetStreamName(stream_id);
694     time_series.style = LINE_DOT_GRAPH;
695     const uint64_t kWindowUs = 1000000;
696     const LoggedRtpPacket* first_in_window = &packet_stream.front();
697     const LoggedRtpPacket* last_in_window = &packet_stream.front();
698     int packets_in_window = 0;
699     for (const LoggedRtpPacket& packet : packet_stream) {
700       if (packet.timestamp > first_in_window->timestamp + kWindowUs) {
701         uint16_t expected_num_packets = last_in_window->header.sequenceNumber -
702             first_in_window->header.sequenceNumber + 1;
703         float fraction_lost = (expected_num_packets - packets_in_window) /
704             static_cast<float>(expected_num_packets);
705         float y = fraction_lost * 100;
706         float x =
707             static_cast<float>(last_in_window->timestamp - begin_time_) /
708             1000000;
709         time_series.points.emplace_back(x, y);
710         first_in_window = &packet;
711         last_in_window = &packet;
712         packets_in_window = 1;
713         continue;
714       }
715       ++packets_in_window;
716       last_in_window = &packet;
717     }
718     plot->series_list_.push_back(std::move(time_series));
719   }
720 
721   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
722   plot->SetSuggestedYAxis(0, 1, "Estimated loss rate (%)", kBottomMargin,
723                           kTopMargin);
724   plot->SetTitle("Estimated incoming loss rate");
725 }
726 
CreateDelayChangeGraph(Plot * plot)727 void EventLogAnalyzer::CreateDelayChangeGraph(Plot* plot) {
728   for (auto& kv : rtp_packets_) {
729     StreamId stream_id = kv.first;
730     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
731     // Filter on direction and SSRC.
732     if (stream_id.GetDirection() != kIncomingPacket ||
733         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_) ||
734         IsAudioSsrc(stream_id) || !IsVideoSsrc(stream_id) ||
735         IsRtxSsrc(stream_id)) {
736       continue;
737     }
738 
739     TimeSeries capture_time_data;
740     capture_time_data.label = GetStreamName(stream_id) + " capture-time";
741     capture_time_data.style = BAR_GRAPH;
742     Pairwise<NetworkDelayDiff::CaptureTime>(packet_stream, begin_time_,
743                                             &capture_time_data);
744     plot->series_list_.push_back(std::move(capture_time_data));
745 
746     TimeSeries send_time_data;
747     send_time_data.label = GetStreamName(stream_id) + " abs-send-time";
748     send_time_data.style = BAR_GRAPH;
749     Pairwise<NetworkDelayDiff::AbsSendTime>(packet_stream, begin_time_,
750                                             &send_time_data);
751     plot->series_list_.push_back(std::move(send_time_data));
752   }
753 
754   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
755   plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin,
756                           kTopMargin);
757   plot->SetTitle("Network latency change between consecutive packets");
758 }
759 
CreateAccumulatedDelayChangeGraph(Plot * plot)760 void EventLogAnalyzer::CreateAccumulatedDelayChangeGraph(Plot* plot) {
761   for (auto& kv : rtp_packets_) {
762     StreamId stream_id = kv.first;
763     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
764     // Filter on direction and SSRC.
765     if (stream_id.GetDirection() != kIncomingPacket ||
766         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_) ||
767         IsAudioSsrc(stream_id) || !IsVideoSsrc(stream_id) ||
768         IsRtxSsrc(stream_id)) {
769       continue;
770     }
771 
772     TimeSeries capture_time_data;
773     capture_time_data.label = GetStreamName(stream_id) + " capture-time";
774     capture_time_data.style = LINE_GRAPH;
775     Pairwise<Accumulated<NetworkDelayDiff::CaptureTime>>(
776         packet_stream, begin_time_, &capture_time_data);
777     plot->series_list_.push_back(std::move(capture_time_data));
778 
779     TimeSeries send_time_data;
780     send_time_data.label = GetStreamName(stream_id) + " abs-send-time";
781     send_time_data.style = LINE_GRAPH;
782     Pairwise<Accumulated<NetworkDelayDiff::AbsSendTime>>(
783         packet_stream, begin_time_, &send_time_data);
784     plot->series_list_.push_back(std::move(send_time_data));
785   }
786 
787   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
788   plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin,
789                           kTopMargin);
790   plot->SetTitle("Accumulated network latency change");
791 }
792 
793 // Plot the fraction of packets lost (as perceived by the loss-based BWE).
CreateFractionLossGraph(Plot * plot)794 void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
795   plot->series_list_.push_back(TimeSeries());
796   for (auto& bwe_update : bwe_loss_updates_) {
797     float x = static_cast<float>(bwe_update.timestamp - begin_time_) / 1000000;
798     float y = static_cast<float>(bwe_update.fraction_loss) / 255 * 100;
799     plot->series_list_.back().points.emplace_back(x, y);
800   }
801   plot->series_list_.back().label = "Fraction lost";
802   plot->series_list_.back().style = LINE_DOT_GRAPH;
803 
804   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
805   plot->SetSuggestedYAxis(0, 10, "Percent lost packets", kBottomMargin,
806                           kTopMargin);
807   plot->SetTitle("Reported packet loss");
808 }
809 
810 // Plot the total bandwidth used by all RTP streams.
CreateTotalBitrateGraph(PacketDirection desired_direction,Plot * plot)811 void EventLogAnalyzer::CreateTotalBitrateGraph(
812     PacketDirection desired_direction,
813     Plot* plot) {
814   struct TimestampSize {
815     TimestampSize(uint64_t t, size_t s) : timestamp(t), size(s) {}
816     uint64_t timestamp;
817     size_t size;
818   };
819   std::vector<TimestampSize> packets;
820 
821   PacketDirection direction;
822   size_t total_length;
823 
824   // Extract timestamps and sizes for the relevant packets.
825   for (size_t i = 0; i < parsed_log_.GetNumberOfEvents(); i++) {
826     ParsedRtcEventLog::EventType event_type = parsed_log_.GetEventType(i);
827     if (event_type == ParsedRtcEventLog::RTP_EVENT) {
828       parsed_log_.GetRtpHeader(i, &direction, nullptr, nullptr, nullptr,
829                                &total_length);
830       if (direction == desired_direction) {
831         uint64_t timestamp = parsed_log_.GetTimestamp(i);
832         packets.push_back(TimestampSize(timestamp, total_length));
833       }
834     }
835   }
836 
837   size_t window_index_begin = 0;
838   size_t window_index_end = 0;
839   size_t bytes_in_window = 0;
840 
841   // Calculate a moving average of the bitrate and store in a TimeSeries.
842   plot->series_list_.push_back(TimeSeries());
843   for (uint64_t time = begin_time_; time < end_time_ + step_; time += step_) {
844     while (window_index_end < packets.size() &&
845            packets[window_index_end].timestamp < time) {
846       bytes_in_window += packets[window_index_end].size;
847       ++window_index_end;
848     }
849     while (window_index_begin < packets.size() &&
850            packets[window_index_begin].timestamp < time - window_duration_) {
851       RTC_DCHECK_LE(packets[window_index_begin].size, bytes_in_window);
852       bytes_in_window -= packets[window_index_begin].size;
853       ++window_index_begin;
854     }
855     float window_duration_in_seconds =
856         static_cast<float>(window_duration_) / 1000000;
857     float x = static_cast<float>(time - begin_time_) / 1000000;
858     float y = bytes_in_window * 8 / window_duration_in_seconds / 1000;
859     plot->series_list_.back().points.push_back(TimeSeriesPoint(x, y));
860   }
861 
862   // Set labels.
863   if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
864     plot->series_list_.back().label = "Incoming bitrate";
865   } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
866     plot->series_list_.back().label = "Outgoing bitrate";
867   }
868   plot->series_list_.back().style = LINE_GRAPH;
869 
870   // Overlay the send-side bandwidth estimate over the outgoing bitrate.
871   if (desired_direction == kOutgoingPacket) {
872     plot->series_list_.push_back(TimeSeries());
873     for (auto& bwe_update : bwe_loss_updates_) {
874       float x =
875           static_cast<float>(bwe_update.timestamp - begin_time_) / 1000000;
876       float y = static_cast<float>(bwe_update.new_bitrate) / 1000;
877       plot->series_list_.back().points.emplace_back(x, y);
878     }
879     plot->series_list_.back().label = "Loss-based estimate";
880     plot->series_list_.back().style = LINE_GRAPH;
881   }
882   plot->series_list_.back().style = LINE_GRAPH;
883   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
884   plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
885   if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
886     plot->SetTitle("Incoming RTP bitrate");
887   } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
888     plot->SetTitle("Outgoing RTP bitrate");
889   }
890 }
891 
892 // For each SSRC, plot the bandwidth used by that stream.
CreateStreamBitrateGraph(PacketDirection desired_direction,Plot * plot)893 void EventLogAnalyzer::CreateStreamBitrateGraph(
894     PacketDirection desired_direction,
895     Plot* plot) {
896   for (auto& kv : rtp_packets_) {
897     StreamId stream_id = kv.first;
898     const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
899     // Filter on direction and SSRC.
900     if (stream_id.GetDirection() != desired_direction ||
901         !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
902       continue;
903     }
904 
905     TimeSeries time_series;
906     time_series.label = GetStreamName(stream_id);
907     time_series.style = LINE_GRAPH;
908     double bytes_to_kilobits = 8.0 / 1000;
909     MovingAverage<PacketSizeBytes>(packet_stream, begin_time_, end_time_,
910                                    window_duration_, step_, bytes_to_kilobits,
911                                    &time_series);
912     plot->series_list_.push_back(std::move(time_series));
913   }
914 
915   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
916   plot->SetSuggestedYAxis(0, 1, "Bitrate (kbps)", kBottomMargin, kTopMargin);
917   if (desired_direction == webrtc::PacketDirection::kIncomingPacket) {
918     plot->SetTitle("Incoming bitrate per stream");
919   } else if (desired_direction == webrtc::PacketDirection::kOutgoingPacket) {
920     plot->SetTitle("Outgoing bitrate per stream");
921   }
922 }
923 
CreateBweSimulationGraph(Plot * plot)924 void EventLogAnalyzer::CreateBweSimulationGraph(Plot* plot) {
925   std::map<uint64_t, const LoggedRtpPacket*> outgoing_rtp;
926   std::map<uint64_t, const LoggedRtcpPacket*> incoming_rtcp;
927 
928   for (const auto& kv : rtp_packets_) {
929     if (kv.first.GetDirection() == PacketDirection::kOutgoingPacket) {
930       for (const LoggedRtpPacket& rtp_packet : kv.second)
931         outgoing_rtp.insert(std::make_pair(rtp_packet.timestamp, &rtp_packet));
932     }
933   }
934 
935   for (const auto& kv : rtcp_packets_) {
936     if (kv.first.GetDirection() == PacketDirection::kIncomingPacket) {
937       for (const LoggedRtcpPacket& rtcp_packet : kv.second)
938         incoming_rtcp.insert(
939             std::make_pair(rtcp_packet.timestamp, &rtcp_packet));
940     }
941   }
942 
943   SimulatedClock clock(0);
944   BitrateObserver observer;
945   RtcEventLogNullImpl null_event_log;
946   PacketRouter packet_router;
947   CongestionController cc(&clock, &observer, &observer, &null_event_log,
948                           &packet_router);
949   // TODO(holmer): Log the call config and use that here instead.
950   static const uint32_t kDefaultStartBitrateBps = 300000;
951   cc.SetBweBitrates(0, kDefaultStartBitrateBps, -1);
952 
953   TimeSeries time_series;
954   time_series.label = "Delay-based estimate";
955   time_series.style = LINE_DOT_GRAPH;
956   TimeSeries acked_time_series;
957   acked_time_series.label = "Acked bitrate";
958   acked_time_series.style = LINE_DOT_GRAPH;
959 
960   auto rtp_iterator = outgoing_rtp.begin();
961   auto rtcp_iterator = incoming_rtcp.begin();
962 
963   auto NextRtpTime = [&]() {
964     if (rtp_iterator != outgoing_rtp.end())
965       return static_cast<int64_t>(rtp_iterator->first);
966     return std::numeric_limits<int64_t>::max();
967   };
968 
969   auto NextRtcpTime = [&]() {
970     if (rtcp_iterator != incoming_rtcp.end())
971       return static_cast<int64_t>(rtcp_iterator->first);
972     return std::numeric_limits<int64_t>::max();
973   };
974 
975   auto NextProcessTime = [&]() {
976     if (rtcp_iterator != incoming_rtcp.end() ||
977         rtp_iterator != outgoing_rtp.end()) {
978       return clock.TimeInMicroseconds() +
979              std::max<int64_t>(cc.TimeUntilNextProcess() * 1000, 0);
980     }
981     return std::numeric_limits<int64_t>::max();
982   };
983 
984   RateStatistics acked_bitrate(250, 8000);
985 
986   int64_t time_us = std::min(NextRtpTime(), NextRtcpTime());
987   int64_t last_update_us = 0;
988   while (time_us != std::numeric_limits<int64_t>::max()) {
989     clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
990     if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
991       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
992       const LoggedRtcpPacket& rtcp = *rtcp_iterator->second;
993       if (rtcp.type == kRtcpTransportFeedback) {
994         TransportFeedbackObserver* observer = cc.GetTransportFeedbackObserver();
995         observer->OnTransportFeedback(*static_cast<rtcp::TransportFeedback*>(
996             rtcp.packet.get()));
997         std::vector<PacketInfo> feedback =
998             observer->GetTransportFeedbackVector();
999         rtc::Optional<uint32_t> bitrate_bps;
1000         if (!feedback.empty()) {
1001           for (const PacketInfo& packet : feedback)
1002             acked_bitrate.Update(packet.payload_size, packet.arrival_time_ms);
1003           bitrate_bps = acked_bitrate.Rate(feedback.back().arrival_time_ms);
1004         }
1005         uint32_t y = 0;
1006         if (bitrate_bps)
1007           y = *bitrate_bps / 1000;
1008         float x = static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
1009                   1000000;
1010         acked_time_series.points.emplace_back(x, y);
1011       }
1012       ++rtcp_iterator;
1013     }
1014     if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1015       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1016       const LoggedRtpPacket& rtp = *rtp_iterator->second;
1017       if (rtp.header.extension.hasTransportSequenceNumber) {
1018         RTC_DCHECK(rtp.header.extension.hasTransportSequenceNumber);
1019         cc.GetTransportFeedbackObserver()->AddPacket(
1020             rtp.header.extension.transportSequenceNumber, rtp.total_length,
1021             PacketInfo::kNotAProbe);
1022         rtc::SentPacket sent_packet(
1023             rtp.header.extension.transportSequenceNumber, rtp.timestamp / 1000);
1024         cc.OnSentPacket(sent_packet);
1025       }
1026       ++rtp_iterator;
1027     }
1028     if (clock.TimeInMicroseconds() >= NextProcessTime()) {
1029       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextProcessTime());
1030       cc.Process();
1031     }
1032     if (observer.GetAndResetBitrateUpdated() ||
1033         time_us - last_update_us >= 1e6) {
1034       uint32_t y = observer.last_bitrate_bps() / 1000;
1035       float x = static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
1036                 1000000;
1037       time_series.points.emplace_back(x, y);
1038       last_update_us = time_us;
1039     }
1040     time_us = std::min({NextRtpTime(), NextRtcpTime(), NextProcessTime()});
1041   }
1042   // Add the data set to the plot.
1043   plot->series_list_.push_back(std::move(time_series));
1044   plot->series_list_.push_back(std::move(acked_time_series));
1045 
1046   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1047   plot->SetSuggestedYAxis(0, 10, "Bitrate (kbps)", kBottomMargin, kTopMargin);
1048   plot->SetTitle("Simulated BWE behavior");
1049 }
1050 
1051 // TODO(holmer): Remove once TransportFeedbackAdapter no longer needs a
1052 // BitrateController.
1053 class NullBitrateController : public BitrateController {
1054  public:
~NullBitrateController()1055   ~NullBitrateController() override {}
CreateRtcpBandwidthObserver()1056   RtcpBandwidthObserver* CreateRtcpBandwidthObserver() override {
1057     return nullptr;
1058   }
SetStartBitrate(int start_bitrate_bps)1059   void SetStartBitrate(int start_bitrate_bps) override {}
SetMinMaxBitrate(int min_bitrate_bps,int max_bitrate_bps)1060   void SetMinMaxBitrate(int min_bitrate_bps, int max_bitrate_bps) override {}
SetBitrates(int start_bitrate_bps,int min_bitrate_bps,int max_bitrate_bps)1061   void SetBitrates(int start_bitrate_bps,
1062                    int min_bitrate_bps,
1063                    int max_bitrate_bps) override {}
ResetBitrates(int bitrate_bps,int min_bitrate_bps,int max_bitrate_bps)1064   void ResetBitrates(int bitrate_bps,
1065                      int min_bitrate_bps,
1066                      int max_bitrate_bps) override {}
OnDelayBasedBweResult(const DelayBasedBwe::Result & result)1067   void OnDelayBasedBweResult(const DelayBasedBwe::Result& result) override {}
AvailableBandwidth(uint32_t * bandwidth) const1068   bool AvailableBandwidth(uint32_t* bandwidth) const override { return false; }
SetReservedBitrate(uint32_t reserved_bitrate_bps)1069   void SetReservedBitrate(uint32_t reserved_bitrate_bps) override {}
GetNetworkParameters(uint32_t * bitrate,uint8_t * fraction_loss,int64_t * rtt)1070   bool GetNetworkParameters(uint32_t* bitrate,
1071                             uint8_t* fraction_loss,
1072                             int64_t* rtt) override {
1073     return false;
1074   }
TimeUntilNextProcess()1075   int64_t TimeUntilNextProcess() override { return 0; }
Process()1076   void Process() override {}
1077 };
1078 
CreateNetworkDelayFeedbackGraph(Plot * plot)1079 void EventLogAnalyzer::CreateNetworkDelayFeedbackGraph(Plot* plot) {
1080   std::map<uint64_t, const LoggedRtpPacket*> outgoing_rtp;
1081   std::map<uint64_t, const LoggedRtcpPacket*> incoming_rtcp;
1082 
1083   for (const auto& kv : rtp_packets_) {
1084     if (kv.first.GetDirection() == PacketDirection::kOutgoingPacket) {
1085       for (const LoggedRtpPacket& rtp_packet : kv.second)
1086         outgoing_rtp.insert(std::make_pair(rtp_packet.timestamp, &rtp_packet));
1087     }
1088   }
1089 
1090   for (const auto& kv : rtcp_packets_) {
1091     if (kv.first.GetDirection() == PacketDirection::kIncomingPacket) {
1092       for (const LoggedRtcpPacket& rtcp_packet : kv.second)
1093         incoming_rtcp.insert(
1094             std::make_pair(rtcp_packet.timestamp, &rtcp_packet));
1095     }
1096   }
1097 
1098   SimulatedClock clock(0);
1099   NullBitrateController null_controller;
1100   TransportFeedbackAdapter feedback_adapter(&clock, &null_controller);
1101   feedback_adapter.InitBwe();
1102 
1103   TimeSeries time_series;
1104   time_series.label = "Network Delay Change";
1105   time_series.style = LINE_DOT_GRAPH;
1106   int64_t estimated_base_delay_ms = std::numeric_limits<int64_t>::max();
1107 
1108   auto rtp_iterator = outgoing_rtp.begin();
1109   auto rtcp_iterator = incoming_rtcp.begin();
1110 
1111   auto NextRtpTime = [&]() {
1112     if (rtp_iterator != outgoing_rtp.end())
1113       return static_cast<int64_t>(rtp_iterator->first);
1114     return std::numeric_limits<int64_t>::max();
1115   };
1116 
1117   auto NextRtcpTime = [&]() {
1118     if (rtcp_iterator != incoming_rtcp.end())
1119       return static_cast<int64_t>(rtcp_iterator->first);
1120     return std::numeric_limits<int64_t>::max();
1121   };
1122 
1123   int64_t time_us = std::min(NextRtpTime(), NextRtcpTime());
1124   while (time_us != std::numeric_limits<int64_t>::max()) {
1125     clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
1126     if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
1127       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
1128       const LoggedRtcpPacket& rtcp = *rtcp_iterator->second;
1129       if (rtcp.type == kRtcpTransportFeedback) {
1130         feedback_adapter.OnTransportFeedback(
1131             *static_cast<rtcp::TransportFeedback*>(rtcp.packet.get()));
1132         std::vector<PacketInfo> feedback =
1133           feedback_adapter.GetTransportFeedbackVector();
1134         for (const PacketInfo& packet : feedback) {
1135           int64_t y = packet.arrival_time_ms - packet.send_time_ms;
1136           float x =
1137               static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
1138               1000000;
1139           estimated_base_delay_ms = std::min(y, estimated_base_delay_ms);
1140           time_series.points.emplace_back(x, y);
1141         }
1142       }
1143       ++rtcp_iterator;
1144     }
1145     if (clock.TimeInMicroseconds() >= NextRtpTime()) {
1146       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
1147       const LoggedRtpPacket& rtp = *rtp_iterator->second;
1148       if (rtp.header.extension.hasTransportSequenceNumber) {
1149         RTC_DCHECK(rtp.header.extension.hasTransportSequenceNumber);
1150         feedback_adapter.AddPacket(rtp.header.extension.transportSequenceNumber,
1151                                    rtp.total_length, PacketInfo::kNotAProbe);
1152         feedback_adapter.OnSentPacket(
1153             rtp.header.extension.transportSequenceNumber, rtp.timestamp / 1000);
1154       }
1155       ++rtp_iterator;
1156     }
1157     time_us = std::min(NextRtpTime(), NextRtcpTime());
1158   }
1159   // We assume that the base network delay (w/o queues) is the min delay
1160   // observed during the call.
1161   for (TimeSeriesPoint& point : time_series.points)
1162     point.y -= estimated_base_delay_ms;
1163   // Add the data set to the plot.
1164   plot->series_list_.push_back(std::move(time_series));
1165 
1166   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
1167   plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
1168   plot->SetTitle("Network Delay Change.");
1169 }
1170 
GetFrameTimestamps() const1171 std::vector<std::pair<int64_t, int64_t>> EventLogAnalyzer::GetFrameTimestamps()
1172     const {
1173   std::vector<std::pair<int64_t, int64_t>> timestamps;
1174   size_t largest_stream_size = 0;
1175   const std::vector<LoggedRtpPacket>* largest_video_stream = nullptr;
1176   // Find the incoming video stream with the most number of packets that is
1177   // not rtx.
1178   for (const auto& kv : rtp_packets_) {
1179     if (kv.first.GetDirection() == kIncomingPacket &&
1180         video_ssrcs_.find(kv.first) != video_ssrcs_.end() &&
1181         rtx_ssrcs_.find(kv.first) == rtx_ssrcs_.end() &&
1182         kv.second.size() > largest_stream_size) {
1183       largest_stream_size = kv.second.size();
1184       largest_video_stream = &kv.second;
1185     }
1186   }
1187   if (largest_video_stream == nullptr) {
1188     for (auto& packet : *largest_video_stream) {
1189       if (packet.header.markerBit) {
1190         int64_t capture_ms = packet.header.timestamp / 90.0;
1191         int64_t arrival_ms = packet.timestamp / 1000.0;
1192         timestamps.push_back(std::make_pair(capture_ms, arrival_ms));
1193       }
1194     }
1195   }
1196   return timestamps;
1197 }
1198 }  // namespace plotting
1199 }  // namespace webrtc
1200