Monitor WSO2 Carbon logs with Logstash

The ELK stack is a popular stack for searching and analyzing data. Many people use it for analyzing logs. WSO2 also has a full-fledged Big Data Analytics Platform, which can analyze logs and do many more things.

In this blog post, I'm explaining on how to monitor logs with Elasticsearch, Logstash and Kibana. I will mainly explain logstash configurations. I will not show how to set up Elasticsearch and Kibana. Those are very easy to setup and there are not much configurations. You can just figure it out very easily! :)

If you want to test an elasticsearch server, you can just extract the elasticsearch distribution and start an elasticsearch server. If you are using Kibana 3, you need to use a web server to host the Kibana application. With Kibana 4, you can use the standalone server provided in the distribution.

Configuring Logstash


Logstash is a great tool for managing events and logs. See Getting Started with Logstash if you haven't used logstash.

First of all, we need to configure logstash to get the wso2carbon.log file as an input. Then we need to use a filter to parse the log messages and extract data to analyze.

The wso2carbon.log file is written using log4j and the configurations are in $CARBON_HOME/repository/conf/log4j.properties.

For WSO2 log message parsing, we will be using the grok filter to extract the details configured via log4j pattern layout

For example, following is the pattern layout configured for wso2carbon.log in WSO2 AS 5.2.1 (wso2as-5.2.1/repository/conf/log4j.properties).

log4j.appender.CARBON_LOGFILE.layout.ConversionPattern=TID: [%T] [%S] [%d] %P%5p {%c} - %x %m {%c}%n

In this pattern, the class name ("{%c}") is logged twice. So, let's remove the extra class name. (I have created a JIRA to remove the extra class name from log4j configuration. See CARBON-15065)

Following should be the final configuration for wso2carbon.log.

log4j.appender.CARBON_LOGFILE.layout.ConversionPattern=TID: [%T] [%S] [%d] %P%5p {%c} - %x %m %n

Now when we start WSO2 AS 5.2.1, we can see all log messages have the pattern specified in log4j configuration.

For example:

isuru@isurup-ThinkPad-T530:~/test/wso2as-5.2.1/bin$ ./wso2server.sh start
isuru@isurup-ThinkPad-T530:~/test/wso2as-5.2.1/bin$ tail -4f ../repository/logs/wso2carbon.log 
TID: [0] [AS] [2015-02-25 18:02:00,345]  INFO {org.wso2.carbon.core.init.JMXServerManager} -  JMX Service URL  : service:jmx:rmi://localhost:11111/jndi/rmi://localhost:9999/jmxrmi
TID: [0] [AS] [2015-02-25 18:02:00,346]  INFO {org.wso2.carbon.core.internal.StartupFinalizerServiceComponent} -  Server           :  Application Server-5.2.1
TID: [0] [AS] [2015-02-25 18:02:00,347]  INFO {org.wso2.carbon.core.internal.StartupFinalizerServiceComponent} -  WSO2 Carbon started in 29 sec
TID: [0] [AS] [2015-02-25 18:02:00,701]  INFO {org.wso2.carbon.ui.internal.CarbonUIServiceComponent} -  Mgt Console URL  : https://172.17.42.1:9443/carbon/


Let's write a grok pattern to parse a log message (single line). Please look at grok filter docs for basic syntax in grok patterns. Once you are familiar with grok syntax, it's very easier to write patterns.

There is also an online "Grok Debugger" application to test grok patterns.

Following is the Grok pattern written for parsing above log lines.

TID:%{SPACE}\[%{INT:tenant_id}\]%{SPACE}\[%{WORD:server_type}\]%{SPACE}\[%{TIMESTAMP_ISO8601:timestamp}\]%{SPACE}%{LOGLEVEL:level}%{SPACE}{%{JAVACLASS:java_class}}%{SPACE}-%{SPACE}%{GREEDYDATA:log_message}

You can test this Grok pattern with Grok Debugger. Use one of the lines in above log file for the input.

Grok Debugger
Grok Debugger

We are now parsing a single log line in logstash. Next, we need to look at how we can group exceptions or multiline log messages into one event.

For that we will use the multiline filter. As mentioned in the docs, we need to use a pattern to identify whether a particular log line is a part of the previous line. As configured in the log4j, all logs must start with "TID". If not we can assume that the particular log line belongs to the previous log line.

Finally we need to configure logstash to send output to some destination. We can use "stdout" output for testing. In a production setup, you can use elasticsearch servers.

Logstash Config File


Following is the complete logstash config file. Save it as "logstash.conf"

input { 
    file {
        add_field => {
            instance_name => 'wso2-worker'
        }
        type => "wso2"
        path => [ '/home/isuru/test/wso2as-5.2.1/repository/logs/wso2carbon.log' ]
    }
}

filter {
    if [type] == "wso2" {
        grok {
            match => [ "message", "TID:%{SPACE}\[%{INT:tenant_id}\]%{SPACE}\[%{WORD:server_type}\]%{SPACE}\[%{TIMESTAMP_ISO8601:timestamp}\]%{SPACE}%{LOGLEVEL:level}%{SPACE}{%{JAVACLASS:java_class}}%{SPACE}-%{SPACE}%{GREEDYDATA:log_message}" ]
        }
        multiline {
            pattern => "^TID"
            negate => true
            what => "previous"
        }
    }
}

