1. 为什么我会花一晚上重写printf1.1 printf散落各处的现实困境先聊个我自己的真实经历。某次我在维护一个跨平台系统的C项目代码跑了几个月功能没问题但一到联调阶段就头疼。几百个文件里到处是printf控制台刷得密密麻麻想找一条关键的初始化和参数输出得先翻好几分钟日志。等到产品要上线的时候更头疼的事来了这些printf总不能一行一行删吧删了之后现场出问题要怎么定位不删的话测试环境里那堆刷屏日志又没法给客户看。这就是典型的“调试输出没有等级管理”的问题。很多C语言项目在开发阶段图省事直接在代码里写printf等到需要控制输出的时候才意识到散落的printf既没有统一的格式也没有开关可控制。而C语言里最适合做这件事的恰恰是很多人觉得“有点绕”的宏定义。基于宏定义实现一套带等级的调试输出也就是标题里说的PRINT_LEVEL本质上就是给printf加一个分级、可控、可裁剪的前置管理机制。1.2 分等级之后的好消息我在这套机制里做了四个等级ERR、WARN、INFO、DBG分别对应错误、警告、关键信息、调试细节。好处是显而易见的平时把输出等级设置在INFO那么DBG等级的详细日志根本不会出现在屏幕上代码逻辑不用动需要排查问题的时候重新编译一次把等级调到DBG所有细节又全部回来了。如果仅仅是想“能开能关”加一个开关宏就够了。但为什么一定要分等级因为不同场景下的信息价值完全不同。比如一个网络通信模块连接失败是ERR重试是WARN启动完成是INFO每个数据包的内容则是DBG。如果只有一个开关要么全关要么全开。全关的时候线上出了毛病你什么都看不到全开的时候又会在正常环境下被海量调试信息淹没。分级之后就能在“噪音”和“细节”之间找到一个合适的平衡点这就是分等级的价值。2. 核心设计三个宏搞定PRINT_LEVEL2.1 等级定义与默认策略我的设计很简单等级本质上就是几个整型常量#define PRINT_LEVEL_ERR 0 #define PRINT_LEVEL_WARN 1 #define PRINT_LEVEL_INFO 2 #define PRINT_LEVEL_DBG 3数字越小越严重。选择整数而不是字符串的好处是可以直接比较大小比如“当前等级大于等于INFO才输出”。同时这个数字也方便通过编译选项传入。接下来定义“当前输出等级”。我的做法是给一个默认值同时允许在编译时通过-D参数覆盖#ifndef PRINT_LEVEL_CURRENT #define PRINT_LEVEL_CURRENT PRINT_LEVEL_INFO #endif这里有个关键点如果有人先include头文件再通过宏定义强制覆盖等级是不生效的。所以我把默认等级的保护条件写成#ifndef只要编译命令行里定义了PRINT_LEVEL_CURRENT头文件的默认值就不会覆盖它。这种“默认值可被外部覆盖”的做法是整个设计里最值得参考的一点。2.2 宏定义代替函数的三个理由有人会问分等级输出用普通函数不行吗比如写一个void log(int level, const char *fmt, ...)技术上确实行但我在实际使用中还是选了宏理由有三条。第一条宏可以拿到调用点的编译位置信息。__FILE__和__LINE__这两个预定义宏只有在宏展开的调用点才会被正确替换。如果封装到函数里__FILE__和__LINE__就变成log.c文件本身和函数内部的行号了那调试输出就失去意义了。第二条宏可以在编译阶段做裁剪。等级输出如果写成函数所有日志参数在调用时都会被求值即使不打印也要浪费CPU和栈空间。而宏配合条件编译可以做到“不满足等级条件的日志代码直接不编译”。这一点在单片机、嵌入式场景里特别重要。比如#if PRINT_LEVEL_CURRENT PRINT_LEVEL_DBG #define PRINT_DBG(fmt, ...) printf(fmt, ##__VA_ARGS__) #else #define PRINT_DBG(fmt, ...) do { } while (0) #endif这样当当前等级低于DBG时PRINT_DBG这个宏展开为一个空语句编译器根本不会为它生成任何代码。如果是函数调用即使不输出参数求值和函数调用的开销始终都在。第三条宏可以保持printf的调用习惯。用函数封装的话很多人都遇到过格式化字符串和可变参数的转发问题写着写着就变成了“二次格式化”要么多包一层缓冲区要么传递变得非常别扭。宏直接展开成printf传参行为跟原版printf完全一致不用自己处理va_list那一套。2.3 可变参数宏的跨平台写法宏定义里最容易踩坑的就是可变参数。C99标准提供了__VA_ARGS__但有一个历史遗留问题当可变参数为空的时候GCC和MSVC的处理方式不一样。GCC以及大多数类Unix编译器支持GNU扩展的写法在__VA_ARGS__前面加两个井号#define PRINT_LEVEL_LOG(level, fmt, ...) \ printf(fmt, ##__VA_ARGS__)这里的##不是字符串拼接它的作用是当可变参数为空时自动把fmt后面的那个逗号吃掉。比如调用PRINT_LEVEL_LOG(PRINT_LEVEL_INFO, hello)展开后就是printf(hello)而不是printf(hello,)。MSVC的传统预处理器不支持这个##__VA_ARGS__写法但它在处理空参数时又相对宽松所以为了兼容我通常写成两组#if defined(_MSC_VER) #define PRINT_LEVEL_LOG(level, fmt, ...) \ do { \ if ((level) PRINT_LEVEL_CURRENT) { \ printf([%s] %s:%d fmt \n, \ PRINT_LEVEL_NAME(level), __FILE__, __LINE__, __VA_ARGS__); \ } \ } while (0) #else #define PRINT_LEVEL_LOG(level, fmt, ...) \ do { \ if ((level) PRINT_LEVEL_CURRENT) { \ printf([%s] %s:%d fmt \n, \ PRINT_LEVEL_NAME(level), __FILE__, __LINE__, ##__VA_ARGS__); \ } \ } while (0) #endif我自己主要的开发环境是GCC和Clang所以正常情况下用下面那套。只有拿到Windows上编译时才需要切到上面那组。3. 可以直接抄的完整实现3.1 头文件print_level.h下面把完整的头文件放出来。这套代码我实际用了挺久基本的思路是“一个通用宏 四个等级快捷宏”。#ifndef PRINT_LEVEL_H #define PRINT_LEVEL_H #include stdio.h #define PRINT_LEVEL_ERR 0 #define PRINT_LEVEL_WARN 1 #define PRINT_LEVEL_INFO 2 #define PRINT_LEVEL_DBG 3 #ifndef PRINT_LEVEL_CURRENT #define PRINT_LEVEL_CURRENT PRINT_LEVEL_INFO #endif #define PRINT_LEVEL_NAME(level) \ ((level) PRINT_LEVEL_ERR ? ERR : \ (level) PRINT_LEVEL_WARN ? WARN : \ (level) PRINT_LEVEL_INFO ? INFO : \ (level) PRINT_LEVEL_DBG ? DBG : ?) #if defined(_MSC_VER) #define PRINT_LEVEL_LOG(level, fmt, ...) \ do { \ if ((level) PRINT_LEVEL_CURRENT) { \ printf([%s] %s:%d fmt \n, \ PRINT_LEVEL_NAME(level), __FILE__, __LINE__, __VA_ARGS__); \ } \ } while (0) #else #define PRINT_LEVEL_LOG(level, fmt, ...) \ do { \ if ((level) PRINT_LEVEL_CURRENT) { \ printf([%s] %s:%d fmt \n, \ PRINT_LEVEL_NAME(level), __FILE__, __LINE__, ##__VA_ARGS__); \ } \ } while (0) #endif #define PRINT_ERR(fmt, ...) PRINT_LEVEL_LOG(PRINT_LEVEL_ERR, fmt, ##__VA_ARGS__) #define PRINT_WARN(fmt, ...) PRINT_LEVEL_LOG(PRINT_LEVEL_WARN, fmt, ##__VA_ARGS__) #define PRINT_INFO(fmt, ...) PRINT_LEVEL_LOG(PRINT_LEVEL_INFO, fmt, ##__VA_ARGS__) #define PRINT_DBG(fmt, ...) PRINT_LEVEL_LOG(PRINT_LEVEL_DBG, fmt, ##__VA_ARGS__) #endif3.2 接口设计与使用示例使用接口的时候代码写起来跟printf几乎没有区别#include print_level.h int main(void) { PRINT_INFO(system started, version %s, 1.0.0); PRINT_DBG(dump param: count%d, size%lu, 10, sizeof(int)); PRINT_WARN(retry count exceeded, will continue); PRINT_ERR(file open failed, errno%d, 2); return 0; }默认等级是INFO所以上面四行输出中PRINT_DBG那一行不会显示。输出的格式是统一的[INFO] main.c:12 system started, version 1.0.0 [WARN] main.c:14 retry count exceeded, will continue [ERR] main.c:15 file open failed, errno2统一格式带来的好处是后续如果要做日志采集可以直接按固定模式去切割不需要每个模块自己定义一套输出格式。这也是我强烈建议“虽然只是调试输出也要统一格式”的原因。不然今天这里加个时间戳明天那里加个进程ID最后整个控制台像几个不同来源的日志硬拼在一起反而不如不输出。我把文件行号放在中括号外面是为了便于按列筛选。比如在终端里用管道grep :15 就能过滤出main.c第15行相关的输出。每个人对格式的偏好不同但一个原则不变日志格式一旦定下来就不要轻易改动否则历史日志就没法对比了。3.3 通过编译选项控制等级这套宏定义最有意思的地方在于等级切换根本不用改代码。编译的时候加一个-D参数就行gcc -DPRINT_LEVEL_CURRENTPRINT_LEVEL_DBG -o app main.c要把等级降到WARNgcc -DPRINT_LEVEL_CURRENTPRINT_LEVEL_WARN -o app main.c为什么不用修改代码因为PRINT_LEVEL_CURRENT在头文件里用了#ifndef保护外部传进来的宏会优先。这个技巧在大型项目管理中非常实用尤其是多个团队共享一套基础库时有人想临时调试某个模块不需要改动公共头文件只需要在自己的编译脚本里加一个宏定义即可不至于影响其他人的构建。在CMake工程里可以这样做target_compile_definitions(app PRIVATE PRINT_LEVEL_CURRENTPRINT_LEVEL_DBG )对于代码洁癖比较强的人也可以不用运行时if判断而是直接按等级各写各的宏。但我日常更推荐上面这种“一个通用宏 运行时判断”的方案因为大多数场景下printf本身的瓶颈远小于日志逻辑的维护成本代码也更紧凑。4. 我踩过的坑和排查思路4.1 空参数引发的逗号问题第一次用可变参数宏时我写过这样的代码#define PRINT_LEVEL_LOG(level, fmt, ...) \ printf([%s] fmt \n, level, __VA_ARGS__)然后调用PRINT_LEVEL_LOG(PRINT_LEVEL_INFO, hello)GCC直接报错或者输出异常。原因很简单可变参数部分是空的但__VA_ARGS__前面的逗号还留在那里预处理后就变成printf(..., level,)多了一个空的参数。解决方法是前面说的##VA_ARGS这个扩展会把空参数时的那个逗号一并删除。但要注意这不是标准C语法是GNU扩展。所以我在写完通用宏之后特意用-stdc99和-pedantic编译验证了一轮发现GCC在开启严格标准模式时对##__VA_ARGS__会警告。这时候就要权衡要么放弃严格模式要么用编译器判断分开处理。我最终选择了编译器判断也就是上面代码里的#if defined(_MSC_VER)那套。4.2 do while(0)的真正用途没有经验的开发者写宏遇到“带输出参数的宏”会这样写#define PRINT_INFO(fmt, ...) printf(fmt, ##__VA_ARGS__)然后用在条件分支里if (ready) PRINT_INFO(all ready); else PRINT_INFO(waiting);这个写法看起来没问题但如果哪天我给宏加上花括号比如多行语句的宏就出事了#define PRINT_INFO(fmt, ...) \ printf([INFO] fmt \n, ##__VA_ARGS__); \ printf(extra info\n);如果调用是if (ready) PRINT_INFO(all ready);预处理完之后else分支就会悬空因为宏展开后有两个语句只有最后一个printf被if管住前面的printf变成无条件执行。更严重的是如果宏里有局部变量和临时操作直接在调用处用花括号可能还会影响变量作用域。do { ... } while(0)就是用来解决这个问题的。它把多行语句包成一个语法上的复合语句后面加一个分号整个宏对外表现得跟一个普通语句一模一样不管外面怎么嵌套if、else、for都不会出问题。我在验证这个宏的时候还专门写了个反例确认过在if后面不加花括号调用也没有隐患。4.3 fmt必须是字面量字符串这个坑踩了两次才知道深浅。PRINT_LEVEL_LOG里用到了字符串拼接的写法printf([%s] %s:%d fmt \n, ...)C语言中相邻字符串字面量会自动拼接所以fmt位置必须是编译期就能确定的字符串字面量。如果写成char *msg hello; PRINT_INFO(msg);编译会直接报错因为..... msg .....这种拼接在C里根本就是非法的。这个限制对大多数场景不是问题因为日志的格式通常都是固定的常量字符串。但如果你确实需要输出一个动态变化的字符串那就得用%s来格式化PRINT_INFO(%s, msg);这是使用这套宏的人最容易忽略的一条规定我建议在团队内部文档里明确写出来。实际调试中我还遇到一个变种有人用switch拼字符串然后传给PRINT_INFO编译直接崩。排查下来就是这个原因后面统一要求所有日志的fmt位置只允许出现双引号的字符串常量。4.4 多线程场景下的输出交错如果项目里开了多线程多个线程同时输出日志控制台会出现完全错乱的输出比如两三条日志的内容混在一起。这个问题的根因是printf并不是“原子输出”的。printf内部虽然会对stdout加锁但一个printf调用里已经包含了多次内部写入另一个线程的printf可能会插入到第一次写入和第二次写入之间。加上我这边还会拼文件路径、行号等字符串输出的时间窗口被拉长交错概率就更高了。我的方案是“锁内输出”。用POSIX线程服务的话可以包一层互斥锁static pthread_mutex_t print_lock PTHREAD_MUTEX_INITIALIZER; #define PRINT_LEVEL_LOCKED_LOG(level, fmt, ...) \ do { \ pthread_mutex_lock(print_lock); \ printf(...); \ pthread_mutex_unlock(print_lock); \ } while (0)但直接在每个宏里都做加锁解锁性能会受影响。折中的做法是DBG等级的日志不用锁因为本来就是调试用出错也无所谓ERR等级的日志加锁保证关键错误信息完整可见。4.5 常见问题速查表下面这组是实际维护这套宏以后沉淀下来的排查清单遇到问题可以直接对着查。现象可能原因处理方法编译报错“expected expression”可变参数空时逗号残留使用##VA_ARGS或在MSVC下走__VA_ARGS__分支编译报错“string literal required”fmt位置传了变量字符串把变量用%s格式化输出if/else分支行为异常宏没有用do while(0)包裹所有多语句宏必须用do while(0)输出没有带文件行号宏被封装到函数中了确保调用点直接用宏而不是再包一层函数日志顺序混乱、内容交错多线程并发输出对关键日志加互斥锁自定义等级不生效头文件里的#ifndef保护被遗漏检查宏定义顺序确保外部宏优先5. 从等级输出到轻量日志模块PRINT_LEVEL这套宏用顺手之后我开始往两个方向扩展。第一个方向是运行时可控。宏定义里的PRINT_LEVEL_CURRENT如果总在编译期固定那么切换到DBG就必须重新编译。在嵌入式设备上重新编译还能接受但在服务器程序里就不方便了所以我后来加了一个可选的全局变量版本extern int g_print_level; #ifndef PRINT_LEVEL_USE_RUNTIME #define PRINT_LEVEL_CURRENT g_print_level #endif这样在程序初始化时读配置文件或者通过命令行参数来设置等级就不需要重新编译了。需要保留编译期裁剪的场景可以继续使用PRINT_LEVEL_CURRENT。两种策略放在同一个头文件里通过一个宏来切换。这个思路也是从实际需求来的服务器程序要支持运行时动态调级但嵌入式固件更看重裁剪必须两者都兼顾。第二个方向是输出重定向。printf默认输出到stdout在很多时候其实是不够的。比如程序以服务方式运行标准输出被重定向到日志文件printf的内容确实也会跟着过去但格式就不可控了。我扩展了一种方式给PRINT_LEVEL_LOG增加一个输出目标参数或者通过宏把printf替换成自定义的写入函数#define PRINT_LEVEL_OUT(fd, fmt, ...) \ do { \ dprintf((fd), [%s] %s:%d fmt \n, ...); \ } while (0)这样调试输出就不再局限于终端可以写到文件、串口甚至网络缓冲区。等级、文件行号这些信息在重定向之后仍然保留日志的可读性不会因为输出介质变化而降低。再往后走如果想做得更像一个日志库还可以加入时间戳、线程ID、日志文件的自动切割等等。但我不建议一上来就把功能加满。PRINT_LEVEL这套方案最大的优势就是“轻”一个头文件几个宏不依赖任何第三方库C89到C99的编译器基本都能编。很多项目其实用不到重量级日志框架真正需要的是把开发阶段的乱printf收敛成一个有等级、能裁剪、可扩展的机制。从这一点看以宏为基础来构建是性价比最高的选择。我个人在实际操作中的体会是调试输出这件事越早规范越省事。等代码写到几万行再回头统一日志成本就完全不一样了。如果你也在为满屏的printf头疼不妨把这份PRINT_LEVEL头文件拿过去按自己的等级划分改一改。先用起来再根据实际场景决定是走运行时调级还是加输出重定向这套结构都能接得住后面不会推倒重来。