From 28d679bad9fda3f180ab0f7d34353e1fa9294d68 Mon Sep 17 00:00:00 2001
From: TheCharlatan <seb.kung@gmail.com>
Date: Wed, 29 May 2024 16:13:45 +0200
Subject: [PATCH] kernel: Add logging to kernel library C header

Exposing logging in the kernel library allows users to follow
operations. Users of the C header can use
`kernel_logging_connection_create(...)` to pass a callback function to
Bitcoin Core's internal logger. Additionally the level and category can
be globally configured.

By default, the logger buffers messages until
`kernel_loggin_connection_create(...)` is called. If the user does not
want any logging messages, it is recommended that
`kernel_disable_logging()` is called, which permanently disables the
logging and any buffering of messages.

Co-authored-by: stringintech <stringintech@gmail.com>
---
 src/kernel/bitcoinkernel.cpp       | 160 +++++++++++++++++++++++++++++
 src/kernel/bitcoinkernel.h         | 147 ++++++++++++++++++++++++++
 src/kernel/bitcoinkernel_wrapper.h |  83 +++++++++++++++
 src/logging.cpp                    |   1 +
 src/logging.h                      |  12 +++
 src/test/kernel/test_kernel.cpp    |  37 +++++++
 6 files changed, 440 insertions(+)

diff --git a/src/kernel/bitcoinkernel.cpp b/src/kernel/bitcoinkernel.cpp
index 50608dc37c0..4aa2c176d88 100644
--- a/src/kernel/bitcoinkernel.cpp
+++ b/src/kernel/bitcoinkernel.cpp
@@ -8,17 +8,22 @@
 
 #include <consensus/amount.h>
 #include <kernel/context.h>
+#include <kernel/cs_main.h>
+#include <logging.h>
 #include <primitives/transaction.h>
 #include <script/interpreter.h>
 #include <script/script.h>
 #include <serialize.h>
 #include <streams.h>
+#include <tinyformat.h>
 #include <util/translation.h>
 
+#include <cassert>
 #include <cstddef>
 #include <cstring>
 #include <exception>
 #include <functional>
+#include <list>
 #include <span>
 #include <string>
 #include <utility>
@@ -103,11 +108,116 @@ struct Handle {
     }
 };
 
+BCLog::Level get_bclog_level(btck_LogLevel level)
+{
+    switch (level) {
+    case btck_LogLevel_INFO: {
+        return BCLog::Level::Info;
+    }
+    case btck_LogLevel_DEBUG: {
+        return BCLog::Level::Debug;
+    }
+    case btck_LogLevel_TRACE: {
+        return BCLog::Level::Trace;
+    }
+    }
+    assert(false);
+}
+
+BCLog::LogFlags get_bclog_flag(btck_LogCategory category)
+{
+    switch (category) {
+    case btck_LogCategory_BENCH: {
+        return BCLog::LogFlags::BENCH;
+    }
+    case btck_LogCategory_BLOCKSTORAGE: {
+        return BCLog::LogFlags::BLOCKSTORAGE;
+    }
+    case btck_LogCategory_COINDB: {
+        return BCLog::LogFlags::COINDB;
+    }
+    case btck_LogCategory_LEVELDB: {
+        return BCLog::LogFlags::LEVELDB;
+    }
+    case btck_LogCategory_MEMPOOL: {
+        return BCLog::LogFlags::MEMPOOL;
+    }
+    case btck_LogCategory_PRUNE: {
+        return BCLog::LogFlags::PRUNE;
+    }
+    case btck_LogCategory_RAND: {
+        return BCLog::LogFlags::RAND;
+    }
+    case btck_LogCategory_REINDEX: {
+        return BCLog::LogFlags::REINDEX;
+    }
+    case btck_LogCategory_VALIDATION: {
+        return BCLog::LogFlags::VALIDATION;
+    }
+    case btck_LogCategory_KERNEL: {
+        return BCLog::LogFlags::KERNEL;
+    }
+    case btck_LogCategory_ALL: {
+        return BCLog::LogFlags::ALL;
+    }
+    }
+    assert(false);
+}
+
+struct LoggingConnection {
+    std::unique_ptr<std::list<std::function<void(const std::string&)>>::iterator> m_connection;
+    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)
+    {
+        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);
+            }
+            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.");
+
+        // 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);
+        }
+    }
+};
+
 } // namespace
 
 struct btck_Transaction : Handle<btck_Transaction, std::shared_ptr<const CTransaction>> {};
 struct btck_TransactionOutput : Handle<btck_TransactionOutput, CTxOut> {};
 struct btck_ScriptPubkey : Handle<btck_ScriptPubkey, CScript> {};
