NanoLogLite是NanoLog的简化版，专注于提高日志性能。本文详细介绍了其源码，包括无锁编程、预处理、运行时库和解码器组件。通过分析日志级别、结构设计和性能优化，阐述了NanoLogLite如何实现低延迟、高吞吐量。文章还探讨了如何使用和理解NanoLogLite的API，如log宏、线程局部存储和回调函数注册等功能。
NanoLogLite源码阅读
前言
这篇文章将主要记录自己阅读NanoLogLite源码后，对它的一个总结与理解（推迟了三个多月才来补这篇文章，就当回忆巩固了吧），并在此基础上，进行了一系列改动。
- 回调函数的注册
- 屏蔽写磁盘操作
- 加tag标识用于在一个程序中生成多个日志流
- 进行日志库的上层封装
- 进行日志存储功能的实现
这个代码，说来惭愧，也算是我在大四的末尾所阅读的第一个开源源码（也是大学的最后一个），同时由于源码中包含着诸多的C++14、甚至17以上的新特性以及泛型编程、元编程的思想，使得我对源码的阅读更加加深了难度，参考资料也比较少，一开始举步维艰，不过好在一步步来，慢慢走，最终还是达到了理想中的预期。
NanoLogLite简介
一般日志的级别
- ERROR:此信息输出后，主体系统核心模块不能正常工作，需要修复才能正常工作
- WARN：此信息输出后，系统一般模块存在问题，不影响系统运行
- INFO：此信息输出后，主要是记录系统运行状态等关联信息
- DEBUG：最细粒度的输出，除却上面各种情况后，你希望输出的相关信息，都可以在这里输出
- TRACE：最细粒度的输出，除却上面各种情况后，你希望输出的相关信息，都可以在这里输出
一般日志的结构设计
多个线程或进程将格式化好的日志写入到一个缓存队列中去，并且定期的将日志内存刷新到可持久化存储的物质上去（磁盘）。
在这种简单的日志系统的结构中，有以下三个开销。
- 格式化
- 多线程写入缓存队列时的加锁开销
- 日志持久化存储的开销
以上三点便是日志系统中影响性能的主要原因，NanoLog则针对以上三点分别进行了优化，使得性能获得了较大的提升。
NanoLog
Nanlog是一款延迟很低吞吐量很高的日志工具，该日志系统较其他常用日志系统延迟低一到两个数量级，吞吐量高一到两个数量级。
https://github.com/PlatformLab/NanoLog/tree/master/preprocessor
Nanlog快的原因
- 无锁编程
- 尽量减少cache miss
- 采用记录系统的tsc寄存器的数值来记录时间，尽可能避免慢速的函数调用
- 对信息进行压缩再解压来提升速度
NanoLog 的不同设计方式决定了它与传统日志模块会在架构上有很大的差异，它由以下三个组件构成：
[外链图片转存失败,源站可能有防盗链机制,建议将图片保存下来直接上传(img-bgyf9DKx-1662023735687)(https://s3-us-west-2.amazonaws.com/secure.notion-static.com/85398d00-0dfb-4b3b-a21e-2c355f1d9f46/Untitled.png)]
-
预处理器：在编译期间从源代码提取日志消息、将原始日志语句替换成优化过的代码并为每条日志消息生成压缩、字典辅助函数；
-
运行时库：在缓冲区中缓存多个线程打印的日志并使用预处理阶段生成的辅助函数输出压缩后的二进制日志；
-
解码器：利用预处理阶段生成的包含静态信息的字典解码日志，获取可以被人类阅读的日志；
-
在编译时重写了日志语句移除静态信息并将昂贵的格式化操作推迟到代码运行后的阶段，这能够在运行时减少大量的计算和 I/O 带宽需求；
-
为每个日志消息编译了特定代码，能够高效地处理动态参数，避免在运行时解析日志消息并编码参数类型；
-
使用轻量级的压缩算法以及不保序的日志减少运行时的 I/O 和处理时间；
-
使用后处理组合压缩的日志数据和编译时提取的静态信息生成可读的日志；
NanoLogLite
NanoLogLite则是在NanoLog的基础上进行了一系列的魔改，取消了日志压缩的过程，使得我们更加容易理解与阅读。后续的介绍均是针对于NanoLogLite展开的。
NanoLogLite源码解析
NanoLogLite的使用
在理解NanoLogLite代码之前需要先能够使用好NanoLogLite进行打日志，供我们常调用的接口如下。
日志写入
#define logi(format, ...) NANO_LOG(INFO, format, ##__VA_ARGS__)
#define logw(format, ...) NANO_LOG(WARN, format, ##__VA_ARGS__)
#define loge(format, ...) NANO_LOG(ERR, format, ##__VA_ARGS__)
#define logd(format, ...) NANO_LOG(DEBUG, format, ##__VA_ARGS__)
logd("Now debug msg is shown");
logw("A callback warning message: %d.", i);
即我们如果需要写入日志的话，只需要以类似printf的形式，便可以进行日志的写入。
分为四个等级依次为info、warn、err、debug，使用者可以根据需要进行调用。
还提供了日志显示等级的函数，即能够屏蔽掉较低等级的日志信息。
void setLogLevel(LogLevel logLevel);
除此之外，提供了一些其他功能函数如下。
// 为该线程开启的日志流设置名字
void setThreadName(const char* name);
// 日志缓存刷新入磁盘
void poll();
以上便是常用到的一些函数，其余的函数用的较少，这里就不在此进行列举了。
NanoLogLite代码理解
一般对于调用逻辑清晰的代码直接从调用入口处一步步走下去，便能理解出大概了。这也是我在阅读NanoLogLite代码时所用到的方法。
#define logi(format, ...) NANO_LOG(INFO, format, ##__VA_ARGS__)
首先便是一个可变参数的宏定义，通过上述的写法，使得我们的log库能够进行格式化的书写。
接着我们将进入NANO_LOG这个函数，其实也是一个宏定义。
#define NANO_LOG(severity, format, ...) \
do {
/*
numNibbles：记录非字符串以及精度和宽度的变量个数（精度和宽度会有专门的符号进行标识）
nParams：记录参数的总个数
*/ \
constexpr int numNibbles = NanoLogInternal::getNumNibblesNeeded(format); \
constexpr int nParams = NanoLogInternal::countFmtParams(format); \
\
/*** Very Important*** These must be 'static' so that we can save pointers \
* to these variables and have them persist beyond the invocation. \
* The static logId is used to forever associate this local scope (tied \
* to an expansion of #NANO_LOG) with an id and the paramTypes array is \
* used by the compression function, which is invoked in another thread \
* at a much later time.
* paraTypes：记录所有参数类型*/ \
static constexpr std::array<NanoLogInternal::ParamType, nParams> paramTypes = \
NanoLogInternal::analyzeFormatString<nParams>(format); \
static int logId = NanoLogInternal::UNASSIGNED_LOGID; \
\
if (NanoLog::severity > NanoLog::getLogLevel()) break; \
\
/* Triggers the GNU printf checker by passing it into a no-op function. \
* Trick: This call is surrounded by an if false so that the VA_ARGS don't \
* evaluate for cases like '++i'.*/ \
if (false) { \
NanoLogInternal::checkFormat(format, ##__VA_ARGS__); \
} /*NOLINT(cppcoreguidelines-pro-type-vararg, hicpp-vararg)*/ \
/*
继续向下执行
*/ \
NanoLogInternal::log(logId, __FILE__, __LINE__, NanoLog::severity, format, numNibbles, paramTypes, ##__VA_ARGS__); \
} while (0)
上述代码中给出了重要函数的注释，在这段代码中，记录一下几个零散的知识点。
- do{}while(0)： 当宏定义中的内容需要为多条语句进行执行时，可以借助do{code}while(0)来进行辅助实现。
- constexpr: 该关键字的主要作用是使指定的常量表达式获得在程序编译阶段计算出结果的能力，而不必等到程序运行阶段。
- 里面函数的执行包含了大量元编程、泛型编程的思想，可以在了解的基础上进行代码的阅读用于加以巩固。
接下来便要进入到log函数中去。
template<long unsigned int N, int M, typename... Ts>
inline void log(int& logId, const char* filename, const int linenum, const LogLevel severity, const char (&format)[M],
const int numNibbles, const std::array<ParamType, N>& paramTypes, Ts... args) {
assert(N == static_cast<uint32_t>(sizeof...(Ts)));
//该线程初次调用，需要进行对应初始化操作
if (logId == UNASSIGNED_LOGID) {
const ParamType* array = paramTypes.data();
const char* pos = strrchr(filename, '/');
if (pos) filename = pos + 1;
// 静态成员将静态信息进行存储
StaticLogInfo info(&compress<Ts...>, filename, linenum, severity, format, numNibbles, array);
// 将 info加入到 invocationSites中去，并更新logId
RuntimeLogger::registerInvocationSite(info, logId);
}
uint64_t previousPrecision = -1;
uint64_t timestamp = tscns.rdtsc();
size_t stringSizes[N + 1] = {}; // HACK: Zero length arrays are not allowed
// 获得总分配空间的大小
size_t allocSize = getArgSizes(paramTypes, previousPrecision, stringSizes, args...) + 8;
// 将其在线程局部缓存中分配空间，若一开始线程局部缓存为空，则会预先申请局部缓存空间，并将其加入全局变量中
auto header = NanoLogInternal::RuntimeLogger::reserveAlloc(allocSize);
if (!header) return;
header->userdata = logId;
char* writePos = (char*)(header + 1);
*(uint64_t*)writePos = timestamp;
writePos += 8;
// 将参数写入到writePos中，即MsgHeader
store_arguments(paramTypes, stringSizes, &writePos, args...);
NanoLogInternal::RuntimeLogger::finishAlloc();
}
log函数主要完成两部工作，分别为静态信息的存储以及动态信息的大小计算及空间分配，静态信息主要存储在invocationSites中，动态信息则存储在线程局部存储StagingBuffer中，在源码中运用了大量泛型编程的思想，阅读起来还是比较吃力的，但理解逻辑后，就会轻松很多~
小思想
NanoLogLite实现无锁写日志也正是通过这一步的线程局部存储（TLS）来实现的，具体线程局部存储的含义可以见我另一篇blog线程局部存储。
每一个线程维护一个StagingBuffer对象来存储日志，全局维护一个buffer对象来存储这些每个线程中的StagingBuffer数据，就类似于一个大数组提前划分好若干个小数组，每个小数组由不同的线程进行管理，便实现了无锁编程。
以上便是写日志时所需的时间，格式化等操作将另起一个进程每隔一段时间进行一次poll的回调，来进行专门的格式化操作，这样便大大提高了写日志的速率，减少了时延。
poll函数如下所示，这个poll函数我已经加入了回调函数进行修改，即支持自定义的一系列函数操作。
void RuntimeLogger::poll_(fn_log_callback call_back) {
char compress_buf[1024 * 1024];
char output_buf[1024 * 1024];
{
std::unique_lock<std::mutex> lock(registrationMutex);
for (size_t i = bgInvocationSites.size(); i < invocationSites.size(); i++) {
// 将字符串根据宽度精度等进行正则匹配，生成rawFragmentEnd
invocationSites[i].createFragments(&rawFragmentEnd);
// 加入到bgInvocationSites中
bgInvocationSites.push_back(invocationSites[i]);
}
}
{
std::unique_lock<std::mutex> lock(bufferMutex);
for (size_t i = 0; i < threadBuffers.size(); i++) {
StagingBuffer* sb = threadBuffers[i];
while (true) {
auto header = sb->peek();
if (!header) {
// If there's no work, check if we're supposed to delete
// the stagingBuffer
if (sb->checkCanDelete()) {
delete sb;
std::swap(threadBuffers[i], threadBuffers.back());
threadBuffers.pop_back();
i--;
}
break;
}
if (header->userdata >= bgInvocationSites.size()) break;
StaticLogInfo& info = bgInvocationSites[header->userdata];
header++;
uint64_t timestamp = *(uint64_t*)(header);
header++;
char* argData = (char*)header;
char* writePos = compress_buf;
// 进行进一步压缩
info.compressionFunction(info.numNibbles, info.paramTypes, &argData, &writePos);
Nibbler nb(compress_buf, info.numNibbles);
const char* nextStringArg = nb.getEndOfPackedArguments();
char* output = output_buf;
// Print out the actual log message, piece by piece
PrintFragment* pf = reinterpret_cast<PrintFragment*>(info.fragments);
for (int i = 0; i < info.numPrintFragments; ++i) {
const wchar_t* wstrArg;
int width = -1;
if (pf->hasDynamicWidth) width = nb.getNext<int>();
int precision = -1;
if (pf->hasDynamicPrecision) precision = nb.getNext<int>();
switch (pf->argType) {
case NONE:
#pragma GCC diagnostic push
#pragma GCC diagnostic ignored "-Wformat-security"
#pragma GCC diagnostic ignored "-Wformat-nonliteral"
output += sprintf(output, pf->formatFragment);
#pragma GCC diagnostic pop
break;
case unsigned_char_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<unsigned char>(), width, precision);
break;
case unsigned_short_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<unsigned short int>(), width, precision);
break;
case unsigned_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<unsigned int>(), width, precision);
break;
case unsigned_long_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<unsigned long int>(), width, precision);
break;
case unsigned_long_long_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<unsigned long long int>(), width, precision);
break;
case uintmax_t_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<uintmax_t>(), width, precision);
break;
case size_t_t: printSingleArg(&output, pf->formatFragment, nb.getNext<size_t>(), width, precision); break;
case wint_t_t: printSingleArg(&output, pf->formatFragment, nb.getNext<wint_t>(), width, precision); break;
case signed_char_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<signed char>(), width, precision);
break;
case short_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<short int>(), width, precision);
break;
case int_t: printSingleArg(&output, pf->formatFragment, nb.getNext<int>(), width, precision); break;
case long_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<long int>(), width, precision);
break;
case long_long_int_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<long long int>(), width, precision);
break;
case intmax_t_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<intmax_t>(), width, precision);
break;
case ptrdiff_t_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<ptrdiff_t>(), width, precision);
break;
case double_t: printSingleArg(&output, pf->formatFragment, nb.getNext<double>(), width, precision); break;
case long_double_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<long double>(), width, precision);
break;
case const_void_ptr_t:
printSingleArg(&output, pf->formatFragment, nb.getNext<const void*>(), width, precision);
break;
// The next two are strings, so handle it accordingly.
case const_char_ptr_t:
printSingleArg(&output, pf->formatFragment, nextStringArg, width, precision);
nextStringArg += strlen(nextStringArg) + 1; // +1 for NULL
break;
case const_wchar_t_ptr_t:
wstrArg = reinterpret_cast<const wchar_t*>(nextStringArg);
printSingleArg(&output, pf->formatFragment, wstrArg, width, precision);
// +1 for NULL
nextStringArg += (wcslen(wstrArg) + 1) * sizeof(wchar_t);
break;
case MAX_FORMAT_TYPE:
default: output += sprintf(output, "Error: Corrupt log header in header file\r\n"); exit(-1);
}
pf =
reinterpret_cast<PrintFragment*>(reinterpret_cast<char*>(pf) + pf->fragmentLength + sizeof(PrintFragment));
}
static const char* logLevelNames[] = {"NAN", "ERR", "WRN", "INF", "DBG"};
const char* logLevel = logLevelNames[info.severity];
uint64_t ns = tscns.tsc2ns(timestamp);
uint64_t t = (ns - midnight_ns) / 1000;
uint32_t us = t % 1000000;
t /= 1000000;
uint32_t s = t % 60;
t /= 60;
uint32_t m = t % 60;
t /= 60;
uint32_t h = t % 24;
//add
sprintf(fmt, "%02d:%02d:%02d.%06d %s:%d %s[%s]: %s\n", h, m, s, us, info.filename, info.lineNum,
logLevel, sb->getName(), output_buf);
StaticInfo static_info_tmp(info.formatString, sb->getName(), info.severity, info.lineNum, us);
RuntimeLogger::static_info = static_info_tmp;
on_log_done(call_back);
//add
// if (outputFp) {
// fprintf(outputFp, "%02d:%02d:%02d.%06d %s:%d %s[%s]: %s\n", h, m, s, us, info.filename, info.lineNum,
// logLevel, sb->getName(), output_buf);
// }
if (logCB && info.severity <= maxCBLogLevel && info.last_ts + minCBPeriod < ns) {
info.last_ts = ns;
logCB(ns, info.severity, output_buf, output - output_buf);
}
sb->consume();
}
}
}
// if (outputFp) {
// fflush(outputFp);
// }
}
以上便是poll函数进行格式化的过程，理解整个过程的前提是对几个关键结构体进行理解，我整理的几个结构体如下所示。
以上便是NanoLogLite的大体步骤，具体还有许多细节还需在阅读源码的过程中反复揣摩，相信一定会收获颇丰。
扫一扫
722
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
