Logstash is a nice tool for managing events and logs. After you finished the setup, the next step is the configuration of the agents/shippers. Since one of the strengths of logstash is the ability to query your logs and make some nice statistics about them, it is key to ‘convert’ your logs somehow in a more structured way. Here’s a little example on how to do this…
The configuration of a shipper is done through a config file (ex. logstash.conf). Below is an example to handle Glassfish’s server log.
input {
file {
codec => multiline {
'negate' => true
'pattern' => '^\[\#\|\d{4}'
'patterns_dir' => '/opt/logstash/agent/etc/patterns'
'what' => 'previous'
}
'path' => '/var/log/glassfish/greyhound/server.log'
'type' => 'glassfish'
}
}
filter {
mutate {
'add_field' => ['application', '%{type}']
}
if [message] =~ /\[GLF_INT\]/ {
mutate {
'update' => ['type', 'application']
}
grok {
'keep_empty_captures' => true
'named_captures_only' => true
'pattern' => '(?m)\[\#\|%{TIMESTAMP_ISO8601:timestamp}\|%{LOGLEVEL}\|%{DATA:server_version}\|%{JAVACLASS}\|%{DATA:thread}\|\[GLF_INT\]%{DATA:category}\|%{DATA:loglevel}\|%{DATA:class}\|line:%{DATA:linenumber}\|%{DATA:message_detail}\|\#\]'
'patterns_dir' => '/opt/logstash/agent/etc/patterns'
}
} else {
mutate {
'add_field' => ['category', 'technical']
'update' => ['type', 'internal']
}
grok {
'keep_empty_captures' => true
'named_captures_only' => true
'pattern' => '(?m)\[\#\|%{TIMESTAMP_ISO8601:timestamp}\|%{LOGLEVEL:loglevel}\|%{DATA:server_version}\|%{JAVACLASS:class}\|%{DATA:thread}\|%{DATA:message_detail}\|\#\]'
'patterns_dir' => '/opt/logstash/agent/etc/patterns'
}
}
if [type] == 'application' and [category] == '' {
mutate {
'update' => ['category', 'technical']
}
}
date {
'match' => ['timestamp', 'ISO8601']
}
}
output {
redis {
'data_type' => 'list'
'host' => '172.168.1.250'
'key' => 'logstash'
}
}
This file is also available on Github: https://gist.github.com/glnds/8774267
Some remarks
Multiline filter
By default Logstash will treat every new line from your log as a new event. Since events often consists of multiple lines you have to tell Logstash how to group multiple lines into a single event. For Glassfish’s server logs the Logstash multiline filter from my example will start a new event for every line starting with [#| + 4 digits
. You can easily test this here: http://rubular.com
Grok that log
One of the basic things you’ll do with your logs is applying a grok filter to them. This process is all about parsing the arbitrary text and structure it.
Here are two grok examples based on the above config.
Example 1
[#|2014-02-02T02:08:50.114+0000|INFO|glassfish3.1.2|javax.enterprise.system.std.com.sun.enterprise.server.logging|_ThreadID=45;_ThreadName=Thread-2;|[GLF_INT]functional|INFO|com.ex.controller.AuthenticationController|line:148|[LOGIN] Successful re-login with token for user ...|#]
This pattern will be parsed by the first grok pattern (through the occurrence of [GLF_INT]) resulting in the following structure:
{
"timestamp": ["2014-02-02T02:08:50.114+0000"],
"server_version": ["glassfish3.1.2"],
"thread": ["_ThreadID=45;_ThreadName=Thread-2;"],
"category": ["functional"],
"loglevel": ["INFO"],
"class": ["com.ex.controller.AuthenticationController"],
"linenumber": ["148"],
"message_detail": ["[LOGIN] Successful re-login with token for user ..."]
}
Example 2
[#|2014-02-01T17:50:17.139+0000|INFO|glassfish3.1.2|javax.enterprise.system.core.com.sun.enterprise.v3.server|_ThreadID=1;_ThreadName=Thread-2;|GlassFish Server Open Source Edition 3.1.2.2 (5) startup time : Felix (7,359ms), startup services(76,273ms), total(83,632ms)|#]
This pattern will be parsed by the second grok pattern resulting in the following structure:
{
"timestamp": ["2014-02-01T17:50:17.139+0000"],
"loglevel": ["INFO"],
"server_version": ["glassfish3.1.2"],
"class": ["javax.enterprise.system.core.com.sun.enterprise.v3.server"],
"thread": ["_ThreadID=1;_ThreadName=Thread-2;"],
"message_detail": ["GlassFish Server Open Source Edition 3.1.2.2 (5) startup time : Felix (7,359ms), startup services(76,273ms), total(83,632ms)"]
}
Here’s a nice tool to test your own grok patterns: http://grokdebug.herokuapp.com
A Little about SLF4J and Logback
Under the hood my java application is using SLF4J and Logback. Although Logback is not the most common choice, it has a nice advantage compared to other logging frameworks: currently it is the only framework implementing SLF4J Markers. Since my application contains both functional and technical log messages it was a requirement to have both types of messages marked properly in logstash. Although there are multiple solutions to handle this, I solved it through the use of an SLF4J Marker. Here’s an example.
Java Class:
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;
import org.slf4j.MarkerFactory;
...
private static final Marker FM = MarkerFactory.getMarker("functional");
private static final Logger LOG = LoggerFactory.getLogger(AuthenticationController.class);
...
LOG.info(FM, "[LOGIN] Successful login with username/password for user " + user.getName());
...
Logback config:
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<layout class="ch.qos.logback.classic.PatternLayout">
<Pattern>[GLF_INT]%marker|%level|%logger|line:%line|%msg%n</Pattern>
</layout>
</appender>
Kibana
Here are some screenshots from the end result in kibana: