perf(gateway): read the log sink through a raw pointer

A log call took a std::shared_ptr copy of the sink through std::atomic_load,
which locks a mutex from a process-wide pool and changes the reference count,
and the call to enabled() did it a second time. The slot now holds a
std::atomic<Sink *> that the log path reads, and set_sink keeps every installed
sink alive until the process exits, so a thread that is logging never uses a
freed sink.

Sink::enabled and Sink::write take the logger name as const std::string &, so the
ROS sink passes c_str() to rcutils without building a string.

Author: bburda

src/ros2_medkit_gateway/include/ros2_medkit_gateway/core/logging.hpp

@@ -14,9 +14,12 @@
 
 #pragma once
 
+#include <atomic>
 #include <memory>
+#include <mutex>
 #include <string>
 #include <string_view>
+#include <vector>
 
 namespace ros2_medkit_gateway::log {
 
@@ -40,13 +43,14 @@ class Sink {
   Sink & operator=(Sink &&) = delete;
   virtual ~Sink() = default;
 
-  virtual bool enabled(std::string_view logger, Level level) const = 0;
-  virtual void write(std::string_view logger, Level level, std::string_view message, const Location & location) = 0;
+  virtual bool enabled(const std::string & logger, Level level) const = 0;
+  virtual void write(const std::string & logger, Level level, std::string_view message, const Location & location) = 0;
 };
 
 /// Replaces the active sink. Call it once at startup, before other threads log.
 /// A null sink restores the default sink, which writes "[LEVEL] [name]: message"
-/// to stderr for INFO and above.
+/// to stderr for INFO and above. Every installed sink stays alive until the process
+/// exits, because a thread that is logging may still use the sink it read before the call.
 void set_sink(std::shared_ptr<Sink> sink);
 
 /// A named log source. Cheap to copy.
@@ -65,7 +69,26 @@ class Logger {
 namespace detail {
 /// Process-wide sink slot. Default visibility, so a plugin that links this code
 /// binds to the executable's slot.
-__attribute__((visibility("default"))) std::shared_ptr<Sink> & sink_slot();
+struct SinkSlot {
+  SinkSlot();
+  SinkSlot(const SinkSlot &) = delete;
+  SinkSlot & operator=(const SinkSlot &) = delete;
+  SinkSlot(SinkSlot &&) = delete;
+  SinkSlot & operator=(SinkSlot &&) = delete;
+  ~SinkSlot() = default;
+
+  /// Makes @p sink the active sink and keeps it alive for the process.
+  void install(std::shared_ptr<Sink> sink);
+
+  /// The sink the log calls use. Never null.
+  std::atomic<Sink *> active{nullptr};
+
+ private:
+  std::mutex mutex_;
+  std::vector<std::shared_ptr<Sink>> installed_;
+};
+
+__attribute__((visibility("default"))) SinkSlot & sink_slot();
 
 void emit(const Logger & logger, Level level, const Location & location, const char * fmt, ...)
     __attribute__((format(printf, 4, 5)));

src/ros2_medkit_gateway/include/ros2_medkit_gateway/ros2/ros2_log_sink.hpp

@@ -25,8 +25,8 @@ namespace ros2_medkit_gateway {
 /// control (`--log-level <name>:=debug`) and `/rosout` behave as with rclcpp.
 class Ros2LogSink : public log::Sink {
  public:
-  bool enabled(std::string_view logger, log::Level level) const override;
-  void write(std::string_view logger, log::Level level, std::string_view message,
+  bool enabled(const std::string & logger, log::Level level) const override;
+  void write(const std::string & logger, log::Level level, std::string_view message,
              const log::Location & location) override;
 };
 

src/ros2_medkit_gateway/src/core/logging.cpp

@@ -14,7 +14,6 @@
 
 #include "ros2_medkit_gateway/core/logging.hpp"
 
-#include <atomic>
 #include <cstdarg>
 #include <cstdio>
 #include <utility>
@@ -42,17 +41,18 @@ const char * level_name(Level level) {
 
 class StderrSink : public Sink {
  public:
-  bool enabled(std::string_view /*logger*/, Level level) const override {
+  bool enabled(const std::string & /*logger*/, Level level) const override {
     return level >= Level::kInfo;
   }
-  void write(std::string_view logger, Level level, std::string_view message, const Location & /*location*/) override {
-    std::fprintf(stderr, "[%s] [%.*s]: %.*s\n", level_name(level), static_cast<int>(logger.size()), logger.data(),
-                 static_cast<int>(message.size()), message.data());
+  void write(const std::string & logger, Level level, std::string_view message,
+             const Location & /*location*/) override {
+    std::fprintf(stderr, "[%s] [%s]: %.*s\n", level_name(level), logger.c_str(), static_cast<int>(message.size()),
+                 message.data());
   }
 };
 
-std::shared_ptr<Sink> current_sink() {
-  return std::atomic_load(&detail::sink_slot());
+Sink & current_sink() {
+  return *detail::sink_slot().active.load(std::memory_order_acquire);
 }
 
 }  // namespace
@@ -61,20 +61,31 @@ void set_sink(std::shared_ptr<Sink> sink) {
   if (!sink) {
     sink = std::make_shared<StderrSink>();
   }
-  std::atomic_store(&detail::sink_slot(), std::move(sink));
+  detail::sink_slot().install(std::move(sink));
 }
 
 Logger::Logger(std::string name) : name_(std::move(name)) {
 }
 
 bool Logger::enabled(Level level) const {
-  return current_sink()->enabled(name_, level);
+  return current_sink().enabled(name_, level);
 }
 
 namespace detail {
 
-std::shared_ptr<Sink> & sink_slot() {
-  static std::shared_ptr<Sink> slot = std::make_shared<StderrSink>();
+SinkSlot::SinkSlot() {
+  install(std::make_shared<StderrSink>());
+}
+
+void SinkSlot::install(std::shared_ptr<Sink> sink) {
+  std::lock_guard<std::mutex> lock(mutex_);
+  Sink * raw = sink.get();
+  installed_.push_back(std::move(sink));
+  active.store(raw, std::memory_order_release);
+}
+
+SinkSlot & sink_slot() {
+  static SinkSlot slot;
   return slot;
 }
 
@@ -90,8 +101,8 @@ void emit(const Logger & logger, Level level, const Location & location, const c
     std::vsnprintf(buffer.data(), buffer.size(), fmt, args);
   }
   va_end(args);
-  current_sink()->write(logger.name(), level,
-                        std::string_view(buffer.data(), needed > 0 ? static_cast<size_t>(needed) : 0), location);
+  current_sink().write(logger.name(), level,
+                       std::string_view(buffer.data(), needed > 0 ? static_cast<size_t>(needed) : 0), location);
 }
 
 }  // namespace detail

src/ros2_medkit_gateway/src/ros2/ros2_log_sink.cpp

@@ -18,16 +18,16 @@
 
 namespace ros2_medkit_gateway {
 
-bool Ros2LogSink::enabled(std::string_view logger, log::Level level) const {
-  return rcutils_logging_logger_is_enabled_for(std::string(logger).c_str(), static_cast<int>(level));
+bool Ros2LogSink::enabled(const std::string & logger, log::Level level) const {
+  return rcutils_logging_logger_is_enabled_for(logger.c_str(), static_cast<int>(level));
 }
 
-void Ros2LogSink::write(std::string_view logger, log::Level level, std::string_view message,
+void Ros2LogSink::write(const std::string & logger, log::Level level, std::string_view message,
                         const log::Location & location) {
   const rcutils_log_location_t rcutils_location = {location.function, location.file,
                                                    static_cast<size_t>(location.line)};
-  rcutils_log(&rcutils_location, static_cast<int>(level), std::string(logger).c_str(), "%.*s",
-              static_cast<int>(message.size()), message.data());
+  rcutils_log(&rcutils_location, static_cast<int>(level), logger.c_str(), "%.*s", static_cast<int>(message.size()),
+              message.data());
 }
 
 }  // namespace ros2_medkit_gateway