В этой главе мы настроим логирование приложения в Kubernetes и разберём его особенности, а также сделаем структурированный формат логов для последующего парсинга системами сбора и анализа логов.

Приложение в этой главе не предназначено для использования в production без доработки. Готовое к работе в production приложение мы получим в конце руководства.

Подготовка окружения

Подготовьте рабочее окружение согласно c инструкциями главы “Подготовка окружения”, если это ещё не сделано.

Рабочее окружение работало, но перестало? Инструкции из этой главы не работают? Может помочь:

Работает ли Docker?

Запустим приложение Docker Desktop. Приложению понадобится некоторое время для того, чтобы запустить Docker. Если никаких ошибок в процессе запуска не возникло, то проверим, что Docker запущен и корректно настроен:

docker run hello-world

Результат успешного выполнения команды:

Unable to find image 'hello-world:latest' locally
latest: Pulling from library/hello-world
b8dfde127a29: Pull complete
Digest: sha256:9f6ad537c5132bcce57f7a0a20e317228d382c3cd61edae14650eec68b2b345c
Status: Downloaded newer image for hello-world:latest

Hello from Docker!
This message shows that your installation appears to be working correctly.

При возникновении проблем обратитесь к документации Docker для их устранения.

Запустим приложение Docker Desktop. Приложению понадобится некоторое время для того, чтобы запустить Docker. Если никаких ошибок в процессе запуска не возникло, то проверим, что Docker запущен и корректно настроен:

docker run hello-world

Результат успешного выполнения команды:

Unable to find image 'hello-world:latest' locally
latest: Pulling from library/hello-world
b8dfde127a29: Pull complete
Digest: sha256:9f6ad537c5132bcce57f7a0a20e317228d382c3cd61edae14650eec68b2b345c
Status: Downloaded newer image for hello-world:latest

Hello from Docker!
This message shows that your installation appears to be working correctly.

При возникновении проблем обратитесь к документации Docker для их устранения.

Запустим Docker:

sudo systemctl restart docker

Убедимся, что Docker запустился:

sudo systemctl status docker

Результат выполнения команды, если Docker успешно запущен:

● docker.service - Docker Application Container Engine
     Loaded: loaded (/lib/systemd/system/docker.service; enabled; vendor preset: enabled)
     Active: active (running) since Thu 2021-06-24 13:05:17 MSK; 13s ago
TriggeredBy: ● docker.socket
       Docs: https://docs.docker.com
   Main PID: 2013888 (dockerd)
      Tasks: 36
     Memory: 100.3M
     CGroup: /system.slice/docker.service
             └─2013888 /usr/bin/dockerd -H fd:// --containerd=/run/containerd/containerd.sock

dockerd[2013888]: time="2021-06-24T13:05:16.936197880+03:00" level=warning msg="Your kernel does not support CPU realtime scheduler"
dockerd[2013888]: time="2021-06-24T13:05:16.936219851+03:00" level=warning msg="Your kernel does not support cgroup blkio weight"
dockerd[2013888]: time="2021-06-24T13:05:16.936224976+03:00" level=warning msg="Your kernel does not support cgroup blkio weight_device"
dockerd[2013888]: time="2021-06-24T13:05:16.936311001+03:00" level=info msg="Loading containers: start."
dockerd[2013888]: time="2021-06-24T13:05:17.119938367+03:00" level=info msg="Loading containers: done."
dockerd[2013888]: time="2021-06-24T13:05:17.134054120+03:00" level=info msg="Daemon has completed initialization"
systemd[1]: Started Docker Application Container Engine.
dockerd[2013888]: time="2021-06-24T13:05:17.148493957+03:00" level=info msg="API listen on /run/docker.sock"

Теперь проверим, что Docker доступен и корректно настроен:

docker run hello-world

Результат успешного выполнения команды:

Unable to find image 'hello-world:latest' locally
latest: Pulling from library/hello-world
b8dfde127a29: Pull complete
Digest: sha256:9f6ad537c5132bcce57f7a0a20e317228d382c3cd61edae14650eec68b2b345c
Status: Downloaded newer image for hello-world:latest

Hello from Docker!
This message shows that your installation appears to be working correctly.

При возникновении проблем обратитесь к документации Docker для их устранения.

Перезагружали компьютер после подготовки окружения?

Запустим кластер minikube, уже настроенный в начале главы “Подготовка окружения”:

minikube start

Выставим Namespace по умолчанию, чтобы не указывать его при каждом вызове kubectl:

