|Summary:||InterruptedIOException ignored by log4j|
|Product:||Log4j - Now in Jira||Reporter:||Jared Oberhaus <oberhaus>|
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!