Plot NetEq stats in RTC event log visualizer.

Bug: webrtc:9147
Change-Id: I61ec7bc5299201e25e1efc503b73b84d5be3ebbf
Reviewed-on: https://webrtc-review.googlesource.com/71740
Commit-Queue: Minyue Li <minyue@webrtc.org>
Reviewed-by: Björn Terelius <terelius@webrtc.org>
Reviewed-by: Henrik Lundin <henrik.lundin@webrtc.org>
Cr-Commit-Position: refs/heads/master@{#23151}

logging/rtc_event_log/rtc_event_log_parser_new.cc

@@ -633,8 +633,7 @@ void ParsedRtcEventLogNew::StoreParsedEvent(const rtclog::Event& event) {
     }
     case ParsedRtcEventLogNew::AUDIO_PLAYOUT_EVENT: {
       LoggedAudioPlayoutEvent playout_event = GetAudioPlayout(event);
-      audio_playout_events_[playout_event.ssrc].push_back(
+      audio_playout_events_[playout_event.ssrc].push_back(playout_event);
-          playout_event.timestamp_us);
       break;
     }
     case ParsedRtcEventLogNew::LOSS_BASED_BWE_UPDATE: {

logging/rtc_event_log/rtc_event_log_parser_new.h

@@ -636,7 +636,8 @@ class ParsedRtcEventLogNew {
   const std::vector<LoggedStopEvent>& stop_log_events() const {
     return stop_log_events_;
   }
-  const std::map<uint32_t, std::vector<int64_t>>& audio_playout_events() const {
+  const std::map<uint32_t, std::vector<LoggedAudioPlayoutEvent>>&
+  audio_playout_events() const {
     return audio_playout_events_;
   }
   const std::vector<LoggedAudioNetworkAdaptationEvent>&
@@ -874,8 +875,8 @@ class ParsedRtcEventLogNew {
   std::vector<LoggedStartEvent> start_log_events_;
   std::vector<LoggedStopEvent> stop_log_events_;
 
-  // Maps an SSRC to the timestamps of parsed audio playout events.
+  std::map<uint32_t, std::vector<LoggedAudioPlayoutEvent>>
-  std::map<uint32_t, std::vector<int64_t>> audio_playout_events_;
+      audio_playout_events_;
 
   std::vector<LoggedAudioNetworkAdaptationEvent>
       audio_network_adaptation_events_;

modules/audio_coding/neteq/tools/neteq_input.h

@@ -32,7 +32,7 @@ class NetEqInput {
 
     RTPHeader header;
     rtc::Buffer payload;
-    double time_ms;
+    int64_t time_ms;
   };
 
   virtual ~NetEqInput() = default;

rtc_tools/event_log_visualizer/analyzer.cc

@@ -604,16 +604,15 @@ void EventLogAnalyzer::CreatePlayoutGraph(Plot* plot) {
     uint32_t ssrc = playout_stream.first;
     if (!MatchingSsrc(ssrc, desired_ssrc_))
       continue;
-    rtc::Optional<int64_t> last_playout;
+    rtc::Optional<int64_t> last_playout_ms;
     TimeSeries time_series(SsrcToString(ssrc), LineStyle::kBar);
-    for (const auto& playout_time : playout_stream.second) {
+    for (const auto& playout_event : playout_stream.second) {
-      float x = ToCallTime(playout_time);
+      float x = ToCallTime(playout_event.log_time_us());
+      int64_t playout_time_ms = playout_event.log_time_ms();
       // If there were no previous playouts, place the point on the x-axis.
-      float y = static_cast<float>(playout_time -
+      float y = playout_time_ms - last_playout_ms.value_or(playout_time_ms);
-                                   last_playout.value_or(playout_time)) /
-                1000;
       time_series.points.push_back(TimeSeriesPoint(x, y));
-      last_playout.emplace(playout_time);
+      last_playout_ms.emplace(playout_time_ms);
     }
     plot->AppendTimeSeries(std::move(time_series));
   }
@@ -1561,37 +1560,35 @@ class NetEqStreamInput : public test::NetEqInput {
   // Does not take any ownership, and all pointers must refer to valid objects
   // that outlive the one constructed.
   NetEqStreamInput(const std::vector<LoggedRtpPacketIncoming>* packet_stream,
-                   const std::vector<int64_t>* output_events_us,
+                   const std::vector<LoggedAudioPlayoutEvent>* output_events,
-                   rtc::Optional<int64_t> end_time_us)
+                   rtc::Optional<int64_t> end_time_ms)
       : packet_stream_(*packet_stream),
         packet_stream_it_(packet_stream_.begin()),
-        output_events_us_it_(output_events_us->begin()),
+        output_events_it_(output_events->begin()),
-        output_events_us_end_(output_events_us->end()),
+        output_events_end_(output_events->end()),
-        end_time_us_(end_time_us) {
+        end_time_ms_(end_time_ms) {
     RTC_DCHECK(packet_stream);
-    RTC_DCHECK(output_events_us);
+    RTC_DCHECK(output_events);
   }
 
   rtc::Optional<int64_t> NextPacketTime() const override {
     if (packet_stream_it_ == packet_stream_.end()) {
       return rtc::nullopt;
     }
-    if (end_time_us_ && packet_stream_it_->rtp.log_time_us() > *end_time_us_) {
+    if (end_time_ms_ && packet_stream_it_->rtp.log_time_ms() > *end_time_ms_) {
       return rtc::nullopt;
     }
-    // Convert from us to ms.
+    return packet_stream_it_->rtp.log_time_ms();
-    return packet_stream_it_->rtp.log_time_us() / 1000;
   }
 
   rtc::Optional<int64_t> NextOutputEventTime() const override {
-    if (output_events_us_it_ == output_events_us_end_) {
+    if (output_events_it_ == output_events_end_) {
       return rtc::nullopt;
     }
-    if (end_time_us_ && *output_events_us_it_ > *end_time_us_) {
+    if (end_time_ms_ && output_events_it_->log_time_ms() > *end_time_ms_) {
       return rtc::nullopt;
     }
-    // Convert from us to ms.
+    return output_events_it_->log_time_ms();
-    return rtc::checked_cast<int64_t>(*output_events_us_it_ / 1000);
   }
 
   std::unique_ptr<PacketData> PopPacket() override {
@@ -1600,8 +1597,7 @@ class NetEqStreamInput : public test::NetEqInput {
     }
     std::unique_ptr<PacketData> packet_data(new PacketData());
     packet_data->header = packet_stream_it_->rtp.header;
-    // Convert from us to ms.
+    packet_data->time_ms = packet_stream_it_->rtp.log_time_ms();
-    packet_data->time_ms = packet_stream_it_->rtp.log_time_us() / 1000.0;
 
     // This is a header-only "dummy" packet. Set the payload to all zeros, with
     // length according to the virtual length.
@@ -1614,8 +1610,8 @@ class NetEqStreamInput : public test::NetEqInput {
   }
 
   void AdvanceOutputEvent() override {
-    if (output_events_us_it_ != output_events_us_end_) {
+    if (output_events_it_ != output_events_end_) {
-      ++output_events_us_it_;
+      ++output_events_it_;
     }
   }
 
@@ -1631,9 +1627,9 @@ class NetEqStreamInput : public test::NetEqInput {
  private:
   const std::vector<LoggedRtpPacketIncoming>& packet_stream_;
   std::vector<LoggedRtpPacketIncoming>::const_iterator packet_stream_it_;
-  std::vector<int64_t>::const_iterator output_events_us_it_;
+  std::vector<LoggedAudioPlayoutEvent>::const_iterator output_events_it_;
-  const std::vector<int64_t>::const_iterator output_events_us_end_;
+  const std::vector<LoggedAudioPlayoutEvent>::const_iterator output_events_end_;
-  const rtc::Optional<int64_t> end_time_us_;
+  const rtc::Optional<int64_t> end_time_ms_;
 };
 
 namespace {
@@ -1642,12 +1638,12 @@ namespace {
 // instrument the test.
 std::unique_ptr<test::NetEqStatsGetter> CreateNetEqTestAndRun(
     const std::vector<LoggedRtpPacketIncoming>* packet_stream,
-    const std::vector<int64_t>* output_events_us,
+    const std::vector<LoggedAudioPlayoutEvent>* output_events,
-    rtc::Optional<int64_t> end_time_us,
+    rtc::Optional<int64_t> end_time_ms,
     const std::string& replacement_file_name,
     int file_sample_rate_hz) {
   std::unique_ptr<test::NetEqInput> input(
-      new NetEqStreamInput(packet_stream, output_events_us, end_time_us));
+      new NetEqStreamInput(packet_stream, output_events, end_time_ms));
 
   constexpr int kReplacementPt = 127;
   std::set<uint8_t> cn_types;
@@ -1698,36 +1694,36 @@ EventLogAnalyzer::NetEqStatsGetterMap EventLogAnalyzer::SimulateNetEq(
     int file_sample_rate_hz) const {
   NetEqStatsGetterMap neteq_stats;
 
-  const std::vector<LoggedRtpPacketIncoming>* audio_packets = nullptr;
-  uint32_t ssrc;
   for (const auto& stream : parsed_log_.incoming_rtp_packets_by_ssrc()) {
-    if (IsAudioSsrc(kIncomingPacket, stream.ssrc)) {
+    const uint32_t ssrc = stream.ssrc;
-      audio_packets = &stream.incoming_packets;
+    if (!IsAudioSsrc(kIncomingPacket, ssrc))
-      ssrc = stream.ssrc;
+      continue;
-      break;
+    const std::vector<LoggedRtpPacketIncoming>* audio_packets =
-    }
+        &stream.incoming_packets;
-  }
     if (audio_packets == nullptr) {
       // No incoming audio stream found.
-    return neteq_stats;
+      continue;
     }
 
-  std::map<uint32_t, std::vector<int64_t>>::const_iterator output_events_it =
+    RTC_DCHECK(neteq_stats.find(ssrc) == neteq_stats.end());
-      parsed_log_.audio_playout_events().find(ssrc);
+
+    std::map<uint32_t, std::vector<LoggedAudioPlayoutEvent>>::const_iterator
+        output_events_it = parsed_log_.audio_playout_events().find(ssrc);
     if (output_events_it == parsed_log_.audio_playout_events().end()) {
       // Could not find output events with SSRC matching the input audio stream.
       // Using the first available stream of output events.
       output_events_it = parsed_log_.audio_playout_events().cbegin();
     }
 
-  rtc::Optional<int64_t> end_time_us =
+    rtc::Optional<int64_t> end_time_ms =
         log_segments_.empty()
             ? rtc::nullopt
-          : rtc::Optional<int64_t>(log_segments_.front().second);
+            : rtc::Optional<int64_t>(log_segments_.front().second / 1000);
 
     neteq_stats[ssrc] = CreateNetEqTestAndRun(
-      audio_packets, &output_events_it->second, end_time_us,
+        audio_packets, &output_events_it->second, end_time_ms,
         replacement_file_name, file_sample_rate_hz);
+  }
 
   return neteq_stats;
 }
@@ -1809,7 +1805,43 @@ void EventLogAnalyzer::CreateAudioJitterBufferGraph(
   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");
+  plot->SetTitle("NetEq timing for " + GetStreamName(kIncomingPacket, ssrc));
+}
+
+void EventLogAnalyzer::CreateNetEqStatsGraph(
+    const NetEqStatsGetterMap& neteq_stats,
+    rtc::FunctionView<float(const NetEqNetworkStatistics&)> stats_extractor,
+    const std::string& plot_name,
+    Plot* plot) const {
+  if (neteq_stats.size() < 1)
+    return;
+
+  std::map<uint32_t, TimeSeries> time_series;
+  float min_y_axis = std::numeric_limits<float>::max();
+  float max_y_axis = std::numeric_limits<float>::min();
+
+  for (const auto& st : neteq_stats) {
+    const uint32_t ssrc = st.first;
+    const auto& stats = st.second->stats();
+
+    for (size_t i = 0; i < stats.size(); ++i) {
+      const float time = ToCallTime(stats[i].first * 1000);  // ms to us.
+      const float value = stats_extractor(stats[i].second);
+      time_series[ssrc].points.emplace_back(TimeSeriesPoint(time, value));
+      min_y_axis = std::min(min_y_axis, value);
+      max_y_axis = std::max(max_y_axis, value);
+    }
+  }
+
+  for (auto& series : time_series) {
+    series.second.label = GetStreamName(kIncomingPacket, series.first);
+    series.second.line_style = LineStyle::kLine;
+    plot->AppendTimeSeries(std::move(series.second));
+  }
+
+  plot->SetXAxis(0, call_duration_s_, "Time (s)", kLeftMargin, kRightMargin);
+  plot->SetYAxis(min_y_axis, max_y_axis, plot_name, kBottomMargin, kTopMargin);
+  plot->SetTitle(plot_name);
 }
 
 void EventLogAnalyzer::CreateIceCandidatePairConfigGraph(Plot* plot) {

rtc_tools/event_log_visualizer/analyzer.h

@@ -79,6 +79,11 @@ class EventLogAnalyzer {
   void CreateAudioJitterBufferGraph(
       const NetEqStatsGetterMap& neteq_stats_getters,
       Plot* plot) const;
+  void CreateNetEqStatsGraph(
+      const NetEqStatsGetterMap& neteq_stats_getters,
+      rtc::FunctionView<float(const NetEqNetworkStatistics&)> stats_extractor,
+      const std::string& plot_name,
+      Plot* plot) const;
 
   void CreateIceCandidatePairConfigGraph(Plot* plot);
   void CreateIceConnectivityCheckGraph(Plot* plot);

rtc_tools/event_log_visualizer/main.cc

@@ -112,9 +112,7 @@ DEFINE_bool(plot_audio_encoder_dtx, false, "Plot the audio encoder DTX.");
 DEFINE_bool(plot_audio_encoder_num_channels,
             false,
             "Plot the audio encoder number of channels.");
-DEFINE_bool(plot_audio_jitter_buffer,
+DEFINE_bool(plot_neteq_stats, false, "Plot the NetEq statistics.");
-            false,
-            "Plot the audio jitter buffer delay profile.");
 DEFINE_bool(plot_ice_candidate_pair_config,
             false,
             "Plot the ICE candidate pair config events.");
@@ -325,7 +323,7 @@ int main(int argc, char* argv[]) {
   if (FLAG_plot_audio_encoder_num_channels) {
     analyzer.CreateAudioEncoderNumChannelsGraph(collection->AppendNewPlot());
   }
-  if (FLAG_plot_audio_jitter_buffer) {
+  if (FLAG_plot_neteq_stats) {
     std::string wav_path;
     if (FLAG_wav_filename[0] != '\0') {
       wav_path = FLAG_wav_filename;
@@ -336,6 +334,30 @@ int main(int argc, char* argv[]) {
     auto neteq_stats = analyzer.SimulateNetEq(wav_path, 48000);
     analyzer.CreateAudioJitterBufferGraph(neteq_stats,
                                           collection->AppendNewPlot());
+    analyzer.CreateNetEqStatsGraph(
+        neteq_stats,
+        [](const webrtc::NetEqNetworkStatistics& stats) {
+          return stats.expand_rate / 16384.f;
+        },
+        "Expand rate", collection->AppendNewPlot());
+    analyzer.CreateNetEqStatsGraph(
+        neteq_stats,
+        [](const webrtc::NetEqNetworkStatistics& stats) {
+          return stats.speech_expand_rate / 16384.f;
+        },
+        "Speech expand rate", collection->AppendNewPlot());
+    analyzer.CreateNetEqStatsGraph(
+        neteq_stats,
+        [](const webrtc::NetEqNetworkStatistics& stats) {
+          return stats.accelerate_rate / 16384.f;
+        },
+        "Accelerate rate", collection->AppendNewPlot());
+    analyzer.CreateNetEqStatsGraph(
+        neteq_stats,
+        [](const webrtc::NetEqNetworkStatistics& stats) {
+          return stats.packet_loss_rate / 16384.f;
+        },
+        "Packet loss rate", collection->AppendNewPlot());
   }
 
   if (FLAG_plot_ice_candidate_pair_config) {
@@ -382,7 +404,7 @@ void SetAllPlotFlags(bool setting) {
   FLAG_plot_audio_encoder_fec = setting;
   FLAG_plot_audio_encoder_dtx = setting;
   FLAG_plot_audio_encoder_num_channels = setting;
-  FLAG_plot_audio_jitter_buffer = setting;
+  FLAG_plot_neteq_stats = setting;
   FLAG_plot_ice_candidate_pair_config = setting;
   FLAG_plot_ice_connectivity_check = setting;
 }