October 2008 - logback-dev - mailman3.qos.ch

[JIRA] Issue Comment Edited: (LBCLASSIC-35) Deadlock when running on multiple core processors
by Ralph Goers (JIRA) 12 Oct '08

12 Oct '08

[ http://jira.qos.ch/browse/LBCLASSIC-35?page=com.atlassian.jira.plugin.syste… ] Ralph Goers edited comment on LBCLASSIC-35 at 10/13/08 12:26 AM: ----------------------------------------------------------------- This bug needs to be fixed as does the bug in AppenderBase. I have a patch that fixes this issue but I don't seem to have permission to attach it to this issue. FWIW, in some cases slow appenders wouldn't be as much of a problem if it weren't for these synchronization points. I have a custom appender that is slow, but is thread safe so many of them can be run in parallel. With these two synchronization points however, Logback ends up showing up as a system wide bottleneck. was (Author: rgoers(a)apache.org) This bug needs to be fixed as does the bug in AppenderBase. I have attached the fix for this issue and will open a second issue for AppenderBase. FWIW, in some cases slow appenders wouldn't be as much of a problem if it weren't for these synchronization points. I have a custom appender that is slow, but is thread safe so many of them can be run in parallel. With these two synchronization points however, Logback ends up showing up as a system wide bottleneck. > Deadlock when running on multiple core processors > ------------------------------------------------- > > Key: LBCLASSIC-35 > URL: http://jira.qos.ch/browse/LBCLASSIC-35 > Project: logback-classic > Issue Type: Bug > Components: Other > Affects Versions: unspecified > Environment: Operating System: Windows > Platform: PC > Reporter: Toni Heimala > Assignee: Ceki Gulcu > Priority: Blocker > > When you run logging into same file from many threads on a system that has more than one physical processor (Dual Core for example), a deadlock will occur after a while. This can not be reproduced on HyperThreading processors. Here's an example program that will demonstrate the behavior: > ----------------------------- > Main.java > ----------------------------- > import java.util.Date; > import java.util.concurrent.ScheduledThreadPoolExecutor; > import java.util.concurrent.TimeUnit; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > import ch.qos.logback.classic.LoggerContext; > import ch.qos.logback.classic.joran.JoranConfigurator; > import ch.qos.logback.core.joran.spi.JoranException; > public class Main extends Thread > { > private final static String LOGGER_CONFIGURATION_FILE = "logger.xml"; > private final Logger logger = LoggerFactory.getLogger(Main.class); > > private final long start; > > public Main() > throws JoranException > { > start = new Date().getTime(); > LoggerContext lc = (LoggerContext)LoggerFactory.getILoggerFactory(); > JoranConfigurator configurator = new JoranConfigurator(); > lc.shutdownAndReset(); > configurator.setContext(lc); > configurator.doConfigure(LOGGER_CONFIGURATION_FILE); > } > > public void start() > { > ScheduledThreadPoolExecutor ex1 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex2 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex3 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex4 = new ScheduledThreadPoolExecutor(1); > ScheduledThreadPoolExecutor ex5 = new ScheduledThreadPoolExecutor(1); > ex1.scheduleAtFixedRate(new Task("EX1"), 10, 10, TimeUnit.MICROSECONDS); > ex2.scheduleAtFixedRate(new Task("EX2"), 10, 10, TimeUnit.MICROSECONDS); > ex3.scheduleAtFixedRate(new Task("EX3"), 10, 10, TimeUnit.MICROSECONDS); > ex4.scheduleAtFixedRate(new Task("EX4"), 10, 10, TimeUnit.MICROSECONDS); > ex5.scheduleAtFixedRate(new Task("EX5"), 10, 10, TimeUnit.MICROSECONDS); > > super.start(); > } > > public void run() > { > try > { > while(true) > { > logger.debug("[MAIN] {}", new Date().getTime() - start); > Thread.sleep(10); > } > } > catch (InterruptedException e) > { > logger.info("[MAIN]: Interrupted: {}", e.getMessage()); > } > } > > public static void main(String[] args) > { > try > { > Main main = new Main(); > main.start(); > } > catch (JoranException e) > { > System.out.println("Failed to load application: " + e.getMessage()); > } > } > } > ------------------------------- > Task.java > ------------------------------- > import java.util.Date; > import org.slf4j.Logger; > import org.slf4j.LoggerFactory; > public class Task implements Runnable > { > private final Logger logger = LoggerFactory.getLogger(Task.class); > private final Logger logger_main = LoggerFactory.getLogger(Main.class); > private final String name; > private final long start; > > public Task(final String name) > { > this.name = name; > start = new Date().getTime(); > } > public void run() > { > logger.debug("[{}] {}", name, new Date().getTime() - start); > logger_main.debug("[MAIN] - [{}] {}", name, new Date().getTime() - start); > } > } -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

Appender synchronization
by Ralph Goers 11 Oct '08

11 Oct '08

I would have opened a Jira issue for this (I will) but it appears to be unavailable. We have run into a serious performance problem with a custom appender. The appender is not particularly fast and logback ends up being a system wide bottleneck. This is because the doAppend method of AppenderBase is synchronzed and Logger's callApenders method calls appendLoopOnAppenders within a synchronzed block. Synchronized blocks should always be as small as possible. Synchronizing appender calls is just asking for trouble. Chapter 4 currently documents this behavior and should be changed. In my case I can avoid the first issue by having my appender override doAppend, but this really shouldn't be necessary. It would be much better to have appenders that aren't thread safe synchronize on the doAppend method or, better yet, within the method. The guard to avoid recursion can be handled with a thread local. As for callAppenders, there is unfortunately no way for me to bypass this problem without patching logback. java.util.concurrent provides several ways to avoid this. One would be to replace the synchronization with a ReadWriteLock. An even better alternative would be to completely remove the synchronization from Logger and change AppenderAttachableImpl use a ReadWriteLock to manage access to the appender List. I will try to work up some patches for these and add them to jira when they are done and jira is available again. Ralph

1 0

svn commit: r1828 - logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling
by noreply.ceki＠qos.ch 08 Oct '08

08 Oct '08

Author: ceki Date: Wed Oct 8 23:06:07 2008 New Revision: 1828 Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java Log: - renamed FileAppender.setFile method as openFile Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/RollingFileAppender.java Wed Oct 8 23:06:07 2008 @@ -98,7 +98,7 @@ try { // This will also close the file. This is OK since multiple // close operations are safe. - this.setFile(); + this.openFile(); } catch (IOException e) { addError( "setFile(" + fileName + ", false) call failed.", e);

1 0

[JIRA] Resolved: (LBCORE-42) add option to FileAppender to auto-create parent directories
by Ceki Gulcu (JIRA) 08 Oct '08

08 Oct '08

[ http://jira.qos.ch/browse/LBCORE-42?page=com.atlassian.jira.plugin.system.i… ] Ceki Gulcu resolved LBCORE-42. ------------------------------ Fix Version/s: 0.9.10 Resolution: Fixed Fixed > add option to FileAppender to auto-create parent directories > ------------------------------------------------------------ > > Key: LBCORE-42 > URL: http://jira.qos.ch/browse/LBCORE-42 > Project: logback-core > Issue Type: Bug > Components: Appender > Affects Versions: unspecified > Environment: Operating System: Linux > Platform: PC > Reporter: Bruno Navert > Assignee: Logback dev list > Fix For: 0.9.10 > > Attachments: FileAppender.java.patch > > > FileAppender should be able to automatically create parent directories as needed when writing the log file. > For instance, if configured with <File>/var/tmp/project_name/some_file.log</File>, and the new option set to true (suggest <CreateParentDirectories>true</CreateParentDirectories> maybe), then in FileAppender.setFile(), it should do > new File( fileName ).getParentFile().mkdirs() > workaround is to create the directory before initializing logback. Possible but far less than ideal, and rather complicated too -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

svn commit: r1827 - in logback/trunk/logback-site/src/site/pages: . manual
by noreply.ceki＠qos.ch 08 Oct '08

08 Oct '08

Author: ceki Date: Wed Oct 8 22:50:37 2008 New Revision: 1827 Modified: logback/trunk/logback-site/src/site/pages/manual/appenders.html logback/trunk/logback-site/src/site/pages/news.html Log: blurb about automatic file creation Modified: logback/trunk/logback-site/src/site/pages/manual/appenders.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/appenders.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/appenders.html Wed Oct 8 22:50:37 2008 @@ -498,6 +498,11 @@ specified as c:/temp/test.log or alternatively as c:\\temp\\test.log. The File option has no default value. + + If the parent directory of the file does now exist, the + FileAppender will automatically create it, including any + necessary but nonexistent parent directories. + </td> </tr> <tr class="a"> Modified: logback/trunk/logback-site/src/site/pages/news.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/news.html (original) +++ logback/trunk/logback-site/src/site/pages/news.html Wed Oct 8 22:50:37 2008 @@ -74,6 +74,15 @@ thus controlling then number of archived log files. Fixed issue <a + href="http://jira.qos.ch/browse/LBCORE-42">LBCORE-42</a>. If the + parent directory of the log file does not exist, then FileAppender + will create it, including any necessary but nonexistent parent + directories. + + + + + Fixed issue <a href="http://jira.qos.ch/browse/LBCORE-27">LBCORE-27</a> reported by Peter Royal. SMTPAppender now outputs its presentation footer and file footer in the the correct order.

1 0

svn commit: r1826 - in logback/trunk/logback-core/src: main/java/ch/qos/logback/core main/java/ch/qos/logback/core/util test/java/ch/qos/logback/core/appender test/java/ch/qos/logback/core/util
by noreply.ceki＠qos.ch 08 Oct '08

08 Oct '08

Author: ceki Date: Wed Oct 8 22:38:22 2008 New Revision: 1826 Added: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/FileUtil.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/FileUtilTest.java Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/FileAppenderTest.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/PackageTest.java Log: LBCORE-42 FileAppender will now automatically create parent directories as needed. Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/FileAppender.java Wed Oct 8 22:38:22 2008 @@ -10,11 +10,13 @@ package ch.qos.logback.core; import java.io.BufferedWriter; +import java.io.File; import java.io.FileOutputStream; import java.io.IOException; import ch.qos.logback.core.status.ErrorStatus; import ch.qos.logback.core.status.InfoStatus; +import ch.qos.logback.core.util.FileUtil; /** * FileAppender appends log events to a file. @@ -79,7 +81,7 @@ /** * If the value of File is not <code>null</code>, then - * {@link #setFile} is called with the values of File and Append + * {@link #openFile} is called with the values of File and Append * properties. */ public void start() { @@ -96,7 +98,7 @@ this)); } try { - setFile(); + openFile(); } catch (java.io.IOException e) { errors++; @@ -136,11 +138,18 @@ * @throws IOException * */ - public synchronized void setFile() throws IOException { + public synchronized void openFile() throws IOException { closeWriter(); + File file = new File(fileName); + if(FileUtil.mustCreateParentDirectories(file)) { + boolean result = FileUtil.createMissingParentDirectories(file); + if(!result) { + addError("Failed to create parent directories for ["+file.getAbsolutePath()+"]"); + } + } + this.writer = createWriter(new FileOutputStream(fileName, append)); - if (bufferedIO) { this.writer = new BufferedWriter(this.writer, bufferSize); } Added: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/FileUtil.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/util/FileUtil.java Wed Oct 8 22:38:22 2008 @@ -0,0 +1,36 @@ +/** + * Logback: the generic, reliable, fast and flexible logging framework. + * + * Copyright (C) 2000-2008, QOS.ch + * + * This library is free software, you can redistribute it and/or modify it under + * the terms of the GNU Lesser General Public License as published by the Free + * Software Foundation. + */ +package ch.qos.logback.core.util; + +import java.io.File; + +public class FileUtil { + + + public static boolean mustCreateParentDirectories(File file) { + File parent = file.getParentFile(); + if(parent != null && !parent.exists()) { + return true; + } else { + return false; + } + } + + public static boolean createMissingParentDirectories(File file) { + File parent = file.getParentFile(); + if(parent == null || parent.exists()) { + throw new IllegalStateException(file + " should not have a null parent"); + } + if(parent.exists()) { + throw new IllegalStateException(file + " should not have existing parent directory"); + } + return parent.mkdirs(); + } +} Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/FileAppenderTest.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/FileAppenderTest.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/appender/FileAppenderTest.java Wed Oct 8 22:38:22 2008 @@ -9,11 +9,16 @@ */ package ch.qos.logback.core.appender; +import java.io.File; +import java.util.Random; + import ch.qos.logback.core.AppenderBase; import ch.qos.logback.core.ContextBase; import ch.qos.logback.core.FileAppender; import ch.qos.logback.core.layout.DummyLayout; import ch.qos.logback.core.layout.NopLayout; +import ch.qos.logback.core.util.Constants; +import ch.qos.logback.core.util.FileUtil; public class FileAppenderTest extends AbstractAppenderTest { @@ -45,14 +50,43 @@ } public void test() { + String filename = Constants.OUTPUT_DIR_PREFIX+"temp.log"; + FileAppender<Object> appender = new FileAppender<Object>(); appender.setLayout(new DummyLayout<Object>()); appender.setAppend(false); - appender.setFile("temp.log"); + appender.setFile(filename); appender.setName("temp.log"); appender.setContext(new ContextBase()); appender.start(); appender.doAppend(new Object()); + appender.stop(); + + File file = new File(filename); + assertTrue(file.exists()); + assertTrue("failed to delete "+file.getAbsolutePath(), file.delete()); + } + + public void testCreateParentFolders() { + int diff = new Random().nextInt(100); + String filename = Constants.OUTPUT_DIR_PREFIX+"/fat"+diff+"/testing.txt"; + File file = new File(filename); + FileAppender<Object> appender = new FileAppender<Object>(); + appender.setLayout(new DummyLayout<Object>()); + appender.setAppend(false); + appender.setFile(filename); + appender.setName("testCreateParentFolders"); + appender.setContext(new ContextBase()); + appender.start(); + appender.doAppend(new Object()); + appender.stop(); + assertFalse(FileUtil.mustCreateParentDirectories(file)); + assertTrue(file.exists()); + + // cleanup + assertTrue("failed to delete "+file.getAbsolutePath(), file.delete()); + File parent = file.getParentFile(); + assertTrue("failed to delete "+parent.getAbsolutePath(), parent.delete()); } } Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/FileUtilTest.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/FileUtilTest.java Wed Oct 8 22:38:22 2008 @@ -0,0 +1,68 @@ +/** + * Logback: the generic, reliable, fast and flexible logging framework. + * + * Copyright (C) 2000-2008, QOS.ch + * + * This library is free software, you can redistribute it and/or modify it under + * the terms of the GNU Lesser General Public License as published by the Free + * Software Foundation. + */ +package ch.qos.logback.core.util; + + +import static org.junit.Assert.assertFalse; +import static org.junit.Assert.assertTrue; + +import java.io.File; +import java.util.ArrayList; +import java.util.List; +import java.util.Random; + +import org.junit.After; +import org.junit.Before; +import org.junit.Test; + +public class FileUtilTest { + + List<File> cleanupList = new ArrayList<File>(); + + @Before + public void setUp() throws Exception { + + } + + @After + public void tearDown() throws Exception { + for(File f: cleanupList) { + f.delete(); + } + } + + + @Test + public void smoke() { + int diff = new Random().nextInt(100); + File file = new File(Constants.OUTPUT_DIR_PREFIX+"/fu"+diff+"/testing.txt"); + // these will be deleted later + cleanupList.add(file); + cleanupList.add(file.getParentFile()); + + assertTrue(FileUtil.mustCreateParentDirectories(file)); + assertTrue(FileUtil.createMissingParentDirectories(file)); + assertFalse(FileUtil.mustCreateParentDirectories(file)); + } + + @Test + public void smokeII() { + int diff = new Random().nextInt(100); + File file = new File(Constants.OUTPUT_DIR_PREFIX+"/fu"+diff+"/bla/testing.txt"); + // these will be deleted later + cleanupList.add(file); + cleanupList.add(file.getParentFile()); + cleanupList.add(file.getParentFile().getParentFile()); + + assertTrue(FileUtil.mustCreateParentDirectories(file)); + assertTrue(FileUtil.createMissingParentDirectories(file)); + assertFalse(FileUtil.mustCreateParentDirectories(file)); + } +} Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/PackageTest.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/PackageTest.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/util/PackageTest.java Wed Oct 8 22:38:22 2008 @@ -9,6 +9,7 @@ */ package ch.qos.logback.core.util; +import junit.framework.JUnit4TestAdapter; import junit.framework.Test; import junit.framework.TestCase; import junit.framework.TestSuite; @@ -20,6 +21,7 @@ TestSuite suite = new TestSuite(); suite.addTestSuite(DurationTest.class); suite.addTestSuite(FileSizeTest.class); + suite.addTest(new JUnit4TestAdapter(FileUtilTest.class)); suite.addTestSuite(OptionHelperTest.class); suite.addTestSuite(StatusPrinterTest.class); suite.addTestSuite(TimeUtilTest.class);

1 0

[JIRA] Updated: (LBCORE-42) add option to FileAppender to auto-create parent directories
by Joel (JIRA) 08 Oct '08

08 Oct '08

[ http://jira.qos.ch/browse/LBCORE-42?page=com.atlassian.jira.plugin.system.i… ] Joel updated LBCORE-42: ----------------------- Attachment: FileAppender.java.patch Any missing parent directories have been automatically created for file appenders in log4j since version 1.2.12. I believe this should be logback's default behavior as well, rather than making it an optional behavior. This will make things more natural for users migrating from log4j. I have attached a patch that will attempt to create missing parent directories. The code is copied directly from log4j's FileAppender.setFile(). Feel free to include the patch directly in logback, or use it as the basis of a suggested solution. Since the code was copied from log4j, I'm not sure if there are licensing issues that would prevent using the code directly as is. > add option to FileAppender to auto-create parent directories > ------------------------------------------------------------ > > Key: LBCORE-42 > URL: http://jira.qos.ch/browse/LBCORE-42 > Project: logback-core > Issue Type: Bug > Components: Appender > Affects Versions: unspecified > Environment: Operating System: Linux > Platform: PC > Reporter: Bruno Navert > Assignee: Logback dev list > Attachments: FileAppender.java.patch > > > FileAppender should be able to automatically create parent directories as needed when writing the log file. > For instance, if configured with <File>/var/tmp/project_name/some_file.log</File>, and the new option set to true (suggest <CreateParentDirectories>true</CreateParentDirectories> maybe), then in FileAppender.setFile(), it should do > new File( fileName ).getParentFile().mkdirs() > workaround is to create the directory before initializing logback. Possible but far less than ideal, and rather complicated too -- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira

1 0

svn commit: r1825 - logback/trunk/logback-classic/src/main/java/org/slf4j/impl
by noreply.ceki＠qos.ch 07 Oct '08

07 Oct '08

Author: ceki Date: Wed Oct 8 00:30:57 2008 New Revision: 1825 Modified: logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java Log: - SLF4J need version information. Modified: logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java ============================================================================== --- logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java (original) +++ logback/trunk/logback-classic/src/main/java/org/slf4j/impl/StaticLoggerBinder.java Wed Oct 8 00:30:57 2008 @@ -46,6 +46,14 @@ * The unique instance of this class. */ public static final StaticLoggerBinder SINGLETON = new StaticLoggerBinder(); + + /** + * Version tag used to check compatibility. The value of this field is + * modified with each release. + */ + //to avoid constant folding by the compiler, VERSION field should *not* be final + public static String VERSION = "1.5.4-SNAPSHOT"; + private static final String loggerFactoryClassStr = ContextSelector.class .getName();

1 0

svn commit: r1820 - in logback/trunk: logback-core/src/main/java/ch/qos/logback/core/rolling logback-core/src/main/java/ch/qos/logback/core/rolling/helper logback-core/src/test/java/ch/qos/logback/core/rolling logback-core/src/test/java/ch/qos/logback/core/rolling/helper logback-site/src/site/pages/manual
by noreply.ceki＠qos.ch 07 Oct '08

07 Oct '08

Author: ceki Date: Tue Oct 7 15:23:33 2008 New Revision: 1820 Added: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedCleaner.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/TimeBasedRollingWithCleanTest.java Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedRollingPolicy.java logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java logback/trunk/logback-site/src/site/pages/manual/appenders.html Log: Fixing LBCORE-11 - Allow TimeBasedRollingPolicy to delete old files if asked by the user. - PeriodicityType are now listed in an enum. Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedRollingPolicy.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedRollingPolicy.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/TimeBasedRollingPolicy.java Tue Oct 7 15:23:33 2008 @@ -13,6 +13,8 @@ import java.util.Date; import java.util.concurrent.Future; +import sun.misc.Cleaner; + import ch.qos.logback.core.rolling.helper.AsynchronousCompressor; import ch.qos.logback.core.rolling.helper.Compressor; import ch.qos.logback.core.rolling.helper.CompressionMode; @@ -20,6 +22,7 @@ import ch.qos.logback.core.rolling.helper.FileNamePattern; import ch.qos.logback.core.rolling.helper.RenameUtil; import ch.qos.logback.core.rolling.helper.RollingCalendar; +import ch.qos.logback.core.rolling.helper.TimeBasedCleaner; /** * <code>TimeBasedRollingPolicy</code> is both easy to configure and quite @@ -48,6 +51,8 @@ String lastGeneratedFileName; Future<?> future; + TimeBasedCleaner tbCleaner; + public void setCurrentTime(long timeInMillis) { currentTime = timeInMillis; isTimeForced = true; @@ -109,8 +114,9 @@ // currentTime = System.currentTimeMillis(); lastCheck.setTime(getCurrentTime()); - nextCheck = rc.getNextCheckMillis(lastCheck); + nextCheck = rc.getNextTriggeringMillis(lastCheck); + tbCleaner = new TimeBasedCleaner(fileNamePattern, rc, 5); // Date nc = new Date(); // nc.setTime(nextCheck); } @@ -130,6 +136,8 @@ } } + tbCleaner.clean(new Date(getCurrentTime())); + // let's update the parent active file name setParentFileName(getNewActiveFileName()); @@ -172,13 +180,13 @@ * file equals the file name for the current period as computed by the * FileNamePattern option. * - * The RollingPolicy must know wether it is responsible for changing the name + * The RollingPolicy must know wether it is responsible for changing the name * of the active file or not. If the active file name is set by the user via * the configuration file, then the RollingPolicy must let it like it is. If * the user does not specify an active file name, then the RollingPolicy * generates one. * - * To be sure that the file name used by the parent class has been generated + * To be sure that the file name used by the parent class has been generated * by the RollingPolicy and not specified by the user, we keep track of the * last generated name object and compare its reference to the parent file * name. If they match, then the RollingPolicy knows it's responsible for the @@ -210,7 +218,7 @@ // addInfo("elapsedPeriodsFileName set to "+elapsedPeriodsFileName); lastCheck.setTime(time); - nextCheck = rc.getNextCheckMillis(lastCheck); + nextCheck = rc.getNextTriggeringMillis(lastCheck); Date x = new Date(); x.setTime(nextCheck); Added: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/PeriodicityType.java Tue Oct 7 15:23:33 2008 @@ -0,0 +1,16 @@ +package ch.qos.logback.core.rolling.helper; + +public enum PeriodicityType { + + ERRONEOUS, TOP_OF_SECOND, TOP_OF_MINUTE, TOP_OF_HOUR, HALF_DAY, TOP_OF_DAY, TOP_OF_WEEK, TOP_OF_MONTH; + + // The followed list is assued to be in + static PeriodicityType[] VALID_ORDERED_LIST = new PeriodicityType[] { + PeriodicityType.TOP_OF_SECOND, + PeriodicityType.TOP_OF_MINUTE, + PeriodicityType.TOP_OF_HOUR, + PeriodicityType.TOP_OF_DAY, + PeriodicityType.TOP_OF_WEEK, + PeriodicityType.TOP_OF_MONTH }; + +} Modified: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java ============================================================================== --- logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java (original) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/RollingCalendar.java Tue Oct 7 15:23:33 2008 @@ -19,36 +19,23 @@ import ch.qos.logback.core.spi.ContextAwareBase; - - /** - * RollingCalendar is a helper class to - * {@link ch.qos.logback.core.rolling.TimeBasedRollingPolicy } - * or similar timed-based rolling policies. Given a periodicity type and the - * current time, it computes the start of the next interval. - * + * RollingCalendar is a helper class to + * {@link ch.qos.logback.core.rolling.TimeBasedRollingPolicy } or similar + * timed-based rolling policies. Given a periodicity type and the current time, + * it computes the start of the next interval (i.e. the triggering date). + * * @author Ceki Gülcü - * - * */ + * + */ public class RollingCalendar extends GregorianCalendar { private static final long serialVersionUID = -5937537740925066161L; - // The gmtTimeZone is used only in computeCheckPeriod() method. static final TimeZone GMT_TIMEZONE = TimeZone.getTimeZone("GMT"); - // The code assumes that the following constants are in a increasing - // sequence. - public static final int TOP_OF_TROUBLE = -1; - public static final int TOP_OF_SECOND = 0; - public static final int TOP_OF_MINUTE = 1; - public static final int TOP_OF_HOUR = 2; - public static final int HALF_DAY = 3; - public static final int TOP_OF_DAY = 4; - public static final int TOP_OF_WEEK = 5; - public static final int TOP_OF_MONTH = 6; - int type = TOP_OF_TROUBLE; + PeriodicityType type = PeriodicityType.ERRONEOUS; public RollingCalendar() { super(); @@ -59,15 +46,15 @@ } public void init(String datePattern) { - type = computeTriggeringPeriod(datePattern); + type = computePeriodicity(datePattern); } - private void setType(int type) { + private void setType(PeriodicityType type) { this.type = type; } - public long getNextCheckMillis(Date now) { - return getNextCheckDate(now).getTime(); + public long getNextTriggeringMillis(Date now) { + return getNextTriggeringDate(now).getTime(); } // This method computes the roll over period by looping over the @@ -78,32 +65,32 @@ // formatting is done in GMT and not local format because the test // logic is based on comparisons relative to 1970-01-01 00:00:00 // GMT (the epoch). - public int computeTriggeringPeriod(String datePattern) { - RollingCalendar rollingCalendar = - new RollingCalendar(GMT_TIMEZONE, Locale.getDefault()); + public PeriodicityType computePeriodicity(String datePattern) { + RollingCalendar rollingCalendar = new RollingCalendar(GMT_TIMEZONE, Locale + .getDefault()); // set sate to 1970-01-01 00:00:00 GMT Date epoch = new Date(0); if (datePattern != null) { - for (int i = TOP_OF_SECOND; i <= TOP_OF_MONTH; i++) { + for (PeriodicityType i : PeriodicityType.VALID_ORDERED_LIST) { SimpleDateFormat simpleDateFormat = new SimpleDateFormat(datePattern); - simpleDateFormat.setTimeZone(GMT_TIMEZONE); // do all date formatting in GMT + simpleDateFormat.setTimeZone(GMT_TIMEZONE); // all date formatting done in GMT String r0 = simpleDateFormat.format(epoch); rollingCalendar.setType(i); - Date next = new Date(rollingCalendar.getNextCheckMillis(epoch)); + Date next = new Date(rollingCalendar.getNextTriggeringMillis(epoch)); String r1 = simpleDateFormat.format(next); - //System.out.println("Type = "+i+", r0 = "+r0+", r1 = "+r1); + // System.out.println("Type = "+i+", r0 = "+r0+", r1 = "+r1); if ((r0 != null) && (r1 != null) && !r0.equals(r1)) { return i; } } } - - return TOP_OF_TROUBLE; // Deliberately head for trouble... + // we failed + return PeriodicityType.ERRONEOUS; } public void printPeriodicity(ContextAwareBase cab) { @@ -148,20 +135,20 @@ } } - public Date getNextCheckDate(Date now) { + public Date getRelativeDate(Date now, int periods) { this.setTime(now); switch (type) { case TOP_OF_SECOND: this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.SECOND, 1); + this.add(Calendar.SECOND, periods); break; case TOP_OF_MINUTE: this.set(Calendar.SECOND, 0); this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.MINUTE, 1); + this.add(Calendar.MINUTE, periods); break; @@ -169,23 +156,7 @@ this.set(Calendar.MINUTE, 0); this.set(Calendar.SECOND, 0); this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.HOUR_OF_DAY, 1); - - break; - - case HALF_DAY: - this.set(Calendar.MINUTE, 0); - this.set(Calendar.SECOND, 0); - this.set(Calendar.MILLISECOND, 0); - - int hour = get(Calendar.HOUR_OF_DAY); - - if (hour < 12) { - this.set(Calendar.HOUR_OF_DAY, 12); - } else { - this.set(Calendar.HOUR_OF_DAY, 0); - this.add(Calendar.DAY_OF_MONTH, 1); - } + this.add(Calendar.HOUR_OF_DAY, periods); break; @@ -194,7 +165,7 @@ this.set(Calendar.MINUTE, 0); this.set(Calendar.SECOND, 0); this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.DATE, 1); + this.add(Calendar.DATE, periods); break; @@ -204,7 +175,7 @@ this.set(Calendar.MINUTE, 0); this.set(Calendar.SECOND, 0); this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.WEEK_OF_YEAR, 1); + this.add(Calendar.WEEK_OF_YEAR, periods); break; @@ -214,7 +185,7 @@ this.set(Calendar.MINUTE, 0); this.set(Calendar.SECOND, 0); this.set(Calendar.MILLISECOND, 0); - this.add(Calendar.MONTH, 1); + this.add(Calendar.MONTH, periods); break; @@ -224,4 +195,8 @@ return getTime(); } + + public Date getNextTriggeringDate(Date now) { + return getRelativeDate(now, 1); + } } Added: logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedCleaner.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/main/java/ch/qos/logback/core/rolling/helper/TimeBasedCleaner.java Tue Oct 7 15:23:33 2008 @@ -0,0 +1,32 @@ +package ch.qos.logback.core.rolling.helper; + +import java.io.File; +import java.util.Date; + +public class TimeBasedCleaner { + + FileNamePattern fileNamePattern; + RollingCalendar rc; + int numberOfPeriods; + + public TimeBasedCleaner(FileNamePattern fileNamePattern, RollingCalendar rc, + int numberOfPeriods) { + this.fileNamePattern = fileNamePattern; + this.rc = rc; + // + this.numberOfPeriods = -numberOfPeriods -1; + } + + public void clean(Date now) { + Date date2delete = rc.getRelativeDate(now, numberOfPeriods); + + String filename = fileNamePattern.convertDate(date2delete); + + File file2Delete = new File(filename); + + if (file2Delete.exists() && file2Delete.isFile()) { + file2Delete.delete(); + } + } + +} Added: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/TimeBasedRollingWithCleanTest.java ============================================================================== --- (empty file) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/TimeBasedRollingWithCleanTest.java Tue Oct 7 15:23:33 2008 @@ -0,0 +1,61 @@ +package ch.qos.logback.core.rolling; + + + + +import org.junit.After; +import org.junit.Before; +import org.junit.Test; + +import ch.qos.logback.core.Context; +import ch.qos.logback.core.ContextBase; +import ch.qos.logback.core.layout.EchoLayout; +import ch.qos.logback.core.util.Constants; + +public class TimeBasedRollingWithCleanTest { + + Context context = new ContextBase(); + EchoLayout<Object> layout = new EchoLayout<Object>(); + + static final String DATE_PATTERN = "yyyy-MM-dd_HH_mm_ss"; + + @Before + public void setUp() throws Exception { + context.setName("test"); + } + + @After + public void tearDown() throws Exception { + } + + + @Test + public void smoke() { + long currentTime = System.currentTimeMillis(); + + RollingFileAppender<Object> rfa = new RollingFileAppender<Object>(); + rfa.setContext(context); + rfa.setLayout(layout); + rfa.setFile(Constants.OUTPUT_DIR_PREFIX + "clean.txt"); + TimeBasedRollingPolicy tbrp = new TimeBasedRollingPolicy(); + tbrp.setContext(context); + tbrp.setFileNamePattern(Constants.OUTPUT_DIR_PREFIX + "clean-%d{" + + DATE_PATTERN + "}.txt"); + tbrp.setParent(rfa); + tbrp.setCurrentTime(currentTime); + tbrp.start(); + rfa.setRollingPolicy(tbrp); + rfa.start(); + + for (int i = 0; i < 10; i++) { + rfa.doAppend("Hello---" + i); + tbrp.setCurrentTime(addTime(tbrp.getCurrentTime(), 500)); + } + + } + + static long addTime(long currentTime, long timeToWait) { + return currentTime + timeToWait; + } + +} Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/rolling/helper/RollingCalendarTest.java Tue Oct 7 15:23:33 2008 @@ -9,7 +9,8 @@ */ package ch.qos.logback.core.rolling.helper; -import ch.qos.logback.core.rolling.helper.RollingCalendar; +import java.util.Date; + import junit.framework.TestCase; public class RollingCalendarTest extends TestCase { @@ -26,37 +27,65 @@ super.tearDown(); } - public void test() { + public void testPeriodicity() { { RollingCalendar rc = new RollingCalendar(); - assertEquals(RollingCalendar.TOP_OF_SECOND, rc - .computeTriggeringPeriod("yyyy-MM-dd_HH_mm_ss")); + assertEquals(PeriodicityType.TOP_OF_SECOND, rc + .computePeriodicity("yyyy-MM-dd_HH_mm_ss")); } { RollingCalendar rc = new RollingCalendar(); - assertEquals(RollingCalendar.TOP_OF_MINUTE, rc - .computeTriggeringPeriod("yyyy-MM-dd_HH_mm")); + assertEquals(PeriodicityType.TOP_OF_MINUTE, rc + .computePeriodicity("yyyy-MM-dd_HH_mm")); } - + { RollingCalendar rc = new RollingCalendar(); - assertEquals(RollingCalendar.TOP_OF_HOUR, rc - .computeTriggeringPeriod("yyyy-MM-dd_HH")); + assertEquals(PeriodicityType.TOP_OF_HOUR, rc + .computePeriodicity("yyyy-MM-dd_HH")); } - + { RollingCalendar rc = new RollingCalendar(); - assertEquals(RollingCalendar.TOP_OF_DAY, rc - .computeTriggeringPeriod("yyyy-MM-dd")); + assertEquals(PeriodicityType.TOP_OF_DAY, rc + .computePeriodicity("yyyy-MM-dd")); } - + { RollingCalendar rc = new RollingCalendar(); - assertEquals(RollingCalendar.TOP_OF_MONTH, rc - .computeTriggeringPeriod("yyyy-MM")); + assertEquals(PeriodicityType.TOP_OF_MONTH, rc + .computePeriodicity("yyyy-MM")); } - } + public void testVaryingNumberOfHourlyPeriods() { + RollingCalendar rc = new RollingCalendar(); + rc.init("yyyy-MM-dd_HH"); + long MILLIS_IN_HOUR = 3600*1000; + + for (int p = 100; p > -100; p--) { + long now = 1223325293589L; // Mon Oct 06 22:34:53 CEST 2008 + Date result = rc.getRelativeDate(new Date(now), p); + long expected = now - (now % (MILLIS_IN_HOUR)) + p * MILLIS_IN_HOUR; + assertEquals(expected, result.getTime()); + } + } + + public void testVaryingNumberOfDailyPeriods() { + RollingCalendar rc = new RollingCalendar(); + rc.init("yyyy-MM-dd"); + final long MILLIS_IN_DAY = 24*3600*1000; + + for (int p = 20; p > -100; p--) { + long now = 1223325293589L; // Mon Oct 06 22:34:53 CEST 2008 + Date nowDate = new Date(now); + Date result = rc.getRelativeDate(nowDate, p); + long offset = rc.getTimeZone().getRawOffset()+rc.getTimeZone().getDSTSavings(); + + long origin = now - (now % (MILLIS_IN_DAY)) - offset; + long expected = origin + p * MILLIS_IN_DAY; + assertEquals("p="+p, expected, result.getTime()); + } + } } Modified: logback/trunk/logback-site/src/site/pages/manual/appenders.html ============================================================================== --- logback/trunk/logback-site/src/site/pages/manual/appenders.html (original) +++ logback/trunk/logback-site/src/site/pages/manual/appenders.html Tue Oct 7 15:23:33 2008 @@ -925,21 +925,9 @@ /wombat/foo.2006-24.log until it is rolled over at the beginning of the next week. </td> - </tr> + </tr> <tr class="a"> <td class="small"> - /wombat/foo.    / %d{yyyy-MM-dd-a}.log - </td> - <td>Rollover at midnight and midday of each day.</td> - - <td>During the first 12 hours of November 3rd, 2006, the logging - will be output to /wombat/foo.2006-11-03-AM.log. After - noon, and until midnight, the logging will be output to - /wombat/foo.2006-11-03-PM.log. - </td> - </tr> - <tr class="b"> - <td class="small"> /wombat/foo.   / %d{yyyy-MM-dd_HH}.log </td> <td>Rollover at the top of each hour.</td> @@ -950,7 +938,7 @@ /wombat/foo.2006-11-03_12.log. </td> </tr> - <tr class="a"> + <tr class="b"> <td class="small"> /wombat/foo.    / %d{yyyy-MM-dd_HH-mm}.log </td>

3 3

95 outstanding bugs
by Ceki Gulcu 07 Oct '08

07 Oct '08

Hello all, I will be spending the next few days reducing the number of outstanding bugs from 95 to a lower more manageable number. In general, important changes are always listed under "news.html". I will also send summaries on this mailing lists from time to time. Cheers, -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

1 0