Adds AudioDeviceTest.MeasureLoopbackLatency unittest

webrtc/modules/audio_device/audio_device_unittest.cc

Index: webrtc/modules/audio_device/audio_device_unittest.cc
diff --git a/webrtc/modules/audio_device/audio_device_unittest.cc b/webrtc/modules/audio_device/audio_device_unittest.cc
index effbf1e08ff052e515315150ec56db16f83b8715..b65b91fcbcec744d4c5e3e2b0b384e45e80815d3 100644
--- a/webrtc/modules/audio_device/audio_device_unittest.cc
+++ b/webrtc/modules/audio_device/audio_device_unittest.cc
@@ -8,6 +8,7 @@
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
+#include <algorithm>
 #include <cstring>
 
 #include "webrtc/base/array_view.h"
@@ -18,6 +19,7 @@
 #include "webrtc/base/race_checker.h"
 #include "webrtc/base/scoped_ref_ptr.h"
 #include "webrtc/base/thread_annotations.h"
+#include "webrtc/base/timeutils.h"
 #include "webrtc/modules/audio_device/audio_device_impl.h"
 #include "webrtc/modules/audio_device/include/audio_device.h"
 #include "webrtc/modules/audio_device/include/mock_audio_transport.h"
@@ -35,7 +37,7 @@ using ::testing::NotNull;
 namespace webrtc {
 namespace {
 
-// #define ENABLE_DEBUG_PRINTF
+#define ENABLE_DEBUG_PRINTF
 #ifdef ENABLE_DEBUG_PRINTF
 #define PRINTD(...) fprintf(stderr, __VA_ARGS__);
 #else
@@ -63,11 +65,20 @@ namespace {
 // an event indicating that the test was OK.
 static constexpr size_t kNumCallbacks = 10;
 // Max amount of time we wait for an event to be set while counting callbacks.
-static constexpr int kTestTimeOutInMilliseconds = 10 * 1000;
+static constexpr size_t kTestTimeOutInMilliseconds = 10 * 1000;
 // Average number of audio callbacks per second assuming 10ms packet size.
 static constexpr size_t kNumCallbacksPerSecond = 100;
 // Run the full-duplex test during this time (unit is in seconds).
-static constexpr int kFullDuplexTimeInSec = 5;
+static constexpr size_t kFullDuplexTimeInSec = 5;
+// Length of round-trip latency measurements. Number of deteced impulses
+// shall be kImpulseFrequencyInHz * kMeasureLatencyTimeInSec - 1 since the
+// last transmitted pulse is not used.
+static constexpr size_t kMeasureLatencyTimeInSec = 11;
+// Sets the number of impulses per second in the latency test.
+static constexpr size_t kImpulseFrequencyInHz = 1;
+// Utilized in round-trip latency measurements to avoid capturing noise samples.
+static constexpr int kImpulseThreshold = 1000;
+static constexpr char kTag[] = "[..........] ";

[kwiberg-webrtc, 2017/04/20 09:26:37]

Can you move all or some of these closer to where they're used? At least
kMeasureLatencyTimeInSec seems to be used only by a single function, and in that
case it may be more readable to have the definition there.

On the other hand, you may still prefer to keep them all in the same place since
they seem to be documented as a unit. Do whatever you feel is more pedagogical.

[henrika_webrtc, 2017/04/20 12:22:30]

Thanks. Moving and inlining kTag ;-)

 
 enum class TransportType {
   kInvalid,
@@ -158,6 +169,124 @@ class FifoAudioStream : public AudioStream {
   size_t written_elements_ GUARDED_BY(race_checker_) = 0;
 };
 
+// Inserts periodic impulses and measures the latency between the time of
+// transmission and time of receiving the same impulse.
+class LatencyAudioStream : public AudioStream {
+ public:
+  // Insert periodic impulses in first two samples of |destination|.
+  void Read(rtc::ArrayView<int16_t> destination, size_t channels) override {
+    EXPECT_EQ(channels, 1u);
+    if (read_count_ == 0) {
+      PRINT("[");
+    }
+    read_count_++;
+    std::fill(destination.begin(), destination.end(), 0);
+    if (read_count_ % (kNumCallbacksPerSecond / kImpulseFrequencyInHz) == 0) {
+      PRINT(".");
+      {
+        rtc::CritScope lock(&lock_);
+        if (pulse_time_ == 0) {
+          pulse_time_ = rtc::TimeMillis();
+        }
+      }
+      const int16_t impulse = std::numeric_limits<int16_t>::max();

[kwiberg-webrtc, 2017/04/20 09:26:37]

constexpr?

[henrika_webrtc, 2017/04/20 12:22:30]

works as well ;-)

+      std::fill_n(destination.begin(), 2, impulse);
+    }
+  }
+
+  // Detect received impulses in |source|, derive time between transmission and
+  // detection and add the calculated delay to list of latencies.
+  void Write(rtc::ArrayView<const int16_t> source, size_t channels) override {
+    EXPECT_EQ(channels, 1u);
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    rtc::CritScope lock(&lock_);
+    write_count_++;
+    if (pulse_time_ == 0) {
+      // Avoid detection of new impulse response until a new impulse has
+      // been transmitted (sets |pulse_time_| to value larger than zero).
+      return;
+    }
+    // Find max value in the audio buffer.
+    size_t max = *std::max_element(source.begin(), source.end());
+    // Find index (element position in vector) of the max element.
+    size_t index_of_max = std::distance(
+        source.begin(), std::find(source.begin(), source.end(), max));

[kwiberg-webrtc, 2017/04/20 09:26:37]

Why are you using std::find here?---you already found the max in the previous
statement.

Also, ArrayView's iterators are random access and support unary minus, so you
don't have to use std::distance.

[kwiberg-webrtc, 2017/04/20 11:14:30]

const size_t index_of_max = std::max_element(source.begin(), source.end()) -
source.begin();

[henrika_webrtc, 2017/04/20 12:22:30]

Thanks!

+    // Derive time between transmitted pulse and received pulse if the level
+    // is high enough (removes noise).
+    if (max > kImpulseThreshold) {
+      PRINTD("(%zu, %zu)", max, index_of_max);
+      int64_t now_time = rtc::TimeMillis();
+      int extra_delay = IndexToMilliseconds(index_of_max, source.size());
+      PRINTD("[%d]", static_cast<int>(now_time - pulse_time_));

[kwiberg-webrtc, 2017/04/20 09:26:37]

checked_cast?

[henrika_webrtc, 2017/04/20 12:22:30]

Done.

+      PRINTD("[%d]", extra_delay);
+      // Total latency is the difference between transmit time and detection
+      // tome plus the extra delay within the buffer in which we detected the
+      // received impulse. It is transmitted at sample 0 but can be received
+      // at sample N where N > 0. The term |extra_delay| accounts for N and it
+      // is a value between 0 and 10ms.
+      latencies_.push_back(now_time - pulse_time_ + extra_delay);
+      pulse_time_ = 0;
+    } else {
+      PRINTD("-");
+    }
+  }
+
+  // Converts index corresponding to position within a 10ms buffer into a
+  // delay value in milliseconds.
+  // Example: index=240, frames_per_10ms_buffer=480 => 5ms as output.
+  int IndexToMilliseconds(size_t index, size_t frames_per_10ms_buffer) const {
+    return static_cast<int>(
+        10.0 * (static_cast<double>(index) / frames_per_10ms_buffer) + 0.5);
+  }

[kwiberg-webrtc, 2017/04/20 09:26:37]

This doesn't need to be a member function. Put it outside the class in an
anonymous namespace?

[henrika_webrtc, 2017/04/20 12:22:30]

Done.

+
+  size_t num_latency_values() const {
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    return latencies_.size();
+  }
+
+  int min_latency() const {
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    if (latencies_.empty())
+      return 0;
+    return *std::min_element(latencies_.begin(), latencies_.end());
+  }
+
+  int max_latency() const {
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    if (latencies_.empty())
+      return 0;
+    return *std::max_element(latencies_.begin(), latencies_.end());
+  }
+
+  int average_latency() const {
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    if (latencies_.empty())
+      return 0;
+    return 0.5 + static_cast<double>(
+                     std::accumulate(latencies_.begin(), latencies_.end(), 0)) /
+                     latencies_.size();
+  }
+
+  void PrintResults() const {
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    PRINT("] ");
+    for (auto it = latencies_.begin(); it != latencies_.end(); ++it) {
+      PRINTD("%d ", *it);
+    }
+    PRINT("\n");
+    PRINT("%s[min, max, avg]=[%d, %d, %d] ms\n", kTag, min_latency(),
+          max_latency(), average_latency());
+  }
+
+  rtc::CriticalSection lock_;
+  rtc::RaceChecker race_checker_;
+
+  int64_t pulse_time_ GUARDED_BY(lock_) = 0;

[kwiberg-webrtc, 2017/04/20 09:26:37]

You're using pulse_time_ == 0 to mean that it's unset. Could you use
Optional<int64_t> instead?

[henrika_webrtc, 2017/04/20 12:22:30]

Done (I think since I have not used Optional before).

+  std::vector<int> latencies_ GUARDED_BY(race_checker_);
+  size_t read_count_ = 0;
+  size_t write_count_ = 0;

[kwiberg-webrtc, 2017/04/20 09:26:37]

Why are these two not protected by anything?

[henrika_webrtc, 2017/04/20 12:22:30]

I know by design that read_count_ is only access on T1 and write_count_ on T2.
Will make that more clear.

+};
+
 // Mocks the AudioTransport object and proxies actions for the two callbacks
 // (RecordedDataIsAvailable and NeedMorePlayData) to different implementations
 // of AudioStreamInterface.
@@ -521,4 +650,38 @@ TEST_F(AudioDeviceTest, RunPlayoutAndRecordingInFullDuplex) {
   PRINT("\n");
 }
 
+// Measures loopback latency and reports the min, max and average values for
+// a full duplex audio session.
+// The latency is measured like so:
+// - Insert impulses periodically on the output side.
+// - Detect the impulses on the input side.
+// - Measure the time difference between the transmit time and receive time.
+// - Store time differences in a vector and calculate min, max and average.
+// This test needs the '--gtest_also_run_disabled_tests' flag to run and also
+// some sort of audio feedback loop. E.g. a headset where the mic is placed
+// close to the speaker to ensure highest possible echo. It is also recommended
+// to run the test at highest possible output volume.
+TEST_F(AudioDeviceTest, DISABLED_MeasureLoopbackLatency) {
+  SKIP_TEST_IF_NOT(requirements_satisfied());
+  NiceMock<MockAudioTransport> mock(TransportType::kPlayAndRecord);
+  LatencyAudioStream audio_stream;
+  mock.HandleCallbacks(event(), &audio_stream,
+                       kMeasureLatencyTimeInSec * kNumCallbacksPerSecond);
+  EXPECT_EQ(0, audio_device()->RegisterAudioCallback(&mock));
+  EXPECT_EQ(0, audio_device()->SetStereoPlayout(false));
+  EXPECT_EQ(0, audio_device()->SetStereoRecording(false));
+  StartPlayout();
+  StartRecording();
+  event()->Wait(
+      std::max(kTestTimeOutInMilliseconds, 1000 * kMeasureLatencyTimeInSec));
+  StopRecording();
+  StopPlayout();
+  // Verify that the correct number of transmitted impulses are detected.
+  EXPECT_EQ(audio_stream.num_latency_values(),
+            static_cast<size_t>(
+                kImpulseFrequencyInHz * kMeasureLatencyTimeInSec - 1));
+  // Print out min, max and average delay values for debugging purposes.
+  audio_stream.PrintResults();
+}
+
 }  // namespace webrtc