We recently upgraded our message processing application from Java 7 to Java 8. Since the upgrade, we get an occasional exception that a stream has been closed while it is being read from. Logging shows that the finalizer thread is calling finalize() on the object that holds the stream (which in turn closes the stream).
The basic outline of the code is as follows:
MIMEWriter writer = new MIMEWriter( out );
in = new InflaterInputStream( databaseBlobInputStream );
MIMEBodyPart attachmentPart = new MIMEBodyPart( in );
writer.writePart( attachmentPart );
MIMEWriter and MIMEBodyPart are part of a home-grown MIME/HTTP library. MIMEBodyPart extends HTTPMessage, which has the following:
public void close() throws IOException
{
if ( m_stream != null )
{
m_stream.close();
}
}
protected void finalize()
{
try
{
close();
}
catch ( final Exception ignored ) { }
}
The exception occurs in the invocation chain of MIMEWriter.writePart, which is as follows:
MIMEWriter.writePart() writes the headers for the part, then calls part.writeBodyPartContent( this )MIMEBodyPart.writeBodyPartContent() calls our utility method IOUtil.copy( getContentStream(), out ) to stream the content to the outputMIMEBodyPart.getContentStream() just returns the input stream passed into the contstructor (see code block above)IOUtil.copy has a loop that reads an 8K chunk from the input stream and writes it to the output stream until the input stream is empty.The MIMEBodyPart.finalize() is called while IOUtil.copy is running, and it gets the following exception:
java.io.IOException: Stream closed
at java.util.zip.InflaterInputStream.ensureOpen(InflaterInputStream.java:67)
at java.util.zip.InflaterInputStream.read(InflaterInputStream.java:142)
at java.io.FilterInputStream.read(FilterInputStream.java:107)
at com.blah.util.IOUtil.copy(IOUtil.java:153)
at com.blah.core.net.MIMEBodyPart.writeBodyPartContent(MIMEBodyPart.java:75)
at com.blah.core.net.MIMEWriter.writePart(MIMEWriter.java:65)
We put some logging in the HTTPMessage.close() method that logged the stack trace of the caller and proved that it is definitely the finalizer thread that is invoking HTTPMessage.finalize() while IOUtil.copy() is running.
The MIMEBodyPart object is definitely reachable from the current thread's stack as this in the stack frame for MIMEBodyPart.writeBodyPartContent. I don't understand why the JVM would call finalize().
I tried extracting the relevant code and running it in a tight loop on my own machine, but I cannot reproduce the problem. We can reliably reproduce the problem with high load on one of our dev servers, but any attempts to create a smaller reproducible test case have failed. The code is compiled under Java 7 but executes under Java 8. If we switch back to Java 7 without recompiling, the problem does not occur.
As a workaround, I've rewritten the affected code using the Java Mail MIME library and the problem has gone away (presumably Java Mail doesn't use finalize()). However, I'm concerned that other finalize() methods in the application may be called incorrectly, or that Java is trying to garbage-collect objects that are still in use.
I know that current best practice recommends against using finalize() and I will probably revisit this home-grown library to remove the finalize() methods. That being said, has anyone come across this issue before? Does anyone have any ideas as to the cause?
A bit of conjecture here. It is possible for an object to be finalized and garbage collected even if there are references to it in local variables on the stack, and even if there is an active call to an instance method of that object on the stack! The requirement is that the object be unreachable. Even if it's on the stack, if no subsequent code touches that reference, it's potentially unreachable.
See this other answer for an example of how an object can be GC'ed while a local variable referencing it is still in scope.
Here's an example of how an object can be finalized while an instance method call is active:
class FinalizeThis {
protected void finalize() {
System.out.println("finalized!");
}
void loop() {
System.out.println("loop() called");
for (int i = 0; i < 1_000_000_000; i++) {
if (i % 1_000_000 == 0)
System.gc();
}
System.out.println("loop() returns");
}
public static void main(String[] args) {
new FinalizeThis().loop();
}
}
While the loop() method is active, there is no possibility of any code doing anything with the reference to the FinalizeThis object, so it's unreachable. And therefore it can be finalized and GC'ed. On JDK 8 GA, this prints the following:
loop() called
finalized!
loop() returns
every time.
Something similar might be going on with MimeBodyPart. Is it being stored in a local variable? (It seems so, since the code seems to adhere to a convention that fields are named with an m_ prefix.)
UPDATE
In the comments, the OP suggested making the following change:
public static void main(String[] args) {
FinalizeThis finalizeThis = new FinalizeThis();
finalizeThis.loop();
}
With this change he didn't observe finalization, and neither do I. However, if this further change is made:
public static void main(String[] args) {
FinalizeThis finalizeThis = new FinalizeThis();
for (int i = 0; i < 1_000_000; i++)
Thread.yield();
finalizeThis.loop();
}
finalization once again occurs. I suspect the reason is that without the loop, the main() method is interpreted, not compiled. The interpreter is probably less aggressive about reachability analysis. With the yield loop in place, the main() method gets compiled, and the JIT compiler detects that finalizeThis has become unreachable while the loop() method is executing.
Another way of triggering this behavior is to use the -Xcomp option to the JVM, which forces methods to be JIT-compiled before execution. I wouldn't run an entire application this way -- JIT-compiling everything can be quite slow and take lots of space -- but it's useful for flushing out cases like this in little test programs, instead of tinkering with loops.