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

[JIRA] Created: (LBCLASSIC-300) Add ability to manually specify configuration BEFORE autoconfiguration
by Phil (JIRA) 18 Nov '11

18 Nov '11

Add ability to manually specify configuration BEFORE autoconfiguration ---------------------------------------------------------------------- Key: LBCLASSIC-300 URL: http://jira.qos.ch/browse/LBCLASSIC-300 Project: logback-classic Issue Type: Improvement Affects Versions: 0.9.29 Reporter: Phil Assignee: Logback dev list Priority: Minor In order to make logback initialization faster, I would like the ability to programmatically configure logback and avoid the logic that happens in ContextInitializer.autoConfig(). Specifically, refer to this stack that occurs when getILoggerFactory() is initially called... ch.qos.logback.classic.util.ContextInitializer.autoConfig() line: 147 org.slf4j.impl.StaticLoggerBinder.init() line: 85 org.slf4j.impl.StaticLoggerBinder.<clinit>() line: 55 org.slf4j.LoggerFactory.bind() line: 121 org.slf4j.LoggerFactory.performInitialization() line: 111 org.slf4j.LoggerFactory.getILoggerFactory() line: 268 Now, for some background... I am using logback for a fast executing CLI program. Right now, initializing logback dominates the execution time of my CLIs. For example... When I started with logback, I was using logback.xml. If one of my CLIs took 1.5 seconds to run, I would see that initializing logback was taking 1 of those seconds (I used the yourkit profiler to identify this). 66% of the execution time is unacceptable. So, I switched from using logback.xml to programatically configuring logback in Java with the following code.. {code} LoggerContext loggingContext = (LoggerContext) LoggerFactory.getILoggerFactory(); loggingContext.reset(); ... FileAppender<ILoggingEvent> fileAppender = new FileAppender<ILoggingEvent>(); ... Logger rootLogger = loggingContext.getLogger(Logger.ROOT_LOGGER_NAME); rootLogger.addAppender(fileAppender); {code} This reduced the initialization time quite a bit. Now logback initialization is taking about .3 seconds. This is much better. However, I still think this can be improved by completely skipping the auto config logic. The initial call to LoggerFactory.getILoggerFactory() will attempt to auto configure logback.... which searches for groovy files, xml files, and falls back to BasicConfigurator. I don't need this auto configuration logic, since I am just going reset it and configure it myself anyway. I would like the ability to programmatically configure logback and totally avoid this auto configuration. Ideally I would be able to construct a LoggerContext instance, or the root Logger, or something. Then allow slf4j to bind to it without going through the auto config steps. -- 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

2 7

[JIRA] Created: (LBCLASSIC-261) MongoDB appender
by Tomasz Nurkiewicz (JIRA) 15 Nov '11

15 Nov '11

MongoDB appender ---------------- Key: LBCLASSIC-261 URL: http://jira.qos.ch/browse/LBCLASSIC-261 Project: logback-classic Issue Type: New Feature Components: appender Affects Versions: 0.9.28 Reporter: Tomasz Nurkiewicz Assignee: Logback dev list An appender similar to DbAppender, but storing logs in MongoDB document-oriented database. Should be capable of storing both classic and access logs. MongoDB seems especially well suited for this task since it is schema-less and very fast. Prototype implementation + integration tests (MongoDB instance running required) can be found here: https://github.com/nurkiewicz/logback/tree/mongodb-appender. -- 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

2 1

[JIRA] Created: (LBCORE-226) TimeBasedRollingPolicy does not trigger at application startup - MaxHistory not working
by Bruce E. Irving (JIRA) 08 Nov '11

08 Nov '11

