Adds delta-time logging for audio playout

webrtc/modules/audio_device/audio_device_buffer.cc

Index: webrtc/modules/audio_device/audio_device_buffer.cc
diff --git a/webrtc/modules/audio_device/audio_device_buffer.cc b/webrtc/modules/audio_device/audio_device_buffer.cc
index b40d5afeb879717b100e6bd56ffb3f62336420a6..f31dd7cc759e7ea30382399e78ae27426062b039 100644
--- a/webrtc/modules/audio_device/audio_device_buffer.cc
+++ b/webrtc/modules/audio_device/audio_device_buffer.cc
@@ -72,6 +72,23 @@ AudioDeviceBuffer::AudioDeviceBuffer()
 AudioDeviceBuffer::~AudioDeviceBuffer() {
   RTC_DCHECK(thread_checker_.CalledOnValidThread());
   LOG(INFO) << "AudioDeviceBuffer::~dtor";
+
+  int total_diff_time = 0;
+  int num_measurements = 0;
+  while (!playout_diff_time_map_.empty()) {

[magjed_webrtc, 2016/07/29 10:07:11]

Use a range-based loop instead:
for (const auto& keyAndValue : playout_diff_time_map_) {
  int time_diff = keyAndValue.first;
  int num_elements = keyAndValue.second;  
}

[henrika_webrtc, 2016/07/29 11:11:00]

Thanks. 

+    int time_diff = playout_diff_time_map_.begin()->first;
+    int num_elements =  playout_diff_time_map_.begin()->second;
+    total_diff_time += num_elements * time_diff;
+    num_measurements += num_elements;
+    LOG(INFO) << time_diff << " => " << num_elements;
+    playout_diff_time_map_.erase(playout_diff_time_map_.begin());
+  }
+  LOG(INFO) << "total_diff_time: " << total_diff_time;
+  LOG(INFO) << "num_measurements: " << num_measurements;
+  LOG(INFO) << "average: "
+            << static_cast<float>(total_diff_time) / num_measurements;
+
+
   _recFile.Flush();
   _recFile.CloseFile();
   delete &_recFile;
@@ -92,6 +109,7 @@ int32_t AudioDeviceBuffer::RegisterAudioCallback(
 int32_t AudioDeviceBuffer::InitPlayout() {
   RTC_DCHECK(thread_checker_.CalledOnValidThread());
   LOG(INFO) << __FUNCTION__;
+  last_playout_time_ = rtc::TimeMillis();
   if (!timer_has_started_) {
     StartTimer();
     timer_has_started_ = true;
@@ -333,6 +351,16 @@ int32_t AudioDeviceBuffer::RequestPlayoutData(size_t nSamples) {
   size_t playBytesPerSample = 0;
   size_t playChannels = 0;
 
+  // Measure time since last function call and update a map where the key value
+  // corresponds to time differences (in milliseconds), and the mapped element
+  // represents the number of times a given time difference was found.
+  // Writing to map can be done without a lock since it is only read once at
+  // destruction when no audio is running.
+  int64_t now_time = rtc::TimeMillis();
+  int64_t diff_time = rtc::TimeDiff(now_time, last_playout_time_);

[magjed_webrtc, 2016/07/29 10:07:11]

Consider using
diff_time = std::min(1000, diff_time);
to limit the number of elements in the map.
Also, you could use a plain array instead of a map if you cap the numbers that
way, but I'm not sure how sparse the array will be and if it's an improvement
over using a map.

[henrika_webrtc, 2016/07/29 11:11:00]

Will add the cap, thanks!

Would like to keep the map since the array would be sparse and we would have to
allocate memory for zeros. Hope that is OK.

[magjed_webrtc, 2016/07/29 12:16:07]

The map has a big overhead per element and will need to store at least two
pointers (left/right child), the key, the value, probably a color (it's a
red–black tree), and will contain as many internal nodes as leaf nodes, so
probably something like 80 bytes per element in average, compared to an array
with just 8 bytes (64 bit int) per element. So if you have more than 50
elements, an array will use less memory. An array will probably be something
like 10x faster as well. 100 lookups per second is not completely negligible.

[henrika_webrtc, 2016/07/29 12:50:24]

Will change

+  last_playout_time_ = now_time;
+  playout_diff_time_map_[diff_time]++;
+
   // TOOD(henrika): improve bad locking model and make it more clear that only
   // 10ms buffer sizes is supported in WebRTC.
   {