Jak zmienić poziom logowania w aplikacji Spring Boot dla uruchomionej aplikacji?

calendar2022-03-30 · 6 min. czytania  ·
Podaj dalej: linkedincopy

Kiedy mamy problem z odtworzeniem błędu w aplikacji na lokalnym środowisku, przydatne może być przejrzenie logów ze środowiska, na którym ten błąd występuje. Zazwyczaj wymaga to zmiany poziomu logowania np. na DEBUG lub TRACE. Standardowo możemy ustawić poziom logowania w preferencjach aplikacji i ją zrestartować.

1# ustawienie poziomu DEBUG dla specyficznej klasy
2logging.level.pl.speedlog.example.logging_level.SchedulerOne=DEBUG

Zdarza się, że na danym środowisku trwają intensywne testy i nie możemy zrestartować aplikacji po zmianie preferencji.

Jak zmienić poziom logowania w aplikacji Spring Boot bez restartu aplikacji?

Rozwiązań jest co najmniej kilka:

  • ustawienie śledzenia zmian w pliku konfiguracyjnym logback, umieszczonym w katalogu aplikacji
  • użycie springboot-config-server i wywołanie endpoint'a do odświeżenia konfiguracji
  • użycie endpointów actuatora

W tym artykule opiszę ostatni sposób czyli użycie biblioteki actuator1. Za jej pomocą możemy sprawdzić i zmienić poziom logowania bez konieczności restartu aplikacji.

  1. Dodajemy zależność

Plik pom.xml

1<dependency>
2    <groupId>org.springframework.boot</groupId>
3    <artifactId>spring-boot-starter-actuator</artifactId>
4</dependency>

lub build.gradle

1implementation 'org.springframework.boot:spring-boot-starter-actuator'
  1. Ustawiamy endpoint w konfiguracji aplikacji. Plik application.properties
1management.endpoints.web.exposure.include=loggers
  1. Przykładowa aplikacja

Przygotujemy aplikację, która co dwie sekundy dodaje w logach komunikat na poziomach INFO, DEBUG, TRACE z dwóch klas SchedulerOne oraz AnotherScheduler.

Dodajemy adnotację @EnableScheduling do głównej klasy.

1@SpringBootApplication
2@EnableScheduling
3public class LoggingLevelApplication {
4
5	public static void main(String[] args) {
6		SpringApplication.run(LoggingLevelApplication.class, args);
7	}
8
9}

Pierwsza klasa dodająca wpisy do logów SchedulerOne.java

 1@Component
 2class SchedulerOne {
 3
 4    private static final Logger log = LoggerFactory.getLogger(SchedulerOne.class);
 5
 6    @Scheduled(fixedRate = 2000)
 7    public void logExample() {
 8        log.trace("This is TRACE level message from class: {}", this.getClass().getSimpleName());
 9        log.debug("This is DEBUG level message from class: {}", this.getClass().getSimpleName());
10        log.info("This is INFO level message from class: {}", this.getClass().getSimpleName());
11    }
12}

Druga klasa dodająca wpisy do logów AnotherScheduler.java

 1@Component
 2class AnotherScheduler {
 3
 4    private static final Logger log = LoggerFactory.getLogger(AnotherScheduler.class);
 5
 6    @Scheduled(fixedRate = 2000)
 7    public void logExample() {
 8        log.trace("This is TRACE level message from class: {}", this.getClass().getSimpleName());
 9        log.debug("This is DEBUG level message from class: {}", this.getClass().getSimpleName());
10        log.info("This is INFO level message from class: {}", this.getClass().getSimpleName());
11    }
12}
  1. Uruchamiamy aplikację
1./gradlew :bootRun

Co 2 sekundy pokazują się logi z 2 klas ma poziomie INFO

