日志组件优化报告

背景

目前项目组日志组件存在以下问题：

1 日志文件每写一次日志就打开关闭一次，存在性能浪费

2 日志里面获取时间需要调用localtime、stat，在频繁调用时该函数消耗cpu比较多

3 日志组件获取环境变量时未判断是否成功，如果环境变量没设置会引起程序core

4 日志组件在写日志时，先初始化局部变量再判断日志级别，可以优化

5 日志组件里面有不少处调用了sprintf、ReplaceEnvVar和strlen，其实可以避免

6 日志组件调用了大量不可重入函数，在信号处理函数中写日志可能引起core

改造方案

1 增加文件句柄缓存与输出缓冲：

增加一个环境变量HIGH_PERFORMANCE_LOG，默认值为0，不启用。

当HIGH_PERFORMANCE_LOG为1时，每次打开日志后将日志文件名记录到g_logInfo. sFullLogName，写完日志后暂时不执行fclose。

下次写日志时判断待写日志文件名是否与g_logInfo. sFullLogName一致，如果一致则不用重新打开文件。否则先将日志文件句柄关闭再进行打开日志文件的流程。

增加一个环境变量HIGH_PERFORMANCE_LOG_CACHE，默认值为0，不启用。在HIGH_PERFORMANCE_LOG_CACHE和HIGH_PERFORMANCE_LOG都为1时，写完日志后不立即执行刷新到磁盘（不调用fflush）

2 减少非必要系统函数调用：

增加函数localtime项目组代替原来的localtime，每次调用localtime项目组时先判断是否与上次调用间隔超过1分钟，如果没超过则使用上次调用localtime返回的结果，如果超过则重新调用localtime并且将结果缓存起来待下次使用。这样从原来一分钟调用多次localtime变成一分钟调用一次。

修改函数CommonGetCurrentDate，首次调用时记录当天起始秒数和第二天起始秒数，并且将返回的日志缓存起来。之后每次调用判断时间是否当天范围内，如果是则直接使用缓存返回，否则重复上面流程。样从原来天调用多次localtime变成一天调用一次。

增加环境变量LOG_SYSCALL_INTERVAL_TIMES，默认值为100，每写LOG_SYSCALL_INTERVAL_TIMES次日志时才执行一次stat（如果缓存打开情况，需要先调用fflush将日志缓冲刷出），不需要每写一次日志就检查一次。注意，由于每100行才检查一次日志大小，所以会影响原来50m切换一次日志文件的逻辑，不一定精确的在50m时切换，会略大一些。

3 获取环境变量失败增加默认值：

改造原来获取环境变量的代码，增加环境变量获取失败时使用默认值的逻辑，避免异常情况下导致程序core

4 将判断日志级别的逻辑往前提：

进入写日志逻辑后，先判断当前日志级别是否需要输出日志，如果不需要则直接返回。减少非必要的变量初始化操作。

5 使用耗时较小的函数代替耗时长的函数：

日志组件每次写日志时需要使用ReplaceEnvVar函数替换日志文件路径里面的变量， 现改为在初始化时就调用ReplaceEnvVar将文件路径变量替换完。后面写日志时使用ifNeedReplaceEnvVar判断是否需要替换变量，如果不需要则不调用ReplaceEnvVar

把简单的sprintf调用改为同功能其它函数代替，如将fprintf(fp, "\n")改为fputc (‘\n‘, fp)

判断字符串是否为空，不使用strlen(str) == 0的写法，改为str[0] == ‘\0‘

非功能测试对比

测试写20万行日志改造前后日志组件消耗时间

结果如下：

单位ms

（50次平均值  测试多次结果偏差不大）

基准测试：

测试日志记录：

结论：

改造后日志组件性能有所提高，效率提高约44%~70%

需要注意HIGH_PERFORMANCE_LOG环境变量启用的情况，如果程序写日志过程中日志文件被删除或者移走，程序不能即时发现，仍然会往原来的日志文件写日志。

需要等到写满LOG_SYSCALL_INTERVAL_TIMES行日志后才会触发日志文件重新打开关闭功能。

callgrind分析情况

后续优化计划

如果以后日志组件再次成为性能瓶颈，可以考虑以下优化：

1 使用linux文件映射进行日志文件读写，代替现有的标准库函数。这样可以减少数据拷贝。

2 写日志时使用流压缩，边写日志边压缩，减少磁盘消耗。

3 实在不行考虑异步落盘，先将日志数据写到共享内存，由专用的日志进程写到日志文件。

原文地址：https://www.cnblogs.com/kingstarer/p/10359022.html