Bug 44157

Summary: InterruptedIOException ignored by log4j
Product: Log4j - Now in Jira Reporter: Jared Oberhaus <oberhaus>
Component: AppenderAssignee: log4j-dev <log4j-dev>
Status: RESOLVED FIXED    
Severity: normal CC: anishc
Priority: P2    
Version: 1.2   
Target Milestone: ---   
Hardware: Other   
OS: other   

Description Jared Oberhaus 2008-01-01 23:03:35 UTC
log4j catches and ignores InterruptedIOException's, causing code that uses log4j to freeze under 
certain conditions.

When the exception InterruptedException is caught, special care must be taken. If InterruptedException 
is caught and ignored, and the thread does not exit, other code that interrupted that thread will not 
function correctly.

The same is true of InterruptedIOException (which derives from IOException). This can be thrown from 
any java.nio blocking method, or can be thrown from java.io methods on Solaris. An 
InterruptedIOException must be treated the same as an InterruptedException; either the exception 
should be allowed to continue up the call stack, or something special must be done.

One example of something special is to call the following:

Thread.currentThread().interrupt();

I propose that everywhere in log4j that IOException is caught, a special catch of InterruptedIOException 
is done and Thread.
Comment 1 Jared Oberhaus 2008-01-01 23:05:16 UTC
Here are some documents that support my suggestion:

http://java.sun.com/j2se/1.5.0/docs/guide/misc/threadPrimitiveDeprecation.html
How do I stop a thread that waits for long periods (e.g., for input)?

http://www-128.ibm.com/developerworks/java/library/j-jtp05236.html
Don't swallow interrupts

Comment 2 Thorbjørn Ravn Andersen 2008-08-02 13:57:52 UTC
I think this should be carefully considered before next release.
Comment 3 Curt Arnold 2008-08-13 14:39:32 UTC
Committed patch in rev 685684.  Appreciate feedback.
Comment 4 Jared Oberhaus 2008-08-13 16:40:00 UTC
This is great, thank you! I took a look at the change, and here's what I observed:

* java/org/apache/log4j/PropertyConfigurator.java
* java/org/apache/log4j/xml/DOMConfigurator.java
There are a few catch(Exception) and catch(Throwable) that could also be hiding InterruptedException.

* java/org/apache/log4j/jmx/AbstractDynamicMBean.java
* java/org/apache/log4j/jmx/Agent.java
* java/org/apache/log4j/jmx/AppenderDynamicMBean.java
* java/org/apache/log4j/jmx/HierarchyDynamicMBean.java
* java/org/apache/log4j/jmx/LayoutDynamicMBean.java
There are couple of catch(Exception) here that do nothing but printStackTrace(). This hides InterruptedException and InterruptedIOException, but I suspect that the intent of those catches is that they never happen... But there are still others that appear to be normal operation and will hide InterruptedException.

* java/org/apache/net/JMSAppender.java
There's a catch(Exception) in the close() method

* java/org/apache/net/JMSSink.java
There's a catch(Exception) in the constructor

* java/org/apache/net/SMTPAppender.java
In sendBuffere there's a catch(Exception)

* java/org/apache/net/SocketAppender.java
In the connect() method there's a catch(IOException) that might call errorHandler.error, but in other cases will not, in which case the InterruptedException will be lost...

* java/org/apache/net/SocketHubAppender.java
There are catch(IOException) in cleanup() and append() that will hide InterruptedIOException.

* java/org/apache/net/TelnetAppender.java
There are a few ignored catch(Exception) and one ignored catch(InterruptedException)

* java/org/apache/log4j/spi/LoggingEvent.java
There's a catch(Exception) here

* java/org/apache/log4j/varia/ExternallyRolledFileAppender.java
The class HUP extends Thread and checks for isInterrupted(), but the catch(Exception) block will effectively eat any that are thrown. Also there are a couple other catch(Exception) in that file.

* java/org/apache/log4j/varia/Roller.java
There's a catch(IOException) here too, but it calls System.exit(2).

* java/org/apache/log4j/chainsaw/...
There are several files in here that catch(Exception); however, this isn't nearly as critical as the InterruptedException's lost above, because chainsaw is usually its own standalone tool.

* java/org/apache/log4j/lf5/...
Like chainsaw, this probably isn't as important as the above, as it's a standalone tool.

