Summary: | Using AsynchAppender in logging configuration prevents virtual machine from exiting | ||
---|---|---|---|
Product: | Log4j - Now in Jira | Reporter: | Sean Reilly <sreilly> |
Component: | Appender | Assignee: | log4j-dev <log4j-dev> |
Status: | RESOLVED FIXED | ||
Severity: | minor | ||
Priority: | P3 | ||
Version: | 1.2 | ||
Target Milestone: | --- | ||
Hardware: | PC | ||
OS: | All | ||
Attachments: |
java source code that reproduces the issue
log4j config that causes the console to hang log4j config that causes the console not to hand log4j jar file used in test case (log4j.jar from v 1.2.3) log4j.dtd used in test runs (from v 1.2.3) |
Description
Sean Reilly
2002-06-10 17:38:09 UTC
Created attachment 2049 [details]
java source code that reproduces the issue
Created attachment 2050 [details]
log4j config that causes the console to hang
Created attachment 2051 [details]
log4j config that causes the console not to hand
Created attachment 2052 [details]
log4j jar file used in test case (log4j.jar from v 1.2.3)
Created attachment 2053 [details]
log4j.dtd used in test runs (from v 1.2.3)
This test case was compiled and run using JDK1.4 It should run in earlier versions with the addition of an xml parser. compiled with "javac -classpath log4j.jar Test.java" the nohang case is run with "%JAVA_HOME_14%\bin\java -cp log4j.jar;. - Dlog4j.configuration=log4jconfig_nohang.xml Test" it generated the following output: 2002-06-10 11:36:59,874: DEBUG (test) - starting 2002-06-10 11:36:59,889: DEBUG (test) - finishing the hanging case is run with "C:\log4j_case>%JAVA_HOME_14%\bin\java -cp log4j.jar;. -Dlog4j.configuration=log4jconfig_hang.xml Test" it generates the same output: 2002-06-10 11:37:04,670: DEBUG (test) - starting 2002-06-10 11:37:04,670: DEBUG (test) - finishing except that execution does not stop. The process continues until forcibly terminated (Ctrl-C on the console, for example). If you need any other test cases, or if I have missed any information you would like to have, please let me know. Sean Reilly Potential solution: I believe that the VM is continuing execution because the thread created by AsyncAppender is not a daemon thread. If this thread were to be set as a Daemon thread then the VM should be able to exit properly. Here is a change to the constructor of Dispatcher (internal class in AsyncAppender) that would accomplish this: Before: Dispatcher(BoundedFIFO bf, AsyncAppender container) { this.bf = bf; this.container = container; this.aai = container.aai; // set the dispatcher priority to lowest possible value this.setPriority(Thread.MIN_PRIORITY); this.setName("Dispatcher-"+getName()); // set the dispatcher priority to MIN_PRIORITY plus or minus 2 // depending on the direction of MIN to MAX_PRIORITY. //+ (Thread.MAX_PRIORITY > Thread.MIN_PRIORITY ? 1 : -1)*2); } After: Dispatcher(BoundedFIFO bf, AsyncAppender container) { this.bf = bf; this.container = container; this.aai = container.aai; this.setDaemon(true); // set the dispatcher priority to lowest possible value this.setPriority(Thread.MIN_PRIORITY); this.setName("Dispatcher-"+getName()); // set the dispatcher priority to MIN_PRIORITY plus or minus 2 // depending on the direction of MIN to MAX_PRIORITY. //+ (Thread.MAX_PRIORITY > Thread.MIN_PRIORITY ? 1 : -1)*2); } This of course leaves the appender vunerable to the possibility of a VM shutdown resulting in logging message loss. If this is an issue, then perhaps a finalizer could be added that would call the dispatcher's close() method? Log4j 1.2.4 fixes this bug. Is this bug only fixed if you call AsyncAppender.close()? I'm experiencing the same issue with 1.2.6, but I'm not calling the close method explicitly (the app using the Appender causes application shutdown, so I have little control over 'when' the app is done with the Appender. |