Visualize delay changes based on both abs-send-time and capture time.

webrtc/tools/event_log_visualizer/analyzer.cc

 /*
  *  Copyright (c) 2016 The WebRTC project authors. All Rights Reserved.
  *
  *  Use of this source code is governed by a BSD-style license
  *  that can be found in the LICENSE file in the root of the source
  *  tree. An additional intellectual property rights grant can be found
  *  in the file PATENTS.  All contributing project authors may
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
@@ skipping 80 matching lines @@
     extension_map->Register(webrtc::StringToRtpExtensionType(extension.uri),
                             extension.id);
   }
 }
 
 constexpr float kLeftMargin = 0.01f;
 constexpr float kRightMargin = 0.02f;
 constexpr float kBottomMargin = 0.02f;
 constexpr float kTopMargin = 0.05f;
 
+class OneWayDelayChangeAbsSendTime {

[stefan-webrtc, 2016/08/09 11:43:17]

Can't we make these classes inherit from an Extractor base class instead of
using templates? To me it looks like we always pass in new and old
LoggedRtpPackets and get double back, it's just how it's implemented that
differs, not the types.

Or perhaps it isn't possible because of Pairwise()?

[terelius, 2016/08/09 12:04:27]

The idea is to add more functions that will be used to generate all (or most) of
the graphs. Typically it will be LoggedRtpPacket, but sometimes we have to
operate on other types.

E.g it should be possible to do something like this
Pointwise<LoggedRtpPacket, PacketSizeBytes>(packets);
Pairwise<uint64_t, PlayoutDifference>(audio_playouts);
Pointwise<BwePacketLossEvent, FractionLoss>(bwe_loss_updates);
MovingAverage<LoggedRtpPacket, PacketSizeBytes>(packets, window_size, step,
scale_bytes_to_kilobits);

We could add a base class, but then we would have to create a new one for each
type of data we are going to analyze.

[stefan-webrtc, 2016/08/09 12:19:48]

Makes sense.

[danilchap, 2016/08/09 12:39:58]

It is not easy to see from from the long name of the functor what does it do.
May be split the name:
OneWayDelay::AbsSendTime::Delta

Delta/Diff (function name instead of operator() ) shows what Extractors
calculate in general
OneWayDelay (namespace or parent class) shows what this particular extractors
calculates
AbsSendTime (trait class name) hints how it does that.

[terelius, 2016/08/09 14:42:54]

The Extractors compute a difference in this CL but they won't do so "in
general". The "typical" Extractor will just take a single packet or event and
select whatever member we are interested in.

Not sure adding a pair of colons will aid readability, but please take a look.

[danilchap, 2016/08/09 15:09:44]

It does for me, like a space between words or an extra empty line. Thank you.

+ public:
+  double operator()(const LoggedRtpPacket& old_packet,
+                    const LoggedRtpPacket& new_packet) {
+    if (old_packet.header.extension.hasAbsoluteSendTime &&
+        new_packet.header.extension.hasAbsoluteSendTime) {
+      int64_t send_time_diff = WrappingDifference(
+          new_packet.header.extension.absoluteSendTime,
+          old_packet.header.extension.absoluteSendTime, 1ul << 24);
+      int64_t recv_time_diff = new_packet.timestamp - old_packet.timestamp;
+      return static_cast<double>(recv_time_diff -
+                                 AbsSendTimeToMicroseconds(send_time_diff)) /
+             1000;
+    } else {
+      return 0;
+    }
+  }
+};
+
+class OneWayDelayChangeCaptureTime {
+ public:
+  double operator()(const LoggedRtpPacket& old_packet,
+                    const LoggedRtpPacket& new_packet) {
+    int64_t send_time_diff = WrappingDifference(
+        new_packet.header.timestamp, old_packet.header.timestamp, 1ul << 32);
+    int64_t recv_time_diff = new_packet.timestamp - old_packet.timestamp;
+
+    const double kVideoSampleRate = 90000;
+    // TODO(terelius): We treat all streams as video for now, even though
+    // audio might be sampled at e.g. 16kHz, because it is really difficult to
+    // figure out the true sampling rate of a stream. The effect is that the
+    // delay will be scaled incorrectly for non-video streams.
+
+    double delay_change =
+        static_cast<double>(recv_time_diff) / 1000 -
+        static_cast<double>(send_time_diff) / kVideoSampleRate * 1000;
+    return delay_change;
+  }
+};
+
+template <typename Extractor>

[danilchap, 2016/08/09 12:39:58]

Accumulated designed just for LoggedRtpPacket, but Pairwise take packet class as
template argument.
may be in the extractors above you can add what type they work on:
class OneWayDelayChangeCaptureTime {
 public:
  using Packet = LoggedRtpPacket;
  double Delta(const Packet& old_packet,
               const Packet& new_packet) { ...

Then Accumulated can be generalized:
template <typename Extractor>
class Accumulated {
using Packet = typename Extractor::Packet;
double operator()(const Packet& old_packet, ...

and Pairwise will not need an extra template argument:
template <typename Extractor>
void Pairwise(const std::vector<typename Extractor::Packet>& data, ...)

+class Accumulated {
+ public:
+  Accumulated() : extract(), sum(0) {}

[danilchap, 2016/08/09 12:39:58]

default constructor for Extractor probably better to omit.
default constructor for Accumulated can be removed too if you add initializing
to declaration:
private:
 Extractor extract;
 double sum = 0;
};

[terelius, 2016/08/09 14:42:54]

Done.

+  double operator()(const LoggedRtpPacket& old_packet,
+                    const LoggedRtpPacket& new_packet) {
+    sum += extract(old_packet, new_packet);
+    return sum;
+  }
+
+ private:
+  Extractor extract;
+  double sum;
+};
+
+template <typename T, typename Extractor>
+void Pairwise(const std::vector<T>& data,
+              uint64_t begin_time,
+              webrtc::plotting::TimeSeries* result) {

[danilchap, 2016/08/09 12:39:58]

since you are in ::webrtc::plotting namesapce, you probably do not need full
name, but if you want write full name, add root:
::webrtc::plotting::TimeSeries

[terelius, 2016/08/09 14:42:54]

Done. Was moving some code around.

+  Extractor extract;
+  for (size_t i = 1; i < data.size(); i++) {
+    float x = static_cast<float>(data[i].timestamp - begin_time) / 1000000;
+    float y = extract(data[i - 1], data[i]);
+    result->points.emplace_back(x, y);
+  }
+}
+
 }  // namespace
 
 EventLogAnalyzer::EventLogAnalyzer(const ParsedRtcEventLog& log)
     : parsed_log_(log), window_duration_(250000), step_(10000) {
   uint64_t first_timestamp = std::numeric_limits<uint64_t>::max();
   uint64_t last_timestamp = std::numeric_limits<uint64_t>::min();
 
   // Maps a stream identifier consisting of ssrc and direction
   // to the header extensions used by that stream,
   std::map<StreamId, RtpHeaderExtensionMap> extension_maps;
@@ skipping 328 matching lines @@
 
   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
   plot->SetSuggestedYAxis(0, 1, "Difference since last packet", kBottomMargin,
                           kTopMargin);
   plot->SetTitle("Sequence number");
 }
 
 void EventLogAnalyzer::CreateDelayChangeGraph(Plot* plot) {
   for (auto& kv : rtp_packets_) {
     StreamId stream_id = kv.first;
+    const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
+    uint32_t ssrc = stream_id.GetSsrc();
     // Filter on direction and SSRC.
     if (stream_id.GetDirection() != kIncomingPacket ||
-        !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
+        !MatchingSsrc(ssrc, desired_ssrc_) || IsAudioSsrc(stream_id) ||
+        !IsVideoSsrc(stream_id) || IsRtxSsrc(stream_id)) {
       continue;
     }
 
-    TimeSeries time_series;
-    time_series.label = SsrcToString(stream_id.GetSsrc());
-    time_series.style = BAR_GRAPH;
-    const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
-    int64_t last_abs_send_time = 0;
-    int64_t last_timestamp = 0;
-    for (const LoggedRtpPacket& packet : packet_stream) {
-      if (packet.header.extension.hasAbsoluteSendTime) {
-        int64_t send_time_diff =
-            WrappingDifference(packet.header.extension.absoluteSendTime,
-                               last_abs_send_time, 1ul << 24);
-        int64_t recv_time_diff = packet.timestamp - last_timestamp;
+    TimeSeries capture_time_data;
+    capture_time_data.label = SsrcToString(ssrc) + " capture-time";
+    capture_time_data.style = BAR_GRAPH;
+    Pairwise<LoggedRtpPacket, OneWayDelayChangeCaptureTime>(
+        packet_stream, begin_time_, &capture_time_data);
+    plot->series_list_.push_back(std::move(capture_time_data));
 
-        last_abs_send_time = packet.header.extension.absoluteSendTime;
-        last_timestamp = packet.timestamp;
-
-        float x = static_cast<float>(packet.timestamp - begin_time_) / 1000000;
-        double y =
-            static_cast<double>(recv_time_diff -
-                                AbsSendTimeToMicroseconds(send_time_diff)) /
-            1000;
-        if (time_series.points.size() == 0) {
-          // There were no previously logged packets for this SSRC.
-          // Generate a point, but place it on the x-axis.
-          y = 0;
-        }
-        time_series.points.emplace_back(x, y);
-      }
-    }
-    // Add the data set to the plot.
-    plot->series_list_.push_back(std::move(time_series));
+    TimeSeries send_time_data;
+    send_time_data.label = SsrcToString(ssrc) + " abs-send-time";
+    send_time_data.style = BAR_GRAPH;
+    Pairwise<LoggedRtpPacket, OneWayDelayChangeAbsSendTime>(
+        packet_stream, begin_time_, &send_time_data);
+    plot->series_list_.push_back(std::move(send_time_data));
   }
 
   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
   plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin,
                           kTopMargin);
   plot->SetTitle("Network latency change between consecutive packets");
 }
 
 void EventLogAnalyzer::CreateAccumulatedDelayChangeGraph(Plot* plot) {
   for (auto& kv : rtp_packets_) {
     StreamId stream_id = kv.first;
+    const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
+    uint32_t ssrc = stream_id.GetSsrc();
     // Filter on direction and SSRC.
     if (stream_id.GetDirection() != kIncomingPacket ||
-        !MatchingSsrc(stream_id.GetSsrc(), desired_ssrc_)) {
+        !MatchingSsrc(ssrc, desired_ssrc_) || IsAudioSsrc(stream_id) ||
+        !IsVideoSsrc(stream_id) || IsRtxSsrc(stream_id)) {
       continue;
     }
-    TimeSeries time_series;
-    time_series.label = SsrcToString(stream_id.GetSsrc());
-    time_series.style = LINE_GRAPH;
-    const std::vector<LoggedRtpPacket>& packet_stream = kv.second;
-    int64_t last_abs_send_time = 0;
-    int64_t last_timestamp = 0;
-    double accumulated_delay_ms = 0;
-    for (const LoggedRtpPacket& packet : packet_stream) {
-      if (packet.header.extension.hasAbsoluteSendTime) {
-        int64_t send_time_diff =
-            WrappingDifference(packet.header.extension.absoluteSendTime,
-                               last_abs_send_time, 1ul << 24);
-        int64_t recv_time_diff = packet.timestamp - last_timestamp;
 
-        last_abs_send_time = packet.header.extension.absoluteSendTime;
-        last_timestamp = packet.timestamp;
+    TimeSeries capture_time_data;
+    capture_time_data.label = SsrcToString(ssrc) + " capture-time";
+    capture_time_data.style = LINE_GRAPH;
+    Pairwise<LoggedRtpPacket, Accumulated<OneWayDelayChangeCaptureTime>>(
+        packet_stream, begin_time_, &capture_time_data);
+    plot->series_list_.push_back(std::move(capture_time_data));
 
-        float x = static_cast<float>(packet.timestamp - begin_time_) / 1000000;
-        accumulated_delay_ms +=
-            static_cast<double>(recv_time_diff -
-                                AbsSendTimeToMicroseconds(send_time_diff)) /
-            1000;
-        if (time_series.points.size() == 0) {
-          // There were no previously logged packets for this SSRC.
-          // Generate a point, but place it on the x-axis.
-          accumulated_delay_ms = 0;
-        }
-        time_series.points.emplace_back(x, accumulated_delay_ms);
-      }
-    }
-    // Add the data set to the plot.
-    plot->series_list_.push_back(std::move(time_series));
+    TimeSeries send_time_data;
+    send_time_data.label = SsrcToString(ssrc) + " abs-send-time";
+    send_time_data.style = LINE_GRAPH;
+    Pairwise<LoggedRtpPacket, Accumulated<OneWayDelayChangeAbsSendTime>>(
+        packet_stream, begin_time_, &send_time_data);
+    plot->series_list_.push_back(std::move(send_time_data));
   }
 
   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
   plot->SetSuggestedYAxis(0, 1, "Latency change (ms)", kBottomMargin,
                           kTopMargin);
   plot->SetTitle("Accumulated network latency change");
 }
 
 // Plot the fraction of packets lost (as perceived by the loss-based BWE).
 void EventLogAnalyzer::CreateFractionLossGraph(Plot* plot) {
@@ skipping 355 matching lines @@
     point.y -= estimated_base_delay_ms;
   // Add the data set to the plot.
   plot->series_list_.push_back(std::move(time_series));
 
   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
   plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
   plot->SetTitle("Network Delay Change.");
 }
 }  // namespace plotting
 }  // namespace webrtc