diff --git a/README.md b/README.md index c9e0467e..026379ad 100644 --- a/README.md +++ b/README.md @@ -407,6 +407,44 @@ imported in the global namespace by the user. In the [Examples](#examples) section the reader can find examples showing how to serialize using json and [protobuf](https://protobuf.dev/). + + +### Logging + +`connection::async_run` is a complex algorithm, with features like built-in reconnection. +This can make configuration problems, like a misconfigured hostname, difficult to debug - +Boost.Redis will keep retrying to connect to the same hostname over and over. +For this reason, Boost.Redis incorporates a lightweight logging solution, and +**will log some status messages to stderr by default**. + +Logging can be customized by passing a `logger` object to the `connection`'s constructor. + +For example, logging can be disabled by writing: + +```cpp +asio::io_context ioc; +redis::connection conn {ioc, redis::logger{redis::logger::level::disabled}}; +``` + +Every message logged by the library is attached a +[syslog-like severity](https://en.wikipedia.org/wiki/Syslog#Severity_level) +tag (a `logger::level`). +You can filter messages by severity by creating a `logger` with a specific level: + +```cpp +asio::io_context ioc; + +// Logs to stderr messages with severity >= level::error. +// This will hide all informational output. +redis::connection conn {ioc, redis::logger{redis::logger::level::error}}; +``` + +`logger`'s constructor accepts a `std::function` +as second argument. If supplied, Boost.Redis will call this function when logging +instead of printing to stderr. This can be used to integrate third-party logging +libraries. See our [spdlog integration example](example/cpp17_spdlog.cpp) for sample code. + + ## Examples @@ -424,6 +462,7 @@ The examples below show how to use the features discussed so far * cpp20_chat_room.cpp: A command line chat built on Redis pubsub. * cpp17_intro.cpp: Uses callbacks and requires C++17. * cpp17_intro_sync.cpp: Runs `async_run` in a separate thread and performs synchronous calls to `async_exec`. +* cpp17_spdlog.cpp: Shows how to use third-party logging libraries like `spdlog` with Boost.Redis. The main function used in some async examples has been factored out in the main.cpp file. diff --git a/example/CMakeLists.txt b/example/CMakeLists.txt index 05db0c5d..8c36bc71 100644 --- a/example/CMakeLists.txt +++ b/example/CMakeLists.txt @@ -51,3 +51,12 @@ endif() if (NOT MSVC) make_example(cpp20_chat_room 20) endif() + +# We build and test the spdlog integration example only if the library is found +find_package(spdlog) +if (spdlog_FOUND) + make_testable_example(cpp17_spdlog 17) + target_link_libraries(cpp17_spdlog PRIVATE spdlog::spdlog) +else() + message(STATUS "Skipping the spdlog example because the spdlog package couldn't be found") +endif() diff --git a/example/cpp17_intro.cpp b/example/cpp17_intro.cpp index dbfaff46..64274fa7 100644 --- a/example/cpp17_intro.cpp +++ b/example/cpp17_intro.cpp @@ -34,7 +34,7 @@ auto main(int argc, char* argv[]) -> int asio::io_context ioc; connection conn{ioc}; - conn.async_run(cfg, {}, asio::detached); + conn.async_run(cfg, asio::detached); conn.async_exec(req, resp, [&](auto ec, auto) { if (!ec) diff --git a/example/cpp17_spdlog.cpp b/example/cpp17_spdlog.cpp new file mode 100644 index 00000000..6e7b71d3 --- /dev/null +++ b/example/cpp17_spdlog.cpp @@ -0,0 +1,102 @@ +// +// Copyright (c) 2025 Marcelo Zimbres Silva (mzimbres@gmail.com), +// Ruben Perez Hidalgo (rubenperez038 at gmail dot com) +// +// Distributed under the Boost Software License, Version 1.0. (See accompanying +// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) +// + +#include +#include + +#include +#include + +#include +#include +#include +#include + +namespace asio = boost::asio; +namespace redis = boost::redis; + +// Maps a Boost.Redis log level to a spdlog log level +static spdlog::level::level_enum to_spdlog_level(redis::logger::level lvl) +{ + switch (lvl) { + // spdlog doesn't include the emerg and alert syslog levels, + // so we convert them to the highest supported level. + // Similarly, notice is similar to info + case redis::logger::level::emerg: + case redis::logger::level::alert: + case redis::logger::level::crit: return spdlog::level::critical; + case redis::logger::level::err: return spdlog::level::err; + case redis::logger::level::warning: return spdlog::level::warn; + case redis::logger::level::notice: + case redis::logger::level::info: return spdlog::level::info; + case redis::logger::level::debug: + default: return spdlog::level::debug; + } +} + +// This function glues Boost.Redis logging and spdlog. +// It should have the signature shown here. It will be invoked +// by Boost.Redis whenever a message is to be logged. +static void do_log(redis::logger::level level, std::string_view msg) +{ + spdlog::log(to_spdlog_level(level), "(Boost.Redis) {}", msg); +} + +auto main(int argc, char* argv[]) -> int +{ + if (argc != 3) { + std::cerr << "Usage: " << argv[0] << " \n"; + exit(1); + } + + try { + // Create an execution context, required to create any I/O objects + asio::io_context ioc; + + // Create a connection to connect to Redis, and pass it a custom logger. + // Boost.Redis will call do_log whenever it needs to log a message. + // Note that the function will only be called for messages with level >= info + // (i.e. filtering is done by Boost.Redis). + redis::connection conn{ + ioc, + redis::logger{redis::logger::level::info, do_log} + }; + + // Configuration to connect to the server + redis::config cfg; + cfg.addr.host = argv[1]; + cfg.addr.port = argv[2]; + + // Run the connection with the specified configuration. + // This will establish the connection and keep it healthy + conn.async_run(cfg, asio::detached); + + // Execute a request + redis::request req; + req.push("PING", "Hello world"); + + redis::response resp; + + conn.async_exec(req, resp, [&](boost::system::error_code ec, std::size_t /* bytes_read*/) { + if (ec) { + spdlog::error("Request failed: {}", ec.what()); + exit(1); + } else { + spdlog::info("PING: {}", std::get<0>(resp).value()); + } + conn.cancel(); + }); + + // Actually run our example. Nothing will happen until we call run() + ioc.run(); + + } catch (std::exception const& e) { + spdlog::error("Error: {}", e.what()); + return 1; + } +} diff --git a/example/cpp20_chat_room.cpp b/example/cpp20_chat_room.cpp index d41a69d0..17dfd0f5 100644 --- a/example/cpp20_chat_room.cpp +++ b/example/cpp20_chat_room.cpp @@ -86,7 +86,7 @@ auto co_main(config cfg) -> awaitable co_spawn(ex, receiver(conn), detached); co_spawn(ex, publisher(stream, conn), detached); - conn->async_run(cfg, {}, consign(detached, conn)); + conn->async_run(cfg, consign(detached, conn)); signal_set sig_set{ex, SIGINT, SIGTERM}; co_await sig_set.async_wait(); diff --git a/example/cpp20_containers.cpp b/example/cpp20_containers.cpp index 98aedce7..c21675d8 100644 --- a/example/cpp20_containers.cpp +++ b/example/cpp20_containers.cpp @@ -133,7 +133,7 @@ auto transaction(std::shared_ptr conn) -> awaitable awaitable co_main(config cfg) { auto conn = std::make_shared(co_await asio::this_coro::executor); - conn->async_run(cfg, {}, consign(detached, conn)); + conn->async_run(cfg, consign(detached, conn)); co_await store(conn); co_await transaction(conn); diff --git a/example/cpp20_echo_server.cpp b/example/cpp20_echo_server.cpp index ac3e0c80..dca86bf3 100644 --- a/example/cpp20_echo_server.cpp +++ b/example/cpp20_echo_server.cpp @@ -60,7 +60,7 @@ auto co_main(config cfg) -> asio::awaitable auto ex = co_await asio::this_coro::executor; auto conn = std::make_shared(ex); asio::co_spawn(ex, listener(conn), asio::detached); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); signal_set sig_set(ex, SIGINT, SIGTERM); co_await sig_set.async_wait(); diff --git a/example/cpp20_intro.cpp b/example/cpp20_intro.cpp index 7389da2a..9c1637a1 100644 --- a/example/cpp20_intro.cpp +++ b/example/cpp20_intro.cpp @@ -24,7 +24,7 @@ using boost::redis::connection; auto co_main(config cfg) -> asio::awaitable { auto conn = std::make_shared(co_await asio::this_coro::executor); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); // A request containing only a ping command. request req; diff --git a/example/cpp20_intro_tls.cpp b/example/cpp20_intro_tls.cpp index 4403d68d..6321c9e8 100644 --- a/example/cpp20_intro_tls.cpp +++ b/example/cpp20_intro_tls.cpp @@ -8,6 +8,7 @@ #include #include +#include #include #include @@ -35,17 +36,18 @@ auto co_main(config cfg) -> asio::awaitable cfg.addr.host = "db.occase.de"; cfg.addr.port = "6380"; - auto conn = std::make_shared(co_await asio::this_coro::executor); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + asio::ssl::context ctx{asio::ssl::context::tlsv12_client}; + ctx.set_verify_mode(asio::ssl::verify_peer); + ctx.set_verify_callback(verify_certificate); + + auto conn = std::make_shared(co_await asio::this_coro::executor, std::move(ctx)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); request req; req.push("PING"); response resp; - conn->next_layer().set_verify_mode(asio::ssl::verify_peer); - conn->next_layer().set_verify_callback(verify_certificate); - co_await conn->async_exec(req, resp); conn->cancel(); diff --git a/example/cpp20_json.cpp b/example/cpp20_json.cpp index c44b64a7..756d5275 100644 --- a/example/cpp20_json.cpp +++ b/example/cpp20_json.cpp @@ -58,7 +58,7 @@ auto co_main(config cfg) -> asio::awaitable { auto ex = co_await asio::this_coro::executor; auto conn = std::make_shared(ex); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); // user object that will be stored in Redis in json format. user const u{"Joao", "58", "Brazil"}; diff --git a/example/cpp20_protobuf.cpp b/example/cpp20_protobuf.cpp index cdf4eb3b..e23415a0 100644 --- a/example/cpp20_protobuf.cpp +++ b/example/cpp20_protobuf.cpp @@ -64,7 +64,7 @@ asio::awaitable co_main(config cfg) { auto ex = co_await asio::this_coro::executor; auto conn = std::make_shared(ex); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); person p; p.set_name("Louis"); diff --git a/example/cpp20_resolve_with_sentinel.cpp b/example/cpp20_resolve_with_sentinel.cpp index d3073ab6..e1bae87c 100644 --- a/example/cpp20_resolve_with_sentinel.cpp +++ b/example/cpp20_resolve_with_sentinel.cpp @@ -44,10 +44,9 @@ auto resolve_master_address(std::vector
const& addresses) -> asio::awai // TODO: async_run and async_exec should be lauched in // parallel here so we can wait for async_run completion // before eventually calling it again. - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); co_await conn->async_exec(req, resp, redir(ec)); conn->cancel(); - conn->reset_stream(); if (!ec && std::get<0>(resp)) co_return address{ std::get<0>(resp).value().value().at(0), diff --git a/example/cpp20_streams.cpp b/example/cpp20_streams.cpp index 785503fd..1cef143f 100644 --- a/example/cpp20_streams.cpp +++ b/example/cpp20_streams.cpp @@ -88,7 +88,7 @@ auto co_main(config cfg) -> net::awaitable // Disable health checks. cfg.health_check_interval = std::chrono::seconds::zero(); - conn->async_run(cfg, {}, net::consign(net::detached, conn)); + conn->async_run(cfg, net::consign(net::detached, conn)); signal_set sig_set(ex, SIGINT, SIGTERM); co_await sig_set.async_wait(); diff --git a/example/cpp20_subscriber.cpp b/example/cpp20_subscriber.cpp index ab372e46..d2ec462f 100644 --- a/example/cpp20_subscriber.cpp +++ b/example/cpp20_subscriber.cpp @@ -87,7 +87,7 @@ auto co_main(config cfg) -> asio::awaitable auto ex = co_await asio::this_coro::executor; auto conn = std::make_shared(ex); asio::co_spawn(ex, receiver(conn), asio::detached); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); signal_set sig_set(ex, SIGINT, SIGTERM); co_await sig_set.async_wait(); diff --git a/example/cpp20_unix_sockets.cpp b/example/cpp20_unix_sockets.cpp index b1cd63ab..3c69ea12 100644 --- a/example/cpp20_unix_sockets.cpp +++ b/example/cpp20_unix_sockets.cpp @@ -34,7 +34,7 @@ auto co_main(config cfg) -> asio::awaitable cfg.unix_socket = "/tmp/redis-socks/redis.sock"; auto conn = std::make_shared(co_await asio::this_coro::executor); - conn->async_run(cfg, {}, asio::consign(asio::detached, conn)); + conn->async_run(cfg, asio::consign(asio::detached, conn)); request req; req.push("PING"); diff --git a/example/sync_connection.hpp b/example/sync_connection.hpp index c2a832ed..80efbe76 100644 --- a/example/sync_connection.hpp +++ b/example/sync_connection.hpp @@ -33,7 +33,7 @@ public: // Starts a thread that will can io_context::run on which the // connection will run. thread_ = std::thread{[this, cfg]() { - conn_->async_run(cfg, {}, asio::detached); + conn_->async_run(cfg, asio::detached); ioc_.run(); }}; } diff --git a/include/boost/redis/config.hpp b/include/boost/redis/config.hpp index 0d7ed04d..eee20c94 100644 --- a/include/boost/redis/config.hpp +++ b/include/boost/redis/config.hpp @@ -60,7 +60,13 @@ struct config { /// Message used by the health-checker in `boost::redis::connection::async_run`. std::string health_check_id = "Boost.Redis"; - /// Logger prefix, see `boost::redis::logger`. + /** + * @brief (Deprecated) Sets the logger prefix, a string printed before log messages. + * + * Setting a prefix in this struct is deprecated. If you need to change how log messages + * look like, please construct a logger object passing a formatting function, and use that + * logger in connection's constructor. This member will be removed in subsequent releases. + */ std::string log_prefix = "(Boost.Redis) "; /// Time the resolve operation is allowed to last. diff --git a/include/boost/redis/connection.hpp b/include/boost/redis/connection.hpp index ce97e869..cf626a06 100644 --- a/include/boost/redis/connection.hpp +++ b/include/boost/redis/connection.hpp @@ -10,6 +10,7 @@ #include #include #include +#include #include #include #include @@ -49,6 +50,7 @@ #include #include #include +#include #include namespace boost::redis { @@ -150,10 +152,9 @@ struct exec_op { } }; -template +template struct writer_op { Conn* conn_; - Logger logger_; asio::coroutine coro{}; template @@ -170,10 +171,10 @@ struct writer_op { asio::buffer(conn_->mpx_.get_write_buffer()), std::move(self)); - logger_.on_write(ec, conn_->mpx_.get_write_buffer()); + conn_->logger_.on_write(ec, conn_->mpx_.get_write_buffer().size()); if (ec) { - logger_.trace("writer_op (1)", ec); + conn_->logger_.trace("writer_op (1)", ec); conn_->cancel(operation::run); self.complete(ec); return; @@ -185,7 +186,7 @@ struct writer_op { // successful write might had already been queued, so we // have to check here before proceeding. if (!conn_->is_open()) { - logger_.trace("writer_op (2): connection is closed."); + conn_->logger_.trace("writer_op (2): connection is closed."); self.complete({}); return; } @@ -194,7 +195,7 @@ struct writer_op { BOOST_ASIO_CORO_YIELD conn_->writer_timer_.async_wait(std::move(self)); if (!conn_->is_open()) { - logger_.trace("writer_op (3): connection is closed."); + conn_->logger_.trace("writer_op (3): connection is closed."); // Notice this is not an error of the op, stoping was // requested from the outside, so we complete with // success. @@ -205,7 +206,7 @@ struct writer_op { } }; -template +template struct reader_op { using dyn_buffer_type = asio::dynamic_string_buffer< char, @@ -216,7 +217,6 @@ struct reader_op { static constexpr std::size_t buffer_growth_hint = 4096; Conn* conn_; - Logger logger_; std::pair res_{std::make_pair(std::nullopt, 0)}; asio::coroutine coro{}; @@ -233,11 +233,11 @@ struct reader_op { conn_->mpx_.get_parser().get_suggested_buffer_growth(buffer_growth_hint), std::move(self)); - logger_.on_read(ec, n); + conn_->logger_.on_read(ec, n); // The connection is not viable after an error. if (ec) { - logger_.trace("reader_op (1)", ec); + conn_->logger_.trace("reader_op (1)", ec); conn_->cancel(operation::run); self.complete(ec); return; @@ -246,7 +246,7 @@ struct reader_op { // The connection might have been canceled while this op was // suspended or after queueing so we have to check. if (!conn_->is_open()) { - logger_.trace("reader_op (2): connection is closed."); + conn_->logger_.trace("reader_op (2): connection is closed."); self.complete(ec); return; } @@ -255,7 +255,7 @@ struct reader_op { res_ = conn_->mpx_.consume_next(ec); if (ec) { - logger_.trace("reader_op (3)", ec); + conn_->logger_.trace("reader_op (3)", ec); conn_->cancel(operation::run); self.complete(ec); return; @@ -273,14 +273,14 @@ struct reader_op { } if (ec) { - logger_.trace("reader_op (4)", ec); + conn_->logger_.trace("reader_op (4)", ec); conn_->cancel(operation::run); self.complete(ec); return; } if (!conn_->is_open()) { - logger_.trace("reader_op (5): connection is closed."); + conn_->logger_.trace("reader_op (5): connection is closed."); self.complete(asio::error::operation_aborted); return; } @@ -302,20 +302,18 @@ inline system::error_code check_config(const config& cfg) return system::error_code{}; } -template +template class run_op { private: Conn* conn_ = nullptr; - Logger logger_; asio::coroutine coro_{}; system::error_code stored_ec_; using order_t = std::array; public: - run_op(Conn* conn, Logger l) + run_op(Conn* conn) noexcept : conn_{conn} - , logger_{l} { } template @@ -339,7 +337,7 @@ public: // Check config ec0 = check_config(conn_->cfg_); if (ec0) { - logger_.log_error("Invalid configuration", ec0); + conn_->logger_.log(logger::level::err, "Invalid configuration", ec0); stored_ec_ = ec0; BOOST_ASIO_CORO_YIELD asio::async_immediate(self.get_io_executor(), std::move(self)); self.complete(stored_ec_); @@ -349,7 +347,7 @@ public: for (;;) { // Try to connect BOOST_ASIO_CORO_YIELD - conn_->stream_.async_connect(&conn_->cfg_, logger_, std::move(self)); + conn_->stream_.async_connect(&conn_->cfg_, &conn_->logger_, std::move(self)); // If we failed, try again if (ec0) { @@ -365,19 +363,19 @@ public: BOOST_ASIO_CORO_YIELD asio::experimental::make_parallel_group( [this](auto token) { - return conn_->handshaker_.async_hello(*conn_, logger_, token); + return conn_->handshaker_.async_hello(*conn_, token); }, [this](auto token) { - return conn_->health_checker_.async_ping(*conn_, logger_, token); + return conn_->health_checker_.async_ping(*conn_, token); }, [this](auto token) { - return conn_->health_checker_.async_check_timeout(*conn_, logger_, token); + return conn_->health_checker_.async_check_timeout(*conn_, token); }, [this](auto token) { - return conn_->reader(logger_, token); + return conn_->reader(token); }, [this](auto token) { - return conn_->writer(logger_, token); + return conn_->writer(token); }) .async_wait(asio::experimental::wait_for_one_error(), std::move(self)); @@ -420,6 +418,8 @@ public: } }; +logger make_stderr_logger(logger::level lvl, std::string prefix); + } // namespace detail /** @brief A SSL connection to the Redis server. @@ -438,7 +438,8 @@ public: using this_type = basic_connection; /// Type of the next layer - using next_layer_type = asio::ssl::stream>; + BOOST_DEPRECATED("This typedef is deprecated, and will be removed with next_layer().") + typedef asio::ssl::stream> next_layer_type; /// Executor type using executor_type = Executor; @@ -457,25 +458,55 @@ public: * * @param ex Executor on which connection operation will run. * @param ctx SSL context. + * @param lgr Logger configuration. It can be used to filter messages by level + * and customize logging. By default, `logger::level::info` messages + * and higher are logged to `stderr`. */ explicit basic_connection( executor_type ex, - asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}) + asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}, + logger lgr = {}) : stream_{ex, std::move(ctx)} , writer_timer_{ex} , reconnect_timer_{ex} , receive_channel_{ex, 256} , health_checker_{ex} + , logger_{std::move(lgr)} { set_receive_response(ignore); writer_timer_.expires_at((std::chrono::steady_clock::time_point::max)()); } + /** @brief Constructor + * + * @param ex Executor on which connection operation will run. + * @param lgr Logger configuration. It can be used to filter messages by level + * and customize logging. By default, `logger::level::info` messages + * and higher are logged to `stderr`. + * + * An SSL context with default settings will be created. + */ + basic_connection(executor_type ex, logger lgr) + : basic_connection( + std::move(ex), + asio::ssl::context{asio::ssl::context::tlsv12_client}, + std::move(lgr)) + { } + /// Constructs from a context. explicit basic_connection( asio::io_context& ioc, - asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}) - : basic_connection(ioc.get_executor(), std::move(ctx)) + asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}, + logger lgr = {}) + : basic_connection(ioc.get_executor(), std::move(ctx), std::move(lgr)) + { } + + /// Constructs from a context. + basic_connection(asio::io_context& ctx, logger lgr) + : basic_connection( + ctx.get_executor(), + asio::ssl::context{asio::ssl::context::tlsv12_client}, + std::move(lgr)) { } /** @brief Starts underlying connection operations. @@ -503,7 +534,6 @@ public: * `boost::redis::connection::cancel(operation::reconnection)`. * * @param cfg Configuration paramters. - * @param l Logger object. The interface expected is specified in the class `boost::redis::logger`. * @param token Completion token. * * The completion token must have the following signature @@ -515,22 +545,62 @@ public: * For example on how to call this function refer to * cpp20_intro.cpp or any other example. */ - template < - class Logger = logger, - class CompletionToken = asio::default_completion_token_t> - auto async_run(config const& cfg = {}, Logger l = Logger{}, CompletionToken&& token = {}) + template > + auto async_run(config const& cfg, CompletionToken&& token = {}) { cfg_ = cfg; health_checker_.set_config(cfg); handshaker_.set_config(cfg); - l.set_prefix(cfg.log_prefix); return asio::async_compose( - detail::run_op{this, l}, + detail::run_op{this}, token, writer_timer_); } + /** + * @copydoc async_run + * + * This function accepts an extra logger parameter. The passed `logger::lvl` + * will be used, but `logger::fn` will be ignored. Instead, a function + * that logs to `stderr` using `config::prefix` will be used. + * This keeps backwards compatibility with previous versions. + * Any logger configured in the constructor will be overriden. + * + * @par Deprecated + * The logger should be passed to the connection's constructor instead of using this + * function. Use the overload without a logger parameter, instead. This function is + * deprecated and will be removed in subsequent releases. + */ + template > + BOOST_DEPRECATED( + "The async_run overload taking a logger argument is deprecated. " + "Please pass the logger to the connection's constructor, instead, " + "and use the other async_run overloads.") + auto async_run(config const& cfg, logger l, CompletionToken&& token = {}) + { + set_stderr_logger(l.lvl, cfg); + return async_run(cfg, std::forward(token)); + } + + /** + * @copydoc async_run + * + * Uses a default-constructed config object to run the connection. + * + * @par Deprecated + * This function is deprecated and will be removed in subsequent releases. + * Use the overload taking an explicit config object, instead. + */ + template > + BOOST_DEPRECATED( + "Running without an explicit config object is deprecated." + "Please create a config object and pass it to async_run.") + auto async_run(CompletionToken&& token = {}) + { + return async_run(config{}, std::forward(token)); + } + /** @brief Receives server side pushes asynchronously. * * When pushes arrive and there is no `async_receive` operation in @@ -755,25 +825,35 @@ private: mpx_.cancel_on_conn_lost(); } - template friend struct detail::reader_op; - template friend struct detail::writer_op; - template friend struct detail::exec_op; - template friend class detail::run_op; + // Used by both this class and connection + void set_stderr_logger(logger::level lvl, const config& cfg) + { + logger_.reset(detail::make_stderr_logger(lvl, cfg.log_prefix)); + } - template - auto reader(Logger l, CompletionToken&& token) + template friend struct detail::reader_op; + template friend struct detail::writer_op; + template friend struct detail::exec_op; + template friend struct detail::hello_op; + template friend class detail::ping_op; + template friend class detail::run_op; + template friend class detail::check_timeout_op; + friend class connection; + + template + auto reader(CompletionToken&& token) { return asio::async_compose( - detail::reader_op{this, l}, + detail::reader_op{this}, std::forward(token), writer_timer_); } - template - auto writer(Logger l, CompletionToken&& token) + template + auto writer(CompletionToken&& token) { return asio::async_compose( - detail::writer_op{this, l}, + detail::writer_op{this}, std::forward(token), writer_timer_); } @@ -793,6 +873,7 @@ private: config cfg_; detail::multiplexer mpx_; + detail::connection_logger logger_; }; /** \brief A basic_connection that type erases the executor. @@ -809,31 +890,94 @@ public: /// Executor type. using executor_type = asio::any_io_executor; - /// Contructs from an executor. + /** @brief Constructor + * + * @param ex Executor on which connection operation will run. + * @param ctx SSL context. + * @param lgr Logger configuration. It can be used to filter messages by level + * and customize logging. By default, `logger::level::info` messages + * and higher are logged to `stderr`. + */ explicit connection( executor_type ex, - asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}); + asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}, + logger lgr = {}); - /// Contructs from a context. + /** @brief Constructor + * + * @param ex Executor on which connection operation will run. + * @param lgr Logger configuration. It can be used to filter messages by level + * and customize logging. By default, `logger::level::info` messages + * and higher are logged to `stderr`. + * + * An SSL context with default settings will be created. + */ + connection(executor_type ex, logger lgr) + : connection( + std::move(ex), + asio::ssl::context{asio::ssl::context::tlsv12_client}, + std::move(lgr)) + { } + + /// Constructs from a context. explicit connection( asio::io_context& ioc, - asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}); + asio::ssl::context ctx = asio::ssl::context{asio::ssl::context::tlsv12_client}, + logger lgr = {}) + : connection(ioc.get_executor(), std::move(ctx), std::move(lgr)) + { } + + /// Constructs from a context. + connection(asio::io_context& ioc, logger lgr) + : connection( + ioc.get_executor(), + asio::ssl::context{asio::ssl::context::tlsv12_client}, + std::move(lgr)) + { } /// Returns the underlying executor. executor_type get_executor() noexcept { return impl_.get_executor(); } - /// Calls `boost::redis::basic_connection::async_run`. + /** + * @brief Calls `boost::redis::basic_connection::async_run`. + * + * This function accepts an extra logger parameter. The passed logger + * will be used by the connection, overwriting any logger passed to the connection's + * constructor. + * + * @par Deprecated + * The logger should be passed to the connection's constructor instead of using this + * function. Use the overload without a logger parameter, instead. This function is + * deprecated and will be removed in subsequent releases. + */ template + BOOST_DEPRECATED( + "The async_run overload taking a logger argument is deprecated. " + "Please pass the logger to the connection's constructor, instead, " + "and use the other async_run overloads.") auto async_run(config const& cfg, logger l, CompletionToken&& token = {}) { return asio::async_initiate( [](auto handler, connection* self, config const* cfg, logger l) { - self->async_run_impl(*cfg, l, std::move(handler)); + self->async_run_impl(*cfg, std::move(l), std::move(handler)); }, token, this, &cfg, - l); + std::move(l)); + } + + /// Calls `boost::redis::basic_connection::async_run`. + template + auto async_run(config const& cfg, CompletionToken&& token = {}) + { + return asio::async_initiate( + [](auto handler, connection* self, config const* cfg) { + self->async_run_impl(*cfg, std::move(handler)); + }, + token, + this, + &cfg); } /// Calls `boost::redis::basic_connection::async_receive`. @@ -877,13 +1021,13 @@ public: BOOST_DEPRECATED( "Accessing the underlying stream is deprecated and will be removed in the next release. Use " "the other member functions to interact with the connection.") - auto& next_layer() noexcept { return impl_.next_layer(); } + auto& next_layer() noexcept { return impl_.stream_.next_layer(); } /// Calls `boost::redis::basic_connection::next_layer`. BOOST_DEPRECATED( "Accessing the underlying stream is deprecated and will be removed in the next release. Use " "the other member functions to interact with the connection.") - auto const& next_layer() const noexcept { return impl_.next_layer(); } + auto const& next_layer() const noexcept { return impl_.stream_.next_layer(); } /// Calls `boost::redis::basic_connection::reset_stream`. BOOST_DEPRECATED( @@ -905,12 +1049,16 @@ public: BOOST_DEPRECATED( "ssl::context has no const methods, so this function should not be called. Set up any " "required TLS configuration before passing the ssl::context to the connection's constructor.") - auto const& get_ssl_context() const noexcept { return impl_.get_ssl_context(); } + auto const& get_ssl_context() const noexcept { return impl_.stream_.get_ssl_context(); } private: void async_run_impl( config const& cfg, - logger l, + logger&& l, + asio::any_completion_handler token); + + void async_run_impl( + config const& cfg, asio::any_completion_handler token); void async_exec_impl( diff --git a/include/boost/redis/detail/connection_logger.hpp b/include/boost/redis/detail/connection_logger.hpp new file mode 100644 index 00000000..51fd24f6 --- /dev/null +++ b/include/boost/redis/detail/connection_logger.hpp @@ -0,0 +1,53 @@ +/* Copyright (c) 2018-2025 Marcelo Zimbres Silva (mzimbres@gmail.com) + * + * Distributed under the Boost Software License, Version 1.0. (See + * accompanying file LICENSE.txt) + */ + +#ifndef BOOST_REDIS_CONNECTION_LOGGER_HPP +#define BOOST_REDIS_CONNECTION_LOGGER_HPP + +#include +#include + +#include +#include + +#include + +namespace boost::redis::detail { + +// Wraps a logger and a string buffer for re-use, and provides +// utility functions to format the log messages that we use. +// The long-term trend will be moving most of this class to finite state +// machines as we write them +class connection_logger { + logger logger_; + std::string msg_; + +public: + connection_logger(logger&& logger) noexcept + : logger_(std::move(logger)) + { } + + void reset(logger&& logger) { logger_ = std::move(logger); } + + void on_resolve(system::error_code const& ec, asio::ip::tcp::resolver::results_type const& res); + void on_connect(system::error_code const& ec, asio::ip::tcp::endpoint const& ep); + void on_connect(system::error_code const& ec, std::string_view unix_socket_ep); + void on_ssl_handshake(system::error_code const& ec); + void on_write(system::error_code const& ec, std::size_t n); + void on_read(system::error_code const& ec, std::size_t n); + void on_hello(system::error_code const& ec, generic_response const& resp); + void log(logger::level lvl, std::string_view msg); + void log(logger::level lvl, std::string_view op, system::error_code const& ec); + void trace(std::string_view message) { log(logger::level::debug, message); } + void trace(std::string_view op, system::error_code const& ec) + { + log(logger::level::debug, op, ec); + } +}; + +} // namespace boost::redis::detail + +#endif // BOOST_REDIS_LOGGER_HPP diff --git a/include/boost/redis/detail/health_checker.hpp b/include/boost/redis/detail/health_checker.hpp index ef90b875..ccb942f9 100644 --- a/include/boost/redis/detail/health_checker.hpp +++ b/include/boost/redis/detail/health_checker.hpp @@ -9,6 +9,7 @@ #include #include +#include #include #include #include @@ -20,16 +21,14 @@ #include #include -#include namespace boost::redis::detail { -template +template class ping_op { public: HealthChecker* checker_ = nullptr; Connection* conn_ = nullptr; - Logger logger_; asio::coroutine coro_{}; template @@ -38,7 +37,7 @@ public: BOOST_ASIO_CORO_REENTER(coro_) for (;;) { if (checker_->ping_interval_ == std::chrono::seconds::zero()) { - logger_.trace("ping_op (1): timeout disabled."); + conn_->logger_.trace("ping_op (1): timeout disabled."); BOOST_ASIO_CORO_YIELD asio::post(std::move(self)); self.complete({}); @@ -46,7 +45,7 @@ public: } if (checker_->checker_has_exited_) { - logger_.trace("ping_op (2): checker has exited."); + conn_->logger_.trace("ping_op (2): checker has exited."); self.complete({}); return; } @@ -54,7 +53,7 @@ public: BOOST_ASIO_CORO_YIELD conn_->async_exec(checker_->req_, any_adapter(checker_->resp_), std::move(self)); if (ec) { - logger_.trace("ping_op (3)", ec); + conn_->logger_.trace("ping_op (3)", ec); checker_->wait_timer_.cancel(); self.complete(ec); return; @@ -66,7 +65,7 @@ public: BOOST_ASIO_CORO_YIELD checker_->ping_timer_.async_wait(std::move(self)); if (ec) { - logger_.trace("ping_op (4)", ec); + conn_->logger_.trace("ping_op (4)", ec); self.complete(ec); return; } @@ -74,12 +73,11 @@ public: } }; -template +template class check_timeout_op { public: HealthChecker* checker_ = nullptr; Connection* conn_ = nullptr; - Logger logger_; asio::coroutine coro_{}; template @@ -88,7 +86,7 @@ public: BOOST_ASIO_CORO_REENTER(coro_) for (;;) { if (checker_->ping_interval_ == std::chrono::seconds::zero()) { - logger_.trace("check_timeout_op (1): timeout disabled."); + conn_->logger_.trace("check_timeout_op (1): timeout disabled."); BOOST_ASIO_CORO_YIELD asio::post(std::move(self)); self.complete({}); @@ -100,20 +98,20 @@ public: BOOST_ASIO_CORO_YIELD checker_->wait_timer_.async_wait(std::move(self)); if (ec) { - logger_.trace("check_timeout_op (2)", ec); + conn_->logger_.trace("check_timeout_op (2)", ec); self.complete(ec); return; } if (checker_->resp_.has_error()) { // TODO: Log the error. - logger_.trace("check_timeout_op (3): Response error."); + conn_->logger_.trace("check_timeout_op (3): Response error."); self.complete({}); return; } if (checker_->resp_.value().empty()) { - logger_.trace("check_timeout_op (4): pong timeout."); + conn_->logger_.trace("check_timeout_op (4): pong timeout."); checker_->ping_timer_.cancel(); conn_->cancel(operation::run); checker_->checker_has_exited_ = true; @@ -157,30 +155,30 @@ public: wait_timer_.cancel(); } - template - auto async_ping(Connection& conn, Logger l, CompletionToken token) + template + auto async_ping(Connection& conn, CompletionToken token) { return asio::async_compose( - ping_op{this, &conn, l}, + ping_op{this, &conn}, token, conn, ping_timer_); } - template - auto async_check_timeout(Connection& conn, Logger l, CompletionToken token) + template + auto async_check_timeout(Connection& conn, CompletionToken token) { checker_has_exited_ = false; return asio::async_compose( - check_timeout_op{this, &conn, l}, + check_timeout_op{this, &conn}, token, conn, wait_timer_); } private: - template friend class ping_op; - template friend class check_timeout_op; + template friend class ping_op; + template friend class check_timeout_op; timer_type ping_timer_; timer_type wait_timer_; diff --git a/include/boost/redis/detail/redis_stream.hpp b/include/boost/redis/detail/redis_stream.hpp index 33166cb4..e8590c70 100644 --- a/include/boost/redis/detail/redis_stream.hpp +++ b/include/boost/redis/detail/redis_stream.hpp @@ -8,6 +8,7 @@ #define BOOST_REDIS_REDIS_STREAM_HPP #include +#include #include #include @@ -67,11 +68,10 @@ class redis_stream { } } - template struct connect_op { redis_stream& obj; const config* cfg; - Logger lgr; + connection_logger* lgr; asio::coroutine coro{}; // This overload will be used for connects. We only need the endpoint @@ -82,7 +82,7 @@ class redis_stream { system::error_code ec, const asio::ip::tcp::endpoint& selected_endpoint) { - lgr.on_connect(ec, selected_endpoint); + lgr->on_connect(ec, selected_endpoint); (*this)(self, ec); } @@ -106,7 +106,7 @@ class redis_stream { asio::cancel_after(obj.timer_, cfg->connect_timeout, std::move(self))); // Log it - lgr.on_connect(ec, cfg->unix_socket); + lgr->on_connect(ec, cfg->unix_socket); // If this failed, we can't continue if (ec) { @@ -130,7 +130,7 @@ class redis_stream { asio::cancel_after(obj.timer_, cfg->resolve_timeout, std::move(self))); // Log it - lgr.on_resolve(ec, resolver_results); + lgr->on_resolve(ec, resolver_results); // If this failed, we can't continue if (ec) { @@ -162,7 +162,7 @@ class redis_stream { asio::ssl::stream_base::client, asio::cancel_after(obj.timer_, cfg->ssl_handshake_timeout, std::move(self))); - lgr.on_ssl_handshake(ec); + lgr->on_ssl_handshake(ec); // If this failed, we can't continue if (ec) { @@ -208,11 +208,11 @@ public: const auto& next_layer() const { return stream_; } // I/O - template - auto async_connect(const config* cfg, Logger l, CompletionToken&& token) + template + auto async_connect(const config* cfg, connection_logger* l, CompletionToken&& token) { return asio::async_compose( - connect_op{*this, cfg, l}, + connect_op{*this, cfg, l}, token); } diff --git a/include/boost/redis/detail/resp3_handshaker.hpp b/include/boost/redis/detail/resp3_handshaker.hpp index 6ce9a857..41949dfe 100644 --- a/include/boost/redis/detail/resp3_handshaker.hpp +++ b/include/boost/redis/detail/resp3_handshaker.hpp @@ -8,17 +8,15 @@ #define BOOST_REDIS_RUNNER_HPP #include +#include #include -#include #include #include #include #include #include -//#include -#include -#include + #include namespace boost::redis::detail { @@ -28,11 +26,10 @@ void push_hello(config const& cfg, request& req); // TODO: Can we avoid this whole function whose only purpose is to // check for an error in the hello response and complete with an error // so that the parallel group that starts it can exit? -template +template struct hello_op { Handshaker* handshaker_ = nullptr; Connection* conn_ = nullptr; - Logger logger_; asio::coroutine coro_{}; template @@ -47,7 +44,7 @@ struct hello_op { handshaker_->hello_req_, any_adapter(handshaker_->hello_resp_), std::move(self)); - logger_.on_hello(ec, handshaker_->hello_resp_); + conn_->logger_.on_hello(ec, handshaker_->hello_resp_); if (ec) { conn_->cancel(operation::run); @@ -71,17 +68,17 @@ class resp3_handshaker { public: void set_config(config const& cfg) { cfg_ = cfg; } - template - auto async_hello(Connection& conn, Logger l, CompletionToken token) + template + auto async_hello(Connection& conn, CompletionToken token) { return asio::async_compose( - hello_op{this, &conn, l}, + hello_op{this, &conn}, token, conn); } private: - template friend struct hello_op; + template friend struct hello_op; void add_hello() { diff --git a/include/boost/redis/impl/connection.ipp b/include/boost/redis/impl/connection.ipp index fc4008ad..088b1ac3 100644 --- a/include/boost/redis/impl/connection.ipp +++ b/include/boost/redis/impl/connection.ipp @@ -5,25 +5,42 @@ */ #include +#include #include +#include +#include +#include namespace boost::redis { -connection::connection(executor_type ex, asio::ssl::context ctx) -: impl_{ex, std::move(ctx)} -{ } +logger detail::make_stderr_logger(logger::level lvl, std::string prefix) +{ + return logger(lvl, [prefix = std::move(prefix)](logger::level, std::string_view msg) { + log_to_file(stderr, msg, prefix.c_str()); + }); +} -connection::connection(asio::io_context& ioc, asio::ssl::context ctx) -: impl_{ioc.get_executor(), std::move(ctx)} +connection::connection(executor_type ex, asio::ssl::context ctx, logger lgr) +: impl_{std::move(ex), std::move(ctx), std::move(lgr)} { } void connection::async_run_impl( config const& cfg, - logger l, + logger&& l, asio::any_completion_handler token) { - impl_.async_run(cfg, l, std::move(token)); + // Avoid calling the basic_connection::async_run overload taking a logger + // because it generates deprecated messages when building this file + impl_.set_stderr_logger(l.lvl, cfg); + impl_.async_run(cfg, std::move(token)); +} + +void connection::async_run_impl( + config const& cfg, + asio::any_completion_handler token) +{ + impl_.async_run(cfg, std::move(token)); } void connection::async_exec_impl( diff --git a/include/boost/redis/impl/connection_logger.ipp b/include/boost/redis/impl/connection_logger.ipp new file mode 100644 index 00000000..8610bc73 --- /dev/null +++ b/include/boost/redis/impl/connection_logger.ipp @@ -0,0 +1,183 @@ +/* Copyright (c) 2018-2024 Marcelo Zimbres Silva (mzimbres@gmail.com) + * + * Distributed under the Boost Software License, Version 1.0. (See + * accompanying file LICENSE.txt) + */ + +#include +#include + +#include +#include + +#include + +namespace boost::redis::detail { + +inline void format_tcp_endpoint(const asio::ip::tcp::endpoint& ep, std::string& to) +{ + // This formatting is inspired by Asio's endpoint operator<< + const auto& addr = ep.address(); + if (addr.is_v6()) + to += '['; + to += addr.to_string(); + if (addr.is_v6()) + to += ']'; + to += ':'; + to += std::to_string(ep.port()); +} + +inline void format_error_code(system::error_code ec, std::string& to) +{ + // Using error_code::what() includes any source code info + // that the error may contain, making the messages too long. + // This implementation was taken from error_code::what() + to += ec.message(); + to += " ["; + to += ec.to_string(); + to += ']'; +} + +void connection_logger::on_resolve( + system::error_code const& ec, + asio::ip::tcp::resolver::results_type const& res) +{ + if (logger_.lvl < logger::level::info) + return; + + if (ec) { + msg_ = "Error resolving the server hostname: "; + format_error_code(ec, msg_); + } else { + msg_ = "Resolve results: "; + auto iter = res.cbegin(); + auto end = res.cend(); + + if (iter != end) { + format_tcp_endpoint(iter->endpoint(), msg_); + ++iter; + for (; iter != end; ++iter) { + msg_ += ", "; + format_tcp_endpoint(iter->endpoint(), msg_); + } + } + } + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::on_connect(system::error_code const& ec, asio::ip::tcp::endpoint const& ep) +{ + if (logger_.lvl < logger::level::info) + return; + + if (ec) { + msg_ = "Failed connecting to the server: "; + format_error_code(ec, msg_); + } else { + msg_ = "Connected to "; + format_tcp_endpoint(ep, msg_); + } + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::on_connect(system::error_code const& ec, std::string_view unix_socket_ep) +{ + if (logger_.lvl < logger::level::info) + return; + + if (ec) { + msg_ = "Failed connecting to the server: "; + format_error_code(ec, msg_); + } else { + msg_ = "Connected to "; + msg_ += unix_socket_ep; + } + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::on_ssl_handshake(system::error_code const& ec) +{ + if (logger_.lvl < logger::level::info) + return; + + msg_ = "SSL handshake: "; + format_error_code(ec, msg_); + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::on_write(system::error_code const& ec, std::size_t n) +{ + if (logger_.lvl < logger::level::info) + return; + + msg_ = "writer_op: "; + if (ec) { + format_error_code(ec, msg_); + } else { + msg_ += std::to_string(n); + msg_ += " bytes written."; + } + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::on_read(system::error_code const& ec, std::size_t n) +{ + if (logger_.lvl < logger::level::info) + return; + + msg_ = "reader_op: "; + if (ec) { + format_error_code(ec, msg_); + } else { + msg_ += std::to_string(n); + msg_ += " bytes read."; + } + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::on_hello(system::error_code const& ec, generic_response const& resp) +{ + if (logger_.lvl < logger::level::info) + return; + + msg_ = "hello_op: "; + if (ec) { + format_error_code(ec, msg_); + if (resp.has_error()) { + msg_ += " ("; + msg_ += resp.error().diagnostic; + msg_ += ')'; + } + } else { + msg_ += "success"; + } + + logger_.fn(logger::level::info, msg_); +} + +void connection_logger::log(logger::level lvl, std::string_view message) +{ + if (logger_.lvl < lvl) + return; + logger_.fn(lvl, message); +} + +void connection_logger::log(logger::level lvl, std::string_view op, system::error_code const& ec) +{ + if (logger_.lvl < lvl) + return; + + msg_ = op; + msg_ += ": "; + format_error_code(ec, msg_); + + logger_.fn(lvl, msg_); +} + +} // namespace boost::redis::detail \ No newline at end of file diff --git a/include/boost/redis/impl/log_to_file.hpp b/include/boost/redis/impl/log_to_file.hpp new file mode 100644 index 00000000..a8d2102e --- /dev/null +++ b/include/boost/redis/impl/log_to_file.hpp @@ -0,0 +1,37 @@ +// +// Copyright (c) 2025 Marcelo Zimbres Silva (mzimbres@gmail.com), +// Ruben Perez Hidalgo (rubenperez038 at gmail dot com) +// +// Distributed under the Boost Software License, Version 1.0. (See accompanying +// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) +// + +#ifndef BOOST_REDIS_LOG_TO_STDERR_HPP +#define BOOST_REDIS_LOG_TO_STDERR_HPP + +#include +#include +#include +#include + +namespace boost::redis::detail { + +// Shared by several ipp files +inline void log_to_file(FILE* f, std::string_view msg, const char* prefix = "(Boost.Redis) ") +{ + // If the message is empty, data() might return a null pointer + const char* msg_ptr = msg.empty() ? "" : msg.data(); + + // Precision should be an int when passed to fprintf. Technically, + // message could be larger than INT_MAX. Impose a sane limit on message sizes + // to prevent memory problems + auto precision = static_cast((std::min)(msg.size(), static_cast(0xffffu))); + + // Log the message. None of our messages should contain NULL bytes, so this should be OK. + // We choose fprintf over std::clog because it's safe in multi-threaded environments. + std::fprintf(f, "%s%.*s\n", prefix, precision, msg_ptr); +} + +} // namespace boost::redis::detail + +#endif \ No newline at end of file diff --git a/include/boost/redis/impl/logger.ipp b/include/boost/redis/impl/logger.ipp index ad9260d2..fdbd9939 100644 --- a/include/boost/redis/impl/logger.ipp +++ b/include/boost/redis/impl/logger.ipp @@ -1,175 +1,24 @@ -/* Copyright (c) 2018-2024 Marcelo Zimbres Silva (mzimbres@gmail.com) - * - * Distributed under the Boost Software License, Version 1.0. (See - * accompanying file LICENSE.txt) - */ +// +// Copyright (c) 2025 Marcelo Zimbres Silva (mzimbres@gmail.com), +// Ruben Perez Hidalgo (rubenperez038 at gmail dot com) +// +// Distributed under the Boost Software License, Version 1.0. (See accompanying +// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) +// +#include #include -#include - -#include -#include +#include #include namespace boost::redis { -void logger::write_prefix() -{ - if (!std::empty(prefix_)) - std::clog << prefix_; -} - -void logger::on_resolve( - system::error_code const& ec, - asio::ip::tcp::resolver::results_type const& res) -{ - if (level_ < level::info) - return; - - write_prefix(); - - std::clog << "resolve results: "; - - if (ec) { - std::clog << ec.message() << std::endl; - } else { - auto begin = std::cbegin(res); - auto end = std::cend(res); - - if (begin == end) - return; - - std::clog << begin->endpoint(); - for (auto iter = std::next(begin); iter != end; ++iter) - std::clog << ", " << iter->endpoint(); - } - - std::clog << std::endl; -} - -void logger::on_connect(system::error_code const& ec, asio::ip::tcp::endpoint const& ep) -{ - if (level_ < level::info) - return; - - write_prefix(); - - std::clog << "connected to "; - - if (ec) - std::clog << ec.message() << std::endl; - else - std::clog << ep; - - std::clog << std::endl; -} - -#ifdef BOOST_ASIO_HAS_LOCAL_SOCKETS -void logger::on_connect(system::error_code const& ec, std::string_view unix_socket_ep) -{ - if (level_ < level::info) - return; - - write_prefix(); - - std::clog << "connected to "; - - if (ec) - std::clog << ec.message() << std::endl; - else - std::clog << unix_socket_ep; - - std::clog << std::endl; -} -#endif - -void logger::on_ssl_handshake(system::error_code const& ec) -{ - if (level_ < level::info) - return; - - write_prefix(); - - std::clog << "SSL handshake: " << ec.message() << std::endl; -} - -void logger::on_write(system::error_code const& ec, std::string_view payload) -{ - if (level_ < level::info) - return; - - write_prefix(); - - if (ec) - std::clog << "writer_op: " << ec.message(); - else - std::clog << "writer_op: " << std::size(payload) << " bytes written."; - - std::clog << std::endl; -} - -void logger::on_read(system::error_code const& ec, std::size_t n) -{ - if (level_ < level::info) - return; - - write_prefix(); - - if (ec) - std::clog << "reader_op: " << ec.message(); - else - std::clog << "reader_op: " << n << " bytes read."; - - std::clog << std::endl; -} - -void logger::on_hello(system::error_code const& ec, generic_response const& resp) -{ - if (level_ < level::info) - return; - - write_prefix(); - - if (ec) { - std::clog << "hello_op: " << ec.message(); - if (resp.has_error()) - std::clog << " (" << resp.error().diagnostic << ")"; - } else { - std::clog << "hello_op: Success"; - } - - std::clog << std::endl; -} - -void logger::trace(std::string_view message) -{ - if (level_ < level::debug) - return; - - write_prefix(); - - std::clog << message << std::endl; -} - -void logger::trace(std::string_view op, system::error_code const& ec) -{ - if (level_ < level::debug) - return; - - write_prefix(); - - std::clog << op << ": " << ec.message() << std::endl; -} - -void logger::log_error(std::string_view op, system::error_code const& ec) -{ - if (level_ < level::err) - return; - - write_prefix(); - - std::clog << op << ": " << ec.message() << std::endl; -} +logger::logger(level l) +: lvl{l} +, fn{[](level, std::string_view msg) { + detail::log_to_file(stderr, msg); +}} +{ } } // namespace boost::redis diff --git a/include/boost/redis/logger.hpp b/include/boost/redis/logger.hpp index fae108b9..70f46b53 100644 --- a/include/boost/redis/logger.hpp +++ b/include/boost/redis/logger.hpp @@ -7,30 +7,17 @@ #ifndef BOOST_REDIS_LOGGER_HPP #define BOOST_REDIS_LOGGER_HPP -#include - -#include - -#include +#include #include -namespace boost::system { -class error_code; -} - namespace boost::redis { -/** @brief Logger class +/** @brief Defines logging configuration * @ingroup high-level-api * - * The class can be passed to the connection objects to log to `std::clog` - * - * Notice that currently this class has no stable interface. Users - * that don't want any logging can disable it by contructing a logger - * with logger::level::emerg to the connection. + * See the member descriptions for more info. */ -class logger { -public: +struct logger { /** @brief Syslog-like log levels * @ingroup high-level-api */ @@ -61,83 +48,51 @@ public: info, /// Debug - debug + debug, }; - /** @brief Constructor - * @ingroup high-level-api + /** @brief Constructor from a level. * - * @param l Log level. + * Constructs a logger with the specified level + * and a logging function that prints messages to stderr. + * + * @param l The value to set @ref lvl to. + * + * @par Exceptions + * No-throw guarantee. */ - logger(level l = level::debug) - : level_{l} + logger(level l = level::info); + + /** @brief Constructor from a level and a function. + * + * Constructs a logger by setting its members to the specified values. + * + * @param l The value to set @ref lvl to. + * @param fn The value to set @ref fn to. + * + * @par Exceptions + * No-throw guarantee. + */ + logger(level l, std::function fn) + : lvl{l} + , fn{std::move(fn)} { } - /** @brief Called when the resolve operation completes. - * @ingroup high-level-api + /** + * @brief Defines a severity filter for messages. * - * @param ec Error returned by the resolve operation. - * @param res Resolve results. + * Only messages with a level >= to the one specified by the logger + * will be logged. */ - void on_resolve(system::error_code const& ec, asio::ip::tcp::resolver::results_type const& res); + level lvl; - /** @brief Called when the connect operation completes. - * @ingroup high-level-api + /** + * @brief Defines a severity filter for messages. * - * @param ec Error returned by the connect operation. - * @param ep Endpoint to which the connection connected. + * Only messages with a level >= to the one specified by the logger + * will be logged. */ - void on_connect(system::error_code const& ec, asio::ip::tcp::endpoint const& ep); -#ifdef BOOST_ASIO_HAS_LOCAL_SOCKETS - void on_connect(system::error_code const& ec, std::string_view unix_socket_ep); -#endif - - /** @brief Called when the ssl handshake operation completes. - * @ingroup high-level-api - * - * @param ec Error returned by the handshake operation. - */ - void on_ssl_handshake(system::error_code const& ec); - - /** @brief Called when the write operation completes. - * @ingroup high-level-api - * - * @param ec Error code returned by the write operation. - * @param payload The payload written to the socket. - */ - void on_write(system::error_code const& ec, std::string_view payload); - - /** @brief Called when the read operation completes. - * @ingroup high-level-api - * - * @param ec Error code returned by the read operation. - * @param n Number of bytes read. - */ - void on_read(system::error_code const& ec, std::size_t n); - - /** @brief Called when the `HELLO` request completes. - * @ingroup high-level-api - * - * @param ec Error code returned by the async_exec operation. - * @param resp Response sent by the Redis server. - */ - void on_hello(system::error_code const& ec, generic_response const& resp); - - /** @brief Sets a prefix to every log message - * @ingroup high-level-api - * - * @param prefix The prefix. - */ - void set_prefix(std::string_view prefix) { prefix_ = prefix; } - - void trace(std::string_view message); - void trace(std::string_view op, system::error_code const& ec); - void log_error(std::string_view op, system::error_code const& ec); - -private: - void write_prefix(); - level level_; - std::string prefix_; + std::function fn; }; } // namespace boost::redis diff --git a/include/boost/redis/src.hpp b/include/boost/redis/src.hpp index 86d92285..687cb3ca 100644 --- a/include/boost/redis/src.hpp +++ b/include/boost/redis/src.hpp @@ -5,6 +5,7 @@ */ #include +#include #include #include #include diff --git a/test/CMakeLists.txt b/test/CMakeLists.txt index 729ef977..ae31f0a2 100644 --- a/test/CMakeLists.txt +++ b/test/CMakeLists.txt @@ -5,11 +5,10 @@ target_link_libraries(boost_redis_project_options INTERFACE boost_redis) if (MSVC) # C4459: name hides outer scope variable is issued by Asio target_compile_options(boost_redis_project_options INTERFACE /bigobj /W4 /WX /wd4459) - target_compile_definitions(boost_redis_project_options INTERFACE _WIN32_WINNT=0x0601) + target_compile_definitions(boost_redis_project_options INTERFACE _WIN32_WINNT=0x0601 _CRT_SECURE_NO_WARNINGS=1) elseif(CMAKE_CXX_COMPILER_ID STREQUAL "Clang" OR CMAKE_CXX_COMPILER_ID STREQUAL "GNU") target_compile_options(boost_redis_project_options INTERFACE -Wall -Wextra -Werror) endif() -target_compile_definitions(boost_redis_project_options INTERFACE BOOST_ALLOW_DEPRECATED=1) # we need to still test deprecated fns add_library(boost_redis_src STATIC boost_redis.cpp) target_compile_features(boost_redis_src PRIVATE cxx_std_17) @@ -29,6 +28,7 @@ macro(make_test TEST_NAME) boost_redis_project_options Boost::unit_test_framework ) + target_compile_definitions(${EXE_NAME} PRIVATE BOOST_ALLOW_DEPRECATED=1) # we need to still test deprecated fns add_test(${EXE_NAME} ${EXE_NAME}) endmacro() @@ -38,6 +38,8 @@ make_test(test_request) make_test(test_low_level_sync_sans_io) make_test(test_any_adapter) make_test(test_exec_fsm) +make_test(test_log_to_file) +make_test(test_conn_logging) # Tests that require a real Redis server make_test(test_conn_quit) diff --git a/test/Jamfile b/test/Jamfile index 5f75e38e..311d1ed5 100644 --- a/test/Jamfile +++ b/test/Jamfile @@ -14,7 +14,8 @@ local requirements = BOOST_ASIO_DISABLE_BOOST_BIND=1 BOOST_ASIO_DISABLE_BOOST_DATE_TIME=1 BOOST_ASIO_DISABLE_BOOST_REGEX=1 - BOOST_ALLOW_DEPRECATED=1 # we need to test deprecated fns + BOOST_ALLOW_DEPRECATED=1 # we need to test deprecated fns + _CRT_SECURE_NO_WARNINGS=1 # suppress MSVC warnings msvc:"/bigobj" windows:_WIN32_WINNT=0x0601 [ requires @@ -53,6 +54,8 @@ local tests = test_low_level_sync_sans_io test_any_adapter test_exec_fsm + test_log_to_file + test_conn_logging ; # Build and run the tests diff --git a/test/common.cpp b/test/common.cpp index 649cbb89..ceb6b35f 100644 --- a/test/common.cpp +++ b/test/common.cpp @@ -25,10 +25,9 @@ void run( std::shared_ptr conn, boost::redis::config cfg, boost::system::error_code ec, - boost::redis::operation op, - boost::redis::logger::level l) + boost::redis::operation op) { - conn->async_run(cfg, {l}, run_callback{conn, op, ec}); + conn->async_run(cfg, run_callback{conn, op, ec}); } static std::string safe_getenv(const char* name, const char* default_value) diff --git a/test/common.hpp b/test/common.hpp index 6cd51c31..b322dc54 100644 --- a/test/common.hpp +++ b/test/common.hpp @@ -33,5 +33,4 @@ void run( std::shared_ptr conn, boost::redis::config cfg = make_test_config(), boost::system::error_code ec = boost::asio::error::operation_aborted, - boost::redis::operation op = boost::redis::operation::receive, - boost::redis::logger::level l = boost::redis::logger::level::debug); + boost::redis::operation op = boost::redis::operation::receive); diff --git a/test/test_conn_logging.cpp b/test/test_conn_logging.cpp new file mode 100644 index 00000000..ab67155e --- /dev/null +++ b/test/test_conn_logging.cpp @@ -0,0 +1,159 @@ +// +// Copyright (c) 2025 Marcelo Zimbres Silva (mzimbres@gmail.com), +// Ruben Perez Hidalgo (rubenperez038 at gmail dot com) +// +// Distributed under the Boost Software License, Version 1.0. (See accompanying +// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) +// + +#include +#include +#include + +#include +#include +#include +#include + +#include "common.hpp" + +#include +#include +#include +#include + +using boost::system::error_code; +namespace net = boost::asio; +using namespace boost::redis; + +namespace { + +// user tests +// logging can be disabled +// logging can be changed verbosity + +template +void run_with_invalid_config(net::io_context& ioc, Conn& conn) +{ + config cfg; + cfg.use_ssl = true; + cfg.unix_socket = "/tmp/sock"; + conn.async_run(cfg, [](error_code ec) { + BOOST_TEST_NE(ec, error_code()); + }); + ioc.run_for(test_timeout); +} + +template +void test_connection_constructor_executor_1() +{ + // Setup + net::io_context ioc; + std::vector messages; + logger lgr(logger::level::info, [&](logger::level, std::string_view msg) { + messages.emplace_back(msg); + }); + Conn conn{ioc.get_executor(), std::move(lgr)}; + + // Produce some logging + run_with_invalid_config(ioc, conn); + + // Some logging was produced + BOOST_TEST_EQ(messages.size(), 1u); +} + +template +void test_connection_constructor_context_1() +{ + // Setup + net::io_context ioc; + std::vector messages; + logger lgr(logger::level::info, [&](logger::level, std::string_view msg) { + messages.emplace_back(msg); + }); + Conn conn{ioc, std::move(lgr)}; + + // Produce some logging + run_with_invalid_config(ioc, conn); + + // Some logging was produced + BOOST_TEST_EQ(messages.size(), 1u); +} + +template +void test_connection_constructor_executor_2() +{ + // Setup + net::io_context ioc; + std::vector messages; + logger lgr(logger::level::info, [&](logger::level, std::string_view msg) { + messages.emplace_back(msg); + }); + Conn conn{ + ioc.get_executor(), + net::ssl::context{net::ssl::context::tlsv12_client}, + std::move(lgr)}; + + // Produce some logging + run_with_invalid_config(ioc, conn); + + // Some logging was produced + BOOST_TEST_EQ(messages.size(), 1u); +} + +template +void test_connection_constructor_context_2() +{ + // Setup + net::io_context ioc; + std::vector messages; + logger lgr(logger::level::info, [&](logger::level, std::string_view msg) { + messages.emplace_back(msg); + }); + Conn conn{ioc, net::ssl::context{net::ssl::context::tlsv12_client}, std::move(lgr)}; + + // Produce some logging + run_with_invalid_config(ioc, conn); + + // Some logging was produced + BOOST_TEST_EQ(messages.size(), 1u); +} + +void test_disable_logging() +{ + // Setup + net::io_context ioc; + std::vector messages; + logger lgr(logger::level::disabled, [&](logger::level, std::string_view msg) { + messages.emplace_back(msg); + }); + connection conn{ioc, std::move(lgr)}; + + // Produce some logging + run_with_invalid_config(ioc, conn); + + // Some logging was produced + BOOST_TEST_EQ(messages.size(), 0u); +} + +} // namespace + +int main() +{ + // basic_connection + using basic_conn_t = basic_connection; + test_connection_constructor_executor_1(); + test_connection_constructor_executor_2(); + test_connection_constructor_context_1(); + test_connection_constructor_context_2(); + + // connection + test_connection_constructor_executor_1(); + test_connection_constructor_executor_2(); + test_connection_constructor_context_1(); + test_connection_constructor_context_2(); + + test_disable_logging(); + + return boost::report_errors(); +} diff --git a/test/test_log_to_file.cpp b/test/test_log_to_file.cpp new file mode 100644 index 00000000..887804c1 --- /dev/null +++ b/test/test_log_to_file.cpp @@ -0,0 +1,123 @@ +// +// Copyright (c) 2025 Marcelo Zimbres Silva (mzimbres@gmail.com), +// Ruben Perez Hidalgo (rubenperez038 at gmail dot com) +// +// Distributed under the Boost Software License, Version 1.0. (See accompanying +// file LICENSE_1_0.txt or copy at http://www.boost.org/LICENSE_1_0.txt) +// + +#include + +#include + +#include +#include +#include +#include +#include +#include + +using namespace boost::redis; + +namespace { + +// RAII helpers for working with C FILE* +struct file_deleter { + void operator()(FILE* f) const { std::fclose(f); } +}; +using unique_file = std::unique_ptr; + +unique_file create_temporary() +{ + unique_file f{std::tmpfile()}; + if (!BOOST_TEST_NE(f.get(), nullptr)) + exit(1); + return f; +} + +std::string get_file_contents(FILE* f) +{ + if (!BOOST_TEST_EQ(std::fseek(f, 0, SEEK_END), 0)) + exit(1); + long fsize = std::ftell(f); + if (!BOOST_TEST_GE(fsize, 0)) + exit(1); + std::rewind(f); + std::string res(fsize, 0); + if (!BOOST_TEST_EQ(std::fread(res.data(), 1u, res.size(), f), fsize)) + exit(1); + return res; +} + +void test_regular() +{ + auto f = create_temporary(); + detail::log_to_file(f.get(), "something happened"); + BOOST_TEST_EQ(get_file_contents(f.get()), "(Boost.Redis) something happened\n"); +} + +void test_empty_message() +{ + auto f = create_temporary(); + detail::log_to_file(f.get(), {}); + BOOST_TEST_EQ(get_file_contents(f.get()), "(Boost.Redis) \n"); +} + +void test_empty_prefix() +{ + auto f = create_temporary(); + detail::log_to_file(f.get(), {}, ""); + BOOST_TEST_EQ(get_file_contents(f.get()), "\n"); +} + +void test_message_not_null_terminated() +{ + constexpr std::string_view str = "some_string"; + auto f = create_temporary(); + detail::log_to_file(f.get(), str.substr(0, 4)); + BOOST_TEST_EQ(get_file_contents(f.get()), "(Boost.Redis) some\n"); +} + +// NULL bytes don't cause UB. None of our messages have +// them, so this is an edge case +void test_message_null_bytes() +{ + char buff[] = {'a', 'b', 'c', 0, 'l', 0}; + auto f = create_temporary(); + detail::log_to_file(f.get(), std::string_view(buff, sizeof(buff))); + BOOST_TEST_EQ(get_file_contents(f.get()), "(Boost.Redis) abc\n"); +} + +// Internally, sizes are converted to int because of C APIs. Check that this +// does not cause trouble. We impose a sanity limit of 0xffff bytes for all messages +void test_message_very_long() +{ + // Setup. Allocating a string of size INT_MAX causes trouble, so we pass a string_view + // with that size, but with only the first 0xffff bytes being valid + std::string msg(0xffffu + 1u, 'a'); + const auto msg_size = static_cast((std::numeric_limits::max)()) + 1u; + auto f = create_temporary(); + + // Log + detail::log_to_file(f.get(), std::string_view(msg.data(), msg_size)); + + // Check + std::string expected = "(Boost.Redis) "; + expected += std::string_view(msg.data(), 0xffffu); + expected += '\n'; + BOOST_TEST_EQ(get_file_contents(f.get()), expected); +} + +} // namespace + +int main() +{ + test_regular(); + test_empty_message(); + test_empty_prefix(); + test_message_not_null_terminated(); + test_message_null_bytes(); + test_message_very_long(); + + return boost::report_errors(); +}