Categories: Tools

Parsing logs with Grok #2 How to parse exceptions alongside regular logs

When dealing with an exception stack trace we have to not only construct a separate match for our grok filter but also make sure that all lines will be treated as one entry.

What we are going to build

In this post I’ll show you how to:

configure Filebeat to merge all lines of an exception stack trace into one entry;
parse it it with Logstash with a custom pattern;
clear tags from a false “failure tag”.

Make Filebeat read all stack trace lines as one entry

Filebeat reads an input file line by line. We have to explicitly tell it to treat a stack trace as a whole by using the multiline option:

If you are sending multiline events to Logstash, use the options described here to handle multiline events before sending the event data to Logstash. Trying to implement multiline event handling in Logstash (for example, by using the Logstash multiline codec) may result in the mixing of streams and corrupted data.
https://www.elastic.co/guide/en/beats/filebeat/current/multiline-examples.html#multiline-examples

Below you’ll find my configuration file for Filebeat. It reads logs from the all.log file, applies the multiline plugin on those that match the patterns and sends everything to Logstash:

# filebeat.yml
filebeat:
  inputs:
    - type: log
      enabled: true
      paths:
        - /logs/all.log
      multiline:
        pattern: '^[[:space:]]+(at|\.{3})[[:space:]]+\b|^Caused by:'
        match: after
output:
  logstash:
    hosts: ["logstash:5044"]

pattern

The Filebeat documentation contains useful examples of dealing with Java exceptions and the pattern I used is copied from there. It will merge lines starting with ‘...‘, ‘at‘ and ‘Caused by‘ from the example input given below:

Exception in thread "main" java.lang.IllegalStateException: A book has a null property
       at com.example.myproject.Author.getBookIds(Author.java:38)
       at com.example.myproject.Bootstrap.main(Bootstrap.java:14)
Caused by: java.lang.NullPointerException
       at com.example.myproject.Book.getId(Book.java:22)
       at com.example.myproject.Author.getBookIds(Author.java:35)
       ... 1 more

Read the Regular expression support docs if you want to construct your own pattern for Filebeat. They differ slightly from the Logstash patterns.

match and negate

The behaviour of multiline depends on the configuration of those two options. The default value for the negate option is false. For match I used ‘after‘. As a result, matching lines are joined with a preceding line that doesn’t match (‘Exception in thread "main“…’ is concatenated with all the following lines that match the pattern).

Add a match for exceptions to your Logstash configuration

In my logstash.conf file I need filters that will handle:

a Java stacktrace:

java.lang.IllegalArgumentException: Exception message at in.keepgrowing.springbootlog4j2scaffolding.SpringBootLog4j2ScaffoldingApplication.main(SpringBootLog4j2ScaffoldingApplication.java:14) [classes/:?]

a regular Spring Boot log:

2020-05-12 08:31:26.530  INFO 10197 --- [SpringContextShutdownHook] o.s.s.c.ThreadPoolTaskExecutor           : Shutting down ExecutorService 'applicationTaskExecutor'

Advice: You can save a lot of time while constructing your patterns by verifying them in the Grok Debbuger. It’s also a good idea to browse the list of the available predefined patterns first.

Because I don’t want to list all patterns in one match section, every entry is being checked against both matches (I think the break_on_match is not working in this case). As a result the _grokparsefailure tag will be added to all entries, even those that matched one of my patterns. I’m going to add my custom tags to solve this issue:

# logstash.conf
…
filter {
    grok {
        match => {
            "message" => "%{JAVACLASS:exception}:\s%{GREEDYDATA:stacktrace}"
        }
        add_tag => ["stacktrace"]
    }
    grok {
        match => {
            "message" => "%{TIMESTAMP_ISO8601:log_timestamp}\s*%{LOGLEVEL:log_level}…"
        }
        add_tag => ["spring_boot_log"]
    }
    if "stacktrace" in [tags] or "spring_boot_log" in [tags] {
        mutate {
            remove_tag => ["_grokparsefailure"]
        }
    }
}
…

To remove the _grokparsefailure tag I have to know that a particular entry was successfully matched by one pattern – the stacktrace or spring_boot_log tag will be present in such a case. Therefore, I can safely delete the _grokparsefailure tag for entries that have my custom tag.

Verify results

Make sure that you have an output configured. It can be send to the STDOUT of the shell running Logstash:

# logstash.conf
…
output {
    stdout {
        codec => rubydebug
    }
}

I’m sending parsed logs to ElasticSearch and use ElasticHQ app to show you the results in a more readable way. You can see how the original message with an exception was parsed on the screenshot below:

You can see the exception part separated from the rest of the message as well as the stacktrace added to the tags. There is also the multiline flag added automatically.