12022-02-13 23:49:11.086  INFO 65959 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
22022-02-13 23:49:11.087  INFO 65959 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
3
42022-02-13 23:49:13.086  INFO 65959 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
52022-02-13 23:49:13.086  INFO 65959 ---[   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
6
72022-02-13 23:49:15.086  INFO 65959 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
82022-02-13 23:49:15.086  INFO 65959 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
  1. Sprawdzenie aktualnego poziomu logowania ustawionego w aplikacji dla klasy SchedulerOne.

Wywołujemy metodę GET dodając do endpint'a nazwę oraz pakiet klasy pl.speedlog.example.logging_level.SchedulerOne.

1curl -s http://localhost:8080/actuator/loggers/pl.speedlog.example.logging_level.SchedulerOne | jq '.'

Wynik

1{
2  "configuredLevel": null,
3  "effectiveLevel": "INFO"
4}
  • configuredLevel - pokazuje poziom logowania ustawiony w konfiguracji dla tej konkretnej klasy. Wartość null oznacza, że poziom ten nie jest ustawiony, więc aplikacja będzie korzystać domyślnego poziomu logowania ustawionego dla całej aplikcji - poziom ROOT.
  • effectiveLevel - pokazuje realny poziom logowania. W tym przypadku poziom logowania INFO wynika z poziomu logowania ustawionego dla całej aplikacji - poziom ROOT.
  1. Ustawienie logowania klasy SchedulerOne na naziom DEBUG

Wywołujemy metodę POST, gdzie w endpoint podajemy nazwę klasy wraz z pakietem pl.speedlog.example.logging_level.SchedulerOne. W body wywołania przekazujemy json'a z nowym poziomem logowania:

1{
2  "configuredLevel": "DEBUG"
3}

Przykład wywołania

1curl -i -X POST -H 'Content-Type: application/json' -d '{"configuredLevel": "DEBUG"}' \
2      http://localhost:8080/actuator/loggers/pl.speedlog.example.logging_level.SchedulerOne

W logach uruchomionej aplikacji widać, że co 2 sekundy z klasy SchedulerOne pojawiły się logi na poziomie DEBUG.

12022-02-13 00:14:31.726  INFO 67510 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
22022-02-13 00:14:31.726 DEBUG 67510 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is DEBUG level message from class: SchedulerOne
32022-02-13 00:14:31.726  INFO 67510 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
4
52022-02-13 00:14:33.726  INFO 67510 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
62022-02-13 00:14:33.726 DEBUG 67510 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is DEBUG level message from class: SchedulerOne
72022-02-13 00:14:33.726  INFO 67510 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
  1. Ustawienie domyślnego poziomu (ROOT) logowania na DEBUG

Przykład wywołania

1curl -i -X POST -H 'Content-Type: application/json' -d '{"configuredLevel": "DEBUG"}' \
2      http://localhost:8080/actuator/loggers/ROOT

Po wywołaniu tego polecenia w logach widzimy, że teraz obie klasy AnotherScheduler oraz SchedulerOne logują na poziomie DEBUG.

12022-02-13 08:54:33.843 DEBUG 13113 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is DEBUG level message from class: AnotherScheduler
22022-02-13 08:54:33.843  INFO 13113 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
32022-02-13 08:54:33.843 DEBUG 13113 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is DEBUG level message from class: SchedulerOne
42022-02-13 08:54:33.843  INFO 13113 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
5
62022-02-13 08:54:35.843 DEBUG 13113 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is DEBUG level message from class: AnotherScheduler
72022-02-13 08:54:35.843  INFO 13113 --- [   scheduling-1] p.s.e.logging_level.AnotherScheduler     : This is INFO level message from class: AnotherScheduler
82022-02-13 08:54:35.843 DEBUG 13113 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is DEBUG level message from class: SchedulerOne
92022-02-13 08:54:35.843  INFO 13113 --- [   scheduling-1] p.s.example.logging_level.SchedulerOne   : This is INFO level message from class: SchedulerOne
  1. Usunięcie skonfigurowanego poziomu logowania

W celu usunięcia ustawionego poziomu logowania dla konkretnej klasy wystarczy przekazać wartość null. Poniżej polecenie cofające konfigurację kategorii ROOT. Po tej zmianie klasa AnotherScheduler ponownie pokazuje logi tylko na poziomie INFO.

1curl -i -X POST -H 'Content-Type: application/json' -d '{"configuredLevel": null}' \
2      http://localhost:8080/actuator/loggers/ROOT
Ostrzeżenie

Zmiana poziomów logowania przez wywołanie endpointu actuatora nie jest stała - po restarcie aplikacji ustawione poziomy logowania wracają do tych, które są ustawione w konfiguracji aplikacji.

Co w przypadku kiedy mamy uruchomionych wiele instancji aplikacji?

Opcji jest kilka. Pierwszą z nich może być ręczne uruchomienie poleceń dla każdej z instancji.

Jeżeli korzystacie z ansible poniżej wrzucam playbook'a, który uruchamia konfigurację poziomu logowania dla grupy serwerów.

Zapiszmy playbooka pod nazwą change-logging-level.yaml. Adres GIST'a: gist.github.com/speedlog/1efb9996d3b9813407b3814b3a462744

 1---
 2- hosts: "{{ nodes }}"   
 3  gather_facts: no 
 4  vars:
 5    - category: ROOT # pass here ROOT or package or classname with package
 6    - level: INFO # pass here logging level or null
 7  tasks:
 8    - name: "Change logging level to '{{ level }}' for '{{ category }}'"
 9      when: level != "null"
10      uri:
11        url: "http://localhost:8080/actuator/loggers/{{ category }}"
12        method: POST
13        status_code: 204
14        body: "{\"configuredLevel\": \"{{ level }}\" }"
15        body_format: json
16        headers:
17          Content-Type: "application/json"
18    - name: "Remove configured logging for '{{ category }}'"
19      when: level == "null"
20      uri:
21        url: "http://localhost:8080/actuator/loggers/{{ category }}"
22        method: POST
23        status_code: 204
24        body: "{\"configuredLevel\": null }"
25        body_format: json
26        headers:
27          Content-Type: "application/json"

Możemy teraz uruchomić playbooka podając zmienne:

  • nodes - lista adresów IP lub nazwa grupy serwerów, na której działa aplikacja
  • category - ROOT lub nazwa pakietu lub nazwa pakietu i klasy, dla których będzie ustawiany poziom logowania
  • level - poziom logowania np. DEBUG lub wartość null

Przykład wywołania ustawiającego poziom TRACE dla klasy pl.speedlog.example.logging_level.AnotherScheduler.

1ansible-playbook change-logging-level.yaml \
2--extra-vars "nodes=localhost category=pl.speedlog.example.logging_level.AnotherScheduler level=TRACE"

Dobre praktyki

Zaprezentowana aplikacja i jej konfiguracja jest uproszczona na potrzeby artykułu. Konfigurując bibliotekę actuator na produkcji dobrą praktyką jest:

  1. Wystawienie endpointów actuatora na osobnym porcie i interfejsie sieciowym.
  2. Autoryzowanie dostępu do actuatora np. za pomocą basic auth.
  3. Dostęp do endpointów actuatora szyfrowanym kanałem (https).

Repozytorium GIT

Na github możecie znaleźć przykładową aplikację gotową do przećwiczenia powyższych poleceń.

github.com/speedlog/springboot-change-logging-level

  1. https://docs.spring.io/spring-boot/docs/current/reference/html/actuator.html#actuator.loggers ↩︎

Tłumaczenia: