Multiple matches from one line

[epacke (Patrik Jonsson)]

Hi!
I am struggling with syslog from one of our vendors (F5). When something goes down a syslog message is sent with the thing that has failed together with the last states of the monitor.

Two sample log lines could look like this:

<182>Feb 2 03:31:01 OurLoadbalancerHostName notice mcpd[6728]: 01070638:5: Pool /Common/my_pool_http_pool member /Common/10.10.10.1:80 monitor status down. [ /Common/my_pool_http_monitor: down; last error: /Common/my_pool_http_monitor: Host is unreachable.; Unable to connect; Response Code: 200 (OK); No successful responses received before deadline. @2019/02/03 02:00:22. ] [ was up for 23hrs:59mins:55sec ]\r\n

<182>Feb 2 03:31:01 OurLoadbalancerHostName notice mcpd[6728]: 01070638:5: Pool /Common/my_pool_http_pool member /Common/10.10.10.1:80 monitor status down. [ /Common/my_pool_http_monitor: down; last error: /Common/my_pool_http_monitor: Host is unreachable.; Could not connect.; No successful responses received before deadline. @2019/02/02 03:31:01. ] [ was up for 23hrs:55mins:22sec ]\r\n

My config looks like this:

input {
  syslog {
    port => 5044
  }
}

filter {

    if [severity_label] != "Informational" {
        drop { }
    } else {
        if ([message] =~ "monitor status down") {
            grok {
                break_on_match => false
                match => {
                    "message" => [
                        "Pool (?<pool>[^ ]+) member (?<member>[^ ]+) monitor status (?<status>[^ ]+) \[ (?<monitor>[^ ]+): .+; last error: (?<last_error>[^\]]+)",
                        "(?<failure_reason>[cC]onnection refused)",
                        "(?<failure_reason>Could not connect)",
                        "(?<failure_reason>Unable to connect)",
                        "(?<failure_reason>Response Code: [0-9]+)"
                    ]
                }
            }
        } else {
            drop { }
        }
    }

}
output {
    stdout { codec => rubydebug }
}

This seems to work quite well for the first line, but the second line gets a "_grokparsefailure" and I am not sure why?

Since I'm a novice logstash administrator I'd also like to get a second opinion on it there is a better way to structure the config file to get multiple matches in an array?

Example array of failure_reason:

"failure_reason" => [
    [0] "Unable to connect",
    [1] "Response Code: 200"
]

Please ignore the drop clauses, they are just there to filter out the particular events I wanted to parse to begin with.

Thankful for any advice,
Patrik

[Badger]

@epacke

the second line gets a "_grokparsefailure" and I am not sure why?

It is because you use "break_on_match => false". Looking at the source, you would expect that you would only get tagged if none of the patterns match. However, testing shows that you get tagged if the last pattern does not match. I cannot reconcile the source code with reality.

If I was dealing with those messages than I would break off the standardized part at the front using dissect

dissect { mapping => { "message" => "<%{level}>%{ts} %{+ts} %{+ts} %{lbhost} %{} %{program}[%{pid}]: %{}:%{}: %{restOfLine}" } }

Then grok against restOfLine. This has a huge advantage that you can anchor patterns such as

"^Pool (?<pool>[^ ]+) member (?<member>[^ ]+) monitor status (?<status>[^ ]+) \[ (?<monitor>[^ ]+): .+; last error: (?<last_error>[^\]]+)",

[epacke (Patrik Jonsson)]

Great input, thank you very much!

[Badger]

Still cannot reconcile the code with what happens. But getting _grokparsefailure if the last pattern does not match is a known issue that has been open for years.

input { generator { count => 1 message => '2019-02-03 14:24:59,147 DEBUG ' } }
filter { grok { break_on_match => false match => {"message" => [ "DEBUG", "INFO" ] } } }
output { stdout { } }

[Badger]

I finally got to understand this. Consider this

input { generator { count => 1 message => '' } }
filter {
    mutate { add_field => { "foo" => "DEBUG" } }
    grok {
        break_on_match => false
        match => {
            "foo" => [ "INFO", "DEBUG" ]
            "bar" => [ "DEBUG", "INFO" ]
         }
    }
}

This does not get a _grokparsefailure. That is because the loop in the filter function never resets matched to false once it is set to true. However if we change that add_field to add bar instead of foo then we do get a _grokparsefailure.

That is because the loop inside match_against_groks is using the matched variable for two different things. One is whether it matched, and the other is to retain the set of matches. So when you have two patterns and the second one does not match, matched get reset to false, and (when you are only matching a single field) that's what ends up being used in the filter loop.

[epacke (Patrik Jonsson)]

@Badger

input { generator { count => 1 message => '' } } filter { mutate { add_field => { "foo" => "DEBUG" } } grok { break_on_match => false match => { "foo" => [ "INFO", "DEBUG" ] "bar" => [ "DEBUG", "INFO" ] } } }

Please bear with me. I am trying to wrap my head around this. So what you're saying is that the content of the match is retained while the match status is reset?

In that case I can safely ignore it and move on as it is a false positive.

Thanks for all your help!

[Badger]

@epacke

So what you're saying is that the content of the match is retained while the match status is reset?

In that case I can safely ignore it and move on as it is a false positive.

Yes.