From 7f1f94956ed3ea90b9d75d2a26b899532cb1ab37 Mon Sep 17 00:00:00 2001 From: Dale Curtis Date: Mon, 17 May 2021 21:03:13 +0000 Subject: [PATCH] Log HRESULT failures during Windows audio output. This will help diagnose failures at the output stage which may be affecting audio renderer playback errors. R=henrika Bug: 1196874 Change-Id: I7ca73305fb6e0fe01056518a200f4881dfe711b9 Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2898468 Auto-Submit: Dale Curtis Reviewed-by: Henrik Andreasson Reviewed-by: Brian White Commit-Queue: Brian White Cr-Commit-Position: refs/heads/master@{#883612} --- .../audio/win/audio_low_latency_output_win.cc | 29 ++++++++++++++++++- .../histograms_xml/media/histograms.xml | 17 +++++++++++ 2 files changed, 45 insertions(+), 1 deletion(-) diff --git a/media/audio/win/audio_low_latency_output_win.cc b/media/audio/win/audio_low_latency_output_win.cc index 2a76f3f57084e4..1f7e1ec946180d 100644 --- a/media/audio/win/audio_low_latency_output_win.cc +++ b/media/audio/win/audio_low_latency_output_win.cc @@ -16,6 +16,7 @@ #include "base/command_line.h" #include "base/logging.h" #include "base/metrics/histogram.h" +#include "base/metrics/histogram_functions.h" #include "base/metrics/histogram_macros.h" #include "base/stl_util.h" #include "base/strings/stringprintf.h" @@ -33,13 +34,23 @@ #include "media/base/limits.h" #include "media/base/media_switches.h" -using base::win::ScopedCOMInitializer; using base::win::ScopedCoMem; +using base::win::ScopedCOMInitializer; namespace media { namespace { +constexpr char kOpenFailureHistogram[] = "Media.Audio.Output.Win.OpenError"; +constexpr char kStartFailureHistogram[] = "Media.Audio.Output.Win.StartError"; +constexpr char kStopFailureHistogram[] = "Media.Audio.Output.Win.StopError"; +constexpr char kRunFailureHistogram[] = "Media.Audio.Output.Win.RunError"; +constexpr char kRenderFailureHistogram[] = "Media.Audio.Output.Win.RenderError"; + +void RecordAudioFailure(const char* histogram, HRESULT hr) { + base::UmaHistogramSparse(histogram, hr); +} + // Converts a COM error into a human-readable string. std::string ErrorToString(HRESULT hresult) { return CoreAudioUtil::ErrorToString(hresult); @@ -181,6 +192,7 @@ bool WASAPIAudioOutputStream::Open() { Microsoft::WRL::ComPtr audio_client( CoreAudioUtil::CreateClient(device_id_, eRender, device_role_)); if (!audio_client.Get()) { + RecordAudioFailure(kOpenFailureHistogram, GetLastError()); SendLogMessage("%s => (ERROR: CAU::CreateClient failed)", __func__); return false; } @@ -188,6 +200,7 @@ bool WASAPIAudioOutputStream::Open() { // Extra sanity to ensure that the provided device format is still valid. if (!CoreAudioUtil::IsFormatSupported(audio_client.Get(), share_mode_, &format_)) { + RecordAudioFailure(kOpenFailureHistogram, GetLastError()); SendLogMessage("%s => (ERROR: CAU::IsFormatSupported failed)", __func__); return false; } @@ -201,6 +214,7 @@ bool WASAPIAudioOutputStream::Open() { requested_iaudioclient3_buffer_size_, &endpoint_buffer_size_frames_, communications_device ? &kCommunicationsSessionId : nullptr); if (FAILED(hr)) { + RecordAudioFailure(kOpenFailureHistogram, hr); SendLogMessage("%s => (ERROR: IAudioClient::SharedModeInitialize=[%s])", __func__, ErrorToString(hr).c_str()); return false; @@ -209,6 +223,7 @@ bool WASAPIAudioOutputStream::Open() { REFERENCE_TIME device_period = 0; if (FAILED(CoreAudioUtil::GetDevicePeriod( audio_client.Get(), AUDCLNT_SHAREMODE_SHARED, &device_period))) { + RecordAudioFailure(kOpenFailureHistogram, GetLastError()); return false; } @@ -271,6 +286,7 @@ bool WASAPIAudioOutputStream::Open() { Microsoft::WRL::ComPtr audio_render_client = CoreAudioUtil::CreateRenderClient(audio_client.Get()); if (!audio_render_client.Get()) { + RecordAudioFailure(kOpenFailureHistogram, GetLastError()); SendLogMessage("%s => (ERROR: CAU::CreateRenderClient failed)", __func__); return false; } @@ -281,6 +297,7 @@ bool WASAPIAudioOutputStream::Open() { hr = audio_client_->GetService(IID_PPV_ARGS(&audio_clock_)); if (FAILED(hr)) { + RecordAudioFailure(kOpenFailureHistogram, hr); SendLogMessage("%s => (ERROR: IAudioClient::GetService(IAudioClock)=[%s])", __func__, ErrorToString(hr).c_str()); return false; @@ -337,6 +354,7 @@ void WASAPIAudioOutputStream::Start(AudioSourceCallback* callback) { audio_render_client_.Reset(); if (!Open() || !CoreAudioUtil::FillRenderEndpointBufferWithSilence( audio_client_.Get(), audio_render_client_.Get())) { + RecordAudioFailure(kStartFailureHistogram, GetLastError()); SendLogMessage("%s => (ERROR: Recovery attempt failed)", __func__); callback->OnError(AudioSourceCallback::ErrorType::kUnknown); return; @@ -356,6 +374,7 @@ void WASAPIAudioOutputStream::Start(AudioSourceCallback* callback) { base::SimpleThread::Options(base::ThreadPriority::REALTIME_AUDIO)); render_thread_->Start(); if (!render_thread_->HasBeenStarted()) { + RecordAudioFailure(kStartFailureHistogram, GetLastError()); SendLogMessage("%s => (ERROR: Failed to start \"wasapi_render_thread\")", __func__); StopThread(); @@ -366,6 +385,7 @@ void WASAPIAudioOutputStream::Start(AudioSourceCallback* callback) { // Start streaming data between the endpoint buffer and the audio engine. HRESULT hr = audio_client_->Start(); if (FAILED(hr)) { + RecordAudioFailure(kStartFailureHistogram, hr); SendLogMessage("%s => (ERROR: IAudioClient::Start=[%s])", __func__, ErrorToString(hr).c_str()); StopThread(); @@ -385,6 +405,7 @@ void WASAPIAudioOutputStream::Stop() { // Stop output audio streaming. HRESULT hr = audio_client_->Stop(); if (FAILED(hr)) { + RecordAudioFailure(kStopFailureHistogram, hr); SendLogMessage("%s => (ERROR: IAudioClient::Stop=[%s])", __func__, ErrorToString(hr).c_str()); source_->OnError(AudioSourceCallback::ErrorType::kUnknown); @@ -397,6 +418,7 @@ void WASAPIAudioOutputStream::Stop() { // Flush all pending data and reset the audio clock stream position to 0. hr = audio_client_->Reset(); if (FAILED(hr)) { + RecordAudioFailure(kStopFailureHistogram, hr); SendLogMessage("%s => (ERROR: IAudioClient::Reset=[%s])", __func__, ErrorToString(hr).c_str()); callback->OnError(AudioSourceCallback::ErrorType::kUnknown); @@ -495,6 +517,7 @@ void WASAPIAudioOutputStream::Run() { hr = audio_clock_->GetFrequency(&device_frequency); error = FAILED(hr); if (error) { + RecordAudioFailure(kRunFailureHistogram, hr); LOG(ERROR) << "WAOS::" << __func__ << " => (ERROR: IAudioClock::GetFrequency=[" << ErrorToString(hr).c_str() << "])"; @@ -523,6 +546,7 @@ void WASAPIAudioOutputStream::Run() { } if (playing && error) { + RecordAudioFailure(kRunFailureHistogram, GetLastError()); LOG(ERROR) << "WAOS::" << __func__ << " => (ERROR: WASAPI rendering failed)"; @@ -562,6 +586,7 @@ bool WASAPIAudioOutputStream::RenderAudioFromSource(UINT64 device_frequency) { num_available_frames = endpoint_buffer_size_frames_ - num_queued_frames; if (FAILED(hr)) { + RecordAudioFailure(kRenderFailureHistogram, hr); LOG(ERROR) << "WAOS::" << __func__ << " => (ERROR: IAudioClient::GetCurrentPadding=[" << ErrorToString(hr).c_str() << "])"; @@ -607,6 +632,7 @@ bool WASAPIAudioOutputStream::RenderAudioFromSource(UINT64 device_frequency) { hr = audio_render_client_->GetBuffer(packet_size_frames_, &audio_data); if (FAILED(hr)) { + RecordAudioFailure(kRenderFailureHistogram, hr); LOG(ERROR) << "WAOS::" << __func__ << " => (ERROR: IAudioRenderClient::GetBuffer=[" << ErrorToString(hr).c_str() << "])"; @@ -678,6 +704,7 @@ bool WASAPIAudioOutputStream::RenderAudioFromSource(UINT64 device_frequency) { // by 10.0 since 10x100ns = 1us. delay_timestamp += base::TimeDelta::FromMicroseconds(qpc_position * 0.1); } else { + RecordAudioFailure(kRenderFailureHistogram, hr); LOG(ERROR) << "WAOS::" << __func__ << " => (ERROR: IAudioClock::GetPosition=[" << ErrorToString(hr).c_str() << "])"; diff --git a/tools/metrics/histograms/histograms_xml/media/histograms.xml b/tools/metrics/histograms/histograms_xml/media/histograms.xml index c29577a06f156b..e8de8782497b6a 100644 --- a/tools/metrics/histograms/histograms_xml/media/histograms.xml +++ b/tools/metrics/histograms/histograms_xml/media/histograms.xml @@ -560,6 +560,23 @@ reviews. Googlers can read more about this at go/gwsq-gerrit. + + dalecurtis@chromium.org + media-dev@chromium.org + + Errors from various methods on WASAPIAudioOutputStream. Recorded upon a + failure being returned from a call into WASAPI. + + + + + + + + + + armax@chromium.org