kernel: make logging struct-based

Replace the string-based logging callback with btck_LogEntry containing
full metadata (message, source location, timestamp, level, category).
This lets consumers format and filter logs as needed.

Use the global log dispatcher instead of BCLog::Logger's buffered
callback system. Messages are discarded when no callbacks are registered.

Author: stickies-v

src/bitcoin-chainstate.cpp

@@ -44,9 +44,12 @@ std::vector<std::byte> hex_string_to_byte_vec(std::string_view hex)
 class KernelLog
 {
 public:
-    void LogMessage(std::string_view message)
+    void LogMessage(const LogEntry& entry)
     {
-        std::cout << "kernel: " << message;
+        std::cout << "kernel: " << entry.Timestamp().time_since_epoch().count()
+                  << " [" << log_category_get_name(entry.Category()) << ":"
+                  << log_level_get_name(entry.Level()) << "] "
+                  << entry.Message() << "\n";
     }
 };
 

src/kernel/bitcoinkernel.cpp

@@ -32,7 +32,9 @@
 #include <util/fs.h>
 #include <util/result.h>
 #include <util/signalinterrupt.h>
+#include <util/string.h>
 #include <util/task_runner.h>
+#include <util/time.h>
 #include <util/translation.h>
 #include <validation.h>
 #include <validationinterface.h>
@@ -44,7 +46,6 @@
 #include <exception>
 #include <functional>
 #include <iterator>
-#include <list>
 #include <memory>
 #include <span>
 #include <stdexcept>
@@ -171,6 +172,14 @@ constexpr util::log::Level get_bclog_level(btck_LogLevel level)
     return LOG_LEVELS[level].bclog;
 }
 
+btck_LogLevel get_btck_level(util::log::Level level)
+{
+    for (size_t i = 0; i < LOG_LEVELS.size(); ++i) {
+        if (LOG_LEVELS[i].bclog == level) return static_cast<btck_LogLevel>(i);
+    }
+    assert(false);
+}
+
 struct LogCategoryMapping {
     BCLog::LogFlags bclog;
     std::string_view name;
@@ -200,6 +209,14 @@ constexpr BCLog::LogFlags get_bclog_flag(btck_LogCategory category)
     return LOG_CATEGORIES[category].bclog;
 }
 
