vm_tools: sommelier: migrate almost all fprintf to log

This CL migrates all existing fprintf(stderr, ...) to the new LOG format. Some of the exit(EXIT_SUCCESS) have been updated to exit(EXIT_FAILURE) as well (since we print error message beforehand). BUG=b:328699937,b:331688838 TEST=N/A Change-Id: I0fd951ea864fb06096501b2d969298a665d160a8 Reviewed-on: https://chromium-review.googlesource.com/c/chromiumos/platform2/+/5465401 Reviewed-by: Chloe Pelling <[email protected]> Tested-by: Max Lee <[email protected]> Commit-Queue: Max Lee <[email protected]>
WhatAmISupposedToPutHere · Apr 23, 2024 · 8e72b5c · 8e72b5c
1 parent a2eba69
commit 8e72b5c
Show file tree

Hide file tree

Showing 14 changed files with 158 additions and 154 deletions.
diff --git a/compositor/sommelier-compositor.cc b/compositor/sommelier-compositor.cc
@@ -3,6 +3,7 @@
 // found in the LICENSE file.
 
 #include "../sommelier.h"            // NOLINT(build/include_directory)
+#include "../sommelier-logging.h"    // NOLINT(build/include_directory)
 #include "../sommelier-timing.h"     // NOLINT(build/include_directory)
 #include "../sommelier-tracing.h"    // NOLINT(build/include_directory)
 #include "../sommelier-transform.h"  // NOLINT(build/include_directory)
