Infinite 100% CPU usage at java.io.FileInputStream.readBytes(Native Method)

Question

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?

Answer 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.