Arnold Galovics

For a well-functioning application development team, it’s important to have the appropriate infrastructure behind, as a structured foundation. If the infrastructure is not supporting the application use-cases or the software development practices, it isn’t a good enough base for growth.

The monitoring and logging services are crucial, especially for a cloud environment and for a microservice architecture. Drawing the line between the 2 is very difficult and might depend on the application specifics but as a general rule, I think no application and its development team can operate efficiently if the logging infrastructure is not there.

Think about having a bug in production and having no logging infra? How can the engineers figure out what’s the problem? Well, it’s not impossible, it’s just very difficult and time-consuming.

Having a logging service is mandatory. However, adapting it to the application environment is just as critical as having it. One problem I see with the basic, tutorial based setups is the fact that they are just starting points and often the service is running with its default settings.

For example, let’s say you have an application running on Kubernetes. You want to have Kibana as a visualization tool for your logs. You just need a log collector, let’s use Fluentd. As soon as you set up the EFK – ElasticSearch, Fluentd, Kibana – stack, you can kick-start the project quickly because logs are going to flow in and Kibana will visualize it for you. So where’s the catch?

For normal, single lined log messages, this is going to work flawlessly. But any engineer who has seen a single exception already, knows that a stacktrace is a multiline log message. Single lines out of an exception trace doesn’t give an engineer much value during an investigation.

So, in this article I’m going to cover how to set up an EFK stack on Kubernetes with an example Java based Spring Boot application to support multiline log messages.

The log collection in K8S

There are different ways to collect logs from a Kubernetes cluster. You can:

• use sidecar containers
• have the application push the logs into the logging service directly
• deploy a log collector agent to each cluster node to collect the logs

I’m going to cover the 3rd option, having a dedicated agent running on the cluster nodes.

So the basic idea in this case is to utilize the Docker engine under Kubernetes. When you are logging from a container to standard out/error, Docker is simply going to store those logs on the filesystem in specific folders.

Since a pod consists of Docker containers, those containers are going to be scheduled on a concrete K8S node, hence its logs are going to be stored on the node’s filesystem.

When you have an agent application running on every cluster-node, you can easily set up some watching for those log files and when something new is coming up, like a new log line, you can simply collect it.

Fluentd is one agent that can work this way. The only thing left is to figure out a way to deploy the agent to every K8S node. Luckily, Kubernetes provides a feature like this, it’s called DaemonSet. When you set up a DaemonSet – which is very similar to a normal Deployment -, Kubernetes makes sure that an instance is going to be deployed to every (selectively some) cluster node, so we’re going to use Fluentd with a DaemonSet.

EFK stack

As an example, I’m going to use the EFK – ElasticSearch, Fluentd, Kibana – stack. Kibana is going to be the visualization tool for the logs, ElasticSearch will be the backbone of Kibana to store the logs. And Fluentd is something we discussed already.

Here’s a full, example descriptor for the EFK stack (too long to put it here).

I didn’t want to go into the details of the EFK stack because the post is not about the stack itself but about how to set up the multiline logging for Fluentd, so please forgive me if you expected a detailed explanation on it.

I’m going to use minikube to set up the stack locally, if you have a normal K8S cluster, that’s fine too.

Everything in the stack is self-contained so a very simple apply is enough

Wait a minute or so to have everything started. Note that the stack relies on a LoadBalancer service to expose the Kibana UI, so in case of minikube, you have to tunnel it:

To get the LoadBalancer IP, query the services via kubectl:

We are looking for the external IP which in my case is 10.98.233.248.

Now, loading 10.98.233.248:5601 into the browser, the Kibana UI should open.

Let’s go for the “Explore on my own” option here and go to to Discover menu on the left-hand side.

Now we have to set up the index pattern, for now ElasticSearch will store it in logstash-<date> format, so we’re going to use the logstash-* pattern.

Click on Next step and then just select the @timestamp field and then Create index pattern.

Example Spring Boot application

Okay, the next thing is to have a realistic example, instead of just putting out a config for you without having an actual application for testing, let’s put together a Spring Boot application.

The main goal for this app is gonna be to have multiline logs on the standard output so we can test the logging setup.

As usual, I generated a project on Spring Initializr without any specific dependency.

The code is very simple, there are going to be 2 use-cases:

1. The first one is when you use a logger to log a multiline message with explicit line breaks
2. The second one is when you have an exception stacktrace in the logs

Here’s the code – I didn’t care about the best practices so everything is in the same class, don’t judge me:

