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}

5 files changed, 62 insertions, 23 deletions

diff --git a/chromeos/dbus/fake_permission_broker_client.cc b/chromeos/dbus/fake_permission_broker_client.cc
index 548173b..2abd285 100644
--- a/chromeos/dbus/fake_permission_broker_client.cc
+++ b/chromeos/dbus/fake_permission_broker_client.cc
@@ -12,6 +12,7 @@
 #include "base/location.h"
 #include "base/logging.h"
 #include "base/posix/eintr_wrapper.h"
+#include "base/strings/stringprintf.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/worker_pool.h"
 #include "dbus/file_descriptor.h"
@@ -20,6 +21,8 @@ namespace chromeos {
 
 namespace {
 
+const char kOpenFailedError[] = "open_failed";
+
 // So that real devices can be accessed by tests and "Chromium OS on Linux" this
 // function implements a simplified version of the method implemented by the
 // permission broker by opening the path specified and returning the resulting
@@ -27,15 +30,23 @@ namespace {
 void OpenPathAndValidate(
     const std::string& path,
     const PermissionBrokerClient::OpenPathCallback& callback,
+    const PermissionBrokerClient::ErrorCallback& error_callback,
     scoped_refptr<base::TaskRunner> task_runner) {
-  dbus::FileDescriptor dbus_fd;
   int fd = HANDLE_EINTR(open(path.c_str(), O_RDWR));
   if (fd < 0) {
-    PLOG(WARNING) << "Failed to open '" << path << "'";
-  } else {
-    dbus_fd.PutValue(fd);
-    dbus_fd.CheckValidity();
+    int error_code = logging::GetLastSystemErrorCode();
+    task_runner->PostTask(
+        FROM_HERE,
+        base::Bind(error_callback, kOpenFailedError,
+                   base::StringPrintf(
+                       "Failed to open '%s': %s", path.c_str(),
+                       logging::SystemErrorCodeToString(error_code).c_str())));
+    return;
   }
+
+  dbus::FileDescriptor dbus_fd;
+  dbus_fd.PutValue(fd);
+  dbus_fd.CheckValidity();
   task_runner->PostTask(FROM_HERE,
                         base::Bind(callback, base::Passed(&dbus_fd)));
 }
@@ -55,11 +66,13 @@ void FakePermissionBrokerClient::CheckPathAccess(
 }
 
 void FakePermissionBrokerClient::OpenPath(const std::string& path,
-                                          const OpenPathCallback& callback) {
-  base::WorkerPool::PostTask(FROM_HERE,
-                             base::Bind(&OpenPathAndValidate, path, callback,
-                                        base::ThreadTaskRunnerHandle::Get()),
-                             false);
+                                          const OpenPathCallback& callback,
+                                          const ErrorCallback& error_callback) {
+  base::WorkerPool::PostTask(
+      FROM_HERE,
+      base::Bind(&OpenPathAndValidate, path, callback, error_callback,
+                 base::ThreadTaskRunnerHandle::Get()),
+      false);
 }
 
 void FakePermissionBrokerClient::RequestTcpPortAccess(
diff --git a/chromeos/dbus/fake_permission_broker_client.h b/chromeos/dbus/fake_permission_broker_client.h
index ee46101..3ce9111 100644
--- a/chromeos/dbus/fake_permission_broker_client.h
+++ b/chromeos/dbus/fake_permission_broker_client.h
@@ -23,7 +23,8 @@ class CHROMEOS_EXPORT FakePermissionBrokerClient
   void CheckPathAccess(const std::string& path,
                        const ResultCallback& callback) override;
   void OpenPath(const std::string& path,
-                const OpenPathCallback& callback) override;
+                const OpenPathCallback& callback,
+                const ErrorCallback& error_callback) override;
   void RequestTcpPortAccess(uint16_t port,
                             const std::string& interface,
                             const dbus::FileDescriptor& lifeline_fd,
diff --git a/chromeos/dbus/mock_permission_broker_client.h b/chromeos/dbus/mock_permission_broker_client.h
index 4d97b06..acc3efa 100644
--- a/chromeos/dbus/mock_permission_broker_client.h
+++ b/chromeos/dbus/mock_permission_broker_client.h
@@ -24,8 +24,10 @@ class MockPermissionBrokerClient : public PermissionBrokerClient {
   MOCK_METHOD1(Init, void(dbus::Bus* bus));
   MOCK_METHOD2(CheckPathAccess,
                void(const std::string& path, const ResultCallback& callback));
-  MOCK_METHOD2(OpenPath,
-               void(const std::string& path, const OpenPathCallback& callback));
+  MOCK_METHOD3(OpenPath,
+               void(const std::string& path,
+                    const OpenPathCallback& callback,
+                    const ErrorCallback& error_callback));
   MOCK_METHOD4(RequestTcpPortAccess,
                void(uint16_t port,
                     const std::string& interface,
diff --git a/chromeos/dbus/permission_broker_client.cc b/chromeos/dbus/permission_broker_client.cc
index fb0c934..c56d801 100644
--- a/chromeos/dbus/permission_broker_client.cc
+++ b/chromeos/dbus/permission_broker_client.cc
@@ -27,6 +27,10 @@ using permission_broker::kRequestUdpPortAccess;
 
 namespace chromeos {
 
+namespace {
+const char kNoResponseError[] = "org.chromium.Error.NoResponse";
+}
+
 class PermissionBrokerClientImpl : public PermissionBrokerClient {
  public:
   PermissionBrokerClientImpl() : proxy_(NULL), weak_ptr_factory_(this) {}
@@ -42,14 +46,17 @@ class PermissionBrokerClientImpl : public PermissionBrokerClient {
   }
 
   void OpenPath(const std::string& path,
-                const OpenPathCallback& callback) override {
+                const OpenPathCallback& callback,
+                const ErrorCallback& error_callback) override {
     dbus::MethodCall method_call(kPermissionBrokerInterface, kOpenPath);
     dbus::MessageWriter writer(&method_call);
     writer.AppendString(path);
-    proxy_->CallMethod(
+    proxy_->CallMethodWithErrorCallback(
         &method_call, dbus::ObjectProxy::TIMEOUT_USE_DEFAULT,
         base::Bind(&PermissionBrokerClientImpl::OnOpenPathResponse,
-                   weak_ptr_factory_.GetWeakPtr(), callback));
+                   weak_ptr_factory_.GetWeakPtr(), callback),
+        base::Bind(&PermissionBrokerClientImpl::OnError,
+                   weak_ptr_factory_.GetWeakPtr(), error_callback));
   }
 
   void RequestTcpPortAccess(uint16_t port,
@@ -133,15 +140,23 @@ class PermissionBrokerClientImpl : public PermissionBrokerClient {
   void OnOpenPathResponse(const OpenPathCallback& callback,
                           dbus::Response* response) {
     dbus::FileDescriptor fd;
+    dbus::MessageReader reader(response);
+    if (!reader.PopFileDescriptor(&fd))
+      LOG(WARNING) << "Could not parse response: " << response->ToString();
+    callback.Run(std::move(fd));
+  }
+
+  void OnError(const ErrorCallback& callback, dbus::ErrorResponse* response) {
+    std::string error_name;
+    std::string error_message;
     if (response) {
       dbus::MessageReader reader(response);
-      if (!reader.PopFileDescriptor(&fd))
-        LOG(WARNING) << "Could not parse response: " << response->ToString();
+      error_name = response->GetErrorName();
+      reader.PopString(&error_message);
     } else {
-      LOG(WARNING) << "Access request method call failed.";
+      error_name = kNoResponseError;
     }
-
-    callback.Run(std::move(fd));
+    callback.Run(error_name, error_message);
   }
 
   dbus::ObjectProxy* proxy_;
diff --git a/chromeos/dbus/permission_broker_client.h b/chromeos/dbus/permission_broker_client.h
index 276bfba..f56bfcc 100644
--- a/chromeos/dbus/permission_broker_client.h
+++ b/chromeos/dbus/permission_broker_client.h
@@ -34,6 +34,12 @@ class CHROMEOS_EXPORT PermissionBrokerClient : public DBusClient {
   // An OpenPathCallback callback is run when an OpenPath request is completed.
   typedef base::Callback<void(dbus::FileDescriptor)> OpenPathCallback;
 
+  // An ErrorCallback callback is run when an error is returned by the
+  // permission broker.
+  typedef base::Callback<void(const std::string& error_name,
+                              const std::string& message)>
+      ErrorCallback;
+
   ~PermissionBrokerClient() override;
 
   static PermissionBrokerClient* Create();
@@ -46,9 +52,11 @@ class CHROMEOS_EXPORT PermissionBrokerClient : public DBusClient {
                                const ResultCallback& callback) = 0;
 
   // OpenPath requests that the permission broker open the device node
-  // identified by |path| and return the resulting file descriptor.
+  // identified by |path| and return the resulting file descriptor. One of
+  // |callback| or |error_callback| is called.
   virtual void OpenPath(const std::string& path,
-                        const OpenPathCallback& callback) = 0;
+                        const OpenPathCallback& callback,
+                        const ErrorCallback& error_callback) = 0;
 
   // Requests the |port| be opened on the firewall for incoming TCP/IP
   // connections received on |interface| (an empty string indicates all