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/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"
 #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
+#define ENABLE_DEBUG_PRINTF
 #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 = 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,
   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
@@ skipping 70 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:
+  // 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.
 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