Re: [logback-user] Logging crossing contexts

Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on. -- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34307440.html Sent from the Logback User mailing list archive at Nabble.com.

We do almost the exact same thing Chris. I have verified that with only 0.9.24 in each app's lib folder, it still has this behavior. So with Chris' input, it looks like this problem is confirmed to happen in 0.9.24, 0.9.28, and 1.0.6 - On Thu, Aug 16, 2012 at 11:01 AM, Chris Rompot <crompot@gmail.com> wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on.
-- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34307440.html Sent from the Logback User mailing list archive at Nabble.com.
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user

On 16.08.2012 18:01, Chris Rompot wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on.
LoggerContext does not implement hashCode() nor equals(). What is the key used to retrieve values in the map? -- Ceki http://tinyurl.com/proLogback

We're using a String, the context name, as the Map's Key. private final Map<String, LoggerContext> synchronizedContextMap; this.synchronizedContextMap = Collections.synchronizedMap(new HashMap<String, LoggerContext>()); On Thu, Aug 16, 2012 at 11:20 AM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 18:01, Chris Rompot wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on.
LoggerContext does not implement hashCode() nor equals(). What is the key used to retrieve values in the map?
-- Ceki http://tinyurl.com/proLogback
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>

We are doing the same with a HashMap, except our key is an class (with appropriately implemented hashCode()) composed of two String attributes. Robert Voliva-2 wrote:
We're using a String, the context name, as the Map's Key.
private final Map<String, LoggerContext> synchronizedContextMap;
this.synchronizedContextMap = Collections.synchronizedMap(new HashMap<String, LoggerContext>());
On Thu, Aug 16, 2012 at 11:20 AM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 18:01, Chris Rompot wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on.
LoggerContext does not implement hashCode() nor equals(). What is the key used to retrieve values in the map?
-- Ceki http://tinyurl.com/proLogback
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
-- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34307989.html Sent from the Logback User mailing list archive at Nabble.com.

At this stage, I unit test reproducing the issue would be helpful. On 16.08.2012 19:21, Chris Rompot wrote:
We are doing the same with a HashMap, except our key is an class (with appropriately implemented hashCode()) composed of two String attributes.
Robert Voliva-2 wrote:
We're using a String, the context name, as the Map's Key.
private final Map<String, LoggerContext> synchronizedContextMap;
this.synchronizedContextMap = Collections.synchronizedMap(new HashMap<String, LoggerContext>());
On Thu, Aug 16, 2012 at 11:20 AM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 18:01, Chris Rompot wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on.
LoggerContext does not implement hashCode() nor equals(). What is the key used to retrieve values in the map?
-- Ceki http://tinyurl.com/proLogback
-- Ceki http://tinyurl.com/proLogback

I was easily able to solve my logging crossing contexts problem after creating a unit test and reading this Javadoc for org.slf4j.LoggerFactory: getILoggerFactory() - Return the ILoggerFactory instance in use. When I mimicked your "Invoking JoranConfigurator directly" example from "Chapter 3: Logback configuration" of your manual, I copied this line: LoggerContext context = (LoggerContext) LoggerFactory.getILoggerFactory(); and needed to replace it with: LoggerContext context = new LoggerContext(); Once I did so, problem solved. Thanks for the great and timely support, Chris Ceki Gulcu wrote:
At this stage, I unit test reproducing the issue would be helpful.
-- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34348171.html Sent from the Logback User mailing list archive at Nabble.com.

Chris - by any chance are the messages that are ending up in the wrong context's log coming from commons-logging API loggers? I seem to have narrowed down my issue to just statements logged through the jcl-over-slf4j dependency. It seems like straight slf4j Logger statements are logging to the correct log files. On Thu, Aug 16, 2012 at 12:21 PM, Chris Rompot <crompot@gmail.com> wrote:
We are doing the same with a HashMap, except our key is an class (with appropriately implemented hashCode()) composed of two String attributes.
Robert Voliva-2 wrote:
We're using a String, the context name, as the Map's Key.
private final Map<String, LoggerContext> synchronizedContextMap;
this.synchronizedContextMap = Collections.synchronizedMap(new HashMap<String, LoggerContext>());
On Thu, Aug 16, 2012 at 11:20 AM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 18:01, Chris Rompot wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a
newly
created context from 2012-08-15 15:48:28 on.
LoggerContext does not implement hashCode() nor equals(). What is the key used to retrieve values in the map?
-- Ceki http://tinyurl.com/proLogback
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user< http://mailman.qos.ch/mailman/listinfo/logback-user>
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
-- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34307989.html Sent from the Logback User mailing list archive at Nabble.com.
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user