TimeBasedRollingPolicy does not trigger at application startup - MaxHistory not working --------------------------------------------------------------------------------------- Key: LBCORE-226 URL: http://jira.qos.ch/browse/LBCORE-226 Project: logback-core Issue Type: Bug Components: Rolling Affects Versions: 0.9.30 Environment: Windows XP, Java 1.6.0_27 Reporter: Bruce E. Irving Assignee: Logback dev list I am using the RollingFileAppender with TimeBasedRolliingPolicy. The application is a desktop utility that may be run several times per day but is almost never running at midnight when the roll would normally occur. The log file naming is working correctly - each day's file is date stamped, but the MaxHistory is not working at all since it is not enforced at app startup. Pertinent config section: <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender"> <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"> <fileNamePattern>MyApp_%d.log</fileNamePattern>  <maxHistory>7</maxHistory>  </rollingPolicy> <encoder> <pattern>%date %-5level [%thread] %logger{10} %msg%n</pattern> </encoder> </appender> I found what I believe is the source of the issue in TimeBasedFileNamingAndTriggeringPolicyBase: public void start() { ... setDateInCurrentPeriod(new Date(getCurrentTime())); if (tbrp.getParentsRawFileProperty() != null) { File currentFile = new File(tbrp.getParentsRawFileProperty()); if (currentFile.exists() && currentFile.canRead()) { setDateInCurrentPeriod(new Date(currentFile.lastModified())); } } addInfo("Setting initial period to " + dateInCurrentPeriod); computeNextCheck(); } Since there is no parentsRawFileProperty, this uses the current time and sets the next check at midnight tonight. Therefore the check is not run at startup, and in my case is never run. This would work fine if dateInCurrentPeriod was set to anything before today. I would suggest the following change: public void start() { ... File currentFile = new File(tbrp.getActiveFileName()); // Use same logic if ParentsRawFileProperty is set or not. if (currentFile.exists() && currentFile.canRead()) { setDateInCurrentPeriod(new Date(currentFile.lastModified())); } else { setDateInCurrentPeriod(0); // No current file found, force a triggering event // or if the above is too brute-force: setDateInCurrentPeriod(rc.getRelativeDate(new Date(), -1)); } addInfo("Setting initial period to " + dateInCurrentPeriod); computeNextCheck(); } Note - this was originally reported as a comment on LBCORE-147; moved here to be tracked as a separate issue. Thanks, -Bruce -- 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

2 2

[JIRA] Created: (LBCORE-230) System Properties should override properties in logback.xml (not the other way around)
by Eric Sirianni (JIRA) 02 Nov '11

02 Nov '11

System Properties should override properties in logback.xml (not the other way around) -------------------------------------------------------------------------------------- Key: LBCORE-230 URL: http://jira.qos.ch/browse/LBCORE-230 Project: logback-core Issue Type: Improvement Affects Versions: 0.9.29 Reporter: Eric Sirianni Assignee: Logback dev list Priority: Minor >From the logback configuration guide (http://logback.qos.ch/manual/configuration.html) "The property is not declared in the configuration file, thus logback will look for it in the System properties. Java system properties can be set on the command line. " I believe the precedence should be reversed. Typically, system properties are used to *override* default values of properties that are specified in XML files or property files (typically checked into source control). Please consider this enhancement. For backwards compatibility you may want to add an option to toggle the precedence ordering. -- 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

2 4

[JIRA] Created: (LBACCESS-26) Can't set RequestLogImpl to use a logback-access.xml file via a classpath path
by Marshall Pierce (JIRA) 01 Nov '11

01 Nov '11

Can't set RequestLogImpl to use a logback-access.xml file via a classpath path ------------------------------------------------------------------------------ Key: LBACCESS-26 URL: http://jira.qos.ch/browse/LBACCESS-26 Project: logback-access Issue Type: Bug Affects Versions: 0.9.28 Reporter: Marshall Pierce Assignee: Logback dev list (Affects 0.9.30, the latest version at the moment) ch.qos.logback.access.jetty.v7.RequestLogImpl has setFileName, the result of which is then handed to File's constructor. This is fine when you're deploying inside a standalone jetty that has the jetty.home property set to a filesystem path, but when you're using embedded jetty, you don't have any of that. Instead I'd like to be able to have it find "/logback-access.xml" in the classpath just the way logback classic does with "/logback.xml". I'm happy to implement the patch; just let me know how you'd like it to be done. One way would be to provide a setter on RLImpl that takes a URL which, if specified, takes precedence over the filename. As a workaround I'm creating a JoranConfigurator and using its doConfigure(URL) method on a URL loaded from the classpath. This works, but it'd be nice to not have to do that. -- 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

