ShiBin's Wiki

Appearance

Published at:

spdlog源码分析 ​

公司QT项目有用到，就看了下它的源码；文章会介绍库的使用特点，核心的类和字段，然后讲同步日志，同步日志会把里面的概念基本过一遍；然后是异步日志，这个相对复杂点，理解起来其实也不复杂，就是一个mpmc，多生产者和多消费者模型，及线程池；异步才需要线程池，同步不需要

项目地址：https://github.com/gabime/spdlog

Log框架主要面临的问题是什么？ ​

答案是：IO性能，Log框架的核心在于把IO操作从当前的工作线程中移出去；下图是不同存储器访问需要的时钟周期差异：

而且，在近几十年的改进并不是特别大（SSD的出现改进了不少）：

IO操作会去调用syscall系统调用的write函数，对于syscall的优化，有两种常见的方式：一种是不用，怎么可能不用呢？简单的说就是：把以前需要调用内核态的函数，自己去在用户态自己实现下，Go语言里面有不少东西是这样做的，这样做的好处体现在，可以屏蔽不同系统内核版本的差异，还有个好处是内核的东西更新慢，它的实现方式效率不一定是最化的；另一种方式尽量少用，最常见的就是IO操作里面加Buffer缓冲区

Spdlog特点及核心数据结构 ​

头文件xxx.h + 实现xxx-inl.h方式 ​

与一般.h头文件+.cpp实现文件不同，spdlog使用xxx.h + 实现xxx-inl.h方式，也一般只有开源的库喜欢把实现写在.h或是.hpp文件里面，反正代码开源，不需要隐藏什么；另一个喜欢把实现写在头文件里面的好处是，只需要#include 头文件即可以使用该库，不需要去链接库文件

核心类registry及单例模式 ​

这个registry就是spdlog里面最最最核心的类，下面是核心字段：

cpp
class registry {
private:
    std::mutex logger_map_mutex_, flusher_mutex_;
    std::recursive_mutex tp_mutex_;
    std::unordered_map<std::string, std::shared_ptr<logger>> loggers_; // 多个logger
    log_levels log_levels_; // 级别
    std::unique_ptr<formatter> formatter_; // 用来处理格式化
    spdlog::level::level_enum global_log_level_ = level::info; // 全局级别
    level::level_enum flush_level_ = level::off; // flush级别
    err_handler err_handler_;
    std::shared_ptr<thread_pool> tp_; // 线程池
    std::unique_ptr<periodic_worker> periodic_flusher_; // 周期性的flush（开线程）
    std::shared_ptr<logger> default_logger_; // 默认logger --> 支持多线程的stdout日志
    bool automatic_registration_ = true;
    size_t backtrace_n_messages_ = 0;
};

Note:库里面经常有mt和st的后缀，mt表示multiple thread多线程；st是single thread单线程

Logger类 ​

Logger中最核心的字段是std::vector<sink_ptr> sinks_;，using sink_ptr = std::shared_ptr<sinks::sink>;，sink是一个抽象类，sink的意思表示日志最终要下沉到哪里去，它会有很多实现；比如：日志要输出到stdout，file，tcp，udp，Android，syslog。另外一点是，logger和sink是一对多的关系；这里的logger是指的同步的log，后面还有继承Logger的异步async_logger

cpp
class logger {
protected:
    std::string name_; // name
    std::vector<sink_ptr> sinks_; //
    spdlog::level_t level_{level::info}; // 级别
    spdlog::level_t flush_level_{level::off};
    err_handler custom_err_handler_{nullptr};
    details::backtracer tracer_;
};

logger里面主要的作用是，

  • 日志类details::log_msg的对象的创建，用来描述每一条日志
  • 调用sink的下沉，由sink决定最终输出到哪里去
cpp
// include/spdlog/logger.h
void log(source_loc loc, level::level_enum lvl, string_view_t msg) {
    // ......

    details::log_msg log_msg(loc, name_, lvl, msg); // 创建日志
    log_it_(log_msg, log_enabled, traceback_enabled); // log_it_内部调用sink
}

下面来讲下details::log_msg

Log_msg结构体 ​

cpp
struct log_msg {
    string_view_t logger_name; // name
    level::level_enum level{level::off}; // 级别
    log_clock::time_point time; // 时间
    size_t thread_id{0}; // 线程id

