Jak používat Log4j a MDC v aplikaci Java Spring Boot?

V rámci jednoho z našich projektů jsme se setkali s mnoha případy ladění. Prosté zprávy v protokolech vždy nestačí. Může být například nutné mít více informací o uživateli, který akci provedl (jeho IP, jeho oprávnění, jeho identifikátor, …). V našem případě byla naše aplikace sestavena z několika mikroslužeb a chtěli jsme přesně identifikovat tok, který následuje po požadavku, který přechází z jedné mikroslužby do druhé. Za tímto účelem byl vygenerován jedinečný identifikátor, který se zobrazoval v protokolech každé webové aplikace. To nám velmi pomohlo při řešení problémů s aplikacemi třetích stran, které jsme používali.

• Jak logovat zprávy?
• Jaké kontextové informace přidat do našich zpráv?
• Mohou být tyto informace přidány při běhu asynchronních vláken?

Tento článek vám pomůže sestavit Spring Boot Java aplikaci pro logování zpráv pomocí Log4j a využít MDC této knihovny (Mapping Diagnostic Context) pro přidání kontextových údajů navíc ke zprávám, zejména pro asynchronní úlohy.

Začneme vygenerováním klasické Spring Boot aplikace se zabudovanou knihovnou Log4j. Tato knihovna nám umožňuje používat logger, který generuje zprávy různých typů (info, error, warning, …)

1. V nástroji Spring Initializr (https://start.spring.io/) sestavte základní projekt Spring Boot bez závislostí.
2. Upravte soubor pom.xml a přidejte závislosti potřebné pro použití knihovny Log4j
3. Vytvořte src/main/resources/log4j2.xml, který definuje formát budoucích zpráv protokolu

pom.xml

src/main/resources/log4j2.xml

Zobrazte naši první zprávu protokolu

V současném stavu, pokud spustíme aplikaci (například prostřednictvím IDE nebo pomocí Mavenu), se žádná zpráva protokolu nezobrazí. Vytvoříme komponentu, která bude využívat knihovnu Log4j k protokolování informační zprávy.

Vytvořte soubor src/main/java/com/sipios/example/mdc/Execute.java s níže uvedeným kódem. Název balíčku je zde com.sipios.example.mdc, samozřejmě by měl být nahrazen vaším 🙂

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

Pokud aplikaci spustíte, zobrazí se nyní první zpráva protokolu respektující definovaný formát. Dále je možné použít metody error a warning. Zobrazí se zprávy protokolu odpovídající těmto typům.

Použití MDC (Mapping Diagnostic Context) ve vašem protokolu

Teď, když víme, jak používat knihovnu Log4j, budeme moci použít Mapping Diagnostic Context (MDC), který nám umožňuje přiřadit datovou mapu k naší zprávě. Několik příkladů dat, která doporučujeme umístit do MDC:

• Údaje o aktuální relaci (uživatel, dotaz, požadavek …)
• Metriky o provádění procesu (počáteční čas a čas provádění, …).)
• Informace o verzi aplikace
• …

Tato mapa se v protokolech zobrazuje, pokud je v definici formátu zprávy Log4j použita maska %X. Tak je tomu v našem případě v souboru src/main/resources/log4j2.xml. V předchozím provedení vidíme {}, což značí prázdnou Mapu.

Použití MDC je velmi jednoduché a používá se jako klasická Mapa prostřednictvím metod put, get, remove, clear…. Přidáme dvě položky do MDC a spustíme aplikaci.

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

MDC je globální a je zachována, dokud není modifikována. Pokud jej chcete vyprázdnit například opuštěním komponenty, stačí použít metodu clear. To by pak dalo následující výsledek.

Jak to funguje s asynchronními komponentami?

Vyzkoušejme MDC s asynchronními komponentami (komponenta prováděná na paralelním vlákně hlavního vlákna)! Nejprve musíme naši aplikaci nakonfigurovat tak, aby takové fazole vykonávala. Vytvoříme službu se dvěma metodami, z nichž jedna je synchronní a druhá asynchronní.

1. Přidejte do třídy Application anotaci @EnableAsync
2. Vytvořte službu s normální metodou a metodou @Async
3. Upravte komponentu tak, aby injektovala a používala metody služby
4. Spustit aplikaci

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

Přidat taskExecutor ve třídě Application

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

Re-execute :

Jak vidíme, MDC v asynchronním vlákně je prázdné. Každá asynchronní úloha se totiž spouští v novém vlákně. Každé vlákno je spojeno s Mapou MDC iniciovanou vykonavatelem úlohy. Na tomto vykonavateli je možné hrát a získat stejný MDC jako v hlavním vlákně. Přidejme dekorátor v asyncExecutor, abychom mohli duplikovat MDC!

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

Nastavte tento dekorátor v asynchronním konfigurátoru

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

Spustit aplikaci

Tady to máte! V protokolech můžeme sdělit všechny souvislosti, které chceme v synchronních nebo asynchronních úlohách.

Díky tomu je ladění aplikace jednodušší a srozumitelnější. V rámci našeho projektu nám to ušetřilo spoustu času při výměnách s našimi přispěvateli. Teď už je to na vás 🙂

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/

.