Logging parallel threads in logback

user_454151 0
Viewed 24028

I'll try to make a brief description of my Selenium framework so that I can explain my problem.

I use Selenium 2 (current version 2.3.1) + testNG 5.14

I set testng.xml file to run the tests in the test suite in parallel, just 2 instances

For logging purposes, I use logback (I've read is the next best thing in the log world)

My problem is that when checking what the application logs I get something like this:

18:48:58.551 [TestNG] INFO d.a.a.s.t.setup.TestConfiguration - Retrieving random User from User Pool

18:48:58.551 [TestNG] INFO d.a.a.s.t.setup.TestConfiguration - Retrieving random User from User Pool

18:48:58.551 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Creating DataSource for acccessing DataBase

18:48:58.551 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Creating DataSource for acccessing DataBase

18:48:58.552 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Launching SQL Query

18:48:58.552 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Launching SQL Query

18:48:59.613 [TestNG] TRACE d.a.a.s.t.setup.TestConfiguration - Query succesful

18:48:59.613 [TestNG] TRACE d.a.a.s.t.setup.TestConfiguration - Query succesful

As you may see, it is impossible to see the difference between the two threads that are running at the same time. My question is, is there a way I can configure the logback settings so that they also add a number or Id to identify each thread that is running?

PD Just in case it may help, my logback.xml file looks like this:

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

  <appender name="FILE" class="ch.qos.logback.core.FileAppender">
    <file>logs/selenium.log</file>

    <encoder>
      <pattern>%date %level [%thread] %logger{10} [%file:%line] %msg%n</pattern>
    </encoder>
  </appender>

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

  <root level="trace">
    <appender-ref ref="FILE" />
    <appender-ref ref="STDOUT" />
  </root>
</configuration>
webdriver testng logback multithreading
4 Answers

If you want thread ids, rather than thread names, and are using an asynchronous appender, Jerico Sandhorn's ThreadIdConverter will not work as expected, because it gets run on a different thread. In that case you can drop in this class.

public class ThreadIdConverter extends ClassicConverter {
    private static final AtomicInteger nextId = new AtomicInteger();
    private static final ConcurrentHashMap<String, String> name2Id = new ConcurrentHashMap<>();

    private static String getNextThreadId(String name) {
        return String.format("%05d", nextId.getAndIncrement());
    }

    @Override
    public String convert(ILoggingEvent event) {
        return name2Id.computeIfAbsent(event.getThreadName(), ThreadIdConverter::getNextThreadId);
    }
}

Configuration works the same way:

    <conversionRule conversionWord="tid" converterClass="pkg.ThreadIdConverter" />
    ....
    <pattern>%date{HH:mm:ss.SSS},%tid,,%msg%n</pattern>

N.B. This class works with AsyncAppender, because the thread name is retrieved before going asynchronous. Also note that if threads have the same name, they will get the same id. However, this is not going to happen in practice, unless you set the same name to multiple threads on purpose, which is generally not a wise thing to do.

user_7095370
Related