    // ......
    source_loc source; // 文件名 + 行号 + 函数名
    string_view_t payload; // 日志主要内容
};

source_loc结构体：

cpp
struct source_loc {
    const char *filename{nullptr}; // 文件名
    int line{0}; // 行号
    const char *funcname{nullptr}; // 函数名
};

同步日志： ​

同步日志的代码跟踪起来相对简单，就是一条同步的执行流，然后就没有了，讲同步日志的目的是为了给后面讲异步日志做铺垫； registry中default_logger_的初始化，sink是输出到stdout，并且是带color输出；同时这还初始化了formatter_，用来处理输出的日志格式

cpp
registry::registry() : formatter_(new pattern_formatter()) {
    // create default logger
    auto color_sink = std::make_shared<sinks::ansicolor_stdout_sink_mt>();

    const char *default_logger_name = "";
    default_logger_ = std::make_shared<spdlog::logger>(default_logger_name, std::move(color_sink));
    loggers_[default_logger_name] = default_logger_;
}

结合上面的些核心类和结构体，可以看到default_logger_处理逻辑：

  • registry单例创建输出到default_logger_，输出到stdout，带color，并且sink是mt结束，表示是支持多线程；同时创建了日志格式化formatter_实例
  • 当调用spdlog::info();函数时，就会使用上面的default_logger_去创建一个log_msg日志消息，包括时间、文件、行号、函数名、日志消息主体
  • sinks::ansicolor_stdout_sink_mt内部会有formatter来格式化日志消息，然后输出到stdout
cpp
template<typename ConsoleMutex>
SPDLOG_INLINE void ansicolor_sink<ConsoleMutex>::log(const details::log_msg &msg)
{
    // Wrap the originally formatted message in color codes.
    // If color is not supported in the terminal, log as is instead.
    std::lock_guard<mutex_t> lock(mutex_);
    msg.color_range_start = 0;
    msg.color_range_end = 0;
    memory_buf_t formatted;
    formatter_->format(msg, formatted);
    if (should_do_colors_ && msg.color_range_end > msg.color_range_start)
    {
        // before color range
        print_range_(formatted, 0, msg.color_range_start);
        // in color range
        print_ccode_(colors_[static_cast<size_t>(msg.level)]);
        print_range_(formatted, msg.color_range_start, msg.color_range_end);
        print_ccode_(reset);
        // after color range
        print_range_(formatted, msg.color_range_end, formatted.size());
    }
    else // no color
    {
        print_range_(formatted, 0, formatted.size());
    }
    fflush(target_file_);
}

异步日志: ​

前面提到异步日志是mpmc多生产者、多消费者模型；这里就会有以下几部分

  • 发送日志消息的前端
  • 缓存日志消息的队列
  • 处理日志消息的后端及线程池

缓存日志消息的队列 ​

mpmc_blocking_q.h文件：从名字上可以看出是多生产者、多消费者的blocking队列

cpp
template<typename T>
class mpmc_blocking_queue {
private:
    std::mutex queue_mutex_;
    std::condition_variable push_cv_;
    std::condition_variable pop_cv_;
    spdlog::details::circular_q<T> q_; // 环形队列 --> 内部是个vector
};

circular_q.h文件，本质上就是一个vector

cpp
template<typename T>
class circular_q {
    size_t max_items_ = 0;
    size_t overrun_counter_ = 0;
    std::vector<T> v_; // 缓存日志消息的vector；默认大小8192
};

日志消息缓存满了之后的处理策略：

  1. async_overflow_policy::block：阻塞，一直到日志消息可以入队；默认的方式
  2. async_overflow_policy::overrun_oldest：丢弃掉队列里面最老的消息，然后把新的日志消息入队

发送日志消息的前端 ​

日志消息入队:

cpp
// async_logger-inl.h
// 发送消息到线程波
void spdlog::async_logger::sink_it_(const details::log_msg& msg) {
    if (auto pool_ptr = thread_pool_.lock()) {
        pool_ptr->post_log(shared_from_this(), msg, overflow_policy_);
    } else {
        throw_spdlog_ex("async log: thread pool doesn't exist anymore");
    }
}

// 创建异步消息, 然后添加到队列
void thread_pool::post_log(async_logger_ptr&& worker_ptr, const details::log_msg& msg, async_overflow_policy overflow_policy) {
    async_msg async_m(std::move(worker_ptr), async_msg_type::log, msg); // 创建异步消息
    post_async_msg_(std::move(async_m), overflow_policy);
}

void thread_pool::post_async_msg_(async_msg&& new_msg, async_overflow_policy overflow_policy) {
    if (overflow_policy == async_overflow_policy::block) {
        q_.enqueue(std::move(new_msg));  // 日志消息入队
    } else {
        q_.enqueue_nowait(std::move(new_msg));
    }
}

处理日志消息的后端及线程池 ​

出队处理消息:

cpp
// thread_pool-inl.h
void thread_pool::worker_loop_() {
    while (process_next_msg_()) { // 死循的方式来环处理下一条消息
    }
}

bool thread_pool::process_next_msg_() {
    async_msg incoming_async_msg; // 收到的log日志消息
    bool      dequeued = q_.dequeue_for(incoming_async_msg, std::chrono::seconds(10)); // 出队
    // ......

    switch (incoming_async_msg.msg_type) {
        case async_msg_type::log: {
            // incoming_async_msg.worker_ptr就是async_logger
            incoming_async_msg.worker_ptr->backend_sink_it_(incoming_async_msg);
            return true;
        }
        // ......
    }

    return true;
}

周期性flush缓冲区 ​

防止在缓冲区的数据丢失

cpp
// registry-inl.h
// periodic_flusher_ 创建
void registry::flush_every(std::chrono::seconds interval) {
    std::lock_guard<std::mutex> lock(flusher_mutex_);
    auto                        clbk = [this]() { this->flush_all(); };
    periodic_flusher_                = details::make_unique<periodic_worker>(clbk, interval);
}

void registry::flush_all() {
    std::lock_guard<std::mutex> lock(logger_map_mutex_);
    for (auto& l : loggers_) {
        l.second->flush();
    }
}

// periodic_worker-inl.h
periodic_worker::periodic_worker(const std::function<void()>& callback_fun, std::chrono::seconds interval) {
    active_ = (interval > std::chrono::seconds::zero());
    if (!active_) {
        return;
    }

    worker_thread_ = std::thread([this, callback_fun, interval]() {
        for (;;) {
            std::unique_lock<std::mutex> lock(this->mutex_);
            if (this->cv_.wait_for(lock, interval, [this] { return !this->active_; })) {
                return;  // active_ == false, so exit this thread
            }
            callback_fun(); // 上面的registry::flush_all()
        }
    });
}

other ​

  1. registry单例模式
    1. map<name, logger>, 创建的异步日志会被添加到这里
    2. defalut_logger
    3. thread_pool线程池, (async_factory_impl) 异步才需要线程池
      1. details::mpmc_blocking_queue<async_msg>; 消息队列
      2. std::vectorstd::thread threads_; 具体线程
      3. void workerloop() 死循环处理消息
    4. periodicflusher; 周期性flush
    5. formatter_; log格式化
    6. log_levels: 级别
  2. 工厂模式
    1. async_factory_impl
    2. synchronous_factory
  3. logger --> async_logger
    1. logger
      1. std::string name*;*
      2. std::vector<sinkptr> sinks;
      3. spdlog::levelt level;_
      4. spdlog::levelt flush_level;
    2. async_logger
      1. std::weakptrdetails::thread_pool thread_pool;
      2. asyncoverflow_policy overflow_policy;
  4. 多生产者,多消费者模型mpmc_blocking_q.h
    1. log 环形队列circular_q --> std::vector 实现
      1. async_overflow_policy::block
      2. async_overflow_policy::overrun_oldest
  5. log_msg--> log_msg_buffer --> async_msg
    1. log_msg
      1. string_view_t logger_name
      2. level level
      3. time_point time
      4. thread_id
      5. source_loc: 文件名, 行号, 函数名
      6. string_view_t payload 消息主体
    2. log_msg_buffer
      1. memory_buf_t
    3. async_msg
      1. async_msg_type
      2. async_logger_ptr --> async_logger
  6. sink基类; 日志输出到哪里去:文件,stdout, android, qt, tcp, upd, mongo, syslog, systemd
    1. base_sink, 通用
  7. 流程

Updated at:

Copyright © 2017-2024 Shi Bin