51工具盒子

依楼听风雨
笑看云卷云舒,淡观潮起潮落

超详细!spdlog源码解析(上)

学过C++后,写过和看过的C++代码还是比较有限,因此便想着学习一些开源项目。spdlog这个项目代码量不大,而且它所实现的功能理解起来也很容易,不需要太多的其他背景知识(毕竟是个日志库嘛),所以就选择了它。在学习这个项目期间,除了看源码外,也看了不少相关的博客,还有也尝试自己实现一个简单的日志库。最后实现了一大半,放弃了。毕竟跟着敲代码只是帮助更深刻理解源码的手段而不是目的。本人水平有限,有写得不对地方欢迎大家指出或者一起讨论。碎碎念结束,接下来进入正题。

总览 {#总览}

spdlog是一个支持多平台的日志库,使用十分方便。既支持header-only version,也支持compiled version。header-only的全部代码都在项目的include文件夹下,直接将里面的内容copy到自己的项目里就能用。因为我是在ubuntu系统下使用的该库,所以之后代码的解析部分如果遇到有不同平台存在不同实现的情况,默认只考虑在ubuntu系统下的情况。并且因为header-only的代码阅读起来更为方便,所以代码解析也只涉及此部分。

spdlog主要由logger(也包括async_logger)、sink、formatter、registry这四个部分组成,它们之间的基本逻辑结构如下图所示:

  • spdlog log API ------ 是建立在logger之上的,只是对logger使用的封装,目的只是为了能够像官网给的示例代码spdlog::info("Welcome to spdlog!");那样,让用户能够以最简单的方式使用spdlog打印出log。这是一种从用户使用维度出发的程序设计思想。
  • logger ------ 是spdlog开始处理日志的入口。sync-logger主要负责日志信息的整理,将格式化(通过第三方库fmt)后的日志内容、日志等级、日志时间等信息"整理"到一个名为log_msg结构体的对象中,然后再交给下游的sink进行处理。而对于async-logger,则是在将整理后的log_msg对象交给线程池,让线程池去处理后续的工作。
  • sink ------ 接收log_msg对象,并通过formatter将对象中所含有的信息转换成字符串,最后将字符串输出到指定的地方,例如控制台、文件等,甚至通过tcp/udp将字符串发送到指定的地方。sink译为"下沉",扩展一下可以理解为"落笔",做的是把日志真正记录下来的事情。
  • formatter ------ 负责将log_msg对象中的信息转换成字符串,例如日志等级、时间、实际内容等。时间的格式和精度、等级输出显示的颜色等都是由formatter决定的。支持用户自定义格式。
  • registry ------ 负责管理所有的logger,包括创建、销毁、获取等。通过registry用户还可以对所有的logger进行一些全局设置,例如设置日志等级。

sync-logger {#sync-logger}

这部分的代码都在logger.h和logger-inl.h中,对应logger类。logger要做的事情就是将要记录的内容通过函数调用层层传递,最后到sink。以logger中成员函数info两种调用情况为例,展示logger的调用过程。

|---------------------------------------------------------------------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 | // 调用例如spdlog::info("Welcome to spdlog!"); // 或者spdlog::info(num); template <typename T> void info(const T &msg) { log(level::info, msg); } // 确定log等级为info // 调用例如spdlog::info("Support for floats {:03.2f}", 1.23456); // 或者spdlog::info("Positional args are {1} {0}..", "too", "supported"); template <typename... Args> void info(format_string_t<Args...> fmt, Args &&...args) { log(level::info, fmt, std::forward<Args>(args)...); } // 确定log等级为info template <typename T> void log(level::level_enum lvl, const T &msg) { log(source_loc{}, lvl, msg); } // 接着再确定日志调用的位置(文件、函数名、行号) template <typename... Args> void log(level::level_enum lvl, format_string_t<Args...> fmt, Args &&...args) { log(source_loc{}, lvl, fmt, std::forward<Args>(args)...); } // 接着再确定日志调用的位置(文件、函数名、行号) template <typename T> void log(source_loc loc, level::level_enum lvl, const T &msg) { log(loc, lvl, "{}", msg); } // 因为spdlog::info(num);可以等价为spdlog::info("{}", num);,所以这里加了一个"{}" template <typename... Args> void log(source_loc loc, level::level_enum lvl, format_string_t<Args...> fmt, Args &&...args) { log_(loc, lvl, details::to_string_view(fmt), std::forward<Args>(args)...); } // 成员函数info两种调用过程都会汇集到此处 |

为了方便展示,在不影响理解代码逻辑的情况下,我对代码做了一些删减,后续的代码展示同理。从上述代码可以看出,logger的调用过程是层层传递的,传递过程中不断添加各种信息,最后两种方式的调用都汇集到log_函数中。学习上述代码过程中需要关注的点是"完美转发",这是一种通过万能引用来减少拷贝的技术,即上述代码中的"Args &&...args"和"std::forward (args)..."。具体不展开,大家感兴趣可以自行搜索。

接下来我们看看log_函数的实现:

|---------------------------------|-------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 9 10 11 | template <typename... Args> void log_(source_loc loc, level::level_enum lvl, string_view_t fmt, Args &&...args) { bool log_enabled = should_log(lvl); bool traceback_enabled = tracer_.enabled(); if (!log_enabled && !traceback_enabled) { return; } memory_buf_t buf; fmt::vformat_to(fmt::appender(buf), fmt, fmt::make_format_args(args...)); details::log_msg log_msg(loc, name_, lvl, string_view_t(buf.data(), buf.size())); log_it_(log_msg, log_enabled, traceback_enabled); } |

首先判断是否需要记录日志should_log(lvl),以及是否需要traceback,如果都不需要则直接返回。判断逻辑是当前log等级是否大于logger的log等级。比如代码开发过成功会输出debug等级的日志,但是生产环境只输出info及以上等级的日志。这样就只需要调整logger的log等级,就能控制日志输出的情况。因此这里要做此判断。而traceback是spdlog的另一个功能,对我们理解spdlog的调用过程相关程度不高,可不必细究。

接着使用第三方的fmt库做格式化,例如将("num {:.2f}", 1.23456)格式化成"num 1.23",这样有效内容就转换成了字符串。再把各种信息都封装到log_msg对象中,最后再调用log_it_函数。

至此logger完成了它的主要工作,最后很剩下的工作就是把log_msg对象交给下游的sink进行处理了,就是上面最后一句代码"log_it_(log_msg, log_enabled, traceback_enabled);"要做的事。这部分代码如下:

|------------------------------------------------------------------|---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 | void logger::log_it_(const spdlog::details::log_msg &log_msg, bool log_enabled, bool traceback_enabled) { if (log_enabled) { sink_it_(log_msg); } if (traceback_enabled) { tracer_.push_back(log_msg); } } void logger::sink_it_(const details::log_msg &msg) { for (auto &sink : sinks_) { if (sink->should_log(msg.level)) { sink->log(msg); } } if (should_flush_(msg)) { flush_(); } } void logger::flush_() { for (auto &sink : sinks_) { sink->flush(); } } |

log_it函数又进一步调用了sink_it函数。在sink_it函数中,首先遍历了sinks_中的所有sink,在把msg交由每个sink去处理。sinks_是logger的成员变量,其声明为"std::vector sinks_;"。可以看出一个logger是可以对应多个sink的,同时sink实际上还是指针形式保存在logger中的,意味着也可以存在多个logger都指向同一个sink的情况。这样日志的输入端(logger)和输出端(sink)就解耦了。这样方便我们扩展,比如现在想让日志同时输出到文件和控制台,只需要在创建logger的时候把两个sink都添加进去就可以了。

同时还看到sink_it函数中还调用了flush_函数,这个函数的作用是让所有sink都进行一次flush操作。前面的sink->log(msg)这是写入了缓冲区,而sink->flush()是将缓冲区的内容进一步写入到文件或者控制台等最终目的地。而且在sink_it函数调用fluah_函数之前,还调用了should_flush_函数,函数中判断了msg的等级和flush_level_的关系,如果msg的等级大于flush_level_则返回true,否则返回false。这么做的目的是减少不必要的flush操作。例如我们像保存info及其以上等级的日志,但是绝大多数时候我们并会实时地查看info级别的日志,但是error级别的日志我们却希望能够及时展示出来。那么我们可以将flush_level_设置为error,这样只有error级别的日志才会进行flush操作。

async-logger {#async-logger}

async-logger的代码在asyn_logger.h和async_looger-inl.h中,对应async_logger类。async_logger继承自logger,前面关于接受日志内容整理log_msg对象中的工作照常做,将对sink的调用(包括sink->log(msg)和sink->flush())都交由线程池去执行了,由此便实现了异步。代码如下:

|------------------------------------------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 9 10 11 12 13 14 | 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"); } } // thread_pool_ 的声明 std::weak_ptr<details::thread_pool> thread_pool_; |

线程池通过pool_ptr->post_log(shared_from_this(), msg, overflow_policy_);这句代码持有了当前asyn_logger的shared_ptr。那这样asyn_logger就不能再以shared_ptr的形式持有线程池了,因为会存在交叉引用带来的内存泄露问题。所以这里使用weak_ptr来持有线程池。

async_logger肯定是比logger快的,毕竟sink中的工作还需要实际IO,这部分相对耗时,交给线程池去做,主线程就可以继续往下执行了。毫无疑问,async_logger实现的重点是线程池。线程池里面要有一个多生产多消费的线程安全队列,用来存放日志内容。可以有多个async_logger(即生产者)向里面生产日志,又同时又多个线程(即消费者)从里面消费日志。这个队列的容量应该是有限的,当队列满了之后向里面生产日志可以有不同的策略,spdlog提供了三种策略:阻塞、丢弃新日志和丢弃旧日志。为方便实现这个需求,用循环队列来实现。

循环队列 {#循环队列}

循环队列的代码在circular_q.h中,实现起来不难。这里只提两点可能在没开始动手实现之前可能想不起来的点:

  • circular_q应设计成类模板,使其能够支持各种数据类型;
  • circular_q中实际存数据的std::vector vec_的大小应该比circular_q能存的数据大小多一个,这样才能判断队列是满的还是空的,两个状态不会混淆。

多生产多消费的线程安全队列 {#多生产多消费的线程安全队列}

这部分代码在mpmc_blocking_q.h中,我们先来看一下其中的成员变量:

|-------------------------|--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 | 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_; }; |

一眼看出queue_mutex_就是用来保护队列的q_。push_cv_和pop_cv_是用来实现生产者消费者模型的关键,其存在的目的是当q_为空或满时,消费者线程或生产者线程是阻塞式等待,而不是空转。我们看看向mpmc_blocking_queue中生产和消费数据的代码:

|------------------------------------------------------------|------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 | void enqueue(T &&item) { { std::unique_lock<std::mutex> lock(queue_mutex_); pop_cv_.wait(lock, [this] { return !this->q_.full(); }); q_.push_back(std::move(item)); } push_cv_.notify_one(); } void dequeue(T &popped_item) { { std::unique_lock<std::mutex> lock(queue_mutex_); push_cv_.wait(lock, [this] { return !this->q_.empty(); }); popped_item = std::move(q_.front()); q_.pop_front(); } pop_cv_.notify_one(); } |

enqueue也用了万能引用和完美转发,它首先获取了queue_mutex_的锁,然后通过pop_cv_.wait阻塞直到q_非满状态,然后item给move进q_中,最后先释放锁才通过push_cv_通知消费者。dequeue则做了类似的反向操作。

spdlog线程池 {#spdlog线程池}

线程池的代码在thread_pool.h和thread_pool-inl.h中,这里的线程池跟那些通用的线程池实现相比,核心没变,每个线程都是负责从队列里面取东西然后执行。不同是线程池因为是专门做日志输出工作的,所以去从队列里取的东西是日志相关的东西,通用的线程池一般取的是函数指针。而且spdlog线程池的线程安全保证都封装在上述的mpmc_blocking_queue(多生产多消费的线程安全队列)里了,所以spdlog线程池的代码逻辑反而简单了。

如果有不熟悉通用线程池实现的朋友,自荐另外一篇文章:梨li狸:C++定时器与线程池的实现与详解

我们就简单看看每个线程(worker)做的是事情:

|---------------------------------------------------------------------------------------|----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------| | 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 | void thread_pool::worker_loop_() { while (process_next_msg_()) { } } bool thread_pool::process_next_msg_() { async_msg incoming_async_msg; q_.dequeue(incoming_async_msg); switch (incoming_async_msg.msg_type) { case async_msg_type::log: { incoming_async_msg.worker_ptr->backend_sink_it_(incoming_async_msg); return true; } case async_msg_type::flush: { incoming_async_msg.worker_ptr->backend_flush_(); return true; } case async_msg_type::terminate: { return false; } default: { assert(false); } } return true; } |

上面的backend_sink_it_backend_flush_里面的实现跟前面同步logger中的logger::sink_it_logger::flush_是一样的。所以看到这就知道了,asyn_logger就是把其中调用sink这部分工作交给线程池来做了,仅此而已。

相关文章:

参考链接:https://zhuanlan.zhihu.com/p/674073158


赞(1)
未经允许不得转载:工具盒子 » 超详细!spdlog源码解析(上)