123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331332333334335336337338339340341342343344345346347348349350351352353354355356357358359360361362363364365366367368369370371372373374375376377378379380381382383384385386387388389390391392393394395396397398 |
- // Copyright (c) 2012 The Chromium Authors. All rights reserved.
- // Use of this source code is governed by a BSD-style license that can be
- // found in the LICENSE file.
- #include "services/audio/sync_reader.h"
- #include <algorithm>
- #include <limits>
- #include <string>
- #include <utility>
- #include "base/command_line.h"
- #include "base/format_macros.h"
- #include "base/logging.h"
- #include "base/metrics/histogram_functions.h"
- #include "base/numerics/safe_conversions.h"
- #include "base/strings/strcat.h"
- #include "base/strings/stringprintf.h"
- #include "base/trace_event/trace_event.h"
- #include "build/build_config.h"
- #include "build/chromeos_buildflags.h"
- #include "media/audio/audio_device_thread.h"
- #include "media/base/audio_parameters.h"
- #include "media/base/media_switches.h"
- using media::AudioLatency;
- namespace {
- // Used to log if any audio glitches have been detected during an audio session.
- // Elements in this enum should not be added, deleted or rearranged.
- enum class AudioGlitchResult {
- kNoGlitches = 0,
- kGlitches = 1,
- kMaxValue = kGlitches
- };
- void LogPerLatencyGlitchUma(AudioLatency::LatencyType latency,
- int renderer_missed_callback_count,
- int renderer_callback_count,
- bool mixing) {
- DCHECK_LE(renderer_missed_callback_count, renderer_callback_count);
- auto LatencyToString = [](AudioLatency::LatencyType latency) {
- switch (latency) {
- case AudioLatency::LATENCY_EXACT_MS:
- return "LatencyExactMs";
- case AudioLatency::LATENCY_INTERACTIVE:
- return "LatencyInteractive";
- case AudioLatency::LATENCY_RTC:
- return "LatencyRtc";
- case AudioLatency::LATENCY_PLAYBACK:
- return "LatencyPlayback";
- default:
- return "LatencyUnknown";
- }
- };
- const std::string suffix = LatencyToString(latency);
- if (!mixing) {
- base::UmaHistogramEnumeration("Media.AudioRendererAudioGlitches2." + suffix,
- (renderer_missed_callback_count > 0)
- ? AudioGlitchResult::kGlitches
- : AudioGlitchResult::kNoGlitches);
- }
- const int kPermilleScaling = 1000;
- // 10%: if we have more that 10% of callbacks having issues, the details are
- // not very interesting any more, so we just log all those cases together to
- // have a better resolution for lower values.
- const int kHistogramRange = kPermilleScaling / 10;
- // 30 s for 10 ms buffers (RTC streams)/ 1 minute for 20 ms buffers (media
- // playback).
- const int kShortStreamMaxCallbackCount = 3000;
- if (renderer_callback_count <= 0)
- return;
- int missed_permille = std::ceil(
- kPermilleScaling * static_cast<double>(renderer_missed_callback_count) /
- renderer_callback_count);
- std::string histogram_name = base::StrCat(
- {"Media.AudioRendererMissedDeadline2.", mixing ? "Mixing." : "",
- (renderer_callback_count < kShortStreamMaxCallbackCount) ? "Short"
- : "Long"});
- base::UmaHistogramCustomCounts(histogram_name,
- std::min(missed_permille, kHistogramRange), 0,
- kHistogramRange + 1, 100);
- base::UmaHistogramCustomCounts(histogram_name + "." + suffix,
- std::min(missed_permille, kHistogramRange), 0,
- kHistogramRange + 1, 100);
- }
- } // namespace
- namespace audio {
- #if !BUILDFLAG(IS_MAC) && !BUILDFLAG(IS_CHROMEOS_ASH) && \
- !BUILDFLAG(IS_CHROMEOS_LACROS)
- const base::Feature kDynamicAudioTimeout{"DynamicAudioTimeout",
- base::FEATURE_ENABLED_BY_DEFAULT};
- const base::FeatureParam<double> kBufferDurationPercent{
- &kDynamicAudioTimeout, "buffer_duration_percent", 0.95};
- #endif
- SyncReader::SyncReader(
- base::RepeatingCallback<void(const std::string&)> log_callback,
- const media::AudioParameters& params,
- base::CancelableSyncSocket* foreign_socket)
- : log_callback_(std::move(log_callback)),
- latency_tag_(params.latency_tag()),
- mute_audio_for_testing_(base::CommandLine::ForCurrentProcess()->HasSwitch(
- switches::kMuteAudio)),
- output_bus_buffer_size_(
- media::AudioBus::CalculateMemorySize(params.channels(),
- params.frames_per_buffer())) {
- #if BUILDFLAG(IS_MAC) || BUILDFLAG(IS_CHROMEOS_ASH) || \
- BUILDFLAG(IS_CHROMEOS_LACROS)
- maximum_wait_time_ = params.GetBufferDuration() / 2;
- maximum_wait_time_for_mixing_ = maximum_wait_time_;
- #else
- if (base::FeatureList::IsEnabled(kDynamicAudioTimeout)) {
- maximum_wait_time_ =
- params.GetBufferDuration() * kBufferDurationPercent.Get();
- } else {
- maximum_wait_time_ = base::Milliseconds(20);
- }
- maximum_wait_time_for_mixing_ = maximum_wait_time_;
- #if BUILDFLAG(CHROME_WIDE_ECHO_CANCELLATION)
- if (base::FeatureList::IsEnabled(media::kChromeWideEchoCancellation)) {
- double mixing_timeout_percent =
- media::kChromeWideEchoCancellationDynamicMixingTimeout.Get();
- // The default negative value means we should ignore this parameter.
- if (mixing_timeout_percent > 0) {
- maximum_wait_time_for_mixing_ =
- params.GetBufferDuration() * mixing_timeout_percent;
- }
- }
- #endif
- #endif
- base::CheckedNumeric<size_t> memory_size =
- media::ComputeAudioOutputBufferSizeChecked(params);
- if (!memory_size.IsValid())
- return;
- shared_memory_region_ =
- base::UnsafeSharedMemoryRegion::Create(memory_size.ValueOrDie());
- shared_memory_mapping_ = shared_memory_region_.Map();
- if (shared_memory_region_.IsValid() && shared_memory_mapping_.IsValid() &&
- base::CancelableSyncSocket::CreatePair(&socket_, foreign_socket)) {
- auto* const buffer = reinterpret_cast<media::AudioOutputBuffer*>(
- shared_memory_mapping_.memory());
- output_bus_ = media::AudioBus::WrapMemory(params, buffer->audio);
- output_bus_->Zero();
- output_bus_->set_is_bitstream_format(params.IsBitstreamFormat());
- }
- }
- SyncReader::~SyncReader() {
- DCHECK_GE(renderer_callback_count_, mixing_renderer_callback_count_);
- if (!renderer_callback_count_)
- return;
- // Subtract 'trailing' count of callbacks missed just before the destructor
- // call. This happens if the renderer process was killed or e.g. the page
- // refreshed while the output device was open etc.
- // This trims off the end of both the missed and total counts so that we
- // preserve the proportion of counts before the teardown period.
- DCHECK_LE(trailing_renderer_missed_callback_count_,
- renderer_missed_callback_count_);
- DCHECK_LE(trailing_renderer_missed_callback_count_, renderer_callback_count_);
- renderer_missed_callback_count_ -= trailing_renderer_missed_callback_count_;
- renderer_callback_count_ -= trailing_renderer_missed_callback_count_;
- DCHECK_LE(mixing_trailing_renderer_missed_callback_count_,
- mixing_renderer_missed_callback_count_);
- DCHECK_LE(mixing_trailing_renderer_missed_callback_count_,
- mixing_renderer_callback_count_);
- mixing_renderer_missed_callback_count_ -=
- mixing_trailing_renderer_missed_callback_count_;
- mixing_renderer_callback_count_ -=
- mixing_trailing_renderer_missed_callback_count_;
- DCHECK_GE(renderer_callback_count_, mixing_renderer_callback_count_);
- if (!renderer_callback_count_)
- return;
- base::UmaHistogramEnumeration("Media.AudioRendererAudioGlitches",
- (renderer_missed_callback_count_ > 0)
- ? AudioGlitchResult::kGlitches
- : AudioGlitchResult::kNoGlitches);
- int percentage_missed =
- 100.0 * renderer_missed_callback_count_ / renderer_callback_count_;
- base::UmaHistogramPercentage("Media.AudioRendererMissedDeadline",
- percentage_missed);
- LogPerLatencyGlitchUma(latency_tag_, renderer_missed_callback_count_,
- renderer_callback_count_, /*mixing=*/false);
- LogPerLatencyGlitchUma(latency_tag_, mixing_renderer_missed_callback_count_,
- mixing_renderer_callback_count_, /*mixing=*/true);
- TRACE_EVENT_INSTANT1("audio", "~SyncReader", TRACE_EVENT_SCOPE_THREAD,
- "Missed callback percentage", percentage_missed);
- log_callback_.Run(base::StringPrintf(
- "ASR: number of detected audio glitches: %" PRIuS " out of %" PRIuS,
- renderer_missed_callback_count_, renderer_callback_count_));
- }
- bool SyncReader::IsValid() const {
- if (output_bus_) {
- DCHECK(shared_memory_region_.IsValid());
- DCHECK(shared_memory_mapping_.IsValid());
- DCHECK_NE(socket_.handle(), base::SyncSocket::kInvalidHandle);
- return true;
- }
- return false;
- }
- base::UnsafeSharedMemoryRegion SyncReader::TakeSharedMemoryRegion() {
- return std::move(shared_memory_region_);
- }
- // AudioOutputController::SyncReader implementations.
- void SyncReader::RequestMoreData(base::TimeDelta delay,
- base::TimeTicks delay_timestamp,
- int prior_frames_skipped) {
- // We don't send arguments over the socket since sending more than 4
- // bytes might lead to being descheduled. The reading side will zero
- // them when consumed.
- auto* const buffer = reinterpret_cast<media::AudioOutputBuffer*>(
- shared_memory_mapping_.memory());
- // Increase the number of skipped frames stored in shared memory.
- buffer->params.frames_skipped += prior_frames_skipped;
- buffer->params.delay_us = delay.InMicroseconds();
- buffer->params.delay_timestamp_us =
- (delay_timestamp - base::TimeTicks()).InMicroseconds();
- // Zero out the entire output buffer to avoid stuttering/repeating-buffers
- // in the anomalous case if the renderer is unable to keep up with real-time.
- output_bus_->Zero();
- uint32_t control_signal = 0;
- if (delay.is_max()) {
- // std::numeric_limits<uint32_t>::max() is a special signal which is
- // returned after the browser stops the output device in response to a
- // renderer side request.
- control_signal = std::numeric_limits<uint32_t>::max();
- }
- size_t sent_bytes = socket_.Send(&control_signal, sizeof(control_signal));
- if (sent_bytes != sizeof(control_signal)) {
- // Ensure we don't log consecutive errors as this can lead to a large
- // amount of logs.
- if (!had_socket_error_) {
- had_socket_error_ = true;
- static const char* socket_send_failure_message =
- "ASR: No room in socket buffer.";
- PLOG(WARNING) << socket_send_failure_message;
- log_callback_.Run(socket_send_failure_message);
- TRACE_EVENT_INSTANT0("audio", socket_send_failure_message,
- TRACE_EVENT_SCOPE_THREAD);
- }
- } else {
- had_socket_error_ = false;
- }
- ++buffer_index_;
- }
- void SyncReader::Read(media::AudioBus* dest, bool is_mixing) {
- ++renderer_callback_count_;
- if (is_mixing)
- ++mixing_renderer_callback_count_;
- if (!WaitUntilDataIsReady(is_mixing)) {
- ++trailing_renderer_missed_callback_count_;
- ++renderer_missed_callback_count_;
- if (is_mixing) {
- ++mixing_trailing_renderer_missed_callback_count_;
- ++mixing_renderer_missed_callback_count_;
- }
- if (renderer_missed_callback_count_ <= 100 &&
- renderer_missed_callback_count_ % 10 == 0) {
- LOG(WARNING) << "SyncReader::Read timed out, audio glitch count="
- << renderer_missed_callback_count_;
- if (renderer_missed_callback_count_ == 100)
- LOG(WARNING) << "(log cap reached, suppressing further logs)";
- }
- dest->Zero();
- return;
- }
- trailing_renderer_missed_callback_count_ = 0;
- mixing_trailing_renderer_missed_callback_count_ = 0;
- // Zeroed buffers may be discarded immediately when outputing compressed
- // bitstream.
- if (mute_audio_for_testing_ && !output_bus_->is_bitstream_format()) {
- dest->Zero();
- return;
- }
- if (output_bus_->is_bitstream_format()) {
- // For bitstream formats, we need the real data size and PCM frame count.
- auto* const buffer = reinterpret_cast<media::AudioOutputBuffer*>(
- shared_memory_mapping_.memory());
- uint32_t data_size = buffer->params.bitstream_data_size;
- uint32_t bitstream_frames = buffer->params.bitstream_frames;
- // |bitstream_frames| is cast to int below, so it must fit.
- if (data_size > output_bus_buffer_size_ ||
- !base::IsValueInRangeForNumericType<int>(bitstream_frames)) {
- // Received data doesn't fit in the buffer, shouldn't happen.
- dest->Zero();
- return;
- }
- output_bus_->SetBitstreamDataSize(data_size);
- output_bus_->SetBitstreamFrames(bitstream_frames);
- output_bus_->CopyTo(dest);
- return;
- }
- // Copy and clip data coming across the shared memory since it's untrusted.
- output_bus_->CopyAndClipTo(dest);
- }
- void SyncReader::Close() {
- socket_.Close();
- output_bus_.reset();
- }
- bool SyncReader::WaitUntilDataIsReady(bool is_mixing) {
- TRACE_EVENT0("audio", "SyncReader::WaitUntilDataIsReady");
- base::TimeDelta timeout =
- is_mixing ? maximum_wait_time_for_mixing_ : maximum_wait_time_;
- const base::TimeTicks start_time = base::TimeTicks::Now();
- const base::TimeTicks finish_time = start_time + timeout;
- // Check if data is ready and if not, wait a reasonable amount of time for it.
- //
- // Data readiness is achieved via parallel counters, one on the renderer side
- // and one here. Every time a buffer is requested via UpdatePendingBytes(),
- // |buffer_index_| is incremented. Subsequently every time the renderer has a
- // buffer ready it increments its counter and sends the counter value over the
- // SyncSocket. Data is ready when |buffer_index_| matches the counter value
- // received from the renderer.
- //
- // The counter values may temporarily become out of sync if the renderer is
- // unable to deliver audio fast enough. It's assumed that the renderer will
- // catch up at some point, which means discarding counter values read from the
- // SyncSocket which don't match our current buffer index.
- size_t bytes_received = 0;
- uint32_t renderer_buffer_index = 0;
- while (timeout.InMicroseconds() > 0) {
- bytes_received = socket_.ReceiveWithTimeout(
- &renderer_buffer_index, sizeof(renderer_buffer_index), timeout);
- if (bytes_received != sizeof(renderer_buffer_index)) {
- bytes_received = 0;
- break;
- }
- if (renderer_buffer_index == buffer_index_)
- break;
- // Reduce the timeout value as receives succeed, but aren't the right index.
- timeout = finish_time - base::TimeTicks::Now();
- }
- // Receive timed out or another error occurred. Receive can timeout if the
- // renderer is unable to deliver audio data within the allotted time.
- if (!bytes_received || renderer_buffer_index != buffer_index_) {
- TRACE_EVENT_INSTANT0("audio", "SyncReader::Read timed out",
- TRACE_EVENT_SCOPE_THREAD);
- base::TimeDelta time_since_start = base::TimeTicks::Now() - start_time;
- base::UmaHistogramCustomTimes("Media.AudioOutputControllerDataNotReady",
- time_since_start, base::Milliseconds(1),
- base::Milliseconds(1000), 50);
- return false;
- }
- return true;
- }
- } // namespace audio
|