Log device/hid messages to chrome://device-log.

Log events and debugging information related to HID devices through the
device event log component so that these errors are visible at
chrome://device-log. A DEVICE_PLOG macro has been added which includes
the last reported system error in the log message.

BUG=448901

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

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

chrome/app/chromium_strings.grd

@@ -1353,6 +1353,9 @@ and incorrect credentials. Either an attacker is trying to pretend to be <ph nam
       <message name="IDS_DEVICE_LOG_TYPE_USB" desc="Checkbox to enable showing events of type USB">
         USB
       </message>
+      <message name="IDS_DEVICE_LOG_TYPE_HID" desc="Checkbox to enable showing events of type HID (Human Interface Device)">
+        HID
+      </message>
       <message name="IDS_DEVICE_LOG_FILEINFO" desc="File info checkbox in device event log">
         File Info
       </message>

chrome/browser/resources/device_log_ui/device_log_ui.html

@@ -49,6 +49,10 @@
       <input id="log-type-usb" type="checkbox">
       <span i18n-content="logTypeUsbText"></span>
     </label>
+    <label>
+      <input id="log-type-hid" type="checkbox">
+      <span i18n-content="logTypeHidText"></span>
+    </label>
     <label>
       <input id="log-fileinfo" type="checkbox">
       <span i18n-content="logLevelFileinfoText"></span>

chrome/browser/ui/webui/device_log_ui.cc

@@ -72,6 +72,7 @@ DeviceLogUI::DeviceLogUI(content::WebUI* web_ui)
   html->AddLocalizedString("logTypeNetworkText", IDS_DEVICE_LOG_TYPE_NETWORK);
   html->AddLocalizedString("logTypePowerText", IDS_DEVICE_LOG_TYPE_POWER);
   html->AddLocalizedString("logTypeUsbText", IDS_DEVICE_LOG_TYPE_USB);
+  html->AddLocalizedString("logTypeHidText", IDS_DEVICE_LOG_TYPE_HID);
 
   html->AddLocalizedString("logEntryFormat", IDS_DEVICE_LOG_ENTRY);
   html->SetJsonPath("strings.js");

components/device_event_log/device_event_log.cc

@@ -84,6 +84,19 @@ DeviceEventLogInstance::~DeviceEventLogInstance() {
   device_event_log::AddEntry(file_, line_, type_, level_, stream_.str());
 }
 
+DeviceEventSystemErrorLogInstance::DeviceEventSystemErrorLogInstance(
+    const char* file,
+    int line,
+    device_event_log::LogType type,
+    device_event_log::LogLevel level,
+    logging::SystemErrorCode err)
+    : err_(err), log_instance_(file, line, type, level) {
+}
+
+DeviceEventSystemErrorLogInstance::~DeviceEventSystemErrorLogInstance() {
+  stream() << ": " << ::logging::SystemErrorCodeToString(err_);
+}
+
 ScopedDeviceLogIfSlow::ScopedDeviceLogIfSlow(LogType type,
                                              const char* file,
                                              const std::string& name)

components/device_event_log/device_event_log.h

@@ -9,6 +9,7 @@
 #include <sstream>
 
 #include "base/basictypes.h"
+#include "base/logging.h"
 #include "base/timer/elapsed_timer.h"
 #include "components/device_event_log/device_event_log_export.h"
 
