MD Settings: Bluetooth: Fix adapter state and discovery

extensions/browser/api/bluetooth/bluetooth_event_router.cc

 // Copyright (c) 2012 The Chromium Authors. All rights reserved.
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
 #include "extensions/browser/api/bluetooth/bluetooth_event_router.h"
 
 #include <map>
 #include <string>
 #include <utility>
 
 #include "base/bind.h"
 #include "base/bind_helpers.h"
 #include "base/lazy_instance.h"
 #include "base/logging.h"
 #include "base/memory/ref_counted.h"
 #include "base/stl_util.h"
 #include "base/strings/utf_string_conversions.h"
 #include "build/build_config.h"
+#include "components/device_event_log/device_event_log.h"
 #include "content/public/browser/notification_details.h"
 #include "content/public/browser/notification_source.h"
 #include "device/bluetooth/bluetooth_adapter.h"
 #include "device/bluetooth/bluetooth_adapter_factory.h"
 #include "device/bluetooth/bluetooth_device.h"
 #include "device/bluetooth/bluetooth_discovery_session.h"
 #include "extensions/browser/api/bluetooth/bluetooth_api_pairing_delegate.h"
 #include "extensions/browser/api/bluetooth/bluetooth_api_utils.h"
 #include "extensions/browser/api/bluetooth/bluetooth_private_api.h"
 #include "extensions/browser/event_router.h"
 #include "extensions/browser/extension_host.h"
 #include "extensions/browser/extension_registry.h"
 #include "extensions/browser/notification_types.h"
 #include "extensions/common/api/bluetooth.h"
 #include "extensions/common/api/bluetooth_private.h"
 
 namespace extensions {
 
 namespace {
 
 void IgnoreAdapterResult(scoped_refptr<device::BluetoothAdapter> adapter) {}
 
 void IgnoreAdapterResultAndThen(
     const base::Closure& callback,
     scoped_refptr<device::BluetoothAdapter> adapter) {
   callback.Run();
 }
 
+std::string GetListenerId(const extensions::EventListenerInfo& details) {
+  return !details.extension_id.empty() ? details.extension_id
+                                       : details.listener_url.host();

[Devlin, 2017/04/12 19:21:44]

Haven't we had issues with using the host as an id before?  Does this handle
e.g. multiple tabs with the same host?

[stevenjb, 2017/04/12 20:35:41]

The code (and TODO) you are thinking of (I assume) are at the top of
event_listener_map.cc, We already call url::Origin(listener_url).GetURL(). This
just extracts the relevant part as a string (we also do this in
bluetooth_private_api.cc).

I want to replace 'extension_id' and 'url' with 'listener_id' in
EventListenerInfo so this isn't needed, but that is more involved and we should
do that separately.

+}
+
 }  // namespace
 
 namespace bluetooth = api::bluetooth;
 namespace bt_private = api::bluetooth_private;
 
 BluetoothEventRouter::BluetoothEventRouter(content::BrowserContext* context)
     : browser_context_(context),
       adapter_(nullptr),
-      num_event_listeners_(0),
       extension_registry_observer_(this),
       weak_ptr_factory_(this) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
+  BLUETOOTH_LOG(USER) << "BluetoothEventRouter()";
   DCHECK(browser_context_);
-  registrar_.Add(this,
-                 extensions::NOTIFICATION_EXTENSION_HOST_DESTROYED,
+  registrar_.Add(this, extensions::NOTIFICATION_EXTENSION_HOST_DESTROYED,
                  content::Source<content::BrowserContext>(browser_context_));
   extension_registry_observer_.Add(ExtensionRegistry::Get(browser_context_));
 }
 
 BluetoothEventRouter::~BluetoothEventRouter() {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
+  BLUETOOTH_LOG(USER) << "~BluetoothEventRouter()";
   if (adapter_.get()) {
     adapter_->RemoveObserver(this);
     adapter_ = nullptr;
   }
   CleanUpAllExtensions();
 }
 
 bool BluetoothEventRouter::IsBluetoothSupported() const {
   return adapter_.get() ||
          device::BluetoothAdapterFactory::IsBluetoothAdapterAvailable();
@@ skipping 28 matching lines @@
   }
   StartDiscoverySessionImpl(adapter, extension_id, callback, error_callback);
 }
 
 void BluetoothEventRouter::StartDiscoverySessionImpl(
     device::BluetoothAdapter* adapter,
     const std::string& extension_id,
     const base::Closure& callback,
     const base::Closure& error_callback) {
   if (!adapter_.get()) {
-    LOG(ERROR) << "Unable to get Bluetooth adapter.";
+    BLUETOOTH_LOG(ERROR) << "Unable to get Bluetooth adapter.";
     error_callback.Run();
     return;
   }
   if (adapter != adapter_.get()) {
-    LOG(ERROR) << "Bluetooth adapter mismatch.";
+    BLUETOOTH_LOG(ERROR) << "Bluetooth adapter mismatch.";
     error_callback.Run();
     return;
   }
   DiscoverySessionMap::iterator iter =
       discovery_session_map_.find(extension_id);
   if (iter != discovery_session_map_.end() && iter->second->IsActive()) {
-    DVLOG(1) << "An active discovery session exists for extension.";
+    BLUETOOTH_LOG(DEBUG) << "An active discovery session exists for extension: "
+                         << extension_id;
     error_callback.Run();
     return;
   }
 
+  BLUETOOTH_LOG(USER) << "StartDiscoverySession: " << extension_id;
+
   // Check whether user pre set discovery filter by calling SetDiscoveryFilter
   // before. If the user has set a discovery filter then start a filtered
   // discovery session, otherwise start a regular session
   PreSetFilterMap::iterator pre_set_iter =
       pre_set_filter_map_.find(extension_id);
   if (pre_set_iter != pre_set_filter_map_.end()) {
     adapter->StartDiscoverySessionWithFilter(
         std::unique_ptr<device::BluetoothDiscoveryFilter>(pre_set_iter->second),
         base::Bind(&BluetoothEventRouter::OnStartDiscoverySession,
                    weak_ptr_factory_.GetWeakPtr(), extension_id, callback),
@@ skipping 12 matching lines @@
     const std::string& extension_id,
     const base::Closure& callback,
     const base::Closure& error_callback) {
   if (adapter != adapter_.get()) {
     error_callback.Run();
     return;
   }
   DiscoverySessionMap::iterator iter =
       discovery_session_map_.find(extension_id);
   if (iter == discovery_session_map_.end() || !iter->second->IsActive()) {
-    DVLOG(1) << "No active discovery session exists for extension.";
+    BLUETOOTH_LOG(DEBUG) << "No active discovery session exists for extension.";
     error_callback.Run();
     return;
   }
+  BLUETOOTH_LOG(USER) << "StopDiscoverySession: " << extension_id;
   device::BluetoothDiscoverySession* session = iter->second;
   session->Stop(callback, error_callback);
 }
 
 void BluetoothEventRouter::SetDiscoveryFilter(
     std::unique_ptr<device::BluetoothDiscoveryFilter> discovery_filter,
     device::BluetoothAdapter* adapter,
     const std::string& extension_id,
     const base::Closure& callback,
     const base::Closure& error_callback) {
-  DVLOG(1) << "SetDiscoveryFilter";
+  BLUETOOTH_LOG(USER) << "SetDiscoveryFilter";
   if (adapter != adapter_.get()) {
     error_callback.Run();
     return;
   }
 
   DiscoverySessionMap::iterator iter =
       discovery_session_map_.find(extension_id);
   if (iter == discovery_session_map_.end() || !iter->second->IsActive()) {
-    DVLOG(1) << "No active discovery session exists for extension, so caching "
-                "filter for later use.";
+    BLUETOOTH_LOG(DEBUG) << "No active discovery session exists for extension, "
+                         << "so caching filter for later use.";
     pre_set_filter_map_[extension_id] = discovery_filter.release();
     callback.Run();
     return;
   }
 
   // extension is already running discovery, update it's discovery filter
   iter->second->SetDiscoveryFilter(std::move(discovery_filter), callback,
                                    error_callback);
 }
 
 BluetoothApiPairingDelegate* BluetoothEventRouter::GetPairingDelegate(
     const std::string& extension_id) {
   return base::ContainsKey(pairing_delegate_map_, extension_id)
              ? pairing_delegate_map_[extension_id]
              : nullptr;
 }
 
 void BluetoothEventRouter::OnAdapterInitialized(
     const device::BluetoothAdapterFactory::AdapterCallback& callback,
     scoped_refptr<device::BluetoothAdapter> adapter) {
   if (!adapter_.get()) {
     adapter_ = adapter;
     adapter_->AddObserver(this);
   }
 
   callback.Run(adapter);
 }
 
 void BluetoothEventRouter::MaybeReleaseAdapter() {
-  if (adapter_.get() && num_event_listeners_ == 0 &&
+  if (adapter_.get() && event_listener_count_.empty() &&
       pairing_delegate_map_.empty()) {
-    VLOG(1) << "Releasing Adapter.";
+    BLUETOOTH_LOG(EVENT) << "Releasing Adapter.";
     adapter_->RemoveObserver(this);
     adapter_ = nullptr;
   }
 }
 
 void BluetoothEventRouter::AddPairingDelegate(const std::string& extension_id) {
   if (!adapter_.get() && IsBluetoothSupported()) {
     GetAdapter(
         base::Bind(&IgnoreAdapterResultAndThen,
                    base::Bind(&BluetoothEventRouter::AddPairingDelegateImpl,
                               weak_ptr_factory_.GetWeakPtr(), extension_id)));
     return;
   }
   AddPairingDelegateImpl(extension_id);
 }
 
 void BluetoothEventRouter::AddPairingDelegateImpl(
     const std::string& extension_id) {
   if (!adapter_.get()) {
     LOG(ERROR) << "Unable to get adapter for extension_id: " << extension_id;
     return;
   }
   if (base::ContainsKey(pairing_delegate_map_, extension_id)) {
     // For WebUI there may be more than one page open to the same url
     // (e.g. chrome://settings). These will share the same pairing delegate.
-    VLOG(1) << "Pairing delegate already exists for extension_id: "
-            << extension_id;
+    BLUETOOTH_LOG(EVENT) << "Pairing delegate already exists for extension_id: "
+                         << extension_id;
     return;
   }
   BluetoothApiPairingDelegate* delegate =
       new BluetoothApiPairingDelegate(browser_context_);
   DCHECK(adapter_.get());
   adapter_->AddPairingDelegate(
       delegate, device::BluetoothAdapter::PAIRING_DELEGATE_PRIORITY_HIGH);
   pairing_delegate_map_[extension_id] = delegate;
 }
 
 void BluetoothEventRouter::RemovePairingDelegate(
     const std::string& extension_id) {
   if (base::ContainsKey(pairing_delegate_map_, extension_id)) {
     BluetoothApiPairingDelegate* delegate = pairing_delegate_map_[extension_id];
     if (adapter_.get())
       adapter_->RemovePairingDelegate(delegate);
     pairing_delegate_map_.erase(extension_id);
     delete delegate;
     MaybeReleaseAdapter();
   }
 }
 
 void BluetoothEventRouter::AdapterPresentChanged(
     device::BluetoothAdapter* adapter,
     bool present) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   if (adapter != adapter_.get()) {
-    DVLOG(1) << "Ignoring event for adapter " << adapter->GetAddress();
+    BLUETOOTH_LOG(DEBUG) << "Ignoring event for adapter "
+                         << adapter->GetAddress();
     return;
   }
   DispatchAdapterStateEvent();
 }
 
 void BluetoothEventRouter::AdapterPoweredChanged(
     device::BluetoothAdapter* adapter,
     bool has_power) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   if (adapter != adapter_.get()) {
-    DVLOG(1) << "Ignoring event for adapter " << adapter->GetAddress();
+    BLUETOOTH_LOG(DEBUG) << "Ignoring event for adapter "
+                         << adapter->GetAddress();
     return;
   }
   DispatchAdapterStateEvent();
 }
 
 void BluetoothEventRouter::AdapterDiscoveringChanged(
     device::BluetoothAdapter* adapter,
     bool discovering) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   if (adapter != adapter_.get()) {
-    DVLOG(1) << "Ignoring event for adapter " << adapter->GetAddress();
+    BLUETOOTH_LOG(DEBUG) << "Ignoring event for adapter "
+                         << adapter->GetAddress();
     return;
   }
 
   if (!discovering) {
     // If any discovery sessions are inactive, clean them up.
     DiscoverySessionMap active_session_map;
     for (DiscoverySessionMap::iterator iter = discovery_session_map_.begin();
-         iter != discovery_session_map_.end();
-         ++iter) {
+         iter != discovery_session_map_.end(); ++iter) {
       device::BluetoothDiscoverySession* session = iter->second;
       if (session->IsActive()) {
         active_session_map[iter->first] = session;
         continue;
       }
       delete session;
     }
     discovery_session_map_.swap(active_session_map);
   }
 
   DispatchAdapterStateEvent();
 
   // Release the adapter after dispatching the event.
   if (!discovering)
     MaybeReleaseAdapter();
 }
 
 void BluetoothEventRouter::DeviceAdded(device::BluetoothAdapter* adapter,
                                        device::BluetoothDevice* device) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   if (adapter != adapter_.get()) {
-    DVLOG(1) << "Ignoring event for adapter " << adapter->GetAddress();
+    BLUETOOTH_LOG(DEBUG) << "Ignoring event for adapter "
+                         << adapter->GetAddress();
     return;
   }
 
   DispatchDeviceEvent(events::BLUETOOTH_ON_DEVICE_ADDED,
                       bluetooth::OnDeviceAdded::kEventName, device);
 }
 
 void BluetoothEventRouter::DeviceChanged(device::BluetoothAdapter* adapter,
                                          device::BluetoothDevice* device) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   if (adapter != adapter_.get()) {
-    DVLOG(1) << "Ignoring event for adapter " << adapter->GetAddress();
+    BLUETOOTH_LOG(DEBUG) << "Ignoring event for adapter "
+                         << adapter->GetAddress();
     return;
   }
 
   DispatchDeviceEvent(events::BLUETOOTH_ON_DEVICE_CHANGED,
                       bluetooth::OnDeviceChanged::kEventName, device);
 }
 
 void BluetoothEventRouter::DeviceRemoved(device::BluetoothAdapter* adapter,
                                          device::BluetoothDevice* device) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   if (adapter != adapter_.get()) {
-    DVLOG(1) << "Ignoring event for adapter " << adapter->GetAddress();
+    BLUETOOTH_LOG(DEBUG) << "Ignoring event for adapter "
+                         << adapter->GetAddress();
     return;
   }
 
   DispatchDeviceEvent(events::BLUETOOTH_ON_DEVICE_REMOVED,
                       bluetooth::OnDeviceRemoved::kEventName, device);
 }
 
