1. 日志系统设计的核心思路与选型考量做Linux后端服务开发日志这件事几乎贯穿项目全生命周期。我见过太多项目前期不重视日志等到线上出问题的时候一群人对着终端干瞪眼完全不知道错误发生在哪个环节。所以当项目标题落到“记录错误信息日志的实现”上时我想聊的不只是某个函数怎么调用而是从设计思路到落地细节的一整套东西。1.1 为什么错误日志不能随便printf了事很多刚接触Linux系统编程的朋友第一反应是用printf或者fprintf(stderr, ...)把错误信息打到终端上。开发阶段这么干确实方便但一旦服务以守护进程方式运行终端被释放这些信息就彻底消失了。更麻烦的是多进程或多线程环境下多个执行流同时往标准错误输出写数据内容会交错混杂根本没法读。错误日志的核心诉求其实就三个可追溯、可分级、可持久化。可追溯意味着每条日志要带时间戳、进程标识、代码位置可分级意味着不是所有信息都同等重要要区分调试信息、一般提示、警告和致命错误可持久化意味着日志要落到磁盘文件并且要有轮转机制不能把磁盘写爆。我个人的经验是一个合格的错误日志模块至少应该具备以下能力按级别过滤输出生产环境只记录警告及以上级别自动附加时间戳、进程ID、线程ID、源文件名和行号支持输出到文件和控制台两种目标文件按大小或日期自动切割保留指定数量的历史文件线程安全多线程并发写入不会串行错乱这几点看起来简单但每一项背后都有坑。比如时间戳的精度问题用time()只能精确到秒高并发场景下同一秒内几百条日志的时间戳完全一样排查问题时根本分不清先后顺序。这时候就需要用到gettimeofday()或者clock_gettime()来获取毫秒甚至微秒级精度。1.2 自研轻量模块还是引入现成库这是每个项目都会面临的选型问题。市面上成熟的日志库不少比如zlog、log4c、glog等功能都很完善。但我在实际项目中很多时候还是选择自己写一个轻量级的日志模块原因有这么几点。第一依赖控制。引入第三方库意味着额外的编译依赖和版本管理成本尤其是嵌入式环境或者需要交叉编译的场景多一个库就多一份麻烦。第二定制需求。现成库虽然功能全但往往过于庞大很多功能用不上反而增加了代码审查的负担。第三学习价值。自己实现一遍日志模块对文件操作、时间处理、线程同步这些基础能力的理解会深刻很多。当然如果你的项目已经用了某个成熟的日志框架那没必要重复造轮子。但如果是一个中小型项目对日志的需求就是“够用就好”自己写一个两三百行的模块完全够使而且可控性最强。选型建议如果团队规模小、项目周期紧优先考虑成熟库如果对可控性和轻量性要求高自研模块是更务实的选择。关键是要在项目初期就定下来不要写到一半再换方案。1.3 日志级别划分的实用原则日志级别不是越多越好。我见过有的项目定义了七八个级别结果实际用的时候大家只记得住两三个剩下的形同虚设。比较实用的划分是四个级别级别名称使用场景生产环境是否输出0DEBUG调试信息变量值、函数进出否1INFO正常业务流程节点可选2WARN可恢复的异常情况是3ERROR严重错误影响功能是这个划分的好处是简单直接团队成员不需要查文档就知道什么时候该用什么级别。DEBUG级别在编译时可以通过宏定义直接去掉不产生任何运行时开销。INFO级别在生产环境可以选择性开启比如排查特定问题时临时打开。我踩过的一个坑是早期项目里把一些频繁调用的底层函数也加了INFO日志结果生产环境日志文件一天涨了好几个G磁盘直接告警。后来改成只有关键业务节点才打INFO底层函数只在出错时打ERROR日志量立刻降下来了。所以级别的使用一定要克制每加一条日志都要想清楚这条信息在生产环境真的有人看吗2. 核心细节解析与关键实现要点2.1 日志格式的设计与字段选择一条错误日志应该包含哪些信息这个问题没有标准答案但有一些字段是必不可少的。我通常采用的格式是这样的[2024-01-15 14:32:07.123] [ERROR] [pid:12345] [tid:140234] [main.c:128] connect_database() - Connection refused逐字段拆解一下时间戳精确到毫秒格式为YYYY-MM-DD HH:MM:SS.mmm。毫秒精度是必须的秒级精度在高并发下不够用。级别固定宽度输出方便用grep过滤。ERROR和WARN用不同颜色在控制台显示文件里则统一纯文本。进程ID多进程服务中区分是哪个进程出的问题。线程ID多线程环境中定位具体执行流。注意pthread_self()返回的类型不一定能直接打印需要转换。源文件与行号通过__FILE__和__LINE__宏自动获取这是定位问题的关键。函数名通过__func__宏获取C99标准支持。具体消息格式化后的错误描述。这里有个细节值得展开__FILE__宏展开的是编译时的完整路径如果项目目录结构深日志里会出现很长的路径前缀。解决办法是在Makefile里用-D__FILE__$(notdir $)这样的技巧或者干脆在日志模块里写个函数把路径截取到文件名部分。我一般选择后者因为更灵活不依赖构建系统。2.2 线程安全的实现方案对比多线程写日志线程安全是绕不开的问题。常见的方案有三种方案一全局互斥锁。最简单直接每次写日志前加锁写完解锁。优点是实现简单缺点是并发性能差所有线程串行化写日志。方案二线程局部缓冲 定期刷盘。每个线程维护自己的缓冲区写日志时先写到自己的缓冲区达到一定大小或时间间隔后再加锁写入文件。优点是并发性能好缺点是实现复杂且进程崩溃时可能丢失缓冲区中未刷盘的数据。方案三无锁队列 单独写线程。日志写入者把消息放入无锁队列由一个专门的写线程负责从队列取数据写文件。优点是性能最好缺点是复杂度最高且同样存在崩溃丢数据的问题。对于大多数中小型项目方案一完全够用。日志写入本身不是高频操作一把互斥锁带来的性能损耗可以忽略不计。我实测过一个场景8个线程每秒共写入约5000条日志用全局互斥锁的CPU占用率不到3%完全在可接受范围内。#include pthread.h static pthread_mutex_t log_mutex PTHREAD_MUTEX_INITIALIZER; void write_log(const char *msg) { pthread_mutex_lock(log_mutex); /* 写入文件操作 */ fputs(msg, log_file); fflush(log_file); pthread_mutex_unlock(log_mutex); }注意fflush这行很关键。如果不主动刷新缓冲区程序崩溃时缓冲区里的日志会丢失。但每条都fflush又会影响性能。折中方案是设置行缓冲模式setvbuf(log_file, NULL, _IOLBF, 0)或者每N条刷新一次。2.3 文件轮转机制的实现细节日志文件不能无限增长必须有轮转机制。常见的策略有两种按大小轮转和按日期轮转。按大小轮转的逻辑是每次写日志前检查当前文件大小如果超过阈值比如10MB就把当前文件重命名然后创建新文件。重命名的规则一般是app.log→app.log.1app.log.1→app.log.2以此类推超过保留数量的旧文件直接删除。按日期轮转则是每天零点切换新文件文件名带日期后缀比如app-2024-01-15.log。这种方式的优点是查找方便缺点是如果某天日志量特别大单个文件可能还是很大。我通常采用大小轮转为主、日期信息为辅的方案文件名里带日期同时按大小切割。这样既方便按日期查找又不会出现超大文件。实现轮转时有个容易忽略的细节重命名文件后文件描述符的处理。如果直接用rename()重命名然后fopen()新文件原来的文件描述符需要正确关闭。更稳妥的做法是用freopen()它会自动关闭旧的文件流并打开新文件。static void rotate_log(void) { fclose(log_file); char old_path[256], new_path[256]; for (int i max_backups - 1; i 1; i--) { snprintf(old_path, sizeof(old_path), %s.%d, log_path, i); snprintf(new_path, sizeof(new_path), %s.%d, log_path, i 1); rename(old_path, new_path); } snprintf(new_path, sizeof(new_path), %s.1, log_path); rename(log_path, new_path); log_file fopen(log_path, a); }这段代码里重命名是从后往前进行的先把最老的文件删掉或者覆盖然后依次往前挪。如果从前往后挪会出现文件被覆盖的问题。3. 完整实操过程与核心代码实现3.1 模块头文件设计先定义对外暴露的接口。头文件的设计原则是调用者只需要包含这一个文件不需要关心内部实现细节。#ifndef LOGGER_H #define LOGGER_H #include stdio.h typedef enum { LOG_LEVEL_DEBUG 0, LOG_LEVEL_INFO, LOG_LEVEL_WARN, LOG_LEVEL_ERROR } log_level_t; int log_init(const char *filepath, log_level_t min_level, size_t max_size, int max_backups); void log_close(void); void log_set_level(log_level_t level); void log_write(log_level_t level, const char *file, int line, const char *func, const char *fmt, ...); #define LOG_DEBUG(fmt, ...) \ log_write(LOG_LEVEL_DEBUG, __FILE__, __LINE__, __func__, fmt, ##__VA_ARGS__) #define LOG_INFO(fmt, ...) \ log_write(LOG_LEVEL_INFO, __FILE__, __LINE__, __func__, fmt, ##__VA_ARGS__) #define LOG_WARN(fmt, ...) \ log_write(LOG_LEVEL_WARN, __FILE__, __LINE__, __func__, fmt, ##__VA_ARGS__) #define LOG_ERROR(fmt, ...) \ log_write(LOG_LEVEL_ERROR, __FILE__, __LINE__, __func__, fmt, ##__VA_ARGS__) #endif这里用宏包了一层好处是调用者不需要手动传__FILE__、__LINE__这些参数写起来更简洁。##__VA_ARGS__是GCC的扩展语法用于处理可变参数为空的情况在C99标准下可以用__VA_OPT__替代但兼容性不如前者。3.2 核心实现文件实现文件里要处理几件事初始化、级别过滤、格式化、线程安全、文件轮转。#include logger.h #include stdarg.h #include string.h #include time.h #include sys/time.h #include pthread.h #include unistd.h #include sys/syscall.h static FILE *g_log_file NULL; static log_level_t g_min_level LOG_LEVEL_INFO; static size_t g_max_size 10 * 1024 * 1024; static int g_max_backups 5; static char g_log_path[256]; static pthread_mutex_t g_mutex PTHREAD_MUTEX_INITIALIZER; static const char *level_names[] { DEBUG, INFO, WARN, ERROR };初始化函数负责打开文件、设置缓冲模式int log_init(const char *filepath, log_level_t min_level, size_t max_size, int max_backups) { if (!filepath) return -1; strncpy(g_log_path, filepath, sizeof(g_log_path) - 1); g_min_level min_level; g_max_size max_size; g_max_backups max_backups; g_log_file fopen(filepath, a); if (!g_log_file) return -1; setvbuf(g_log_file, NULL, _IOLBF, 0); return 0; }setvbuf设置为行缓冲模式这样每条日志写入后会自动刷新兼顾了性能和安全性。如果对性能要求极高可以改为全缓冲然后定期手动fflush。获取线程ID这里有个坑。pthread_self()返回的是pthread_t类型在Linux上通常是无符号长整型但标准并不保证它可以直接打印。更可靠的方式是用系统调用获取内核线程IDstatic pid_t get_tid(void) { return (pid_t)syscall(SYS_gettid); }SYS_gettid返回的是内核视角的线程ID在ps -eLf命令的输出里能看到对应的值排查问题时非常方便。3.3 日志写入的完整流程写入函数是整个模块的核心流程是级别过滤 → 加锁 → 检查轮转 → 格式化时间 → 拼接日志行 → 写入 → 解锁。void log_write(log_level_t level, const char *file, int line, const char *func, const char *fmt, ...) { if (level g_min_level) return; /* 获取时间戳 */ struct timeval tv; gettimeofday(tv, NULL); struct tm tm_info; localtime_r(tv.tv_sec, tm_info); char time_buf[32]; snprintf(time_buf, sizeof(time_buf), %04d-%02d-%02d %02d:%02d:%02d.%03d, tm_info.tm_year 1900, tm_info.tm_mon 1, tm_info.tm_mday, tm_info.tm_hour, tm_info.tm_min, tm_info.tm_sec, (int)(tv.tv_usec / 1000)); /* 格式化用户消息 */ char msg_buf[1024]; va_list args; va_start(args, fmt); vsnprintf(msg_buf, sizeof(msg_buf), fmt, args); va_end(args); /* 提取文件名去掉路径 */ const char *basename strrchr(file, /); basename basename ? basename 1 : file; pthread_mutex_lock(g_mutex); /* 检查是否需要轮转 */ if (g_log_file) { long pos ftell(g_log_file); if (pos 0 (size_t)pos g_max_size) { rotate_log(); } } if (g_log_file) { fprintf(g_log_file, [%s] [%s] [pid:%d] [tid:%d] [%s:%d] %s() - %s\n, time_buf, level_names[level], getpid(), get_tid(), basename, line, func, msg_buf); } pthread_mutex_unlock(g_mutex); }这里有几个细节值得说明。第一时间格式化用了localtime_r而不是localtime前者是线程安全版本。第二vsnprintf保证了缓冲区不会溢出即使消息很长也会被截断而不是崩溃。第三文件名的路径截取放在锁外面做减少临界区长度。3.4 编译与测试验证把上面的代码保存为logger.c和logger.h写一个测试程序验证功能#include logger.h #include pthread.h #include unistd.h void *worker(void *arg) { int id *(int *)arg; for (int i 0; i 1000; i) { LOG_INFO(worker %d iteration %d, id, i); if (i % 100 0) { LOG_ERROR(worker %d simulated error at %d, id, i); } } return NULL; } int main(void) { log_init(test.log, LOG_LEVEL_DEBUG, 1024 * 1024, 3); pthread_t threads[4]; int ids[4] {1, 2, 3, 4}; for (int i 0; i 4; i) { pthread_create(threads[i], NULL, worker, ids[i]); } for (int i 0; i 4; i) { pthread_join(threads[i], NULL); } log_close(); return 0; }编译命令gcc -o test_logger test.c logger.c -lpthread -Wall -Wextra运行后检查test.log应该能看到格式整齐的日志行每条都带时间戳、级别、进程ID、线程ID和代码位置。同时因为设置了1MB的轮转阈值应该能看到test.log.1、test.log.2等历史文件。实操心得测试时故意把max_size设小一点比如1KB能快速验证轮转逻辑是否正确。另外建议用valgrind跑一遍检查有没有内存泄漏或者文件描述符泄漏。4. 常见问题排查与避坑经验实录4.1 日志丢失的几种典型场景日志丢失是最让人头疼的问题明明代码里写了日志出问题的时候却找不到。根据我的经验常见原因有这几类场景一程序异常退出缓冲区未刷新。这是最常见的情况。fprintf写入的数据先进入用户态缓冲区只有缓冲区满或者调用fflush才会真正写到磁盘。如果程序收到信号直接退出缓冲区里的数据就丢了。解决办法是设置行缓冲模式或者在信号处理函数里调用fflush。场景二多进程写同一个文件。如果父进程和子进程都打开了同一个日志文件各自维护自己的文件偏移量写入的内容会互相覆盖。解决办法是每个进程写独立的日志文件或者在打开文件时加O_APPEND标志。场景三磁盘满导致写入失败。这个比较隐蔽fprintf返回成功不代表数据真的写进去了。需要检查ferror(g_log_file)的返回值并在磁盘空间不足时采取降级措施比如只输出到控制台。场景四日志级别设置过高。生产环境把级别设成了ERROR结果排查问题时发现关键的上下文信息都是INFO级别全被过滤掉了。建议生产环境至少保留WARN级别关键业务模块保留INFO。4.2 性能问题的定位与优化日志模块本身不应该成为性能瓶颈。如果发现加了日志之后程序明显变慢可以从这几个方向排查问题现象可能原因排查方法解决方案CPU占用高频繁fflushperf top观察改为全缓冲定期刷新写入延迟大磁盘IO慢iostat观察考虑异步写入或内存缓冲锁竞争严重临界区过长加锁时间统计缩小临界区格式化放锁外日志文件巨大级别设置不当统计各级别条数调整级别去掉高频DEBUG我遇到过一个典型案例某服务在压测时QPS上不去排查发现是日志模块的fflush调用太频繁。每条日志都刷新一次磁盘单条日志的写入延迟在几毫秒级别累积起来就成了瓶颈。改成每100条刷新一次之后QPS提升了将近30%。4.3 日志分析的实用技巧日志写出来是为了看的所以格式设计要方便后续分析。几个实用技巧技巧一用固定分隔符。字段之间用|或者\t分隔方便用awk、cut等工具做列提取。我习惯用|因为视觉上更清晰。技巧二关键信息放前面。时间戳、级别、进程ID这些固定字段放最前面消息内容放最后。这样用grep过滤级别时输出结果对齐好看。技巧三错误码统一管理。不要直接在日志里写魔法数字定义一套错误码枚举日志里输出错误码和对应的文字描述。排查问题时可以用错误码做精确过滤。技巧四定期归档和清理。日志文件保留太久会占满磁盘保留太短又不够排查问题。我的经验值是ERROR级别日志保留30天INFO级别保留7天DEBUG级别只在排查问题时临时开启。# 统计各级别日志条数 awk -F[][] {print $4} app.log | sort | uniq -c | sort -rn # 查找特定时间段的错误日志 grep ERROR app.log | awk $1 [2024-01-15 $1 [2024-01-15 15:00 # 提取所有唯一的错误消息 grep ERROR app.log | sed s/.*- // | sort -u这些命令在实际排查问题时非常高效比一条条翻日志快得多。4.4 跨平台兼容性注意事项虽然标题限定在Linux环境但实际项目中经常需要代码在多个平台编译。几个需要注意的点syscall(SYS_gettid)是Linux特有的在其他平台上需要用pthread_self()或者平台特定的API。localtime_r在Windows上叫localtime_s参数顺序还不一样。gettimeofday在Windows上需要包含winsock2.h。如果项目有跨平台需求建议把这些平台相关的代码用宏隔离开#ifdef __linux__ #include sys/syscall.h #define GET_TID() ((pid_t)syscall(SYS_gettid)) #elif defined(_WIN32) #define GET_TID() ((pid_t)GetCurrentThreadId()) #else #define GET_TID() ((pid_t)pthread_self()) #endif这样核心逻辑不变只替换平台相关的部分维护起来清爽很多。4.5 日志模块的单元测试思路日志模块虽然简单但也值得写单元测试。我通常从这几个维度验证级别过滤设置不同级别验证输出条数是否符合预期格式正确性用正则表达式匹配日志行验证各字段格式轮转逻辑写入超过阈值的数据验证文件数量和命名并发安全多线程同时写入验证日志行不交错、不丢失边界条件空消息、超长消息、特殊字符消息的处理并发安全的测试有个小技巧让每个线程写入带唯一标识的消息最后统计所有标识是否都出现且只出现一次。如果出现重复或者缺失说明线程安全有问题。// 并发测试的验证逻辑 grep -c worker 1 iteration test.log // 应该等于1000 grep worker 1 iteration test.log | sort -u | wc -l // 也应该等于1000这两个数字相等说明没有重复也没有丢失。5. 从错误日志到可观测性的延伸思考5.1 错误日志与结构化日志的关系传统的文本日志适合人看但不适合机器分析。现在越来越多的项目开始采用结构化日志比如JSON格式每条日志是一个独立的JSON对象字段固定方便程序解析和聚合。{ts:2024-01-15T14:32:07.123,level:ERROR,pid:12345,tid:140234,file:main.c,line:128,func:connect_database,msg:Connection refused}结构化日志的好处是可以用日志分析平台做聚合统计、告警、可视化。但缺点是文件体积比纯文本大人直接看也不够直观。我的建议是如果项目已经有日志采集和分析平台优先用结构化格式如果只是本地排查问题纯文本格式更实用。5.2 日志与监控告警的联动错误日志写到文件只是第一步更重要的是让错误能被及时发现。常见的做法是在日志模块里加一个回调钩子当ERROR级别日志产生时触发告警通知。typedef void (*log_alert_cb)(const char *msg); static log_alert_cb g_alert_cb NULL; void log_set_alert_callback(log_alert_cb cb) { g_alert_cb cb; }在log_write函数里当级别为ERROR且回调不为空时调用回调函数。回调的具体实现可以是发邮件、发消息、写监控系统等。这样日志模块就不仅仅是记录还承担了告警触发的职责。不过要注意告警回调本身不能阻塞太久否则会影响业务线程。稳妥的做法是把告警消息放入队列由单独的线程异步处理。5.3 日志模块的演进方向一个日志模块从能用 to 好用通常会经历几个阶段的演进。最初是简单的文件写入然后加上级别和格式接着是轮转和线程安全再往后是异步写入和结构化输出最后是与监控告警系统集成。每个阶段解决的都是实际遇到的问题不需要一开始就设计得面面俱到。我的经验是先让日志能落盘再让日志好排查最后让日志能告警。这个顺序不能反否则容易过度设计增加不必要的复杂度。我在实际项目中的体会是日志模块的代码量不大但细节特别多。每一条日志的格式、每一个字段的含义、每一种异常情况的处理都需要仔细推敲。写完之后多跑几轮测试多模拟一些异常场景把问题暴露在开发阶段比上线后抓瞎强得多。另外日志模块的接口一旦定下来后续尽量不要频繁改动因为调用方太多了改一次接口就要动几十个文件。前期多花点时间把接口设计好后面省心很多。