Log Analysis - Troubleshoot Logstash with Its Logs

Body

Within Log Analysis' scalable data collection architecture, Logstash is an important component.

 

For those who are not familiar with Logstash but have needs to extent its usage beyond the provided example, troubleshooting Logstash with its log is crucial.

 

(1) Let's start with the log that is configured in the utility script used to start Logstash - be it Receiver or Sender.

 

Under the <LOGSTASH_DIR>/utilities directory, you should find the script that is used to start Logstash.

 

Eg.

[danielyeap@rec1 utilities]$ pwd
/home/danielyeap/LogAnalysis/utilities
[danielyeap@rec1 utilities]$ ls -l
total 12
-rwxr-xr-x 1 danielyeap danielyeap 2444 Mar 23 20:02 rec1-logstash-single_line-util.sh
[danielyeap@rec1 utilities]$ 

 

 

In the file (in the example, rec1-logstash-single_line-util.sh), search for the "logstash_log" parameter.

 

Eg.

name="logstash-agent"
LOGSTASH_HOME="/home/danielyeap/LogAnalysis/Logstash/logstash-2.2.1"
JAVA_HOME="/home/danielyeap/LogAnalysis/ibm-java"
logstash_bin="${LOGSTASH_HOME}/bin/logstash"
## Update the logstash configuration file name to use the correct configuration
logstash_conf="${LOGSTASH_HOME}/logstash-scala/logstash/config/rec1-logstash-single_line.conf"
logstash_log="${LOGSTASH_HOME}/../logs/rec1-single-line-ls-console.log"
plugin_path="${LOGSTASH_HOME}/logstash-scala/"

 

The parameter will point you to the logfile for the Logstash process.

 

This log file will contain information about the Logstash process that you started. 

 

Eg.