kubectl config set-context minikube --namespace=werf-guide-app

Результат успешного выполнения команды:

😄  minikube v1.20.0 on Ubuntu 20.04
✨  Using the docker driver based on existing profile
👍  Starting control plane node minikube in cluster minikube
🚜  Pulling base image ...
🎉  minikube 1.21.0 is available! Download it: https://github.com/kubernetes/minikube/releases/tag/v1.21.0
💡  To disable this notice, run: 'minikube config set WantUpdateNotification false'

🔄  Restarting existing docker container for "minikube" ...
🐳  Preparing Kubernetes v1.20.2 on Docker 20.10.6 ...
🔎  Verifying Kubernetes components...
    ▪ Using image gcr.io/google_containers/kube-registry-proxy:0.4
    ▪ Using image k8s.gcr.io/ingress-nginx/controller:v0.44.0
    ▪ Using image registry:2.7.1
    ▪ Using image docker.io/jettech/kube-webhook-certgen:v1.5.1
    ▪ Using image docker.io/jettech/kube-webhook-certgen:v1.5.1
    ▪ Using image gcr.io/k8s-minikube/storage-provisioner:v5
🔎  Verifying registry addon...
🔎  Verifying ingress addon...
🌟  Enabled addons: storage-provisioner, registry, default-storageclass, ingress
🏄  Done! kubectl is now configured to use "minikube" cluster and "werf-guide-app" namespace by default

Убедитесь, что вывод команды содержит строку:

Restarting existing docker container for "minikube"

Если её нет, значит был создан новый кластер minikube вместо использования старого. В таком случае повторите установку рабочего окружения с minikube с самого начала.

Теперь запустите команду в фоновом PowerShell-терминале и не закрывайте его:

minikube tunnel --cleanup=true

Запустим кластер minikube, уже настроенный в начале главы “Подготовка окружения”:

minikube start --namespace werf-guide-app

Выставим Namespace по умолчанию, чтобы не указывать его при каждом вызове kubectl:

kubectl config set-context minikube --namespace=werf-guide-app

Результат успешного выполнения команды:

😄  minikube v1.20.0 on Ubuntu 20.04
✨  Using the docker driver based on existing profile
👍  Starting control plane node minikube in cluster minikube
🚜  Pulling base image ...
🎉  minikube 1.21.0 is available! Download it: https://github.com/kubernetes/minikube/releases/tag/v1.21.0
💡  To disable this notice, run: 'minikube config set WantUpdateNotification false'

🔄  Restarting existing docker container for "minikube" ...
🐳  Preparing Kubernetes v1.20.2 on Docker 20.10.6 ...
🔎  Verifying Kubernetes components...
    ▪ Using image gcr.io/google_containers/kube-registry-proxy:0.4
    ▪ Using image k8s.gcr.io/ingress-nginx/controller:v0.44.0
    ▪ Using image registry:2.7.1
    ▪ Using image docker.io/jettech/kube-webhook-certgen:v1.5.1
    ▪ Using image docker.io/jettech/kube-webhook-certgen:v1.5.1
    ▪ Using image gcr.io/k8s-minikube/storage-provisioner:v5
🔎  Verifying registry addon...
🔎  Verifying ingress addon...
🌟  Enabled addons: storage-provisioner, registry, default-storageclass, ingress
🏄  Done! kubectl is now configured to use "minikube" cluster and "werf-guide-app" namespace by default

Убедитесь, что вывод команды содержит строку:

Restarting existing docker container for "minikube"

Если её нет, значит был создан новый кластер minikube вместо использования старого. В таком случае повторите установку рабочего окружения с minikube с самого начала.

Случайно удаляли Namespace приложения?

Если вы непреднамеренно удалили Namespace приложения, то необходимо выполнить следующие команды, чтобы продолжить прохождение руководства:

kubectl create namespace werf-guide-app
kubectl create secret docker-registry registrysecret \
  --docker-server='https://index.docker.io/v1/' \
  --docker-username='<ИМЯ ПОЛЬЗОВАТЕЛЯ DOCKER HUB>' \
  --docker-password='<ПАРОЛЬ ПОЛЬЗОВАТЕЛЯ DOCKER HUB>'

Результат успешного выполнения команды:

namespace/werf-guide-app created
secret/registrysecret created
Ничего не помогло, окружение или инструкции по-прежнему не работают?

Если ничего не помогло, то пройдите главу “Подготовка окружения” с начала, подготовив новое окружение с нуля. Если и это не помогло, тогда, пожалуйста, расскажите о своей проблеме в нашем Telegram или оставьте Issue на GitHub, и мы обязательно вам поможем.

