How to set up meaningful logging in your Spring Boot application?

No meaningful logs don’t mean manual logs.

Have you ever wished to write your application logs so perfect, that anyone looking at those can understand what has happened in your application? Have you ever wanted to resolve all your application issues just by looking at the logs? If the answer to both of these questions is yes, you’ve landed at the right place. In this article, I am going to show you how you can set up meaningful logs which can help you achieve both of the above goals.

But before we dive in, let’s analyze at the default logs of a simple spring boot application.

Default logs of a Spring Boot application

(Source — https://github.com/akashchandwani/logging-demo/tree/default branch: default)

These application logs have the following columns —

1. Timestamp
2. Logging Level
3. Process Id
4. Thread name
5. Class name
6. Log description

These column values look good but are not sufficient. If someone would look at these logs and would want to find what’s going on in the application, they would be unsuccessful. It is basically due to the following limitation of these default logs—

1. Timezone information is not present — Timestamp without the timezone is an ambiguous time. You won’t be able to guess the actual event time of the event as the server time can run on any timezone.
2. Redundant default INFO logs — All the logs that you see above are default logs that you see when you start your spring boot application. They do tell us what’s going on in the background, but they fail to tell us anything application-specific. Having this combination is like knowing the internal working of your system, but not knowing about the actual job of it. I feel limiting these default logs to the WARN level is necessary to avoid the clutter from your application logs.
3. No core application logs — What good are your logs if there are no application-specific logs. If you see your framework-specific logs, which you are no way going to configure or change? They won’t help you debug your application
4. No User information — Even if you had core application logs, there is no user column to tell you which user was using your app at any point of time. It is super useful to have user information in your logs.
5. No Session Information — Now suppose you have core application logs and user information. Still, without session information, you won’t be able to find whether a particular event occurred in the same session or a different one.
6. No detailed application logs — Now suppose you have all the above information, but those are not detailed enough for you fix a bug in your application? That means that we have failed in the logging. The main objective of this blog is to enable you to find issues in your application, just by looking at the logs.

Now if the above information is convincing enough for you, and you are sure that these default logs won’t do us any good on itself, and we have to add more logs in our application, you are right. Let’s proceed to make these logs more meaningful. Note that we won’t be adding those manually. Instead, we would be using Filters, Aspects and configurations in the application.properties file to automate these. Let’s go through how we can incorporate each of the above limitations of the default logs of spring boot —

1. Add timezone — We can quickly put timezone next to our timestamp by overwriting the default timestamp pattern. The property logging.pattern.dateformat will be useful in this case. In your application.properties, add —

logging.pattern.dateformat=dd-MM-yyyy HH:mm:ss.SSS XXX

2. Change root logging to WARN level — The default INFO logs can be easily removed by making our logging.level.root property to warn. Now you should only see the WARN level and ERROR level logs from your spring boot app. In your application.property add —

logging.level.root=warn

3. Use a Filter to put API information — Now to print API request log and API response status log, create a filter and add those logs there. In this way, all incoming requests and their responses would be printed in your logs. You would also need to add @Component annotation to your Filter class so that it will automatically be wired in your spring boot application. We will be logging the HTTP method and URI before the execution of your API and HTTP response status after the request is completed. Both would be logged at `info` level Here is the code to do the same

4. Add user and session information — If your request is authorized and you have users using your application, you can add his/her userId in the logs. You can extract the username from the UserPrincipal Object. Then to add the user information in the logs, we can use the MDC (Mapped Diagnostic Context) feature of Slf4j. Put the userId attribute in the MDC static variable and then configure your logging.pattern.level property to place if before the logging level variable, i.e., %5p. In the below example, I am adding userId, sessionId, HTTP method and Request-URI to the MDC variable, and adding them before the level pattern.

logging.pattern.level=%X{sessionId} %X{userId} %X{method} %X{request} %5p

5. Add Aspects for detailed logs — Before you can use aspects, you’ll need to make sure you have the following dependency pom.xml file

<dependency>
    <groupId>org.aspectj</groupId>
    <artifactId>aspectjweaver</artifactId>
    <scope>compile</scope>
</dependency>

Now create a pointcut to snoop all the service method as we want to add a log before a method execution with the method information and arguments information, and after a method is executed, we want to add the return type and the value returned from that method. The implementation of the aspect if below —

If your service method parameters are an object or the return type is a custom object, you can add their values to the logs by implementing a toString() method in them. If you are using Lombok, you can add @ToString annotation at the top of that class implementation. Now we would also need to enable TRACE logging for our detailed logs as we have configured our aspect class to print TRACE logs. We can change the logging level below to DEBUG or INFO if we don’t need those detailed logs on any environment.

logging.group.app=com.example.demo
logging.level.app=TRACE

At this point, our application.properties should look something like this —

Now let’s run our application again and make some user operations —

Final logs after our changes

Woah! These are much better. Now you can easily see what the user is doing in our application. The user is hitting the health API multiple times, and he is getting 200 Ok response each time.

Mission Accomplished! We have now made our spring boot’s default logs to be meaningful. Now anyone looking at the logs would be able to guess what is happening in the application.

Now, you might think — Are these the standard of logging? — Unfortunately, the answer is — No. You can, and should always customize your logs according to your features and requirement. The aim of customizing the logs in this way was to make the logs more meaningful. That is — to enable anyone looking at the logs to find the issues and resolve them on the fly. I don’t suggest you copy these configurations and put in your application blindly. It would be best if you thought about what would work best for you and apply those configurations only.

If you would like to read more about spring logging, please refer —

1. https://docs.spring.io/spring-boot/docs/2.1.12.RELEASE/reference/html/boot-features-logging.html

Thanks for reading. If you have enjoyed reading this, please give some claps to this post, It would encourage me to write more of such informative blogs/articles.

P.S. —

You can find the complete source code of this demo on GitHub— https://github.com/akashchandwani/logging-demo