Enregistrement des threads parallèles dans logback

Question

Je vais essayer de faire une brève description de mon framework Selenium afin de pouvoir expliquer mon problème.

J'utilise Sélénium 2 (version actuelle 2.3.1) + testNG 5.14

Je configure le fichier testng.xml pour exécuter les tests de la suite de tests en parallèle, juste 2 instances

À des fins de journalisation, j'utilise logback (J'ai lu que c'était la meilleure chose à faire dans le monde du bois).

Mon problème est qu'en vérifiant les journaux de l'application, j'obtiens quelque chose comme ceci :

18:48:58.551 [TestNG] INFO d.a.a.s.t.setup.TestConfiguration - Récupération d'un utilisateur aléatoire dans le pool d'utilisateurs

18:48:58.551 [TestNG] INFO d.a.a.s.t.setup.TestConfiguration - Récupération d'un utilisateur aléatoire dans le pool d'utilisateurs

18:48:58.551 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Création d'un DataSource pour accéder à la base de données

18:48:58.551 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Création d'une source de données pour accéder à la base de données.

18:48:58.552 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Lancement de la requête SQL

18:48:58.552 [TestNG] DEBUG d.a.a.s.t.setup.TestConfiguration - Lancement de la requête SQL

18:48:59.613 [TestNG] TRACE d.a.a.s.t.setup.TestConfiguration - Requête réussie

18:48:59.613 [TestNG] TRACE d.a.a.s.t.setup.TestConfiguration - Requête réussie

Comme vous pouvez le constater, il est impossible de voir la différence entre les deux threads qui tournent en même temps. Ma question est la suivante : existe-t-il un moyen de configurer les paramètres de logback de manière à ce qu'ils ajoutent également un numéro ou un identifiant pour identifier chaque thread en cours d'exécution ?

PD Juste au cas où cela pourrait aider, mon logback.xml ressemble à ceci :

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

Answer 1

Logback Contexte de diagnostic mappé (MDC) est votre ami. Il vous permet d'ajouter des variables locales de threads qui peuvent être gérées, copiées entre les threads et enregistrées à l'aide d'un format de journalisation.

Dans la documentation :

L'un des objectifs de conception de logback est d'auditer et de déboguer des applications distribuées complexes. La plupart des systèmes distribués du monde réel doivent traiter avec plusieurs clients simultanément. Dans une implémentation multithread typique d'un tel système, différents threads vont gérer différents clients. Une approche possible mais légèrement déconseillée pour différencier la sortie de journalisation d'un client d'un autre consiste à instancier un nouveau logger distinct pour chaque client. Cette technique favorise la prolifération des loggers et peut augmenter leur surcharge de gestion.

Une technique plus légère consiste à estampiller de façon unique chaque demande de journal desservant un client donné. Neil Harrison a décrit cette méthode dans le livre Patterns for Logging Diagnostic Messages in Pattern Languages of Program Design 3, édité par R. Martin, D. Riehle, et F. Buschmann (Addison-Wesley, 1997). Logback exploite une variante de cette technique incluse dans l'API SLF4J : Mapped Diagnostic Contexts (MDC).

Pour marquer de façon unique chaque demande, l'utilisateur introduit des informations contextuelles dans le MDC, l'abréviation de Mapped Diagnostic Context. Les éléments saillants de la classe MDC sont présentés ci-dessous. Veuillez vous référer à la javadocs MDC pour une liste complète des méthodes.

Answer 2

Si vous souhaitez une alternative aux noms imprévisibles que vous obtenez avec %thread comme je le fais habituellement, vous pouvez utiliser de simples ID locaux de threads. C'est beaucoup plus facile pour les yeux. Cela fonctionnera avec logback...

public class ThreadIdConverter extends ClassicConverter {
  private static int nextId = 0;
  private static final ThreadLocal<String> threadId = new ThreadLocal<String>() {    
    @Override
    protected String initialValue() {
      int nextId = nextId();
      return String.format("%05d", nextId);
    }
  };

  private static synchronized int nextId() {
    return ++nextId;
  }

  @Override
  public String convert(ILoggingEvent event) {
    return threadId.get();
  }
}

Ensuite, mettez cette simple ligne dans votre XML logback :

<conversionRule conversionWord="tid" 
    converterClass="com.yourstuff.logback.ThreadIdConverter" />

Définissez votre modèle comme suit (remarquez "tid") :

<pattern>%d{HH:mm:ss.SSS} [%tid] %-5level - %msg%n</pattern>

Et vos journaux ressembleront à ceci :

10:32:02.517 [00001] INFO something here
10:32:02.517 [00002] INFO something here
10:32:02.517 [00003] INFO something here
10:32:02.517 [00001] INFO something more here 
10:32:02.517 [00001] INFO something more here

Vous pouvez le faire avec n'importe quel enregistreur qui prend en charge les extensions personnalisées. J'espère que cela vous aidera.

Answer 3

Pour information, vous pouvez afficher l'identifiant du thread en utilisant %thread comme décrit dans la documentation à l'adresse suivante http://logback.qos.ch/manual/configuration.html :

The output is formatted using a PatternLayoutEncoder set to the pattern %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n.

Answer 4

Si vous voulez des identifiants de threads, plutôt que des noms de threads, et que vous utilisez un appender asynchrone, le ThreadIdConverter de Jerico Sandhorn ne fonctionnera pas comme prévu, car il est exécuté sur un thread différent. Dans ce cas, vous pouvez utiliser cette classe.

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);
    }
}

La configuration fonctionne de la même manière :

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

N.B. Cette classe fonctionne avec AsyncAppender car le nom du thread est récupéré avant de devenir asynchrone. Notez également que si les threads ont le même nom, ils obtiendront le même identifiant. Cependant, cela ne se produira pas dans la pratique, à moins que vous ne donniez volontairement le même nom à plusieurs threads, ce qui n'est généralement pas une chose sage à faire.