Skip to content

Commit

Permalink
Log HRESULT failures during Windows audio output.
Browse files Browse the repository at this point in the history 
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 <dalecurtis@chromium.org>
Reviewed-by: Henrik Andreasson <henrika@chromium.org>
Reviewed-by: Brian White <bcwhite@chromium.org>
Commit-Queue: Brian White <bcwhite@chromium.org>
Cr-Commit-Position: refs/heads/master@{#883612}
  • Loading branch information
@dalecurtis
dalecurtis authored and Chromium LUCI CQ committed May 17, 2021
1 parent cb711ef commit 7f1f949
Show file tree
Hide file tree
Showing 2 changed files with 45 additions and 1 deletion.
29 changes: 28 additions & 1 deletion media/audio/win/audio_low_latency_output_win.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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"
Expand All @@ -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);
Expand Down Expand Up @@ -181,13 +192,15 @@ bool WASAPIAudioOutputStream::Open() {
Microsoft::WRL::ComPtr<IAudioClient> 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;
}

// 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;
}
Expand All @@ -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;
Expand All @@ -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;
}

Expand Down Expand Up @@ -271,6 +286,7 @@ bool WASAPIAudioOutputStream::Open() {
Microsoft::WRL::ComPtr<IAudioRenderClient> 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;
}
Expand All @@ -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;
Expand Down Expand Up @@ -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;
Expand All @@ -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();
Expand All @@ -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();
Expand All @@ -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);
Expand All @@ -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);
Expand Down Expand Up @@ -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() << "])";
Expand Down Expand Up @@ -523,6 +546,7 @@ void WASAPIAudioOutputStream::Run() {
}

if (playing && error) {
RecordAudioFailure(kRunFailureHistogram, GetLastError());
LOG(ERROR) << "WAOS::" << __func__
<< " => (ERROR: WASAPI rendering failed)";

Expand Down Expand Up @@ -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() << "])";
Expand Down Expand Up @@ -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() << "])";
Expand Down Expand Up @@ -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() << "])";
Expand Down
17 changes: 17 additions & 0 deletions tools/metrics/histograms/histograms_xml/media/histograms.xml
View file
Original file line number Diff line number Diff line change
Expand Up @@ -560,6 +560,23 @@ reviews. Googlers can read more about this at go/gwsq-gerrit.
</summary>
</histogram>

<histogram name="Media.Audio.Output.Win.{AudioOutputMethod}Error"
enum="Hresult" expires_after="M98">
<owner>dalecurtis@chromium.org</owner>
<owner>media-dev@chromium.org</owner>
<summary>
Errors from various methods on WASAPIAudioOutputStream. Recorded upon a
failure being returned from a call into WASAPI.
</summary>
<token key="AudioOutputMethod">
<variant name="Open"/>
<variant name="Render"/>
<variant name="Run"/>
<variant name="Start"/>
<variant name="Stop"/>
</token>
</histogram>

<histogram name="Media.Audio.OutputDeviceAuthorizationTime" units="ms"
expires_after="2021-10-10">
<owner>armax@chromium.org</owner>
Expand Down

0 comments on commit 7f1f949

Please sign in to comment.