Logging in Spring Boot with Loki

Logging in Spring Boot with Loki

In this article, you will learn how to collect and send the Spring Boot app logs to Grafana Loki. We will use Loki4j Logback appended for that. Loki is a horizontally scalable, highly available log aggregation system inspired by Prometheus. I’ll show how to configure integration between the app and Loki step by step. However, you can also use my auto-configured library for logging HTTP requests and responses that will do all those steps for you.

Source Code

If you would like to try it by yourself, you may always take a look at my source code. To do that you need to clone my GitHub repository. For the source code repository with my custom Spring Boot Logging library go here. Then you should just follow my instructions.

Using Loki4j Logback Appender

In order to use Loki4j Logback appended we need to include a single dependency in Maven pom.xml. The current version of that library is 1.4.1:

<dependency>
    <groupId>com.github.loki4j</groupId>
    <artifactId>loki-logback-appender</artifactId>
    <version>1.4.1</version>
</dependency>

Then we need to create the logback-spring.xml file in the src/main/resources directory. Our instance of Loki is available under the http://localhost:3100 address (1). Loki does not index the contents of the logs – but only metadata labels. There are some static labels like the app name, log level, or hostname. We can set them in the format.label field (2). We will also set some dynamic labels and therefore we enable the Logback markers feature (3). Finally, we are setting the log format pattern (4). In order to simplify, potential transformations with LogQL (Loki query language) we will use JSON notation.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>

  <springProperty name="name" source="spring.application.name" />

  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <encoder>
      <pattern>
        %d{HH:mm:ss.SSS} %-5level %logger{36} %X{X-Request-ID} - %msg%n
      </pattern>
    </encoder>
  </appender>

  <appender name="LOKI" class="com.github.loki4j.logback.Loki4jAppender">
    <!-- (1) -->
    <http>
      <url>http://localhost:3100/loki/api/v1/push</url>
    </http>
    <format>
      <!-- (2) -->
      <label>
        <pattern>app=${name},host=${HOSTNAME},level=%level</pattern>
        <!-- (3) -->
        <readMarkers>true</readMarkers>
      </label>
      <message>
        <!-- (4) -->
        <pattern>
{
   "level":"%level",
   "class":"%logger{36}",
   "thread":"%thread",
   "message": "%message",
   "requestId": "%X{X-Request-ID}"
}
        </pattern>
      </message>
    </format>
  </appender>

  <root level="INFO">
    <appender-ref ref="CONSOLE" />
    <appender-ref ref="LOKI" />
  </root>

</configuration>

Besides the static labels, we may send dynamic data, e.g. something specific just for the current request. Assuming we have a service that manages persons, we want to log the id of the target person from the request. As I mentioned before, with Loki4j we can use Logback markers for that. In classic Logback, markers are mostly used to filter log records. With Loki, we just need to define the LabelMarker object containing the key/value Map of dynamic fields (1). Then we pass the object to the current log line (2).

@RestController
@RequestMapping("/persons")
public class PersonController {

    private final Logger LOG = LoggerFactory
       .getLogger(PersonController.class);
    private final List<Person> persons = new ArrayList<>();

    @GetMapping
    public List<Person> findAll() {
        return persons;
    }

    @GetMapping("/{id}")
    public Person findById(@PathVariable("id") Long id) {
        Person p = persons.stream().filter(it -> it.getId().equals(id))
                .findFirst()
                .orElseThrow();
        LabelMarker marker = LabelMarker.of("personId", () -> 
           String.valueOf(p.getId())); // (1)
        LOG.info(marker, "Person successfully found"); // (2)
        return p;
    }

    @GetMapping("/name/{firstName}/{lastName}")
    public List<Person> findByName(
       @PathVariable("firstName") String firstName,
       @PathVariable("lastName") String lastName) {
       
       return persons.stream()
          .filter(it -> it.getFirstName().equals(firstName)
                        && it.getLastName().equals(lastName))
          .toList();
    }

    @PostMapping
    public Person add(@RequestBody Person p) {
        p.setId((long) (persons.size() + 1));
        LabelMarker marker = LabelMarker.of("personId", () -> 
           String.valueOf(p.getId()));
        LOG.info(marker, "New person successfully added");
        persons.add(p);
        return p;
    }

    @DeleteMapping("/{id}")
    public void delete(@PathVariable("id") Long id) {
        Person p = persons.stream()
           .filter(it -> it.getId().equals(id))
           .findFirst()
           .orElseThrow();
        persons.remove(p);
        LabelMarker marker = LabelMarker.of("personId", () -> 
           String.valueOf(id));
        LOG.info(marker, "Person successfully removed");
    }

    @PutMapping
    public void update(@RequestBody Person p) {
        Person person = persons.stream()
                .filter(it -> it.getId().equals(p.getId()))
                .findFirst()
                .orElseThrow();
        persons.set(persons.indexOf(person), p);
        LabelMarker marker = LabelMarker.of("personId", () -> 
            String.valueOf(p.getId()));
        LOG.info(marker, "Person successfully updated");
    }

}

Assuming we have multiple dynamic fields in the single log line, we have to create the LabelMarker object in this way:

LabelMarker marker = LabelMarker.of(() -> Map.of("audit", "true",
                    "X-Request-ID", MDC.get("X-Request-ID"),
                    "X-Correlation-ID", MDC.get("X-Correlation-ID")));

Running Loki with Spring Boot App

The simplest way to run Loki on the local machine is with a Docker container. Besides just the Loki instance, we will also run Grafana to display and search logs. Here’s the docker-compose.yml with all the required services. You can run them with the docker compose up command. However, there is another way – directly with the Spring Boot app.

version: "3"

networks:
  loki:

services:
  loki:
    image: grafana/loki:2.8.2
    ports:
      - "3100:3100"
    command: -config.file=/etc/loki/local-config.yaml
    networks:
      - loki

  grafana:
    environment:
      - GF_PATHS_PROVISIONING=/etc/grafana/provisioning
      - GF_AUTH_ANONYMOUS_ENABLED=true
      - GF_AUTH_ANONYMOUS_ORG_ROLE=Admin
    entrypoint:
      - sh
      - -euc
      - |
        mkdir -p /etc/grafana/provisioning/datasources
        cat <<EOF > /etc/grafana/provisioning/datasources/ds.yaml
        apiVersion: 1
        datasources:
        - name: Loki
          type: loki
          access: proxy
          orgId: 1
          url: http://loki:3100
          basicAuth: false
          isDefault: true
          version: 1
          editable: false
        EOF
        /run.sh
    image: grafana/grafana:latest
    ports:
      - "3000:3000"
    networks:
      - loki

In order to take advantage of the Spring Boot Docker Compose support we need to place the docker-compose.yml in the app root directory. Then, we have to include the spring-boot-docker-compose dependency in the Maven pom.xml:

<dependency>
  <groupId>org.springframework.boot</groupId>
  <artifactId>spring-boot-docker-compose</artifactId>
  <optional>true</optional>
</dependency>

Once we do all the required things, we can run the app. For example, with the following Maven command:

$ mvn spring-boot:run

Now, before the app, Spring Boot starts containers defined in the docker-compose.yml.

spring-boot-loki-docker-compose

Let’s just display a list of running containers. As you see, everything will work fine since Loki listens on the local port 3100:

$ docker ps            
CONTAINER ID   IMAGE                    COMMAND                  CREATED         STATUS         PORTS                    NAMES
d23390fbee06   grafana/loki:2.8.2       "/usr/bin/loki -conf…"   4 minutes ago   Up 2 minutes   0.0.0.0:3100->3100/tcp   sample-spring-boot-web-loki-1
84a47637a50b   grafana/grafana:latest   "sh -euc 'mkdir -p /…"   2 days ago      Up 2 minutes   0.0.0.0:3000->3000/tcp   sample-spring-boot-web-grafana-1

Testing Logging on the Spring Boot REST App

After running the app, we can make some test calls of our REST API. In the beginning, let’s add some persons:

$ curl 'http://localhost:8080/persons' \
  -H 'Content-Type: application/json' \
  -d '{"firstName": "AAA","lastName": "BBB","age": 20,"gender": "MALE"}'

$ curl 'http://localhost:8080/persons' \
  -H 'Content-Type: application/json' \
  -d '{"firstName": "CCC","lastName": "DDD","age": 30,"gender": "FEMALE"}'

$ curl 'http://localhost:8080/persons' \
  -H 'Content-Type: application/json' \
  -d '{"firstName": "EEE","lastName": "FFF","age": 40,"gender": "MALE"}'

Then, we may call the “find” endpoints several times with different criteria:

$ curl http://localhost:8080/persons/1
$ curl http://localhost:8080/persons/2
$ curl http://localhost:8080/persons/3

Here are the application logs from the console. There are just simple log lines – not formatted in JSON.

Now, let’s switch to Grafana. We already have integration with Loki configured. In the new dashboard, we need to choose Loki.

spring-boot-loki-grafana-datasource

Here’s the history of app logs stored in Loki.

As you see we are logging in the JSON format. Some log lines contain dynamic labels included with the Loki4j Logback appended.

spring-boot-loki-logs

We added the personId label to some logs, so we can easily filter records only with requests for a particular person. Here’s the LogQL query that filters records for the personId=1:

{app="first-service"} |= `` | personId = `1`

Here’s the result visible in the Grafana dashboard:

spring-boot-loki-labels

We can also format logs using LogQL. Thanks to JSON format it is possible to prepare a query that parses the whole log message.

{app="first-service"} |= `` | json

As you see, now Loki treats all the JSON fields as metadata labels:

Using Spring Boot Loki Starter Library

If you don’t want to configure those things by yourself, you can use my Spring Boot library which provides auto-configuration for that. Additionally, it automatically logs all the incoming HTTP requests and outgoing HTTP responses. If default settings are enough you just need to include the single Spring Boot starter as a dependency:

<dependency>
  <groupId>com.github.piomin</groupId>
  <artifactId>logstash-logging-spring-boot-starter</artifactId>
  <version>2.0.2</version>
</dependency>

The library logs each request and response with several default labels including e.g. requestId or correlationId.

If you need more information about my Spring Boot Logging library you can refer to my previous articles about it. Here’s the article with a detailed explanation with some implementation details. Another one is more focused on the usage guide.

Leave a Reply