+btck_LogCategory get_btck_category(BCLog::LogFlags flag)
+{
+    for (size_t i = 0; i < LOG_CATEGORIES.size(); ++i) {
+        if (LOG_CATEGORIES[i].bclog == flag) return static_cast<btck_LogCategory>(i);
+    }
+    assert(false);
+}
+
 btck_SynchronizationState cast_state(SynchronizationState state)
 {
     switch (state) {
@@ -225,47 +242,45 @@ btck_Warning cast_btck_warning(kernel::Warning warning)
 }
 
 struct LoggingConnection {
-    std::unique_ptr<std::list<std::function<void(const std::string&)>>::iterator> m_connection;
+    util::log::Dispatcher::CallbackHandle m_callback_handle;
     void* m_user_data;
     std::function<void(void* user_data)> m_deleter;
 
     LoggingConnection(btck_LogCallback callback, void* user_data, btck_DestroyCallback user_data_destroy_callback)
+        : m_user_data{user_data}, m_deleter{user_data_destroy_callback}
     {
-        LOCK(cs_main);
-
-        auto connection{LogInstance().PushBackCallback([callback, user_data](const std::string& str) { callback(user_data, str.c_str(), str.length()); })};
-
-        // Only start logging if we just added the connection.
-        if (LogInstance().NumConnections() == 1 && !LogInstance().StartLogging()) {
-            LogError("Logger start failed.");
-            LogInstance().DeleteCallback(connection);
-            if (user_data && user_data_destroy_callback) {
-                user_data_destroy_callback(user_data);
+        m_callback_handle = util::log::g_dispatcher().RegisterCallback([callback, user_data](const util::log::Entry& entry) {
+            const auto timestamp_ns{Ticks<std::chrono::nanoseconds>(entry.timestamp.time_since_epoch())};
+            std::string_view file_name{entry.source_loc.file_name()};
+            std::string_view function_name{entry.source_loc.function_name_short()};
+            // Some log statements are manually suffixed with a newline.
+            std::string_view message{util::RemoveSuffixView(entry.message, "\n")};
+
+            btck_LogEntry btck_entry{
+                .message = {message.data(), message.size()},
+                .file_name = {file_name.data(), file_name.size()},
+                .function_name = {function_name.data(), function_name.size()},
+                .thread_name = {entry.thread_name.data(), entry.thread_name.size()},
+                .timestamp_ns = timestamp_ns,
+                .line = entry.source_loc.line(),
+                .level = get_btck_level(entry.level),
+                .category = get_btck_category(static_cast<BCLog::LogFlags>(entry.category)),
+            };
+            try {
+                callback(user_data, &btck_entry);
+            } catch (const std::exception& e) {
+                LogError("Logging callback threw unexpected exception: %s", e.what());
             }
-            throw std::runtime_error("Failed to start logging");
-        }
-
-        m_connection = std::make_unique<std::list<std::function<void(const std::string&)>>::iterator>(connection);
-        m_user_data = user_data;
-        m_deleter = user_data_destroy_callback;
+        });
 
         LogDebug(BCLog::KERNEL, "Logger connected.");
     }
 
     ~LoggingConnection()
     {
-        LOCK(cs_main);
         LogDebug(BCLog::KERNEL, "Logger disconnecting.");
+        util::log::g_dispatcher().UnregisterCallback(m_callback_handle);
 
-        // Switch back to buffering by calling DisconnectTestLogger if the
-        // connection that we are about to remove is the last one.
-        if (LogInstance().NumConnections() == 1) {
-            LogInstance().DisconnectTestLogger();
-        } else {
-            LogInstance().DeleteCallback(*m_connection);
-        }
-
-        m_connection.reset();
         if (m_user_data && m_deleter) {
             m_deleter(m_user_data);
         }
@@ -773,6 +788,7 @@ void btck_logging_disable()
 
 btck_LoggingConnection* btck_logging_connection_create(btck_LogCallback callback, void* user_data, btck_DestroyCallback user_data_destroy_callback)
 {
+    assert(callback);
     try {
         return btck_LoggingConnection::create(callback, user_data, user_data_destroy_callback);
     } catch (const std::exception&) {

src/kernel/bitcoinkernel.h

@@ -133,12 +133,6 @@ typedef struct btck_TransactionOutput btck_TransactionOutput;
  * Opaque data structure for holding a logging connection.
  *
  * The logging connection can be used to manually stop logging.
- *
- * Messages that were logged before a connection is created are buffered in a
- * 1MB buffer. Logging can alternatively be permanently disabled by calling
- * @ref btck_logging_disable. Functions changing the logging settings are
- * global and change the settings for all existing btck_LoggingConnection
- * instances.
  */
 typedef struct btck_LoggingConnection btck_LoggingConnection;
 
@@ -370,8 +364,11 @@ typedef struct {
 /**
  * Function signature for the global logging callback. All bitcoin kernel
  * internal logs will pass through this callback.
+ *
+ * @param[in] user_data User-defined data passed to btck_logging_connection_create.
+ * @param[in] entry     Structured log entry. Valid only for the duration of the callback.
  */
-typedef void (*btck_LogCallback)(void* user_data, const char* message, size_t message_len);
+typedef void (*btck_LogCallback)(void* user_data, const btck_LogEntry* entry);
 
 /**
  * Function signature for freeing user data.
@@ -834,11 +831,12 @@ BITCOINKERNEL_API void btck_logging_enable_category(btck_LogCategory category);
 BITCOINKERNEL_API void btck_logging_disable_category(btck_LogCategory category);
 
 /**
- * @brief Start logging messages through the provided callback. Log messages
- * produced before this function is first called are buffered and on calling this
- * function are logged immediately.
+ * @brief Start logging messages through the provided callback.
+ *
+ * Messages are delivered as structured btck_LogEntry data, allowing the
+ * consumer to format and filter as needed.
  *
- * @param[in] log_callback               Non-null, function through which messages will be logged.
+ * @param[in] log_callback               Non-null, function through which log entries will be delivered.
  * @param[in] user_data                  Nullable, holds a user-defined opaque structure. Is passed back
  *                                       to the user through the callback. If the user_data_destroy_callback
  *                                       is also defined it is assumed that ownership of the user_data is passed

src/kernel/bitcoinkernel_wrapper.h

@@ -866,8 +866,8 @@ inline std::string_view log_category_get_name(LogCategory category)
 }
 
 template <typename T>
-concept Log = requires(T a, std::string_view message) {
-    { a.LogMessage(message) } -> std::same_as<void>;
+concept Log = requires(T a, const LogEntry& entry) {
+    { a.LogMessage(entry) } -> std::same_as<void>;
 };
 
 template <Log T>
@@ -876,7 +876,7 @@ class Logger : UniqueHandle<btck_LoggingConnection, btck_logging_connection_dest
 public:
     Logger(std::unique_ptr<T> log)
         : UniqueHandle{btck_logging_connection_create(
-              +[](void* user_data, const char* message, size_t message_len) { static_cast<T*>(user_data)->LogMessage({message, message_len}); },
+              +[](void* user_data, const btck_LogEntry* entry) { static_cast<T*>(user_data)->LogMessage(LogEntry{*entry}); },
               log.release(),
               +[](void* user_data) { delete static_cast<T*>(user_data); })}
     {

src/test/kernel/test_kernel.cpp

@@ -6,10 +6,10 @@
 #include <kernel/bitcoinkernel_wrapper.h>
 
 #define BOOST_TEST_MODULE Bitcoin Kernel Test Suite
-#include <boost/test/included/unit_test.hpp>
-
 #include <test/kernel/block_data.h>
 
+#include <boost/test/included/unit_test.hpp>
+
 #include <charconv>
 #include <cstdint>
 #include <cstdlib>
@@ -91,9 +91,13 @@ void check_equal(std::span<const std::byte> _actual, std::span<const std::byte>
 class TestLog
 {
 public:
-    void LogMessage(std::string_view message)
+    void LogMessage(const LogEntry& entry)
     {
-        std::cout << "kernel: " << message;
+        // TODO: stream Timestamp() directly once minimum gcc version is bumped to 13.1 (required for std::format support)
+        std::cout << "kernel: " << entry.Timestamp().time_since_epoch().count()
+                  << " [" << log_category_get_name(entry.Category()) << ":"
+                  << log_level_get_name(entry.Level()) << "] "
+                  << entry.Message() << "\n";
     }
 };