serial: Add a section to chrome://device-log

This change adds a section to chrome://device-log for the Serial API.
Existing error messages are now directed here and the platform-specific
enumeration backends have been updated to generate log entries when
devices are added and removed, as is done for other device types.

Bug: 1107826
Change-Id: I694b42fe82b96c44257c979b8a2ea276b34f3124
Reviewed-on: https://chromium-review.googlesource.com/c/chromium/src/+/2436277
Commit-Queue: Reilly Grant <reillyg@chromium.org>
Reviewed-by: Steven Bennetts <stevenjb@chromium.org>
Reviewed-by: Matt Reynolds <mattreynolds@chromium.org>
Cr-Commit-Position: refs/heads/master@{#811531}

chrome/app/generated_resources.grd

@@ -9970,6 +9970,9 @@ Please help our engineers fix this problem. Tell us what happened right before y
       <message name="IDS_DEVICE_LOG_TYPE_FIDO" desc="Checkbox to enable showing events related to security keys, which is physical devices used by users to log in to websites. It's called FIDO in English because that's the name of the standards body that defines security keys">
         FIDO
       </message>
+      <message name="IDS_DEVICE_LOG_TYPE_SERIAL" desc="Checkbox to enable showing events related to serial devices">
+        Serial
+      </message>
       <message name="IDS_DEVICE_LOG_FILEINFO" desc="File info checkbox in device event log">
         File Info
       </message>

chrome/app/generated_resources_grd/IDS_DEVICE_LOG_TYPE_SERIAL.png.sha1

+f1fef308c235b0bdb31b61a2ecf0ed32a0b9be78
\ No newline at end of file

chrome/browser/resources/device_log_ui/device_log_ui.html

@@ -68,6 +68,10 @@
       <input id="log-type-fido" type="checkbox">
       <span>$i18n{logTypeFidoText}</span>
     </label>
+    <label>
+      <input id="log-type-serial" type="checkbox">
+      <span>$i18n{logTypeSerialText}</span>
+    </label>
   </div>
   <div id="log-container"></div>
 </body>

chrome/browser/ui/webui/device_log_ui.cc

@@ -89,6 +89,7 @@ DeviceLogUI::DeviceLogUI(content::WebUI* web_ui)
       {"logTypeHidText", IDS_DEVICE_LOG_TYPE_HID},
       {"logTypePrinterText", IDS_DEVICE_LOG_TYPE_PRINTER},
       {"logTypeFidoText", IDS_DEVICE_LOG_TYPE_FIDO},
+      {"logTypeSerialText", IDS_DEVICE_LOG_TYPE_SERIAL},
       {"logEntryFormat", IDS_DEVICE_LOG_ENTRY},
   };
   AddLocalizedStringsBulk(html, kStrings);

components/device_event_log/device_event_log.h