Comment 5 Curt Arnold 2008-08-14 00:58:47 UTC
org.apache.log4j.lf5 and .chainsaw are no longer maintained but are provided simply for compatibility with earlier jars.  Probably would not hurt anyone if they disappeared, but can't say that for certain so they have to stay.  However, don't see any need to change them.  Chainsaw 2 was spun out from log4j and is a different beast than the org.apache.log4j.chainsaw classes in the jar.

Committed round two in 685796.


Comment 6 Jared Oberhaus 2008-08-14 15:25:57 UTC
Thanks again for your change. Looks great...

First, I have to admit that my feedback in Comment #4 was based on my
reviewing an older copy of log4j, not the latest trunk. Please accept
my apologies for this... I am rectifying that now by checking out the
latest trunk and looking it over.

Here is what I've observed:

* Ignoring issues in contribs/...
* Ignoring issues in examples/...
* Ignoring issues in tests/...
* Ignoring chainsaw and lf5 (thanks for the info in Comment #5)

* catch(Throwable), catch(Exception), catch(InvocationTargetException)
There are cases I've found of catch(InvocationTargetException), and of
catch(Throwable) and catch(Exception). In the case where
InvocationTargetException is thrown, the result of getTargetException
could be an InterruptedException or an InterruptedIOException. Also,
the Throwable or Exception could be InterruptedException or
InterruptedIOException, or an InvocationTargetException with
InterruptedException or InterruptedIOException in
getTargetException. Perhaps a utility method could be used (similar to
ErrorHandler.error) that analyzes all of these cases.

Note that I now realize I should audit my own code for these cases, as
I also use Method.invoke and catch(InvocationTargetException)...

Here's a list of the places where I found either catch(Throwable),
catch(Exception) or catch(InvocationTargetException) and it seemed
that one of these exceptions was possible (I'm ignoring cases where
Throwable/Exception couldn't include one of the 3 above exceptions):

java/org/apache/log4j/config/PropertyGetter.java:80
java/org/apache/log4j/config/PropertySetter.java:145
java/org/apache/log4j/config/PropertySetter.java:229
java/org/apache/log4j/helpers/Loader.java:115
java/org/apache/log4j/helpers/Loader.java:175
java/org/apache/log4j/helpers/OptionConverter.java:233
java/org/apache/log4j/helpers/OptionConverter.java:331
java/org/apache/log4j/jmx/Agent.java:85
java/org/apache/log4j/jmx/AppenderDynamicMBean.java:254
java/org/apache/log4j/jmx/AppenderDynamicMBean.java:310
java/org/apache/log4j/jmx/LayoutDynamicMBean.java:192
java/org/apache/log4j/jmx/LayoutDynamicMBean.java:250
java/org/apache/log4j/net/SocketNode.java:106
java/org/apache/log4j/spi/LocationInfo.java:170
java/org/apache/log4j/spi/LoggingEvent.java:441
java/org/apache/log4j/xml/DOMConfigurator.java:406


* java/org/apache/log4j/net/SocketHubAppender.java:374
Ignored InterruptedException

* java/org/apache/log4j/net/TelnetAppender.java:108
Ignored InterruptedException

* java/org/apache/log4j/net/SocketHubAppender.java:428
ignored InterruptedIOException; the comment says that it's a timeout,
but a timeout will usually cause SocketTimeoutException.

Comment 7 Curt Arnold 2008-08-14 23:01:19 UTC
Applied everything in comment 6 in rev 686149 except:

> java/org/apache/log4j/net/SocketHubAppender.java:428
> ignored InterruptedIOException; the comment says that it's a timeout,
> but a timeout will usually cause SocketTimeoutException.

SocketTimeoutException was added in JDK 1.4 and extends InterruptedIOException.  The only way to catch the timeout JDK 1.3 and earlier is to catch the InterruptedIOException.  I think the logic is doing what it needs to do.

There is the unlikely possibility that InstantiationExceptions are also masking InterruptedExceptions or InterruptedIOExceptions however InstantiationException.getCause() was added in JDK 1.4.  I do not feel that it is worth doing a reflective call to check for the underlying exception.
Comment 8 Jared Oberhaus 2008-08-14 23:36:28 UTC
This is great, thanks so much for your changes.

I forget that log4j has to deal with older versions of the JVM; thanks for watching out for that and letting me know. And thanks for pointing out InstantiationException; and the approach to treating it is fair.

I'll be waiting for the next release of log4j that contain these changes... Thanks again!

Comment 9 Gilles Scokart 2009-06-23 12:50:32 UTC
*** Bug 47401 has been marked as a duplicate of this bug. ***