@@ -34,12 +35,22 @@
 #define USB_LOG(level)                         \
   DEVICE_LOG(::device_event_log::LOG_TYPE_USB, \
              ::device_event_log::LOG_LEVEL_##level)
+#define HID_LOG(level)                         \
+  DEVICE_LOG(::device_event_log::LOG_TYPE_HID, \
+             ::device_event_log::LOG_LEVEL_##level)
+#define HID_PLOG(level)                         \
+  DEVICE_PLOG(::device_event_log::LOG_TYPE_HID, \
+              ::device_event_log::LOG_LEVEL_##level)
 
-// Generally prefer the above macros unless |type| or  |level| is not constant.
+// Generally prefer the above macros unless |type| or |level| is not constant.
 
 #define DEVICE_LOG(type, level)                                            \
   ::device_event_log::internal::DeviceEventLogInstance(__FILE__, __LINE__, \
                                                        type, level).stream()
+#define DEVICE_PLOG(type, level)                                            \
+  ::device_event_log::internal::DeviceEventSystemErrorLogInstance(          \
+      __FILE__, __LINE__, type, level, ::logging::GetLastSystemErrorCode()) \
+      .stream()
 
 // Declare {Type_LOG_IF_SLOW() at the top of a method to log slow methods
 // where "slow" is defined by kSlowMethodThresholdMs in the .cc file.
@@ -66,6 +77,8 @@ enum LogType {
   LOG_TYPE_LOGIN,
   // USB device related events (i.e. device/usb).
   LOG_TYPE_USB,
+  // Human-interface device related events (i.e. device/hid).
+  LOG_TYPE_HID,
   // Used internally
   LOG_TYPE_UNKNOWN
 };
@@ -156,6 +169,30 @@ class DEVICE_EVENT_LOG_EXPORT DeviceEventLogInstance {
   DISALLOW_COPY_AND_ASSIGN(DeviceEventLogInstance);
 };
 
+// Implementation class for DEVICE_PLOG macros. Provides a stream for creating
+// a log string and adds the event, including system error code, using
+// device_event_log::AddEntry on destruction.
+class DEVICE_EVENT_LOG_EXPORT DeviceEventSystemErrorLogInstance {
+ public:
+  DeviceEventSystemErrorLogInstance(const char* file,
+                                    int line,
+                                    device_event_log::LogType type,
+                                    device_event_log::LogLevel level,
+                                    logging::SystemErrorCode err);
+  ~DeviceEventSystemErrorLogInstance();
+
+  std::ostream& stream() { return log_instance_.stream(); }
+
+ private:
+  logging::SystemErrorCode err_;
+  // Constructor parameters are passed to |log_instance_| which will update the
+  // log when it is destroyed (after a string description of |err_| is appended
+  // to the stream).
+  DeviceEventLogInstance log_instance_;
+
+  DISALLOW_COPY_AND_ASSIGN(DeviceEventSystemErrorLogInstance);
+};
+
 // Implementation class for SCOPED_LOG_IF_SLOW macros. Tests the elapsed time on
 // destruction and adds a Debug or Error log entry if it exceeds the
 // corresponding expected maximum elapsed time.

components/device_event_log/device_event_log_impl.cc

@@ -30,6 +30,7 @@ const char* kLogTypeNetworkDesc = "Network";
 const char* kLogTypePowerDesc = "Power";
 const char* kLogTypeLoginDesc = "Login";
 const char* kLogTypeUsbDesc = "USB";
+const char* kLogTypeHidDesc = "HID";
 
 std::string GetLogTypeString(LogType type) {
   switch (type) {
@@ -41,6 +42,8 @@ std::string GetLogTypeString(LogType type) {
       return kLogTypeLoginDesc;
     case LOG_TYPE_USB:
       return kLogTypeUsbDesc;
+    case LOG_TYPE_HID:
+      return kLogTypeHidDesc;
     default:
       NOTREACHED();
       return "Unknown";

device/hid/BUILD.gn

@@ -42,6 +42,7 @@ source_set("hid") {
 
   deps = [
     "//base",
+    "//components/device_event_log",
     "//device/core",
     "//net",
   ]

device/hid/hid.gyp

@@ -14,6 +14,8 @@
         '../..',
       ],
       'dependencies': [
+        '../../components/components.gyp:device_event_log_component',
+        '../../net/net.gyp:net',
         '../core/core.gyp:device_core',
       ],
       'sources': [

device/hid/hid_connection.cc

@@ -6,6 +6,8 @@
 
 #include <algorithm>
 
+#include "components/device_event_log/device_event_log.h"
+
 namespace device {
 
 namespace {
@@ -82,7 +84,7 @@ void HidConnection::Close() {
 void HidConnection::Read(const ReadCallback& callback) {
   DCHECK(thread_checker_.CalledOnValidThread());
   if (device_info_->max_input_report_size() == 0) {
-    VLOG(1) << "This device does not support input reports.";
+    HID_LOG(USER) << "This device does not support input reports.";
     callback.Run(false, NULL, 0);
     return;
   }
@@ -95,25 +97,25 @@ void HidConnection::Write(scoped_refptr<net::IOBuffer> buffer,
                           const WriteCallback& callback) {
   DCHECK(thread_checker_.CalledOnValidThread());
   if (device_info_->max_output_report_size() == 0) {
-    VLOG(1) << "This device does not support output reports.";
+    HID_LOG(USER) << "This device does not support output reports.";
     callback.Run(false);
     return;
   }
   if (size > device_info_->max_output_report_size() + 1) {
-    VLOG(1) << "Output report buffer too long (" << size << " > "
-            << (device_info_->max_output_report_size() + 1) << ").";
+    HID_LOG(USER) << "Output report buffer too long (" << size << " > "
+                  << (device_info_->max_output_report_size() + 1) << ").";
     callback.Run(false);
     return;
   }
   DCHECK_GE(size, 1u);
   uint8_t report_id = buffer->data()[0];
   if (device_info_->has_report_id() != (report_id != 0)) {
-    VLOG(1) << "Invalid output report ID.";
+    HID_LOG(USER) << "Invalid output report ID.";
     callback.Run(false);
     return;
   }
   if (IsReportIdProtected(report_id)) {
-    VLOG(1) << "Attempt to set a protected output report.";
+    HID_LOG(USER) << "Attempt to set a protected output report.";
     callback.Run(false);
     return;
   }
@@ -125,17 +127,17 @@ void HidConnection::GetFeatureReport(uint8_t report_id,
                                      const ReadCallback& callback) {
   DCHECK(thread_checker_.CalledOnValidThread());
   if (device_info_->max_feature_report_size() == 0) {
-    VLOG(1) << "This device does not support feature reports.";
+    HID_LOG(USER) << "This device does not support feature reports.";
     callback.Run(false, NULL, 0);
     return;
   }
   if (device_info_->has_report_id() != (report_id != 0)) {
-    VLOG(1) << "Invalid feature report ID.";
+    HID_LOG(USER) << "Invalid feature report ID.";
     callback.Run(false, NULL, 0);
     return;
   }
   if (IsReportIdProtected(report_id)) {
-    VLOG(1) << "Attempt to get a protected feature report.";
+    HID_LOG(USER) << "Attempt to get a protected feature report.";
     callback.Run(false, NULL, 0);
     return;
   }
@@ -148,19 +150,19 @@ void HidConnection::SendFeatureReport(scoped_refptr<net::IOBuffer> buffer,
                                       const WriteCallback& callback) {
   DCHECK(thread_checker_.CalledOnValidThread());
   if (device_info_->max_feature_report_size() == 0) {
-    VLOG(1) << "This device does not support feature reports.";
+    HID_LOG(USER) << "This device does not support feature reports.";
     callback.Run(false);
     return;
   }
   DCHECK_GE(size, 1u);
   uint8_t report_id = buffer->data()[0];
   if (device_info_->has_report_id() != (report_id != 0)) {
-    VLOG(1) << "Invalid feature report ID.";
+    HID_LOG(USER) << "Invalid feature report ID.";
     callback.Run(false);
     return;
   }
   if (IsReportIdProtected(report_id)) {
-    VLOG(1) << "Attempt to set a protected feature report.";
+    HID_LOG(USER) << "Attempt to set a protected feature report.";
     callback.Run(false);
     return;
   }
@@ -174,7 +176,7 @@ bool HidConnection::CompleteRead(scoped_refptr<net::IOBuffer> buffer,
   DCHECK_GE(size, 1u);
   uint8_t report_id = buffer->data()[0];
   if (IsReportIdProtected(report_id)) {
-    VLOG(1) << "Filtered a protected input report.";
+    HID_LOG(EVENT) << "Filtered a protected input report.";
     return false;
   }
 

device/hid/hid_connection_linux.cc

@@ -17,6 +17,7 @@
 #include "base/posix/eintr_wrapper.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/thread_restrictions.h"
+#include "components/device_event_log/device_event_log.h"
 #include "device/hid/hid_service.h"
 
 // These are already defined in newer versions of linux/hidraw.h.
@@ -57,7 +58,7 @@ class HidConnectionLinux::FileThreadHelper
     if (!base::MessageLoopForIO::current()->WatchFileDescriptor(
             platform_file_, true, base::MessageLoopForIO::WATCH_READ,
             &file_watcher_, this)) {
-      LOG(ERROR) << "Failed to start watching device file.";
+      HID_LOG(ERROR) << "Failed to start watching device file.";
     }
   }
 
@@ -80,7 +81,7 @@ class HidConnectionLinux::FileThreadHelper
     ssize_t bytes_read = HANDLE_EINTR(read(platform_file_, data, length));
     if (bytes_read < 0) {
       if (errno != EAGAIN) {
-        VPLOG(1) << "Read failed";
+        HID_PLOG(EVENT) << "Read failed";
         // This assumes that the error is unrecoverable and disables reading
         // from the device until it has been re-opened.
         // TODO(reillyg): Investigate starting and stopping the file descriptor
@@ -212,12 +213,12 @@ void HidConnectionLinux::FinishWrite(size_t expected_size,
                                      const WriteCallback& callback,
                                      ssize_t result) {
   if (result < 0) {
-    VPLOG(1) << "Write failed";
+    HID_PLOG(EVENT) << "Write failed";
     callback.Run(false);
   } else {
     if (static_cast<size_t>(result) != expected_size) {
-      LOG(WARNING) << "Incomplete HID write: " << result
-                   << " != " << expected_size;
+      HID_LOG(EVENT) << "Incomplete HID write: " << result
+                     << " != " << expected_size;
     }
     callback.Run(true);
   }
@@ -229,10 +230,10 @@ void HidConnectionLinux::FinishGetFeatureReport(
     const ReadCallback& callback,
     int result) {
   if (result < 0) {
-    VPLOG(1) << "Failed to get feature report";
+    HID_PLOG(EVENT) << "Failed to get feature report";
     callback.Run(false, NULL, 0);
   } else if (result == 0) {
-    VLOG(1) << "Get feature result too short.";
+    HID_LOG(EVENT) << "Get feature result too short.";
     callback.Run(false, NULL, 0);
   } else if (report_id == 0) {
     // Linux adds a 0 to the beginning of the data received from the device.
@@ -247,7 +248,7 @@ void HidConnectionLinux::FinishGetFeatureReport(
 void HidConnectionLinux::FinishSendFeatureReport(const WriteCallback& callback,
                                                  int result) {
   if (result < 0) {
-    VPLOG(1) << "Failed to send feature report";
+    HID_PLOG(EVENT) << "Failed to send feature report";
     callback.Run(false);
   } else {
     callback.Run(true);

device/hid/hid_connection_mac.cc

@@ -10,10 +10,19 @@
 #include "base/single_thread_task_runner.h"
 #include "base/strings/stringprintf.h"
 #include "base/thread_task_runner_handle.h"
+#include "components/device_event_log/device_event_log.h"
 #include "device/hid/hid_connection_mac.h"
 
 namespace device {
 
+namespace {
+
+std::string HexErrorCode(IOReturn error_code) {
+  return base::StringPrintf("0x%04x", error_code);
+}
+
+}  // namespace
+
 HidConnectionMac::HidConnectionMac(
     IOHIDDeviceRef device,
     scoped_refptr<HidDeviceInfo> device_info,
@@ -59,8 +68,7 @@ void HidConnectionMac::PlatformClose() {
       device_.get(), CFRunLoopGetMain(), kCFRunLoopDefaultMode);
   IOReturn result = IOHIDDeviceClose(device_.get(), 0);
   if (result != kIOReturnSuccess) {
-    VLOG(1) << "Failed to close HID device: "
-            << base::StringPrintf("0x%04x", result);
+    HID_LOG(EVENT) << "Failed to close HID device: " << HexErrorCode(result);
   }
 
   while (!pending_reads_.empty()) {
@@ -120,8 +128,7 @@ void HidConnectionMac::InputReportCallback(void* context,
                                            CFIndex report_length) {
   HidConnectionMac* connection = static_cast<HidConnectionMac*>(context);
   if (result != kIOReturnSuccess) {
-    VLOG(1) << "Failed to read input report: "
-            << base::StringPrintf("0x%08x", result);
+    HID_LOG(EVENT) << "Failed to read input report: " << HexErrorCode(result);
     return;
   }
 
@@ -186,8 +193,7 @@ void HidConnectionMac::GetFeatureReportAsync(uint8_t report_id,
                    this,
                    base::Bind(callback, true, buffer, report_size)));
   } else {
-    VLOG(1) << "Failed to get feature report: "
-            << base::StringPrintf("0x%08x", result);
+    HID_LOG(EVENT) << "Failed to get feature report: " << HexErrorCode(result);
     task_runner_->PostTask(FROM_HERE,
                            base::Bind(&HidConnectionMac::ReturnAsyncResult,
                                       this,
@@ -222,7 +228,7 @@ void HidConnectionMac::SetReportAsync(IOHIDReportType report_type,
                                       this,
                                       base::Bind(callback, true)));
   } else {
-    VLOG(1) << "Failed to set report: " << base::StringPrintf("0x%08x", result);
+    HID_LOG(EVENT) << "Failed to set report: " << HexErrorCode(result);
     task_runner_->PostTask(FROM_HERE,
                            base::Bind(&HidConnectionMac::ReturnAsyncResult,
                                       this,

device/hid/hid_connection_win.cc

@@ -12,6 +12,7 @@
 #include "base/numerics/safe_conversions.h"
 #include "base/profiler/scoped_tracker.h"
 #include "base/win/object_watcher.h"
+#include "components/device_event_log/device_event_log.h"
 
 #define INITGUID
 
@@ -83,7 +84,7 @@ void PendingHidTransfer::TakeResultFromWindowsAPI(BOOL result) {
     AddRef();
     watcher_.StartWatching(event_.Get(), this);
   } else {
-    VPLOG(1) << "HID transfer failed";
+    HID_PLOG(EVENT) << "HID transfer failed";
     callback_.Run(this, false);
   }
 }
@@ -216,7 +217,7 @@ void HidConnectionWin::OnReadComplete(scoped_refptr<net::IOBuffer> buffer,
           file_.Get(), transfer->GetOverlapped(), &bytes_transferred, FALSE)) {
     CompleteRead(buffer, bytes_transferred, callback);
   } else {
-    VPLOG(1) << "HID read failed";
+    HID_PLOG(EVENT) << "HID read failed";
     callback.Run(false, NULL, 0);
   }
 }
@@ -236,7 +237,7 @@ void HidConnectionWin::OnReadFeatureComplete(
           file_.Get(), transfer->GetOverlapped(), &bytes_transferred, FALSE)) {
     callback.Run(true, buffer, bytes_transferred);
   } else {
-    VPLOG(1) << "HID read failed";
+    HID_PLOG(EVENT) << "HID read failed";
     callback.Run(false, NULL, 0);
   }
 }
@@ -254,7 +255,7 @@ void HidConnectionWin::OnWriteComplete(const WriteCallback& callback,
           file_.Get(), transfer->GetOverlapped(), &bytes_transferred, FALSE)) {
     callback.Run(true);
   } else {
-    VPLOG(1) << "HID write failed";
+    HID_PLOG(EVENT) << "HID write failed";
     callback.Run(false);
   }
 }

device/hid/hid_service.cc

@@ -9,6 +9,7 @@
 #include "base/logging.h"
 #include "base/message_loop/message_loop.h"
 #include "base/stl_util.h"
+#include "components/device_event_log/device_event_log.h"
 
 #if defined(OS_LINUX) && defined(USE_UDEV)
 #include "device/hid/hid_service_linux.h"
@@ -103,6 +104,12 @@ void HidService::AddDevice(scoped_refptr<HidDeviceInfo> device_info) {
   if (!ContainsKey(devices_, device_info->device_id())) {
     devices_[device_info->device_id()] = device_info;
 
+    HID_LOG(USER) << "HID device "
+                  << (enumeration_ready_ ? "added" : "detected")
+                  << ": vendorId = " << device_info->vendor_id()
+                  << ", productId = " << device_info->product_id()
+                  << ", deviceId = '" << device_info->device_id() << "'";
+
     if (enumeration_ready_) {
       FOR_EACH_OBSERVER(Observer, observer_list_, OnDeviceAdded(device_info));
     }
@@ -113,6 +120,8 @@ void HidService::RemoveDevice(const HidDeviceId& device_id) {
   DCHECK(thread_checker_.CalledOnValidThread());
   DeviceMap::iterator it = devices_.find(device_id);
   if (it != devices_.end()) {
+    HID_LOG(USER) << "HID device removed: deviceId = '" << device_id << "'";
+
     if (enumeration_ready_) {
       FOR_EACH_OBSERVER(Observer, observer_list_, OnDeviceRemoved(it->second));
     }

device/hid/hid_service_linux.cc

@@ -13,12 +13,12 @@
 #include "base/files/file_path.h"
 #include "base/files/file_util.h"
 #include "base/location.h"
-#include "base/logging.h"
 #include "base/scoped_observer.h"
 #include "base/strings/string_number_conversions.h"
 #include "base/strings/string_split.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/thread_restrictions.h"
+#include "components/device_event_log/device_event_log.h"
 #include "device/hid/device_monitor_linux.h"
 #include "device/hid/hid_connection_linux.h"
 #include "device/hid/hid_device_info_linux.h"
@@ -282,29 +282,30 @@ void HidServiceLinux::OpenDevice(scoped_ptr<ConnectParams> params) {
     base::File::Error file_error = device_file.error_details();
 
     if (file_error == base::File::FILE_ERROR_ACCESS_DENIED) {
-      VLOG(1) << "Access denied opening device read-write, trying read-only.";
+      HID_LOG(EVENT)
+          << "Access denied opening device read-write, trying read-only.";
       flags = base::File::FLAG_OPEN | base::File::FLAG_READ;
       device_file.Initialize(device_path, flags);
     }
   }
   if (!device_file.IsValid()) {
-    LOG(ERROR) << "Failed to open '" << params->device_info->device_node()
-               << "': "
-               << base::File::ErrorToString(device_file.error_details());
+    HID_LOG(EVENT) << "Failed to open '" << params->device_info->device_node()
+                   << "': "
+                   << base::File::ErrorToString(device_file.error_details());
     task_runner->PostTask(FROM_HERE, base::Bind(params->callback, nullptr));
     return;
   }
 
   int result = fcntl(device_file.GetPlatformFile(), F_GETFL);
   if (result == -1) {
-    PLOG(ERROR) << "Failed to get flags from the device file descriptor";
+    HID_PLOG(ERROR) << "Failed to get flags from the device file descriptor";
     task_runner->PostTask(FROM_HERE, base::Bind(params->callback, nullptr));
     return;
   }
 
   result = fcntl(device_file.GetPlatformFile(), F_SETFL, result | O_NONBLOCK);
   if (result == -1) {
-    PLOG(ERROR) << "Failed to set the non-blocking flag on the device fd";
+    HID_PLOG(ERROR) << "Failed to set the non-blocking flag on the device fd";
     task_runner->PostTask(FROM_HERE, base::Bind(params->callback, nullptr));
     return;
   }

device/hid/hid_service_mac.cc

@@ -21,12 +21,17 @@
 #include "base/strings/sys_string_conversions.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/thread_restrictions.h"
+#include "components/device_event_log/device_event_log.h"
 #include "device/hid/hid_connection_mac.h"
 
 namespace device {
 
 namespace {
 
+std::string HexErrorCode(IOReturn error_code) {
+  return base::StringPrintf("0x%04x", error_code);
+}
+
 bool TryGetHidIntProperty(IOHIDDeviceRef device,
                           CFStringRef key,
                           int32_t* result) {
@@ -96,8 +101,8 @@ HidServiceMac::HidServiceMac(
                                        this,
                                        &iterator);
   if (result != kIOReturnSuccess) {
-    LOG(ERROR) << "Failed to listen for device arrival: "
-               << base::StringPrintf("0x%04x", result);
+    HID_LOG(ERROR) << "Failed to listen for device arrival: "
+                   << HexErrorCode(result);
     return;
   }
 
@@ -113,8 +118,8 @@ HidServiceMac::HidServiceMac(
                                             this,
                                             &iterator);
   if (result != kIOReturnSuccess) {
-    LOG(ERROR) << "Failed to listen for device removal: "
-               << base::StringPrintf("0x%04x", result);
+    HID_LOG(ERROR) << "Failed to listen for device removal: "
+                   << HexErrorCode(result);
     return;
   }
 
@@ -140,7 +145,7 @@ void HidServiceMac::Connect(const HidDeviceId& device_id,
   base::mac::ScopedIOObject<io_service_t> service(
       IORegistryEntryFromPath(kIOMasterPortDefault, service_path));
   if (!service.get()) {
-    VLOG(1) << "IOService not found for path: " << device_id;
+    HID_LOG(EVENT) << "IOService not found for path: " << device_id;
     task_runner_->PostTask(FROM_HERE, base::Bind(callback, nullptr));
     return;
   }
@@ -148,15 +153,14 @@ void HidServiceMac::Connect(const HidDeviceId& device_id,
   base::ScopedCFTypeRef<IOHIDDeviceRef> hid_device(
       IOHIDDeviceCreate(kCFAllocatorDefault, service));
   if (!hid_device) {
-    VLOG(1) << "Unable to create IOHIDDevice object.";
+    HID_LOG(EVENT) << "Unable to create IOHIDDevice object.";
     task_runner_->PostTask(FROM_HERE, base::Bind(callback, nullptr));
     return;
   }
 
   IOReturn result = IOHIDDeviceOpen(hid_device, kIOHIDOptionsTypeNone);
   if (result != kIOReturnSuccess) {
-    VLOG(1) << "Failed to open device: " << base::StringPrintf("0x%04x",
-                                                               result);
+    HID_LOG(EVENT) << "Failed to open device: " << HexErrorCode(result);
     task_runner_->PostTask(FROM_HERE, base::Bind(callback, nullptr));
     return;
   }
@@ -229,23 +233,23 @@ scoped_refptr<HidDeviceInfo> HidServiceMac::CreateDeviceInfo(
   IOReturn result =
       IORegistryEntryGetPath(service, kIOServicePlane, service_path);
   if (result != kIOReturnSuccess) {
-    VLOG(1) << "Failed to get IOService path: " << base::StringPrintf("0x%04x",
-                                                                      result);
+    HID_LOG(EVENT) << "Failed to get IOService path: " << HexErrorCode(result);
     return nullptr;
   }
 
   base::ScopedCFTypeRef<IOHIDDeviceRef> hid_device(
       IOHIDDeviceCreate(kCFAllocatorDefault, service));
   if (!hid_device) {
-    VLOG(1) << "Unable to create IOHIDDevice object for " << service_path
-            << ".";
+    HID_LOG(EVENT) << "Unable to create IOHIDDevice object for " << service_path
+                   << ".";
     return nullptr;
   }
 
   std::vector<uint8> report_descriptor;
   if (!TryGetHidDataProperty(hid_device, CFSTR(kIOHIDReportDescriptorKey),
                              &report_descriptor)) {
-    VLOG(1) << "Unable to get report descriptor for " << service_path << ".";
+    HID_LOG(EVENT) << "Unable to get report descriptor for " << service_path
+                   << ".";
     return nullptr;
   }
 

device/hid/hid_service_win.cc

@@ -18,6 +18,7 @@
 #include "base/strings/sys_string_conversions.h"
 #include "base/thread_task_runner_handle.h"
 #include "base/threading/thread_restrictions.h"
+#include "components/device_event_log/device_event_log.h"
 #include "device/hid/hid_connection_win.h"
 #include "device/hid/hid_device_info.h"
 #include "net/base/io_buffer.h"
@@ -64,7 +65,7 @@ void HidServiceWin::Connect(const HidDeviceId& device_id,
 
   base::win::ScopedHandle file(OpenDevice(device_info->device_id()));
   if (!file.IsValid()) {
-    PLOG(ERROR) << "Failed to open device";
+    HID_PLOG(EVENT) << "Failed to open device";
     task_runner_->PostTask(FROM_HERE, base::Bind(callback, nullptr));
     return;
   }
@@ -186,20 +187,20 @@ void HidServiceWin::AddDeviceOnFileThread(
   HIDD_ATTRIBUTES attrib = {0};
   attrib.Size = sizeof(HIDD_ATTRIBUTES);
   if (!HidD_GetAttributes(device_handle.Get(), &attrib)) {
-    VLOG(1) << "Failed to get device attributes.";
+    HID_LOG(EVENT) << "Failed to get device attributes.";
     return;
   }
 
   PHIDP_PREPARSED_DATA preparsed_data = nullptr;
   if (!HidD_GetPreparsedData(device_handle.Get(), &preparsed_data) ||
       !preparsed_data) {
-    VLOG(1) << "Failed to get device data.";
+    HID_LOG(EVENT) << "Failed to get device data.";
     return;
   }
 
   HIDP_CAPS capabilities = {0};
   if (HidP_GetCaps(preparsed_data, &capabilities) != HIDP_STATUS_SUCCESS) {
-    VLOG(1) << "Failed to get device capabilities.";
+    HID_LOG(EVENT) << "Failed to get device capabilities.";
     HidD_FreePreparsedData(preparsed_data);
     return;
   }