Note that there are some explanatory texts on larger screens.

plurals
  1. POSystem.out.println eventually blocks
    primarykey
    data
    text
    <p>I have an application that consolidates all of its logging into a single-instance class in order to facilitate selective debug printing etc. The class has been around for a year or so working smoothly, but just recently I happened to turn the log level up to its highest setting (which I rarely do) and the <strong>standard output seems to eventually block</strong>. This causes havoc the next time some other part of the code calls <code>println</code>, or when it tries to use the logging class (which is blocked waiting for <code>println</code> to return).</p> <p>My first thought was that I had some sort of concurrency issue with my logging class, but scouring the stack traces reassures me that my synchronization is working correctly and that only a single thread is attempting to write to the console at any given time. Here is a sample stack trace on the offending thread:</p> <pre><code>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 </code></pre> <p>Digging a little deeper into the native stack traces, I found that the JVM process is blocking on the Windows native <code>ZwWriteFile</code> call. My best guess is that the JVM is using named pipes configured for synchronous reading/writing the buffered data, but that the reader has somehow stopped and let the buffer fill. Meanwhile the writer is blocked waiting for buffer space to become available, but this never happens. Here's the native stack trace of the same thread:</p> <pre><code> 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() ... </code></pre> <p>The end result is that the stdout buffer is getting filled up and sooner or later, stuff stops writing to the console.</p> <p>Here's the catch: if I run the application standalone instead of running it from an Apache Ant build script, I can't reproduce the problem. So it might have to do with how Ant redirects the process output, but I'm hesitant to submit a bug report because it seems like someone else would have run into this issue before... and, because I can't get the same behavior to reproduce in isolation.</p> <p>Any thoughts or advice on how I might go about tracking this down further?</p> <p><strong>UPDATE</strong>: Updating Eclipse from 3.4.2 to Helios (M2) magically solved the problem. I am also able to continue using 3.4.2 by launching the integrated Ant builder from the command line instead of the UI:</p> <pre><code>java -jar &lt;eclipse directory&gt;\plugins\org.eclipse.equinox.launcher_&lt;version&gt;.jar -application org.eclipse.ant.core.antRunner -buildfile &lt;buildfile&gt; </code></pre>
    singulars
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    plurals
    1. This table or related slice is empty.
    1. This table or related slice is empty.
    1. This table or related slice is empty.
 

Querying!

 
Guidance

SQuiL has stopped working due to an internal error.

If you are curious you may find further information in the browser console, which is accessible through the devtools (F12).

Reload