Java-Protokollierung mit verschachteltem Diagnosekontext (NDC)

1. Übersicht

Der verschachtelte Diagnosekontext (NDC) ist ein Mechanismus zur Unterscheidung von verschachtelten Protokollnachrichten aus verschiedenen Quellen. NDC bietet dazu die Möglichkeit, jedem Protokolleintrag eindeutige Kontextinformationen hinzuzufügen.

In diesem Artikel werden wir die Verwendung von NDC und seine Verwendung / Unterstützung in verschiedenen Java-Protokollierungsframeworks untersuchen.

2. Diagnosekontexte

In einer typischen Multithread-Anwendung wie einer Webanwendung oder REST-APIs wird jede Clientanforderung von einem anderen Thread bedient. Die aus einer solchen Anwendung generierten Protokolle sind eine Mischung aus allen Clientanforderungen und -quellen. Dies macht es schwierig, die Protokolle geschäftlich zu verstehen oder zu debuggen.

Der verschachtelte Diagnosekontext (Nested Diagnostic Context, NDC) verwaltet einen Stapel von Kontextinformationen pro Thread. Die Daten in NDC stehen für jede Protokollanforderung im Code zur Verfügung und können so konfiguriert werden, dass sie mit jeder Protokollnachricht protokolliert werden - auch an Stellen, an denen die Daten nicht im Gültigkeitsbereich liegen. Diese Kontextinformationen in jeder Protokollnachricht helfen dabei, die Protokolle nach Quelle und Kontext zu unterscheiden.

Der Mapped Diagnostic Context (MDC) verwaltet Informationen auch pro Thread, jedoch als Map.

3. Der NDC-Stapel in einer Beispielanwendung

Um die Verwendung eines NDC-Stacks zu demonstrieren, nehmen wir ein Beispiel einer REST-API, die Geld an ein Anlagekonto sendet.

Die als Eingabe erforderlichen Informationen werden in einer Anlageklasse dargestellt :

public class Investment { private String transactionId; private String owner; private Long amount; public Investment (String transactionId, String owner, Long amount) { this.transactionId = transactionId; this.owner = owner; this.amount = amount; } // standard getters and setters }

Die Überweisung auf das Anlagekonto erfolgt über InvestmentService . Den vollständigen Quellcode für diese Klassen finden Sie in diesem Github-Projekt.

In der Beispielanwendung werden die Datentransaktions- ID und der Eigentümer im NDC-Stapel in dem Thread abgelegt, der eine bestimmte Anforderung verarbeitet. Diese Daten sind in jeder Protokollnachricht in diesem Thread verfügbar. Auf diese Weise kann jede eindeutige Transaktion verfolgt und der relevante Kontext jeder Protokollnachricht identifiziert werden.

4. NDC in Log4j

Log4j bietet eine Klasse namens NDC, die statische Methoden zum Verwalten von Daten im NDC-Stapel bereitstellt. Grundlegende Verwendung:

