Grok cant match my log

Elastic Stack Logstash
1

My log:

[23:59:52.743]2018-08-14 23:59:52 DEBUG [resin-tcp-connection-*:8012-59] /queryup[sversion=5][model=HUAWEI G7-UL20][from=_360][lastupdatetime=1532506757000][versioncode=201805140][userId=13994251][mac=863846027484619][version=5.2.7][uniqid=974846027484619][needsecretary=true][os=Android4.4.4][screen=720,1184][token=8737a7830aa0c5a14633abd300187af1][appid=1][agent=testBizCard/5.2.7][ip=113.231.11.12][session=abcsZQsuoJfY-6xkJk5uw] [com.test.mobile.interceptor.LoggerInterceptor.before(63)]

logstash config:

input {
  file {
      path => [ "/data/test/*" ]
      start_position => "beginning"
      tags =>  "test"
      type => "test"
      codec=> multiline {
         pattern => "^\[([0-9]{2}:[0-9]{2}:[0-9]{2}.[0-9]{3})\]([0-9]{4}-[0-9]{2}-[0-9]{2})"
         negate => true
         what => "previous"
      }
  }
}

filter {
  if [type] == "test" {

      grok {
            patterns_dir => "/etc/logstash/mypatterns"
            match => [

                "message" , "\[%{TIME:time}\](20%{YEAR:year}-%{MONTHNUM:month}-%{MONTHDAY:day} %{HOUR}:%{MINUTE}:%{SECOND}) %{LOGLEVEL:level} %{NOTSPACE} %{URIPATH:uripath}%{DATA}%{MODEL:model}%{DATA}%{USERID:userId}%{DATA}%{VERSION:version}%{DATA}}%{CLIENTOS:clientos}"

            ]
      }

      mutate {
           add_field => [ "test_time","20%{year}-%{month}-%{day} %{time}"]
      }


      date {
            match => [ "test_time","yyyy-MM-dd HH:mm:ss.SSS" ]
      }

      mutate {
           remove_field => ["test_time","year","month","day","time"]
      }

  }
}

output {

  if [type] == "test" {
    file {
        path => "/data/debug.log"

    }
    stdout{
        codec => rubydebug
    }
  }

}

My custom grok pattern: /etc/logstash/mypatterns

MODEL model=(.*?)(?=])
USERID userId=(.*?)(?=])
VERSION version=(.*?)(?=])
CLIENTOS os=(.*?)(?=])
CLIENTIP ip=(.*?)(?=])

I'm testing my grok pattern successful in 'http://grokdebug.herokuapp.com/',but Running in logstash like above configuration does't mach my log.

logstash erro log:

{"path":"/data/test/mobile/stdout.log.3","tags":["test","_grokparsefailure","_dateparsefailure"],"type":"test","message":"[23:59:52.743]2018-08-14 23:59:52 DEBUG [resin-tcp-connection-*:8012-59] /queryup[sversion=5][model=HUAWEI G7-UL20][from=_360][lastupdatetime=1532506757000][versioncode=201805140][userId=13994251][mac=863846027484619][version=5.2.7][uniqid=974846027484619][needsecretary=true][os=Android4.4.4][screen=720,1184][token=8737a7830aa0c5a14633abd300187af1][appid=1][agent=testBizCard/5.2.7][ip=113.231.11.12][session=abcsZQsuoJfY-6xkJk5uw] [com.test.mobile.interceptor.LoggerInterceptor.before(63)]","@timestamp":"2018-09-25T02:45:36.011Z","@version":"1","host":"rkeserver.bcc.global"}

If I delete the last two parts, it can match my log,the configurgration like :

     grok {
            patterns_dir => "/etc/logstash/mypatterns"
            match => [

                "message" , "\[%{TIME:time}\](20%{YEAR:year}-%{MONTHNUM:month}-%{MONTHDAY:day} %{HOUR}:%{MINUTE}:%{SECOND}) %{LOGLEVEL:level} %{NOTSPACE} %{URIPATH:uripath}%{DATA}%{MODEL:model}%{DATA}%{USERID:userId}%{DATA}%{VERSION:version}
            ]
      }
2

Is the last section of your message always <space>[<text>]?