On Thu, Aug 16, 2012 at 3:44 PM, Robert Voliva <rvoliva@gmail.com> wrote:
Chris - by any chance are the messages that are ending up in the wrong context's log coming from commons-logging API loggers? I seem to have narrowed down my issue to just statements logged through the jcl-over-slf4j dependency. It seems like straight slf4j Logger statements are logging to the correct log files.
We are in the process of narrowing down some bugs, but we have some that are using log4j-over-slf4j that after a context restart either stop logging or start logging to random logfiles that belong to other contexts, we are currently doing some testing to figure otu just exactly which component is to blame.
On Thu, Aug 16, 2012 at 12:21 PM, Chris Rompot <crompot@gmail.com> wrote:
We are doing the same with a HashMap, except our key is an class (with appropriately implemented hashCode()) composed of two String attributes.
Robert Voliva-2 wrote:
We're using a String, the context name, as the Map's Key.
private final Map<String, LoggerContext> synchronizedContextMap;
this.synchronizedContextMap = Collections.synchronizedMap(new HashMap<String, LoggerContext>());
On Thu, Aug 16, 2012 at 11:20 AM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 18:01, Chris Rompot wrote:
Ceki Gulcu wrote:
If my memory serves me correctly, the context selection code has not changed significantly since 0.9.28.
How do you perform context selection? Is it JNDI based? Again, what happens when you revert to logback 0.9.28?
-- Ceki http://tinyurl.com/proLogback
We recently noticed the same problem using logback-classic version 1.0.6. We store our LoggerContexts as values of a static HashMap. I have verified that the keys used to retrieve the appropriate LoggerContext have distinct hash codes. In the example that we noticed, the appropriate context was used on 2012-08-15 11:48:58 - 15:48:07 after which it was no longer used. Log entries that should have gone to it were mixed in with those for a newly created context from 2012-08-15 15:48:28 on.
LoggerContext does not implement hashCode() nor equals(). What is the key used to retrieve values in the map?
-- Ceki http://tinyurl.com/proLogback
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
-- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34307989.html Sent from the Logback User mailing list archive at Nabble.com.
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
_______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user

On 16.08.2012 22:44, Robert Voliva wrote:
Chris - by any chance are the messages that are ending up in the wrong context's log coming from commons-logging API loggers? I seem to have narrowed down my issue to just statements logged through the jcl-over-slf4j dependency. It seems like straight slf4j Logger statements are logging to the correct log files.
Both jcl-over-slf4j and log4j-over-slf4j cache the loggers they create. It follows that context selections does not work in the same way as they do for native slf4j, i.e. logback, loggers. -- Ceki http://tinyurl.com/proLogback

I need to check, but that could be the problem since we are using the Spring Framework and because of it jcl-over-slf4j.version 1.6.6. Ceki Gulcu wrote:
On 16.08.2012 22:44, Robert Voliva wrote:
Chris - by any chance are the messages that are ending up in the wrong context's log coming from commons-logging API loggers? I seem to have narrowed down my issue to just statements logged through the jcl-over-slf4j dependency. It seems like straight slf4j Logger statements are logging to the correct log files.
Both jcl-over-slf4j and log4j-over-slf4j cache the loggers they create. It follows that context selections does not work in the same way as they do for native slf4j, i.e. logback, loggers. -- Ceki http://tinyurl.com/proLogback _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/listinfo/logback-user
-- View this message in context: http://old.nabble.com/Logging-crossing-contexts-tp34292668p34309115.html Sent from the Logback User mailing list archive at Nabble.com.

Thanks for pointing me in that direction. I can see now that the jcl-over-slf4j LogFactory doesn't use the logging context selectors. Ceki - is there a path forward from here for us? Or are we just stuck with this behavior? Could the jcl-over-slf4j LogFactory conceivably be changed to use context selectors? Any other ideas/alternatives? On Thu, Aug 16, 2012 at 4:04 PM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 22:44, Robert Voliva wrote:
Chris - by any chance are the messages that are ending up in the wrong context's log coming from commons-logging API loggers? I seem to have narrowed down my issue to just statements logged through the jcl-over-slf4j dependency. It seems like straight slf4j Logger statements are logging to the correct log files.
Both jcl-over-slf4j and log4j-over-slf4j cache the loggers they create. It follows that context selections does not work in the same way as they do for native slf4j, i.e. logback, loggers.
-- Ceki http://tinyurl.com/proLogback
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>

To follow up on this, I was able to fix our problem. I basically re-implemented jcl-over-slf4j with a LogFactory implementation almost identical to logback's LoggerFactory - which uses the ContextSelector code. Replaced that implementation instead of jcl-over-slf4j and it worked. On Thu, Aug 16, 2012 at 10:59 PM, Robert Voliva <rvoliva@gmail.com> wrote:
Thanks for pointing me in that direction. I can see now that the jcl-over-slf4j LogFactory doesn't use the logging context selectors.
Ceki - is there a path forward from here for us? Or are we just stuck with this behavior? Could the jcl-over-slf4j LogFactory conceivably be changed to use context selectors? Any other ideas/alternatives?
On Thu, Aug 16, 2012 at 4:04 PM, ceki <ceki@qos.ch> wrote:
On 16.08.2012 22:44, Robert Voliva wrote:
Chris - by any chance are the messages that are ending up in the wrong context's log coming from commons-logging API loggers? I seem to have narrowed down my issue to just statements logged through the jcl-over-slf4j dependency. It seems like straight slf4j Logger statements are logging to the correct log files.
Both jcl-over-slf4j and log4j-over-slf4j cache the loggers they create. It follows that context selections does not work in the same way as they do for native slf4j, i.e. logback, loggers.
-- Ceki http://tinyurl.com/proLogback
______________________________**_________________ Logback-user mailing list Logback-user@qos.ch http://mailman.qos.ch/mailman/**listinfo/logback-user<http://mailman.qos.ch/mailman/listinfo/logback-user>
participants (4)
-
ceki
-
Chris Rompot
-
Lee Lowder
-
Robert Voliva