-void BluetoothEventRouter::OnListenerAdded() {
-  num_event_listeners_++;
+void BluetoothEventRouter::OnListenerAdded(const EventListenerInfo& details) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
+  std::string id = GetListenerId(details);
+  int count = ++event_listener_count_[id];
+  BLUETOOTH_LOG(EVENT) << "Event Listener Added: " << id << " Count: " << count;
   if (!adapter_.get())
     GetAdapter(base::Bind(&IgnoreAdapterResult));
 }
 
-void BluetoothEventRouter::OnListenerRemoved() {
-  if (num_event_listeners_ > 0)
-    num_event_listeners_--;
+void BluetoothEventRouter::OnListenerRemoved(const EventListenerInfo& details) {
+  DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
+  std::string id = GetListenerId(details);
+  auto iter = event_listener_count_.find(id);
+  if (iter == event_listener_count_.end())
+    return;  // Edge case if adapter wasn't ready when listener was added.

[Devlin, 2017/04/12 19:21:44]

If this can happen, doesn't that mean we could also be off-by-one somewhere?

[stevenjb, 2017/04/12 20:35:41]

We can theoretically (by code inspection) remove more than add but not vice
versa. I don't think it can happen in practice. Updated comment.

[Devlin, 2017/04/12 22:23:20]

So, my interpretation of your comment here is that the following is possible:

1. Listener added
2. Adapter initialized
3. Listener removed -> no listener entry

But, doesn't that mean we could also have:
1. Listener added
2. Adapter initialized
3. Listener 2 added
4. Listener removed -> we'll remove the entry in the map, despite the fact that
there's still an active listener.

Am I missing something?

[stevenjb, 2017/04/12 22:33:01]

1. Listener is *not* added because adapter is not intialized:
https://cs.chromium.org/chromium/src/extensions/browser/api/bluetooth/bluetoo...

[Devlin, 2017/04/12 23:01:26]

I should have been more clear.

1. Listener added through addListener(), notifies EventRouter, notifies
BluetoothAPI, checks adapter - adapter unitialized.

Net State:
1 listener in EventRouter
0 listeners in BluetoothEventRouter

2. Adapter initialized

Net State:
1 listener in EventRouter
0 listeners in BluetoothEventRouter

3. Listener 2 added through addListener(), notifies EventRouter, notifies
BluetoothAPI, adapter is initialized, so notifies BluetoothEventRouter.

Net State:
2 listeners in EventRouter
1 listener in BluetoothEventRouter

4. Listener removed through removeListener(), notifies EventRouter, notifies
BluetoothAPI, adapter is initialized, so notifies BluetoothEventRouter.  We'll
remove the entry in the map, despite the fact that there's still an active
listener in EventRouter.

Net State:
1 listener in EventRouter
0 listeners in BluetoothEventRouter

[stevenjb, 2017/04/12 23:12:28]

HUH????

"added through addListener()" - what addListener where?

Basically:

In this code:
https://cs.chromium.org/chromium/src/extensions/browser/api/bluetooth/bluetoo...

We may not call addListener for "Reasons" that I think never happen but, in
theory, could.

Therefore we could, in theory, call this method (OnListenerRemoved) without a
corresponding call to OnListenerAdded().

The opposite may or may not be true but I don't care about that - it won't cause
a crash, just another dangling ref counter and this code is so full of potential
for that I barely know where to begin.

I can put a CHECK here instead.

What would you like me to do, other than rewrite all of this code which I simply
do not have time for?

[Devlin, 2017/04/13 00:13:39]

addListener() == the JS addListener function, which is forwarded to the event
router.

Making this CHECK would solve my concerns. :)

[stevenjb, 2017/04/13 00:25:30]

Done.

+  int count = --(iter->second);
+  BLUETOOTH_LOG(EVENT) << "Event Listener Removed: " << id
+                       << " Count: " << count;
+  if (count <= 0) {

[Devlin, 2017/04/12 19:21:44]

< 0?  How?

[stevenjb, 2017/04/12 20:35:40]

Habit, changed to == 0.

+    event_listener_count_.erase(iter);
+    // When all listeners for a listener id have been removed, remove any
+    // pairing delegate or discovery session and filters.
+    CleanUpForExtension(id);
+  }
   MaybeReleaseAdapter();
 }
 
 void BluetoothEventRouter::DispatchAdapterStateEvent() {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   api::bluetooth::AdapterState state;
   CHECK(adapter_.get());
   PopulateAdapterState(*adapter_, &state);
 
   std::unique_ptr<base::ListValue> args =
@@ skipping 14 matching lines @@
 
   std::unique_ptr<base::ListValue> args =
       bluetooth::OnDeviceAdded::Create(extension_device);
   std::unique_ptr<Event> event(
       new Event(histogram_value, event_name, std::move(args)));
   EventRouter::Get(browser_context_)->BroadcastEvent(std::move(event));
 }
 
 void BluetoothEventRouter::CleanUpForExtension(
     const std::string& extension_id) {
+  BLUETOOTH_LOG(DEBUG) << "CleanUpForExtension: " << extension_id;
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   RemovePairingDelegate(extension_id);
 
   PreSetFilterMap::iterator pre_set_iter =
       pre_set_filter_map_.find(extension_id);
   if (pre_set_iter != pre_set_filter_map_.end()) {
     delete pre_set_iter->second;
     pre_set_filter_map_.erase(pre_set_iter);
   }
 
   // Remove any discovery session initiated by the extension.
   DiscoverySessionMap::iterator session_iter =
       discovery_session_map_.find(extension_id);
   if (session_iter == discovery_session_map_.end())
     return;
   delete session_iter->second;
   discovery_session_map_.erase(session_iter);
 }
 
 void BluetoothEventRouter::CleanUpAllExtensions() {
+  BLUETOOTH_LOG(DEBUG) << "CleanUpAllExtensions";
+
   for (auto& it : pre_set_filter_map_)
     delete it.second;
-
   pre_set_filter_map_.clear();
 
-  for (auto& it : discovery_session_map_)
+  for (auto& it : discovery_session_map_) {
+    BLUETOOTH_LOG(DEBUG) << "Clean up Discovery Session: " << it.first;
     delete it.second;
-
+  }
   discovery_session_map_.clear();
 
   PairingDelegateMap::iterator pairing_iter = pairing_delegate_map_.begin();
   while (pairing_iter != pairing_delegate_map_.end())
     RemovePairingDelegate(pairing_iter++->first);
 }
 
 void BluetoothEventRouter::OnStartDiscoverySession(
     const std::string& extension_id,
     const base::Closure& callback,
     std::unique_ptr<device::BluetoothDiscoverySession> discovery_session) {
+  BLUETOOTH_LOG(EVENT) << "OnStartDiscoverySession: " << extension_id;
   // Clean up any existing session instance for the extension.
   DiscoverySessionMap::iterator iter =
       discovery_session_map_.find(extension_id);
   if (iter != discovery_session_map_.end())
     delete iter->second;
   discovery_session_map_[extension_id] = discovery_session.release();
   callback.Run();
 }
 
 void BluetoothEventRouter::OnSetDiscoveryFilter(const std::string& extension_id,
                                                 const base::Closure& callback) {
-  DVLOG(1) << "Successfully set DiscoveryFilter.";
+  BLUETOOTH_LOG(DEBUG) << "Successfully set DiscoveryFilter.";
   callback.Run();
 }
 
 void BluetoothEventRouter::Observe(
     int type,
     const content::NotificationSource& source,
     const content::NotificationDetails& details) {
   DCHECK_CURRENTLY_ON(content::BrowserThread::UI);
   DCHECK_EQ(extensions::NOTIFICATION_EXTENSION_HOST_DESTROYED, type);
   ExtensionHost* host = content::Details<ExtensionHost>(details).ptr();
+  BLUETOOTH_LOG(DEBUG) << "Host Destroyed: " << host->extension_id();
   CleanUpForExtension(host->extension_id());
 }
 
 void BluetoothEventRouter::OnExtensionUnloaded(
     content::BrowserContext* browser_context,
     const Extension* extension,
     UnloadedExtensionInfo::Reason reason) {
   CleanUpForExtension(extension->id());
 }
 
 }  // namespace extensions