2 7

birthTime of the context
by ceki 01 Nov '11

01 Nov '11

Hi Joern, > Could you reset the birthTime of the Context as I requested in > LBCLASSIC-273? Please? :) The birth time of the context designates the start time of the application (assuming logback was started at application launch). I don't think it makes sense to reset the birth time when the context is reset. For example, relative time would go backwards if birth time was reset which users may find confusing. -- Ceki http://twitter.com/#!/ceki

2 5

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_0.9.30-65-ga7323fa
by git-noreply＠pixie.qos.ch 31 Oct '11

31 Oct '11

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via a7323fa988ff2b26229ad3f4bef10968238ff991 (commit) from f28496ad3e5c631876c5e777c1bb54df88969476 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=a7323fa988ff2b26229ad3f4… http://github.com/ceki/logback/commit/a7323fa988ff2b26229ad3f4bef10968238ff… commit a7323fa988ff2b26229ad3f4bef10968238ff991 Author: Ceki Gulcu <ceki(a)qos.ch> Date: Tue Nov 1 00:07:32 2011 +0100 upgrade to slf4j 1.6.4, sync wagon-ssh version with that expected by site-plugin diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/util/LogbackMDCAdapter.java b/logback-classic/src/main/java/ch/qos/logback/classic/util/LogbackMDCAdapter.java index b045016..c41673c 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/util/LogbackMDCAdapter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/util/LogbackMDCAdapter.java @@ -103,8 +103,6 @@ public final class LogbackMDCAdapter implements MDCAdapter { } Map<String, String> oldMap = copyOnInheritThreadLocal.get(); - //System.out.println(Thread.currentThread().toString()+", "+oldMap); - Integer lastOp = getAndSetLastOperation(WRITE_OPERATION); if (wasLastOpReadOrNull(lastOp) || oldMap == null) { diff --git a/pom.xml b/pom.xml index 8565a3b..bb62aa1 100755 --- a/pom.xml +++ b/pom.xml @@ -31,7 +31,7 @@ <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>  - <slf4j.version>1.6.3</slf4j.version> + <slf4j.version>1.6.4</slf4j.version> <junit.version>4.8.2</junit.version> <janino.version>2.5.10</janino.version> <scala.version>2.9.1</scala.version> @@ -176,7 +176,7 @@ <extension> <groupId>org.apache.maven.wagon</groupId> <artifactId>wagon-ssh</artifactId> - <version>1.0-beta-1</version> + <version>2.0</version> </extension> </extensions> ----------------------------------------------------------------------- Summary of changes: .../logback/classic/util/LogbackMDCAdapter.java | 2 -- pom.xml | 4 ++-- 2 files changed, 2 insertions(+), 4 deletions(-) hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

Build seems to be fixed.
by Joern Huxhorn 31 Oct '11

31 Oct '11

Hi Ceki, just wanted to let you know that it appears like you really fixed the build/tests now. No random build failures on our systems anymore, thumbs up. Cheers, Joern.

2 5

[GIT] Logback: the generic, reliable, fast and flexible logging framework. branch master updated. v_0.9.30-64-gf28496a
by git-noreply＠pixie.qos.ch 31 Oct '11

31 Oct '11

