Convert audio thread hang crash to UMA. Dump driver info on Win.

This crash has gone on for too long and, as far as we know, can't
be fixed within Chrome. So instead of crashing just log this data
to UMA on all platforms. On Windows dump a non-crash report
with the device driver name and version information since we have
an open channel with Microsoft for tracking down misbehaving drivers.

Introduces a new histogram Media.AudioThreadStatus for tracking
started, hung, and recovered values. As well as code for reading
the driver name and version from dxdiag structures.

Notably, since this is now a UMA we will record hangs even on
stable or beta, but only log crash dumps on Dev/Canary/Unknown;
since these hangs appear to be high frequency, it doesn't seem
wise or necessary to enable the crash dumps on stable/beta. If
canary/unknown prove sufficient for crash key dumps, I'll limit
to there in a followup CL.

BUG=422522,478932,546750
TEST=new unittest, manual verification of uma values.
TBR=thestig

Review URL: https://codereview.chromium.org/1513143002

Cr-Commit-Position: refs/heads/master@{#364792}

13 files changed, 180 insertions, 42 deletions

diff --git a/chrome/browser/chrome_browser_main.cc b/chrome/browser/chrome_browser_main.cc
index 6f18aad..3f042a7 100644
--- a/chrome/browser/chrome_browser_main.cc
+++ b/chrome/browser/chrome_browser_main.cc
@@ -746,7 +746,7 @@ void ChromeBrowserMainParts::SetupMetricsAndFieldTrials() {
   if (channel == version_info::Channel::UNKNOWN ||
       channel == version_info::Channel::CANARY ||
       channel == version_info::Channel::DEV) {
-    media::AudioManager::EnableHangMonitor();
+    media::AudioManager::EnableCrashKeyLoggingForAudioThreadHangs();
   }
 
   // Enable profiler instrumentation depending on the channel.
diff --git a/chrome/common/crash_keys.cc b/chrome/common/crash_keys.cc
index 96553c3..93b98e5 100644
--- a/chrome/common/crash_keys.cc
+++ b/chrome/common/crash_keys.cc
@@ -47,6 +47,10 @@ const char kGPUVendor[] = "gpu-gl-vendor";
 const char kGPURenderer[] = "gpu-gl-renderer";
 #endif
 
+#if defined(OS_WIN)
+const char kHungAudioThreadDetails[] = "hung-audio-thread-details";
+#endif
+
 const char kPrinterInfo[] = "prn-info-%" PRIuS;
 
 #if defined(OS_CHROMEOS)
@@ -141,6 +145,11 @@ size_t RegisterChromeCrashKeys() {
 #endif
     { kBug464926CrashKey, kSmallSize },
     { kViewCount, kSmallSize },
+
+    // media/:
+#if defined(OS_WIN)
+    { kHungAudioThreadDetails, kSmallSize },
+#endif
     { kZeroEncodeDetails, kSmallSize },
   };
 
diff --git a/chrome/common/crash_keys.h b/chrome/common/crash_keys.h
index 97f85ed..262daed 100644
--- a/chrome/common/crash_keys.h
+++ b/chrome/common/crash_keys.h
@@ -78,6 +78,10 @@ extern const char kGPUVendor[];
 extern const char kGPURenderer[];
 #endif
 
+#if defined(OS_WIN)
+extern const char kHungAudioThreadDetails[];
+#endif
+
 // The user's printers, up to kPrinterInfoCount. Should be set with
 // ScopedPrinterInfo.
 const size_t kPrinterInfoCount = 4;
diff --git a/media/audio/BUILD.gn b/media/audio/BUILD.gn
index 706004c..8892e76 100644
--- a/media/audio/BUILD.gn
+++ b/media/audio/BUILD.gn
@@ -170,6 +170,8 @@ source_set("audio") {
       "win/waveout_output_win.cc",
       "win/waveout_output_win.h",
     ]
+
+    libs += [ "dxguid.lib" ]
   }
 
   if (is_android) {
diff --git a/media/audio/audio_manager.cc b/media/audio/audio_manager.cc
index ebdfc4e..b0d866ca 100644
--- a/media/audio/audio_manager.cc
+++ b/media/audio/audio_manager.cc
@@ -8,10 +8,14 @@
 #include "base/bind_helpers.h"
 #include "base/command_line.h"
 #include "base/debug/alias.h"
+#include "base/debug/crash_logging.h"
+#include "base/debug/dump_without_crashing.h"
 #include "base/lazy_instance.h"
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/power_monitor/power_monitor.h"
+#include "base/strings/stringprintf.h"
 #include "build/build_config.h"
 #include "media/audio/audio_manager_factory.h"
 #include "media/audio/fake_audio_log_factory.h"
@@ -20,6 +24,7 @@
 
 #if defined(OS_WIN)
 #include "base/win/scoped_com_initializer.h"
+#include "media/audio/win/core_audio_util_win.h"
 #endif
 
 namespace media {
@@ -46,13 +51,25 @@ const int kMaxHangFailureCount = 2;
 // process so we can catch offenders quickly in the field.
 class AudioManagerHelper : public base::PowerObserver {
  public:
-  AudioManagerHelper()
-      : max_hung_task_time_(base::TimeDelta::FromMinutes(1)),
-        hang_detection_enabled_(true),
-        io_task_running_(false),
-        audio_task_running_(false) {}
+  // These values are histogrammed over time; do not change their ordinal
+  // values.
+  enum ThreadStatus {
+    THREAD_NONE = 0,
+    THREAD_STARTED,
+    THREAD_HUNG,
+    THREAD_RECOVERED,
+    THREAD_MAX = THREAD_RECOVERED
+  };
+
+  AudioManagerHelper() {}
   ~AudioManagerHelper() override {}
 
+  void HistogramThreadStatus(ThreadStatus status) {
+    audio_thread_status_ = status;
+    UMA_HISTOGRAM_ENUMERATION("Media.AudioThreadStatus", audio_thread_status_,
+                              THREAD_MAX + 1);
+  }
+
   void StartHangTimer(
       const scoped_refptr<base::SingleThreadTaskRunner>& monitor_task_runner) {
     CHECK(!monitor_task_runner_);
@@ -61,7 +78,7 @@ class AudioManagerHelper : public base::PowerObserver {
     hang_failures_ = 0;
     io_task_running_ = audio_task_running_ = true;
     UpdateLastAudioThreadTimeTick();
-    CrashOnAudioThreadHang();
+    RecordAudioThreadStatus();
   }
 
   // Disable hang detection when the system goes into the suspend state.
@@ -90,12 +107,12 @@ class AudioManagerHelper : public base::PowerObserver {
       io_task_running_ = true;
 
       base::AutoUnlock unlock(hang_lock_);
-      CrashOnAudioThreadHang();
+      RecordAudioThreadStatus();
     }
   }
 
   // Runs on |monitor_task_runner| typically, but may be started on any thread.
-  void CrashOnAudioThreadHang() {
+  void RecordAudioThreadStatus() {
     {
       base::AutoLock lock(hang_lock_);
 
@@ -110,15 +127,24 @@ class AudioManagerHelper : public base::PowerObserver {
       const base::TimeTicks now = base::TimeTicks::Now();
       const base::TimeDelta tick_delta = now - last_audio_thread_timer_tick_;
       if (tick_delta > max_hung_task_time_) {
-        CHECK_LT(++hang_failures_, kMaxHangFailureCount);
+        if (++hang_failures_ >= kMaxHangFailureCount &&
+            audio_thread_status_ < THREAD_HUNG) {
+          if (enable_crash_key_logging_)
+            LogAudioDriverCrashKeys();
+          HistogramThreadStatus(THREAD_HUNG);
+        }
       } else {
         hang_failures_ = 0;
+        if (audio_thread_status_ == THREAD_NONE)
+          HistogramThreadStatus(THREAD_STARTED);
+        else if (audio_thread_status_ == THREAD_HUNG)
+          HistogramThreadStatus(THREAD_RECOVERED);
       }
     }
 
     // Don't hold the lock while posting the next task.
     monitor_task_runner_->PostDelayedTask(
-        FROM_HERE, base::Bind(&AudioManagerHelper::CrashOnAudioThreadHang,
+        FROM_HERE, base::Bind(&AudioManagerHelper::RecordAudioThreadStatus,
                               base::Unretained(this)),
         max_hung_task_time_);
   }
@@ -167,18 +193,40 @@ class AudioManagerHelper : public base::PowerObserver {
   }
 #endif
 
+  void enable_crash_key_logging() { enable_crash_key_logging_ = true; }
+
  private:
+  void LogAudioDriverCrashKeys() {
+    DCHECK(enable_crash_key_logging_);
+
+#if defined(OS_WIN)
+    std::string driver_name, driver_version;
+    if (!CoreAudioUtil::GetDxDiagDetails(&driver_name, &driver_version))
+      return;
+
+    base::debug::ScopedCrashKey crash_key(
+        "hung-audio-thread-details",
+        base::StringPrintf("%s:%s", driver_name.c_str(),
+                           driver_version.c_str()));
+
+    // Please forward crash reports to http://crbug.com/422522
+    base::debug::DumpWithoutCrashing();
+#endif
+  }
+
   FakeAudioLogFactory fake_log_factory_;
 
-  const base::TimeDelta max_hung_task_time_;
+  const base::TimeDelta max_hung_task_time_ = base::TimeDelta::FromMinutes(1);
   scoped_refptr<base::SingleThreadTaskRunner> monitor_task_runner_;
 
   base::Lock hang_lock_;
-  bool hang_detection_enabled_;
+  bool hang_detection_enabled_ = true;
   base::TimeTicks last_audio_thread_timer_tick_;
-  int hang_failures_;
-  bool io_task_running_;
-  bool audio_task_running_;
+  int hang_failures_ = 0;
+  bool io_task_running_ = false;
+  bool audio_task_running_ = false;
+  ThreadStatus audio_thread_status_ = THREAD_NONE;
+  bool enable_crash_key_logging_ = false;
 
 #if defined(OS_WIN)
   scoped_ptr<base::win::ScopedCOMInitializer> com_initializer_for_testing_;
@@ -191,8 +239,6 @@ class AudioManagerHelper : public base::PowerObserver {
   DISALLOW_COPY_AND_ASSIGN(AudioManagerHelper);
 };
 
-bool g_hang_monitor_enabled = false;
-
 base::LazyInstance<AudioManagerHelper>::Leaky g_helper =
     LAZY_INSTANCE_INITIALIZER;
 
@@ -240,11 +286,13 @@ AudioManager* AudioManager::CreateWithHangTimer(
     AudioLogFactory* audio_log_factory,
     const scoped_refptr<base::SingleThreadTaskRunner>& monitor_task_runner) {
   AudioManager* manager = Create(audio_log_factory);
-  if (g_hang_monitor_enabled ||
-      base::CommandLine::ForCurrentProcess()->HasSwitch(
-          switches::kEnableAudioHangMonitor)) {
-    g_helper.Pointer()->StartHangTimer(monitor_task_runner);
-  }
+
+// On OSX the audio thread is the UI thread, for which a hang monitor is not
+// necessary or recommended.
+#if !defined(OS_MACOSX)
+  g_helper.Pointer()->StartHangTimer(monitor_task_runner);
+#endif
+
   return manager;
 }
 
@@ -257,14 +305,9 @@ AudioManager* AudioManager::CreateForTesting() {
 }
 
 // static
-void AudioManager::EnableHangMonitor() {
+void AudioManager::EnableCrashKeyLoggingForAudioThreadHangs() {
   CHECK(!g_last_created);
-// On OSX the audio thread is the UI thread, for which a hang monitor is not
-// necessary or recommended.  If it's manually requested, we should allow it
-// to start though.
-#if !defined(OS_MACOSX)
-  g_hang_monitor_enabled = true;
-#endif
+  g_helper.Pointer()->enable_crash_key_logging();
 }
 
 #if defined(OS_LINUX)
diff --git a/media/audio/audio_manager.h b/media/audio/audio_manager.h
index 4da250d..6ee4f6d 100644
--- a/media/audio/audio_manager.h
+++ b/media/audio/audio_manager.h
@@ -26,6 +26,11 @@ class AudioOutputStream;
 
 // Manages all audio resources.  Provides some convenience functions that avoid
 // the need to provide iterators over the existing streams.
+//
+// Except on OSX, a hang monitor for the audio thread is always created. When a
+// thread hang is detected, it is reported to UMA.  Optionally, if called prior,
+// EnableCrashKeyLoggingForAudioThreadHangs() will cause a non-crash dump to be
+// logged on Windows (this allows us to report driver hangs to Microsoft).
 class MEDIA_EXPORT AudioManager {
  public:
   virtual ~AudioManager();
@@ -55,11 +60,8 @@ class MEDIA_EXPORT AudioManager {
   // Similar to Create() except uses a FakeAudioLogFactory for testing.
   static AudioManager* CreateForTesting();
 
-  // Enables the hang monitor for the AudioManager once it's created.  Must be
-  // called before the AudioManager is created.  CreateWithHangTimer() requires
-  // either switches::kEnableAudioHangMonitor to be present or this to have been
-  // called previously to start the hang monitor.  Does nothing on OSX.
-  static void EnableHangMonitor();
+  // Enables non-crash dumps when audio thread hangs are detected.
+  static void EnableCrashKeyLoggingForAudioThreadHangs();
 
 #if defined(OS_LINUX)
   // Sets the name of the audio source as seen by external apps. Only actually
diff --git a/media/audio/win/core_audio_util_win.cc b/media/audio/win/core_audio_util_win.cc
index 1ce0191..4db77c0 100644
--- a/media/audio/win/core_audio_util_win.cc
+++ b/media/audio/win/core_audio_util_win.cc
@@ -5,6 +5,7 @@
 #include "media/audio/win/core_audio_util_win.h"
 
 #include <devicetopology.h>
+#include <dxdiag.h>
 #include <functiondiscoverykeys_devpkey.h>
 
 #include "base/command_line.h"
@@ -14,6 +15,7 @@
 #include "base/win/scoped_co_mem.h"
 #include "base/win/scoped_handle.h"
 #include "base/win/scoped_propvariant.h"
+#include "base/win/scoped_variant.h"
 #include "base/win/windows_version.h"
 #include "media/audio/audio_manager_base.h"
 #include "media/base/media_switches.h"
@@ -908,4 +910,56 @@ bool CoreAudioUtil::FillRenderEndpointBufferWithSilence(
                                                 AUDCLNT_BUFFERFLAGS_SILENT));
 }
 
+bool CoreAudioUtil::GetDxDiagDetails(std::string* driver_name,
+                                     std::string* driver_version) {
+  ScopedComPtr<IDxDiagProvider, &IID_IDxDiagProvider> provider;
+  HRESULT hr =
+      provider.CreateInstance(CLSID_DxDiagProvider, NULL, CLSCTX_INPROC_SERVER);
+  if (FAILED(hr))
+    return false;
+
+  DXDIAG_INIT_PARAMS params = {sizeof(params)};
+  params.dwDxDiagHeaderVersion = DXDIAG_DX9_SDK_VERSION;
+  params.bAllowWHQLChecks = FALSE;
+  params.pReserved = NULL;
+  hr = provider->Initialize(&params);
+  if (FAILED(hr))
+    return false;
+
+  ScopedComPtr<IDxDiagContainer, &IID_IDxDiagContainer> root;
+  hr = provider->GetRootContainer(root.Receive());
+  if (FAILED(hr))
+    return false;
+
+  // Limit to the SoundDevices subtree. The tree in its entirity is
+  // enormous and only this branch contains useful information.
+  ScopedComPtr<IDxDiagContainer, &IID_IDxDiagContainer> sound_devices;
+  hr = root->GetChildContainer(L"DxDiag_DirectSound.DxDiag_SoundDevices.0",
+                               sound_devices.Receive());
+  if (FAILED(hr))
+    return false;
+
+  base::win::ScopedVariant variant;
+  hr = sound_devices->GetProp(L"szDriverName", variant.Receive());
+  if (FAILED(hr))
+    return false;
+
+  if (variant.type() == VT_BSTR && variant.ptr()->bstrVal) {
+    base::WideToUTF8(variant.ptr()->bstrVal, wcslen(variant.ptr()->bstrVal),
+                     driver_name);
+  }
+
+  variant.Reset();
+  hr = sound_devices->GetProp(L"szDriverVersion", variant.Receive());
+  if (FAILED(hr))
+    return false;
+
+  if (variant.type() == VT_BSTR && variant.ptr()->bstrVal) {
+    base::WideToUTF8(variant.ptr()->bstrVal, wcslen(variant.ptr()->bstrVal),
+                     driver_version);
+  }
+
+  return true;
+}
+
 }  // namespace media
diff --git a/media/audio/win/core_audio_util_win.h b/media/audio/win/core_audio_util_win.h
index 9110272..6ad14365 100644
--- a/media/audio/win/core_audio_util_win.h
+++ b/media/audio/win/core_audio_util_win.h
@@ -228,6 +228,11 @@ class MEDIA_EXPORT CoreAudioUtil {
   static bool FillRenderEndpointBufferWithSilence(
       IAudioClient* client, IAudioRenderClient* render_client);
 
+  // Returns the default audio driver file name and version string according to
+  // DxDiag.  Used for crash reporting.  Can be slow (~seconds).
+  static bool GetDxDiagDetails(std::string* driver_name,
+                               std::string* driver_version);
+
  private:
   CoreAudioUtil() {}
   ~CoreAudioUtil() {}
diff --git a/media/audio/win/core_audio_util_win_unittest.cc b/media/audio/win/core_audio_util_win_unittest.cc
index 0f850d3..82da188 100644
--- a/media/audio/win/core_audio_util_win_unittest.cc
+++ b/media/audio/win/core_audio_util_win_unittest.cc
@@ -37,6 +37,14 @@ class CoreAudioUtilWinTest : public ::testing::Test {
   ScopedCOMInitializer com_init_;
 };
 
+TEST_F(CoreAudioUtilWinTest, GetDxDiagDetails) {
+  ABORT_AUDIO_TEST_IF_NOT(DevicesAvailable());
+  std::string name, version;
+  ASSERT_TRUE(CoreAudioUtil::GetDxDiagDetails(&name, &version));
+  EXPECT_TRUE(!name.empty());
+  EXPECT_TRUE(!version.empty());
+}
+
 TEST_F(CoreAudioUtilWinTest, NumberOfActiveDevices) {
   ABORT_AUDIO_TEST_IF_NOT(DevicesAvailable());
 
diff --git a/media/base/media_switches.cc b/media/base/media_switches.cc
index 9f39d7d..0368728 100644
--- a/media/base/media_switches.cc
+++ b/media/base/media_switches.cc
@@ -92,11 +92,6 @@ const char kWaveOutBuffers[] = "waveout-buffers";
 const char kUseCras[] = "use-cras";
 #endif
 
-// Enables the audio thread hang monitor.  Allows us to find users in the field
-// who have stuck audio threads.  See crbug.com/422522 and crbug.com/478932.
-// TODO(dalecurtis): This should be removed once those issues are resolved.
-const char kEnableAudioHangMonitor[] = "enable-audio-hang-monitor";
-
 // Use fake device for Media Stream to replace actual camera and microphone.
 const char kUseFakeDeviceForMediaStream[] = "use-fake-device-for-media-stream";
 
diff --git a/media/base/media_switches.h b/media/base/media_switches.h
index bcaa81a..6598330 100644
--- a/media/base/media_switches.h
+++ b/media/base/media_switches.h
@@ -47,8 +47,6 @@ MEDIA_EXPORT extern const char kWaveOutBuffers[];
 MEDIA_EXPORT extern const char kUseCras[];
 #endif
 
-MEDIA_EXPORT extern const char kEnableAudioHangMonitor[];
-
 MEDIA_EXPORT extern const char kUseFakeDeviceForMediaStream[];
 MEDIA_EXPORT extern const char kUseFileForFakeVideoCapture[];
 MEDIA_EXPORT extern const char kUseFileForFakeAudioCapture[];
diff --git a/media/media.gyp b/media/media.gyp
index 18297a4..70be514 100644
--- a/media/media.gyp
+++ b/media/media.gyp
@@ -995,6 +995,7 @@
         ['OS=="win"', {
           'link_settings':  {
             'libraries': [
+              '-ldxguid.lib',
               '-lmf.lib',
               '-lmfplat.lib',
               '-lmfreadwrite.lib',
diff --git a/tools/metrics/histograms/histograms.xml b/tools/metrics/histograms/histograms.xml
index 22acd6c..58bce2f 100644
--- a/tools/metrics/histograms/histograms.xml
+++ b/tools/metrics/histograms/histograms.xml
@@ -18289,6 +18289,16 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   </summary>
 </histogram>
 
+<histogram name="Media.AudioThreadStatus" enum="AudioThreadStatus">
+  <owner>dalecurtis@chromium.org</owner>
+  <summary>
+    State of the audio thread. A value of &quot;started&quot; is emitted once
+    the hang monitor has been initialized. If the thread is detected as hung
+    later, a value of &quot;hung&quot; is emitted. If the hung thread later
+    recovers a value of &quot;recovered&quot; is emitted.
+  </summary>
+</histogram>
+
 <histogram name="Media.AudioTrackProcessingStates"
     enum="AudioTrackProcessingStates">
   <owner>grunell@chromium.org</owner>
@@ -55841,6 +55851,13 @@ http://cs/file:chrome/histograms.xml - but prefer this file for new entries.
   <int value="11" label="k24000Hz"/>
 </enum>
 
+<enum name="AudioThreadStatus" type="int">
+  <int value="0" label="None"/>
+  <int value="1" label="Started"/>
+  <int value="2" label="Hung"/>
+  <int value="3" label="Recovered"/>
+</enum>
+
 <enum name="AudioTrackProcessingStates" type="int">
   <int value="0" label="Enabled"/>
   <int value="1" label="Disabled"/>