+struct btck_LoggingConnection : Handle<btck_LoggingConnection, LoggingConnection> {};
 
 btck_Transaction* btck_transaction_create(const void* raw_transaction, size_t raw_transaction_len)
 {
@@ -253,3 +363,53 @@ int btck_script_pubkey_verify(const btck_ScriptPubkey* script_pubkey,
                                nullptr);
     return result ? 1 : 0;
 }
+
+
+void btck_logging_set_options(const btck_LoggingOptions options)
+{
+    LOCK(cs_main);
+    LogInstance().m_log_timestamps = options.log_timestamps;
+    LogInstance().m_log_time_micros = options.log_time_micros;
+    LogInstance().m_log_threadnames = options.log_threadnames;
+    LogInstance().m_log_sourcelocations = options.log_sourcelocations;
+    LogInstance().m_always_print_category_level = options.always_print_category_levels;
+}
+
+void btck_logging_set_level_category(btck_LogCategory category, btck_LogLevel level)
+{
+    LOCK(cs_main);
+    if (category == btck_LogCategory_ALL) {
+        LogInstance().SetLogLevel(get_bclog_level(level));
+    }
+
+    LogInstance().AddCategoryLogLevel(get_bclog_flag(category), get_bclog_level(level));
+}
+
+void btck_logging_enable_category(btck_LogCategory category)
+{
+    LogInstance().EnableCategory(get_bclog_flag(category));
+}
+
+void btck_logging_disable_category(btck_LogCategory category)
+{
+    LogInstance().DisableCategory(get_bclog_flag(category));
+}
+
+void btck_logging_disable()
+{
+    LogInstance().DisableLogging();
+}
+
+btck_LoggingConnection* btck_logging_connection_create(btck_LogCallback callback, void* user_data, btck_DestroyCallback user_data_destroy_callback)
+{
+    try {
+        return btck_LoggingConnection::create(callback, user_data, user_data_destroy_callback);
+    } catch (const std::exception&) {
+        return nullptr;
+    }
+}
+
+void btck_logging_connection_destroy(btck_LoggingConnection* connection)
+{
+    delete connection;
+}
diff --git a/src/kernel/bitcoinkernel.h b/src/kernel/bitcoinkernel.h
index bb16cd11842..1576b79edd3 100644
--- a/src/kernel/bitcoinkernel.h
+++ b/src/kernel/bitcoinkernel.h
@@ -99,6 +99,69 @@ typedef struct btck_ScriptPubkey btck_ScriptPubkey;
  */
 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;
+
+/** Callback function types */
+
+/**
+ * Function signature for the global logging callback. All bitcoin kernel
+ * internal logs will pass through this callback.
+ */
+typedef void (*btck_LogCallback)(void* user_data, const char* message, size_t message_len);
+
+/**
+ * Function signature for freeing user data.
+ */
+typedef void (*btck_DestroyCallback)(void* user_data);
+
+/**
+ * A collection of logging categories that may be encountered by kernel code.
+ */
+typedef uint8_t btck_LogCategory;
+#define btck_LogCategory_ALL ((btck_LogCategory)(0))
+#define btck_LogCategory_BENCH ((btck_LogCategory)(1))
+#define btck_LogCategory_BLOCKSTORAGE ((btck_LogCategory)(2))
+#define btck_LogCategory_COINDB ((btck_LogCategory)(3))
+#define btck_LogCategory_LEVELDB ((btck_LogCategory)(4))
+#define btck_LogCategory_MEMPOOL ((btck_LogCategory)(5))
+#define btck_LogCategory_PRUNE ((btck_LogCategory)(6))
+#define btck_LogCategory_RAND ((btck_LogCategory)(7))
+#define btck_LogCategory_REINDEX ((btck_LogCategory)(8))
+#define btck_LogCategory_VALIDATION ((btck_LogCategory)(9))
+#define btck_LogCategory_KERNEL ((btck_LogCategory)(10))
+
+/**
+ * The level at which logs should be produced.
+ */
+typedef uint8_t btck_LogLevel;
+#define btck_LogLevel_TRACE ((btck_LogLevel)(0))
+#define btck_LogLevel_DEBUG ((btck_LogLevel)(1))
+#define btck_LogLevel_INFO ((btck_LogLevel)(2))
+
+/**
+ * Options controlling the format of log messages.
+ *
+ * Set fields as non-zero to indicate true.
+ */
+typedef struct {
+    int log_timestamps;               //!< Prepend a timestamp to log messages.
+    int log_time_micros;              //!< Log timestamps in microsecond precision.
+    int log_threadnames;              //!< Prepend the name of the thread to log messages.
+    int log_sourcelocations;          //!< Prepend the source location to log messages.
+    int always_print_category_levels; //!< Prepend the log category and level to log messages.
+} btck_LoggingOptions;
+
 /**
  * A collection of status codes that may be issued by the script verify function.
  */
