导致运行时异常与控制台输出中的println一起正确排序

Question

VM Java控制台输出的一个常见问题是System.out和System.err通常不能正确同步,可能是因为它们位于不同的线程上.这导致混合输出,如下所示:

调试输出与运行时异常堆栈跟踪混淆

[8, 1, 3, 5, 9, 13, 15, 17, 19]
Exception in thread "main" java.lang.ArrayIndexOutOfBoundsException: 9
scanning xAnswer: 1 xValue: 1 total: 1 [1, 1, 0, 0, 0, 0, 0, 0, 0]
    at cra.common.Group_jsc.listSubsetSum(Group_jsc.java:29)
scanning xAnswer: 2 xValue: 2 total: 4 [2, 1, 2, 0, 0, 0, 0, 0, 0]
    at cra.common.Group_jsc.main(Group_jsc.java:12)
scanning xAnswer: 3 xValue: 3 total: 9 [3, 1, 2, 3, 0, 0, 0, 0, 0]
scanning xAnswer: 4 xValue: 4 total: 18 [4, 1, 2, 3, 4, 0, 0, 0, 0]
scanning xAnswer: 5 xValue: 5 total: 31 [5, 1, 2, 3, 4, 5, 0, 0, 0]
  reset to xAnswer: 4 xValue: 5 total: 26 [4, 1, 2, 3, 5, 5, 0, 0, 0]
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
scanning xAnswer: 5 xValue: 6 total: 41 [5, 1, 2, 3, 5, 6, 0, 0, 0]
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
  reset to xAnswer: 4 xValue: 6 total: 35 [4, 1, 2, 3, 6, 6, 0, 0, 0]
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:601)
    at com.intellij.rt.execution.application.AppMain.main(AppMain.java:120)
scanning xAnswer: 5 xValue: 7 total: 52 [5, 1, 2, 3, 6, 7, 0, 0, 0]
  reset to xAnswer: 4 xValue: 7 total: 45 [4, 1, 2, 3, 7, 7, 0, 0, 0]
scanning xAnswer: 5 xValue: 8 total: 64 [5, 1, 2, 3, 7, 8, 0, 0, 0]
  reset to xAnswer: 4 xValue: 8 total: 56 [4, 1, 2, 3, 8, 8, 0, 0, 0]

Process finished with exit code 1

由于异常发生在进程结束时,我希望在程序中的所有println 之后发生异常打印.为什么会发生这种情况以及如何解决问题呢？

(请注意,此特定示例来自IntelliJ的IDEA控制台,但在Eclipse和其他Java IDE中也会发生同样的事情)

Answer 1

VM Java 控制台输出的一个常见问题是 System.out 和 System.err 通常未正确同步，

不，它们完美同步。问题在于这些行是混合的，因为它们被打印为对 的单独调用println(...)。这是来自的代码Exception.printStackTrace()：

        StackTraceElement[] trace = getOurStackTrace();
        for (int i=0; i < trace.length; i++)
            s.println("\tat " + trace[i]);

记录器（如 log4j）获取完整的堆栈跟踪并将多行转换为单个日志输出调用，然后以原子方式持久保存。

为什么会发生这种情况以及可以采取哪些措施来纠正该问题？

通常，对于 Unix 程序，标准输出会被缓冲，而标准错误则不会。我不认为 Java 是这样，但也许确实如此。要阅读以下 javadoc System.out：

“标准”输出流。该流已打开并准备好接受输出数据。通常，该流对应于显示输出或由主机环境或用户指定的另一个输出目的地。

与System.err：

按照惯例，此输出流用于显示错误消息或其他应引起用户立即注意的信息，即使主要输出流（变量的值）out已重定向到通常是没有持续监控。

有关更多详细信息，请参阅此答案：为什么有时会首先打印 System.err 语句？

如果从命令行运行，您应该将 out 和 err 输出重定向到不同的文件。以下是使用 ~unix 执行此操作的方法：

如何将 stderr 和 stdout 重定向到 bash 同一行中的不同文件？

在 Java 中，您可以使用System.setOut(...)和System.setErr(...)将不同的输出发送到不同的PrintStreams，这样行就不会交错。

您编辑了问题以注意到这是在 IDE 内部发生的。如果你需要使用System.out然后err你可以使用上面的Java代码重定向它们。

然而，通常使用日志记录代码来代替。常见的日志记录包是log4j或logback，它们自动将单个多行日志消息写入输出文件，这样它们就不会交错。正如 @fge 提到的，尽管其他包提供了更多功能，但java.util.loggingJVM 中也内置了该功能。