  • Verwenden Sie bei der Eingabe eines Kontexts NDC.push () , um dem aktuellen Thread Kontextdaten hinzuzufügen
  • Verwenden Sie beim Verlassen des Kontexts NDC.pop () , um die Kontextdaten zu entfernen
  • Rufen Sie beim Beenden des Threads NDC.remove () auf, um den Diagnosekontext für den Thread zu entfernen und sicherzustellen, dass Speicher freigegeben wird (ab Log4j 1.3 nicht mehr erforderlich).

Verwenden Sie in der Beispielanwendung NDC, um Kontextdaten an relevanten Stellen im Code hinzuzufügen / zu entfernen:

import org.apache.log4j.NDC; @RestController public class Log4JController { @Autowired @Qualifier("Log4JInvestmentService") private InvestmentService log4jBusinessService; @RequestMapping( value = "/ndc/log4j", method = RequestMethod.POST) public ResponseEntity postPayment( @RequestBody Investment investment) { NDC.push("tx.id=" + investment.getTransactionId()); NDC.push("tx.owner=" + investment.getOwner()); log4jBusinessService.transfer(investment.getAmount()); NDC.pop(); NDC.pop(); NDC.remove(); return new ResponseEntity(investment, HttpStatus.OK); } }

Der Inhalt von NDC kann in Protokollnachrichten angezeigt werden, indem die Option % x im ConversionPattern verwendet wird, das vom Appender in log4j.properties verwendet wird :

log4j.appender.consoleAppender.layout.ConversionPattern = %-4r [%t] %5p %c{1} - %m - [%x]%n

Lassen Sie uns die REST-API für Tomcat bereitstellen. Musteranfrage:

POST /logging-service/ndc/log4j { "transactionId": "4", "owner": "Marc", "amount": 2000 }

Wir können die diagnostischen Kontextinformationen in der Protokollausgabe sehen:

48569 [http-nio-8080-exec-3] INFO Log4JInvestmentService - Preparing to transfer 2000$. - [tx.id=4 tx.owner=Marc] 49231 [http-nio-8080-exec-4] INFO Log4JInvestmentService - Preparing to transfer 1500$. - [tx.id=6 tx.owner=Samantha] 49334 [http-nio-8080-exec-3] INFO Log4JInvestmentService - Has transfer of 2000$ completed successfully ? true. - [tx.id=4 tx.owner=Marc] 50023 [http-nio-8080-exec-4] INFO Log4JInvestmentService - Has transfer of 1500$ completed successfully ? true. - [tx.id=6 tx.owner=Samantha] ...

5. NDC in Log4j 2

NDC in Log4j 2 wird als Thread Context Stack bezeichnet:

import org.apache.logging.log4j.ThreadContext; @RestController public class Log4J2Controller { @Autowired @Qualifier("Log4J2InvestmentService") private InvestmentService log4j2BusinessService; @RequestMapping( value = "/ndc/log4j2", method = RequestMethod.POST) public ResponseEntity postPayment( @RequestBody Investment investment) { ThreadContext.push("tx.id=" + investment.getTransactionId()); ThreadContext.push("tx.owner=" + investment.getOwner()); log4j2BusinessService.transfer(investment.getAmount()); ThreadContext.pop(); ThreadContext.pop(); ThreadContext.clearAll(); return new ResponseEntity(investment, HttpStatus.OK); } }

Verwenden Sie wie bei Log4j die Option % x in der Log4j 2-Konfigurationsdatei log4j2.xml :

Protokollausgabe:

204724 [http-nio-8080-exec-1] INFO Log4J2InvestmentService - Preparing to transfer 1500$. - [tx.id=6, tx.owner=Samantha] 205455 [http-nio-8080-exec-2] INFO Log4J2InvestmentService - Preparing to transfer 2000$. - [tx.id=4, tx.owner=Marc] 205525 [http-nio-8080-exec-1] INFO Log4J2InvestmentService - Has transfer of 1500$ completed successfully ? false. - [tx.id=6, tx.owner=Samantha] 206064 [http-nio-8080-exec-2] INFO Log4J2InvestmentService - Has transfer of 2000$ completed successfully ? true. - [tx.id=4, tx.owner=Marc] ...

6. NDC in Protokollierungsfassaden (JBoss-Protokollierung)

Protokollierungsfassaden wie SLF4J ermöglichen die Integration in verschiedene Protokollierungsframeworks. NDC wird in SLF4J nicht unterstützt (ist jedoch im Modul slf4j-ext enthalten). JBoss Logging ist genau wie SLF4J eine Protokollierungsbrücke. NDC wird in der JBoss-Protokollierung unterstützt.

Standardmäßig durchsucht JBoss Logging den ClassLoader nach der Verfügbarkeit von Back-Ends / Anbietern in der folgenden Rangfolge: JBoss LogManager, Log4j 2, Log4j, SLF4J und JDK Logging.

JBoss LogManager als Protokollierungsanbieter wird normalerweise auf dem WildFly-Anwendungsserver verwendet. In unserem Fall wählt die JBoss-Protokollierungsbrücke die nächste in der Rangfolge (Log4j 2) als Protokollierungsanbieter aus.

Beginnen wir mit dem Hinzufügen der erforderlichen Abhängigkeit in pom.xml :

 org.jboss.logging jboss-logging 3.3.0.Final 

Die neueste Version der Abhängigkeit kann hier überprüft werden.

Fügen wir dem NDC-Stapel Kontextinformationen hinzu:

import org.jboss.logging.NDC; @RestController public class JBossLoggingController { @Autowired @Qualifier("JBossLoggingInvestmentService") private InvestmentService jbossLoggingBusinessService; @RequestMapping( value = "/ndc/jboss-logging", method = RequestMethod.POST) public ResponseEntity postPayment( @RequestBody Investment investment) { NDC.push("tx.id=" + investment.getTransactionId()); NDC.push("tx.owner=" + investment.getOwner()); jbossLoggingBusinessService.transfer(investment.getAmount()); NDC.pop(); NDC.pop(); NDC.clear(); return new ResponseEntity(investment, HttpStatus.OK); } }

Protokollausgabe:

17045 [http-nio-8080-exec-1] INFO JBossLoggingInvestmentService - Preparing to transfer 1,500$. - [tx.id=6, tx.owner=Samantha] 17725 [http-nio-8080-exec-1] INFO JBossLoggingInvestmentService - Has transfer of 1,500$ completed successfully ? true. - [tx.id=6, tx.owner=Samantha] 18257 [http-nio-8080-exec-2] INFO JBossLoggingInvestmentService - Preparing to transfer 2,000$. - [tx.id=4, tx.owner=Marc] 18904 [http-nio-8080-exec-2] INFO JBossLoggingInvestmentService - Has transfer of 2,000$ completed successfully ? true. - [tx.id=4, tx.owner=Marc] ...

7. Fazit

Wir haben gesehen, wie der diagnostische Kontext dazu beiträgt, Protokolle auf sinnvolle Weise zu korrelieren - sowohl aus geschäftlicher Sicht als auch zu Debugging-Zwecken. Es ist eine unschätzbare Technik, um die Protokollierung zu bereichern, insbesondere in Multithread-Anwendungen.

Das in diesem Artikel verwendete Beispiel finden Sie im Github-Projekt.