Summary: | IllegalStateException thrown from FileAppender.closeFile() when log file is actively being tailed | ||
---|---|---|---|
Product: | Log4j - Now in Jira | Reporter: | Jake Happs <jake.happs> |
Component: | Appender | Assignee: | log4j-dev <log4j-dev> |
Status: | NEEDINFO --- | ||
Severity: | major | CC: | jake.happs, jlindwall, thorbjoern |
Priority: | P2 | ||
Version: | 1.2 | ||
Target Milestone: | --- | ||
Hardware: | Sun | ||
OS: | Solaris |
Description
Jake Happs
2007-07-18 14:22:39 UTC
JVM bug maybe? We are also seeing this problem but with Log4j's DailyRollingFileAppender and FileAppender. It occurs in jdk 1.5.0_11 and jdk1.5.0_13 but not in j2sdk1.3.1_20. Here is a dorky test program to reproduce it: import org.apache.log4j.FileAppender; import org.apache.log4j.Logger; import org.apache.log4j.Priority; import org.apache.log4j.PatternLayout; import org.apache.log4j.spi.LoggingEvent; public class TailBug { public static void main(String[] args) throws InterruptedException { final String filename = "tailme"; FileAppender fa = new FileAppender(); fa.setName("myappender"); fa.setFile(filename); fa.setLayout(new PatternLayout("%d %m%n")); fa.activateOptions(); writeSomeMessages(fa); System.out.println("NOW Start tailing " + filename + "!!!!!\n"); System.out.println("The logfile will be rotated to in 10 seconds"); Thread.sleep(10000); final String newfilename = "tailme2"; fa.setFile(newfilename); fa.activateOptions(); // Exception will be thrown here writeSomeMessages(fa); System.out.println("Done!"); } private static void writeSomeMessages(FileAppender fa) { System.out.println("Logging 5 messages to file " + fa.getFile() + "...\n"); for( int i = 0; i < 5; i++ ) { fa.append(new LoggingEvent("", Logger.getLogger("log"), Priority.WARN, "This is a test message", null)); } } } This seems to be Sun JVM bug 5005426 (which was also later reported in a duplicate bug 5005419). It does not affect JVM 1.3.1 or Java 6, in my experimentation. I'll see if I can get this bug re-opened in JDK 1.5.0. http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=5005426 5005426 http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=5005419 5005419 I've opened a bug request with Sun to notify them that this bug (which was fixed in 1.3.1 and 1.4.2 AND Java 6) is affecting Java 5. I'll report any status here; for now their automated system has simply accepted my report. Sun has been very helpful and speedy in addressing this regression bug. They have a fix for it, and it will roll it out ASAP (probably for jdk 1.5.0_15). ------------- Problem Description (Expand on problem statement as necessary) Escalate Bug 5005426 for JDK 5.0. This bug was fixed in 1.4.2 and in 6.0, but still existed in 5.0. ------------------------------------------------------- Solution Note (Root Cause, Possible Causes or Actions taken for Closure) Sustaining will backport the fix into a 5.0 update release (most likely _15). If this has been identified to be a Sun bug and they have accepted it, would it be reasonable to close this bug? No response in a month. Setting to NEEDINFO. |