Skip to content

Commit

Permalink
Improvements in logging.
Browse files Browse the repository at this point in the history
  • Loading branch information
@mzimbres
mzimbres committed Nov 24, 2024
1 parent 59725ba commit 74312db
Show file tree
Hide file tree
Showing 8 changed files with 49 additions and 136 deletions.
28 changes: 11 additions & 17 deletions include/boost/redis/detail/connection_base.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -199,34 +199,28 @@ struct writer_op {
logger_.on_write(ec, conn_->write_buffer_);

if (ec) {
logger_.trace("writer-op: error. Exiting ...");
logger_.trace("writer_op (1)", ec);
conn_->cancel(operation::run);
self.complete(ec);
return;
}

if (is_cancelled(self)) {
logger_.trace("writer-op: canceled. Exiting ...");
self.complete(asio::error::operation_aborted);
return;
}

conn_->on_write();

// A socket.close() may have been called while a
// successful write might had already been queued, so we
// have to check here before proceeding.
if (!conn_->is_open()) {
logger_.trace("writer-op: canceled (2). Exiting ...");
logger_.trace("writer_op (2): connection is closed.");
self.complete({});
return;
}
}

BOOST_ASIO_CORO_YIELD
conn_->writer_timer_.async_wait(std::move(self));
if (!conn_->is_open() || is_cancelled(self)) {
logger_.trace("writer-op: canceled (3). Exiting ...");
if (!conn_->is_open()) {
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.
Expand Down Expand Up @@ -277,7 +271,7 @@ struct reader_op {

// The connection is not viable after an error.
if (ec) {
logger_.trace("reader-op: error. Exiting ...");
logger_.trace("reader_op (1)", ec);
conn_->cancel(operation::run);
self.complete(ec);
return;
Expand All @@ -286,16 +280,16 @@ struct reader_op {
// Somebody might have canceled implicitly or explicitly
// while we were suspended and after queueing so we have to
// check.
if (!conn_->is_open() || is_cancelled(self)) {
logger_.trace("reader-op: canceled. Exiting ...");
if (!conn_->is_open()) {
logger_.trace("reader_op (2): connection is closed.");
self.complete(ec);
return;
}
}

res_ = conn_->on_read(buffer_view(conn_->dbuf_), ec);
if (ec) {
logger_.trace("reader-op: parse error. Exiting ...");
logger_.trace("reader_op (3)", ec);
conn_->cancel(operation::run);
self.complete(ec);
return;
Expand All @@ -308,14 +302,14 @@ struct reader_op {
}

if (ec) {
logger_.trace("reader-op: error. Exiting ...");
logger_.trace("reader_op (4)", ec);
conn_->cancel(operation::run);
self.complete(ec);
return;
}

if (!conn_->is_open() || is_cancelled(self)) {
logger_.trace("reader-op: canceled (2). Exiting ...");
if (!conn_->is_open()) {
logger_.trace("reader_op (5): connection is closed.");
self.complete(asio::error::operation_aborted);
return;
}
Expand Down
18 changes: 10 additions & 8 deletions include/boost/redis/detail/health_checker.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,34 +34,35 @@ class ping_op {
BOOST_ASIO_CORO_REENTER (coro_) for (;;)
{
if (checker_->ping_interval_ == std::chrono::seconds::zero()) {
logger_.trace("ping-op: timeout disabled. Exiting ...");
logger_.trace("ping_op: timeout disabled.");
BOOST_ASIO_CORO_YIELD
asio::post(std::move(self));
self.complete({});
return;
}

if (checker_->checker_has_exited_) {
logger_.trace("ping_op: checker has exited. Exiting ...");
logger_.trace("ping_op: checker has exited.");
self.complete({});
return;
}

BOOST_ASIO_CORO_YIELD
conn_->async_exec(checker_->req_, checker_->resp_, std::move(self));
if (ec) {
logger_.trace("ping_op: error/cancelled (1).");
logger_.trace("ping_op (exec)", ec);
checker_->wait_timer_.cancel();
self.complete(ec);
return;
}

// Wait before pinging again.
checker_->ping_timer_.expires_after(checker_->ping_interval_);

BOOST_ASIO_CORO_YIELD
checker_->ping_timer_.async_wait(std::move(self));
if (ec) {
logger_.trace("ping_op: error/cancelled (2).");
logger_.trace("ping_op (wait)", ec);
self.complete(ec);
return;
}
Expand All @@ -83,30 +84,31 @@ class check_timeout_op {
BOOST_ASIO_CORO_REENTER (coro_) for (;;)
{
if (checker_->ping_interval_ == std::chrono::seconds::zero()) {
logger_.trace("check-timeout-op: timeout disabled. Exiting ...");
logger_.trace("check_timeout_op: timeout disabled.");
BOOST_ASIO_CORO_YIELD
asio::post(std::move(self));
self.complete({});
return;
}

checker_->wait_timer_.expires_after(2 * checker_->ping_interval_);

BOOST_ASIO_CORO_YIELD
checker_->wait_timer_.async_wait(std::move(self));
if (ec) {
logger_.trace("check-timeout-op: error/canceled. Exiting ...");
logger_.trace("check_timeout_op (async_wait)", ec);
self.complete(ec);
return;
}

if (checker_->resp_.has_error()) {
logger_.trace("check-timeout-op: Response error. Exiting ...");
logger_.trace("check_timeout_op: Response error.");
self.complete({});
return;
}

if (checker_->resp_.value().empty()) {
logger_.trace("check-timeout-op: Response has no value. Exiting ...");
logger_.trace("check_timeout_op: pong timeout.");
checker_->ping_timer_.cancel();
conn_->cancel(operation::run);
checker_->checker_has_exited_ = true;
Expand Down
15 changes: 7 additions & 8 deletions include/boost/redis/detail/runner.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,13 +50,18 @@ struct hello_op {
conn_->async_exec(runner_->hello_req_, runner_->hello_resp_, std::move(self));
logger_.on_hello(ec, runner_->hello_resp_);

if (ec || runner_->has_error_in_response()) {
logger_.trace("hello-op: error/canceled. Exiting ...");
if (ec) {
conn_->cancel(operation::run);
self.complete(ec);
return;
}

if (runner_->has_error_in_response()) {
conn_->cancel(operation::run);
self.complete(error::resp3_hello);
return;
}

self.complete({});
}
}
Expand Down Expand Up @@ -143,12 +148,6 @@ class runner_op {
asio::experimental::wait_for_one_error(),
std::move(self));

// TODO: Unify these lines.
logger_.on_check_health(ec1, ec2);
logger_.on_run(ec0, ec1);
logger_.on_runner(ec0, ec1, ec2);
logger_.on_connection_lost({});

if (order[0] == 0 && !!ec0) {
self.complete(ec0);
return;
Expand Down
3 changes: 3 additions & 0 deletions include/boost/redis/error.hpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -81,6 +81,9 @@ enum class error

/// Incompatible node depth.
incompatible_node_depth,

/// Resp3 hello command error
resp3_hello,
};

/** \internal
Expand Down
1 change: 1 addition & 0 deletions include/boost/redis/impl/error.ipp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,7 @@ struct error_category_impl : system::error_category {
case error::ssl_handshake_timeout: return "SSL handshake timeout.";
case error::sync_receive_push_failed: return "Can't receive server push synchronously without blocking.";
case error::incompatible_node_depth: return "Incompatible node depth.";
case error::resp3_hello: return "RESP3 handshake error (hello command).";
default: BOOST_ASSERT(false); return "Boost.Redis error.";
}
}
Expand Down
83 changes: 14 additions & 69 deletions include/boost/redis/impl/logger.ipp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@ void logger::on_resolve(system::error_code const& ec, asio::ip::tcp::resolver::r

write_prefix();

std::clog << "run-all-op: resolve addresses ";
std::clog << "resolve results: ";

if (ec) {
std::clog << ec.message() << std::endl;
Expand All @@ -51,7 +51,7 @@ void logger::on_connect(system::error_code const& ec, asio::ip::tcp::endpoint co

write_prefix();

std::clog << "run-all-op: connected to endpoint ";
std::clog << "connected to ";

if (ec)
std::clog << ec.message() << std::endl;
Expand All @@ -68,22 +68,7 @@ void logger::on_ssl_handshake(system::error_code const& ec)

write_prefix();

std::clog << "Runner: SSL handshake " << ec.message() << std::endl;
}

void logger::on_connection_lost(system::error_code const& ec)
{
if (level_ < level::info)
return;

write_prefix();

if (ec)
std::clog << "Connection lost: " << ec.message();
else
std::clog << "Connection lost.";

std::clog << std::endl;
std::clog << "SSL handshake: " << ec.message() << std::endl;
}

void
Expand All @@ -97,9 +82,9 @@ logger::on_write(
write_prefix();

if (ec)
std::clog << "writer-op: " << ec.message();
std::clog << "writer_op: " << ec.message();
else
std::clog << "writer-op: " << std::size(payload) << " bytes written.";
std::clog << "writer_op: " << std::size(payload) << " bytes written.";

std::clog << std::endl;
}
Expand All @@ -112,23 +97,9 @@ void logger::on_read(system::error_code const& ec, std::size_t n)
write_prefix();

if (ec)
std::clog << "reader-op: " << ec.message();
std::clog << "reader_op: " << ec.message();
else
std::clog << "reader-op: " << n << " bytes read.";

std::clog << std::endl;
}

void logger::on_run(system::error_code const& reader_ec, system::error_code const& writer_ec)
{
if (level_ < level::info)
return;

write_prefix();

std::clog << "run-op: "
<< reader_ec.message() << " (reader), "
<< writer_ec.message() << " (writer)";
std::clog << "reader_op: " << n << " bytes read.";

std::clog << std::endl;
}
Expand All @@ -144,60 +115,34 @@ logger::on_hello(
write_prefix();

if (ec) {
std::clog << "hello-op: " << ec.message();
std::clog << "hello_op: " << ec.message();
if (resp.has_error())
std::clog << " (" << resp.error().diagnostic << ")";
} else {
std::clog << "hello-op: Success";
std::clog << "hello_op: Success";
}

std::clog << std::endl;
}

void
logger::on_runner(
system::error_code const& hello,
system::error_code const& check_health,
system::error_code const& run)
void logger::trace(std::string_view message)
{
if (level_ < level::info)
return;

write_prefix();

std::clog << "hello: "
<< hello.message() << " (async_hello), "
<< check_health.message() << " (async_check_health) "
<< run.message() << " (async_run_lean).";

std::clog << std::endl;
}

void
logger::on_check_health(
system::error_code const& ping_ec,
system::error_code const& timeout_ec)
{
if (level_ < level::info)
if (level_ < level::debug)
return;

write_prefix();

std::clog << "check-health-op: "
<< ping_ec.message() << " (async_ping), "
<< timeout_ec.message() << " (async_check_timeout).";

std::clog << std::endl;
std::clog << message << std::endl;
}

void logger::trace(std::string_view reason)
void logger::trace(std::string_view op, system::error_code const& ec)
{
if (level_ < level::debug)
return;

write_prefix();

std::clog << reason << std::endl;
std::clog << op << ": " << ec.message() << std::endl;
}

} // boost::redis
Loading

0 comments on commit 74312db

Please sign in to comment.