Log generation best practices, with a Spring Boot example

Good log analysis starts before anything is collected. If an application writes logs that are missing ids, mixed in time zones or full of secrets, no tool can make them easy to read later. This guide covers what to log and how to log it, using a Java Spring Boot service as the example. The ideas apply to any language, and the last section covers sending the logs to Graylog.

What makes a log line useful

A good log line answers four questions: when it happened, how serious it was, which part of the system wrote it, and which request or order it belongs to. Message text should describe the event in a stable form, so the same event always looks the same. Put the variable parts, such as ids and amounts, in named fields rather than building them into the message, so that you can group and filter them later.

A Spring Boot example

Versions. The example is written for Spring Boot 3.x on Java 17 or later, because Spring Boot 3 uses the jakarta.* packages.

Spring Boot uses Logback by default. The example below has three parts: a filter that gives each request an id, a Logback configuration that puts that id on every line, and a service that logs a payment step with its outcome.

1. Give every request an id

The filter reads an id from the X-Request-Id header if the caller sent one, or makes a new one. It stores the id in MDC, a per-thread map that Logback can print on every line, and it removes the id when the request ends so that it cannot leak into the next request on the same thread. It also returns the id in the response, so a client can quote it when reporting a problem.

package com.example.checkout;

import jakarta.servlet.FilterChain;
import jakarta.servlet.ServletException;
import jakarta.servlet.http.HttpServletRequest;
import jakarta.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Optional;
import java.util.UUID;
import org.slf4j.MDC;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.OncePerRequestFilter;

@Component
public class RequestIdFilter extends OncePerRequestFilter {

    static final String HEADER = "X-Request-Id";
    static final String MDC_KEY = "requestId";

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain)
            throws ServletException, IOException {
        String id = Optional.ofNullable(request.getHeader(HEADER))
                .filter(s -> !s.isBlank())
                .orElseGet(() -> UUID.randomUUID().toString());
        MDC.put(MDC_KEY, id);
        response.setHeader(HEADER, id);
        try {
            chain.doFilter(request, response);
        } finally {
            MDC.remove(MDC_KEY);
        }
    }
}

2. Put the id and the time on every line

This Logback configuration writes readable lines to the console. The pattern puts an ISO timestamp with its offset first, then the level, the thread, the service name, the request id (or none outside a request), the logger name and the message. Save it as src/main/resources/logback-spring.xml. Spring Boot reads this file automatically.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
  <property name="APP_NAME" value="checkout"/>

  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>%d{yyyy-MM-dd'T'HH:mm:ss.SSSXXX} %-5level [%thread] service=${APP_NAME} requestId=%X{requestId:-none} %logger{36} - %msg%n</pattern>
    </encoder>
  </appender>

  <root level="INFO">
    <appender-ref ref="CONSOLE"/>
  </root>
  <logger name="com.example.checkout" level="DEBUG"/>
</configuration>

If your logs are read by a program, JSON is easier to parse than a text pattern. The logstash-logback-encoder library writes one JSON object per line, and it includes every MDC value as a field. To use it, add the library to your build and replace the encoder above with net.logstash.logback.encoder.LogstashEncoder. Check the library's README for the current version and its setup steps.

3. Log the events, not the noise

The service below logs when a payment starts and how it ends. It uses placeholders ({}) instead of string concatenation, so the message is only built when the level is enabled. It logs the exception as the last argument, so the stack trace is kept. It logs ids and amounts, but never card numbers or tokens.

package com.example.checkout;

import java.time.Duration;
import java.util.concurrent.TimeoutException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Service;

@Service
public class PaymentService {

    private static final Logger log = LoggerFactory.getLogger(PaymentService.class);
    private static final Duration TIMEOUT = Duration.ofSeconds(2);

    public void charge(String orderId, long amountCents) {
        long started = System.nanoTime();
        log.info("payment started orderId={} amountCents={}", orderId, amountCents);
        try {
            callGateway(orderId, amountCents);
            log.info("payment succeeded orderId={} durationMs={}", orderId, millisSince(started));
        } catch (TimeoutException e) {
            log.warn("payment timed out orderId={} timeoutMs={} durationMs={}",
                    orderId, TIMEOUT.toMillis(), millisSince(started));
            throw new IllegalStateException("payment timed out", e);
        }
    }

    private void callGateway(String orderId, long amountCents) throws TimeoutException {
        // the real call to the payment provider goes here
    }

    private static long millisSince(long startNanos) {
        return (System.nanoTime() - startNanos) / 1_000_000;
    }
}

Notice the three log lines. Each one has the same field names, so they can be searched and grouped together. The timeout is logged at WARN with its ids and then rethrown. The service does not log the stack trace itself, so the handler higher up the call stack logs it once, rather than every layer logging the same error.

Best practices

• Use one message shape per event. Write payment timed out orderId=... every time, not a different sentence each time. Stable messages can be counted.
• Use fields for variable data. Ids, durations, counts and status codes go in named fields. Use the same name every time (orderId, not order_id in one place and order in another).
• Log in UTC or with an offset. A timestamp without a time zone is easy to misread when services run in different regions. The pattern above includes the offset.
• Choose levels by who needs to act. ERROR means something failed and a person or an alert should look at it. WARN means something went wrong but was handled. INFO records normal milestones such as a payment starting or finishing. DEBUG is for developers and should be off in production by default.
• Log an exception once. Log it where you handle it, and pass the exception object as the last argument so the stack trace is included.
• Never log secrets or personal data. Passwords, tokens, card numbers, session ids and full customer records should not reach the log. If you must refer to a customer, use an internal id.
• Set a request id on every request. Accept one from the caller, create one if none is sent, and return it in the response. This is the key that connects logs across services.
• Keep the hot path quiet. Do not log inside a loop that runs thousands of times per second. Log the summary instead: how many items were processed and how long it took.
• Make levels configurable. Change them per package at runtime or in configuration, so you can turn on DEBUG for one service during an incident without redeploying everything.

Sending the logs to Graylog

Once the application writes good lines, the logs need to reach Graylog. There are three common routes:

1. GELF over TCP or UDP. The application sends structured messages straight to Graylog. Set up a GELF input in Graylog first, then point an appender at it. The Graylog GELF input documentation explains the input options, including the protocol, port and TLS setting.
2. A log shipper reading the files. Filebeat, Fluent Bit or Fluentd reads the log files and forwards them. This keeps the application unchanged, and the shipper can add host and pod names. Check the shipper's documentation for the Graylog output it supports.
3. Syslog. For servers and older systems, a Syslog input in Graylog receives the lines directly. It is simple, but it carries fewer structured fields than GELF or JSON.

In all three cases, the Graylog inputs documentation describes how to create the input and check that messages arrive. After the logs arrive, the Graylog extractors guide shows how to pull fields such as requestId out of plain text lines when the application does not send them as structured fields.

Turning on DEBUG logs

DEBUG lines are the most detailed, and they are usually off in production because they are noisy and cost storage. When an incident needs them, you can turn DEBUG on for one package, such as com.example.checkout, without changing the code. Keep the change narrow: setting the root logger to DEBUG floods the logs with framework output and hides the lines you need. Turn it off again when you are done.

Option 1: a command-line flag at startup

Spring Boot reads any configuration property from the command line. This starts the service with DEBUG on for one package only:

java -jar checkout.jar --logging.level.com.example.checkout=DEBUG

The same setting works as a Java system property, which is useful when the launch command is fixed:

java -Dlogging.level.com.example.checkout=DEBUG -jar checkout.jar

Option 2: an environment variable in Kubernetes

Spring Boot maps environment variables to properties. Upper case, with underscores in place of dots, sets logging.level.com.example.checkout. Add it to the container's env list in the Deployment:

apiVersion: apps/v1
kind: Deployment
metadata:
  name: checkout
spec:
  template:
    spec:
      containers:
        - name: checkout
          image: registry.example.com/checkout:1.4.2
          env:
            - name: LOGGING_LEVEL_COM_EXAMPLE_CHECKOUT
              value: DEBUG

For a quick change to a running deployment, kubectl can set the variable without editing the file. This triggers a rolling restart, so every pod picks it up:

kubectl set env deployment/checkout LOGGING_LEVEL_COM_EXAMPLE_CHECKOUT=DEBUG -n shop

To turn it off, remove the variable. The trailing dash deletes it:

kubectl set env deployment/checkout LOGGING_LEVEL_COM_EXAMPLE_CHECKOUT- -n shop

Option 2b: the same change in Lens or OpenLens

If you prefer a visual tool, Lens and OpenLens make the same change without any commands. The menu labels can differ slightly between versions, but the steps are these:

1. Open Workloads, then Deployments, and click checkout in the shop namespace.
2. Open the Deployment's Edit view, which shows its YAML.
3. Under the container's env list, add LOGGING_LEVEL_COM_EXAMPLE_CHECKOUT with the value DEBUG, then save.

Saving starts a rolling restart, so the new pods come up with DEBUG on. To check it, open one of the new pods and look at its environment variables. To turn DEBUG off, remove the variable in the same view and save again.

For the Actuator option in Option 3, Lens can port-forward a pod from the pod's menu. Then send the same curl request from your terminal. Lens can also open a shell in a pod, which is useful for looking at its environment but not for changing it.

Option 3: change the level on a running pod

If you do not want a restart, Spring Boot Actuator can change a logger's level while the service runs. Add the Actuator dependency, expose the loggers endpoint, and protect it, because anyone who can reach it can change your log levels:

management.endpoints.web.exposure.include=health,loggers

Reach the pod from your machine with a port forward, then send a POST request:

kubectl port-forward pod/checkout-7d9f 8080:8080 -n shop

curl -X POST http://localhost:8080/actuator/loggers/com.example.checkout \
  -H "Content-Type: application/json" \
  -d '{"configuredLevel": "DEBUG"}'

Set the level back with the same request and "configuredLevel": null, which returns the package to the level in the configuration. A restart also resets it. Changes made this way apply to one pod only, so check each replica if the service runs more than one.

Before you leave DEBUG on

• Keep it narrow. One package, not the root logger.
• Set a reminder to turn it off. Put the variable in a change ticket, or note the time you enabled it.
• Watch the volume. DEBUG output can multiply the size of your logs. Check the storage and the Graylog ingest figures after you turn it on.
• Check for secrets. Detailed logs are more likely to include request bodies. Make sure the sensitive fields are still masked.

Check your setup

Before you rely on the logs in an incident, run a test. Send a request with a known X-Request-Id, then search Graylog for that id. If the search returns the request's lines from every service it touched, the setup works. If it returns nothing, check the time zone, the field names and whether the input is running.

Next steps

Once the logs arrive, you can read them in order with the guides on reading production logs across several services and sorting a Graylog export. For a CSV file exported from Graylog, the Log Sorter can put the lines in time order and filter them. The Log Playground opens several log files side by side.

Questions