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..f721a6889fc25f358857ed9cf376f08202809921 100644
--- a/webrtc/modules/audio_device/audio_device_unittest.cc
+++ b/webrtc/modules/audio_device/audio_device_unittest.cc
@@ -8,16 +8,22 @@
  *  be found in the AUTHORS file in the root of the source tree.
  */
 
+#include <algorithm>
 #include <cstring>
+#include <numeric>
 
 #include "webrtc/base/array_view.h"
 #include "webrtc/base/buffer.h"
 #include "webrtc/base/criticalsection.h"
 #include "webrtc/base/event.h"
 #include "webrtc/base/logging.h"
+#include "webrtc/base/optional.h"
 #include "webrtc/base/race_checker.h"
+#include "webrtc/base/safe_conversions.h"
 #include "webrtc/base/scoped_ref_ptr.h"
 #include "webrtc/base/thread_annotations.h"
+#include "webrtc/base/thread_checker.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"
@@ -63,11 +69,19 @@ 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 = 10;
+// 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;
 
 enum class TransportType {
   kInvalid,
@@ -87,6 +101,14 @@ class AudioStream {
   virtual ~AudioStream() = default;
 };
 
+// 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) {
+  return rtc::checked_cast<int>(
+      10.0 * (static_cast<double>(index) / frames_per_10ms_buffer) + 0.5);
+}
+
 }  // namespace
 
 // Simple first in first out (FIFO) class that wraps a list of 16-bit audio
@@ -158,6 +180,126 @@ 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:
+  LatencyAudioStream() {
+    // Delay thread checkers from being initialized until first callback from
+    // respective thread.
+    read_thread_checker_.DetachFromThread();
+    write_thread_checker_.DetachFromThread();
+  }
+
+  // Insert periodic impulses in first two samples of |destination|.
+  void Read(rtc::ArrayView<int16_t> destination, size_t channels) override {
+    RTC_DCHECK_RUN_ON(&read_thread_checker_);
+    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_) {
+          pulse_time_ = rtc::Optional<int64_t>(rtc::TimeMillis());
+        }
+      }
+      constexpr int16_t impulse = std::numeric_limits<int16_t>::max();
+      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_RUN_ON(&write_thread_checker_);
+    RTC_DCHECK_RUNS_SERIALIZED(&race_checker_);
+    rtc::CritScope lock(&lock_);
+    write_count_++;
+    if (!pulse_time_) {
+      // Avoid detection of new impulse response until a new impulse has
+      // been transmitted (sets |pulse_time_| to value larger than zero).
+      return;
+    }
+    // Find index (element position in vector) of the max element.
+    const size_t index_of_max =
+        std::max_element(source.begin(), source.end()) - source.begin();
+    // Derive time between transmitted pulse and received pulse if the level
+    // is high enough (removes noise).
+    const size_t max = source[index_of_max];
+    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]", rtc::checked_cast<int>(now_time - pulse_time_));
+      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_.reset();
+    } else {
+      PRINTD("-");
+    }
+  }
+
+  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("[..........] [min, max, avg]=[%d, %d, %d] ms\n", min_latency(),
+          max_latency(), average_latency());
+  }
+
+  rtc::CriticalSection lock_;
+  rtc::RaceChecker race_checker_;
+  rtc::ThreadChecker read_thread_checker_;
+  rtc::ThreadChecker write_thread_checker_;
+
+  rtc::Optional<int64_t> pulse_time_ GUARDED_BY(lock_);
+  std::vector<int> latencies_ GUARDED_BY(race_checker_);
+  size_t read_count_ ACCESS_ON(read_thread_checker_) = 0;
+  size_t write_count_ ACCESS_ON(write_thread_checker_) = 0;
+};
+
 // Mocks the AudioTransport object and proxies actions for the two callbacks
 // (RecordedDataIsAvailable and NeedMorePlayData) to different implementations
 // of AudioStreamInterface.
@@ -510,8 +652,8 @@ TEST_F(AudioDeviceTest, RunPlayoutAndRecordingInFullDuplex) {
   EXPECT_EQ(0, audio_device()->SetStereoRecording(false));
   StartPlayout();
   StartRecording();
-  event()->Wait(
-      std::max(kTestTimeOutInMilliseconds, 1000 * kFullDuplexTimeInSec));
+  event()->Wait(static_cast<int>(
+      std::max(kTestTimeOutInMilliseconds, 1000 * kFullDuplexTimeInSec)));
   StopRecording();
   StopPlayout();
   // This thresholds is set rather high to accommodate differences in hardware
@@ -521,4 +663,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(static_cast<int>(
+      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