Add NetEq delay plotting to event_log_visualizer

webrtc/modules/audio_coding/neteq/tools/neteq_delay_analyzer.cc

Index: webrtc/modules/audio_coding/neteq/tools/neteq_delay_analyzer.cc
diff --git a/webrtc/modules/audio_coding/neteq/tools/neteq_delay_analyzer.cc b/webrtc/modules/audio_coding/neteq/tools/neteq_delay_analyzer.cc
new file mode 100644
index 0000000000000000000000000000000000000000..45bb6efe4dbdb5db504052eed5b2a39a3e2118b5
--- /dev/null
+++ b/webrtc/modules/audio_coding/neteq/tools/neteq_delay_analyzer.cc
@@ -0,0 +1,166 @@
+/*
+ *  Copyright (c) 2017 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.
+ */
+
+#include "webrtc/modules/audio_coding/neteq/tools/neteq_delay_analyzer.h"
+
+#include <algorithm>
+#include <limits>
+#include <utility>
+
+namespace webrtc {
+namespace test {
+
+void NetEqDelayAnalyzer::AfterInsertPacket(
+    const test::NetEqInput::PacketData& packet,
+    NetEq* neteq) {
+  data_.insert(
+      std::make_pair(packet.header.timestamp,
+                     TimingData(packet.header.sequenceNumber, packet.time_ms)));
+}
+
+void NetEqDelayAnalyzer::BeforeGetAudio(NetEq* neteq) {
+  last_sync_buffer_ms_ = neteq->SyncBufferSizeMs();
+}
+
+void NetEqDelayAnalyzer::AfterGetAudio(int64_t time_now_ms,
+                                       const AudioFrame& audio_frame,
+                                       bool muted,

[ivoc, 2017/05/16 13:25:50]

Since this is not used you can comment out the name.

[hlundin-webrtc, 2017/05/30 14:56:06]

Done.

+                                       NetEq* neteq) {
+  get_audio_time_ms_.push_back(time_now_ms);
+  // Check what timestamps were decoded in the last GetAudio call.
+  std::vector<uint32_t> dec_ts = neteq->LastDecodedTimestamps();
+  // Find those timestamps in data_, insert their decoding time and sync
+  // delay.
+  for (uint32_t ts : dec_ts) {
+    auto it = data_.find(ts);
+    if (it == data_.end()) {
+      // This is a packet that was split out from another packet. Skip it.
+      continue;
+    }
+    RTC_CHECK(!it->second.decode_get_audio_count)

[ivoc, 2017/05/16 13:25:50]

I think this code block would be easier to read with an intermediary variable.
Something like
auto& it_timing = it->second;

[hlundin-webrtc, 2017/05/30 14:56:06]

Done.

+        << "Decode time already written";
+    it->second.decode_get_audio_count =
+        rtc::Optional<int64_t>(get_audio_count_);
+    RTC_CHECK(!it->second.sync_delay_ms) << "Decode time already written";
+    it->second.sync_delay_ms = rtc::Optional<int64_t>(last_sync_buffer_ms_);
+    it->second.target_delay_ms = rtc::Optional<int>(neteq->TargetDelayMs());
+    it->second.current_delay_ms =
+        rtc::Optional<int>(neteq->FilteredCurrentDelayMs());
+  }
+  last_sample_rate_hz_ = audio_frame.sample_rate_hz_;
+  ++get_audio_count_;
+}
+
+void NetEqDelayAnalyzer::CreateGraphs(

[ivoc, 2017/05/16 13:25:50]

This function is pretty long, so you can consider breaking out a part of it into
a helper function.

[hlundin-webrtc, 2017/05/30 14:56:06]

Done.

+    std::vector<float>* send_time_s,
+    std::vector<float>* arrival_delay_ms,
+    std::vector<float>* corrected_arrival_delay_ms,
+    std::vector<rtc::Optional<float>>* playout_delay_ms,
+    std::vector<rtc::Optional<float>>* target_delay_ms) const {
+  // Create nominal_get_audio_time_ms, a vector starting at
+  // get_audio_time_ms_[0] and increasing by 10 for each element.
+  std::vector<int64_t> nominal_get_audio_time_ms(get_audio_time_ms_.size());
+  nominal_get_audio_time_ms[0] = get_audio_time_ms_[0];
+  std::transform(
+      nominal_get_audio_time_ms.begin(), nominal_get_audio_time_ms.end() - 1,

[ivoc, 2017/05/16 13:25:50]

Will this crash if nominal_get_audio_time_ms is empty?

[hlundin-webrtc, 2017/05/30 14:56:06]

Presumably, but we already set the first element on line 70, so it will always
be at least 1 element long. But we should probably check that get_audio_time_ms
is not empty.

[ivoc, 2017/05/30 16:29:45]

Acknowledged.

+      nominal_get_audio_time_ms.begin() + 1, [](int64_t& x) { return x + 10; });
+  RTC_DCHECK(
+      std::is_sorted(get_audio_time_ms_.begin(), get_audio_time_ms_.end()));
+
+  std::vector<double> rtp_timestamps_ms;
+  std::vector<double> arrival_time_ms;
+  std::vector<double> corrected_arrival_time_ms;
+  std::vector<int64_t> decode_get_audio_count;
+  std::vector<int64_t> sync_delay_ms;
+  std::vector<int> raw_target_delay_ms;
+  std::vector<int> filtered_delay_ms;
+  double offset = std::numeric_limits<double>::max();
+
+  TimestampUnwrapper unwrapper;
+  for (auto& d : data_) {

[ivoc, 2017/05/16 13:25:50]

Please add a comment to explain what this loop does.

[hlundin-webrtc, 2017/05/30 14:56:06]

Done.

+    rtp_timestamps_ms.push_back(unwrapper.Unwrap(d.first) /
+                                (last_sample_rate_hz_ / 1000.f));
+    arrival_time_ms.push_back(d.second.arrival_time_ms);

[ivoc, 2017/05/16 13:25:50]

Also here I would suggest to introduce an intermediate variable for d.second, to
make the code more readable. Something like d_timing.

[hlundin-webrtc, 2017/05/30 14:56:06]

Done.

+    offset =
+        std::min(offset, arrival_time_ms.back() - rtp_timestamps_ms.back());
+    // Interpolate arrival times.
+    double x = d.second.arrival_time_ms;
+    // Find first element which is larger than x.
+    auto it = std::find_if(get_audio_time_ms_.begin(), get_audio_time_ms_.end(),
+                           [x](int64_t v) -> bool { return v > x; });
+    if (it == get_audio_time_ms_.end()) {
+      --it;
+    }
+    const size_t upper_ix = it - get_audio_time_ms_.begin();
+
+    size_t lower_ix;
+    if (upper_ix == 0 || get_audio_time_ms_[upper_ix] <= x) {
+      lower_ix = upper_ix;
+    } else {
+      lower_ix = upper_ix - 1;
+    }
+    double y;

[ivoc, 2017/05/16 13:25:50]

The variable names are a bit cryptic in this function, some comments to explain
(or more descriptive names) would be helpful.

[hlundin-webrtc, 2017/05/30 14:56:06]

I broke this part out to a generalized interpolation function. In the new
context, I think that x and y makes sense. WDYT?

+    if (lower_ix == upper_ix) {
+      y = nominal_get_audio_time_ms[lower_ix];
+    } else {
+      RTC_DCHECK_NE(get_audio_time_ms_[lower_ix], get_audio_time_ms_[upper_ix]);
+      y = (x - get_audio_time_ms_[lower_ix]) *
+              (nominal_get_audio_time_ms[upper_ix] -
+               nominal_get_audio_time_ms[lower_ix]) /
+              (get_audio_time_ms_[upper_ix] - get_audio_time_ms_[lower_ix]) +
+          nominal_get_audio_time_ms[lower_ix];
+    }
+    corrected_arrival_time_ms.push_back(y);
+
+    decode_get_audio_count.push_back(
+        d.second.decode_get_audio_count.value_or(-1));
+    sync_delay_ms.push_back(d.second.sync_delay_ms.value_or(-1));
+    raw_target_delay_ms.push_back(d.second.target_delay_ms.value_or(-1));
+    filtered_delay_ms.push_back(d.second.current_delay_ms.value_or(-1));
+  }
+  send_time_s->resize(rtp_timestamps_ms.size());
+  std::transform(rtp_timestamps_ms.begin(), rtp_timestamps_ms.end(),
+                 send_time_s->begin(), [rtp_timestamps_ms](double x) {
+                   return (x - rtp_timestamps_ms[0]) / 1000.f;
+                 });
+
+  RTC_DCHECK_EQ(send_time_s->size(), corrected_arrival_time_ms.size());
+  RTC_DCHECK_EQ(send_time_s->size(), rtp_timestamps_ms.size());
+  RTC_DCHECK_EQ(send_time_s->size(), decode_get_audio_count.size());
+  for (size_t i = 0; i < send_time_s->size(); ++i) {

[ivoc, 2017/05/16 13:25:50]

Please add a comment to explain what this for loop does.

[hlundin-webrtc, 2017/05/30 14:56:06]

Done.

+    const double y =
+        corrected_arrival_time_ms[i] - (rtp_timestamps_ms[i] + offset);
+    corrected_arrival_delay_ms->emplace_back(y);

[ivoc, 2017/05/16 13:25:50]

This is exactly the same as push_back for a vector<float>, right? 

[hlundin-webrtc, 2017/05/30 14:56:06]

You are right. This is over-kill. I changed them all, since I think emplace_back
doesn't improve the case with std::vector<rtc::Optional<float>> either.

+    const double z = arrival_time_ms[i] - (rtp_timestamps_ms[i] + offset);
+    arrival_delay_ms->emplace_back(z);
+
+    if (decode_get_audio_count[i] > -1) {
+      RTC_DCHECK_NE(sync_delay_ms[i], -1);
+      const float playout_ms = decode_get_audio_count[i] * 10 +
+                               get_audio_time_ms_[0] + sync_delay_ms[i] -
+                               (rtp_timestamps_ms[i] + offset);
+      playout_delay_ms->emplace_back(rtc::Optional<float>(playout_ms));
+      RTC_DCHECK_GT(raw_target_delay_ms[i], -1);
+      RTC_DCHECK_GT(filtered_delay_ms[i], -1);
+      const float target =
+          playout_ms - filtered_delay_ms[i] + raw_target_delay_ms[i];
+      target_delay_ms->emplace_back(rtc::Optional<float>(target));
+    } else {
+      playout_delay_ms->emplace_back(rtc::Optional<float>());
+      target_delay_ms->emplace_back(rtc::Optional<float>());
+    }
+  }
+  RTC_DCHECK_EQ(send_time_s->size(), corrected_arrival_delay_ms->size());
+  RTC_DCHECK_EQ(send_time_s->size(), playout_delay_ms->size());
+  RTC_DCHECK_EQ(send_time_s->size(), target_delay_ms->size());
+}
+
+}  // namespace test
+}  // namespace webrtc