{:timestamp=>"2017-06-22T11:09:18.466000+0800", :message=>"Registering kafka producer", :topic_id=>"%{datasource}", :bootstrap_servers=>"kafka1:17991,kafka2:17991", :level=>:info}
{:timestamp=>"2017-06-22T11:09:18.911000+0800", :message=>"Registering file input", :path=>["/var/log/syslog-la.log"], :level=>:info}
{:timestamp=>"2017-06-22T11:09:18.932000+0800", :message=>"No sincedb_path set, generating one based on the file path", :sincedb_path=>"/home/danielyeap/.sincedb_8544b0ebccb6905fbc355606698464bd", :path=>["/var/log/syslog-la.log"], :level=>:info}
{:timestamp=>"2017-06-22T11:09:18.974000+0800", :message=>"Registering kafka producer", :topic_id=>"%{datasource}", :bootstrap_servers=>"kafka1:17991,kafka2:17991", :level=>:info}
{:timestamp=>"2017-06-22T11:09:18.975000+0800", :message=>"Starting pipeline", :id=>"base", :pipeline_workers=>1, :batch_size=>125, :batch_delay=>5, :max_inflight=>125, :level=>:info}
{:timestamp=>"2017-06-22T11:09:18.978000+0800", :message=>"Pipeline started", :level=>:info}
{:timestamp=>"2017-06-22T11:09:19.216000+0800", :message=>"Opening file", :path=>"/home/danielyeap/LogAnalysis/Logstash/logs/rec1-sl-rubydebug.log", :level=>:info}
{:timestamp=>"2017-06-22T11:09:28.962000+0800", :message=>"Starting stale files cleanup cycle", :files=>{"/home/danielyeap/LogAnalysis/Logstash/logs/rec1-sl-rubydebug.log"=>#<IOWriter:0x66ad8085 @active=true, @io=#<File:/home/danielyeap/LogAnalysis/Logstash/logs/rec1-sl-rubydebug.log>>}, :level=>:info}

 

 

(2) Next, let's explore the Logstash configuration/properties file to check on its logging setup.

 

Eg.

[danielyeap@rec1 config]$ pwd
/home/danielyeap/LogAnalysis/Logstash/logstash-2.2.1/logstash-scala/logstash/config
[danielyeap@rec1 config]$ ls -l
total 20
-rwxr-xr-x 1 danielyeap danielyeap 3847 Mar 24 09:38 rec1-logstash-single_line.conf
[danielyeap@rec1 config]$ 

 

 

In the file (in the example, rec1-logstash-single_line.conf), you should see the following lines (if you are using the provided example configuration file) in the Logstash "output" section =>

 

Eg.

output {
        ## File output plugin with rubydebug codec for debugging the messages received/processed
        ## Should be disable in production use
        if ("_grokparsefailure" in [tags]) {
                file {
                        path => "PATH_TO_LOG_DIR/receiver-sl-grokparsefailure.log"
                        codec => rubydebug
                }
        }
        else {
                file {
                        path => "PATH_TO_LOG_DIR/receiver-sl-rubydebug.log"
                        codec => rubydebug
                }

        }
...

}

 

The first log file (receiver-sl-grokparsefailure.log) will contain log messages that show any GROK parsing failure (if you use GROK in the "filter" section).

 

Eg.

{
       "message" => "%{SYSLOG_MSG}",
      "@version" => "1",
    "@timestamp" => "2017-03-23T12:40:02.640Z",
          "path" => "/var/log/messages",
          "host" => "rec1.ibmtest.com",
          "type" => "syslog",
     "timestamp" => "Mar 23 20:40:01",
     "logsource" => "rec1",
       "program" => "systemd",
          "tags" => [
        [0] "grok_syslog",
        [1] "_grokparsefailure"
    ],
    "datasource" => "test",
    "resourceID" => "%{app-name}_1"
}

 

The example above shows you which event is not parsed successfully.

 

***

 

The second log file (receiver-sl-rubydebug.log) is normally more important, because it contains details about those events that are parsed successfully.

 

Eg.

{
       "message" => "2017-06-23T10:21:53.789204+08:00 host=rec1, relayHost=rec1, tag=systemd:, programName=systemd, procid=-, facility=daemon, sev=info, appName=systemd, msg=Started Hostname Service.",
      "@version" => "1",
    "@timestamp" => "2017-06-23T02:21:54.194Z",
          "path" => "/var/log/syslog-la.log",
          "host" => "rec1.ibmtest.com",
          "type" => "syslog",
    "datasource" => "test",
    "resourceID" => "test1"
}
{
       "message" => "2017-06-23T10:22:21.750594+08:00 host=rec1, relayHost=rec1, tag=fprintd:, programName=fprintd, procid=-, facility=daemon, sev=info, appName=fprintd, msg=** Message: No devices in use, exit",
      "@version" => "1",
    "@timestamp" => "2017-06-23T02:22:22.223Z",
          "path" => "/var/log/syslog-la.log",
          "host" => "rec1.ibmtest.com",
          "type" => "syslog",
    "datasource" => "test",
    "resourceID" => "test1"
}

 

***

 

Lastly, I would like to share the workflow that I normally use to code the Logstash configuration and test the data:

(1) Setup the datasource in the "input" section of the Logstash configuration file.

(2) Code the "filter" section as necessary.

(3) If you use GROK, make sure you add the debugging bits in the "output" section like this:

 

Eg.

        if ("_grokparsefailure" in [tags]) {
                file {
                        path => "/home/danielyeap/LogAnalysis/Logstash/logs/rec1-sl-grokparsefailure.log"
                        codec => rubydebug
                }
        }

 

(4) In the "output" section, always have the debugging log enabled:

 

Eg.

                file {
                        path => "/home/danielyeap/LogAnalysis/Logstash/logs/rec1-sl-rubydebug.log"
                        codec => rubydebug
                }

 

(5) Pass some data to Logstash.

(6) Check the debugging log in Step #4 above on whether the data is parsed correctly.

(7) If no, go back to Step #1 and #2 to check.

(8) If yes, check the output sinks (either Kafka or Log Analysis DB) on whether the data is sent properly.

 

That's all and I hope it helps you!

 

 

 

 

Subscribe and follow us for all the latest information directly on your social feeds:

 

 

  

Check out all our other posts and updates:
Academy Blogs:	https://goo.gl/eZjStB
Academy Videos:	https://goo.gl/kJeFZE
Academy Google+:	https://goo.gl/HnTs0w
Academy Twitter :	https://goo.gl/DiJbvD