rpcdaemon: add support for rotating file logs of external interfaces (#…

…1784)

infra: add default settings in logging initialization
conan: add spdlog dependency

conanfile.py

@@ -14,6 +14,7 @@
 
 from conan import ConanFile
 
+
 class SilkwormRecipe(ConanFile):
     settings = 'os', 'compiler', 'build_type', 'arch'
     generators = 'cmake_find_package'
@@ -41,20 +42,22 @@ def requirements(self):
         self.requires('protobuf/3.21.4')
         self.requires('roaring/1.1.2')
         self.requires('snappy/1.1.7')
+        self.requires('spdlog/1.12.0')
         self.requires('sqlitecpp/3.3.0')
         self.requires('tomlplusplus/3.3.0')
 
     def configure(self):
         self.options['asio-grpc'].local_allocator = 'boost_container'
 
-        # Currently Conan Center has Windows binaries built only with msvc16 only and mimalloc built only with option override=False.
-        # In order to build mimalloc with override=True we would need to switch to msvc17 compiler but this would trigger a full rebuild
-        # from sources of all dependencies wasting a lot of time, so we prefer to keep mimalloc override disabled on Windows.
-        # The same applies also for boost with option asio_no_deprecated, so we can skip configuration entirely on Windows.
+        # Conan Center has Windows binaries built only with msvc16 and mimalloc built only with option override=False.
+        # In order to build mimalloc with override=True we could switch to msvc17 compiler but this would trigger a full
+        # rebuild from sources of all dependencies increasing build time a lot, so we prefer to keep mimalloc override
+        # disabled on Windows.
+        # The same applies also for boost with option asio_no_deprecated, so we skip configuration entirely on Windows.
         if self.settings.os == 'Windows':
             return
 
-        # Moreover, mimalloc override=True causes a crash on macOS at startup when running rpcdaemon, so we just enable it on Linux
+        # mimalloc override=True causes a crash on macOS at startup in rpcdaemon, so we just enable it on Linux
         if self.settings.os == 'Linux':
             self.options['mimalloc'].override = True
 
@@ -65,7 +68,8 @@ def configure(self):
         for component in self.boost_components_unused():
             setattr(self.options['boost'], 'without_' + component, True)
 