@@ -333,6 +396,90 @@ BITCOINKERNEL_API void btck_transaction_output_destroy(btck_TransactionOutput* t
 
 ///@}
 
+/** @name Logging
+ * Logging-related functions.
+ */
+///@{
+
+/**
+ * @brief This disables the global internal logger. No log messages will be
+ * buffered internally anymore once this is called and the buffer is cleared.
+ * This function should only be called once and is not thread or re-entry safe.
+ * Log messages will be buffered until this function is called, or a logging
+ * connection is created. This must not be called while a logging connection
+ * already exists.
+ */
+BITCOINKERNEL_API void btck_logging_disable();
+
+/**
+ * @brief Set some options for the global internal logger. This changes global
+ * settings and will override settings for all existing @ref
+ * btck_LoggingConnection instances.
+ *
+ * @param[in] options Sets formatting options of the log messages.
+ */
+BITCOINKERNEL_API void btck_logging_set_options(const btck_LoggingOptions options);
+
+/**
+ * @brief Set the log level of the global internal logger. This does not
+ * enable the selected categories. Use @ref btck_logging_enable_category to
+ * start logging from a specific, or all categories. This changes a global
+ * setting and will override settings for all existing
+ * @ref btck_LoggingConnection instances.
+ *
+ * @param[in] category If btck_LogCategory_ALL is chosen, sets both the global fallback log level
+ *                     used by all categories that don't have a specific level set, and also
+ *                     sets the log level for messages logged with the btck_LogCategory_ALL category itself.
+ *                     For any other category, sets a category-specific log level that overrides
+ *                     the global fallback for that category only.
+
+ * @param[in] level    Log level at which the log category is set.
+ */
+BITCOINKERNEL_API void btck_logging_set_level_category(btck_LogCategory category, btck_LogLevel level);
+
+/**
+ * @brief Enable a specific log category for the global internal logger. This
+ * changes a global setting and will override settings for all existing @ref
+ * btck_LoggingConnection instances.
+ *
+ * @param[in] category If btck_LogCategory_ALL is chosen, all categories will be enabled.
+ */
+BITCOINKERNEL_API void btck_logging_enable_category(btck_LogCategory category);
+
+/**
+ * @brief Disable a specific log category for the global internal logger. This
+ * changes a global setting and will override settings for all existing @ref
+ * btck_LoggingConnection instances.
+ *
+ * @param[in] category If btck_LogCategory_ALL is chosen, all categories will be disabled.
+ */
+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.
+ *
+ * @param[in] log_callback               Non-null, function through which messages will be logged.
+ * @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
+ *                                       to the created logging connection.
+ * @param[in] user_data_destroy_callback Nullable, function for freeing the user data.
+ * @return                               A new kernel logging connection, or null on error.
+ */
+BITCOINKERNEL_API btck_LoggingConnection* BITCOINKERNEL_WARN_UNUSED_RESULT btck_logging_connection_create(
+    btck_LogCallback log_callback,
+    void* user_data,
+    btck_DestroyCallback user_data_destroy_callback) BITCOINKERNEL_ARG_NONNULL(1);
+
+/**
+ * Stop logging and destroy the logging connection.
+ */
+BITCOINKERNEL_API void btck_logging_connection_destroy(btck_LoggingConnection* logging_connection);
+
+///@}
+
 #ifdef __cplusplus
 } // extern "C"
 #endif // __cplusplus
