24

I'm right now debugging a program which has two threads per one external process, and those two threads keep on reading Process.getErrorStream() and Process.getInputStream() using a while ((i = in.read(buf, 0, buf.length)) >= 0) loop.

Sometimes when the external process crashes due to a JVM crash (see these hs_err_pid.log files), those threads which read the stdout/stderr of that external process begin consuming 100% CPU and never exit. The loop body is not being executed (I've added a logging statement there), so the infinite loop appears to be inside the native method java.io.FileInputStream.readBytes.

I've reproduced this on both Windows 7 64-bit (jdk1.6.0_30 64-bit, jdk1.7.0_03 64-bit), and Linux 2.6.18 (jdk1.6.0_21 32-bit). The code in question is here and it is used like this. See those links for the full code - here are the interesting bits:

private final byte[]              buf = new byte[256];
private final InputStream         in;
...    

int i;
while ((i = this.in.read(this.buf, 0, this.buf.length)) >= 0) {
    ...
}

The stack traces look like

"PIT Stream Monitor" daemon prio=6 tid=0x0000000008869800 nid=0x1f70 runnable [0x000000000d7ff000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(Native Method)
    at java.io.FileInputStream.read(FileInputStream.java:220)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
    at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
    - locked <0x00000007c89d6d90> (a java.io.BufferedInputStream)
    at org.pitest.util.StreamMonitor.readFromStream(StreamMonitor.java:38)
    at org.pitest.util.StreamMonitor.process(StreamMonitor.java:32)
    at org.pitest.util.AbstractMonitor.run(AbstractMonitor.java:19)
   Locked ownable synchronizers:
    - None

or

"PIT Stream Monitor" daemon prio=6 tid=0x0000000008873000 nid=0x1cb8 runnable [0x000000000e3ff000]
   java.lang.Thread.State: RUNNABLE
    at java.io.FileInputStream.readBytes(Native Method)
    at java.io.FileInputStream.read(FileInputStream.java:220)
    at org.pitest.util.StreamMonitor.readFromStream(StreamMonitor.java:38)
    at org.pitest.util.StreamMonitor.process(StreamMonitor.java:32)
    at org.pitest.util.AbstractMonitor.run(AbstractMonitor.java:19)
   Locked ownable synchronizers:
    - None

With the Sysinternals Process Explorer I was able to get native stack traces of those threads. Most often, over 80% of the time, the stack trace looks like this:

ntdll.dll!NtReadFile+0xa
KERNELBASE.dll!ReadFile+0x7a
kernel32.dll!ReadFile+0x59
java.dll!handleRead+0x2c
java.dll!VerifyClassCodesForMajorVersion+0x1d1
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

This also happens quite often:

ntdll.dll!RtlNtStatusToDosErrorNoTeb+0x52
ntdll.dll!RtlNtStatusToDosError+0x23
KERNELBASE.dll!GetCurrentThreadId+0x2c
KERNELBASE.dll!CreatePipe+0x21a
kernel32.dll!ReadFile+0x59
java.dll!handleRead+0x2c
java.dll!VerifyClassCodesForMajorVersion+0x1d1
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

ntdll.dll!RtlNtStatusToDosErrorNoTeb+0x42
ntdll.dll!RtlNtStatusToDosError+0x23
KERNELBASE.dll!GetCurrentThreadId+0x2c
KERNELBASE.dll!CreatePipe+0x21a
kernel32.dll!ReadFile+0x59
java.dll!handleRead+0x2c
java.dll!VerifyClassCodesForMajorVersion+0x1d1
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

And sometimes it's executing this part of the code:

java.dll!VerifyClassCodesForMajorVersion+0xc3
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

java.dll!Java_sun_io_Win32ErrorMode_setErrorMode+0x847c
java.dll!VerifyClassCodesForMajorVersion+0xd7
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

jvm.dll!JNI_GetCreatedJavaVMs+0x1829f
java.dll!VerifyClassCodesForMajorVersion+0x128
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

jvm.dll+0x88c1
jvm.dll!JNI_GetCreatedJavaVMs+0x182a7
java.dll!VerifyClassCodesForMajorVersion+0x128
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

java.dll!VerifyClassCodesForMajorVersion+0x10b
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

jvm.dll!JNI_CreateJavaVM+0x1423
java.dll!VerifyClassCodesForMajorVersion+0x190
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

jvm.dll+0x88bf
jvm.dll!JNI_CreateJavaVM+0x147d
java.dll!VerifyClassCodesForMajorVersion+0x190
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

java.dll!VerifyClassCodesForMajorVersion+0x1aa
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

java.dll!VerifyClassCodesForMajorVersion+0x1c3
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

java.dll!VerifyClassCodesForMajorVersion+0x224
java.dll!Java_java_io_FileInputStream_readBytes+0x1d

Any ideas how to solve this problem? Is this a known problem with the JVM? Is there a workaround?

14
  • 3
    Could you include your loop code? BTW the condition >= 0 is overly broad, if buf.length is non-zero, then read() is guaranteed to read at least 1 byte or return -1 (or throw an Exception). Apr 16, 2012 at 16:48
  • What? Is Process.getInputStream() returning a FileInputStream? Apr 16, 2012 at 17:28
  • Yes. In java.lang.ProcessImpl#ProcessImpl you can see stdout_stream and stderr_stream being initialized with a FileInputStream. It kinda makes sense from the Unix point of view, where everything is a file. Apr 16, 2012 at 17:57
  • 3
    Looking at OpenJDK's source code, the implementation of readBytes has no loops and is a thin wrapper over Windows' ReadFile function. Let's continue looking into OS issues... maybe antivirus or something... Apr 16, 2012 at 19:33
  • 1
    This issue might be related: weblogs.java.net/blog/kohsuke/archive/2009/09/28/… Apr 17, 2012 at 8:03

1 Answer 1

1

I've not yet been able to reproduce this locally, but the two possible workarounds might be

  • Play around with in.available().

  • Redirect stout and stderr in the external process to a socket and read this from the controlling process instead.

2
  • A quick fix using in.available() has helped to avoid the problem for now. We are still looking for a better solution and the reason why this is happening in the first place. I'll try to produce a SSCCE by removing superfluous code from the closed source project where I can reproduce this. Apr 21, 2012 at 14:31
  • The problem can be re-produced by crashing the child process with the infinite array allocating loop from stackoverflow.com/questions/65200/how-do-you-crash-a-jvm and probably the other techniques listed there.
    – henry
    Apr 22, 2012 at 20:03

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.