【问题标题】:Java multithreaded application System.out.println generate latencyJava 多线程应用 System.out.println 生成延迟
【发布时间】:2017-04-01 18:35:23
【问题描述】:

我正在用 Java 编写一个多线程应用程序,使用 log4j 进行日志记录。在我的基准测试中,我发现每次输出日志时,都会产生 1 或 2 毫秒的延迟。经过调查,我发现问题只是在控制台输出中,即使我摆脱了log4j并使用System.out.print直接打印也出现了问题。在那个线程中,我使用了以下测试:

        System.out.println("===============================================================");
        long ts = java.lang.System.currentTimeMillis();
        String toPrint = "### TEST 1 " + (java.lang.System.currentTimeMillis() - ts) + " ms \n";
        toPrint = toPrint + "### TEST 2 " + (java.lang.System.currentTimeMillis() - ts) + " ms \n";
        toPrint = toPrint + "### TEST 3 " + (java.lang.System.currentTimeMillis() - ts) + " ms \n";
        toPrint = toPrint + "### TEST 4 " + (java.lang.System.currentTimeMillis() - ts) + " ms \n";
        System.out.print(toPrint);
        System.out.println("===============================================================");

        System.out.println("### TEST 1 " + (java.lang.System.currentTimeMillis() - ts) + " ms");
        System.out.println("### TEST 2 " + (java.lang.System.currentTimeMillis() - ts) + " ms");
        System.out.println("### TEST 3 " + (java.lang.System.currentTimeMillis() - ts) + " ms");
        System.out.println("### TEST 4 " + (java.lang.System.currentTimeMillis() - ts) + " ms");
        System.out.println("===============================================================");

输出是:

===============================================================
### TEST 1 0 ms
### TEST 2 0 ms
### TEST 3 0 ms
### TEST 4 0 ms
===============================================================
### TEST 1 7 ms
### TEST 2 9 ms
### TEST 3 10 ms
### TEST 4 11 ms
=============================================================== 

多线程应用程序直接输出到控制台而不产生延迟的正确方法是什么?

我们可以直接设置 log4j 吗?

提前感谢您的帮助...

【问题讨论】:

  • 在这种延迟中是一个问题 - 每一点工作都需要一些时间 - 然后可能会创建一个新线程来执行您的打印。
  • 写入控制台需要很短的时间。就是那样子。如果您在控制台上记录了太多重要的日志,请降低您的日志级别,或完全关闭控制台日志记录。您也可以随时 tail 您可能生成的日志文件。
  • @Andreas 非常感谢您的回答。但是,我的 cpu 都没有饱和,在现代服务器上输出一条线需要 2 毫秒,这听起来不合理。关闭控制台确实修复了pb。
  • @ScaryWombat 感谢您的回答,这就是我使用 log4j 2 输出到文件和控制台的原因。但是,添加控制台附加程序时我确实有延迟
  • 是的,控制台 io 有价格

标签: java multithreading console log4j latency


【解决方案1】:

我不得不将代码更改为 nanos 才能看到结果。在 Eclipse 中运行我得到~120,000 ns 的最终编号。在 Windows 命令提示符中运行时,我会在明确的提示符下(在 cls 命令之后)得到~700,000 ns,但在必须滚动时得到~2,000,000 ns

写入控制台是同步的,并且必须等待滚动和打印完成,所以不要登录到控制台,或者只在那里记录非常少的输出。

您在评论中说您正在登录到文件控制台。这在开发中很好,但不要在生产中登录到控制台。你为什么要?生产代码无论如何都应该在无人看管的情况下运行,而且没有人在看控制台,那么为什么要浪费时间在那里记录呢?

如果您暂时需要实时观看生产日志,请在日志文件上使用tail。对于 Windows,请参阅“Looking for a windows equivalent of the unix tail command”。

如果您坚持要登录到控制台,请尝试使用AsyncAppender

【讨论】:

  • 非常感谢,我没有意识到控制台 io 如此昂贵。你确实回答了我的第一个问题。但是,log4j 2 应该解决这些问题,知道如何确保控制台 io 可以在 log4j 的低优先级的单独线程中完成? (现在我正在按照您的建议进行操作,并在产品中关闭控制台输出)
猜你喜欢
  • 2017-10-05
  • 2021-04-19
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2011-10-18
相关资源
最近更新 更多