This will produce the following logs:

Good, now let’s compile a minimalistic Dockerfile for the application:

And then a K8S deployment descriptor:

Okay, we have everything for deploying the Spring Boot app to Kubernetes.

First of all, let’s build the JAR inside a container, and the final docker image. In case of minikube, I want to build it so the local cluster can access it:

Last thing, deploy to K8S:

Now let’s look at the logs:

Hopefully you see the same log messages as above, if not then you did not follow the steps. 🙂

Now if everything is working properly, if you go back to Kibana and open the Discover menu again, you should see the logs flowing in (I’m filtering for the fluentd-test-ns namespace).

And this is how a multiline log appears by default:

Not very neat, especially the stacktrace because every line is splitted into multiple records in Kibana. Searching with this setup is crazy difficult.

Multiline Fluentd support

Multiline support for the rescue. Fluentd has the capability to group multiline messages into one based on different rules.

If you start digging, mostly there are 5 solutions out there:

• the multiline parser
• the regex parser
• the GCP detect-exceptions plugin
• the concat filter plugin
• having the application log in a structured format like JSON

Here’s my take on them.

The GCP detect-exceptions plugin: great plugin if you want to group exceptions only for various languages, however normal multiline logs are not going to get grouped.

The regex parser: this will simply not work because of the nature how logs are getting into Fluentd. Don’t forget, all standard out log lines are stored for Docker containers on the filesystem and Fluentd is just watching the file. The regex parser operates on a single line, so grouping is not possible. At least I wasn’t able to do so.

The multiline parser: The most promising option. Even a Java example is included with the official documentation. The plugin can theoretically group multiple lines together with a regular expression, however I got the impression that in case of the Docker based JSON log, it simply doesn’t work. It could work if it reads directly from a standard output, but not from JSON based inputs. I spent quite some time experimenting with it but no luck.

The concat filter plugin: I didn’t give much chance to this plugin either since the multiline plugin wasn’t working but I eventually tried to make it work. After hours of reading and digging into the plugin internals, reading closed GitHub issues and so on, I was able to get it working, here’s how.

The plugin can concatenate the logs by having a regular expression specified that denotes the starting point for a multiline log like this config:

This fits to the Spring Boot pattern and this works. Kinda, until logs are continuously flowing into Fluentd. So how does the plugin know there’s an end of a multiline log? Well, it doesn’t. With this configuration, if there’s no log flowing in after the pattern is matching to the last message, it’s going to wait forever with sending the log message to Kibana, i.e. if the last log message is an exception stacktrace, it’s not going to show up until there’s a subsequent log that breaks the pattern.

So, back to the docs. There’s an option that seems like the one we need: flush_interval. According to the docs it specifies The number of seconds after which the last received event log will be flushed. If specified 0, wait for next line forever.

Let’s set it to 1 second, that should be enough for now.

Sort of works, but not 100%. In Kibana, now some of the logs are appearing grouped but some are not even showing up.

So what’s going on? Well, it took me time to figure out but I had it. So when after the flushing interval, the plugin can’t determine if it’s the end of the multiline log (i.e. the case above), the plugin kind of turns that log message into an error because of the flush interval timeout.

In order to flow even the timed out messages into Kibana, we have to hack the configuration a little bit. We’ll rely on the labeling functionality of the plugin and then a relabeling plugin to redirect all events, even the error ones into the same output:

First of all, the timeout_label setting specifies the label for error events, in this case @NORMAL. Then, the config is matching for everything and relabeling the events to @NORMAL so literally every event will have the same label applied.

Then, with the label directive, it’s filtering for the @NORMAL events and matching for everything. This way we can redirect the error events to the same output and everything will show up in the logs.

The fully working K8S config is here.

After the config modifications, just apply the EFK stack again:

Now just restart the Fluentd pod:

And now suddenly the result in Kibana will be a well-formatted, readable, searchable log stream.

Conclusion

The supporting infrastructure for an application is crucial. Logging is no different. If you lack proper logging support, engineers are going to have a really difficult time to do investigations effectively. Often, setting up K8S infrastructure comes with the challenge that multiline logs are not properly flowing into Kibana/Splunk/whatever visualization tool.

In the post, we’ve checked how the Fluentd configuration can be changed to feed the multiline logs properly. Small step for you, giant leap for the engineers working on the application.

As usual, if you enjoyed it, follow me on Twitter for more and the code is available here on GitHub.

Initial EFK stack descriptor

efk-stack.yaml