output {
    # elasticsearch { host => localhost }
    stdout { codec => rubydebug }
}

Please note that I have used "add_field" in file input to show that you can add extra details to the log event.

Running Logstash


Now it's time to run logstash!

$ tar -xvf logstash-1.4.2.tar.gz 
$ cd logstash-1.4.2/bin

We will first test whether the configuration file is okay.

$ ./logstash --configtest -f ~/conf/logstash.conf 
Using milestone 2 input plugin 'file'. This plugin should be stable, but if you see strange behavior, please let us know! For more information on plugin milestones, see http://logstash.net/docs/1.4.2/plugin-milestones {:level=>:warn}
Configuration OK

Let's start logstash

$ ./logstash -f ~/conf/logstash.conf

Now start the WSO2 AS 5.2.1 server. You will now see log events from logstash.

For example:

{
          "message" => "TID: [0] [AS] [2015-02-26 00:31:41,389]  INFO {org.wso2.carbon.core.internal.StartupFinalizerServiceComponent} -  WSO2 Carbon started in 17 sec",
         "@version" => "1",
       "@timestamp" => "2015-02-25T19:01:49.151Z",
             "type" => "wso2",
    "instance_name" => "wso2-worker",
             "host" => "isurup-ThinkPad-T530",
             "path" => "/home/isuru/test/wso2as-5.2.1/repository/logs/wso2carbon.log",
        "tenant_id" => "0",
      "server_type" => "AS",
        "timestamp" => "2015-02-26 00:31:41,389",
            "level" => "INFO",
       "java_class" => "org.wso2.carbon.core.internal.StartupFinalizerServiceComponent",
      "log_message" => "WSO2 Carbon started in 17 sec"
}

Troubleshooting Tips


  • You need to run the server as the file input will read only new lines. However if you want to test a log file from the beginning, you can use following input configuration.


input { 
    file {
        add_field => {
            instance_name => 'wso2-worker'
        }
        type => "wso2"
        start_position => "beginning"
        sincedb_path => "/dev/null"
        path => [ '/home/isuru/test/wso2as-5.2.1/repository/logs/wso2carbon.log' ]
    }
}

  • When you are using multiline filter, the last line of the log file may not be processed. This is an issue in logstash 1.4.2 and I didn't notice the same issue in logstash-1.5.0.beta1. 


I hope these instructions are clear. I will try to write a blog post on using Elasticsearch & Kibana later. :)

Comments

Post a Comment

Popular posts from this blog

Specifying a custom Event Settings file for Java Flight Recorder

Image
When you are using Java Flight Recorder (JFR), the JFR will use an event settings file to check which event types to record. By default in JFR, there are two settings, "default" and "profile". The default setting is recommended for Continuous Recordings as it has very low overhead (typically less than 1% overhead). The profile setting has more events and useful when profiling the application. As mentioned in my previous blog post regarding  Java Flight Recorder Continuous Recordings , we use following arguments to do a Continuous Recording. -XX:+UnlockCommercialFeatures -XX:+FlightRecorder -XX:FlightRecorderOptions=defaultrecording=true,disk=true,repository=./tmp,dumponexit=true,dumponexitpath=./ Note: According to the Oracle documentation on " java " command, we should be able to specify "settings" parameter to the -XX:FlightRecorderOptions. However, the settings parameter has no effect when used with the -XX:FlightRecorderOptions and
Read more

Flame Graphs with Java Flight Recordings

Flame Graphs Brendon D. Gregg , who is a computer performance analyst , has created  Flame Graphs to visualize stack traces in an interactive way. You must watch his talk at USENIX/LISA13 , titled Blazing Performance with Flame Graphs , which explains Flame Graphs in detail. There can be different types of flame graphs and I'm focusing on  CPU Flame Graphs  with Java in this blog post. Please look at the Flame Graphs Description  to understand the Flame Graph visualization. CPU Flame Graphs and Java Stack Traces As  Brendon  mentioned in his talk, understanding why CPUs are busy is very important when analyzing performance.  CPU Flame Graphs  is a good way to identify hot methods from sampled stack traces. In order to generate CPU Flame Graphs for Java Stack Traces , we need a way to get sample stack traces. Brendon has given examples to use jstack  and Google's lightweight-java-profiler . Please refer to his perl program on generating  CPU Flame G
Read more

Java CPU Flame Graphs

Update (September 14, 2015): Java 8 Update 60 was released on August 18, 2015. There are some recent changes to "perf-map-agent". There is no longer a script named "perf-java" and you should use "bin/create-java-perf-map.sh " Brendan Gregg shared an exciting news in his Monitorama talk: The " JDK-8068945 " is fixed in Java 8 Update 60 Build 19 ! Without this fix, it was not possible to see full stack in Java with Linux perf_events and standard JDK (without any patches). For more information, see Brendan's Java CPU Flame Graphs page. The Problem with Java and Perf First of all, let's see what's the problem with using current latest Java and perf. For this example, I used the same program explained in my previous blog post regarding FlameGraphs . java org.wso2.example.JavaThreadCPUUsage.App Then I sampled on-CPU functions for Java program using perf. (See Brendan's Perf Examples ) sudo perf record -F 99 -g -
Read more