@@ -65,6 +65,12 @@
 #define PRINTER_LOG(level)                         \
   DEVICE_LOG(::device_event_log::LOG_TYPE_PRINTER, \
              ::device_event_log::LOG_LEVEL_##level)
+#define SERIAL_LOG(level)                         \
+  DEVICE_LOG(::device_event_log::LOG_TYPE_SERIAL, \
+             ::device_event_log::LOG_LEVEL_##level)
+#define SERIAL_PLOG(level)                         \
+  DEVICE_PLOG(::device_event_log::LOG_TYPE_SERIAL, \
+              ::device_event_log::LOG_LEVEL_##level)
 
 #if defined(OS_ANDROID) && defined(OFFICIAL_BUILD)
 // FIDO_LOG is discarded for release Android builds in order to reduce binary
@@ -121,8 +127,10 @@ enum LogType {
   LOG_TYPE_PRINTER = 7,
   // Security key events.
   LOG_TYPE_FIDO = 8,
+  // Serial port related events (i.e. services/device/serial).
+  LOG_TYPE_SERIAL = 9,
   // Used internally, must be the last type (may be changed).
-  LOG_TYPE_UNKNOWN = 9
+  LOG_TYPE_UNKNOWN = 10
 };
 
 // Used to specify the detail level for logging. In GetAsString, used to

components/device_event_log/device_event_log_impl.cc

@@ -37,6 +37,7 @@ const char* kLogTypeHidDesc = "HID";
 const char* kLogTypeMemoryDesc = "Memory";
 const char* kLogTypePrinterDesc = "Printer";
 const char* kLogTypeFidoDesc = "FIDO";
+const char* kLogTypeSerialDesc = "Serial";
 
 enum class ShowTime {
   kNone,
@@ -64,6 +65,8 @@ std::string GetLogTypeString(LogType type) {
       return kLogTypePrinterDesc;
     case LOG_TYPE_FIDO:
       return kLogTypeFidoDesc;
+    case LOG_TYPE_SERIAL:
+      return kLogTypeSerialDesc;
     case LOG_TYPE_UNKNOWN:
       break;
   }

services/device/serial/BUILD.gn

@@ -58,6 +58,7 @@ if (is_win || ((is_linux || is_chromeos) && use_udev) || is_mac) {
 
     deps = [
       "//base",
+      "//components/device_event_log",
       "//device/bluetooth:bluetooth",
       "//device/bluetooth/public/cpp",
       "//mojo/public/cpp/bindings",

services/device/serial/DEPS

 include_rules = [
   "+chromeos/dbus",
+  "+components/device_event_log",
   "+net/base",
   "+services/device/public/mojom",
   "+third_party/re2",

services/device/serial/serial_device_enumerator.cc

@@ -8,6 +8,7 @@
 
 #include "base/unguessable_token.h"
 #include "build/build_config.h"
+#include "components/device_event_log/device_event_log.h"
 
 #if defined(OS_LINUX) || defined(OS_CHROMEOS)
 #include "services/device/serial/serial_device_enumerator_linux.h"
@@ -91,6 +92,9 @@ void SerialDeviceEnumerator::RemovePort(base::UnguessableToken token) {
   auto it = ports_.find(token);
   DCHECK(it != ports_.end());
   mojom::SerialPortInfoPtr port = std::move(it->second);
+
+  SERIAL_LOG(EVENT) << "Serial device removed: path=" << port->path;
+
   ports_.erase(it);
 
   for (auto& observer : observer_list_)

services/device/serial/serial_device_enumerator_linux.cc

@@ -17,6 +17,7 @@
 #include "base/strings/string_util.h"
 #include "base/strings/stringprintf.h"
 #include "base/threading/scoped_blocking_call.h"
+#include "components/device_event_log/device_event_log.h"
 #include "device/udev_linux/udev.h"
 
 namespace device {
@@ -190,6 +191,11 @@ void SerialDeviceEnumeratorLinux::CreatePort(ScopedUdevDevicePtr device,
   if (serial_number)
     info->serial_number = serial_number;
 
+  SERIAL_LOG(EVENT) << "Serial device added: path=" << info->path
+                    << " vid=" << (vendor_id ? vendor_id : "(none)")
+                    << " pid=" << (product_id ? product_id : "(none)")
+                    << " serial=" << info->serial_number.value_or("(none)");
+
   paths_.insert(std::make_pair(syspath, token));
   AddPort(std::move(info));
 }

services/device/serial/serial_device_enumerator_mac.cc

@@ -27,6 +27,7 @@
 #include "base/strings/stringprintf.h"
 #include "base/strings/sys_string_conversions.h"
 #include "base/threading/scoped_blocking_call.h"
+#include "components/device_event_log/device_event_log.h"
 
 namespace device {
 
@@ -230,13 +231,15 @@ void SerialDeviceEnumeratorMac::AddDevices() {
     auto token = base::UnguessableToken::Create();
     info->token = token;
 
-    VLOG(1) << "Found serial device: dialin="
-            << dialin_device.value_or("(none)")
-            << " callout=" << callout_device.value_or("(none)")
-            << " vid=" << vendor_id_str.value_or("(none)")
-            << " pid=" << product_id_str.value_or("(none)")
-            << " usb_serial=" << info->serial_number.value_or("(none)")
-            << " usb_driver=" << info->usb_driver_name.value_or("(none)");
+    SERIAL_LOG(EVENT) << "Serial device added: dialin="
+                      << dialin_device.value_or("(none)")
+                      << " callout=" << callout_device.value_or("(none)")
+                      << " vid=" << vendor_id_str.value_or("(none)")
+                      << " pid=" << product_id_str.value_or("(none)")
+                      << " usb_serial="
+                      << info->serial_number.value_or("(none)")
+                      << " usb_driver="
+                      << info->usb_driver_name.value_or("(none)");
 
     entries_.insert({entry_id, token});
     AddPort(std::move(info));

services/device/serial/serial_device_enumerator_win.cc

@@ -31,6 +31,7 @@
 #include "base/threading/scoped_blocking_call.h"
 #include "base/win/registry.h"
 #include "base/win/scoped_devinfo.h"
+#include "components/device_event_log/device_event_log.h"
 #include "services/device/public/cpp/device_features.h"
 #include "third_party/re2/src/re2/re2.h"
 
@@ -317,10 +318,10 @@ void SerialDeviceEnumeratorWin::EnumeratePort(HDEVINFO dev_info,
     product_id_str = base::StringPrintf("%04X", product_id);
   }
 
-  VLOG(1) << "Found serial device: path=" << info->path
-          << " instance_id=" << info->device_instance_id
-          << " vid=" << vendor_id_str.value_or("(none)")
-          << " pid=" << product_id_str.value_or("(none)");
+  SERIAL_LOG(EVENT) << "Serial device added: path=" << info->path
+                    << " instance_id=" << info->device_instance_id
+                    << " vid=" << vendor_id_str.value_or("(none)")
+                    << " pid=" << product_id_str.value_or("(none)");
 
   paths_.insert(std::make_pair(*path, token));
   AddPort(std::move(info));

services/device/serial/serial_io_handler.cc

@@ -16,6 +16,7 @@
 #include "base/task/task_traits.h"
 #include "base/task/thread_pool.h"
 #include "build/build_config.h"
+#include "components/device_event_log/device_event_log.h"
 
 #if defined(OS_CHROMEOS)
 #include "chromeos/dbus/permission_broker/permission_broker_client.h"
@@ -98,8 +99,8 @@ void SerialIoHandler::ReportPathOpenError(const std::string& error_name,
                                           const std::string& error_message) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   DCHECK(open_complete_);
-  LOG(ERROR) << "Permission broker failed to open '" << port_
-             << "': " << error_name << ": " << error_message;
+  SERIAL_LOG(ERROR) << "Permission broker failed to open '" << port_
+                    << "': " << error_name << ": " << error_message;
   std::move(open_complete_).Run(false);
 }
 
@@ -143,8 +144,8 @@ void SerialIoHandler::FinishOpen(base::File file) {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   DCHECK(open_complete_);
   if (!file.IsValid()) {
-    LOG(ERROR) << "Failed to open serial port: "
-               << base::File::ErrorToString(file.error_details());
+    SERIAL_LOG(ERROR) << "Failed to open serial port: "
+                      << base::File::ErrorToString(file.error_details());
     std::move(open_complete_).Run(false);
     return;
   }

services/device/serial/serial_io_handler_posix.cc

@@ -14,6 +14,7 @@
 #include "base/files/file_util.h"
 #include "base/posix/eintr_wrapper.h"
 #include "build/build_config.h"
+#include "components/device_event_log/device_event_log.h"
 
 #if defined(OS_LINUX) || defined(OS_CHROMEOS)
 #include <asm-generic/ioctls.h>
@@ -171,7 +172,7 @@ bool SerialIoHandlerPosix::ConfigurePortImpl() {
   struct termios config;
   if (tcgetattr(file().GetPlatformFile(), &config) != 0) {
 #endif
-    VPLOG(1) << "Failed to get port configuration";
+    SERIAL_PLOG(DEBUG) << "Failed to get port configuration";
     return false;
   }
 
@@ -277,7 +278,7 @@ bool SerialIoHandlerPosix::ConfigurePortImpl() {
 #else
   if (tcsetattr(file().GetPlatformFile(), TCSANOW, &config) != 0) {
 #endif
-    VPLOG(1) << "Failed to set port attributes";
+    SERIAL_PLOG(DEBUG) << "Failed to set port attributes";
     return false;
   }
 
@@ -285,7 +286,7 @@ bool SerialIoHandlerPosix::ConfigurePortImpl() {
   if (need_iossiospeed) {
     speed_t bitrate = options().bitrate;
     if (ioctl(file().GetPlatformFile(), IOSSIOSPEED, &bitrate) == -1) {
-      VPLOG(1) << "Failed to set custom baud rate";
+      SERIAL_PLOG(DEBUG) << "Failed to set custom baud rate";
       return false;
     }
   }
@@ -330,7 +331,7 @@ void SerialIoHandlerPosix::AttemptRead(bool within_read) {
                          mojom::SerialReceiveError::DEVICE_LOST);
         StopWatchingFileRead();
       } else {
-        VPLOG(1) << "Read failed";
+        SERIAL_PLOG(DEBUG) << "Read failed";
         RunReadCompleted(within_read, 0,
                          mojom::SerialReceiveError::SYSTEM_ERROR);
       }
@@ -387,7 +388,7 @@ void SerialIoHandlerPosix::OnFileCanWriteWithoutBlocking() {
         WriteCompleted(0, mojom::SerialSendError::DISCONNECTED);
         StopWatchingFileWrite();
       } else {
-        VPLOG(1) << "Write failed";
+        SERIAL_PLOG(DEBUG) << "Write failed";
         WriteCompleted(0, mojom::SerialSendError::SYSTEM_ERROR);
       }
     } else {
@@ -458,19 +459,19 @@ void SerialIoHandlerPosix::Flush(mojom::SerialPortFlushMode mode) const {
   }
 
   if (tcflush(file().GetPlatformFile(), queue_selector) != 0)
-    VPLOG(1) << "Failed to flush port";
+    SERIAL_PLOG(DEBUG) << "Failed to flush port";
 }
 
 void SerialIoHandlerPosix::Drain() {
   if (tcdrain(file().GetPlatformFile()) != 0)
-    VPLOG(1) << "Failed to drain port";
+    SERIAL_PLOG(DEBUG) << "Failed to drain port";
 }
 
 mojom::SerialPortControlSignalsPtr SerialIoHandlerPosix::GetControlSignals()
     const {
   int status;
   if (ioctl(file().GetPlatformFile(), TIOCMGET, &status) == -1) {
-    VPLOG(1) << "Failed to get port control signals";
+    SERIAL_PLOG(DEBUG) << "Failed to get port control signals";
     return mojom::SerialPortControlSignalsPtr();
   }
 
@@ -505,24 +506,24 @@ bool SerialIoHandlerPosix::SetControlSignals(
   }
 
   if (set && ioctl(file().GetPlatformFile(), TIOCMBIS, &set) != 0) {
-    VPLOG(1) << "Failed to set port control signals";
+    SERIAL_PLOG(DEBUG) << "Failed to set port control signals";
     return false;
   }
 
   if (clear && ioctl(file().GetPlatformFile(), TIOCMBIC, &clear) != 0) {
-    VPLOG(1) << "Failed to clear port control signals";
+    SERIAL_PLOG(DEBUG) << "Failed to clear port control signals";
     return false;
   }
 
   if (signals.has_brk) {
     if (signals.brk) {
       if (ioctl(file().GetPlatformFile(), TIOCSBRK, 0) != 0) {
-        VPLOG(1) << "Failed to set break";
+        SERIAL_PLOG(DEBUG) << "Failed to set break";
         return false;
       }
     } else {
       if (ioctl(file().GetPlatformFile(), TIOCCBRK, 0) != 0) {
-        VPLOG(1) << "Failed to clear break";
+        SERIAL_PLOG(DEBUG) << "Failed to clear break";
         return false;
       }
     }
@@ -539,7 +540,7 @@ mojom::SerialConnectionInfoPtr SerialIoHandlerPosix::GetPortInfo() const {
   struct termios config;
   if (tcgetattr(file().GetPlatformFile(), &config) == -1) {
 #endif
-    VPLOG(1) << "Failed to get port info";
+    SERIAL_PLOG(DEBUG) << "Failed to get port info";
     return mojom::SerialConnectionInfoPtr();
   }
 

services/device/serial/serial_io_handler_win.cc

@@ -11,6 +11,7 @@
 #include "base/bind.h"
 #include "base/sequence_checker.h"
 #include "base/task/current_thread.h"
+#include "components/device_event_log/device_event_log.h"
 
 namespace device {
 
@@ -158,7 +159,7 @@ bool SerialIoHandlerWin::PostOpen() {
   COMMTIMEOUTS timeouts = {0};
   timeouts.ReadIntervalTimeout = 1;
   if (!::SetCommTimeouts(file().GetPlatformFile(), &timeouts)) {
-    VPLOG(1) << "Failed to set serial timeouts";
+    SERIAL_PLOG(DEBUG) << "Failed to set serial timeouts";
     return false;
   }
 
@@ -208,21 +209,21 @@ void SerialIoHandlerWin::CancelReadImpl() {
   DCHECK(file().IsValid());
 
   if (!PurgeComm(file().GetPlatformFile(), PURGE_RXABORT))
-    VPLOG(1) << "RX abort failed";
+    SERIAL_PLOG(DEBUG) << "RX abort failed";
 }
 
 void SerialIoHandlerWin::CancelWriteImpl() {
   DCHECK_CALLED_ON_VALID_SEQUENCE(sequence_checker_);
   DCHECK(file().IsValid());
   if (!PurgeComm(file().GetPlatformFile(), PURGE_TXABORT))
-    VPLOG(1) << "TX abort failed";
+    SERIAL_PLOG(DEBUG) << "TX abort failed";
 }
 
 bool SerialIoHandlerWin::ConfigurePortImpl() {
   DCB config = {0};
   config.DCBlength = sizeof(config);
   if (!GetCommState(file().GetPlatformFile(), &config)) {
-    VPLOG(1) << "Failed to get serial port info";
+    SERIAL_PLOG(DEBUG) << "Failed to get serial port info";
     return false;
   }
 
@@ -258,7 +259,7 @@ bool SerialIoHandlerWin::ConfigurePortImpl() {
   }
 
   if (!SetCommState(file().GetPlatformFile(), &config)) {
-    VPLOG(1) << "Failed to set serial port info";
+    SERIAL_PLOG(DEBUG) << "Failed to set serial port info";
     return false;
   }
   return true;
@@ -286,7 +287,8 @@ void SerialIoHandlerWin::OnIOCompleted(
                error == ERROR_DEVICE_REMOVED) {
       ReadCompleted(0, mojom::SerialReceiveError::DEVICE_LOST);
     } else {
-      VLOG(1) << "Read failed: " << logging::SystemErrorCodeToString(error);
+      SERIAL_LOG(DEBUG) << "Read failed: "
+                        << logging::SystemErrorCodeToString(error);
       ReadCompleted(0, mojom::SerialReceiveError::SYSTEM_ERROR);
     }
   } else if (context == write_context_.get()) {
@@ -298,7 +300,8 @@ void SerialIoHandlerWin::OnIOCompleted(
     } else if (error == ERROR_GEN_FAILURE) {
       WriteCompleted(0, mojom::SerialSendError::DISCONNECTED);
     } else {
-      VLOG(1) << "Write failed: " << logging::SystemErrorCodeToString(error);
+      SERIAL_LOG(DEBUG) << "Write failed: "
+                        << logging::SystemErrorCodeToString(error);
       WriteCompleted(0, mojom::SerialSendError::SYSTEM_ERROR);
       if (error == ERROR_GEN_FAILURE && IsReadPending()) {
         // For devices using drivers such as FTDI, CP2xxx, when device is
@@ -321,7 +324,7 @@ void SerialIoHandlerWin::OnIOCompleted(
 void SerialIoHandlerWin::ClearPendingError() {
   DWORD errors;
   if (!ClearCommError(file().GetPlatformFile(), &errors, nullptr)) {
-    VPLOG(1) << "Failed to clear communication error";
+    SERIAL_PLOG(DEBUG) << "Failed to clear communication error";
     return;
   }
 
@@ -357,19 +360,19 @@ void SerialIoHandlerWin::Flush(mojom::SerialPortFlushMode mode) const {
   }
 
   if (!PurgeComm(file().GetPlatformFile(), flags))
-    VPLOG(1) << "Failed to flush serial port";
+    SERIAL_PLOG(DEBUG) << "Failed to flush serial port";
 }
 
 void SerialIoHandlerWin::Drain() {
   if (!FlushFileBuffers(file().GetPlatformFile()))
-    VPLOG(1) << "Failed to drain serial port";
+    SERIAL_PLOG(DEBUG) << "Failed to drain serial port";
 }
 
 mojom::SerialPortControlSignalsPtr SerialIoHandlerWin::GetControlSignals()
     const {
   DWORD status;
   if (!GetCommModemStatus(file().GetPlatformFile(), &status)) {
-    VPLOG(1) << "Failed to get port control signals";
+    SERIAL_PLOG(DEBUG) << "Failed to get port control signals";
     return mojom::SerialPortControlSignalsPtr();
   }
 
@@ -385,18 +388,18 @@ bool SerialIoHandlerWin::SetControlSignals(
     const mojom::SerialHostControlSignals& signals) {
   if (signals.has_dtr && !EscapeCommFunction(file().GetPlatformFile(),
                                              signals.dtr ? SETDTR : CLRDTR)) {
-    VPLOG(1) << "Failed to configure DTR signal";
+    SERIAL_PLOG(DEBUG) << "Failed to configure data-terminal-ready signal";
     return false;
   }
   if (signals.has_rts && !EscapeCommFunction(file().GetPlatformFile(),
                                              signals.rts ? SETRTS : CLRRTS)) {
-    VPLOG(1) << "Failed to configure RTS signal";
+    SERIAL_PLOG(DEBUG) << "Failed to configure request-to-send signal";
     return false;
   }
   if (signals.has_brk &&
       !EscapeCommFunction(file().GetPlatformFile(),
                           signals.brk ? SETBREAK : CLRBREAK)) {
-    VPLOG(1) << "Failed to configure break signal";
+    SERIAL_PLOG(DEBUG) << "Failed to configure break signal";
     return false;
   }
 
@@ -407,7 +410,7 @@ mojom::SerialConnectionInfoPtr SerialIoHandlerWin::GetPortInfo() const {
   DCB config = {0};
   config.DCBlength = sizeof(config);
   if (!GetCommState(file().GetPlatformFile(), &config)) {
-    VPLOG(1) << "Failed to get serial port info";
+    SERIAL_PLOG(DEBUG) << "Failed to get serial port info";
     return mojom::SerialConnectionInfoPtr();
   }
   auto info = mojom::SerialConnectionInfo::New();