wip async sink

This commit is contained in:
gabime 2024-12-07 13:54:40 +02:00
parent a00229eaa5
commit 07c697f4f5
9 changed files with 232 additions and 432 deletions

View File

@ -153,7 +153,7 @@ set(SPDLOG_HEADERS
"include/spdlog/details/file_helper.h"
"include/spdlog/details/fmt_helper.h"
"include/spdlog/details/log_msg.h"
"include/spdlog/details/log_msg_buffer.h"
"include/spdlog/details/async_log_msg.h"
"include/spdlog/details/mpmc_blocking_q.h"
"include/spdlog/details/null_mutex.h"
"include/spdlog/details/os.h"
@ -192,7 +192,7 @@ set(SPDLOG_SRCS
"src/details/file_helper.cpp"
"src/details/os_filesystem.cpp"
"src/details/log_msg.cpp"
"src/details/log_msg_buffer.cpp"
"src/details/async_log_msg.cpp"
"src/details/context.cpp"
"src/sinks/base_sink.cpp"
"src/sinks/basic_file_sink.cpp"

View File

@ -5,73 +5,84 @@
// spdlog usage example
#include <chrono>
#include <clocale>
#include <cstdio>
void stdout_logger_example();
void basic_example();
void rotating_example();
void daily_example();
void callback_example();
void async_example();
void binary_example();
void vector_example();
void stopwatch_example();
void trace_example();
void multi_sink_example();
void user_defined_example();
void err_handler_example();
void syslog_example();
void udp_example();
void custom_flags_example();
void file_events_example();
void replace_global_logger_example();
#include "/home/gabi//spdlog2/tests/test_sink.h"
#include "spdlog/sinks/async_sink.h"
#include "spdlog/sinks/stdout_color_sinks.h"
#include "spdlog/spdlog.h"
#include "spdlog/version.h"
#include "spdlog/stopwatch.h"
using namespace spdlog::sinks;
void worker_thread(std::shared_ptr<spdlog::logger> logger, int n_messages) {
for (int i = 0; i < n_messages; ++i) {
// std::this_thread::sleep_for(std::chrono::milliseconds(10));
logger->info("Worker thread message #{}", i);
}
}
bool async_example2(size_t n_threads, size_t n_messages) {
auto test_sink = std::make_shared<test_sink_st>();
auto n_total_messages = n_messages * n_threads;
{
std::vector<std::thread> threads;
auto async_sink = std::make_shared<async_sink_mt>();
async_sink->add_sink(test_sink);
auto logger = std::make_shared<spdlog::logger>("async_logger", async_sink);
logger->set_level(spdlog::level::trace);
spdlog::stopwatch sw;
for (int i = 0; i < n_threads; ++i) {
threads.emplace_back(worker_thread, logger, n_messages);
}
// wait for worker threads to finish
for (auto &t : threads) {
t.join();
}
auto millis = sw.elapsed_ms().count();
if (millis == 0) {
millis = 1;
}
spdlog::info("Elapsed {} millis ({:L}/sec)", millis, n_total_messages * 1000 / millis);
}
// wait for the worker thread to finish
// check that all messages were processed
if (test_sink->msg_counter() != n_messages * n_threads) {
spdlog::error("Expected: {:L}, Counted: {:L}", n_total_messages,
test_sink->msg_counter());
return false;
}
spdlog::info("OK: {:L}", test_sink->msg_counter());
return true;
}
#include <random>
int main(int, char *[]) {
spdlog::info("Welcome to spdlog version {}.{}.{} !", SPDLOG_VER_MAJOR, SPDLOG_VER_MINOR, SPDLOG_VER_PATCH);
spdlog::warn("Easy padding in numbers like {:08d}", 12);
spdlog::critical("Support for int: {0:d}; hex: {0:x}; oct: {0:o}; bin: {0:b}", 42);
spdlog::info("Support for floats {:03.2f}", 1.23456);
spdlog::info("Positional args are {1} {0}..", "too", "supported");
spdlog::info("{:>8} aligned, {:<8} aligned", "right", "left");
// Runtime log levels
spdlog::set_level(spdlog::level::info); // Set global log level to info
spdlog::debug("This message should not be displayed!");
spdlog::set_level(spdlog::level::trace); // Set specific logger's log level
spdlog::debug("This message should be displayed..");
// Customize msg format for all loggers
spdlog::set_pattern("[%H:%M:%S %z] [%^%L%$] [thread %t] %v");
spdlog::info("This an info message with custom format");
spdlog::set_pattern("%+"); // back to default format
spdlog::set_level(spdlog::level::info);
std::locale::global(std::locale("en_US.UTF-8"));
// constexpr size_t n_messages = 1'00;
// constexpr size_t n_threads = 1;
try {
stdout_logger_example();
basic_example();
rotating_example();
daily_example();
callback_example();
async_example();
binary_example();
vector_example();
multi_sink_example();
user_defined_example();
err_handler_example();
trace_example();
stopwatch_example();
udp_example();
custom_flags_example();
file_events_example();
replace_global_logger_example();
// random n_messages and n_threads
std::mt19937 gen(std::random_device{}());
for (int i = 0; i < 100; i++) {
auto n_threads = std::uniform_int_distribution<size_t>(1, 10)(gen);
auto n_messages = std::uniform_int_distribution<size_t>(1, 1'000'000)(gen);
spdlog::info("***********************************");
spdlog::info("Test #{}. Threads: {}, Count: {:L}", i, n_threads, n_messages);
if (!async_example2(n_threads, n_messages)) {
spdlog::error("Stopped");
break;
}
}
// Release all spdlog resources
// This is optional (only mandatory if using windows + async log).
spdlog::shutdown();
}
@ -81,223 +92,3 @@ int main(int, char *[]) {
return 1;
}
}
#include "spdlog/sinks/stdout_color_sinks.h"
// or #include "spdlog/sinks/stdout_sinks.h" if no colors needed.
void stdout_logger_example() {
// Create color multithreading logger.
auto console = spdlog::create<stdout_color_sink_mt>("console");
// or for stderr:
//auto console = spdlog::create<stderr_color_sink_mt>("console");
}
#include "spdlog/sinks/basic_file_sink.h"
void basic_example() {
// Create basic file logger (not rotated).
auto my_logger = spdlog::create<basic_file_sink_mt>("file_logger", "logs/basic-log.txt", true);
}
#include "spdlog/sinks/rotating_file_sink.h"
void rotating_example() {
// Create a file rotating logger with 5mb size max and 3 rotated files.
auto rotating_logger = spdlog::create<rotating_file_sink_mt>("some_logger_name", "logs/rotating.txt", 1048576 * 5, 3);
}
#include "spdlog/sinks/daily_file_sink.h"
void daily_example() {
// Create a daily logger - a new file is created every day on 2:30am.
auto daily_logger = spdlog::create<daily_file_format_sink_mt>("daily_logger", "logs/daily.txt", 2, 30);
}
#include "spdlog/sinks/callback_sink.h"
void callback_example() {
// Create the logger
auto logger = spdlog::create<callback_sink_mt>("custom_callback_logger", [](const spdlog::details::log_msg & /*msg*/) {
// do what you need to do with msg
});
}
void async_example() {
// TODO
// // Default thread pool settings can be modified *before* creating the async logger:
// // spdlog::init_thread_pool(32768, 1); // queue with max 32k items 1 backing thread.
// auto async_file = spdlog::basic_logger_mt<spdlog::async_factory>("async_file_logger", "logs/async_log.txt");
// // alternatively:
// // auto async_file =
// // spdlog::create_async<spdlog::sinks::basic_file_sink_mt>("async_file_logger",
// // "logs/async_log.txt");
//
// for (int i = 1; i < 101; ++i) {
// async_file->info("Async message #{}", i);
// }
}
// Log binary data as hex.
// Many types of std::container<char> types can be used.
// Iterator ranges are supported too.
// Format flags:
// {:X} - print in uppercase.
// {:s} - don't separate each byte with space.
// {:p} - don't print the position on each line start.
// {:n} - don't split the output to lines.
#include "spdlog/fmt/bin_to_hex.h"
void binary_example() {
std::vector<char> buf;
for (int i = 0; i < 80; i++) {
buf.push_back(static_cast<char>(i & 0xff));
}
spdlog::info("Binary example: {}", spdlog::to_hex(buf));
spdlog::info("Another binary example:{:n}", spdlog::to_hex(std::begin(buf), std::begin(buf) + 10));
// more examples:
// logger->info("uppercase: {:X}", spdlog::to_hex(buf));
// logger->info("uppercase, no delimiters: {:Xs}", spdlog::to_hex(buf));
// logger->info("uppercase, no delimiters, no position info: {:Xsp}", spdlog::to_hex(buf));
// logger->info("hexdump style: {:a}", spdlog::to_hex(buf));
// logger->info("hexdump style, 20 chars per line {:a}", spdlog::to_hex(buf, 20));
}
// Log a vector of numbers
#include "fmt/ranges.h"
void vector_example() {
std::vector<int> vec = {1, 2, 3};
spdlog::info("Vector example: {}", vec);
}
// Compile time log levels.
// define SPDLOG_ACTIVE_LEVEL to required level (e.g. SPDLOG_LEVEL_TRACE)
void trace_example() {
// trace from global logger
SPDLOG_TRACE("Some trace message.. {} ,{}", 1, 3.23);
// debug from global logger
SPDLOG_DEBUG("Some debug message.. {} ,{}", 1, 3.23);
}
// stopwatch example
#include <thread>
#include "spdlog/stopwatch.h"
void stopwatch_example() {
spdlog::stopwatch sw;
std::this_thread::sleep_for(std::chrono::milliseconds(123));
spdlog::info("Stopwatch: {} seconds", sw);
}
#include "spdlog/sinks/udp_sink.h"
void udp_example() {
udp_sink_config cfg("127.0.0.1", 11091);
auto my_logger = spdlog::create<udp_sink_mt>("udplog", cfg);
my_logger->set_level(spdlog::level::debug);
my_logger->info("hello world");
}
// A logger with multiple sinks (stdout and file) - each with a different format and log level.
void multi_sink_example() {
auto console_sink = std::make_shared<stdout_color_sink_mt>();
console_sink->set_level(spdlog::level::warn);
console_sink->set_pattern("[multi_sink_example] [%^%l%$] %v");
auto file_sink = std::make_shared<basic_file_sink_mt>("logs/multisink.txt", true);
file_sink->set_level(spdlog::level::trace);
spdlog::logger logger("multi_sink", {console_sink, file_sink});
logger.set_level(spdlog::level::debug);
logger.warn("this should appear in both console and file");
logger.info("this message should not appear in the console, only in the file");
}
// User defined types logging
struct my_type {
int i = 0;
explicit my_type(int i)
: i(i) {}
};
template <>
struct fmt::formatter<my_type> : fmt::formatter<std::string> {
auto format(my_type my, format_context &ctx) const -> decltype(ctx.out()) {
return fmt::format_to(ctx.out(), "[my_type i={}]", my.i);
}
};
void user_defined_example() { spdlog::info("user defined type: {}", my_type(14)); }
// Custom error handler. Will be triggered on log failure.
void err_handler_example() {
// can be set globally or per logger(logger->set_error_handler(..))
spdlog::set_error_handler([](const std::string &msg) { printf("*** Custom log error handler: %s ***\n", msg.c_str()); });
}
// syslog example (linux/osx/freebsd)
#ifndef _WIN32
#include "spdlog/sinks/syslog_sink.h"
void syslog_example() {
std::string ident = "spdlog-example";
auto syslog_logger = spdlog::create<syslog_sink_mt>("syslog", ident, LOG_PID);
syslog_logger->warn("This is warning that will end up in syslog.");
}
#endif
// Android example.
#if defined(__ANDROID__)
#include "spdlog/sinks/android_sink.h"
void android_example() {
std::string tag = "spdlog-android";
auto android_logger = spdlog::android_logger_mt("android", tag);
android_logger->critical("Use \"adb shell logcat\" to view this message.");
}
#endif
// Log patterns can contain custom flags.
// this will add custom flag '%*' which will be bound to a <my_formatter_flag> instance
#include "spdlog/pattern_formatter.h"
class my_formatter_flag : public spdlog::custom_flag_formatter {
public:
void format(const spdlog::details::log_msg &, const std::tm &, spdlog::memory_buf_t &dest) override {
std::string some_txt = "custom-flag";
dest.append(some_txt.data(), some_txt.data() + some_txt.size());
}
[[nodiscard]]
std::unique_ptr<custom_flag_formatter> clone() const override {
return std::make_unique<my_formatter_flag>();
}
};
void custom_flags_example() {
auto formatter = std::make_unique<spdlog::pattern_formatter>();
formatter->add_flag<my_formatter_flag>('*').set_pattern("[%n] [%*] [%^%l%$] %v");
// set the new formatter using spdlog::set_formatter(formatter) or
// logger->set_formatter(formatter) spdlog::set_formatter(std::move(formatter));
}
void file_events_example() {
// pass the spdlog::file_event_handlers to file sinks for open/close log file notifications
spdlog::file_event_handlers handlers;
handlers.before_open = [](spdlog::filename_t) { spdlog::trace("Before opening logfile"); };
handlers.after_open = [](spdlog::filename_t, std::FILE *fstream) {
spdlog::trace("After opening logfile");
fputs("After opening\n", fstream);
};
handlers.before_close = [](spdlog::filename_t, std::FILE *fstream) {
spdlog::trace("Before closing logfile");
fputs("Before closing\n", fstream);
};
handlers.after_close = [](spdlog::filename_t) { spdlog::trace("After closing logfile"); };
auto file_sink = std::make_shared<spdlog::sinks::basic_file_sink_mt>("logs/events-sample.txt", true, handlers);
spdlog::logger my_logger("some_logger", file_sink);
my_logger.trace("Some log line");
}
void replace_global_logger_example() {
// store the old logger so we don't break other examples.
auto old_logger = spdlog::global_logger();
auto new_logger = spdlog::create<basic_file_sink_mt>("new_global_logger", "logs/new-default-log.txt", true);
spdlog::set_global_logger(new_logger);
spdlog::set_level(spdlog::level::info);
spdlog::debug("This message should not be displayed!");
spdlog::set_level(spdlog::level::trace);
spdlog::debug("This message should be displayed..");
spdlog::set_global_logger(old_logger);
}

View File

@ -1,69 +0,0 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
#pragma once
// Fast asynchronous logger.
// Uses pre allocated queue.
// Creates a single back thread to pop messages from the queue and log them.
//
// Upon each log write the logger:
// 1. Checks if its log level is enough to log the message
// 2. Push a new copy of the message to a queue (or block the caller until
// space is available in the queue)
// Upon destruction, logs all remaining messages in the queue before
// destructing
#include "./logger.h"
namespace spdlog {
// Async overflow policy - block by default.
enum class async_overflow_policy {
block, // Block until message can be enqueued
overrun_oldest, // Discard the oldest message in the queue if full when trying to
// add new item.
discard_new // Discard new message if the queue is full when trying to add new item.
};
namespace details {
class thread_pool;
}
class SPDLOG_API async_logger final : public std::enable_shared_from_this<async_logger>, public logger {
friend class details::thread_pool;
public:
template <typename It>
async_logger(std::string logger_name,
It begin,
It end,
std::weak_ptr<details::thread_pool> tp,
async_overflow_policy overflow_policy = async_overflow_policy::block)
: logger(std::move(logger_name), begin, end),
thread_pool_(std::move(tp)),
overflow_policy_(overflow_policy) {}
async_logger(std::string logger_name,
sinks_init_list sinks_list,
std::weak_ptr<details::thread_pool> tp,
async_overflow_policy overflow_policy = async_overflow_policy::block);
async_logger(std::string logger_name,
sink_ptr single_sink,
std::weak_ptr<details::thread_pool> tp,
async_overflow_policy overflow_policy = async_overflow_policy::block);
std::shared_ptr<logger> clone(std::string new_name) override;
protected:
void sink_it_(const details::log_msg &msg) override;
void flush_() override;
void backend_sink_it_(const details::log_msg &incoming_log_msg);
void backend_flush_();
private:
std::weak_ptr<details::thread_pool> thread_pool_;
async_overflow_policy overflow_policy_;
};
} // namespace spdlog

View File

@ -0,0 +1,37 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
#pragma once
#include <cstdint>
#include "./log_msg.h"
namespace spdlog {
namespace details {
// Extend log_msg with internal buffer to store its payload.
// This is needed since log_msg holds string_views that points to stack data.
class SPDLOG_API async_log_msg : public log_msg {
public:
enum class msg_type:std::uint8_t { log, flush, terminate };
async_log_msg() = default;
explicit async_log_msg(msg_type type);
async_log_msg(msg_type type, const log_msg &orig_msg);
~async_log_msg() = default;
async_log_msg(const async_log_msg &other);
async_log_msg(async_log_msg &&other) noexcept;
async_log_msg &operator=(const async_log_msg &other);
async_log_msg &operator=(async_log_msg &&other) noexcept;
msg_type message_type() const {return msg_type_;}
private:
msg_type msg_type_{msg_type::log};
memory_buf_t buffer_;
void update_string_views();
};
} // namespace details
} // namespace spdlog

View File

@ -1,28 +0,0 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
#pragma once
#include "./log_msg.h"
namespace spdlog {
namespace details {
// Extend log_msg with internal buffer to store its payload.
// This is needed since log_msg holds string_views that points to stack data.
class SPDLOG_API log_msg_buffer : public log_msg {
memory_buf_t buffer;
void update_string_views();
public:
log_msg_buffer() = default;
explicit log_msg_buffer(const log_msg &orig_msg);
log_msg_buffer(const log_msg_buffer &other);
log_msg_buffer(log_msg_buffer &&other) noexcept;
log_msg_buffer &operator=(const log_msg_buffer &other);
log_msg_buffer &operator=(log_msg_buffer &&other) noexcept;
};
} // namespace details
} // namespace spdlog

View File

@ -0,0 +1,63 @@
#pragma once
#include <thread>
#include "../details/async_log_msg.h"
#include "../details/mpmc_blocking_q.h"
#include "./dist_sink.h"
namespace spdlog {
namespace sinks {
template <typename Mutex>
class async_sink final : public dist_sink<Mutex> {
public:
using base_t = dist_sink<Mutex>;
using queue_t = details::mpmc_blocking_queue<details::async_log_msg>;
async_sink() {
q_ = std::make_unique<queue_t>(8192);
worker_thread_ = std::thread([this] {
details::async_log_msg incoming_msg;
for (;;) {
q_->dequeue(incoming_msg);
if (incoming_msg.message_type() == details::async_log_msg::msg_type::terminate) {
break;
}
base_t::sink_it_(incoming_msg);
}
});
}
~async_sink() override {
try {
q_->enqueue(details::async_log_msg(details::async_log_msg::msg_type::terminate));
worker_thread_.join();
} catch (...) {}
};
async_sink(const async_sink &) = delete;
async_sink &operator=(const async_sink &) = delete;
async_sink(async_sink &&) = default;
async_sink &operator=(async_sink &&) = default;
private:
void sink_it_(const details::log_msg &msg) override {
// Asynchronously send the log message to the base sink
q_->enqueue(details::async_log_msg(details::async_log_msg::msg_type::log, msg));
}
void flush_() override {
// Asynchronously flush the base sink
q_->enqueue(details::async_log_msg(details::async_log_msg::msg_type::flush));
}
std::thread worker_thread_;
std::unique_ptr<queue_t> q_;
};
using async_sink_mt = async_sink<std::mutex>;
using async_sink_st = async_sink<details::null_mutex>;
} // namespace sinks
} // namespace spdlog

View File

@ -7,8 +7,8 @@
#include <mutex>
#include <string_view>
#include "../details/async_log_msg.h"
#include "../details/circular_q.h"
#include "../details/log_msg_buffer.h"
#include "../details/null_mutex.h"
#include "./base_sink.h"

View File

@ -0,0 +1,60 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
#include "spdlog/details/async_log_msg.h"
namespace spdlog {
namespace details {
async_log_msg::async_log_msg(const msg_type type)
: msg_type_{type} {}
// copy logger name and payload to buffer so can be used asynchronously
// note: source location pointers are copied without allocation since they
// are compiler generated const chars* (__FILE__, __LINE__, __FUNCTION__)
// if you pass custom strings to source location, make sure they outlive the async_log_msg
async_log_msg::async_log_msg(const msg_type type, const log_msg &orig_msg)
: log_msg{orig_msg}, msg_type_(type) {
buffer_.append(logger_name);
buffer_.append(payload);
update_string_views();
}
async_log_msg::async_log_msg(const async_log_msg &other)
: log_msg{other}, msg_type_{other.msg_type_} {
buffer_.append(logger_name);
buffer_.append(payload);
update_string_views();
}
async_log_msg::async_log_msg(async_log_msg &&other) noexcept
: log_msg{other}, msg_type_{other.msg_type_}, buffer_{std::move(other.buffer_)} {
update_string_views();
}
async_log_msg &async_log_msg::operator=(const async_log_msg &other) {
log_msg::operator=(other);
msg_type_ = other.msg_type_;
buffer_.clear();
buffer_.append(other.buffer_.data(), other.buffer_.data() + other.buffer_.size());
update_string_views();
return *this;
}
async_log_msg &async_log_msg::operator=(async_log_msg &&other) noexcept {
log_msg::operator=(other);
msg_type_ = other.msg_type_;
buffer_ = std::move(other.buffer_);
update_string_views();
return *this;
}
void async_log_msg::update_string_views() {
logger_name = string_view_t{buffer_.data(), logger_name.size()};
payload = string_view_t{buffer_.data() + logger_name.size(), payload.size()};
}
} // namespace details
} // namespace spdlog

View File

@ -1,54 +0,0 @@
// Copyright(c) 2015-present, Gabi Melman & spdlog contributors.
// Distributed under the MIT License (http://opensource.org/licenses/MIT)
#include "spdlog/details/log_msg_buffer.h"
namespace spdlog {
namespace details {
// copy logger name and payload to buffer so can be used asynchronously
// note: source location pointers are copied without allocation since they
// are compiler generated const chars* (__FILE__, __LINE__, __FUNCTION__)
// if you pass custom strings to source location, make sure they outlive the log_msg_buffer
log_msg_buffer::log_msg_buffer(const log_msg &orig_msg)
: log_msg{orig_msg} {
buffer.append(logger_name);
buffer.append(payload);
update_string_views();
}
log_msg_buffer::log_msg_buffer(const log_msg_buffer &other)
: log_msg{other} {
buffer.append(logger_name);
buffer.append(payload);
update_string_views();
}
log_msg_buffer::log_msg_buffer(log_msg_buffer &&other) noexcept
: log_msg{other},
buffer{std::move(other.buffer)} {
update_string_views();
}
log_msg_buffer &log_msg_buffer::operator=(const log_msg_buffer &other) {
log_msg::operator=(other);
buffer.clear();
buffer.append(other.buffer.data(), other.buffer.data() + other.buffer.size());
update_string_views();
return *this;
}
log_msg_buffer &log_msg_buffer::operator=(log_msg_buffer &&other) noexcept {
log_msg::operator=(other);
buffer = std::move(other.buffer);
update_string_views();
return *this;
}
void log_msg_buffer::update_string_views() {
logger_name = string_view_t{buffer.data(), logger_name.size()};
payload = string_view_t{buffer.data() + logger_name.size(), payload.size()};
}
} // namespace details
} // namespace spdlog