Add path open errors from the permission broker to the device log.

This change adds an additional ErrorCallback parameter to the permission
broker client so that the caller can get a better log message when its
request to open a device node fails.

This will hopefully help to determine the cause of the many "Did not get
valid device handle from permission broker" errors that some users are
seeing.

BUG=570784

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

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

6 files changed, 78 insertions, 27 deletions

diff --git a/device/hid/hid_service_linux.cc b/device/hid/hid_service_linux.cc
index 0829576..057d18c 100644
--- a/device/hid/hid_service_linux.cc
+++ b/device/hid/hid_service_linux.cc
@@ -241,9 +241,13 @@ void HidServiceLinux::Connect(const HidDeviceId& device_id,
   chromeos::PermissionBrokerClient* client =
       chromeos::DBusThreadManager::Get()->GetPermissionBrokerClient();
   DCHECK(client) << "Could not get permission broker client.";
+  chromeos::PermissionBrokerClient::ErrorCallback error_callback =
+      base::Bind(&HidServiceLinux::OnPathOpenError,
+                 params->device_info->device_node(), params->callback);
   client->OpenPath(
       device_info->device_node(),
-      base::Bind(&HidServiceLinux::OnPathOpened, base::Passed(&params)));
+      base::Bind(&HidServiceLinux::OnPathOpenComplete, base::Passed(&params)),
+      error_callback);
 #else
   file_task_runner_->PostTask(FROM_HERE,
                               base::Bind(&HidServiceLinux::OpenOnBlockingThread,
@@ -254,8 +258,8 @@ void HidServiceLinux::Connect(const HidDeviceId& device_id,
 #if defined(OS_CHROMEOS)
 
 // static
-void HidServiceLinux::OnPathOpened(scoped_ptr<ConnectParams> params,
-                                   dbus::FileDescriptor fd) {
+void HidServiceLinux::OnPathOpenComplete(scoped_ptr<ConnectParams> params,
+                                         dbus::FileDescriptor fd) {
   scoped_refptr<base::SingleThreadTaskRunner> file_task_runner =
       params->file_task_runner;
   file_task_runner->PostTask(
@@ -264,21 +268,24 @@ void HidServiceLinux::OnPathOpened(scoped_ptr<ConnectParams> params,
 }
 
 // static
+void HidServiceLinux::OnPathOpenError(const std::string& device_path,
+                                      const ConnectCallback& callback,
+                                      const std::string& error_name,
+                                      const std::string& error_message) {
+  HID_LOG(EVENT) << "Permission broker failed to open '" << device_path
+                 << "': " << error_name << ": " << error_message;
+  callback.Run(nullptr);
+}
+
+// static
 void HidServiceLinux::ValidateFdOnBlockingThread(
     scoped_ptr<ConnectParams> params,
     dbus::FileDescriptor fd) {
   base::ThreadRestrictions::AssertIOAllowed();
-
   fd.CheckValidity();
-  if (fd.is_valid()) {
-    params->device_file = base::File(fd.TakeValue());
-    FinishOpen(std::move(params));
-  } else {
-    HID_LOG(EVENT) << "Permission broker denied access to '"
-                   << params->device_info->device_node() << "'.";
-    params->task_runner->PostTask(FROM_HERE,
-                                  base::Bind(params->callback, nullptr));
-  }
+  DCHECK(fd.is_valid());
+  params->device_file = base::File(fd.TakeValue());
+  FinishOpen(std::move(params));
 }
 
 #else
diff --git a/device/hid/hid_service_linux.h b/device/hid/hid_service_linux.h
index 9f87504..7d92830 100644
--- a/device/hid/hid_service_linux.h
+++ b/device/hid/hid_service_linux.h
@@ -37,8 +37,12 @@ class HidServiceLinux : public HidService {
   // functions are static and the necessary parameters are passed as a single
   // struct.
 #if defined(OS_CHROMEOS)
-  static void OnPathOpened(scoped_ptr<ConnectParams> params,
-                           dbus::FileDescriptor fd);
+  static void OnPathOpenComplete(scoped_ptr<ConnectParams> params,
+                                 dbus::FileDescriptor fd);
+  static void OnPathOpenError(const std::string& device_path,
+                              const ConnectCallback& callback,
+                              const std::string& error_name,
+                              const std::string& error_message);
   static void ValidateFdOnBlockingThread(scoped_ptr<ConnectParams> params,
                                          dbus::FileDescriptor fd);
 #else
diff --git a/device/serial/serial_io_handler.cc b/device/serial/serial_io_handler.cc
index 35b41f7..a5257ed 100644
--- a/device/serial/serial_io_handler.cc
+++ b/device/serial/serial_io_handler.cc
@@ -54,12 +54,15 @@ void SerialIoHandler::Open(const std::string& port,
       chromeos::DBusThreadManager::Get()->GetPermissionBrokerClient();
   DCHECK(client) << "Could not get permission_broker client.";
   // PermissionBrokerClient should be called on the UI thread.
+  scoped_refptr<base::SingleThreadTaskRunner> task_runner =
+      base::ThreadTaskRunnerHandle::Get();
   ui_thread_task_runner_->PostTask(
-      FROM_HERE, base::Bind(&chromeos::PermissionBrokerClient::OpenPath,
-                            base::Unretained(client), port,
-                            base::Bind(&SerialIoHandler::OnPathOpened, this,
-                                       file_thread_task_runner_,
-                                       base::ThreadTaskRunnerHandle::Get())));
+      FROM_HERE,
+      base::Bind(
+          &chromeos::PermissionBrokerClient::OpenPath, base::Unretained(client),
+          port, base::Bind(&SerialIoHandler::OnPathOpened, this,
+                           file_thread_task_runner_, task_runner),
+          base::Bind(&SerialIoHandler::OnPathOpenError, this, task_runner)));
 #else
   file_thread_task_runner_->PostTask(
       FROM_HERE, base::Bind(&SerialIoHandler::StartOpen, this, port,
@@ -73,12 +76,20 @@ void SerialIoHandler::OnPathOpened(
     scoped_refptr<base::SingleThreadTaskRunner> file_thread_task_runner,
     scoped_refptr<base::SingleThreadTaskRunner> io_thread_task_runner,
     dbus::FileDescriptor fd) {
-  DCHECK(CalledOnValidThread());
   file_thread_task_runner->PostTask(
       FROM_HERE, base::Bind(&SerialIoHandler::ValidateOpenPort, this,
                             io_thread_task_runner, base::Passed(&fd)));
 }
 
+void SerialIoHandler::OnPathOpenError(
+    scoped_refptr<base::SingleThreadTaskRunner> io_thread_task_runner,
+    const std::string& error_name,
+    const std::string& error_message) {
+  io_thread_task_runner->PostTask(
+      FROM_HERE, base::Bind(&SerialIoHandler::ReportPathOpenError, this,
+                            error_name, error_message));
+}
+
 void SerialIoHandler::ValidateOpenPort(
     scoped_refptr<base::SingleThreadTaskRunner> io_thread_task_runner,
     dbus::FileDescriptor fd) {
@@ -93,6 +104,17 @@ void SerialIoHandler::ValidateOpenPort(
       base::Bind(&SerialIoHandler::FinishOpen, this, base::Passed(&file)));
 }
 
+void SerialIoHandler::ReportPathOpenError(const std::string& error_name,
+                                          const std::string& error_message) {
+  DCHECK(CalledOnValidThread());
+  DCHECK(!open_complete_.is_null());
+  LOG(ERROR) << "Permission broker failed to open '" << port_
+             << "': " << error_name << ": " << error_message;
+  OpenCompleteCallback callback = open_complete_;
+  open_complete_.Reset();
+  callback.Run(false);
+}
+
 #endif
 
 void SerialIoHandler::MergeConnectionOptions(
diff --git a/device/serial/serial_io_handler.h b/device/serial/serial_io_handler.h
index f494743..d1a4827 100644
--- a/device/serial/serial_io_handler.h
+++ b/device/serial/serial_io_handler.h
@@ -50,10 +50,20 @@ class SerialIoHandler : public base::NonThreadSafe,
       scoped_refptr<base::SingleThreadTaskRunner> io_thread_task_runner,
       dbus::FileDescriptor fd);
 
+  // Signals that the permission broker failed to open the port.
+  void OnPathOpenError(
+      scoped_refptr<base::SingleThreadTaskRunner> io_thread_task_runner,
+      const std::string& error_name,
+      const std::string& error_message);
+
   // Validates the file descriptor provided by the permission broker.
   void ValidateOpenPort(
       scoped_refptr<base::SingleThreadTaskRunner> io_thread_task_runner,
       dbus::FileDescriptor fd);
+
+  // Reports the open error from the permission broker.
+  void ReportPathOpenError(const std::string& error_name,
+                           const std::string& error_message);
 #endif  // defined(OS_CHROMEOS)
 
   // Performs an async Read operation. Behavior is undefined if this is called
diff --git a/device/usb/usb_device_impl.cc b/device/usb/usb_device_impl.cc
index 271b631..5280699 100644
--- a/device/usb/usb_device_impl.cc
+++ b/device/usb/usb_device_impl.cc
@@ -196,7 +196,8 @@ void UsbDeviceImpl::Open(const OpenCallback& callback) {
   DCHECK(client) << "Could not get permission broker client.";
   client->OpenPath(
       device_path_,
-      base::Bind(&UsbDeviceImpl::OnOpenRequestComplete, this, callback));
+      base::Bind(&UsbDeviceImpl::OnOpenRequestComplete, this, callback),
+      base::Bind(&UsbDeviceImpl::OnOpenRequestError, this, callback));
 #else
   blocking_task_runner_->PostTask(
       FROM_HERE,
@@ -291,14 +292,18 @@ void UsbDeviceImpl::OnOpenRequestComplete(const OpenCallback& callback,
                             base::Passed(&fd), callback));
 }
 
+void UsbDeviceImpl::OnOpenRequestError(const OpenCallback& callback,
+                                       const std::string& error_name,
+                                       const std::string& error_message) {
+  USB_LOG(EVENT) << "Permission broker failed to open the device: "
+                 << error_name << ": " << error_message;
+  callback.Run(nullptr);
+}
+
 void UsbDeviceImpl::OpenOnBlockingThreadWithFd(dbus::FileDescriptor fd,
                                                const OpenCallback& callback) {
   fd.CheckValidity();
-  if (!fd.is_valid()) {
-    USB_LOG(EVENT) << "Did not get valid device handle from permission broker.";
-    task_runner_->PostTask(FROM_HERE, base::Bind(callback, nullptr));
-    return;
-  }
+  DCHECK(fd.is_valid());
 
   PlatformUsbDeviceHandle handle;
   const int rv = libusb_open_fd(platform_device_, fd.TakeValue(), &handle);
diff --git a/device/usb/usb_device_impl.h b/device/usb/usb_device_impl.h
index e41dac0..40bfd1e 100644
--- a/device/usb/usb_device_impl.h
+++ b/device/usb/usb_device_impl.h
@@ -97,6 +97,9 @@ class UsbDeviceImpl : public UsbDevice {
 #if defined(OS_CHROMEOS)
   void OnOpenRequestComplete(const OpenCallback& callback,
                              dbus::FileDescriptor fd);
+  void OnOpenRequestError(const OpenCallback& callback,
+                          const std::string& error_name,
+                          const std::string& error_message);
   void OpenOnBlockingThreadWithFd(dbus::FileDescriptor fd,
                                   const OpenCallback& callback);
 #endif