Add visualization of late feedback packets, and avoid plotting incorrect delays computed based on t…

webrtc/rtc_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 1229 matching lines @@
     if (kv.first.GetDirection() == PacketDirection::kIncomingPacket) {
       for (const LoggedRtcpPacket& rtcp_packet : kv.second)
         incoming_rtcp.insert(
             std::make_pair(rtcp_packet.timestamp, &rtcp_packet));
     }
   }
 
   SimulatedClock clock(0);
   TransportFeedbackAdapter feedback_adapter(&clock);
 
+  TimeSeries late_feedback_series("Late feedback results.", DOT_GRAPH);
   TimeSeries time_series("Network Delay Change", LINE_DOT_GRAPH);
   int64_t estimated_base_delay_ms = std::numeric_limits<int64_t>::max();
 
   auto rtp_iterator = outgoing_rtp.begin();
   auto rtcp_iterator = incoming_rtcp.begin();
 
   auto NextRtpTime = [&]() {
     if (rtp_iterator != outgoing_rtp.end())
       return static_cast<int64_t>(rtp_iterator->first);
     return std::numeric_limits<int64_t>::max();
   };
 
   auto NextRtcpTime = [&]() {
     if (rtcp_iterator != incoming_rtcp.end())
       return static_cast<int64_t>(rtcp_iterator->first);
     return std::numeric_limits<int64_t>::max();
   };
 
   int64_t time_us = std::min(NextRtpTime(), NextRtcpTime());
+  int64_t prev_y = 0;
   while (time_us != std::numeric_limits<int64_t>::max()) {
     clock.AdvanceTimeMicroseconds(time_us - clock.TimeInMicroseconds());
     if (clock.TimeInMicroseconds() >= NextRtcpTime()) {
       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtcpTime());
       const LoggedRtcpPacket& rtcp = *rtcp_iterator->second;
       if (rtcp.type == kRtcpTransportFeedback) {
         feedback_adapter.OnTransportFeedback(
             *static_cast<rtcp::TransportFeedback*>(rtcp.packet.get()));
         std::vector<PacketFeedback> feedback =
             feedback_adapter.GetTransportFeedbackVector();
         SortPacketFeedbackVector(&feedback);
         for (const PacketFeedback& packet : feedback) {
-          int64_t y = packet.arrival_time_ms - packet.send_time_ms;
           float x =
               static_cast<float>(clock.TimeInMicroseconds() - begin_time_) /
               1000000;
+          if (packet.send_time_ms == -1) {
+            late_feedback_series.points.emplace_back(x, prev_y);
+            continue;
+          }
+          int64_t y = packet.arrival_time_ms - packet.send_time_ms;
+          prev_y = y;
           estimated_base_delay_ms = std::min(y, estimated_base_delay_ms);
           time_series.points.emplace_back(x, y);
         }
       }
       ++rtcp_iterator;
     }
     if (clock.TimeInMicroseconds() >= NextRtpTime()) {
       RTC_DCHECK_EQ(clock.TimeInMicroseconds(), NextRtpTime());
       const LoggedRtpPacket& rtp = *rtp_iterator->second;
       if (rtp.header.extension.hasTransportSequenceNumber) {
         RTC_DCHECK(rtp.header.extension.hasTransportSequenceNumber);
         feedback_adapter.AddPacket(rtp.header.ssrc,
                                    rtp.header.extension.transportSequenceNumber,
                                    rtp.total_length, PacedPacketInfo());
         feedback_adapter.OnSentPacket(
             rtp.header.extension.transportSequenceNumber, rtp.timestamp / 1000);
       }
       ++rtp_iterator;
     }
     time_us = std::min(NextRtpTime(), NextRtcpTime());
   }
   // We assume that the base network delay (w/o queues) is the min delay
   // observed during the call.
   for (TimeSeriesPoint& point : time_series.points)
     point.y -= estimated_base_delay_ms;
+  for (TimeSeriesPoint& point : late_feedback_series.points)
+    point.y -= estimated_base_delay_ms;

[terelius, 2017/08/30 11:11:25]

FYI: This can cause negative values if the first packet is late.

[stefan-webrtc, 2017/09/01 08:53:07]

Acknowledged.

   // Add the data set to the plot.
   plot->AppendTimeSeries(std::move(time_series));
+  plot->AppendTimeSeries(std::move(late_feedback_series));

[terelius, 2017/08/30 11:11:25]

I prefer AppendTimeSeriesIfNotEmpty here.

[stefan-webrtc, 2017/09/01 08:53:07]

Done.

 
   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
   plot->SetSuggestedYAxis(0, 10, "Delay (ms)", kBottomMargin, kTopMargin);
   plot->SetTitle("Network Delay Change.");
 }
 
 std::vector<std::pair<int64_t, int64_t>> EventLogAnalyzer::GetFrameTimestamps()
     const {
   std::vector<std::pair<int64_t, int64_t>> timestamps;
   size_t largest_stream_size = 0;
@@ skipping 396 matching lines @@
     plot->AppendTimeSeries(std::move(series.second));
   }
 
   plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
   plot->SetYAxis(min_y_axis, max_y_axis, "Relative delay (ms)", kBottomMargin,
                  kTopMargin);
   plot->SetTitle("NetEq timing");
 }
 }  // namespace plotting
 }  // namespace webrtc