Implementing AudioOutputDevice authorization timeout

media/audio/audio_output_device.cc

Index: media/audio/audio_output_device.cc
diff --git a/media/audio/audio_output_device.cc b/media/audio/audio_output_device.cc
index a3effebfb43af118500197a6eed9a48093563f7d..2fa6f1be9324d3631f8671bf85f9b41db7e158f6 100644
--- a/media/audio/audio_output_device.cc
+++ b/media/audio/audio_output_device.cc
@@ -12,14 +12,19 @@
 
 #include "base/callback_helpers.h"
 #include "base/macros.h"
+#include "base/metrics/histogram_macros.h"
 #include "base/threading/thread_restrictions.h"
 #include "base/time/time.h"
+#include "base/timer/elapsed_timer.h"
+#include "base/timer/timer.h"
 #include "base/trace_event/trace_event.h"
 #include "build/build_config.h"
 #include "media/audio/audio_device_description.h"
 #include "media/audio/audio_output_controller.h"
 #include "media/base/limits.h"
 
+constexpr int kAuthorizationTimeoutMs = 4000;

[o1ka, 2016/06/10 14:21:09]

Since content::kHungRendererDelayMs is obviously in content, we can't rely on it
here, so using an absolute value.

+
 namespace media {
 
 // Takes care of invoking the render callback on the audio thread.
@@ -154,8 +159,19 @@ void AudioOutputDevice::RequestDeviceAuthorizationOnIOThread() {
   DCHECK(task_runner()->BelongsToCurrentThread());
   DCHECK_EQ(state_, IDLE);
   state_ = AUTHORIZING;
+
   ipc_->RequestDeviceAuthorization(this, session_id_, device_id_,
                                    security_origin_);
+
+  // Create the timer on the thread it's used on. It's guaranteed to be
+  // deleted on the same thread since users must call Stop() before deleting
+  // AudioOutputDevice; see ShutDownOnIOThread().
+  auth_timeout_action_.reset(new base::OneShotTimer());
+  auth_timeout_action_->Start(
+      FROM_HERE, base::TimeDelta::FromMilliseconds(kAuthorizationTimeoutMs),
+      base::Bind(&AudioOutputDevice::ProcessDeviceAuthorizationOnIOThread, this,
+                 OUTPUT_DEVICE_STATUS_ERROR_INTERNAL, media::AudioParameters(),
+                 std::string(), true /* timed out */));
 }
 
 void AudioOutputDevice::CreateStreamOnIOThread(const AudioParameters& params) {
@@ -229,6 +245,9 @@ void AudioOutputDevice::ShutDownOnIOThread() {
   }
   start_on_authorized_ = false;
 
+  // Destoy the timer on the thread it's used on.
+  auth_timeout_action_.reset(nullptr);
+
   // We can run into an issue where ShutDownOnIOThread is called right after
   // OnStreamCreated is called in cases where Start/Stop are called before we
   // get the OnStreamCreated callback.  To handle that corner case, we call
@@ -284,7 +303,44 @@ void AudioOutputDevice::OnDeviceAuthorized(
     OutputDeviceStatus device_status,
     const media::AudioParameters& output_params,
     const std::string& matched_device_id) {
+  ProcessDeviceAuthorizationOnIOThread(device_status, output_params,
+                                       matched_device_id, false);
+}
+
+void AudioOutputDevice::ProcessDeviceAuthorizationOnIOThread(
+    OutputDeviceStatus device_status,
+    const media::AudioParameters& output_params,
+    const std::string& matched_device_id,
+    bool timed_out) {
   DCHECK(task_runner()->BelongsToCurrentThread());
+
+  if (auth_timeout_action_)
+    auth_timeout_action_->Stop();
+
+  if (timed_out) {
+    DCHECK_EQ(OUTPUT_DEVICE_STATUS_ERROR_INTERNAL, device_status);
+    UMA_HISTOGRAM_BOOLEAN(
+        "Media.Audio.Render.OutputDeviceAuthorizationTimedOut", true);
+    auth_delay_.reset(new base::ElapsedTimer());
+  } else {
+    if (state_ == IPC_CLOSED) {
+      // ProcessDeviceAuthorizationOnIOThread has already been called with
+      // |timed_out| set to true, i.e. authorization timed out, but now we
+      // received a late authorization response. Do nothing, since we can't
+      // upgrade device information after |did_receive_auth_| is signalled.

[DaleCurtis, 2016/06/10 18:29:18]

signaled.

[o1ka, 2016/06/13 13:22:12]

Acknowledged.

+      if (auth_delay_) {
+        UMA_HISTOGRAM_COUNTS(
+            "Media.Audio.Render.OutputDeviceAuthorizationTimeoutExceededMs",

[o1ka, 2016/06/10 14:21:09]

I'm not sure if we want to have this metric. Since we close IPC when
authorization request times out, we'll log only a little fraction which is
(probably) received right after the timeout fired. The values should be within
just several milliseconds. And we won't receive any later authorizations as soon
as IPC is closed.

[DaleCurtis, 2016/06/10 18:29:18]

Yeah, I don't think this is useful.

[o1ka, 2016/06/13 13:22:12]

Removed.

+            auth_delay_->Elapsed().InMilliseconds());
+        auth_delay_.reset(nullptr);
+      }
+      return;
+    } else {
+      UMA_HISTOGRAM_BOOLEAN(

[DaleCurtis, 2016/06/10 18:29:18]

Just have this in one spot outside the conditional:

UMA_HISTOGRAM_BOOLEAN("Media.Audio.Render.OutputDeviceAuthorizationTimedOut",
timed_out);

[o1ka, 2016/06/13 13:22:13]

Done.

+          "Media.Audio.Render.OutputDeviceAuthorizationTimedOut", false);
+    }
+  }
+
   DCHECK_EQ(state_, AUTHORIZING);
 
   // It may happen that a second authorization is received as a result to a