In this chapter, we will learn about application logging in Kubernetes and implement it. Additionally, we will introduce a structured logging format to make it ready for parsing by log collection and analysis systems.

The application described in this chapter is not intended for use in production environments as-is. Note that successful completion of this entire guide is required to create a production-ready application.

Preparing the environment

Prepare the environment using the instructions provided in the “Preparing the environment” chapter (if you have not done this already).

Please, refer to these helpful resources if the environment has stopped working or instructions in this chapter don’t work:

Is Docker running?

Let’s launch Docker Desktop. It takes some time for this application to start Docker. If there are no errors during the startup process, check that Docker is running and is properly configured:

docker run hello-world

You will see the following output if the command completes successfully:

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.

Should you have any problems, please refer to the Docker documentation.

Let’s launch the Docker Desktop application. It takes some time for the application to start Docker. If there are no errors during the startup process, then check that Docker is running and is properly configured:

docker run hello-world

You will see the following output if the command completes successfully:

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.

Should you have any problems, please refer to the Docker documentation.

Start Docker:

sudo systemctl restart docker

Make sure that Docker is running:

sudo systemctl status docker

If the Docker start is successful, you will see the following output:

● 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"

Now let’s check if Docker is available and its configuration is correct:

docker run hello-world

You will see the following output if the command completes successfully:

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.

Should you have any problems, please refer to the Docker documentation.

Have you restarted the computer after setting up the environment?

Let’s start the minikube cluster we have already configured in the “Preparing the environment” chapter:

minikube start

Set the default Namespace so that you don’t have to specify it every time you invoke kubectl:

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

You will see the following output if the command completes successfully:

😄  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

Make sure that the command output contains the following line:

Restarting existing docker container for "minikube"

Its absence means that a new minikube cluster was created instead of using the old one. In this case, repeat all the steps required to install the environment using minikube.

Now run the command in the background PowerShell terminal (do not close its window):

minikube tunnel --cleanup=true

Let’s start the minikube cluster we have already configured in the “Preparing the environment” chapter:

minikube start --namespace werf-guide-app

Set the default Namespace so that you don’t have to specify it every time you invoke kubectl:

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

You will see the following output if the command completes successfully:

😄  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

Make sure that the command output contains the following line:

Restarting existing docker container for "minikube"

Its absence means that a new minikube cluster was created instead of using the old one. In this case, repeat all the steps required to install the environment from scratch using minikube.

Did you accidentally delete the application's Namespace?

If you have inadvertently deleted Namespace of the application, you must run the following commands to proceed with the guide:

kubectl create namespace werf-guide-app
kubectl create secret docker-registry registrysecret \
  --docker-server='https://index.docker.io/v1/' \
  --docker-username='<Docker Hub username>' \
  --docker-password='<Docker Hub password>'

You will see the following output if the command completes successfully:

namespace/werf-guide-app created
secret/registrysecret created
Nothing helps; the environment or instructions keep failing.

If nothing worked, repeat all the steps described in the “Preparing the environment” chapter and create a new environment from scratch. If creating an environment from scratch did not help either, please, tell us about your problem in our Telegram chat or create an issue on GitHub. We will be happy to help you!

Preparing the repository

Update the existing repository containing the application:

Run the following commands in PowerShell:

cd ~/werf-guide/app

