日志组件优化报告

背景

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

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

	不设置环境变量	HIGH_PERFORMANCE_LOG=1	HIGH_PERFORMANCE_LOG=1 HIGH_PERFORMANCE_LOG_CACHE=1	HIGH_PERFORMANCE_LOG=1 HIGH_PERFORMANCE_LOG_CACHE=1 LOG_SYSCALL_INTERVAL_TIMES=1000
新WrtieLog	4836.7	1001.88	453.12	454.28
新HtLog	5603.4	1355.96	1253.96	1277.58
新DebugLog	7017.66	2600.98	2323.88	2333.98
旧WrtieLog	7388.92	7442.24	7196.72	7380.76
旧HtLog	7654.6	7712.28	7498.46	7655.82
旧DebugLog	9404.58	9431.44	8805.68	9049.94
效率比	0.65	0.13	0.06	0.06

（50次平均值  测试屡次结果误差不大）

 

基准测试：

 

 

 

 

测试日志记录：

 

 

结论：

 

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

 

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

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

 

callgrind分析状况

 

 

后续优化计划

若是之后日志组件再次成为性能瓶颈，能够考虑如下优化：

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

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

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