@@ -238,8 +239,7 @@ static void sl_host_surface_attach(struct wl_client* client,
 
         rv = host->ctx->channel->allocate(create_info, create_output);
         if (rv) {
-          fprintf(stderr, "error: virtwl dmabuf allocation failed: %s\n",
-                  strerror(-rv));
+          LOG(FATAL) << "virtwl dmabuf allocation failed: " << strerror(-rv);
           _exit(EXIT_FAILURE);
         }
 
@@ -332,14 +332,11 @@ static void sl_host_surface_attach(struct wl_client* client,
           // of guest side sync going forward.
           zwp_linux_surface_synchronization_v1_destroy(host->surface_sync);
           host->surface_sync = nullptr;
-          fprintf(stderr,
-                  "DMA_BUF_IOCTL_EXPORT_SYNC_FILE not implemented, defaulting "
-                  "to implicit fence for synchronization.\n");
+          LOG(INFO) << "DMA_BUF_IOCTL_EXPORT_SYNC_FILE not implemented, "
+                       "defaulting to implicit fence for synchronization";
         } else {
-          fprintf(stderr,
-                  "Explicit synchronization failed with reason: %s. "
-                  "Will retry on next attach.\n",
-                  strerror(ret));
+          LOG(WARNING) << "Explicit synchronization failed with reason: "
+                       << strerror(ret) << ", will retry on next attach";
         }
       } else {
         if (sl_dmabuf_sync_is_virtgpu(sync_file_fd)) {

diff --git a/compositor/sommelier-dmabuf-sync.cc b/compositor/sommelier-dmabuf-sync.cc
@@ -14,6 +14,7 @@
 #include <xf86drm.h>
 
 #include "../sommelier.h"          // NOLINT(build/include_directory)
+#include "../sommelier-logging.h"  // NOLINT(build/include_directory)
 #include "../sommelier-tracing.h"  // NOLINT(build/include_directory)
 #include "../virtualization/linux-headers/virtgpu_drm.h"  // NOLINT(build/include_directory)
 #include "sommelier-dmabuf-sync.h"  // NOLINT(build/include_directory)
@@ -90,8 +91,8 @@ void sl_dmabuf_sync_wait(int sync_file_fd) {
     struct sync_file_info sfi = {};
 
     ret = sl_ioctl(sync_file_fd, SYNC_IOC_FILE_INFO, &sfi);
-    fprintf(stderr, "Fence wait timeout. Possible GPU hang! fd:%d name:%s\n",
-            sync_file_fd, ret < 0 ? "<unknown>" : sfi.name);
+    LOG(WARNING) << "Fence wait timeout. Possible GPU hang! fd:" << sync_file_fd
+                 << " name:" << (ret < 0 ? "<unknown>" : sfi.name);
   }
 }
 

diff --git a/quirks/sommelier-quirks.cc b/quirks/sommelier-quirks.cc
@@ -11,8 +11,9 @@
 
 #include "quirks/quirks.pb.h"
 #include "quirks/sommelier-quirks.h"
-#include "sommelier-ctx.h"     // NOLINT(build/include_directory)
-#include "sommelier-window.h"  // NOLINT(build/include_directory)
+#include "sommelier-ctx.h"      // NOLINT(build/include_directory)
+#include "sommelier-logging.h"  // NOLINT(build/include_directory)
+#include "sommelier-window.h"   // NOLINT(build/include_directory)
 #include "xcb/xcb-shim.h"
 
 void Quirks::Load(std::string textproto) {
@@ -39,7 +40,7 @@ void Quirks::LoadFromFile(std::string path) {
   int fd = open(path.c_str(), O_RDONLY);
   if (fd < 0) {
     const char* e = strerror(errno);
-    fprintf(stderr, "Failed to open quirks config: %s: %s\n", path.c_str(), e);
+    LOG(ERROR) << "failed to open quirks config: " << path << ": " << e;
     return;
   }
   google::protobuf::io::FileInputStream f(fd);
@@ -52,7 +53,7 @@ void Quirks::LoadFromFile(std::string path) {
 void Quirks::PrintFeaturesEnabled(uint32_t steam_game_id) {
   // Very inefficient but straight-forward function to
   // print features enabled for the steam_game_id.
-  fprintf(stderr, "Enabled features for %d:\n", steam_game_id);
+  LOG(INFO) << "Enabled features for " << steam_game_id;
   for (int i = quirks::Feature_MIN; i <= quirks::Feature_MAX; i++) {
     if (!quirks::Feature_IsValid(i) || !IsEnabled(steam_game_id, i)) {
       continue;
@@ -92,10 +93,10 @@ bool Quirks::IsEnabled(struct sl_window* window, int feature) {
   bool is_enabled = IsEnabled(window->steam_game_id, feature);
 
   if (is_enabled && sl_window_should_log_quirk(window, feature)) {
-    fprintf(stderr,
-            "Quirk %s applied to window 0x%x due to rule `steam_game_id: %d`\n",
-            quirks::Feature_Name(feature).c_str(), window->id,
-            window->steam_game_id);
+    LOG(INFO) << "Quirk " << quirks::Feature_Name(feature) << " applied to "
+              << window
+              << " due to rule `steam_game_id: " << window->steam_game_id
+              << "`";
 
     // Also set a window property for additional debugging.
     // Create comma-separated list of quirks

diff --git a/sommelier-ctx.cc b/sommelier-ctx.cc
@@ -6,13 +6,15 @@
 
 #include <assert.h>
 #include <cerrno>
+#include <cstdlib>
 #include <string>
 #include <sys/socket.h>
 #include <unistd.h>
 #include <wayland-util.h>
 
 #include "aura-shell-client-protocol.h"  // NOLINT(build/include_directory)
 #include "sommelier.h"                   // NOLINT(build/include_directory)
+#include "sommelier-logging.h"           // NOLINT(build/include_directory)
 #include "sommelier-tracing.h"           // NOLINT(build/include_directory)
 
 // TODO(b/173147612): Use container_token rather than this name.
@@ -239,7 +241,7 @@ static int sl_handle_clipboard_event(int fd, uint32_t mask, void* data) {
 
   rv = ctx->channel->handle_pipe(fd, readable, hang_up);
   if (rv) {
-    fprintf(stderr, "reading pipe failed with %s\n", strerror(rv));
+    LOG(ERROR) << "reading pipe failed with " << strerror(rv);
     return 0;
   }
 
@@ -265,11 +267,9 @@ static int sl_handle_wayland_channel_event(int fd, uint32_t mask, void* data) {
   int rv;
 
   if (!(mask & WL_EVENT_READABLE)) {
-    fprintf(stderr,
-            "Got error or hangup on virtwl ctx fd"
-            " (mask %d), exiting\n",
-            mask);
-    exit(EXIT_SUCCESS);
+    LOG(FATAL) << "Got error or hangup on virtwl ctx fd (mask " << mask
+               << "), exiting";
+    exit(EXIT_FAILURE);
   }
 
   receive.channel_fd = fd;
@@ -339,11 +339,9 @@ static int sl_handle_virtwl_socket_event(int fd, uint32_t mask, void* data) {
   int rv;
 
   if (!(mask & WL_EVENT_READABLE)) {
-    fprintf(stderr,
-            "Got error or hangup on virtwl socket"
-            " (mask %d), exiting\n",
-            mask);
-    exit(EXIT_SUCCESS);
+    LOG(FATAL) << "Got error or hangup on virtwl socket (mask " << mask
+               << "), exiting";
+    exit(EXIT_FAILURE);
   }
 
   buffer_iov.iov_base = data_buffer;
@@ -398,8 +396,7 @@ bool sl_context_init_wayland_channel(struct sl_context* ctx,
   }
   int rv = ctx->channel->init();
   if (rv) {
-    fprintf(stderr, "error: could not initialize wayland channel: %s\n",
-            strerror(-rv));
+    LOG(ERROR) << "could not initialize wayland channel: " << strerror(-rv);
     return false;
   }
   if (!display) {
@@ -418,8 +415,7 @@ bool sl_context_init_wayland_channel(struct sl_context* ctx,
 
     rv = ctx->channel->create_context(ctx->wayland_channel_fd);
     if (rv) {
-      fprintf(stderr, "error: failed to create virtwl context: %s\n",
-              strerror(-rv));
+      LOG(ERROR) << "failed to create virtwl context: " << strerror(-rv);
       return false;
     }
 

diff --git a/sommelier-data-device-manager.cc b/sommelier-data-device-manager.cc
@@ -3,6 +3,7 @@
 // found in the LICENSE file.
 
 #include "sommelier.h"            // NOLINT(build/include_directory)
+#include "sommelier-logging.h"    // NOLINT(build/include_directory)
 #include "sommelier-transform.h"  // NOLINT(build/include_directory)
 
 #include <assert.h>
@@ -199,7 +200,7 @@ static void sl_data_offer_receive(struct wl_client* client,
   int pipe_fd, rv;
   rv = host->ctx->channel->create_pipe(pipe_fd);
   if (rv) {
-    fprintf(stderr, "error: failed to create virtwl pipe: %s\n", strerror(-rv));
+    LOG(ERROR) << "failed to create virtwl pipe: " << strerror(-rv);
     close(fd);
     return;
   }

diff --git a/sommelier-gaming.cc b/sommelier-gaming.cc
@@ -3,6 +3,7 @@
 // found in the LICENSE file.
 
 #include "sommelier.h"          // NOLINT(build/include_directory)
+#include "sommelier-logging.h"  // NOLINT(build/include_directory)
 #include "sommelier-tracing.h"  // NOLINT(build/include_directory)
 
 #include <assert.h>
@@ -68,11 +69,6 @@ struct std::hash<DeviceID> {
   }
 };
 
-struct InputMapping {
-  const char* id;
-  const std::unordered_map<uint32_t, uint32_t> mapping;
-};
-
 // Buttons being emulated by libevdev uinput.
 // Note: Do not enable BTN_TL2 or BTN_TR2, as they will significantly
 // change the Linux joydev interpretation of the triggers on ABS_Z/ABS_RZ.
@@ -437,13 +433,7 @@ static void sl_internal_gamepad_removed(void* data,
   zcr_gamepad_v2_destroy(gamepad);
 
   wl_list_remove(&host_gamepad->link);
-  fprintf(
-      stderr,
-      "info: Gamepad removed: name=%s, bus=%u, vendor_id=%x, product_id=%x, "
-      "version=%x, input_mapping=%s \n",
-      host_gamepad->name, host_gamepad->bus, host_gamepad->vendor_id,
-      host_gamepad->product_id, host_gamepad->version,
-      (host_gamepad->input_mapping) ? host_gamepad->input_mapping->id : "none");
+  LOG(INFO) << "Gamepad removed: " << host_gamepad;
   delete host_gamepad;
 }
 
@@ -558,8 +548,7 @@ static void sl_internal_gamepad_axis_added(void* data,
                                .flat = flat,
                                .resolution = resolution};
   if (host_gamepad->state != kStatePending) {
-    fprintf(stderr, "error: %s invoked in unexpected state %d\n", __func__,
-            host_gamepad->state);
+    LOG(ERROR) << "invoked in unexpected state " << host_gamepad->state;
     host_gamepad->state = kStateError;
     return;
   }
@@ -577,8 +566,7 @@ static void sl_internal_gamepad_activated(void* data,
   struct sl_host_gamepad* host_gamepad = (struct sl_host_gamepad*)data;
 
   if (host_gamepad->state != kStatePending) {
-    fprintf(stderr, "error: %s invoked in unexpected state %d\n", __func__,
-            host_gamepad->state);
+    LOG(ERROR) << "invoked in unexpected state " << host_gamepad->state;
     host_gamepad->state = kStateError;
     return;
   }
@@ -590,9 +578,8 @@ static void sl_internal_gamepad_activated(void* data,
     // TODO(kenalba): can we destroy and clean up the ev_dev now?
     host_gamepad->state = kStateActivated;
   } else {
-    fprintf(stderr,
-            "error: libevdev_uinput_create_from_device failed with error %d\n",
-            err);
+    LOG(ERROR) << "libevdev_uinput_create_from_device failed with error "
+               << err;
     host_gamepad->state = kStateError;
   }
 }
@@ -640,7 +627,7 @@ static void sl_internal_gaming_seat_gamepad_added_with_device_info(
   host_gamepad->input_mapping = nullptr;
 
   if (host_gamepad->ev_dev == nullptr) {
-    fprintf(stderr, "error: libevdev_new failed\n");
+    LOG(ERROR) << "libevdev_new failed";
     host_gamepad->state = kStateError;
     return;
   }
@@ -675,13 +662,7 @@ static void sl_internal_gaming_seat_gamepad_added_with_device_info(
   for (unsigned int i = 0; i < ARRAY_SIZE(kButtons); i++)
     Libevdev::Get()->enable_event_code(host_gamepad->ev_dev, EV_KEY,
                                        kButtons[i], nullptr);
-  fprintf(
-      stderr,
-      "info: Gamepad added: name=%s, bus=%u, vendor_id=%x, product_id=%x, "
-      "version=%x, input_mapping=%s \n",
-      host_gamepad->name, host_gamepad->bus, host_gamepad->vendor_id,
-      host_gamepad->product_id, host_gamepad->version,
-      (host_gamepad->input_mapping) ? host_gamepad->input_mapping->id : "none");
+  LOG(INFO) << "Gamepad added: " << host_gamepad;
 }
 
 // Note: not currently implemented by Exo.
@@ -690,8 +671,7 @@ static void sl_internal_gaming_seat_gamepad_added(
     struct zcr_gaming_seat_v2* gaming_seat,
     struct zcr_gamepad_v2* gamepad) {
   TRACE_EVENT("gaming", "sl_internal_gaming_seat_gamepad_added");
-  fprintf(stderr,
-          "error: sl_internal_gaming_seat_gamepad_added unimplemented\n");
+  LOG(ERROR) << "sl_internal_gaming_seat_gamepad_added unimplemented";
 }
 
 static const struct zcr_gaming_seat_v2_listener

diff --git a/sommelier-logging.h b/sommelier-logging.h
@@ -17,6 +17,7 @@
 #include <sstream>
 #include <string>
 
+#include "sommelier.h"         // NOLINT(build/include_directory)
 #include "sommelier-window.h"  // NOLINT(build/include_directory)
 
 // Build Sommelier with -Dlog_level=X to define LOG_LEVEL
@@ -75,6 +76,20 @@ class Log {
     return *this;
   }
 
+#ifdef GAMEPAD_SUPPORT
+  Log& operator<<(sl_host_gamepad* host_gamepad) {
+    *this << "(name=" << host_gamepad->name << ", bus=" << host_gamepad->bus
+          << ", vendor_id=" << std::hex << host_gamepad->vendor_id
+          << ", product_id=" << host_gamepad->product_id
+          << ", version=" << host_gamepad->version << std::dec
+          << ", input_mapping="
+          << (host_gamepad->input_mapping ? host_gamepad->input_mapping->id
+                                          : "none")
+          << ")";
+    return *this;
+  }
+#endif
+
   ~Log() {
     // Example expected usage:
     //   LOG(INFO) << "hello world ";

diff --git a/sommelier-scope-timer.cc b/sommelier-scope-timer.cc
@@ -2,6 +2,7 @@
 // Use of this source code is governed by a BSD-style license that can be
 // found in the LICENSE file.
 
+#include "sommelier-logging.h"      // NOLINT(build/include_directory)
 #include "sommelier-scope-timer.h"  // NOLINT(build/include_directory)
 
 #include <fstream>
@@ -26,6 +27,7 @@ ScopeTimer::~ScopeTimer() {
   int64_t end = timespec_to_ns(&end_time);
   int64_t start = timespec_to_ns(&start_time_);
   int64_t diff = end - start;
-  fprintf(stderr, "sommelier_scope_timer: %s: %f seconds\n", event_name_,
-          static_cast<float>(diff) / static_cast<float>(NSEC_PER_SEC));
+  LOG(INFO) << event_name_ << ": "
+            << static_cast<float>(diff) / static_cast<float>(NSEC_PER_SEC)
+            << " seconds";
 }
diff --git a/sommelier-tracing.cc b/sommelier-tracing.cc
@@ -6,6 +6,7 @@
 
 #include <assert.h>
 #include <fcntl.h>
+#include <cstring>
 #include <memory>
 #include <sstream>
 #include <string>
@@ -15,8 +16,9 @@
 #include <vector>
 #include <xcb/xproto.h>
 
-#include "sommelier.h"      // NOLINT(build/include_directory)
-#include "sommelier-ctx.h"  // NOLINT(build/include_directory)
+#include "sommelier.h"          // NOLINT(build/include_directory)
+#include "sommelier-ctx.h"      // NOLINT(build/include_directory)
+#include "sommelier-logging.h"  // NOLINT(build/include_directory)
 
 #if defined(_M_IA64) || defined(_M_IX86) || defined(__ia64__) ||      \
     defined(__i386__) || defined(__amd64__) || defined(__x86_64__) || \
@@ -74,8 +76,8 @@ void dump_trace(const char* trace_filename) {
   // Write the trace into a file.
   int fd = open(trace_filename, O_RDWR | O_CREAT | O_TRUNC, 0644);
   if (fd == -1) {
-    fprintf(stderr, "error: unable to open trace file %s: %s\n", trace_filename,
-            strerror(errno));
+    LOG(ERROR) << "unable to open trace file " << trace_filename << ": "
+               << strerror(errno);
     return;
   }
   size_t pos = 0;
@@ -85,8 +87,8 @@ void dump_trace(const char* trace_filename) {
       if (errno == EINTR || errno == EAGAIN) {
         continue;
       }
-      fprintf(stderr, "error: unable to write trace file %s: %s\n",
-              trace_filename, strerror(errno));
+      LOG(ERROR) << "unable to write trace file " << trace_filename << ": "
+                 << strerror(errno);
       close(fd);
       return;
     }