Logstash failed to parse timestamp field, Invalid format, malformed (grok, date filter, add_field)

Hello,

I am getting the error "failed to parse [logdate]","reason"=>"failed to parse [logdate]", "caused_by"=>{"type"=>"illegal_argument_exception", "reason"=>"Invalid format: "2018-Jan-16T11:07:42" is malformed at "-Jan-16T11:07:42""}.

In the stdout window, I can see that it is recognizing/parsing the @timestamp, but not ingesting into elasticsearch.
Sample output from STDOUT
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: "year" => "2018",
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: "message" => [
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: [0] "[Thu Jan 11 2018 17:43:52 GMT-0700 (MST)] INFO UUID1002 - responded to ssshivam - Hit (1) for Gold or (2) for platinum",
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: [1] "Hit (1) for Gold or (2) for platinum"
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: ],
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: "type" => "jarvis",
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: "path" => "/logs/jarvis/hubot_jarvis-160118-1116.log",
Jan 25 15:01:17 lpdpoc14.phx.aexp.com logstash[38670]: "@timestamp" => 2018-01-12T00:43:52.000Z,

---Sample text from log file---
[Thu Jan 11 2018 18:51:54 GMT-0700 (MST)] INFO UUID1006 - responded to username - I can list top 10 processes by CPU or Memory consumption. Hit [1] for CPU , [2] for Memory

--Connfig--1---in logstash--

grok {
                                match => {
                                                message => '\[%{DAY:day} %{MONTH:month} %{MONTHDAY:mday} %{YEAR:year} %{TIME:time} GMT-0700 \(MST\)\] INFO UUID%{NUMBER:conversation_id} - (%{WORD:response} to )?%{WORD:user_id} (%{WORD:question} me )?- %{GREEDYDATA:message}'
                                         }

}
 mutate { add_field => {"logdate" => "%{year}-%{month}-%{mday} %{time}"}
     }

----Config-2------in logstash-- tried with these settings also

grok {
                                match => {
                                                message => '\[%{DAY:day} %{MONTH:month} %{MONTHDAY:mday} %{YEAR:year} %{TIME:time} GMT-0700 \(MST\)\] INFO UUID%{NUMBER:conversation_id} - (%{WORD:response} to )?%{WORD:user_id} (%{WORD:question} me )?- %{GREEDYDATA:message}'
                                         }

}
 mutate { add_field => {"logdate" => "%{month}-%{mday}-%{year} %{time}"}
     }

------Below is the date filter----

    date {
     match => [ "logdate", "YYYY-MM-dd HH:mm:ss.SSS","YYYY-MMM-dd HH:mm:ss","EEE MMM dd YYYY HH:mm:ss 'GMT-0700 (MST)'", "EEE MMM dd yyyy HH:mm:ss ZZZ","ISO8601","yyyy-MM-dd'T'HH:mm:ss.SSSSSS","MMM-dd-YYYY HH:mm:ss" ]
      target => "@timestamp"
    }

Why not delete the logdate field? You're storing the timestamp in @timestamp so logdate is redundant.

Thanks for your response @magnusbaeck .

I modified the date filter to include the remove field of logdate

"

. But now it is just taking the current time into @timestamp.

--date config--

date {
 match => [ "logdate", "YYYY-MM-dd HH:mm:ss.SSS","YYYY-MMM-dd HH:mm:ss","EEE MMM dd YYYY HH:mm:ss 'GMT-0700 (MST)'", "EEE MMM dd yyyy HH:mm:ss ZZZ","ISO8601","yyyy-MM-dd'T'HH:mm:ss.SSSSSS","MMM-dd-YYYY HH:mm:ss" ]
  target => "@timestamp"
  remove_field => ["logdate"]
}

--Sample record ingested ----

{
  "_index": "logstash-2018.01.26",
  "_type": "doc",
  "_id": "FpBwM2EB0w8VkgxV39b_",
  "_version": 1,
  "_score": null,
  "_source": {
    "path": "/logs/jarvis/hubot_jarvis-160118-1116.log",
    "@timestamp": "2018-01-26T17:08:10.670Z",
    "logdate": "%{month}-%{mday}-%{year} %{time}",
    "@version": "1",
    "host": "lpdpoc14.phx.aexp.com",
    "message": "[Tue Jan 16 2018 11:01:32 GMT-0700 (MST)] INFO UUID1316 - responded to user.user2 - The number of jobs running in your application queue is 1",
    "type": "jarvis",
    "tags": [
      "_grokparsefailure",
      "_dateparsefailure"
    ]
  },
  "fields": {
    "@timestamp": [
      "2018-01-26T17:08:10.670Z"
    ]
  },
  "highlight": {
    "path": [
      "/logs/jarvis/@kibana-highlighted-field@hubot_jarvis@/kibana-highlighted-field@-160118-1116.log"
    ]
  },
  "sort": [
    1516986490670
  ]
}

Can you please throw some light as what is happening here? Also, I did not think that redundant data would cause the problem in first place.

Never mind. Looks like where ever there is grok failure to extract field defined, it is hard-coding the logdate value. So the above setting actually works after removing logdate field. I just have to fix the grok pattern for all the combinations coming in the log file. Thanks again for your help

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