Adds AudioDeviceTest.MeasureLoopbackLatency unittest

webrtc/modules/audio_device/audio_device_unittest.cc

 /*
  *  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 <algorithm>
 #include <cstring>
 
 #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"
 #include "webrtc/system_wrappers/include/sleep.h"
 #include "webrtc/test/gmock.h"
 #include "webrtc/test/gtest.h"
 
 using ::testing::_;
 using ::testing::AtLeast;
 using ::testing::Ge;
 using ::testing::Invoke;
 using ::testing::NiceMock;
 using ::testing::NotNull;
 
 namespace webrtc {
 namespace {
 
 // #define ENABLE_DEBUG_PRINTF

[kwiberg-webrtc, 2017/04/20 12:33:27]

Did you mean to do this?

[henrika_webrtc, 2017/04/20 12:39:26]

Yes I did. Only used to add extra verbose debug logs for cases when the
transmitted pulses are not detected.

 #ifdef ENABLE_DEBUG_PRINTF
 #define PRINTD(...) fprintf(stderr, __VA_ARGS__);
 #else
 #define PRINTD(...) ((void)0)
 #endif
 #define PRINT(...) fprintf(stderr, __VA_ARGS__);
 
 // Don't run these tests in combination with sanitizers.
 #if !defined(ADDRESS_SANITIZER) && !defined(MEMORY_SANITIZER)
 #define SKIP_TEST_IF_NOT(requirements_satisfied) \
   do {                                           \
     if (!requirements_satisfied) {               \
       return;                                    \
     }                                            \
   } while (false)
 #else
 // Or if other audio-related requirements are not met.
 #define SKIP_TEST_IF_NOT(requirements_satisfied) \
   do {                                           \
     return;                                      \
   } while (false)
 #endif
 
 // Number of callbacks (input or output) the tests waits for before we set
 // 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,
   kPlay,
   kRecord,
   kPlayAndRecord,
 };
 
 // Interface for processing the audio stream. Real implementations can e.g.
 // run audio in loopback, read audio from a file or perform latency
 // measurements.
 class AudioStream {
  public:
   virtual void Write(rtc::ArrayView<const int16_t> source, size_t channels) = 0;
   virtual void Read(rtc::ArrayView<int16_t> destination, size_t channels) = 0;
 
   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
 // buffers of fixed size and allows Write and Read operations. The idea is to
 // store recorded audio buffers (using Write) and then read (using Read) these
 // stored buffers with as short delay as possible when the audio layer needs
 // data to play out. The number of buffers in the FIFO will stabilize under
 // normal conditions since there will be a balance between Write and Read calls.
 // The container is a std::list container and access is protected with a lock
 // since both sides (playout and recording) are driven by its own thread.
@@ skipping 51 matching lines @@
 
   rtc::CriticalSection lock_;
   rtc::RaceChecker race_checker_;
 
   std::list<Buffer16> fifo_ GUARDED_BY(lock_);
   size_t write_count_ GUARDED_BY(race_checker_) = 0;
   size_t max_size_ GUARDED_BY(race_checker_) = 0;
   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.
 class MockAudioTransport : public test::MockAudioTransport {
  public:
   explicit MockAudioTransport(TransportType type) : type_(type) {}
   ~MockAudioTransport() {}
 
   // Set default actions of the mock object. We are delegating to fake
   // implementation where the number of callbacks is counted and an event
@@ skipping 343 matching lines @@
       std::max(kTestTimeOutInMilliseconds, 1000 * kFullDuplexTimeInSec));
   StopRecording();
   StopPlayout();
   // This thresholds is set rather high to accommodate differences in hardware
   // in several devices. The main idea is to capture cases where a very large
   // latency is built up.
   EXPECT_LE(audio_stream.average_size(), 5u);
   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