Подготовка репозитория

Обновим существующий репозиторий с приложением:

Выполним следующий набор команд в PowerShell:

cd ~/werf-guide/app

# Чтобы увидеть, какие изменения мы собрались вносить далее в этой главе, заменим все файлы приложения
# в репозитории новыми, уже измененными файлами приложения, которые содержат описанные далее изменения.
git rm -r .
cp -Recurse -Force ~/werf-guide/guides/examples/java_springboot/020_logging/* .
git add .
git commit -m WIP
Посмотреть, какие именно изменения мы произведём
# Показать, какие файлы мы собираемся изменить.
git show --stat
# Показать изменения.
git show

Выполним следующий набор команд в Bash:

cd ~/werf-guide/app

# Чтобы увидеть, какие изменения мы собрались вносить далее в этой главе, заменим все файлы приложения
# в репозитории новыми, уже измененными файлами приложения, которые содержат описанные далее изменения.
git rm -r .
cp -rf ~/werf-guide/guides/examples/java_springboot/020_logging/. .
git add .
git commit -m WIP
Посмотреть, какие именно изменения мы произведём
# Показать, какие файлы мы собираемся изменить.
git show --stat
# Показать изменения.
git show

Не работает? Попробуйте инструкции на вкладке “Начинаю проходить руководство с этой главы” выше.

Подготовим новый репозиторий с приложением:

Выполним следующий набор команд в PowerShell:

# Склонируем репозиторий с примерами в ~/werf-guide/guides, если он ещё не был склонирован.
if (-not (Test-Path ~/werf-guide/guides)) {
  git clone https://github.com/werf/werf-guides $env:HOMEPATH/werf-guide/guides
}

# Скопируем файлы приложения (пока без изменений) в ~/werf-guide/app.
rm -Recurse -Force ~/werf-guide/app
cp -Recurse -Force ~/werf-guide/guides/examples/java_springboot/010_basic_app ~/werf-guide/app

# Сделаем из директории ~/werf-guide/app git-репозиторий.
cd ~/werf-guide/app
git init
git add .
git commit -m initial

# Чтобы увидеть, какие изменения мы собрались вносить далее в этой главе, заменим все файлы приложения
# в репозитории новыми, уже измененными файлами приложения, которые содержат описанные далее изменения.
git rm -r .
cp -Recurse -Force ~/werf-guide/guides/examples/java_springboot/020_logging/* .
git add .
git commit -m WIP
Посмотреть, какие именно изменения мы произведём
# Показать, какие файлы мы собираемся изменить.
git show --stat
# Показать изменения.
git show

Выполним следующий набор команд в Bash:

# Склонируем репозиторий с примерами в ~/werf-guide/guides, если он ещё не был склонирован.
test -e ~/werf-guide/guides || git clone https://github.com/werf/werf-guides ~/werf-guide/guides

# Скопируем файлы приложения (пока без изменений) в ~/werf-guide/app.
rm -rf ~/werf-guide/app
cp -rf ~/werf-guide/guides/examples/java_springboot/010_basic_app ~/werf-guide/app

# Сделаем из директории ~/werf-guide/app git-репозиторий.
cd ~/werf-guide/app
git init
git add .
git commit -m initial

# Чтобы увидеть, какие изменения мы собрались вносить далее в этой главе, заменим все файлы приложения
# в репозитории новыми, уже измененными файлами приложения, которые содержат описанные далее изменения.
git rm -r .
cp -rf ~/werf-guide/guides/examples/java_springboot/020_logging/. .
git add .
git commit -m WIP
Посмотреть, какие именно изменения мы произведём
# Показать, какие файлы мы собираемся изменить.
git show --stat
# Показать изменения.
git show

Вывод логов в stdout

У задеплоенных в Kubernetes приложений логи всегда должны отправляться в stdout/stderr. Отправка логов в стандартные потоки делает логи доступными для Kubernetes и систем сбора логов, помогает избегать потерь логов при пересоздании контейнеров, а также переполнения логами дисков Kubernetes-узлов при сохранении их в файлах внутри контейнеров.

По умолчанию Spring Boot пишет логи в stdout, поэтому для вывода логов не требуется дополнительных действий.

Формат логов

Логи Spring Boot-приложения по умолчанию представляют собой обычный текст:

2022-01-18 14:26:03.260  INFO 71634 --- [           main] com.flant.werfguidesapp.Application      : No active profile set, falling back to default profiles: default
2022-01-18 14:26:04.637  INFO 71634 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat initialized with port(s): 8080 (http)
2022-01-18 14:26:04.650  INFO 71634 --- [           main] o.apache.catalina.core.StandardService   : Starting service [Tomcat]
2022-01-18 14:26:04.651  INFO 71634 --- [           main] org.apache.catalina.core.StandardEngine  : Starting Servlet engine: [Apache Tomcat/9.0.55]
2022-01-18 14:26:04.725  INFO 71634 --- [           main] o.a.c.c.C.[Tomcat].[localhost].[/]       : Initializing Spring embedded WebApplicationContext
2022-01-18 14:26:04.725  INFO 71634 --- [           main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 1329 ms
2022-01-18 14:26:05.230  INFO 71634 --- [           main] o.s.b.w.embedded.tomcat.TomcatWebServer  : Tomcat started on port(s): 8080 (http) with context path ''
2022-01-18 14:26:05.259  INFO 71634 --- [           main] com.flant.werfguidesapp.Application      : Started Application in 2.927 seconds (JVM running for 6.405)

java.net.SocketTimeoutException:Receive timed out
    at j.n.PlainDatagramSocketImpl.receive0(Native Method)[na:1.8.0_151]
    at j.n.AbstractPlainDatagramSocketImpl.receive(AbstractPlainDatagramSocketImpl.java:143)[^]
    at j.n.DatagramSocket.receive(DatagramSocket.java:812)[^]
    at o.s.n.SntpClient.requestTime(SntpClient.java:213)[classes/]
 ...

Обратите внимание, что логи Spring и текст исключений перемешаны и имеют разный формат. Такой текст парсить системами сбора и анализа логов будет очень непросто.

Эту проблему можно решить, если отдавать логи в структурированном формате вроде JSON: система сбора логов обычно очень просто распознает и разбирает JSON-логи, а также корректно обрабатывает логи/сообщения в неожиданных, неструктурированных форматах, которые могут вклиниваться между логами в JSON-формате.

Для этого нужно настроить приложение на вывод логов в формате JSON. Для начала, подключим нужные зависимости в файле pom.xml.

...
<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-web</artifactId>
	<exclusions>
		<exclusion>
			<groupId>org.springframework.boot</groupId>
			<artifactId>spring-boot-starter-logging</artifactId>
		</exclusion>
	</exclusions>
</dependency>
...
<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>
<dependency>
	<groupId>com.fasterxml.jackson.core</groupId>
	<artifactId>jackson-databind</artifactId>
	<version>2.10.3</version>
	<exclusions>
		<exclusion>
			<groupId>com.fasterxml.jackson.core</groupId>
			<artifactId>jackson-core</artifactId>
		</exclusion>
		<exclusion>
			<groupId>com.fasterxml.jackson.core</groupId>
			<artifactId>jackson-annotations</artifactId>
		</exclusion>
	</exclusions>
</dependency>
<dependency>
	<groupId>com.fasterxml.jackson.core</groupId>
	<artifactId>jackson-core</artifactId>
	<version>2.10.3</version>
</dependency>
<dependency>
	<groupId>com.fasterxml.jackson.core</groupId>
	<artifactId>jackson-annotations</artifactId>
	<version>2.10.3</version>
</dependency>
... <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-web</artifactId> <exclusions> <exclusion> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-logging</artifactId> </exclusion> </exclusions> </dependency> ... <dependency> <groupId>org.springframework.boot</groupId> <artifactId>spring-boot-starter-log4j2</artifactId> </dependency> <dependency> <groupId>com.fasterxml.jackson.core</groupId> <artifactId>jackson-databind</artifactId> <version>2.10.3</version> <exclusions> <exclusion> <groupId>com.fasterxml.jackson.core</groupId> <artifactId>jackson-core</artifactId> </exclusion> <exclusion> <groupId>com.fasterxml.jackson.core</groupId> <artifactId>jackson-annotations</artifactId> </exclusion> </exclusions> </dependency> <dependency> <groupId>com.fasterxml.jackson.core</groupId> <artifactId>jackson-core</artifactId> <version>2.10.3</version> </dependency> <dependency> <groupId>com.fasterxml.jackson.core</groupId> <artifactId>jackson-annotations</artifactId> <version>2.10.3</version> </dependency>

Добавление поддержки тегирования логов выходит за рамки этого руководства, но может быть реализовано при необходимости.

Добавим файл log4j2-spring.xml c настройками логгера в каталог /src/main/resources/:

<?xml version="1.0" encoding="UTF-8"?>
<Configuration>
	<Appenders>
		<Console name="Console" target="SYSTEM_OUT">
			<JsonLayout complete="false" compact="true"
				eventEol="true"></JsonLayout>
			<PatternLayout
				pattern="%style{%d{ISO8601}}{black} %highlight{%-5level }[%style{%t}{bright,blue}] %style{%C{1.}}{bright,yellow}: %msg%n%throwable" />
		</Console>
	</Appenders>
	<Loggers>
		<!-- LOG everything at INFO level -->
		<Root level="info">
			<AppenderRef ref="Console" />
		</Root>
		<Logger name="main.logger" level="trace"></Logger>
	</Loggers>
</Configuration>
<?xml version="1.0" encoding="UTF-8"?> <Configuration> <Appenders> <Console name="Console" target="SYSTEM_OUT"> <JsonLayout complete="false" compact="true" eventEol="true"></JsonLayout> <PatternLayout pattern="%style{%d{ISO8601}}{black} %highlight{%-5level }[%style{%t}{bright,blue}] %style{%C{1.}}{bright,yellow}: %msg%n%throwable" /> </Console> </Appenders> <Loggers> <!-- LOG everything at INFO level --> <Root level="info"> <AppenderRef ref="Console" /> </Root> <Logger name="main.logger" level="trace"></Logger> </Loggers> </Configuration>

ОБРАТИТЕ ВНИМАНИЕ! Эти изменения и нижеследующие не нужно выполнять самим, здесь мы просто рассказываем, как получили приложение, которое используется в примере. К выполнению предназначена глава «Проверка работоспособности».

Управление уровнем логирования

По умолчанию уровень логирования приложения для production-окружения задан как info. Но иногда возникает необходимость изменить это.

К примеру, при диагностике проблем в production может помочь переключение логирования с info на debug для получения дополнительной отладочной информации. Но если приложение работает в большом количестве реплик, то переключать все реплики приложения на debug может быть не лучшей идеей, т.к. это может сказаться на безопасности, а также сильно увеличить нагрузку на компоненты, ответственные за сбор, хранение и анализ логов.

Решить эту проблему поможет возможность выставлять уровень логирования через переменную окружения. Это позволит, например, запустить рядом с уже существующим Deployment’ом приложения, у которого уровень логирования info, точно такой же Deployment, но в одной реплике и с уровнем логирования debug. Также для этого нового Deployment’а мы можем отключить централизованный сбор логов, если таковой имеется. Всё это в совокупности позволит нам не перегружать системы сбора логов и не сохранять в них потенциально небезопасные отладочные логи.

Возможность указывать уровень логирования через переменную окружения LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB реализуется так:

...
env:
- name: LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB
  value: DEBUG
... env: - name: LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB value: DEBUG

Мы сами определили переменную окружения для управления уровнем логирования. Ее имя аналогично параметру logging.level.org.springframework.web, который можно задать в файле настроек приложения application.properties.

Если переменная окружения не указана, будет использован стандартный уровень info.

Отображение логов при деплое с werf

По умолчанию werf при деплое показывает логи всех контейнеров приложения и делает это до тех пор, пока они не перейдут в состояние Ready. С помощью специальных werf-аннотаций можно организовать фильтрацию логов и выводить только те строки, которые удовлетворяют заданным шаблонам. В дополнение к этому можно настроить вывод логов только для определённых контейнеров.

К примеру, следующим образом можно отключить вывод контейнера с именем container_name при выкате:

annotations:
  werf.io/skip-logs-for-containers: container_name

А в следующем примере показывается, как можно выводить только те строки, которые удовлетворяют заданному регулярному выражению:

annotations:
  werf.io/log-regex: ".*ERROR.*"

Список всех доступных аннотаций можно посмотреть здесь.

Эти аннотации влияют только на то, как логи отображаются при деплое с werf. Они не оказывают никакого влияния на развертываемое приложение или его конфигурацию. Логи по-прежнему доступны в stdout/stderr контейнера в первоначальном виде.

Проверка работоспособности

Теперь попробуем развернуть приложение:

werf converge --repo <ИМЯ ПОЛЬЗОВАТЕЛЯ DOCKER HUB>/werf-guide-app

Ожидаемый результат:

┌ ⛵ image app
│ Use cache image for app/dockerfile
│      name: <ИМЯ ПОЛЬЗОВАТЕЛЯ DOCKER HUB>/werf-guide-app:3645079de60ff0f034765087f309ffd2189da4fff66fe284feb3a064-1642509706054
│        id: 085a4e8f0fa9
│   created: 2022-01-18 15:41:45 +0300 MSK
│      size: 209.5 MiB
└ ⛵ image app (2.81 seconds)

┌ Waiting for release resources to become ready
│ ┌ Status progress
│ │ DEPLOYMENT                                                                                                  REPLICAS            AVAILABLE             UP-TO-DATE                           
│ │ werf-guide-app                                                                                              1/1                 1                     1                                    
│ └ Status progress
└ Waiting for release resources to become ready (0.03 seconds)

Release "werf-guide-app" has been upgraded. Happy Helming!
NAME: werf-guide-app
LAST DEPLOYED: Tue Jan 18 15:47:53 2022
NAMESPACE: werf-guide-app
STATUS: deployed
REVISION: 46
TEST SUITE: None
Running time 6.12 seconds

Выполним пару запросов для генерации логов:

curl http://werf-guide-app.test/ping       # Вернёт "pong" и код возврата 200.
curl http://werf-guide-app.test/not_found  # Ничего не вернёт, только код возврата 404.

В результате выполнения запросов возвращаемые сервером коды возврата отображаться не будут, но их можно посмотреть в логах. Проверим их:

kubectl logs deploy/werf-guide-app | grep DEBUG

Ожидаемый результат:

{"instant":{"epochSecond":1642518222,"nanoOfSecond":411412000},"thread":"http-nio-8080-exec-1","level":"DEBUG","loggerName":"org.springframework.web.servlet.DispatcherServlet","message":"GET \"/ping\", parameters={}","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1642518222,"nanoOfSecond":421270000},"thread":"http-nio-8080-exec-1","level":"DEBUG","loggerName":"org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping","message":"Mapped to com.flant.werfguidesapp.controllers.PingController#Ping(HttpServletRequest)","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1642518222,"nanoOfSecond":447590000},"thread":"http-nio-8080-exec-1","level":"DEBUG","loggerName":"org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor","message":"Using 'text/plain', given [*/*] and supported [text/plain, */*, text/plain, */*, application/json, application/*+json, application/json, application/*+json]","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1642518222,"nanoOfSecond":448685000},"thread":"http-nio-8080-exec-1","level":"DEBUG","loggerName":"org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor","message":"Writing [\"pong<LF>\"]","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1642518222,"nanoOfSecond":479727000},"thread":"http-nio-8080-exec-1","level":"DEBUG","loggerName":"org.springframework.web.servlet.DispatcherServlet","message":"Completed 200 OK","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":19,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":272066000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.DispatcherServlet","message":"GET \"/not_found\", parameters={}","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":277174000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.handler.SimpleUrlHandlerMapping","message":"Mapped to ResourceHttpRequestHandler [classpath [META-INF/resources/], classpath [resources/], classpath [static/], classpath [public/], ServletContext [/]]","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":281053000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.resource.ResourceHttpRequestHandler","message":"Resource not found","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":281489000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.DispatcherServlet","message":"Completed 404 NOT_FOUND","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":286808000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.DispatcherServlet","message":"\"ERROR\" dispatch for GET \"/error\", parameters={}","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":288721000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping","message":"Mapped to org.springframework.boot.autoconfigure.web.servlet.error.BasicErrorController#error(HttpServletRequest)","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":297948000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor","message":"Using 'application/json', given [*/*] and supported [application/json, application/*+json, application/json, application/*+json]","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":298565000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.mvc.method.annotation.HttpEntityMethodProcessor","message":"Writing [{timestamp=Tue Jan 18 15:03:51 GMT 2022, status=404, error=Not Found, path=/not_found}]","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}
{"instant":{"epochSecond":1642518231,"nanoOfSecond":311389000},"thread":"http-nio-8080-exec-2","level":"DEBUG","loggerName":"org.springframework.web.servlet.DispatcherServlet","message":"Exiting from \"ERROR\" dispatch, status 404","endOfBatch":false,"loggerFqcn":"org.apache.commons.logging.LogAdapter$Log4jLog","threadId":20,"threadPriority":5}

Как видим, логи теперь отдаются в JSON и легко могут быть распарсены. Некоторые логи по-прежнему отдаются обычным текстом, но главное, что системы сбора логов теперь не будут пытаться распарсить логи приложения и часть других логов так, как будто они имеют один формат: JSON-логи сохранятся отдельно и для них будет возможен поиск/фильтрация только по нужным полям.

назад
далее