In this tutorial, we’ll discuss why logging is important, how to control your logging output, how to write your own logging statements, and how to view your logs in production.
Contents
Logging provides observability of your app in a live environment. What went wrong? What does the stack trace of an error experienced in production look like?
Logging allows you to debug errors.
Using a logging framework provides a consistent, informative, timestamped output, and handles the formatting and display of stack traces. If you’ve used System.out.println to output information, you’ve noticed that these messages lack that extra context that the other messages have.
Don’t log sensitive information, such as passwords, PII (personally identifiable information), or credit card numbers.
Too much logging is hard to sort through. Too little logging won’t provide insight into critical issues. We’ll talk about a few techniques to manage the signal to noise ratio inherent in getting this right.
Spring Boot by default ships with all the necessary libraries to add additional logging to your application. You will be interacting with SLF4J, a logging abstraction which simplifies logger use. Under the hood, the logging implementation is provided by Logback.
This tutorial will be based off of the
coding-events
project. Clone this project and check out the auth-filter
branch. Create a new branch from here called logging (git checkout -b logging
from the auth-filter branch). If you’d like to keep the
changes we’ll be making, first fork the project to your own GitHub
account.
Feel free to use your own project for this tutorial, just make sure you update class and package names where relevant.
You likely already have some experience reading log messages, but let’s examine a typical event logged by Spring.
Here’s the first log message that displays immediately under the Spring Boot banner on startup:
2017-11-05 13:33:58.594 INFO 73394 --- [ restartedMain] org.launchcode.CodingEventsApplication : Starting CodingEventsApplication on LaunchCodeComputer with PID 73394 (/Users/launchcoder/workspace/coding-events/build/classes/main started by launchcoder in /Users/launchcoder/workspace/coding-events)
Here’s what’s displayed by default:
Date and Timestamp
Log Level — ERROR, WARN, INFO, DEBUG or TRACE (discussed next)
Process ID
Thread name — Enclosed in square brackets (may be truncated for console output).
Logger name — This is usually the source class name (often abbreviated).
The log message - Here Spring is telling us what process ID our application started on, where it was started from, and by whom.
Loggers typically support five different log levels, or degrees of
severity, ranging from most severe (ERROR) to least severe
(TRACE). As a developer, this provides context for the message (How
serious is the issue?), and enables control over which messages are
displayed during runtime.
The five standard log levels, in order of increasing severity, are:
TRACE
DEBUG
INFO
WARN
ERROR
Each message that is potentially logged by an application has a level,
and a running application has a level configured as well. The
application log level controls which messages are actually logged, with
all messages at the applications log level or higher being logged. For
example, if the application level is set to INFO, then INFO,
WARN, and ERROR messages are displayed. If the application level
is ERROR, then only messages with that level are displayed. If the
application level is TRACE, then all messages are displayed in the
logs.
Logging levels allow you to control what information an application
logs. You may want to only log INFO and above when your application
is working normally, but you may want to enable DEBUG-level logs in
order to troubleshoot a problem without redeploying your code. Logging
frameworks allow you to control the log level via configuration files
and properties.
In Spring Boot projects, you can use the application.properties file
to control log levels. Spring allows log levels to be set not just for
the application as a whole, but also separately for individual packages.
This allows different packages to have different levels. This feature
can help you focus in on only the most important messages. For example,
if you are debugging a problem and know precisely which package the
issue lies in, you can reduce the number of messages that you have to
wade through by enabling more verbose logging for just that package.
Within application.properties, all properties are prepended with
logging.level, followed by the package name and a log level. Spring
scans the file for such properties on application startup.
For example, if you want to log every event at a specific level, use:
logging.level.root=DEBUG
If you want to log everything that Spring is doing, you’ll set:
logging.level.org.springframework=TRACE
Notice that we’re setting the log level here only for the package
org.springframework. Any DEBUG message emitted by a class at or
below this package/directory will be displayed.
Say you want to log everything in your app, but ignore informational messages from Spring. You would set the following properties:
logging.level.org.springframework=WARN
logging.level.org.launchcode=TRACE
Here are some more common packages that may be useful to log during debugging:
# For debugging security
logging.level.org.springframework.security=DEBUG
# General debugging of web applications without getting ALL of Spring's logs
logging.level.org.springframework.web=DEBUG
# Database/ORM logging. Best used in conjunction:
logging.level.org.hibernate.SQL=DEBUG
logging.level.org.hibernate.type=TRACE
# Consuming REST apis via RestTemplate:
logging.level.org.springframework.web.client.RestTemplate = DEBUG
logging.level.org.apache.http = DEBUG
Note
Some loggers also provide a FATAL level, but Logback treats this the same as an ERROR.
As you start to build more complex applications and host them in a live environment, you’ll want to start adding your own logging messages.
To do so, you’ll need to instantiate (create) a logger inside the class we want to do some logging in. This is done by adding the following to the top of your class, inside of your class declaration.
private static final Logger logger = LoggerFactory.getLogger(EventController.class);
Here, we’re adding a logger to our EventController, but if you’re
working on your own project, be sure to use the appropriate class name.
This gives us access to a logging instance, which we can start using to create log messages.
Consider a situation where you might want to log why a user failed validation. This way, if the user contacts us confused as to why they can’t create a new event, register, or otherwise use our application, we’ll have a record of what was the root problem. Add the following line inside one of our validation blocks, like so:
if (errors.hasErrors()) {
logger.info("Error during event registration: " + errors.getAllErrors().toString());
model.addAttribute("title", "Add Event");
return "events/create";
}
In the event that a user has provided incorrect information when adding an event, we will log that there was an error, as well as the errors themselves, which should give us insight into what was the root of the problem.
Here we are just logging a string which we concatenate with the +
symbol. Each logger provides many overloaded methods allowing you to
pass in additional parameters, such as an object or an exception. Any
objects that are passed in will be logged via their toString method.
If it’s an object you’ve created, make sure you’ve overridden the
default toString and you aren’t logging any sensitive information
stored in your object.
If you’ve deployed your app via Cloud Foundry, you can view your logs by
using the cf logs command. For example, if your app was named
coding-events you’d type cf logs coding-events. This will display your
logs in real time. If you want to view recent logs, add the --recent
flag like so, cf logs coding-events --recent, and the most recent logs
will be displayed.
If you’ve hosted your app using Pivotal Web Services, you can also view your logs by logging into your PWS console. Navigate to your space and then your application. There should be a tab for Logs. From there, you can view old logs, as well as monitor them in real time.