[logback-user] Logback console plugin - relative time

Olivier Cailloux mlsmg at ulb.ac.be
Thu Sep 4 19:29:35 CEST 2008


Hello,

/Problem/

In logback view (in Eclipse), using the default Pattern Layout 
"%relative %level [%thread] %logger{25} %message %nopex", I get as first 
part of the log strings the total time in milliseconds since first 
started my application for a given eclipse run, instead of the time in 
milliseconds since started my application. E.g., I see a time of 40000 
as first log entry when running the application, not because the 
application is running since 40 seconds at logging time, but because the 
first time I ran my application for the eclipse session I am in has been 
started 40 seconds ago.

/Test case/

With the following logback.xml:
-----
<?xml version="1.0" encoding="UTF-8"?>

<configuration>

  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <param name="Pattern" value="%relative %level [%thread] 
%logger{25} %message %nopex\n" />
    </layout>
  </appender>

  <root>
    <level value="debug" />
    <appender-ref ref="STDOUT" />
  </root>

  <consolePlugin />
 
</configuration>
-----

and the following Log.java class:
-----
package main;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public class Log {
    private static final Logger s_logger = 
LoggerFactory.getLogger(Log.class);

    public static void main(String[] args) {
        s_logger.info("Started.");
    }

}
-----

I get the following output:
- in the "normal" Eclipse Console (that is, stdout), I invariably see 
(each time I start the application), the unique log entry "0 INFO [main] 
main.Log Started. " (This is the expected behaviour, AFAIU.)
- in the logback view, after having started the application four times 
with several seconds interval each time, I see (BTW, how do you copy the 
contents in the clipboard?):
-----
-47 INFO [main] main.Log Started.
13328 INFO [main] main.Log Started.
18703 INFO [main] main.Log Started.
49406 INFO [main] main.Log Started.
-----

/Question/

Shouldn't the count start at zero each time I start the app? How can I 
get that behaviour in Logback view?

/Tries and setup details/

Clicking "Clear Console" in Logback view does not change the behaviour. 
The LogBack console indeed clears, but the next time I start the 
application I see again a time number which is far greater than zero. 
This number will continue to grow until I restart Eclipse.

Eclipse 3.4, and LogBack Console Plug-in version 1.1.0. I have observed 
this behaviour in Eclipse 3.3.2 as well, and on two different computers. 
Naturally the problem is the same with a simple configuration file as 
given in http://logback.qos.ch/consolePlugin.html ; STDOUT appender has 
been added in the test case above to show the difference in behaviour 
between the console and the logback view.

Thank you for any help.
Olivier



More information about the Logback-user mailing list