This is an automated email from the git hooks/post-receive script. It was generated because a ref change was pushed to the repository containing the project "Logback: the generic, reliable, fast and flexible logging framework.". The branch, master has been updated via f28496ad3e5c631876c5e777c1bb54df88969476 (commit) from 1b3439a5868d50b8423f675e15dc8db9a35b7102 (commit) Those revisions listed above that are new to this repository have not appeared on any other notification email; so we list those revisions in full, below. - Log ----------------------------------------------------------------- http://git.qos.ch/gitweb/?p=logback.git;a=commit;h=f28496ad3e5c631876c5e777… http://github.com/ceki/logback/commit/f28496ad3e5c631876c5e777c1bb54df88969… commit f28496ad3e5c631876c5e777c1bb54df88969476 Author: Ceki Gulcu <ceki(a)qos.ch> Date: Mon Oct 31 21:41:19 2011 +0100 added timeOfLastReset method to StatusChecker diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java index 19f8aa1..9d78f8e 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeFilter.java @@ -19,6 +19,7 @@ import java.util.List; import ch.qos.logback.classic.gaffer.GafferUtil; import ch.qos.logback.classic.util.EnvUtil; +import ch.qos.logback.core.CoreConstants; import ch.qos.logback.core.joran.event.SaxEvent; import ch.qos.logback.core.joran.spi.ConfigurationWatchList; import ch.qos.logback.core.joran.util.ConfigurationWatchListUtil; @@ -39,9 +40,6 @@ import ch.qos.logback.core.spi.FilterReply; */ public class ReconfigureOnChangeFilter extends TurboFilter { - final static long INIT = System.currentTimeMillis(); - final static long SENTINEL = Long.MAX_VALUE; - /** * Scan for changes in configuration file once every minute. */ @@ -153,7 +151,7 @@ public class ReconfigureOnChangeFilter extends TurboFilter { return; } LoggerContext lc = (LoggerContext) context; - addInfo("Will reset and reconfigure context named [" + context.getName() + "]"); + addInfo(CoreConstants.RESET_MSG_PREFIX + "named ["+context.getName() + "]"); if (mainConfigurationURL.toString().endsWith("xml")) { performXMLConfiguration(lc); } else if (mainConfigurationURL.toString().endsWith("groovy")) { diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java b/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java index b4c1e74..22db069 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/joran/JoranConfiguratorTest.java @@ -19,6 +19,7 @@ import java.util.concurrent.TimeUnit; import java.util.logging.LogManager; import ch.qos.logback.classic.jul.JULHelper; +import ch.qos.logback.classic.turbo.ReconfigureOnChangeFilter; import ch.qos.logback.core.pattern.parser.Parser; import ch.qos.logback.core.pattern.parser.ScanException; import ch.qos.logback.core.status.Status; @@ -308,7 +309,7 @@ public class JoranConfiguratorTest { //StatusPrinter.print(loggerContext); StatusChecker checker = new StatusChecker(loggerContext); assertTrue(checker.isErrorFree(0)); - assertTrue(checker.containsMatch("Will reset and reconfigure context")); + assertTrue(checker.containsMatch(CoreConstants.RESET_MSG_PREFIX)); } @Test diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java index 3884672..d451b1b 100644 --- a/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java +++ b/logback-classic/src/test/java/ch/qos/logback/classic/turbo/ReconfigureOnChangeTest.java @@ -260,7 +260,7 @@ public class ReconfigureOnChangeTest { } int effectiveResets = checker - .matchCount("Will reset and reconfigure context"); + .matchCount(CoreConstants.RESET_MSG_PREFIX); String failMsg = "effective=" + effectiveResets + ", expected=" + expected; diff --git a/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java b/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java index fcb642f..55fb8e4 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java +++ b/logback-core/src/main/java/ch/qos/logback/core/CoreConstants.java @@ -82,7 +82,6 @@ public class CoreConstants { public static final char DOUBLE_QUOTE_CHAR = '"'; public static final char SINGLE_QUOTE_CHAR = '\''; - /** * Number of rows before in an HTML table before, * we close the table and create a new one @@ -140,4 +139,6 @@ public class CoreConstants { public static final int MILLIS_IN_ONE_WEEK = MILLIS_IN_ONE_DAY*7; public static final String CONTEXT_SCOPE_VALUE = "context"; + + final public static String RESET_MSG_PREFIX = "Will reset and reconfigure context "; } diff --git a/logback-core/src/main/java/ch/qos/logback/core/status/StatusChecker.java b/logback-core/src/main/java/ch/qos/logback/core/status/StatusChecker.java index d9e3d2c..ae61c74 100644 --- a/logback-core/src/main/java/ch/qos/logback/core/status/StatusChecker.java +++ b/logback-core/src/main/java/ch/qos/logback/core/status/StatusChecker.java @@ -116,4 +116,22 @@ public class StatusChecker { return false; } + /** + * Return the time of last reset. -1 if last reset time could not be found + * @return time of last reset or -1 + */ + public long timeOfLastReset() { + List<Status> statusList = sm.getCopyOfStatusList(); + if(statusList == null) + return -1; + + int len = statusList.size(); + for(int i = len-1; i >= 0; i--) { + Status s = statusList.get(i); + if(CoreConstants.RESET_MSG_PREFIX.equals(s.getMessage())) { + return s.getDate(); + } + } + return -1; + } } diff --git a/logback-core/src/test/java/ch/qos/logback/core/status/StatusCheckerTest.java b/logback-core/src/test/java/ch/qos/logback/core/status/StatusCheckerTest.java new file mode 100644 index 0000000..695edb2 --- /dev/null +++ b/logback-core/src/test/java/ch/qos/logback/core/status/StatusCheckerTest.java @@ -0,0 +1,40 @@ +package ch.qos.logback.core.status; + +import ch.qos.logback.core.Context; +import ch.qos.logback.core.ContextBase; +import ch.qos.logback.core.CoreConstants; +import org.junit.Test; + +import static junit.framework.Assert.assertEquals; +import static org.junit.Assert.assertTrue; + +/** + * @author Ceki Gücü + */ +public class StatusCheckerTest { + + Context context = new ContextBase(); + StatusChecker checker = new StatusChecker(context); + + @Test + public void emptyStatusListShouldResultInNotFound() { + assertEquals(-1, checker.timeOfLastReset()); + } + + @Test + public void withoutResetsCheckerShouldReturnNotFound() { + context.getStatusManager().add(new InfoStatus("test", this)); + assertEquals(-1, checker.timeOfLastReset()); + } + + @Test + public void statusListShouldReturnLastResetTime() { + context.getStatusManager().add(new InfoStatus("test", this)); + long resetTime = System.currentTimeMillis(); + context.getStatusManager().add(new InfoStatus(CoreConstants.RESET_MSG_PREFIX, this)); + context.getStatusManager().add(new InfoStatus("bla", this)); + assertTrue(resetTime <= checker.timeOfLastReset()); + } + + +} ----------------------------------------------------------------------- Summary of changes: .../classic/turbo/ReconfigureOnChangeFilter.java | 6 +-- .../classic/joran/JoranConfiguratorTest.java | 3 +- .../classic/turbo/ReconfigureOnChangeTest.java | 2 +- .../java/ch/qos/logback/core/CoreConstants.java | 3 +- .../ch/qos/logback/core/status/StatusChecker.java | 18 +++++++++ .../qos/logback/core/status/StatusCheckerTest.java | 40 ++++++++++++++++++++ 6 files changed, 65 insertions(+), 7 deletions(-) create mode 100644 logback-core/src/test/java/ch/qos/logback/core/status/StatusCheckerTest.java hooks/post-receive -- Logback: the generic, reliable, fast and flexible logging framework.

1 0

[JIRA] Created: (LBCORE-232) Add javadoc to ch.qos.logback.core.spi.LifeCycle
by Baptiste Mathus (JIRA) 31 Oct '11

31 Oct '11

Add javadoc to ch.qos.logback.core.spi.LifeCycle ------------------------------------------------ Key: LBCORE-232 URL: http://jira.qos.ch/browse/LBCORE-232 Project: logback-core Issue Type: Improvement Components: Appender Affects Versions: 0.9.14 Reporter: Baptiste Mathus Assignee: Logback dev list This central Appender class has no documentation for any of its method. It would be great to add some text describing under what circumstances/when it's supposed to be called. Currently, for example, I think I'm being bitten too by LBGENERAL-42 so I wonder what the exact Lifecycle.close() call context is. Seems like close is never called at JVM exit. This could be a possible use case, but I guess it would at least benefit a lot to have this context described in the contract of the interface, -- 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 1