diff --git a/src/kernel/bitcoinkernel_wrapper.h b/src/kernel/bitcoinkernel_wrapper.h
index d50dee38bc4..c828e9b3e79 100644
--- a/src/kernel/bitcoinkernel_wrapper.h
+++ b/src/kernel/bitcoinkernel_wrapper.h
@@ -11,12 +11,33 @@
 #include <memory>
 #include <span>
 #include <stdexcept>
+#include <string_view>
 #include <type_traits>
 #include <utility>
 #include <vector>
 
 namespace btck {
 
+enum class LogCategory : btck_LogCategory {
+    ALL = btck_LogCategory_ALL,
+    BENCH = btck_LogCategory_BENCH,
+    BLOCKSTORAGE = btck_LogCategory_BLOCKSTORAGE,
+    COINDB = btck_LogCategory_COINDB,
+    LEVELDB = btck_LogCategory_LEVELDB,
+    MEMPOOL = btck_LogCategory_MEMPOOL,
+    PRUNE = btck_LogCategory_PRUNE,
+    RAND = btck_LogCategory_RAND,
+    REINDEX = btck_LogCategory_REINDEX,
+    VALIDATION = btck_LogCategory_VALIDATION,
+    KERNEL = btck_LogCategory_KERNEL
+};
+
+enum class LogLevel : btck_LogLevel {
+    TRACE_LEVEL = btck_LogLevel_TRACE,
+    DEBUG_LEVEL = btck_LogLevel_DEBUG,
+    INFO_LEVEL = btck_LogLevel_INFO
+};
+
 enum class ScriptVerifyStatus : btck_ScriptVerifyStatus {
     OK = btck_ScriptVerifyStatus_OK,
     ERROR_INVALID_FLAGS_COMBINATION = btck_ScriptVerifyStatus_ERROR_INVALID_FLAGS_COMBINATION,
@@ -286,6 +307,25 @@ public:
     const CType* get() const { return m_ptr; }
 };
 
+template <typename CType, void (*DestroyFunc)(CType*)>
+class UniqueHandle
+{
+protected:
+    struct Deleter {
+        void operator()(CType* ptr) const noexcept
+        {
+            if (ptr) DestroyFunc(ptr);
+        }
+    };
+    std::unique_ptr<CType, Deleter> m_ptr;
+
+public:
+    explicit UniqueHandle(CType* ptr) : m_ptr{check(ptr)} {}
+
+    CType* get() { return m_ptr.get(); }
+    const CType* get() const { return m_ptr.get(); }
+};
+
 class Transaction;
 class TransactionOutput;
 
@@ -440,6 +480,49 @@ bool ScriptPubkeyApi<Derived>::Verify(int64_t amount,
     return result == 1;
 }
 
+inline void logging_disable()
+{
+    btck_logging_disable();
+}
+
+inline void logging_set_options(const btck_LoggingOptions& logging_options)
+{
+    btck_logging_set_options(logging_options);
+}
+
+inline void logging_set_level_category(LogCategory category, LogLevel level)
+{
+    btck_logging_set_level_category(static_cast<btck_LogCategory>(category), static_cast<btck_LogLevel>(level));
+}
+
+inline void logging_enable_category(LogCategory category)
+{
+    btck_logging_enable_category(static_cast<btck_LogCategory>(category));
+}
+
+inline void logging_disable_category(LogCategory category)
+{
+    btck_logging_disable_category(static_cast<btck_LogCategory>(category));
+}
+
+template <typename T>
+concept Log = requires(T a, std::string_view message) {
+    { a.LogMessage(message) } -> std::same_as<void>;
+};
+
+template <Log T>
+class Logger : UniqueHandle<btck_LoggingConnection, btck_logging_connection_destroy>
+{
+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}); },
+              log.release(),
+              +[](void* user_data) { delete static_cast<T*>(user_data); })}
+    {
+    }
+};
+
 } // namespace btck
 
 #endif // BITCOIN_KERNEL_BITCOINKERNEL_WRAPPER_H