-    def boost_components_unused(self):
+    @staticmethod
+    def boost_components_unused() -> set[str]:
         components_all = [
             'atomic',
             'chrono',

silkworm/infra/CMakeLists.txt

@@ -21,6 +21,7 @@ find_package(Catch2 REQUIRED)
 find_package(gRPC REQUIRED)
 find_package(GTest REQUIRED)
 find_package(magic_enum REQUIRED)
+find_package(spdlog REQUIRED)
 
 add_subdirectory(test_util)
 
@@ -50,6 +51,7 @@ set(LIBS_PRIVATE
     absl::time
     Boost::container # required for asio-grpc
     magic_enum::magic_enum
+    spdlog::spdlog
 )
 # cmake-format: on
 

silkworm/infra/common/log.hpp

@@ -51,7 +51,7 @@ struct Settings {
 
 //! \brief Initializes logging facilities
 //! \note This function is not thread safe as it's meant to be used at start of process and never called again
-void init(const Settings& settings);
+void init(const Settings& settings = {});
 
 //! \brief Get the current logging verbosity
 //! \note This function is not thread safe as it's meant to be used in tests

silkworm/infra/common/log_test.cpp

@@ -79,6 +79,8 @@ TEST_CASE("LogBuffer", "[silkworm][common][log]") {
     std::stringstream string_cout, string_cerr;
     test_util::StreamSwap cout_swap{std::cout, string_cout};
     test_util::StreamSwap cerr_swap{std::cerr, string_cerr};
+    // Make sure logging facility is initialized
+    init();
 
     SECTION("LogBuffer stores nothing for verbosity higher than default") {
         check_log_empty<Level::kDebug>();

silkworm/rpc/common/interface_log.cpp

@@ -0,0 +1,103 @@
+/*
+   Copyright 2024 The Silkworm Authors
+
+   Licensed under the Apache License, Version 2.0 (the "License");
+   you may not use this file except in compliance with the License.
+   You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing, software
+   distributed under the License is distributed on an "AS IS" BASIS,
+   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+   See the License for the specific language governing permissions and
+   limitations under the License.
+*/
+
+#include "interface_log.hpp"
+
+#include <spdlog/sinks/rotating_file_sink.h>
+#include <spdlog/spdlog.h>
+
+#include <silkworm/core/common/base.hpp>
+#include <silkworm/infra/common/ensure.hpp>
+
+namespace silkworm::log {
+
+class InterfaceLogImpl final {
+  public:
+    explicit InterfaceLogImpl(std::string_view name, std::string_view folder, bool auto_flush);
+    ~InterfaceLogImpl() {
+        flush();
+    }
+
+    [[nodiscard]] std::filesystem::path path() const {
+        return file_path_;
+    }
+
+    template <typename... Args>
+    void log(spdlog::format_string_t<Args...> fmt, Args&&... args) {
+        rotating_logger_->info(fmt, std::forward<Args>(args)...);
+    }
+
+    void log(std::string_view msg) {
+        rotating_logger_->info(msg);
+        if (auto_flush_) {
+            rotating_logger_->flush();
+        }
+    }
+
+    void flush() {
+        rotating_logger_->flush();
+    }
+
+  private:
+    std::string name_;
+    bool auto_flush_;
+    std::filesystem::path file_path_;
+    std::size_t max_file_size_{1 * kMebi};
+    std::size_t max_files_{10};
+    std::shared_ptr<spdlog::logger> rotating_logger_;
+};
+
+InterfaceLogImpl::InterfaceLogImpl(std::string_view name, std::string_view folder, bool auto_flush)
+    : name_{name},
+      auto_flush_{auto_flush},
+      file_path_{folder / std::filesystem::path{name_ + ".log"}},
+      rotating_logger_{spdlog::rotating_logger_mt(name_, file_path_.string(), max_file_size_, max_files_)} {
+    ensure(!name_.empty(), "InterfaceLogImpl: name is empty");
+
+    // Hard-code log level because we want all-or-nothing in interface log
+    rotating_logger_->set_level(spdlog::level::info);
+
+    // Customize log pattern to avoid unnecessary fields (log level, logger name)
+    rotating_logger_->set_pattern("[%Y-%m-%d %H:%M:%S.%e] %v");
+}
+
+InterfaceLog::InterfaceLog(std::string_view name, std::string_view folder, bool auto_flush)
+    : p_impl_{std::make_unique<InterfaceLogImpl>(name, folder, auto_flush)} {
+}
+
+// An explicit destructor is needed to avoid error:
+// invalid application of 'sizeof' to an incomplete type 'silkworm::log::InterfaceLogImpl'
+InterfaceLog::~InterfaceLog() {
+    p_impl_->flush();
+}
+
+std::filesystem::path InterfaceLog::path() const {
+    return p_impl_->path();
+}
+
+void InterfaceLog::log_req(std::string_view msg) {
+    p_impl_->log("REQ -> {}", msg);
+}
+
+void InterfaceLog::log_rsp(std::string_view msg) {
+    p_impl_->log("RSP <- {}", msg);
+}
+
+void InterfaceLog::flush() {
+    p_impl_->flush();
+}
+
+}  // namespace silkworm::log

silkworm/rpc/common/interface_log.hpp

@@ -0,0 +1,43 @@
+/*
+   Copyright 2024 The Silkworm Authors
+
+   Licensed under the Apache License, Version 2.0 (the "License");
+   you may not use this file except in compliance with the License.
+   You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing, software
+   distributed under the License is distributed on an "AS IS" BASIS,
+   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+   See the License for the specific language governing permissions and
+   limitations under the License.
+*/
+
+#pragma once
+
+#include <filesystem>
+#include <memory>
+#include <string_view>
+
+namespace silkworm::log {
+
+class InterfaceLogImpl;
+
+class InterfaceLog final {
+  public:
+    explicit InterfaceLog(std::string_view name, std::string_view folder = "logs/", bool auto_flush = false);
+    ~InterfaceLog();
+
+    [[nodiscard]] std::filesystem::path path() const;
+
+    void log_req(std::string_view msg);
+    void log_rsp(std::string_view msg);
+
+    void flush();
+
+  private:
+    std::unique_ptr<InterfaceLogImpl> p_impl_;
+};
+
+}  // namespace silkworm::log

silkworm/rpc/common/interface_log_test.cpp

@@ -0,0 +1,67 @@
+/*
+   Copyright 2024 The Silkworm Authors
+
+   Licensed under the Apache License, Version 2.0 (the "License");
+   you may not use this file except in compliance with the License.
+   You may obtain a copy of the License at
+
+       http://www.apache.org/licenses/LICENSE-2.0
+
+   Unless required by applicable law or agreed to in writing, software
+   distributed under the License is distributed on an "AS IS" BASIS,
+   WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+   See the License for the specific language governing permissions and
+   limitations under the License.
+*/
+
+#include "interface_log.hpp"
+
+#include <fstream>
+#include <memory>
+#include <string>
+
+#include <absl/strings/match.h>
+#include <catch2/catch.hpp>
+
+#include <silkworm/infra/common/directories.hpp>
+
+namespace silkworm::log {
+
+TEST_CASE("InterfaceLog basic", "[infra][common][log]") {
+    const auto tmp_dir{TemporaryDirectory::get_unique_temporary_path()};
+    static int count{0};
+    auto ifc_log{std::make_unique<InterfaceLog>("eth_rpc" + std::to_string(++count), tmp_dir.string())};
+    REQUIRE(!ifc_log->path().empty());
+    ifc_log->log_req(R"({"json":"2.0"})");
+    ifc_log->log_rsp(R"({"json":"2.0"})");
+    std::ifstream log_ifstream{ifc_log->path().string()};
+
+    // Log file must be empty before flushing
+    CHECK(log_ifstream.get() == -1);
+    CHECK(log_ifstream.eof());
+    log_ifstream.clear();
+    log_ifstream.seekg(std::ios::beg);
+
+    SECTION("explicit flush") {
+        // InterfaceLog instance gets flushed here but remains alive until the end
+        ifc_log->flush();
+    }
+
+    SECTION("implicit flush") {
+        // InterfaceLog instance gets destroyed here and implicitly flushed
+        ifc_log.reset();
+    }
+
+    // First line must be the request
+    std::string content;
+    std::getline(log_ifstream, content);
+    CHECK(absl::StrContains(content, R"(REQ -> {"json":"2.0"})"));
+    // Second line must be the response
+    std::getline(log_ifstream, content);
+    CHECK(absl::StrContains(content, R"(RSP <- {"json":"2.0"})"));
+    // No other content is present
+    CHECK(log_ifstream.get() == -1);
+    CHECK(log_ifstream.eof());
+}
+
+}  // namespace silkworm::log