添加日志输出后,Java应用程序速度会上升

Question

我们偶然发现了一个相当奇怪的问题IMO.我们的客户一直在抱怨我们的应用程序从文件导入和处理数据的速度[filesize 1kB cca,在正常条件下导入文件所需的时间是4-10秒,具体取决于整体工作负载.是的,它很多] ......

所以我们开始研究它,但是发生了一些非常意外的事情:在将调试日志输出插入代码的某些部分[否则不影响逻辑]后,导入加速了很多:300ms-2200ms/file取决于总体工作负载.

使用的语言:Java

我站上的JDK 6_34 [不知道我的同事使用的是什么版本]

我经历了很多次代码.没什么不寻常的.即使它全部在一个线程中执行,该线程也没有竞争对手做同样的工作或访问相同的文件.

这种情况对任何人都很熟悉吗？

PS:我希望这个问题确实属于这里.如果没有,我真诚地道歉.

编辑:

至于日志记录,我们使用log4j.

操作系统:Windows XP /我的机器.一位同事有同样的,另一位使用Win7 /

CPU:E7500 @ 2.93 GHz

RAM:2 GB DDR2

另一台机器基本相同.第三个的配置对我来说是未知的,因为它是新的而不是我的工作站.

在我的情况下,文件全部从/向本地HDD加载/存储.

最让我担心的是我们使用的平台没有任何来源,因为我们已经支付了许可证,但没有支付来源.<

Answer 1

我的理论是,添加日志记录正在改变应用程序的线程调度模式.

通常,这应该不重要.但是,如果应用程序中的基础问题与线程调度有关,那么日志记录会改变观察到的行为就不足为奇了.

我建议您审核代码库的相关部分,以查找Thread.sleep(...)调用,Thread.yield()调用,代码轮询的位置等.还要考虑这可能发生在第三方库代码中.

@ OldCurmudgeon的答案包括两个你应该寻找的简单版本.即使使用sleep(0)也是浪费,但它比明显大于零的sleep(N)地方更好N.

Answer 2

添加日志记录会向您的逻辑添加同步点。也许您所看到的是这个的（奇怪的）副作用。