If so, you should think of the line as having three sections, beginning, middle, end.
The beginning is easy to grok
The middle starts with /queryup[
The end starts with ] [ and should be anchored to the end of string $
Use the KV filter to break up the middle.

3

Thank you for your reply!

Yes,you are right that the last section of my message always <space>[<text>]

But I am sorry!It is hard to me to debug!If it is wrong ,the logstash log just tell me ,"_grokparsefailure","_dateparsefailure". I don't know what went wrong!

Although you tell me I should split three sections,I don't know how to split it to three sections.I just know to match filed one by one!

4

Ok, don't fret, I'll help - these next steps are hard.

Here is a working example:

input {
  generator {
    lines => [
      '[23:59:52.743]2018-08-14 23:59:52 DEBUG [resin-tcp-connection-*:8012-59] /queryup[sversion=5][model=HUAWEI G7-UL20][from=_360][lastupdatetime=1532506757000][versioncode=201805140][userId=13994251][mac=863846027484619][version=5.2.7][uniqid=974846027484619][needsecretary=true][os=Android4.4.4][screen=720,1184][token=8737a7830aa0c5a14633abd300187af1][appid=1][agent=testBizCard/5.2.7][ip=113.231.11.12][session=abcsZQsuoJfY-6xkJk5uw] [com.test.mobile.interceptor.LoggerInterceptor.before(63)]'
    ]
    count => 1
  }
}

filter {
  grok {
    match => {
      "message" => [
        '^\[%{TIME:time}\]%{TIMESTAMP_ISO8601:date_time} %{LOGLEVEL:level} %{NOTSPACE} %{URIPATH:uripath}\[%{DATA:kv_section}\] \[%{DATA:tail_section}\]$'
      ]
    }
  }
  kv {
    source => "kv_section"
    # value split defaults to '='
    field_split => "\]\["
    remove_field => ["message", "kv_section"]
  }
  mutate {
    gsub => ["[date_time]", "\s\S+$", "T%{[time]}Z"]
  }
  date {
     match => [ "date_time", "ISO8601"]
     remove_field => ["time", "date_time"]
  }
}

output {
  stdout {
    codec => rubydebug
  }
}

Result:

{
              "host" => "Elastics-MacBook-Pro.local",
             "level" => "DEBUG",
                "os" => "Android4.4.4",
           "session" => "abcsZQsuoJfY-6xkJk5uw",
           "uripath" => "/queryup",
             "appid" => "1",
              "from" => "_360",
    "lastupdatetime" => "1532506757000",
               "mac" => "863846027484619",
             "model" => "HUAWEI G7-UL20",
             "agent" => "testBizCard/5.2.7",
          "@version" => "1",
        "@timestamp" => 2018-08-14T23:59:52.743Z,
            "uniqid" => "974846027484619",
            "screen" => "720,1184",
                "ip" => "113.231.11.12",
           "version" => "5.2.7",
      "tail_section" => "com.test.mobile.interceptor.LoggerInterceptor.before(63)",
             "token" => "8737a7830aa0c5a14633abd300187af1",
          "sequence" => 0,
     "needsecretary" => "true",
          "sversion" => "5",
       "versioncode" => "201805140",
            "userId" => "13994251"
}

Hope this helps.

5

Thank you very much for your reply!

I had solved my question as your advice yesterday!

My solution:

filter {
  if [type] == "test" {

      grok {
            match => [

                "message" =>  "\[%{TIME:time}\](20%{YEAR:year}-%{MONTHNUM:month}-%{MONTHDAY:day} %{HOUR}:%{MINUTE}:%{SECOND}) %{LOGLEVEL:level} %{NOTSPACE} %{URIPATH:uripath}"
            ]
      }

      if [level] == "DEBUG" {


          kv { 
              value_split => "="
              field_split => "\[\]" 
          }
    
      }

      mutate {
           add_field => [ "test_time","20%{year}-%{month}-%{day} %{time}"]
      }


      date {
            match => [ "test_time","yyyy-MM-dd HH:mm:ss.SSS" ]
      }

      prune {
         whitelist_names => [ "^@timestamp$","^type$","^model$","^host$","^agent$","^version$","^path$","^uripath$","^message$","^@version$","^userId$","^level$","^os$","^from$","^ip$"]
      }

  }
}

I think your example is better than mine.

I still want to how to debug when it report "_grokparsefailure","_dateparsefailure"? What went wrong?

At the last thank you very much again!

6

For grok and date parse failure debugging, I advise using the generator input, one grok or date and the stdout+rubydebug config. Start simple and work from left to right. The generator input string can be part of the text or all of it. If you use part of it start from the left and concatenate logical sections from the original line.

For regular expressions I test with https://regex101.com/

Lastly. the kv filter has a settings to include or exclude fields so you may not need the prune filter. @timestamp is not a required field but if you use date/time based indexes in the ES output, you will get errors if the @timestamp field is missing.

7

Thank you very much for your help!!!
I will try as your advice.
Thank you very much again!!!

8

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.