• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
2  *  Copyright (c) 2012 The WebRTC project authors. All Rights Reserved.
3  *
4  *  Use of this source code is governed by a BSD-style license
5  *  that can be found in the LICENSE file in the root of the source
6  *  tree. An additional intellectual property rights grant can be found
7  *  in the file PATENTS.  All contributing project authors may
8  *  be found in the AUTHORS file in the root of the source tree.
9  */
10 
11 #include "modules/audio_device/audio_device_buffer.h"
12 
13 #include <string.h>
14 
15 #include <cmath>
16 #include <cstddef>
17 #include <cstdint>
18 
19 #include "common_audio/signal_processing/include/signal_processing_library.h"
20 #include "rtc_base/checks.h"
21 #include "rtc_base/logging.h"
22 #include "rtc_base/time_utils.h"
23 #include "rtc_base/trace_event.h"
24 #include "system_wrappers/include/metrics.h"
25 
26 namespace webrtc {
27 
28 static const char kTimerQueueName[] = "AudioDeviceBufferTimer";
29 
30 // Time between two sucessive calls to LogStats().
31 static const size_t kTimerIntervalInSeconds = 10;
32 static const size_t kTimerIntervalInMilliseconds =
33     kTimerIntervalInSeconds * rtc::kNumMillisecsPerSec;
34 // Min time required to qualify an audio session as a "call". If playout or
35 // recording has been active for less than this time we will not store any
36 // logs or UMA stats but instead consider the call as too short.
37 static const size_t kMinValidCallTimeTimeInSeconds = 10;
38 static const size_t kMinValidCallTimeTimeInMilliseconds =
39     kMinValidCallTimeTimeInSeconds * rtc::kNumMillisecsPerSec;
40 #ifdef AUDIO_DEVICE_PLAYS_SINUS_TONE
41 static const double k2Pi = 6.28318530717959;
42 #endif
43 
AudioDeviceBuffer(TaskQueueFactory * task_queue_factory)44 AudioDeviceBuffer::AudioDeviceBuffer(TaskQueueFactory* task_queue_factory)
45     : task_queue_(task_queue_factory->CreateTaskQueue(
46           kTimerQueueName,
47           TaskQueueFactory::Priority::NORMAL)),
48       audio_transport_cb_(nullptr),
49       rec_sample_rate_(0),
50       play_sample_rate_(0),
51       rec_channels_(0),
52       play_channels_(0),
53       playing_(false),
54       recording_(false),
55       typing_status_(false),
56       play_delay_ms_(0),
57       rec_delay_ms_(0),
58       capture_timestamp_ns_(0),
59       num_stat_reports_(0),
60       last_timer_task_time_(0),
61       rec_stat_count_(0),
62       play_stat_count_(0),
63       play_start_time_(0),
64       only_silence_recorded_(true),
65       log_stats_(false) {
66   RTC_LOG(LS_INFO) << "AudioDeviceBuffer::ctor";
67 #ifdef AUDIO_DEVICE_PLAYS_SINUS_TONE
68   phase_ = 0.0;
69   RTC_LOG(LS_WARNING) << "AUDIO_DEVICE_PLAYS_SINUS_TONE is defined!";
70 #endif
71 }
72 
~AudioDeviceBuffer()73 AudioDeviceBuffer::~AudioDeviceBuffer() {
74   RTC_DCHECK_RUN_ON(&main_thread_checker_);
75   RTC_DCHECK(!playing_);
76   RTC_DCHECK(!recording_);
77   RTC_LOG(LS_INFO) << "AudioDeviceBuffer::~dtor";
78 }
79 
RegisterAudioCallback(AudioTransport * audio_callback)80 int32_t AudioDeviceBuffer::RegisterAudioCallback(
81     AudioTransport* audio_callback) {
82   RTC_DCHECK_RUN_ON(&main_thread_checker_);
83   RTC_DLOG(LS_INFO) << __FUNCTION__;
84   if (playing_ || recording_) {
85     RTC_LOG(LS_ERROR) << "Failed to set audio transport since media was active";
86     return -1;
87   }
88   audio_transport_cb_ = audio_callback;
89   return 0;
90 }
91 
StartPlayout()92 void AudioDeviceBuffer::StartPlayout() {
93   RTC_DCHECK_RUN_ON(&main_thread_checker_);
94   // TODO(henrika): allow for usage of DCHECK(!playing_) here instead. Today the
95   // ADM allows calling Start(), Start() by ignoring the second call but it
96   // makes more sense to only allow one call.
97   if (playing_) {
98     return;
99   }
100   RTC_DLOG(LS_INFO) << __FUNCTION__;
101   // Clear members tracking playout stats and do it on the task queue.
102   task_queue_.PostTask([this] { ResetPlayStats(); });
103   // Start a periodic timer based on task queue if not already done by the
104   // recording side.
105   if (!recording_) {
106     StartPeriodicLogging();
107   }
108   const int64_t now_time = rtc::TimeMillis();
109   // Clear members that are only touched on the main (creating) thread.
110   play_start_time_ = now_time;
111   playing_ = true;
112 }
113 
StartRecording()114 void AudioDeviceBuffer::StartRecording() {
115   RTC_DCHECK_RUN_ON(&main_thread_checker_);
116   if (recording_) {
117     return;
118   }
119   RTC_DLOG(LS_INFO) << __FUNCTION__;
120   // Clear members tracking recording stats and do it on the task queue.
121   task_queue_.PostTask([this] { ResetRecStats(); });
122   // Start a periodic timer based on task queue if not already done by the
123   // playout side.
124   if (!playing_) {
125     StartPeriodicLogging();
126   }
127   // Clear members that will be touched on the main (creating) thread.
128   rec_start_time_ = rtc::TimeMillis();
129   recording_ = true;
130   // And finally a member which can be modified on the native audio thread.
131   // It is safe to do so since we know by design that the owning ADM has not
132   // yet started the native audio recording.
133   only_silence_recorded_ = true;
134 }
135 
StopPlayout()136 void AudioDeviceBuffer::StopPlayout() {
137   RTC_DCHECK_RUN_ON(&main_thread_checker_);
138   if (!playing_) {
139     return;
140   }
141   RTC_DLOG(LS_INFO) << __FUNCTION__;
142   playing_ = false;
143   // Stop periodic logging if no more media is active.
144   if (!recording_) {
145     StopPeriodicLogging();
146   }
147   RTC_LOG(LS_INFO) << "total playout time: "
148                    << rtc::TimeSince(play_start_time_);
149 }
150 
StopRecording()151 void AudioDeviceBuffer::StopRecording() {
152   RTC_DCHECK_RUN_ON(&main_thread_checker_);
153   if (!recording_) {
154     return;
155   }
156   RTC_DLOG(LS_INFO) << __FUNCTION__;
157   recording_ = false;
158   // Stop periodic logging if no more media is active.
159   if (!playing_) {
160     StopPeriodicLogging();
161   }
162   // Add UMA histogram to keep track of the case when only zeros have been
163   // recorded. Measurements (max of absolute level) are taken twice per second,
164   // which means that if e.g 10 seconds of audio has been recorded, a total of
165   // 20 level estimates must all be identical to zero to trigger the histogram.
166   // `only_silence_recorded_` can only be cleared on the native audio thread
167   // that drives audio capture but we know by design that the audio has stopped
168   // when this method is called, hence there should not be aby conflicts. Also,
169   // the fact that `only_silence_recorded_` can be affected during the complete
170   // call makes chances of conflicts with potentially one last callback very
171   // small.
172   const size_t time_since_start = rtc::TimeSince(rec_start_time_);
173   if (time_since_start > kMinValidCallTimeTimeInMilliseconds) {
174     const int only_zeros = static_cast<int>(only_silence_recorded_);
175     RTC_HISTOGRAM_BOOLEAN("WebRTC.Audio.RecordedOnlyZeros", only_zeros);
176     RTC_LOG(LS_INFO) << "HISTOGRAM(WebRTC.Audio.RecordedOnlyZeros): "
177                      << only_zeros;
178   }
179   RTC_LOG(LS_INFO) << "total recording time: " << time_since_start;
180 }
181 
SetRecordingSampleRate(uint32_t fsHz)182 int32_t AudioDeviceBuffer::SetRecordingSampleRate(uint32_t fsHz) {
183   RTC_LOG(LS_INFO) << "SetRecordingSampleRate(" << fsHz << ")";
184   rec_sample_rate_ = fsHz;
185   return 0;
186 }
187 
SetPlayoutSampleRate(uint32_t fsHz)188 int32_t AudioDeviceBuffer::SetPlayoutSampleRate(uint32_t fsHz) {
189   RTC_LOG(LS_INFO) << "SetPlayoutSampleRate(" << fsHz << ")";
190   play_sample_rate_ = fsHz;
191   return 0;
192 }
193 
RecordingSampleRate() const194 uint32_t AudioDeviceBuffer::RecordingSampleRate() const {
195   return rec_sample_rate_;
196 }
197 
PlayoutSampleRate() const198 uint32_t AudioDeviceBuffer::PlayoutSampleRate() const {
199   return play_sample_rate_;
200 }
201 
SetRecordingChannels(size_t channels)202 int32_t AudioDeviceBuffer::SetRecordingChannels(size_t channels) {
203   RTC_LOG(LS_INFO) << "SetRecordingChannels(" << channels << ")";
204   rec_channels_ = channels;
205   return 0;
206 }
207 
SetPlayoutChannels(size_t channels)208 int32_t AudioDeviceBuffer::SetPlayoutChannels(size_t channels) {
209   RTC_LOG(LS_INFO) << "SetPlayoutChannels(" << channels << ")";
210   play_channels_ = channels;
211   return 0;
212 }
213 
RecordingChannels() const214 size_t AudioDeviceBuffer::RecordingChannels() const {
215   return rec_channels_;
216 }
217 
PlayoutChannels() const218 size_t AudioDeviceBuffer::PlayoutChannels() const {
219   return play_channels_;
220 }
221 
SetTypingStatus(bool typing_status)222 int32_t AudioDeviceBuffer::SetTypingStatus(bool typing_status) {
223   typing_status_ = typing_status;
224   return 0;
225 }
226 
SetVQEData(int play_delay_ms,int rec_delay_ms)227 void AudioDeviceBuffer::SetVQEData(int play_delay_ms, int rec_delay_ms) {
228   play_delay_ms_ = play_delay_ms;
229   rec_delay_ms_ = rec_delay_ms;
230 }
231 
SetRecordedBuffer(const void * audio_buffer,size_t samples_per_channel)232 int32_t AudioDeviceBuffer::SetRecordedBuffer(const void* audio_buffer,
233                                              size_t samples_per_channel) {
234   return SetRecordedBuffer(audio_buffer, samples_per_channel, 0);
235 }
236 
SetRecordedBuffer(const void * audio_buffer,size_t samples_per_channel,int64_t capture_timestamp_ns)237 int32_t AudioDeviceBuffer::SetRecordedBuffer(const void* audio_buffer,
238                                              size_t samples_per_channel,
239                                              int64_t capture_timestamp_ns) {
240   // Copy the complete input buffer to the local buffer.
241   const size_t old_size = rec_buffer_.size();
242   rec_buffer_.SetData(static_cast<const int16_t*>(audio_buffer),
243                       rec_channels_ * samples_per_channel);
244   // Keep track of the size of the recording buffer. Only updated when the
245   // size changes, which is a rare event.
246   if (old_size != rec_buffer_.size()) {
247     RTC_LOG(LS_INFO) << "Size of recording buffer: " << rec_buffer_.size();
248   }
249 
250   // If the timestamp is less then or equal to zero, it's not valid and are
251   // ignored. If we do antimestamp alignment on them they might accidentally
252   // become greater then zero, and will be handled as if they were a correct
253   // timestamp.
254   capture_timestamp_ns_ =
255       (capture_timestamp_ns > 0)
256           ? rtc::kNumNanosecsPerMicrosec *
257                 timestamp_aligner_.TranslateTimestamp(
258                     capture_timestamp_ns_ / rtc::kNumNanosecsPerMicrosec,
259                     rtc::TimeMicros())
260           : capture_timestamp_ns;
261   // Derive a new level value twice per second and check if it is non-zero.
262   int16_t max_abs = 0;
263   RTC_DCHECK_LT(rec_stat_count_, 50);
264   if (++rec_stat_count_ >= 50) {
265     // Returns the largest absolute value in a signed 16-bit vector.
266     max_abs = WebRtcSpl_MaxAbsValueW16(rec_buffer_.data(), rec_buffer_.size());
267     rec_stat_count_ = 0;
268     // Set `only_silence_recorded_` to false as soon as at least one detection
269     // of a non-zero audio packet is found. It can only be restored to true
270     // again by restarting the call.
271     if (max_abs > 0) {
272       only_silence_recorded_ = false;
273     }
274   }
275   // Update recording stats which is used as base for periodic logging of the
276   // audio input state.
277   UpdateRecStats(max_abs, samples_per_channel);
278   return 0;
279 }
280 
DeliverRecordedData()281 int32_t AudioDeviceBuffer::DeliverRecordedData() {
282   if (!audio_transport_cb_) {
283     RTC_LOG(LS_WARNING) << "Invalid audio transport";
284     return 0;
285   }
286   const size_t frames = rec_buffer_.size() / rec_channels_;
287   const size_t bytes_per_frame = rec_channels_ * sizeof(int16_t);
288   uint32_t new_mic_level_dummy = 0;
289   uint32_t total_delay_ms = play_delay_ms_ + rec_delay_ms_;
290   int32_t res = audio_transport_cb_->RecordedDataIsAvailable(
291       rec_buffer_.data(), frames, bytes_per_frame, rec_channels_,
292       rec_sample_rate_, total_delay_ms, 0, 0, typing_status_,
293       new_mic_level_dummy, capture_timestamp_ns_);
294   if (res == -1) {
295     RTC_LOG(LS_ERROR) << "RecordedDataIsAvailable() failed";
296   }
297   return 0;
298 }
299 
RequestPlayoutData(size_t samples_per_channel)300 int32_t AudioDeviceBuffer::RequestPlayoutData(size_t samples_per_channel) {
301   TRACE_EVENT1("webrtc", "AudioDeviceBuffer::RequestPlayoutData",
302                "samples_per_channel", samples_per_channel);
303 
304   // The consumer can change the requested size on the fly and we therefore
305   // resize the buffer accordingly. Also takes place at the first call to this
306   // method.
307   const size_t total_samples = play_channels_ * samples_per_channel;
308   if (play_buffer_.size() != total_samples) {
309     play_buffer_.SetSize(total_samples);
310     RTC_LOG(LS_INFO) << "Size of playout buffer: " << play_buffer_.size();
311   }
312 
313   size_t num_samples_out(0);
314   // It is currently supported to start playout without a valid audio
315   // transport object. Leads to warning and silence.
316   if (!audio_transport_cb_) {
317     RTC_LOG(LS_WARNING) << "Invalid audio transport";
318     return 0;
319   }
320 
321   // Retrieve new 16-bit PCM audio data using the audio transport instance.
322   int64_t elapsed_time_ms = -1;
323   int64_t ntp_time_ms = -1;
324   const size_t bytes_per_frame = play_channels_ * sizeof(int16_t);
325   uint32_t res = audio_transport_cb_->NeedMorePlayData(
326       samples_per_channel, bytes_per_frame, play_channels_, play_sample_rate_,
327       play_buffer_.data(), num_samples_out, &elapsed_time_ms, &ntp_time_ms);
328   if (res != 0) {
329     RTC_LOG(LS_ERROR) << "NeedMorePlayData() failed";
330   }
331 
332   // Derive a new level value twice per second.
333   int16_t max_abs = 0;
334   RTC_DCHECK_LT(play_stat_count_, 50);
335   if (++play_stat_count_ >= 50) {
336     // Returns the largest absolute value in a signed 16-bit vector.
337     max_abs =
338         WebRtcSpl_MaxAbsValueW16(play_buffer_.data(), play_buffer_.size());
339     play_stat_count_ = 0;
340   }
341   // Update playout stats which is used as base for periodic logging of the
342   // audio output state.
343   UpdatePlayStats(max_abs, num_samples_out / play_channels_);
344   return static_cast<int32_t>(num_samples_out / play_channels_);
345 }
346 
GetPlayoutData(void * audio_buffer)347 int32_t AudioDeviceBuffer::GetPlayoutData(void* audio_buffer) {
348   RTC_DCHECK_GT(play_buffer_.size(), 0);
349 #ifdef AUDIO_DEVICE_PLAYS_SINUS_TONE
350   const double phase_increment =
351       k2Pi * 440.0 / static_cast<double>(play_sample_rate_);
352   int16_t* destination_r = reinterpret_cast<int16_t*>(audio_buffer);
353   if (play_channels_ == 1) {
354     for (size_t i = 0; i < play_buffer_.size(); ++i) {
355       destination_r[i] = static_cast<int16_t>((sin(phase_) * (1 << 14)));
356       phase_ += phase_increment;
357     }
358   } else if (play_channels_ == 2) {
359     for (size_t i = 0; i < play_buffer_.size() / 2; ++i) {
360       destination_r[2 * i] = destination_r[2 * i + 1] =
361           static_cast<int16_t>((sin(phase_) * (1 << 14)));
362       phase_ += phase_increment;
363     }
364   }
365 #else
366   memcpy(audio_buffer, play_buffer_.data(),
367          play_buffer_.size() * sizeof(int16_t));
368 #endif
369   // Return samples per channel or number of frames.
370   return static_cast<int32_t>(play_buffer_.size() / play_channels_);
371 }
372 
StartPeriodicLogging()373 void AudioDeviceBuffer::StartPeriodicLogging() {
374   task_queue_.PostTask([this] { LogStats(AudioDeviceBuffer::LOG_START); });
375 }
376 
StopPeriodicLogging()377 void AudioDeviceBuffer::StopPeriodicLogging() {
378   task_queue_.PostTask([this] { LogStats(AudioDeviceBuffer::LOG_STOP); });
379 }
380 
LogStats(LogState state)381 void AudioDeviceBuffer::LogStats(LogState state) {
382   RTC_DCHECK_RUN_ON(&task_queue_);
383   int64_t now_time = rtc::TimeMillis();
384 
385   if (state == AudioDeviceBuffer::LOG_START) {
386     // Reset counters at start. We will not add any logging in this state but
387     // the timer will started by posting a new (delayed) task.
388     num_stat_reports_ = 0;
389     last_timer_task_time_ = now_time;
390     log_stats_ = true;
391   } else if (state == AudioDeviceBuffer::LOG_STOP) {
392     // Stop logging and posting new tasks.
393     log_stats_ = false;
394   } else if (state == AudioDeviceBuffer::LOG_ACTIVE) {
395     // Keep logging unless logging was disabled while task was posted.
396   }
397 
398   // Avoid adding more logs since we are in STOP mode.
399   if (!log_stats_) {
400     return;
401   }
402 
403   int64_t next_callback_time = now_time + kTimerIntervalInMilliseconds;
404   int64_t time_since_last = rtc::TimeDiff(now_time, last_timer_task_time_);
405   last_timer_task_time_ = now_time;
406 
407   Stats stats;
408   {
409     MutexLock lock(&lock_);
410     stats = stats_;
411     stats_.max_rec_level = 0;
412     stats_.max_play_level = 0;
413   }
414 
415   // Cache current sample rate from atomic members.
416   const uint32_t rec_sample_rate = rec_sample_rate_;
417   const uint32_t play_sample_rate = play_sample_rate_;
418 
419   // Log the latest statistics but skip the first two rounds just after state
420   // was set to LOG_START to ensure that we have at least one full stable
421   // 10-second interval for sample-rate estimation. Hence, first printed log
422   // will be after ~20 seconds.
423   if (++num_stat_reports_ > 2 &&
424       static_cast<size_t>(time_since_last) > kTimerIntervalInMilliseconds / 2) {
425     uint32_t diff_samples = stats.rec_samples - last_stats_.rec_samples;
426     float rate = diff_samples / (static_cast<float>(time_since_last) / 1000.0);
427     uint32_t abs_diff_rate_in_percent = 0;
428     if (rec_sample_rate > 0 && rate > 0) {
429       abs_diff_rate_in_percent = static_cast<uint32_t>(
430           0.5f +
431           ((100.0f * std::abs(rate - rec_sample_rate)) / rec_sample_rate));
432       RTC_HISTOGRAM_PERCENTAGE("WebRTC.Audio.RecordSampleRateOffsetInPercent",
433                                abs_diff_rate_in_percent);
434       RTC_LOG(LS_INFO) << "[REC : " << time_since_last << "msec, "
435                        << rec_sample_rate / 1000 << "kHz] callbacks: "
436                        << stats.rec_callbacks - last_stats_.rec_callbacks
437                        << ", "
438                           "samples: "
439                        << diff_samples
440                        << ", "
441                           "rate: "
442                        << static_cast<int>(rate + 0.5)
443                        << ", "
444                           "rate diff: "
445                        << abs_diff_rate_in_percent
446                        << "%, "
447                           "level: "
448                        << stats.max_rec_level;
449     }
450 
451     diff_samples = stats.play_samples - last_stats_.play_samples;
452     rate = diff_samples / (static_cast<float>(time_since_last) / 1000.0);
453     abs_diff_rate_in_percent = 0;
454     if (play_sample_rate > 0 && rate > 0) {
455       abs_diff_rate_in_percent = static_cast<uint32_t>(
456           0.5f +
457           ((100.0f * std::abs(rate - play_sample_rate)) / play_sample_rate));
458       RTC_HISTOGRAM_PERCENTAGE("WebRTC.Audio.PlayoutSampleRateOffsetInPercent",
459                                abs_diff_rate_in_percent);
460       RTC_LOG(LS_INFO) << "[PLAY: " << time_since_last << "msec, "
461                        << play_sample_rate / 1000 << "kHz] callbacks: "
462                        << stats.play_callbacks - last_stats_.play_callbacks
463                        << ", "
464                           "samples: "
465                        << diff_samples
466                        << ", "
467                           "rate: "
468                        << static_cast<int>(rate + 0.5)
469                        << ", "
470                           "rate diff: "
471                        << abs_diff_rate_in_percent
472                        << "%, "
473                           "level: "
474                        << stats.max_play_level;
475     }
476   }
477   last_stats_ = stats;
478 
479   int64_t time_to_wait_ms = next_callback_time - rtc::TimeMillis();
480   RTC_DCHECK_GT(time_to_wait_ms, 0) << "Invalid timer interval";
481 
482   // Keep posting new (delayed) tasks until state is changed to kLogStop.
483   task_queue_.PostDelayedTask(
484       [this] { AudioDeviceBuffer::LogStats(AudioDeviceBuffer::LOG_ACTIVE); },
485       TimeDelta::Millis(time_to_wait_ms));
486 }
487 
ResetRecStats()488 void AudioDeviceBuffer::ResetRecStats() {
489   RTC_DCHECK_RUN_ON(&task_queue_);
490   last_stats_.ResetRecStats();
491   MutexLock lock(&lock_);
492   stats_.ResetRecStats();
493 }
494 
ResetPlayStats()495 void AudioDeviceBuffer::ResetPlayStats() {
496   RTC_DCHECK_RUN_ON(&task_queue_);
497   last_stats_.ResetPlayStats();
498   MutexLock lock(&lock_);
499   stats_.ResetPlayStats();
500 }
501 
UpdateRecStats(int16_t max_abs,size_t samples_per_channel)502 void AudioDeviceBuffer::UpdateRecStats(int16_t max_abs,
503                                        size_t samples_per_channel) {
504   MutexLock lock(&lock_);
505   ++stats_.rec_callbacks;
506   stats_.rec_samples += samples_per_channel;
507   if (max_abs > stats_.max_rec_level) {
508     stats_.max_rec_level = max_abs;
509   }
510 }
511 
UpdatePlayStats(int16_t max_abs,size_t samples_per_channel)512 void AudioDeviceBuffer::UpdatePlayStats(int16_t max_abs,
513                                         size_t samples_per_channel) {
514   MutexLock lock(&lock_);
515   ++stats_.play_callbacks;
516   stats_.play_samples += samples_per_channel;
517   if (max_abs > stats_.max_play_level) {
518     stats_.max_play_level = max_abs;
519   }
520 }
521 
522 }  // namespace webrtc
523