Logstash Grok Issue with Multi-Line Events

[cawoodm (Marc)]

We have the following multi-line log file:

INFO   | jvm 1    | srvmain | 2019/03/25 15:17:00.333 | ERROR [aaa] 200] [bbb] foo
INFO   | jvm 1    | srvmain | 2019/03/25 15:17:00.333 | Mar 05, 2019 2:54:39 PM bar

FileBeat correctly generates the following multi-line message:

INFO   | jvm 1    | srvmain | 2019/03/25 15:17:00.333 | ERROR [aaa] 200] [bbb] foo
INFO   | jvm 1    | srvmain | 2019/03/25 15:17:00.333 | Mar 05, 2019 2:54:39 PM bar

LogStash is now supposed to get the text "ERROR" into the field "type" but misses "ERROR" and finds "Mar".

LogStash Filter:

grok { 
	match => { "message" => "(?:.*) (?<logdate>%{YEAR}/%{MONTHNUM2}/%{MONTHDAY} %{HOUR}:%{MINUTE}:%{SECOND}) \| %{NOTSPACE:type}:? %{GREEDYDATA:raw}" }
}

Logstash Generates:

       "type" => "Mar",
       "message" => "INFO   | jvm 1    | srvmain | 2019/03/25 15:17:00.333 | ERROR [aaa] [200] [bbb] foo\nINFO   | jvm 1    | srvmain | 2019/03/25 15:17:00.333 | Mar 05, 2019 2:54:39 PM bar",
       "tags" => [
          [0] "beats_input_codec_plain_applied"
       ],

As you can see the type field is "Mar" (matching the date in the second line of the message) instead of "ERROR" matching the first line of the message.

Note: The grok pattern works in the Grok Debugger tool:
https://grokdebug.herokuapp.com/

You just have to remove the | before ERROR because the debugger won't work with \| for some reason.

[cawoodm (Marc)]

BUMP: Still having this frustrating issue:

INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | ERROR [ajp-bio-8009-exec-3] [6B8F5BD240579BE247A50EE34BB6EC4D] [192.168.3.5] [GlobalControllerExceptionHandler] could not translate value expression 'session.catalogversions'
INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | de.hybris.platform.servicelayer.search.exceptions.FlexibleSearchException: could not translate value expression 'session.catalogversions'
INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | 	at de.hybris.platform.servicelayer.search.impl.DefaultFlexibleSearchService$2.execute(DefaultFlexibleSearchService.java:416) ~[coreserver.jar:?]
INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | 	at de.hybris.platform.servicelayer.search.impl.DefaultFlexibleSearchService$2.execute(DefaultFlexibleSearchService.java:1) ~[coreserver.jar:?]
INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | 	at de.hybris.platform.servicelayer.session.impl.DefaultSessionService.executeInLocalView(DefaultSessionService.java:89) ~[coreserver.jar:?]
INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | 	at de.hybris.platform.servicelayer.search.impl.DefaultFlexibleSearchService.getJaloResult(DefaultFlexibleSearchService.java:395) ~[coreserver.jar:?]
INFO   | jvm 1    | srvmain | 2019/03/29 02:01:37.697 | 	at de.hybris.platform.servicelayer.search.impl.DefaultFlexibleSearchService.search(DefaultFlexibleSearchService.java:167) ~[coreserver.jar:?]

Grok:

grok {
  match => {
    "message" =>"(?:.*) (?<logdate>%{YEAR}/%{MONTHNUM}/%{MONTHDAY} %{HOUR}:%{MINUTE}:%{SECOND}) \|\s+(?<type>[a-zA-Z\-<>]+):? %{GREEDYDATA:raw}"
  }
}

Results in type="at" instead of type="ERROR".

Here: https://grokdebug.herokuapp.com/ it works correctly

[Badger]

You have issues with tabs vs. spaces in your examples, but try

"message" => "(?<logdate>%{YEAR}/%{MONTHNUM}/%{MONTHDAY} %{HOUR}:%{MINUTE}:%{SECOND}) \|\s+(?<type>[a-zA-Z\-<>]+):? %{GREEDYDATA:raw}"

i.e., just get rid of the leading (?:.*)

[cawoodm (Marc)]

@Badger

(?<logdate>%{YEAR}/%{MONTHNUM}/%{MONTHDAY} %{HOUR}:%{MINUTE}:%{SECOND}) |\s+(?<type>[a-zA-Z-<>]+):? %{GREEDYDATA:raw}

Not sure what you mean: my logs have tabs yes but I use \s to deal with that. I've removed the prefix as you said: perhaps that was being too "greedy". We'll watch it and see...