brpc 流式日志Streaming Log完全指南从 std::ostream 原理到 LOG / PLOG / VLOG / CHECK 全套宏实战【免费下载链接】brpcbrpc is an Industrial-grade RPC framework using C Language, which is often used in high performance system such as Search, Storage, Machine learning, Advertisement, Recommendation etc. brpc means better RPC.项目地址: https://gitcode.com/GitHub_Trending/brpc/brpcbrpcbetter RPC内置了一套工业级的 C 流式日志库——streaming log它通过继承std::ostream让任意实现了operator的对象都能零临时内存地直接打入日志并提供LOG、PLOG、VLOG、CHECK、noflush、LOG_EVERY_N、LOG_ONCE等一整套与 glog 高度兼容的宏。本文以 docs/cn/streaming_log.md 为骨架结合 src/butil/logging.h、src/butil/logging.cc 与 test/logging_unittest.cc 的源码实现系统讲解流式日志的底层原理、全套宏的语义、等级体系、频控打印、bthread 友好缓冲以及 LogSink 自定义输出读完即可在你的 brpc 服务中写出正确、高效、可观测的日志代码。一、流式日志的设计原理为什么是 std::ostream流式日志streaming log是打印复杂对象或模板对象的不二之选。大部分业务对象都很复杂如果用printf形式的函数打印你需要先把对象转成string才能以%s输出。但string组合起来既不方便比如没法直接 append 数字还得分配大量的临时内存string导致的。C 中解决这个问题的方法便是把日志流式地送入std::ostream对象。为了打印对象 A我们需要实现如下的函数std::ostream operator(std::ostream os, const A a);这个函数的意思是把对象a打印入os并返回os。之所以返回os是因为operator对应了二元操作左结合当我们写下os a b c;时它相当于operator(operator(operator(os, a), b), c);。很明显operator需要不断地返回os的引用才能完成这个过程这个过程一般称为chaining。在不支持重载二元运算符的语言中你可能会看到一些更繁琐的形式比如os.print(a).print(b).print(c)。我们在operator的实现中也使用 chaining。事实上流式打印一个复杂对象就像 DFS 一棵树一样逐个调用儿子节点的operator儿子又逐个调用孙子节点的operator以此类推。比如对象 A 有两个成员变量 B 和 C打印 A 的过程就是把其中的 B 和 C 对象送入 ostream 中struct A { B b; C c; }; std::ostream operator(std::ostream os, const A a) { return os A{b a.b , c a.c }; }B 和 C 的结构及打印函数分别如下struct B { int value; }; std::ostream operator(std::ostream os, const B b) { return os B{value b.value }; } struct C { string name; }; std::ostream operator(std::ostream os, const C c) { return os C{name c.name }; }那么打印某个 A 对象的结果可能是A{bB{value10}, cC{nametom}}在打印过程中我们不需要分配临时内存因为对象都被直接送入了最终要送入的那个ostream对象。当然ostream对象自身的内存管理是另一回事了。把对象的打印过程通过ostream串联起来之后最常见的std::cout和std::cerr都继承了ostream所以实现了上面函数的对象就可以输出到std::cout和std::cerr了。换句话说如果日志流也继承了ostream那么那些对象也可以打入日志了。流式日志正是通过继承std::ostream把对象打入日志的。从源码结构看这一设计在 src/butil/logging.h 中的LogStream类上得到了直接印证class LogStream : virtual private CharArrayStreamBuf, public std::ostream { ... bool _noflush; // noflush 标志位 ... };LogStream同时私有继承了CharArrayStreamBuf并公开继承了std::ostream从而把日志内容写入自定义的字符缓冲。在目前的实现中送入日志流的日志被记录在thread-local 的缓冲中在完成一条日志后会被刷入屏幕或logging::LogSink这个实现是线程安全的。logging.cc中通过bthread_key_create/bthread_setspecific/bthread_getspecific见 src/butil/logging.cc把日志流挂到 bthread 的 thread-local 存储上因此即便在多线程、多 bthread 并发场景下每条日志的缓冲也是彼此隔离、安全刷出的。二、LOG与 glog 同名的核心宏如果你用过 glog那LOG基本不用学习因为宏名称和 glog 是一致的。注意不需要加上std::endlLOG(FATAL) Fatal error occurred! contexts ...; LOG(WARNING) Unusual thing happened ... ...; LOG(TRACE) Something just took place... ...;streaming log 的日志等级与 glog 映射关系如下streaming logglog使用场景FATALFATAL (coredump)致命错误。但由于百度内大部分 FATAL 实际上非致命所以 streaming log 的 FATAL 默认不像 glog 那样直接 coredump除非打开了crash_on_fatal_log这个 gflagERRORERROR不致命的错误。WARNINGWARNING不常见的分支。NOTICE-一般来说你不应该使用 NOTICE它用于打印重要的业务日志若要使用务必和检索端同学确认。glog 没有 NOTICE。INFO, TRACEINFO打印重要的副作用。比如打开关闭了某某资源之类的。VLOG(n)INFO打印分层的详细日志。DEBUGINFOVLOG(1) (NDEBUG)仅为代码兼容性基本没有用。若要使日志仅在未定义 NDEBUG 时才打印用 DLOG/DPLOG/DVLOG 等即可。源码中等级常量定义在 src/butil/logging.hBLOG_VERBOSE -1、BLOG_INFO 0、BLOG_NOTICE 1、BLOG_WARNING 2、BLOG_ERROR 3、BLOG_FATAL 4共 5 个等级其中BLOG_TRACE就是BLOG_INFOBLOG_DEBUG在NDEBUG未定义时等于BLOG_INFO、定义了NDEBUG时退化为BLOG_VERBOSE——这正是上表中DEBUG 仅为代码兼容性的由来。关于 FATAL 的默认行为crash_on_fatal_log是一个 gflag默认值为falseCrash process when a FATAL log is printed定义在 src/butil/logging.cc。也就是说brpc 的LOG(FATAL)默认只打印日志并终止当前逻辑并不会像 glog 默认那样直接 coredump只有显式设置--crash_on_fatal_logtrue才会崩溃方便在线上对真正的致命错误做兜底。另外与等级相关的还有一个常用 gflagminloglevel默认值为0含义是只打印等级大于等于该值的日志低于该值的被静默丢弃0INFO 1NOTICE 2WARNING 3ERROR 4FATAL定义见 src/butil/logging.cc可通过--minloglevel2等方式在启动时压制低等级日志。三、PLOG自动附加 errno 错误信息PLOG和LOG的不同之处在于它会在日志后加上错误码的信息类似于printf中的%m。在 posix 系统中错误码就是errno。int fd open(foo.conf, O_RDONLY); // foo.conf does not exist, errno was set to ENOENT if (fd 0) { PLOG(FATAL) Fail to open foo.conf; // Fail to open foo.conf: No such file or directory return -1; }单测 test/logging_unittest.cc 验证了这一点当errno为EINTR时PLOG(FATAL) Error occurred的完整输出为Error occurred: Interrupted system call。在errno语义不清或日志输出与预期不符时请先确认errno已被正确设置例如某些成功路径并不会清空errno。四、noflush延迟刷出循环打印的利器如果你暂时不希望刷到屏幕加上noflush。这一般会用在打印循环中LOG(TRACE) Items: noflush; for (iterator it items.begin(); it ! items.end(); it) { LOG(TRACE) *it noflush; } LOG(TRACE);前两次 TRACE 日志都没有刷到屏幕而是还记录在 thread-local 缓冲中第三次 TRACE 日志则把缓冲都刷入了屏幕。如果 items 里面有三个元素不加noflush的打印结果可能是这样的TRACE: ... Items: TRACE: ... item1 TRACE: ... item2 TRACE: ... item3加了之后是这样的TRACE: ... Items: item1 item2 item3从源码看noflush被实现为一个操纵符inline LogStream noflush(LogStream ls)它把LogStream的_noflush标志置为true见 src/butil/logging.h并在LogStream::Flush等刷出逻辑中读取该标志决定是刷入目标还是继续积累_noflush字段定义于 src/butil/logging.h。noflush支持 bthread可以实现类似于 UB 的 pushnotice 的效果即检索线程一路打印都暂不刷出加上noflush直到最后检索结束时再一次性刷出。注意如果检索过程是异步的就不应该使用noflush因为异步显然会跨越 bthread使noflush仍然失效。注意如果编译时开启了 glog 选项BRPC_WITH_GLOG则不支持noflush。五、条件打印LOG_IFLOG_IF(log_level, condition)只有当condition成立时才会打印相当于if (condition) { LOG() ...; }但更加简短。比如LOG_IF(NOTICE, n 10) This log will only be printed when n 10;六、频控打印EVERY_SECOND / EVERY_N / FIRST_N / ONCE在高频热点路径上直接打日志会把日志系统压垮brpc 提供了四组频控宏用极小的开销换取既能探查运行状态又不刷屏的效果。XXX_EVERY_SECONDXXX 可以是 LOG、LOG_IF、PLOG、SYSLOG、VLOG、DLOG 等。这类日志每秒最多打印一次可放在频繁运行热点处探查运行状态。第一次必打印比普通 LOG 增加一次gettimeofday30ns 左右的开销。LOG_EVERY_SECOND(INFO) High-frequent logs;XXX_EVERY_NXXX 可以是 LOG、LOG_IF、PLOG、SYSLOG、VLOG、DLOG 等。这类日志每触发 N 次才打印一次可放在频繁运行热点处探查运行状态。第一次必打印比普通 LOG 增加一次relaxed 原子加的开销。这个宏是线程安全的即不同线程同时运行这段代码时对 N 的限制也是准确的——文档明确说明 glog 中的同名宏不是线程安全的。LOG_EVERY_N(ERROR, 10) High-frequent logs;XXX_FIRST_NXXX 可以是 LOG、LOG_IF、PLOG、SYSLOG、VLOG、DLOG 等。这类日志最多打印 N 次。在 N 次前比普通 LOG 增加一次 relaxed 原子加的开销N 次后基本无开销。LOG_FIRST_N(ERROR, 20) Logs that prints for at most 20 times;XXX_ONCEXXX 可以是 LOG、LOG_IF、PLOG、SYSLOG、VLOG、DLOG 等。这类日志最多打印 1 次等价于XXX_FIRST_N(..., 1)LOG_ONCE(ERROR) Logs that only prints once;这些宏的原子计数依赖butil/atomicops.h见 src/butil/logging.h 的 include 注释 Used by LOG_EVERY_N, LOG_FIRST_N etc这也是EVERY_N能做到跨线程精确计数的底层保证。七、VLOG分层详细日志与模块级覆盖VLOG(verbose_level)是分层的详细日志通过两个 gflags--verbose和--verbose_module控制需要打印的层注意 glog 是--v和--vmodule。只有当--verbose指定的值大于等于verbose_level时对应的 VLOG 才会打印。比如VLOG(0) verbose log tier 0; VLOG(1) verbose log tier 1; VLOG(2) verbose log tier 2;当--verbose1时前两条会打印最后一条不会。--verbose_module可以覆盖某个模块的级别模块指去掉扩展名的文件名或文件路径。比如--verbose1 --verbose_modulechannel2,server3 # 打印 channel.cpp 中 2server.cpp 中 3其他文件 1 的 VLOG --verbose1 --verbose_modulesrc/brpc/channel2,server3 # 当不同目录下有同名文件时可以加上路径--verbose和--verbose_module可以通过google::SetCommandLineOption动态设置glog 风格接口。从源码看brpc 在非 glog 模式下还额外注册了v与vmodule两个兼容 gflag默认值0与语义与 glog 相同见 src/butil/logging.cc单测 test/logging_unittest.cc 展示了通过SetCommandLineOption(v, 1)与SetCommandLineOption(vmodule, logging_unittest1)动态调整 VLOG 层级的用法。VLOG 有一个变种VLOG2让用户指定虚拟文件路径比如// public/foo/bar.cpp VLOG2(a/b/c, 2) being filtered by a/b/c rather than public/foo/bar;VLOG 和 VLOG2 也有相应的VLOG_IF和VLOG2_IF。八、DLOGDebug 版日志与副作用陷阱所有的日志宏都有 debug 版本以 D 开头比如DLOG、DVLOG当定义了NDEBUG后这些日志不会打印。千万别在 D 开头的日志流上有重要的副作用。不会打印指的是连参数都不会评估。如果你的参数是有副作用的那么当定义了 NDEBUG 后这些副作用都不会发生。比如DLOG(FATAL) foo();其中foo是一个函数它修改一个字典反正必不可少但当定义了 NDEBUG 后foo就运行不到了。从宏定义看src/butil/logging.hNDEBUG 下DLOG_IF被替换为BAIDU_EAT_STREAM_PARAMS即整个流表达式在编译期被吃掉参数求值自然也不会发生。九、CHECK断言式日志与调用栈定位日志另一个重要变种是CHECK(expression)当expression为 false 时会打印一条 FATAL 日志。类似 gtest 中的 ASSERT也有CHECK_EQ、CHECK_GT等变种。当 CHECK 失败后其后的日志流会被打印。CHECK_LT(1, 2) This is definitely true, this log will never be seen; CHECK_GT(1, 2) 1 cant be greater than 2;运行后你应该看到一条 FATAL 日志和调用处的 call stackFATAL: ... Check failed: 1 2 (1 vs 2). 1 cant be greater than 2 #0 0x000000afaa23 butil::debug::StackTrace::StackTrace() #1 0x000000c29fec logging::LogStream::FlushWithoutReset() #2 0x000000c2b8e6 logging::LogStream::Flush() #3 0x000000c2bd63 logging::DestroyLogStream() #4 0x000000c2a52d logging::LogMessage::~LogMessage() #5 0x000000a716b2 (anonymous namespace)::StreamingLogTest_check_Test::TestBody() #6 0x000000d16d04 testing::internal::HandleSehExceptionsInMethodIfSupported() #7 0x000000d19e96 testing::internal::HandleExceptionsInMethodIfSupported() #8 0x000000d08cd4 testing::Test::Run() #9 0x000000d08dfe testing::TestInfo::Run() #10 0x000000d08ec4 testing::TestCase::Run() #11 0x000000d123c7 testing::internal::UnitTestImpl::RunAllTests() #12 0x000000d16d94 testing::internal::HandleSehExceptionsInMethodIfSupported()call stack 中的第二列是代码地址你可以使用addr2line查看对应的文件行数$ addr2line -e ./test_base 0x000000a716b2 /home/gejun/latest_baidu_rpc/public/common/test/test_streaming_log.cpp:223提示实际使用时把./test_base换成你自己的可执行文件路径把地址换成 call stack 中#N行对应的地址。CHECK 失败时打印栈的能力由print_stack_on_checkgflag 控制默认true见 src/butil/logging.cc。你应该根据比较关系使用具体的CHECK_XX这样当出现错误时你可以看到更详细的信息比如int x 1; int y 2; CHECK_GT(x, y); // Check failed: x y (1 vs 2). CHECK(x y); // Check failed: x y.CHECK系列在 src/butil/logging.h 中提供了CHECK_EQ、CHECK_NE、CHECK_LE、CHECK_LT、CHECK_GE、CHECK_GT六个比较变种对应、!、、、、。和 DLOG 类似你不应该在 DCHECK 的日志流中包含重要的副作用。十、LogSink自定义日志输出目标streaming log 通过logging::SetLogSink修改日志刷入的目标默认是屏幕。用户可以继承LogSink实现自己的日志打印逻辑。LogSink的核心接口定义在 src/butil/logging.hclass LogSink { public: LogSink() {} virtual ~LogSink() {} // Called when a log is ready to be written out. // Returns true to stop further processing. virtual bool OnLogMessage(int severity, const char* file, int line, const butil::StringPiece log_content) 0; virtual bool OnLogMessage(int severity, const char* file, int line, const char* /*func*/, const butil::StringPiece log_content) { return OnLogMessage(severity, file, line, log_content); } ... }; // Sets the LogSink that gets passed every log message before // its sent to default log destinations. // This function is thread-safe and waits until current LogSink is not used // anymore. // Returns previous sink. BUTIL_EXPORT LogSink* SetLogSink(LogSink* sink);要点每条日志在写入默认目的地之前都会先交给当前LogSink的OnLogMessageOnLogMessage返回true表示停止后续处理。SetLogSink是线程安全的会等待当前 LogSink 不再被使用后才完成切换并返回之前的 sink便于用完恢复。带func参数的重载版本默认转调四参数版本自定义 sink 可以按需覆写其中之一。StringSink面向单测的官方实现StringSink同时继承了LogSink和std::string把日志内容存放在 string 中主要用于单测。其定义见 src/butil/logging.h内部用butil::Lock保证多线程 append 的安全。单测 test/logging_unittest.cc 演示了StringSink的典型用法——配合LOG_AT指定任意的文件/行号TEST_F(LoggingTest, log_at) { ::logging::StringSink log_str; ::logging::LogSink* old_sink ::logging::SetLogSink(log_str); LOG_AT(WARNING, specified_file.cc, 12345) file/line is specified; // the file:line part should be using the argument given by us. ASSERT_NE(std::string::npos, log_str.find(specified_file.cc:12345)); // restore the old sink. ::logging::SetLogSink(old_sink); }LOG_AT(severity, file, line)是另一个实用宏它允许你在日志中显式指定file与line而不是使用宏所在的编译位置这在转发日志、统一归集日志来源时非常有用它还有一个带函数名的四参数变体LOG_AT(severity, file, line, func)宏定义见 src/butil/logging.h。十一、从源码看实现要点小结日志等级5 级枚举BLOG_INFO到BLOG_FATALTRACE与INFO同值DEBUG在 NDEBUG 下退化为 verbose见 src/butil/logging.h。流式核心LogStream私有继承CharArrayStreamBuf、公开继承std::ostream日志先进入 thread-local 缓冲完成一条后刷入屏幕或LogSink见 src/butil/logging.h。bthread 支持日志流挂在 bthread 的 thread-local 上bthread_key_create等见 src/butil/logging.cc这是noflush能在 bthread 内攒批刷出的基础。频控宏EVERY_N/FIRST_N/ONCE依赖butil/atomicops.h的 relaxed 原子操作实现线程安全的计数见 src/butil/logging.h。常用 gflagcrash_on_fatal_logFATAL 是否崩溃、minloglevel等级过滤、log_pid/log_bid/log_hostname/log_year日志内容增强、v/vmoduleVLOG 层级glog 兼容均定义于 src/butil/logging.cc。测试佐证LOG_AT、PLOG、VLOG层级、StringSink等行为均有对应单测可查阅 test/logging_unittest.cc 继续深入。十二、实战建议复杂对象一律实现operator让日志天然具备树状可读结构避免临时string拼接带来的分配开销LOG(TRACE) obj即可直接输出。区分等级FATAL留给真正不可恢复的错误并配合crash_on_fatal_log决定是否崩溃WARNING给不常见分支INFO/TRACE给重要的副作用资源打开/关闭业务重要日志谨慎使用NOTICE。热点路径用频控宏每秒探查用LOG_EVERY_SECOND按次数抽样用LOG_EVERY_N一次性告警用LOG_ONCE避免高频日志拖垮服务。系统调用失败用PLOG自动带上errno的描述排查文件打不开连接失败时省去手动查错误码。循环攒批用noflush仅在同步、不跨 bthread 的代码路径中使用异步流程请勿使用且 glog 模式下不支持。VLOG分层治理详细日志线上默认--verbose0排查时按模块--verbose_modulexxx2动态放大无需改代码重编译。自定义采集用LogSink继承LogSink并SetLogSink即可把日志重定向到自己的存储/上报系统单测中用StringSink断言日志内容保证日志行为可验证。【免费下载链接】brpcbrpc is an Industrial-grade RPC framework using C Language, which is often used in high performance system such as Search, Storage, Machine learning, Advertisement, Recommendation etc. brpc means better RPC.项目地址: https://gitcode.com/GitHub_Trending/brpc/brpc创作声明：本文部分内容由AI辅助生成（AIGC），仅供参考
