[ http://jira.qos.ch/browse/LBCLASSIC-256?page=com.atlassian.jira.plugin.syste... ] Samuel Stanojevic updated LBCLASSIC-256: ---------------------------------------- Attachment: LevelChangePropagator.java I am attaching my patched version of LevelChangePropagator that has fixed the bug for me, if it helps.

java.util.logging propagated level changes are lost because of race condition with garbage collection -----------------------------------------------------------------------------------------------------

Key: LBCLASSIC-256 URL: http://jira.qos.ch/browse/LBCLASSIC-256 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Environment: win7 64-bit, bootstrapped in a Tomcat server Reporter: Samuel Stanojevic Assignee: Logback dev list Attachments: LevelChangePropagator.java

I have bootstrapped logback in my Tomcat server, and have setup JUL to redirect logging requests to SLF4J by adding the following in my logging.properties: .handlers = org.slf4j.bridge.SLF4JBridgeHandler Anyways, my setup works pretty nicely. The problem is when I try to activate the JUL LevelChangePropagator, the info doesn't quite propagate as expected. Here is my config: <configuration debug="true"> <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"> <resetJUL>true</resetJUL> </contextListener>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder by default --> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> <target>System.out</target> </appender> <root level="ERROR"> <appender-ref ref="STDOUT" /> </root>

<logger name="test.propagation" level="TRACE"/> <!-- race condition here? --> </configuration> The problem is that if my app tries to do: java.util.logging.Logger.getLogger("test.propagation").fine("hello world"); ..., it doesn't print. I have confirmed that the bug is because, even though the LevelChangePropagator class does propagate the level change info to JUL, it fails to keep a strong reference to the logger that it just changed. By not keeping a strong reference, and because the JUL LogManager only keeps WeakReferences to loggers, then the GC has time to clear out the change before the app's first attempt to use the logger. (see java.util.logging.LogManager#addLogger where the javadoc says "The application should retain its own reference to the Logger object to avoid it being garbage collected. The LogManager may only retain a weak reference") To test my hunch, I patched the LevelChangePropagator class by adding a global hashset of java.util.logging.Logger, and I systematically add the loggers to the hashset in the method "propagate(logger,level)". After this patch, my logging started working as expected. My fix may not be the best, and may have implications that I did not think about, but I think something along those lines needs to be done to fix the bug.

-- 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

[ http://jira.qos.ch/browse/LBCLASSIC-256?page=com.atlassian.jira.plugin.syste... ] Carlos Sierra commented on LBCLASSIC-256: ----------------------------------------- We have came across this issue too. What we have done to circumvent this problems is use the groovy configurator to attach the configured loggers to the LoggingContext. This way the logger does not get collected and you can use this with the current standard distribution. This is not a fix, but may be handy: Use function configure_logger in the configuration instead of using logger def resilient_loggers=[] context.putObject("resilient_loggers", resilient_loggers) resilient_loggers.add(java.util.logging.Logger.getLogger("")) root(WARN, ["CONSOLE"]) def configure_logger(logName, level, handlers=[], additivity=true) { resilient_loggers=context.getObject("resilient_loggers") resilient_loggers.add(java.util.logging.Logger.getLogger(logName)) logger(logName, level, handlers, additivity) } Don't know whether you can do this using XML configuration. I believe these objects will be unreferenced when the LoggerContext is stopped/started so garbage collector may clean them.

java.util.logging propagated level changes are lost because of race condition with garbage collection -----------------------------------------------------------------------------------------------------

Key: LBCLASSIC-256 URL: http://jira.qos.ch/browse/LBCLASSIC-256 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Environment: win7 64-bit, bootstrapped in a Tomcat server Reporter: Samuel Stanojevic Assignee: Ceki Gulcu Attachments: LevelChangePropagator.java

I have bootstrapped logback in my Tomcat server, and have setup JUL to redirect logging requests to SLF4J by adding the following in my logging.properties: .handlers = org.slf4j.bridge.SLF4JBridgeHandler Anyways, my setup works pretty nicely. The problem is when I try to activate the JUL LevelChangePropagator, the info doesn't quite propagate as expected. Here is my config: <configuration debug="true"> <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"> <resetJUL>true</resetJUL> </contextListener>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder by default --> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> <target>System.out</target> </appender> <root level="ERROR"> <appender-ref ref="STDOUT" /> </root>

<logger name="test.propagation" level="TRACE"/> <!-- race condition here? --> </configuration> The problem is that if my app tries to do: java.util.logging.Logger.getLogger("test.propagation").fine("hello world"); ..., it doesn't print. I have confirmed that the bug is because, even though the LevelChangePropagator class does propagate the level change info to JUL, it fails to keep a strong reference to the logger that it just changed. By not keeping a strong reference, and because the JUL LogManager only keeps WeakReferences to loggers, then the GC has time to clear out the change before the app's first attempt to use the logger. (see java.util.logging.LogManager#addLogger where the javadoc says "The application should retain its own reference to the Logger object to avoid it being garbage collected. The LogManager may only retain a weak reference") To test my hunch, I patched the LevelChangePropagator class by adding a global hashset of java.util.logging.Logger, and I systematically add the loggers to the hashset in the method "propagate(logger,level)". After this patch, my logging started working as expected. My fix may not be the best, and may have implications that I did not think about, but I think something along those lines needs to be done to fix the bug.

-- 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

[ http://jira.qos.ch/browse/LBCLASSIC-256?page=com.atlassian.jira.plugin.syste... ] Martin Maier commented on LBCLASSIC-256: ---------------------------------------- I have the same problem as described by Samuel. Would be great if this could be fixed at some point.

java.util.logging propagated level changes are lost because of race condition with garbage collection -----------------------------------------------------------------------------------------------------

Key: LBCLASSIC-256 URL: http://jira.qos.ch/browse/LBCLASSIC-256 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Environment: win7 64-bit, bootstrapped in a Tomcat server Reporter: Samuel Stanojevic Assignee: Ceki Gulcu Attachments: LevelChangePropagator.java

I have bootstrapped logback in my Tomcat server, and have setup JUL to redirect logging requests to SLF4J by adding the following in my logging.properties: .handlers = org.slf4j.bridge.SLF4JBridgeHandler Anyways, my setup works pretty nicely. The problem is when I try to activate the JUL LevelChangePropagator, the info doesn't quite propagate as expected. Here is my config: <configuration debug="true"> <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"> <resetJUL>true</resetJUL> </contextListener>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder by default --> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> <target>System.out</target> </appender> <root level="ERROR"> <appender-ref ref="STDOUT" /> </root>

<logger name="test.propagation" level="TRACE"/> <!-- race condition here? --> </configuration> The problem is that if my app tries to do: java.util.logging.Logger.getLogger("test.propagation").fine("hello world"); ..., it doesn't print. I have confirmed that the bug is because, even though the LevelChangePropagator class does propagate the level change info to JUL, it fails to keep a strong reference to the logger that it just changed. By not keeping a strong reference, and because the JUL LogManager only keeps WeakReferences to loggers, then the GC has time to clear out the change before the app's first attempt to use the logger. (see java.util.logging.LogManager#addLogger where the javadoc says "The application should retain its own reference to the Logger object to avoid it being garbage collected. The LogManager may only retain a weak reference") To test my hunch, I patched the LevelChangePropagator class by adding a global hashset of java.util.logging.Logger, and I systematically add the loggers to the hashset in the method "propagate(logger,level)". After this patch, my logging started working as expected. My fix may not be the best, and may have implications that I did not think about, but I think something along those lines needs to be done to fix the bug.

-- 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

[ http://jira.qos.ch/browse/LBCLASSIC-256?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu resolved LBCLASSIC-256. ---------------------------------- Fix Version/s: 1.0.3 Resolution: Fixed Fixed in http://github.com/ceki/logback/commit/0a2446b and https://github.com/ceki/logback/commit/d903644be4

java.util.logging propagated level changes are lost because of race condition with garbage collection -----------------------------------------------------------------------------------------------------

Key: LBCLASSIC-256 URL: http://jira.qos.ch/browse/LBCLASSIC-256 Project: logback-classic Issue Type: Bug Affects Versions: 0.9.28 Environment: win7 64-bit, bootstrapped in a Tomcat server Reporter: Samuel Stanojevic Assignee: Ceki Gulcu Fix For: 1.0.3

Attachments: LevelChangePropagator.java

I have bootstrapped logback in my Tomcat server, and have setup JUL to redirect logging requests to SLF4J by adding the following in my logging.properties: .handlers = org.slf4j.bridge.SLF4JBridgeHandler Anyways, my setup works pretty nicely. The problem is when I try to activate the JUL LevelChangePropagator, the info doesn't quite propagate as expected. Here is my config: <configuration debug="true"> <contextListener class="ch.qos.logback.classic.jul.LevelChangePropagator"> <resetJUL>true</resetJUL> </contextListener>

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- encoders are assigned the type ch.qos.logback.classic.encoder.PatternLayoutEncoder by default --> <encoder> <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern> </encoder> <target>System.out</target> </appender> <root level="ERROR"> <appender-ref ref="STDOUT" /> </root>

<logger name="test.propagation" level="TRACE"/> <!-- race condition here? --> </configuration> The problem is that if my app tries to do: java.util.logging.Logger.getLogger("test.propagation").fine("hello world"); ..., it doesn't print. I have confirmed that the bug is because, even though the LevelChangePropagator class does propagate the level change info to JUL, it fails to keep a strong reference to the logger that it just changed. By not keeping a strong reference, and because the JUL LogManager only keeps WeakReferences to loggers, then the GC has time to clear out the change before the app's first attempt to use the logger. (see java.util.logging.LogManager#addLogger where the javadoc says "The application should retain its own reference to the Logger object to avoid it being garbage collected. The LogManager may only retain a weak reference") To test my hunch, I patched the LevelChangePropagator class by adding a global hashset of java.util.logging.Logger, and I systematically add the loggers to the hashset in the method "propagate(logger,level)". After this patch, my logging started working as expected. My fix may not be the best, and may have implications that I did not think about, but I think something along those lines needs to be done to fix the bug.

-- 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