Logging in Java: what, how, where and with what?

Hello everyone, JavaRush community! Today we’ll talk about Java logging:

1. What is this, why is it. In what cases is it better to use, in what cases is it not?
2. What are the different implementations of logging in Java and what should we do with this diversity?
Logging levels. Let's discuss what appender is and how to configure it correctly.
3. Logging nodes and how to configure them correctly so that everything works the way we want.

This material is intended for a wide audience. It will be clear both to those who are just getting acquainted with Java, and to those who are already working, but only figured it out with logger.info(“log something”); Let's Go!

Why is logging needed?

Let's look at real cases in which logging would solve the problem. Here is an example from my work. There are application points that integrate with other services. I use logging of these points as an “alibi” : if the integration does not work, it will be easy to figure out which side the problem originated from. It is also advisable to log important information that is saved to the database. For example, creating an administrator user. This is exactly what would be good to log.

Java Logging Tools

Well-known solutions for logging in Java include:

• log4j
• JUL - java.util.logging
• JCL - jakarta commons logging
• Logback
• SLF4J - simple logging facade for java

System.err.println

Initially, of course, there was System.err.println (record output to the console). It is still used to quickly obtain a log during debugging. Of course, there is no need to talk about any settings here, so let’s just remember it and move on.

Log4j

This was already a full-fledged solution, which was created from the needs of developers. It turned out to be a really interesting tool to use. Due to various circumstances, this solution never made it into the JDK, which greatly upset the entire community. log4j had configuration options so that logging could be turned on in a package com.example.typeand turned off in a subpackage com.example.type.generic. This made it possible to quickly separate what needed to be logged from what was not needed. It is important to note here that there are two versions of log4j: 1.2.x and 2.x.x, which are not compatible with each other . log4j added such a concept as appender , that is, a tool with which logs are recorded and layout - log formatting. This allows you to record only what you need and how you need it. We'll talk more about appender a little later.

JUL - java.util.logging

One of the key advantages is the solution - JUL is included in the JDK (Java development kit). Unfortunately, during its development, it was not the popular log4j that was taken as a basis, but a solution from IBM, which influenced its development. In fact, at the moment there is JUL, but no one uses it. From the “so-so”: in JUL the logging levels are different from what is in Logback, Log4j, Slf4j, and this worsens the understanding between them. Creating a logger is more or less similar. To do this you need to import:

java.util.logging.Logger log = java.util.logging.Logger.getLogger(LoggingJul.class.getName());

The class name is specifically passed in order to know where the logging is coming from. Since Java 8, it is possible to pass Supplier<String>. This helps to count and create a string only at the moment when it is really needed, and not every time, as it was before. Only with the release of Java 8 did developers solve important problems, after which JUL truly became usable. Namely, methods with argument Supplier<String> msgSupplieras shown below:

public void info(Supplier<String> msgSupplier) {
   log(Level.INFO, msgSupplier);
}

JCL - jakarta commons logging

Due to the fact that for a long time there was no industry standard in logging and there was a period when many people created their own custom logger, they decided to release JCL - a common wrapper that would be used over others. Why? When some dependencies were added to the project, they could use a different logger than the logger on the project. Because of this, they were added transitively to the project, which created real problems when trying to put it all together. Unfortunately, the wrapper was very poor in functionality and did not introduce any additions. It would probably be convenient if everyone used JCL to do their work. But in reality it didn’t work out that way, so using JCL is not a good idea at the moment.

Logback

How thorny is the path of open-source... Logback was written by the same developer as log4j to create a successor to it. The idea was the same as log4j. The differences were that in logback:

• improved performance;
• added native support for slf4j;
• The filtering option has been expanded.

By default, logback does not require any settings and records all logs from the DEBUG level and above. If configuration is needed, it can be done via xml configuration:

<configuration> 
    <appender name="FILE" class="ch.qos.logback.core.FileAppender"> 
        <file>app.log</file> 
        <encoder> 
            <pattern>%d{HH:mm:ss,SSS} %-5p [%c] - %m%n</pattern> 
        </encoder> 
    </appender> 
    <logger name="org.hibernate.SQL" level="DEBUG" /> 
    <logger name="org.hibernate.type.descriptor.sql" level="TRACE" /> 
    <root level="info"> 
        <appender-ref ref="FILE" /> 
    </root> 
</configuration>

SLF4J - simple logging facade for java

Around 2006, one of the founding fathers of log4j left the project and created slf4j - Simple Logging Facade for Java - a wrapper around log4j, JUL, common-loggins and logback. As you can see, progress has reached the point that they created a wrapper on top of the wrapper... Moreover, it is divided into two parts: the API, which is used in the application, and the implementation, which is added as separate dependencies for each type of logging. For example, slf4j-log4j12.jar, slf4j-jdk14.jar. It is enough to connect the correct implementation and that’s it: the entire project will work with it. Slf4j supports all new features such as string formatting for logging. There was such a problem before. Let's say there is a log entry:

