Are you logging?

- Are you logging?

- Yes. I'm using a "sysout", "print" or "console.writeline" approach.

Unfortunately, you're not logging, because logging is more than "writing texts". So, this article will explain what is and how works logging. Let’s start with a simple definition:

Logging is a way of representing how the software is working at a given moment.

The previous definition shows us that logging has an important task: giving us information about the state of the software. This information will help us to detect what is happening: it’s ok or some errors occur.

To do this, logging uses several ways to tell us what is happening, through its level of information. The main levels are:

• INFO: Shows runtime events, which help us to understand how the software is working in a "happy way";
• WARNING: Shows unexpected events at runtime, which don't change the software behavior. This information shows “something strange is happening” and some things must be corrected;
• DEBUG: Shows detailed and extra information about the software execution. This information helps us to solve errors when it occurs;
• TRACE: Shows more detailed information than DEBUG level, for example, parameters and returns of methods;
• ERROR: Shows unexpected runtime events, but this makes the software break the current execution. As an effect, it must be finished. This event can be handled.

Some logging APIs provide an extra level for errors: FATAL or CRITICAL. Both mean that the software must be ended because the error causes big damage.

Last but not least, some log levels can include another level. For example, if your application is set to INFO level, messages about INFO and WARN will show. If you set DEBUG, INFO, DEGUB, and WARN will show. If you set TRACE, INFO, DEGUB, TRACE, and WARN will show. But if you set up your application for ERROR or FATAL level, just messages like this will show.

Now some people can think: why do I need so verbose way if I have "sysout", "print" or "console.writeline" approach? The answer is: with it, we are able to control when the information must appear. On the opposite approach, information appears always, which will become a mess instead of helping us to solve a problem. Furthermore, is a useful tool for diagnostic problems.

The main languages proving ways for logging. In Java, it’s common to use the framework SLF4J, which is the most usually logging component. C#(.Net) uses Serilog or Ilogger and Python use class logging. All that proves a rich way to log, but in this article, I’ll use SLF4J to show how we can do logging. But keep in mind: what I say here is valid for another language. The theory is the same. To explain how to do effective logging, I’ll use an application built in SpringBoot.

At first, let’s see the application:

The main are:

• LoggingApplication.java: Main class which starts e run our example;
• MyBusinessClass.java: Simple business class that has a simple code to explain log levels;
• MyException.java: Helper exception class;
• MyEntity.java: Helper entity class to provide some data;
• application.properties: File that's config some logging properties for the app;
• pom.xml: Maven pom to set up logging.

Let's start with the pom, which is the file to set up the spring-boot application. To enable SLF4j logging, we need to add the next lines:

<dependency>
	<groupId>org.springframework.boot</groupId>
	<artifactId>spring-boot-starter-log4j2</artifactId>
</dependency>        

These lines are responsible to provide the jars for the SLF4J:

Now, let’s see the applicatoin.properties file. That’s responsible for config our application:

We have two lines:

• logging.level.com.github.thiagoleitecarvalho: Config the level log. It's important to pay attention to "com.github.thiagoleitecarvalho", which config the level only for files in our app;
• logging.file.name: The log file created for our app.

Let's choose INFO.

The LoggingApplication.java has two lines with INFO, which are the only lines in our app:

@SpringBootApplication
public class LoggingApplication {

  private static final Logger LOGGER =? LoggerFactory.getLogger(LoggingApplication.class);
		
  public static void main(String[] args) {
		
	SpringApplication.run(LoggingApplication.class, args);
	LOGGER.info("Application Started...");
		
	MyEntity entity = new MyEntity();
	entity.setAttribute1("My entity");
	entity.setAttribute2(-1.0);
	entity.setAttribute3(false);
	entity.setAttribute4(2);
		
	try {
	  String message = new MyBusinessClass().method1(entity);
			
	  LOGGER.info("Message: {}", message);
	} catch (MyException e) {
		LOGGER.error("An error occurs: {}", e.getMessage());
	}
  }
}        

The previous code shows an INFO message “Application Started...”, and WARN message and ERROR message. Furthermore, we create and set data for the object “entity”. When we run the app, the result is:

As we config the INFO level, our app displayed 2 level messages: INFO(green) and WARN(yellow). The ERROR message appears independently, because of the negative value.

If we set up DEGUG the result is:

Now we have 3 messages: INFO(green), DEBUG(green) and WARN(yellow). Again, an ERROR message appears. To finish, let's set up TRACE and change the value of "attribute2" to "1.0".

Finally, we have 8 messages: INFO, DEBUG and TRACE, all green. I'll ask to change the value of "attribute3" to "true" and see the result. Pay attention to “{}” in "LoggingApplication", because this is a parameter for a log message. In our example is the message returned by “method1”

After all these executions, please open the "log.txt" file, which we configured earlier. It must be like this:

This file keeps all executions and could help us for searching some "strange behaviors" when they occur.

Log is a powerful tool to help us discover and solve problems, but some troubles can appear if it's not used well. In addition to the?"mess",?we can generate I/O overhead, programming overhead due to creating log data and increasing the size of the code, among others.

To avoid these, some tips can help us:

• Environments: config development and staging to DEGUB or TRACE, if you need. Production(live) must be always INFO;
• ERROR level: This is the only message that must be displayed inside a catch clause;
• Messages: Avoid messages inside loops. Avoid unnecessary messages;
• Parameters: Don't use concatenation if you need parameters for the log messages. All log components support parameterized messages.

Setting the log in the right way is an art and I hope this article is the beginning of a new path to creating effective logging. See you in the next article. Bye! :)

The example presented here is available on the Git link below:

References

hps://www.slf4j.org/

Gupta, Samudra. Pro Apache Log4j. 2th edition. United States, Springer-Verlag New York, 2005.