Hoe gebruik je Log4j en MDC in Java Spring Boot-applicatie?

In het kader van een van onze projecten werden we geconfronteerd met veel debugging cases. Eenvoudige berichten in de logboeken zijn niet altijd voldoende. Het kan bijvoorbeeld nodig zijn om meer informatie te hebben over de gebruiker die de actie heeft uitgevoerd (zijn IP, zijn machtigingen, zijn identificatiecode, …). In ons geval was onze applicatie opgebouwd uit verschillende microservices en wilden we precies de flow identificeren die gevolgd werd door een verzoek dat van de ene microservice naar de andere ging. Voor dit doel werd een unieke identifier gegenereerd en weergegeven in de logs van elke webapplicatie. Dit hielp ons veel bij het oplossen van problemen met applicaties van derden die we gebruikten.

• Hoe loggen we berichten?
• Welke contextinformatie moeten we toevoegen aan onze berichten?
• Kan deze informatie worden toegevoegd wanneer asynchrone threads worden uitgevoerd?

Dit artikel zal je helpen een Spring Boot Java applicatie te bouwen om berichten te loggen met Log4j en de MDC van deze bibliotheek (Mapping Diagnostic Context) te gebruiken om contextinformatie toe te voegen naast berichten, speciaal voor asynchrone taken.

Laten we beginnen met het genereren van een klassieke Spring Boot applicatie met de ingebouwde Log4j bibliotheek. Deze bibliotheek stelt ons in staat om een logger te gebruiken die log berichten van verschillende types genereert (info, error, warning, …)

1. Op Spring Initializr (https://start.spring.io/), bouw een basis Spring Boot project zonder dependencies.
2. Bewerk het pom.xml bestand om de dependencies toe te voegen die nodig zijn om de Log4j bibliotheek te gebruiken
3. Creëer het src/main/resources/log4j2.xml bestand aan dat het formaat voor toekomstige logberichten definieert

pom.xml

src/main/resources/log4j2.xml

Toon ons eerste logbericht

In de huidige staat, als we de applicatie starten (via een IDE bijvoorbeeld of met behulp van Maven), verschijnt er geen logbericht. We zullen een component maken dat de Log4j bibliotheek gebruikt om een informatie boodschap te loggen.

Maak een src/main/java/com/sipios/example/mdc/Execute.java bestand met de onderstaande code. De pakketnaam is hier com.sipios.example.mdc, natuurlijk moet deze worden vervangen door de uwe 🙂

src/main/java/com/sipios/example/mdc/Execute.java

Als u de toepassing uitvoert, wordt nu een eerste logbericht weergegeven dat voldoet aan de gedefinieerde opmaak. Het is ook mogelijk om de methoden error en warning te gebruiken. Logberichten die overeenkomen met deze types zullen worden weergegeven.

Gebruik MDC (Mapping Diagnostic Context) in uw log

Nu we weten hoe we de Log4j bibliotheek moeten gebruiken, kunnen we gebruik maken van de Mapping Diagnostic Context (MDC) waarmee we een data Map aan ons bericht kunnen koppelen. Enkele voorbeelden van gegevens die we aanraden in de MDC te zetten:

• Gegevens van de huidige sessie (gebruiker, query, verzoek …)
• Metrieken over de uitvoering van het proces (initiële tijd en uitvoeringstijd, …)
• Kennis over de versie van de applicatie
• …

Deze kaart wordt in de logs weergegeven als het %X masker wordt gebruikt in de Log4j bericht formaat definitie. Dit is hier het geval in ons src/main/resources/log4j2.xml bestand. In de vorige uitvoering zien we {}, wat duidt op een lege Map.

Het gebruik van MDC is heel eenvoudig en wordt gebruikt als een klassieke Map via put, get, remove, clear methoden… Laten we twee entries aan de MDC toevoegen en de applicatie uitvoeren.

src/main/java/com/sipios/example/mdc/Execute.java

MDC is globaal en blijft behouden zolang hij niet wordt gewijzigd. Als je het wilt legen door bijvoorbeeld een component te laten staan, gebruik je gewoon de methode clear. Dit zou dan het volgende resultaat geven.

Hoe werkt het met asynchrone componenten?

Laten we MDC eens proberen met asynchrone componenten (een component die op een parallelle thread van de hoofdthread wordt uitgevoerd)! Allereerst moeten we onze applicatie configureren om dergelijke bonen uit te voeren. We maken een service aan met twee methoden, de ene is synchroon en de andere asynchroon.

1. Voeg @EnableAsync annotatie toe aan de klasse Application
2. Maak een service met een normale methode en een @Async methode
3. Modificeer de component om de methoden van de service te injecteren en te gebruiken
4. Lanceer de applicatie

src/main/java/com/sipios/example/mdc/Application.java

src/main/java/com/sipios/example/mdc/service/Example.java

src/main/java/com/sipios/example/mdc/Execute.java

Taakuitvoerder toevoegen aan klasse Applicatie

src/main/java/com/sipios/example/mdc/Application.java

Taakuitvoerder opnieuw uitvoeren :

Zoals we kunnen zien, is MDC in asynchrone thread leeg. Elke asynchrone taak wordt namelijk in een nieuwe thread gestart. Elke thread is gekoppeld aan een Map MDC die wordt gestart door de uitvoerder van de taak. Het is mogelijk om op deze executor te spelen om dezelfde MDC te verkrijgen als op de hoofddraad. Laten we een decorator toevoegen aan asyncExecutor om MDC te dupliceren!

src/main/java/com/sipios/example/mdc/ExampleTaskDecorator.java

Stel deze decorator in async config

src/main/java/com/sipios/example/mdc/Application.java

Relaunch application

Daar gaat ie dan! We kunnen in de logs alle context overbrengen die we willen in synchrone of asynchrone taken.

Dankzij dit is het debuggen van een applicatie eenvoudiger en begrijpelijker geworden. Als onderdeel van ons project heeft dit ons veel tijd bespaard in de uitwisselingen met onze bijdragers. Het is nu aan u 🙂

Bibliografie

• http://www.baeldung.com/mdc-in-log4j-2-logback
• https://spring.io/guides/gs/async-method/
• https://moelholm.com/2017/07/24/spring-4-3-using-a-taskdecorator-to-copy-mdc-data-to-async-threads/