log.debug("User " + user + " connected from " + request.getRemoteAddr());

userThere is an implicit conversion in the object user.toString()due to string concatenation, and this takes time, which slows down the system. And everything is ok if we debug the application. Problems begin if the logging level for this class is INFO and higher. That is, this log should not be written down, and string concatenation should also not be performed. In theory, this should have been decided by the logging library itself. Moreover, this turned out to be the biggest problem of the first version of log4j. They didn’t deliver a normal solution, but suggested doing it like this:

if (log.isDebugEnabled()) {
    log.debug("User " + user + " connected from " + request.getRemoteAddr());
}

That is, instead of one logging line, they suggested writing 3(!). Logging should minimize changes to the code, and three lines clearly contradicted the general approach. slf4j had no compatibility problems with the JDK and API, so a beautiful solution immediately emerged:

log.debug("User {} connected from {}", user, request.getRemoteAddr());

where {}denote insertions of arguments that are passed in the method. That is, the first {}corresponds to user, the second {}- request.getRemoteAddr(). Due to this, only if the logging level allows logging, this message can be concatenated into a single one. After this, SJF4J quickly grew in popularity and is currently the best solution. Therefore, we will consider logging using the example of a bundle slf4j-log4j12.

What needs to be logged

Of course, you shouldn’t log everything. Sometimes this is unnecessary and even dangerous. For example, if you pledge someone’s personal data and it somehow comes to light, there will be real problems, especially on projects oriented towards the West. But there is also something that is mandatory to log :

1. Start/end of the application. We need to know that the application actually launched as we expected and ended as expected.
2. Security questions. Here it would be good to log password guessing attempts, log logins of important users, etc.
3. Some application states . For example, the transition from one state to another in a business process.
4. Some information for debugging , with an appropriate level of logging.
5. Some SQL scripts. There are real cases when this is needed. Again, by skillfully adjusting the levels, excellent results can be achieved.
6. Executed threads (Thread) can be logged in cases where correct operation is checked.

Popular logging mistakes

There are many nuances, but here are a few common mistakes:

1. Excess logging. You shouldn’t log every step that could theoretically be important. There is a rule: logs can load performance by no more than 10%. Otherwise there will be performance problems.
2. Logging all data into one file. This will make reading/writing to it very difficult at a certain point, not to mention there are file size limits on certain systems.
3. Using incorrect logging levels. Each logging level has clear boundaries and should be respected. If the boundary is vague, you can agree on which level to use.

Logging levels

What are logging levels? In order to somehow rank the logs, it was necessary to give certain designations and distinctions. For this purpose, logging levels were introduced. The level is set in the application. If an entry belongs to a level below the designated one, it is not entered into the log. For example, we have logs that are used to debug the application. In normal production work (when the application is used for its intended purpose), such logs are not needed. Therefore, the level of logging will be higher than for debugging. Let's look at levels using log4j as an example. Other solutions, except JUL, use the same levels. Here they are in decreasing order:

• OFF: no logs are written, all will be ignored;
• FATAL: an error after which the application will no longer be able to work and will be stopped, for example, JVM out of memory error;
• ERROR: The error rate when there are problems that need to be solved. The error does not stop the application as a whole. Other queries may work correctly;
• WARN: Indicates logs that contain a warning. An unexpected action occurred, despite this the system resisted and completed the request;
• INFO: a log that records important actions in the application. These are not errors, these are not warnings, these are expected actions of the system;
• DEBUG: logs needed to debug the application. To ensure that the system does exactly what is expected of it, or to describe the system’s action: “method1 started working”;
• TRACE: lower priority logs for debugging, with the lowest logging level;
• ALL: level at which all logs from the system will be recorded.

It turns out that if the INFO logging level is enabled in some place in the application, all levels will be logged, starting from INFO and up to FATAL. If the logging level is FATAL, only logs with this level will be recorded.

Recording and sending logs: Appender

We will consider this process using log4j as an example: it provides ample opportunities for recording/sending logs:

• for writing to a file - solution DailyRollingFileAppender ;
• to receive data into the application console - ConsoleAppender ;
• to write logs to the database - JDBCAppender ;
• to control transmission via TCP/IP - TelnetAppender ;
• to ensure that logging does not affect performance - AsyncAppender .

There are several other implementations: the full list can be found here . By the way, if the required appender is not available, this is not a problem. You can write your own appender by implementing the Appender interface , which just accepts log4j.

Logging nodes

For the demonstration we will use the slf4j interface, and the implementation from log4j. Creating a logger is very simple: you need to write the following in a class named MainDemo, in which logging will be done:

org.slf4j.Logger logger = org.slf4j.LoggerFactory.getLogger(MainDemo.class);

This will create a logger for us. To make a log entry, you can use many methods that indicate at what level the entries will be made. For example:

logger.trace("Method 1 started with argument={}", argument);
logger.debug("Database updated with script = {}", script);
logger.info("Application has started on port = {}", port);
logger.warn("Log4j didn't find log4j.properties. Please, provide them");
logger.error("Connection refused to host = {}", host);

Even though we are passing the class, in the end it is the full name of the class with packages that is written down. This is done so that you can then divide the logging into nodes, and configure a logging level and an appender for each node. For example, the name of the class: com.github.romankh3.logginglecture.MainDemo- a logger was created in it. And this is how it can be divided into logging nodes. The main node is the null RootLogger . This is the node that receives all the logs of the entire application. The rest can be depicted as shown below: Appenders configure their work specifically on logging nodes. Now, using log4j.properties as an example , we will look at how to configure them.

Step by step setup of Log4j.properties

Now we will set everything up step by step and see what can be done:

log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender

This line says that we are registering a CONSOLE appender that uses the org.apache.log4j.ConsoleAppender implementation. This appender writes data to the console. Next, let's register another appender that will write to a file:

log4j.appender.FILE=org.apache.log4j.RollingFileAppender

It is important to note that the appenders will still need to be configured. Once we already have registered appenders, we can determine what level of logging will be in the nodes and which appenders will be used.

log4j.rootLogger=DEBUG, CONSOLE, FILE

• log4j.rootLogger means that we will configure the main node, which contains all the logs;
• after the equal sign, the first word indicates at what level and higher the logs will be recorded (in our case, this is DEBUG);
• then after the comma all appenders that will be used are indicated.

To configure a specific logging node, you need to use the following entry:

log4j.logger.com.github.romankh3.logginglecture=TRACE, OWN, CONSOLE

where log4j.logger.it is used to configure a specific node, in our case it is com.github.romankh3.logginglecture. And now let's talk about setting up the CONSOLE appender:

# CONSOLE appender customisation
log4j.appender.CONSOLE=org.apache.log4j.ConsoleAppender
log4j.appender.CONSOLE.threshold=DEBUG
log4j.appender.CONSOLE.layout=org.apache.log4j.PatternLayout
log4j.appender.CONSOLE.layout.ConversionPattern=[%-5p] : %c:%L : %m%n

Here we see that we can set the level from which the appender will process. Real situation: a message with the info level was received by the logging node and passed on to the appender that is assigned to it, but the appender, with the warn level and higher, accepted this log, but did nothing with it. Next, you need to decide what template will be in the message. I'm using PatternLayout in the example, but there are many solutions out there. They will not be disclosed in this article. An example of setting up a FILE appender:

# File appender customisation
log4j.appender.FILE=org.apache.log4j.RollingFileAppender
log4j.appender.FILE.File=./target/logging/logging.log
log4j.appender.FILE.MaxFileSize=1MB
log4j.appender.FILE.threshold=DEBUG
log4j.appender.FILE.MaxBackupIndex=2
log4j.appender.FILE.layout=org.apache.log4j.PatternLayout
log4j.appender.FILE.layout.ConversionPattern=[ %-5p] - %c:%L - %m%n

Here you can configure which file the logs will be written to, as can be seen from

log4j.appender.FILE.File=./target/logging/logging.log

The recording goes to the file logging.log. To avoid problems with the file size, you can set the maximum: in this case, 1MB. MaxBackupIndex - tells how many such files there will be. If more than this number is created, the first file will be deleted. To look at a real example where logging is configured, you can go to the open repository on GitHub.

Let's consolidate the result

Try doing everything described yourself:

• Создайте свой проект по типу того, что есть в примере выше.
• Если есть знания использования Maven — используем, если нет, то вот link на статью, где описано How подключить библиотеку.

Подведем итоги

1. Мы поговорor о том, Howие бывают решения в Java.
2. Почти все известные библиотеки по логированию написали под управлением одного человека :D
3. Мы узнали, что нужно логировать, а что не стоит.
4. Разобрались с уровнями логирования.
5. Познакомorсь с узлами логирования.
6. Рассмотрели, что такое аппендер и для чего он.
7. Поэтапно настроor log4j.proterties файл.

Дополнительные материалы

1. JavaRush: Логирование. Размотать клубок стектрейса
2. JavaRush: Logger lecture
3. Хабр: Java logging. Hello world
4. Хабр: Java logging: история кошмара
5. Youtube: Головач курсы. Логирование. Часть 1, Часть 2, Часть 3, Часть 4
6. Log4j: appender
7. Log4j: layout

Смотрите также мои другие статьи:

• Как тестовое задание на собеседование превратилось в open-source библиотеку
• Creation системы мониторинга цен на авиабилеты: пошаговое руководство [Часть 1]
• Гайд по созданию клиента для Skyscanner API и его публикации в jCenter и Maven Central [Часть 1]
• Debug в Intellij IDEA: гайд для новичков