Skip to content

Commit

Permalink
Handle exceptions in async sink
Browse files Browse the repository at this point in the history
  • Loading branch information
gabime committed Jan 4, 2025
1 parent 0d780b0 commit 833bb36
Show file tree
Hide file tree
Showing 5 changed files with 60 additions and 11 deletions.
3 changes: 1 addition & 2 deletions include/spdlog/logger.h
Original file line number Diff line number Diff line change
Expand Up @@ -209,8 +209,7 @@ class SPDLOG_API logger {
void flush_();
[[nodiscard]] bool should_flush_(const details::log_msg &msg) const;

// handle errors during logging.
// default handler prints the error to stderr at max rate of 1 message/sec.
// default handler prints the error to stderr
void err_handler_(const std::string &msg);
};

Expand Down
7 changes: 4 additions & 3 deletions include/spdlog/sinks/async_sink.h
Original file line number Diff line number Diff line change
Expand Up @@ -70,9 +70,10 @@ class SPDLOG_API async_sink final : public sink {
using queue_t = details::mpmc_blocking_queue<async_log_msg>;

void send_message_(async_log_msg::type msg_type, const details::log_msg &msg) const;
void backend_loop_() const;
void backend_log_(const details::log_msg &msg) const;
void backend_flush_() const;
void backend_loop_();
void backend_log_(const details::log_msg &msg) ;
void backend_flush_();
void err_handler_(const std::string &msg);

config config_;
std::unique_ptr<queue_t> q_;
Expand Down
32 changes: 27 additions & 5 deletions src/sinks/async_sink.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,7 @@ void async_sink::send_message_(async_log_msg::type msg_type, const details::log_
}
}

void async_sink::backend_loop_() const {
void async_sink::backend_loop_() {
details::async_log_msg incoming_msg;
for (;;) {
q_->dequeue(incoming_msg);
Expand All @@ -101,19 +101,41 @@ void async_sink::backend_loop_() const {
}
}

void async_sink::backend_log_(const details::log_msg &msg) const {
void async_sink::backend_log_(const details::log_msg &msg) {
for (const auto &sink : config_.sinks) {
if (sink->should_log(msg.log_level)) {
sink->log(msg);
try {
sink->log(msg);
} catch (const std::exception &ex) {
err_handler_(std::string("async log failed: ") + ex.what());
}
}
}
}

void async_sink::backend_flush_() const {
void async_sink::backend_flush_() {
for (const auto &sink : config_.sinks) {
sink->flush();
try {
sink->flush();
} catch (const std::exception &ex) {
err_handler_(std::string("async flush failed: ") + ex.what());
} catch (...) {
err_handler_("Async flush failed with unknown exception");
}
}
}
void async_sink::err_handler_(const std::string &message) {
using std::chrono::system_clock;
const auto now = system_clock::now();
const auto tm_time = details::os::localtime(system_clock::to_time_t(now));
char date_buf[64];
std::strftime(date_buf, sizeof(date_buf), "%Y-%m-%d %H:%M:%S", &tm_time);
#if defined(USING_R) && defined(R_R_H) // if in R environment
REprintf("[*** LOG ERROR ***] [%s] [%s] %s\n", date_buf, name().c_str(), message.c_str());
#else
std::fprintf(stderr, "[*** LOG ERROR ***] [%s] %s\n", date_buf, message.c_str());
#endif
}

} // namespace sinks
} // namespace spdlog
9 changes: 9 additions & 0 deletions tests/test_async.cpp
Original file line number Diff line number Diff line change
Expand Up @@ -286,3 +286,12 @@ TEST_CASE("level-off", "[async]") {
REQUIRE(test_sink->msg_counter() == 0);
REQUIRE(test_sink->flush_counter() == 0);
}

TEST_CASE("backend_ex", "[async]") {
const auto test_sink = std::make_shared<test_sink_mt>();
test_sink->set_exception(std::runtime_error("test backend exception"));
constexpr size_t queue_size = 16;
auto [logger, async_sink] = creat_async_logger(queue_size, test_sink);
REQUIRE_NOTHROW(logger->info("Hello message"));
REQUIRE_NOTHROW(logger->flush());
}
20 changes: 19 additions & 1 deletion tests/test_sink.h
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
#include <chrono>
#include <mutex>
#include <thread>
#include <exception>

#include "spdlog/details/null_mutex.h"
#include "spdlog/details/os.h"
Expand Down Expand Up @@ -36,6 +37,14 @@ class test_sink : public base_sink<Mutex> {
delay_ = delay;
}

void set_exception(const std::runtime_error& ex) {
exception_ptr_ = std::make_exception_ptr(ex);
}

void clear_exception() {
exception_ptr_ = nullptr;
}

// return last output without the eol
std::vector<std::string> lines() {
std::lock_guard<Mutex> lock(base_sink<Mutex>::mutex_);
Expand All @@ -44,6 +53,9 @@ class test_sink : public base_sink<Mutex> {

protected:
void sink_it_(const details::log_msg &msg) override {
if (exception_ptr_) {
std::rethrow_exception(exception_ptr_);
}
memory_buf_t formatted;
base_sink<Mutex>::formatter_->format(msg, formatted);
// save the line without the eol
Expand All @@ -55,12 +67,18 @@ class test_sink : public base_sink<Mutex> {
std::this_thread::sleep_for(delay_);
}

void flush_() override { flush_counter_++; }
void flush_() override {
if (exception_ptr_) {
std::rethrow_exception(exception_ptr_);
}
flush_counter_++;
}

size_t msg_counter_{0};
size_t flush_counter_{0};
std::chrono::milliseconds delay_{std::chrono::milliseconds::zero()};
std::vector<std::string> lines_;
std::exception_ptr exception_ptr_; // will be thrown on next log or flush if not null
};

using test_sink_mt = test_sink<std::mutex>;
Expand Down

0 comments on commit 833bb36

Please sign in to comment.