# To see what changes we will make later in this chapter, let's replace all the application files
# in the repository with new, modified files containing the changes described below.
git rm -r .
cp -Recurse -Force ~/werf-guide/guides/examples/java_springboot/020_logging/* .
git add .
git commit -m WIP
What changes we will make
# Enter the command below to show the files we are going to change.
git show --stat
# Enter the command below to show the changes that will be made.
git show

Run the following commands in Bash:

cd ~/werf-guide/app

# To see what changes we will make later in this chapter, let's replace all the application files
# in the repository with new, modified files containing the changes described below.
git rm -r .
cp -rf ~/werf-guide/guides/examples/java_springboot/020_logging/. .
git add .
git commit -m WIP
What changes we will make
# Enter the command below to show files we are going to change.
git show --stat
# Enter the command below to show the changes that will be made.
git show

Doesn’t work? Try the instructions on the “I am just starting from this chapter” tab above.

Prepare a new repository with the application:

Run the following commands in PowerShell:

# Clone the example repository to ~/werf-guide/guides (if you have not cloned it yet).
if (-not (Test-Path ~/werf-guide/guides)) {
  git clone https://github.com/werf/werf-guides $env:HOMEPATH/werf-guide/guides
}

# Copy the (unchanged) application files to ~/werf-guide/app.
rm -Recurse -Force ~/werf-guide/app
cp -Recurse -Force ~/werf-guide/guides/examples/java_springboot/010_basic_app ~/werf-guide/app

# Make the ~/werf-guide/app directory a git repository.
cd ~/werf-guide/app
git init
git add .
git commit -m initial

# To see what changes we will make later in this chapter, let's replace all the application files
# in the repository with new, modified files containing the changes described below.
git rm -r .
cp -Recurse -Force ~/werf-guide/guides/examples/java_springboot/020_logging/* .
git add .
git commit -m WIP
What changes we will make
# Enter the command below to show the files we are going to change.
git show --stat
# Enter the command below to show the changes that will be made.
git show

Run the following commands in Bash:

# Clone the example repository to ~/werf-guide/guides (if you have not cloned it yet).
test -e ~/werf-guide/guides || git clone https://github.com/werf/werf-guides ~/werf-guide/guides

# Copy the (unchanged) application files to ~/werf-guide/app.
rm -rf ~/werf-guide/app
cp -rf ~/werf-guide/guides/examples/java_springboot/010_basic_app ~/werf-guide/app

# Make the ~/werf-guide/app directory a git repository.
cd ~/werf-guide/app
git init
git add .
git commit -m initial

# To see what changes we will make later in this chapter, let's replace all the application files
# in the repository with new, modified files containing the changes described below.
git rm -r .
cp -rf ~/werf-guide/guides/examples/java_springboot/020_logging/. .
git add .
git commit -m WIP
What changes we will make
# Enter the command below to show files we are going to change.
git show --stat
# Enter the command below to show the changes that will be made.
git show

Redirecting logs to stdout

All applications deployed to a Kubernetes cluster must write logs to stdout/stderr. Sending logs to standard streams makes them accessible by Kubernetes and log collection systems. Such an approach keeps logs from being deleted when containers are recreated and prevents consuming all available storage on Kubernetes nodes if the output is sent to log files in containers.

By default, Spring Boot writes logs to stdout, so no extra steps are required to output them.

Formatting logs

By default, Spring Boot-based application generate plain text logs:

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/]
 ...

Note that the Spring Boot logs and the exception messages are all mixed up and have different formats. Regular log collection and analysis systems will probably struggle with parsing all this gibberish.

You can solve this problem by shipping logs in a structured JSON-like format. Most log collection systems can both, easily parse JSON and correctly process logs/messages in other (unexpected, unstructured) formats when they sneak in between JSON-formatted logs.

You have to configure the application to output logs in the JSON format to do this. First, enable the necessary dependencies in the pom.xml file.

...
<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>

Log tagging support is beyond the scope of this guide; however, you can implement it if necessary.

Add the log4j2-spring.xml file with the logger settings to the /src/main/resources/ directory:

<?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>

Please Note! The commands in the current section are for illustrative purposes only. They show how a basic application was generated. Only the commands in the “Checking whether the application is running” section are intended to be executed.

Managing the logging level

By default, the application logging level for the production environment is set to info. However, sometimes you may wish to change that.

For example, switching the logging level from info to debug can provide additional debugging information and help in troubleshooting problems in production. However, if the application has many replicas, switching them all to the debug level may not be the best idea. It may affect security and significantly increase the load on log collection, storage, and analysis components.

You can use an environment variable to set the logging level, thus solving the above problem. Using this approach, you can run a single Deployment replica with the debug logging level next to the existing replicas with the info logging level enabled. Moreover, you can disable centralized log collection for this new Deployment (if any). Together, all these measures prevent overloading log collection systems while keeping debug logs containing potentially sensitive information from being streamed to them.

Here is how you can set the logging level using the LOGGING_LEVEL_ORG_SPRINGFRAMEWORK_WEB environment variable:

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

We have defined our own environment variable to control the logging level. Its name is the same as the logging.level.org.springframework.web parameter that you can set in the application.properties file.

If the environment variable is omitted, the info level is used by default.

Displaying logs in werf-based deploys

By default, when deploying, werf prints logs of all application containers until they become Ready. You can filter these logs using custom werf annotations. In this case, werf will only print lines that match the specified patterns. Additionally, you can enable log output for specific containers.

For example, here is how you can disable log output for the container_name container during the deployment:

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

The example below shows how you can enable printing lines that match a pre-defined regular expression:

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

A list of all available annotations can be found here.

Note that these annotations only influence the way logs are shown during the werf-based deployment process. They do not affect the application being deployed or its configuration in any way. You can still use stdout/stderr streams of the container to view raw logs.

Checking whether the application is running

Let’s deploy our application:

werf converge --repo <DOCKER HUB USERNAME>/werf-guide-app

You should see the following output:

┌ ⛵ image app
│ Use cache image for app/dockerfile
│      name: <DOCKER HUB USERNAME>/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

Make several requests in order to generate some logging data:

curl http://werf-guide-app.test/ping       # returns "pong" + 200 OK status code
curl http://werf-guide-app.test/not_found  # no response; returns 404 Not Found

While our requests are being made, we won’t see any codes returned by the server. However, we can find them in the logs — let’s take a look at them:

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

You should see the following output:

{"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}

Note that application logs are now rendered in JSON format, and most log processing systems can easily parse them. At the same time, Rails and Puma logs are streamed in plain text just like before. The main advantage of this approach is that log processing systems will no longer try to parse application logs and Rails/Puma logs as if they have the same format. JSON logs will be stored separately, letting you perform searching/filtering based on the selected fields.

prev
next