Logging from different threads
Hello, I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way: final static Logger logger = LoggerFactory.getLogger(TheClass.class); I have this configuration: <configuration> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>DEBUG</level> </filter> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender> <appender name="FILE" class="ch.qos.logback.core.FileAppender"> <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <level>TRACE</level> </filter> <File>../../build/puma-gentest1-log.txt</File> <Append>false</Append> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%-5level: %msg (%d{HH:mm:ss} [%thread] %logger{35}) %n</Pattern> </layout> </appender> <root> <level value="TRACE" /> <appender-ref ref="STDOUT" /> <appender-ref ref="FILE" /> </root> <logger name="freemarker.cache"> <level value="INFO" /> </logger> </configuration> The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla). ----- -- Lukas Zapletal http://lukas.zapletalovi.com -- View this message in context: http://www.nabble.com/Logging-from-different-threads-tp22229676p22229676.htm... Sent from the Logback User mailing list archive at Nabble.com.
Hello Lukas, Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active? Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent: <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender> <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender> There is another minor observation I would like to make. Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file. Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way:
[snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
Hi I HAVE FOUND THE SOLUTION! The class not being logged is in very very long package. Its a : com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject I am using %logger{20} pattern and it seems this very long package cannot even fit in this pattern (with only 20 characters permitted). I have raised this value to 200 and now it works - the package and the log record appears: com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject.ISObjectContentGenerator I would suppose that if the name of the logger is longer and cannot be shortened to the limit something like i.i.ISObjectContentGenerator will appear throwing away beginning of the name. Not at all. I have also tried %logger{0} to see only "ISObjectContentGenerator" but this did not work too. Is this a bug? I am using version 0.9.9. LZ Ceki Gulcu wrote:
Hello Lukas,
Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active?
Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
There is another minor observation I would like to make.
Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file.
Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way:
[snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com -- View this message in context: http://www.nabble.com/Logging-from-different-threads-tp22229676p22241710.htm... Sent from the Logback User mailing list archive at Nabble.com.
It may be a bug. Could your please enter a bug report? Lukas Zapletal wrote:
I am using %logger{20} pattern and it seems this very long package cannot even fit in this pattern (with only 20 characters permitted). I have raised this value to 200 and now it works - the package and the log record appears:
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject.ISObjectContentGenerator
I would suppose that if the name of the logger is longer and cannot be shortened to the limit something like
i.i.ISObjectContentGenerator
will appear throwing away beginning of the name. Not at all. I have also tried %logger{0} to see only "ISObjectContentGenerator" but this did not work too.
Is this a bug? I am using version 0.9.9.
LZ
Ceki Gulcu wrote:
Hello Lukas,
Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active?
Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
There is another minor observation I would like to make.
Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file.
Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way: [snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
Upgrade to 0.9.15 did not help :-( I think logback should not skip records only for reason it cannot shorten a name... what do you think? LZ Lukas Zapletal (gmail) wrote:
Hi
I HAVE FOUND THE SOLUTION!
The class not being logged is in very very long package. Its a :
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject
I am using %logger{20} pattern and it seems this very long package cannot even fit in this pattern (with only 20 characters permitted). I have raised this value to 200 and now it works - the package and the log record appears:
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject.ISObjectContentGenerator
I would suppose that if the name of the logger is longer and cannot be shortened to the limit something like
i.i.ISObjectContentGenerator
will appear throwing away beginning of the name. Not at all. I have also tried %logger{0} to see only "ISObjectContentGenerator" but this did not work too.
Is this a bug? I am using version 0.9.9.
LZ
Ceki Gulcu wrote:
Hello Lukas,
Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active?
Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
There is another minor observation I would like to make.
Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file.
Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way:
[snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com -- View this message in context: http://www.nabble.com/Logging-from-different-threads-tp22229676p22241748.htm... Sent from the Logback User mailing list archive at Nabble.com.
Checking the code, it appears that the abbreviation algorithm can handle names with 12 parts. Your class name has 13. It's a bug in the abbreviation algorithm. Lukas, could you please enter a bug report? Lukas Zapletal wrote:
Upgrade to 0.9.15 did not help :-(
I think logback should not skip records only for reason it cannot shorten a name... what do you think?
LZ
Lukas Zapletal (gmail) wrote:
Hi
I HAVE FOUND THE SOLUTION!
The class not being logged is in very very long package. Its a :
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject
I am using %logger{20} pattern and it seems this very long package cannot even fit in this pattern (with only 20 characters permitted). I have raised this value to 200 and now it works - the package and the log record appears:
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject.ISObjectContentGenerator
I would suppose that if the name of the logger is longer and cannot be shortened to the limit something like
i.i.ISObjectContentGenerator
will appear throwing away beginning of the name. Not at all. I have also tried %logger{0} to see only "ISObjectContentGenerator" but this did not work too.
Is this a bug? I am using version 0.9.9.
LZ
Ceki Gulcu wrote:
Hello Lukas,
Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active?
Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
There is another minor observation I would like to make.
Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file.
Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way: [snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
I meant to say, up to 12 parts, not just 12. Ceki Gulcu wrote:
Checking the code, it appears that the abbreviation algorithm can handle names with 12 parts. Your class name has 13. It's a bug in the abbreviation algorithm. Lukas, could you please enter a bug report?
Lukas Zapletal wrote:
Upgrade to 0.9.15 did not help :-(
I think logback should not skip records only for reason it cannot shorten a name... what do you think?
LZ
Lukas Zapletal (gmail) wrote:
Hi
I HAVE FOUND THE SOLUTION!
The class not being logged is in very very long package. Its a :
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject
I am using %logger{20} pattern and it seems this very long package cannot even fit in this pattern (with only 20 characters permitted). I have raised this value to 200 and now it works - the package and the log record appears:
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject.ISObjectContentGenerator
I would suppose that if the name of the logger is longer and cannot be shortened to the limit something like i.i.ISObjectContentGenerator will appear throwing away beginning of the name. Not at all. I have also tried %logger{0} to see only "ISObjectContentGenerator" but this did not work too.
Is this a bug? I am using version 0.9.9.
LZ
Ceki Gulcu wrote:
Hello Lukas,
Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active?
Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
There is another minor observation I would like to make.
Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file.
Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way: [snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
Why not. But what about patch with JUnit test? :-) Give me a minute to bring on my IntelliJ... LZ Ceki Gulcu wrote:
I meant to say, up to 12 parts, not just 12.
Ceki Gulcu wrote:
Checking the code, it appears that the abbreviation algorithm can handle names with 12 parts. Your class name has 13. It's a bug in the abbreviation algorithm. Lukas, could you please enter a bug report?
Lukas Zapletal wrote:
Upgrade to 0.9.15 did not help :-(
I think logback should not skip records only for reason it cannot shorten a name... what do you think?
LZ
Lukas Zapletal (gmail) wrote:
Hi
I HAVE FOUND THE SOLUTION!
The class not being logged is in very very long package. Its a :
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject
I am using %logger{20} pattern and it seems this very long package cannot even fit in this pattern (with only 20 characters permitted). I have raised this value to 200 and now it works - the package and the log record appears:
com.pike.puma.wm.isd2dita.core.g.project.server.pkg.isobjecttype.isobject.ISObjectContentGenerator
I would suppose that if the name of the logger is longer and cannot be shortened to the limit something like i.i.ISObjectContentGenerator will appear throwing away beginning of the name. Not at all. I have also tried %logger{0} to see only "ISObjectContentGenerator" but this did not work too.
Is this a bug? I am using version 0.9.9.
LZ
Ceki Gulcu wrote:
Hello Lukas,
Your configuration file looks good. I see no reason why logging output should be generated correctly from some worker threads and not others. Are you sure that the silent thread is active?
Here are some remarks about your configuration file *unrelated* to the problem your you are describing. As of logback version 0.9.15, if no class name is provided, layout property will default to PatternLayout. This, the next two configuration excerpts are equivalent:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <!-- no class attribute specified --> <layout> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> <layout class="ch.qos.logback.classic.PatternLayout"> <Pattern>%d{HH:mm:ss} [%thread] %-5level %logger{20} - %msg%n</Pattern> </layout> </appender>
There is another minor observation I would like to make.
Setting the level of a threshold filter to TRACE makes it (the filter) a pass through filter. The threshold filter in FileAppender is set to the level TRACE. On the other hand, setting such a filter does not hurt either, except perhaps cluttering the configuration file.
Lukas Zapletal wrote:
Hello,
I have application with 4 threads called M, 1, 2 and 3. Its using Logback over slf4j in normal way: [snip]
The problem: I cannot see error messages logged by one of "worker" threads. I have no clue why. Its not from freemarker.cache package - its different package (com.pike.blabla).
-- Lukas Zapletal
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch _______________________________________________ Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com -- View this message in context: http://www.nabble.com/Logging-from-different-threads-tp22229676p22242500.htm... Sent from the Logback User mailing list archive at Nabble.com.
A patch with a unit test would be a nice exercise. Would you like any hints on how to start? Lukas Zapletal wrote:
Why not.
But what about patch with JUnit test? :-)
Give me a minute to bring on my IntelliJ...
LZ -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
I do not need no hits - I know your infrastructure very well. I just wonder why you hard-limit number of dots to 12? Why this number. Solutions for this bug: a) increase this limit b) restructuralize the code that it never throws ArrayIndexOutOfBoundsException What you you prefer. I think a) does not need a patch - you can do it easily :-) LZ Ceki Gulcu wrote:
A patch with a unit test would be a nice exercise. Would you like any hints on how to start?
Lukas Zapletal wrote:
Why not.
But what about patch with JUnit test? :-)
Give me a minute to bring on my IntelliJ...
LZ -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
Logback-user mailing list Logback-user@qos.ch http://qos.ch/mailman/listinfo/logback-user
----- -- Lukas Zapletal http://lukas.zapletalovi.com -- View this message in context: http://www.nabble.com/Logging-from-different-threads-tp22229676p22243854.htm... Sent from the Logback User mailing list archive at Nabble.com.
Lukas Zapletal wrote:
I just wonder why you hard-limit number of dots to 12? Why this number.
No particular reason. -- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
participants (2)
-
Ceki Gulcu -
Lukas Zapletal