java - System.out.println 最终阻塞

Question

我有一个应用程序将其所有日志记录合并到一个单实例类中，以便于选择性调试打印等。该类已经存在了一年左右，运行顺利，但就在最近我碰巧打开了日志升级到最高设置(我很少这样做)，标准输出似乎最终会阻塞。这会在下次代码的其他部分调用 println 时，或者当它尝试使用日志记录类(它被阻止等待 println 返回)时造成严重破坏。

我的第一个想法是我的日志记录类存在某种并发问题，但是搜索堆栈跟踪让我确信我的同步工作正常并且在任何给定时间只有一个线程尝试写入控制台.这是有问题的线程上的示例堆栈跟踪:

Thread [Thread-127] (Suspended) 
    FileOutputStream.writeBytes(byte[], int, int) line: not available [native method] [local variables unavailable] 
    FileOutputStream.write(byte[], int, int) line: 260  
    BufferedOutputStream.flushBuffer() line: 65 
    BufferedOutputStream.flush() line: 123  
    PrintStream.write(byte[], int, int) line: 432   
    StreamEncoder.writeBytes() line: 202    
    StreamEncoder.implFlushBuffer() line: 272   
    StreamEncoder.flushBuffer() line: 85    
    OutputStreamWriter.flushBuffer() line: 168  
    PrintStream.write(String) line: 477 
    PrintStream.print(String) line: 619 
    PrintStream.println(String) line: 756   
    Logger(Logger).LogMessage(String) line: 180 
    RemoteConsoleMonitor$1.run() line: 56   
    Thread.run() line: 662  

深入研究 native 堆栈跟踪，我发现 JVM 进程阻塞了 Windows native ZwWriteFile 调用。我最好的猜测是 JVM 正在使用配置为同步读取/写入缓冲数据的命名管道，但读取器已以某种方式停止并让缓冲区填满。同时，编写器被阻塞等待缓冲区空间可用，但这从未发生过。这是同一线程的 native 堆栈跟踪:

    ntdll.dll!_ZwWriteFile@36()  + 0x15 bytes   
    ntdll.dll!_ZwWriteFile@36()  + 0x15 bytes   
    jvm.dll!InterfaceSupport::serialize_memory(JavaThread * thread=0x00000220)  Line 40 + 0x9 bytes C++
    java.dll!writeBytes(const JNINativeInterface_ * * env=0x2ac2b13c, _jobject * this=0x3e00f204, _jobject * bytes=0x3e00f200, long off=0, long len=97, _jfieldID * fid=0x7ecee033)  Line 144 + 0x21 bytes  C
    java.dll!Java_java_io_FileOutputStream_writeBytes(const JNINativeInterface_ * * env=0x2ac2b13c, _jobject * this=0x3e00f204, _jobject * bytes=0x3e00f200, long off=0, long len=97)  Line 73 + 0x20 bytes C
0d8a3826()  
    ...

最终结果是 stdout 缓冲区被填满，迟早，东西会停止写入控制台。

问题是:如果我独立运行应用程序而不是从 Apache Ant 构建脚本运行它，我将无法重现该问题。所以这可能与 Ant 如何重定向流程输出有关，但我对提交错误报告犹豫不决，因为似乎其他人之前会遇到这个问题......而且，因为我无法得到相同的结果隔离繁殖的行为。

关于我如何进一步追踪它有什么想法或建议吗？

更新:将 Eclipse 从 3.4.2 更新到 Helios (M2) 神奇地解决了这个问题。我还可以通过从命令行而不是 UI 启动集成的 Ant 构建器来继续使用 3.4.2:

java -jar <eclipse directory>\plugins\org.eclipse.equinox.launcher_<version>.jar -application org.eclipse.ant.core.antRunner -buildfile <buildfile>

Answer 1

嗯，这不是解决方案，而是供您进一步调查的一些指南。

根据 Apache Ant FAQ

When Apache Ant forks a new process for example by using the , or tasks, it will also start a new thread reading from standard input and sending everything that it has read to that process. . .

在下面几行中，他们提到了类 Unix 系统上的一个问题:

This behaviour leads to strange side effects like the Ant process being suspended when a build forking new process is run as a background process on Unix-like systems.....

查看相关的 Bug .

您现在可以采取的步骤:

1. 更新到最新版本的 Apache Ant
2. 更新到最新版本的 Java。
3. 如果可能，请为您的操作系统应用最新补丁
4. 检查一次使用Ant执行应用程序时问题是否仍然存在
5. 如果否，则微笑 :)
6. 否则尝试另一种方法。尝试通过 Java 的 ProcessBuilder 或 Runtime.getRuntime().exec() 执行您的应用程序，即编写一个小的应用程序启动器代码并通过它执行您的应用程序。
7. 如果您的应用程序可以运行，那么问题出在 Ant 上。提交错误。
8. 如果应用程序仍然表现异常，那么您需要进一步调查您的代码或考虑提交 Java 错误。

希望这对您有所帮助。祝你好运。