Hogyan használjuk a Log4j-t és az MDC-t a Java Spring Boot alkalmazásban?

Egyik projektünk keretében számos hibakeresési esettel szembesültünk. Az egyszerű üzenetek a naplókban nem mindig elegendőek. Szükség lehet például több információra a műveletet végrehajtó felhasználóról (IP címe, jogosultságai, azonosítója, …). A mi esetünkben az alkalmazásunk több mikroszolgáltatásból épült fel, és pontosan meg akartuk határozni az egyik mikroszolgáltatásból a másikba átmenő kérés által követett folyamatot. Ebből a célból egy egyedi azonosítót generáltunk, amelyet minden egyes webes alkalmazás naplójában megjelenítettünk. Ez sokat segített az általunk használt harmadik féltől származó alkalmazásokkal kapcsolatos problémák megoldásában.

• Hogyan naplózzuk az üzeneteket?
• Milyen kontextusinformációt adjunk az üzeneteinkhez?
• Aszinkron szálak futtatása esetén is hozzáadható ez az információ?

Ez a cikk segít egy Spring Boot Java alkalmazást készíteni az üzenetek naplózásához a Log4j segítségével, és a könyvtár MDC-jének (Mapping Diagnostic Context) használatával az üzenetek mellett kontextusadatokat is hozzáadhatunk, különösen aszinkron feladatok esetén.

Kezdjük egy klasszikus Spring Boot alkalmazás létrehozásával a beépített Log4j könyvtárral. Ez a könyvtár lehetővé teszi számunkra egy olyan logger használatát, amely különböző típusú naplóüzeneteket generál (info, error, warning, …)

1. A Spring Initializr-en (https://start.spring.io/) készítsünk egy alap Spring Boot projektet függőségek nélkül.
2. Módosítsuk a pom.xml fájlt, hogy hozzáadjuk a Log4j könyvtár használatához szükséges függőségeket
3. Hozzuk létre a src/main/resources/log4j2.xml fájlt, amely meghatározza a jövőbeli naplóüzenetek formátumát

pom.xml

src/main/resources/log4j2.xml

Első naplóüzenetünk megjelenítése

A jelenlegi állapotban, ha elindítjuk az alkalmazást (például IDE-n keresztül vagy Maven segítségével), nem jelenik meg naplóüzenet. Létrehozunk egy olyan komponenst, amely a Log4j könyvtárat használja egy információs üzenet naplózására.

Készítsünk egy src/main/java/com/sipios/example/mdc/Execute.java fájlt az alábbi kóddal. A csomag neve itt com.sipios.example.mdc, természetesen a sajátodra kell cserélni 🙂

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

Ha futtatod az alkalmazást, akkor most megjelenik egy első, a meghatározott formátumot tiszteletben tartó naplóüzenet. Lehetőség van a error és warning metódusok használatára is. Ezeknek a típusoknak megfelelő naplóüzenetek fognak megjelenni.

MDC (Mapping Diagnostic Context) használata a naplóban

Most már tudjuk, hogyan kell használni a Log4j könyvtárat, használhatjuk a Mapping Diagnostic Contextet (MDC), amely lehetővé teszi, hogy egy adattérképet társítsunk az üzenetünkhöz. Néhány példa az adatokra, amelyeket ajánlott az MDC-be helyezni:

• Az aktuális munkamenet adatai (felhasználó, lekérdezés, kérés …)
• Metrikák a folyamat végrehajtásáról (kezdeti idő és végrehajtási idő, …)
• Az alkalmazás verziójára vonatkozó információk
• …

Ez a térkép jelenik meg a naplókban, ha a Log4j üzenetformátum meghatározásában a %X maszkot használjuk. Ez a helyzet itt a src/main/resources/log4j2.xml fájlunkban. Az előző végrehajtásban {} látható, ami egy üres Map-et jelez.

Az MDC használata nagyon egyszerű, és a put, get, remove, clear metódusokon keresztül a klasszikus Map-hez hasonlóan használható… Adjunk hozzá két bejegyzést az MDC-hez és hajtsuk végre az alkalmazást.

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

A MDC globális és megmarad, amíg nem módosítjuk. Ha ki akarjuk üríteni például egy komponens elhagyásával, csak használjuk a clear módszert. Ekkor a következő eredményt kapjuk.

Hogyan működik aszinkron komponensekkel?

Próbáljuk ki az MDC-t aszinkron komponensekkel (a főszál párhuzamos szálán végrehajtott komponens)! Először is be kell állítanunk az alkalmazásunkat az ilyen babok futtatására. Létrehozunk egy szolgáltatást két metódussal, az egyik szinkron, a másik aszinkron.

1. Add @EnableAsync annotációt az Application osztályhoz
2. Létrehozunk egy szolgáltatást egy normál és egy @Async metódussal
3. Módosítjuk a komponenst, hogy a szolgáltatás metódusait injektálja és használja
4. Elindítjuk az alkalmazást

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

Add taskExecutor in Application class

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

Re-execute :

Amint látjuk, az MDC az async szálban üres. Valójában minden aszinkron feladat egy új szálban indul. Minden szál a feladat végrehajtója által kezdeményezett Map MDC-hez kapcsolódik. Ezen a végrehajtón lehet játszani, hogy ugyanazt az MDC-t kapjuk, mint a főszálon. Adjunk hozzá egy dekorátort az asyncExecutorhoz az MDC duplikálásához!

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

Ez a dekorátor beállítása az aszinkron konfigurációban

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

Az alkalmazás újraindítása

Íme! A naplókban minden olyan kontextust közvetíthetünk, amit szinkron vagy aszinkron feladatokban szeretnénk.

Ezeknek köszönhetően az alkalmazás hibakeresése egyszerűsödik és érthetőbbé válik. A projektünk részeként ez rengeteg időt takarított meg nekünk a közreműködőkkel folytatott eszmecserék során. Most már csak rajtad múlik 🙂

Bibliográfia

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