AudioRendererSinkCache: Do not use unhealthy sinks

content/renderer/media/audio_renderer_sink_cache_impl.cc

Index: content/renderer/media/audio_renderer_sink_cache_impl.cc
diff --git a/content/renderer/media/audio_renderer_sink_cache_impl.cc b/content/renderer/media/audio_renderer_sink_cache_impl.cc
index 26b2ba5a31b4e53a3a78ef4858910b12d2623398..6ecfb82a8c5363e190b2918e753ebbf4b2c808cc 100644
--- a/content/renderer/media/audio_renderer_sink_cache_impl.cc
+++ b/content/renderer/media/audio_renderer_sink_cache_impl.cc
@@ -37,6 +37,11 @@ enum GetOutputDeviceInfoCacheUtilization {
   SINK_CACHE_LAST_ENTRY
 };
 
+bool SinkIsHealthy(media::AudioRendererSink* sink) {
+  return sink->GetOutputDeviceInfo().device_status() ==
+         media::OUTPUT_DEVICE_STATUS_OK;
+}
+
 }  // namespace
 
 // Cached sink data.
@@ -81,71 +86,51 @@ media::OutputDeviceInfo AudioRendererSinkCacheImpl::GetSinkInfo(
     int session_id,
     const std::string& device_id,
     const url::Origin& security_origin) {
-  CacheEntry cache_entry = {source_render_frame_id,
-                            std::string() /* device_id */, security_origin,
-                            nullptr /* sink */, false /* not used */};
+  scoped_refptr<media::AudioRendererSink> sink;
 
   if (media::AudioDeviceDescription::UseSessionIdToSelectDevice(session_id,
                                                                 device_id)) {
     // We are provided with session id instead of device id. Session id is
     // unique, so we can't find any matching sink. Creating a new one.
-    cache_entry.sink = create_sink_cb_.Run(source_render_frame_id, session_id,
-                                           device_id, security_origin);
-    cache_entry.device_id = cache_entry.sink->GetOutputDeviceInfo().device_id();
-
-    DVLOG(1) << "GetSinkInfo: address: " << cache_entry.sink.get()
-             << " - used session to create new sink.";
+    sink = create_sink_cb_.Run(source_render_frame_id, session_id, device_id,
+                               security_origin);
 
-    // Cache a newly-created sink.
-    base::AutoLock auto_lock(cache_lock_);
-    cache_.push_back(cache_entry);
+    CacheUnusedSinkIfHealthy(source_render_frame_id,
+                             sink->GetOutputDeviceInfo().device_id(),
+                             security_origin, sink);
     UMA_HISTOGRAM_ENUMERATION(
         "Media.Audio.Render.SinkCache.GetOutputDeviceInfoCacheUtilization",
         SINK_CACHE_MISS_CANNOT_LOOKUP_BY_SESSION_ID, SINK_CACHE_LAST_ENTRY);
 
   } else {

[DaleCurtis, 2016/11/30 22:00:05]

Seems you could early return here to avoid the big nested if, that also avoids
the C-style sink variable.

[o1ka, 2016/12/02 12:20:43]

Done.

     // Ignore session id.
-    base::AutoLock auto_lock(cache_lock_);
-
-    auto cache_iter =
-        FindCacheEntry_Locked(source_render_frame_id, device_id,
-                              security_origin, false /* unused_only */);
-
-    if (cache_iter != cache_.end()) {
-      // A matching cached sink is found.
-      DVLOG(1) << "GetSinkInfo: address: " << cache_iter->sink.get()
-               << " - reused a cached sink.";
-
-      UMA_HISTOGRAM_ENUMERATION(
-          "Media.Audio.Render.SinkCache.GetOutputDeviceInfoCacheUtilization",
-          SINK_CACHE_HIT, SINK_CACHE_LAST_ENTRY);
-      return cache_iter->sink->GetOutputDeviceInfo();
+    {
+      base::AutoLock auto_lock(cache_lock_);
+      auto cache_iter =
+          FindCacheEntry_Locked(source_render_frame_id, device_id,
+                                security_origin, false /* unused_only */);
+      if (cache_iter != cache_.end()) {
+        // A matching cached sink is found.
+        UMA_HISTOGRAM_ENUMERATION(
+            "Media.Audio.Render.SinkCache.GetOutputDeviceInfoCacheUtilization",
+            SINK_CACHE_HIT, SINK_CACHE_LAST_ENTRY);
+        return cache_iter->sink->GetOutputDeviceInfo();
+      }
     }
 
     // No matching sink found, create a new one.
-    cache_entry.device_id = device_id;
-    cache_entry.sink = create_sink_cb_.Run(
-        source_render_frame_id, 0 /* session_id */, device_id, security_origin);
-
-    DVLOG(1) << "GetSinkInfo: address: " << cache_entry.sink.get()
-             << " - no matching cached sink found, created a new one.";
-
-    // Cache a newly-created sink.
-    cache_.push_back(cache_entry);
+    sink = create_sink_cb_.Run(source_render_frame_id, 0 /* session_id */,
+                               device_id, security_origin);
+    CacheUnusedSinkIfHealthy(source_render_frame_id, device_id, security_origin,
+                             sink);
     UMA_HISTOGRAM_ENUMERATION(
         "Media.Audio.Render.SinkCache.GetOutputDeviceInfoCacheUtilization",
         SINK_CACHE_MISS_NO_SINK, SINK_CACHE_LAST_ENTRY);
   }
 
-  // Schedule it for deletion.
-  DeleteLaterIfUnused(cache_entry.sink.get());
-
-  DVLOG(1) << "GetSinkInfo: address: " << cache_entry.sink.get()
-           << " created. source_render_frame_id: " << source_render_frame_id
-           << " session_id: " << session_id << " device_id: " << device_id
-           << " security_origin: " << security_origin;
-
-  return cache_entry.sink->GetOutputDeviceInfo();
+  //|sink| is ref-counted, so it's ok if it is removed from cache before we get
+  // here.
+  return sink->GetOutputDeviceInfo();
 }
 
 scoped_refptr<media::AudioRendererSink> AudioRendererSinkCacheImpl::GetSink(
@@ -163,9 +148,6 @@ scoped_refptr<media::AudioRendererSink> AudioRendererSinkCacheImpl::GetSink(
 
   if (cache_iter != cache_.end()) {
     // Found unused sink; mark it as used and return.
-    DVLOG(1) << "GetSink: address: " << cache_iter->sink.get()
-             << " - found unused cached sink, reusing it.";
-
     cache_iter->used = true;
     UMA_HISTOGRAM_BOOLEAN(
         "Media.Audio.Render.SinkCache.InfoSinkReusedForOutput", true);
@@ -179,13 +161,13 @@ scoped_refptr<media::AudioRendererSink> AudioRendererSinkCacheImpl::GetSink(
                           security_origin),
       true /* used */};
 
-  cache_.push_back(cache_entry);
+  bool cache_it = SinkIsHealthy(cache_entry.sink.get());

[DaleCurtis, 2016/11/30 22:00:05]

_it naming seems incorrect for a bool.

[o1ka, 2016/12/02 12:20:43]

Done.

+  if (cache_it)
+    cache_.push_back(cache_entry);
+
+  UMA_HISTOGRAM_BOOLEAN("Media.Audio.Render.SinkCache.HealthyUsedSinkCached",

[DaleCurtis, 2016/11/30 22:00:05]

Do we need these new metrics? With your fixes we'll see drops in the existing
metrics.

[o1ka, 2016/12/02 12:20:43]

Done.

+                        cache_it);
 
-  DVLOG(1) << "GetSink: address: " << cache_entry.sink.get()
-           << " - no unused cached sink found, created a new one."
-           << " source_render_frame_id: " << source_render_frame_id
-           << " device_id: " << device_id
-           << " security_origin: " << security_origin;
   return cache_entry.sink;
 }
 
@@ -220,14 +202,6 @@ void AudioRendererSinkCacheImpl::DeleteSink(
                                    });
 
     if (cache_iter == cache_.end()) {
-      // If |force_delete_used| is not set it means the sink scheduled for
-      // deletion got aquired and released before scheduled deletion - it's ok.
-      DCHECK(!force_delete_used)
-          << "DeleteSink: address: " << sink_ptr
-          << " could not find a sink which is supposed to be in use";
-
-      DVLOG(1) << "DeleteSink: address: " << sink_ptr
-               << " force_delete_used = false - already deleted.";
       return;
     }
 
@@ -236,11 +210,8 @@ void AudioRendererSinkCacheImpl::DeleteSink(
     DCHECK((!force_delete_used) || (force_delete_used && cache_iter->used))
         << "Attempt to delete a non-aquired sink.";
 
-    if (!force_delete_used && cache_iter->used) {
-      DVLOG(1) << "DeleteSink: address: " << sink_ptr
-               << " sink in use, skipping deletion.";
+    if (!force_delete_used && cache_iter->used)
       return;
-    }
 
     // To stop the sink before deletion if it's not used, we need to hold
     // a ref to it.
@@ -251,14 +222,12 @@ void AudioRendererSinkCacheImpl::DeleteSink(
     }
 
     cache_.erase(cache_iter);
-    DVLOG(1) << "DeleteSink: address: " << sink_ptr;
   }  // Lock scope;
 
   // Stop the sink out of the lock scope.
   if (sink_to_stop.get()) {
     DCHECK_EQ(sink_ptr, sink_to_stop.get());
     sink_to_stop->Stop();
-    DVLOG(1) << "DeleteSink: address: " << sink_ptr << " stopped.";
   }
 }
 
@@ -288,6 +257,30 @@ AudioRendererSinkCacheImpl::FindCacheEntry_Locked(
       });
 };
 
+void AudioRendererSinkCacheImpl::CacheUnusedSinkIfHealthy(
+    int source_render_frame_id,
+    const std::string& device_id,
+    const url::Origin& security_origin,
+    scoped_refptr<media::AudioRendererSink> sink) {
+  if (!SinkIsHealthy(sink.get())) {
+    UMA_HISTOGRAM_BOOLEAN(
+        "Media.Audio.Render.SinkCache.HealthyUnusedSinkCached", false);
+    return;
+  }
+
+  CacheEntry cache_entry = {source_render_frame_id, device_id, security_origin,
+                            sink, false /* not used */};
+
+  {
+    base::AutoLock auto_lock(cache_lock_);
+    cache_.push_back(cache_entry);
+  }
+
+  UMA_HISTOGRAM_BOOLEAN("Media.Audio.Render.SinkCache.HealthyUnusedSinkCached",
+                        true);
+  DeleteLaterIfUnused(cache_entry.sink.get());
+}
+
 int AudioRendererSinkCacheImpl::GetCacheSizeForTesting() {
   return cache_.size();
 }