为什么我的日志库会导致性能测试运行得更快？

Question

在过去的一年里,我一直在用C++开发一个记录库,并考虑到性能.为了评估性能,我开发了一组基准来比较我的代码与其他库,包括根本不执行日志记录的基本情况.

在我的上一个基准测试中,我测量了当日志记录处于活动状态时以及何时不处理时CPU密集型任务的总运行时间.然后我可以比较时间来确定我的库有多少开销.此条形图显示与我的非记录基础案例相比的差异.

正如您所看到的,我的库("鲁莽")增加了负面开销(除非所有4个CPU核心都忙).启用日志记录时,程序运行速度比禁用日程快约半秒.

我知道我应该尝试将其分解为一个更简单的案例,而不是询问一个4000行程序.但是有很多场所要去除什么,没有假设我会在试图隔离它时让问题消失.我可能会花一年时间做这件事.我希望Stack Overflow的集体专业知识能够使这个问题变得更加浅薄,或者对于那些比我有更多经验的人来说,这个原因是显而易见的.

关于我的图书馆和基准的一些事实:

• 该库包含一个前端API,用于将日志参数推送到无锁队列(Boost.Lockless)和后端线程,后者执行字符串格式化并将日志条目写入磁盘.
• 时间基于简单地调用std::chrono::steady_clock::now()程序的开头和结尾,并打印差异.
• 基准测试运行在4核Intel CPU(i7-3770K)上.
• 基准程序计算1024x1024 Mandelbrot分形并记录每个像素的统计数据,即它写入大约一百万个日志条目.
• 单个工作线程案例的总运行时间约为35秒.因此速度提升约为1.5%.
• 基准测试生成一个输出文件(这不是定时代码的一部分),其中包含生成的Mandelbrot分形.我已经验证打开和关闭日志记录时会产生相同的输出.
• 基准测试运行100次(所有基准测试库,大约需要10个小时).条形图显示平均时间,误差条显示四分位数范围.
• Mandelbrot计算的源代码
• 基准的源代码.
• 代码存储库和文档的根.

我的问题是,如何在启用日志记录库时解释明显的速度增加？

编辑:这是在尝试评论中给出的建议后解决的.我的日志对象是在基准测试的第24行创建的.显然,当LOG_INIT()触及日志对象时,它会触发页面错误,导致图像缓冲区的部分或全部页面映射到物理内存.我仍然不确定为什么这会使性能提高近半秒; 即使没有日志对象,mandelbrot_thread()函数中发生的第一件事就是写入图像缓冲区的底部,这应该具有类似的效果.但是,无论如何,在开始基准测试之前使用memset()清除缓冲区会使一切变得更加清晰.目前的基准是在这里

我试过的其他事情是:

• 使用oprofile探查器运行它.我从来没有能够得到它的注册任何的锁定时间,甚至扩大就业,使其运行约10分钟后.几乎所有的时间都在Mandelbrot计算的内循环中.但也许我能够以不同的方式解释它们,因为我知道页面错误.我没想过要检查图像写入是否花费了不成比例的时间.
• 卸下锁.这确实对性能产生了重大影响,但结果仍然很奇怪,无论如何我无法对任何多线程变体进行更改.
• 比较生成的汇编代码.存在差异,但是日志记录构建显然做了更多的事情.没有什么能成为明显的表演杀手.

Answer 1

当首次访问未初始化的内存时，页面错误会影响时序。

因此，在第一次调用之前，请std::chrono::steady_clock::now()通过在 Sample_buffer 上运行 memset() 来初始化内存。