diff --git a/src/logging.cpp b/src/logging.cpp
index 2ed6835197b..f9d8f980488 100644
--- a/src/logging.cpp
+++ b/src/logging.cpp
@@ -201,6 +201,7 @@ static const std::map<std::string, BCLog::LogFlags, std::less<>> LOG_CATEGORIES_
     {"txreconciliation", BCLog::TXRECONCILIATION},
     {"scan", BCLog::SCAN},
     {"txpackages", BCLog::TXPACKAGES},
+    {"kernel", BCLog::KERNEL},
 };
 
 static const std::unordered_map<BCLog::LogFlags, std::string> LOG_CATEGORIES_BY_FLAG{
diff --git a/src/logging.h b/src/logging.h
index 723aeb790fb..defff61d300 100644
--- a/src/logging.h
+++ b/src/logging.h
@@ -94,6 +94,7 @@ namespace BCLog {
         TXRECONCILIATION = (CategoryMask{1} << 26),
         SCAN        = (CategoryMask{1} << 27),
         TXPACKAGES  = (CategoryMask{1} << 28),
+        KERNEL      = (CategoryMask{1} << 29),
         ALL         = ~NONE,
     };
     enum class Level {
@@ -256,6 +257,12 @@ namespace BCLog {
             m_print_callbacks.erase(it);
         }
 
+        size_t NumConnections()
+        {
+            StdLockGuard scoped_lock(m_cs);
+            return m_print_callbacks.size();
+        }
+
         /** Start logging (and flush all buffered messages) */
         bool StartLogging() EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
         /** Only for testing */
@@ -287,6 +294,11 @@ namespace BCLog {
             StdLockGuard scoped_lock(m_cs);
             m_category_log_levels = levels;
         }
+        void AddCategoryLogLevel(LogFlags category, Level level)
+        {
+            StdLockGuard scoped_lock(m_cs);
+            m_category_log_levels[category] = level;
+        }
         bool SetCategoryLogLevel(std::string_view category_str, std::string_view level_str) EXCLUSIVE_LOCKS_REQUIRED(!m_cs);
 
         Level LogLevel() const { return m_log_level.load(); }
diff --git a/src/test/kernel/test_kernel.cpp b/src/test/kernel/test_kernel.cpp
index 632a01d038e..ea7b2c741d2 100644
--- a/src/test/kernel/test_kernel.cpp
+++ b/src/test/kernel/test_kernel.cpp
@@ -12,8 +12,10 @@
 #include <cstdint>
 #include <cstdlib>
 #include <iostream>
+#include <memory>
 #include <ranges>
 #include <span>
+#include <string_view>
 #include <vector>
 
 using namespace btck;
@@ -49,6 +51,15 @@ void check_equal(std::span<const std::byte> _actual, std::span<const std::byte>
         expected.begin(), expected.end());
 }
 
+class TestLog
+{
+public:
+    void LogMessage(std::string_view message)
+    {
+        std::cout << "kernel: " << message;
+    }
+};
+
 void run_verify_test(
     const ScriptPubkey& spent_script_pubkey,
     const Transaction& spending_tx,
@@ -344,3 +355,29 @@ BOOST_AUTO_TEST_CASE(btck_script_verify_tests)
         /*input_index*/ 0,
         /*is_taproot*/ true);
 }
+
+BOOST_AUTO_TEST_CASE(logging_tests)
+{
+    btck_LoggingOptions logging_options = {
+        .log_timestamps = true,
+        .log_time_micros = true,
+        .log_threadnames = false,
+        .log_sourcelocations = false,
+        .always_print_category_levels = true,
+    };
+
+    logging_set_options(logging_options);
+    logging_set_level_category(LogCategory::BENCH, LogLevel::TRACE_LEVEL);
+    logging_disable_category(LogCategory::BENCH);
+    logging_enable_category(LogCategory::VALIDATION);
+    logging_disable_category(LogCategory::VALIDATION);
+
+    // Check that connecting, connecting another, and then disconnecting and connecting a logger again works.
+    {
+        logging_set_level_category(LogCategory::KERNEL, LogLevel::TRACE_LEVEL);
+        logging_enable_category(LogCategory::KERNEL);
+        Logger logger{std::make_unique<TestLog>()};
+        Logger logger_2{std::make_unique<TestLog>()};
+    }
+    Logger logger{std::make_unique<TestLog>()};
+}