Problem with the code. Only parsing one grok pattern and not overwriting message field

Hi all, i am trying to parse certain log lines and fetch only required information. I am using if else statements to differentiate according to which my lines should parse. But all log line are parsing using first grok pattern and it is not even entering the statements.

sample Log lines:

INFO 2019-08-28 21:49:57,953 [Operator App Mixins] Request URL: /api/v1/operatorapp/societySystem/manualGateEvent/
INFO 2019-08-28 21:49:57,953 [Operator App Mixins] Request Query Params: <QueryDict: {}>
INFO 2019-08-28 21:49:57,954 [Operator App Mixins] Request Data: {u'gate_number': 2, u'action_type': u'open_gate', u'created': u'28-08-2019 09:49 PM'}
INFO 2019-08-28 21:49:57,958 [Operator App Mixins] Logged In operator- 3374 - M2K Aura Exit, URL: /api/v1/operatorapp/societySystem/manualGateEvent/
INFO 2019-08-28 21:49:57,959 [Operator App Mixins] Event Gate: M2K Aura, Gate-2, Exit
INFO 2019-08-28 21:49:57,967 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/manualGateEvent/, Operator: 3374 - M2K Aura Exit, Resp Status: 200
INFO 2019-08-28 21:49:57,967 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/manualGateEvent/, User: 3374 - M2K Aura Exit, Resp Time: 0.024612903595
INFO 2019-08-28 21:49:58,127 [User App Mixins] Request URL: /api/v1/userapp/booking/list/, Method: POST
INFO 2019-08-28 21:49:58,128 [User App Mixins] Request Query Params: <QueryDict: {}>
INFO 2019-08-28 21:49:58,128 [User App Mixins] Request Data: {u'last_booking_id': 0}
INFO 2019-08-28 21:49:58,128 [User App Mixins] Logged In User- 23545 - ANUJ SETHI, Android User, URL: /api/v1/userapp/booking/list/
INFO 2019-08-28 21:49:58,129 [RBS User Views] Fetch Parking Booking List
INFO 2019-08-28 21:49:58,129 [RBS User Views] Request data: {u'last_booking_id': 0}
INFO 2019-08-28 21:49:58,132 [RBS User Views] Sending Bookings List: 0
INFO 2019-08-28 21:49:58,134 [User App Mixins] URL: /api/v1/userapp/booking/list/, User: 23545 - ANUJ SETHI, Resp Status: 200
INFO 2019-08-28 21:49:58,134 [User App Mixins] URL: /api/v1/userapp/booking/list/, User: 23545 - ANUJ SETHI, Resp Time: 0.045
INFO 2019-08-28 21:49:58,617 [Cloud Action Views] Fetch Cloud Action
INFO 2019-08-28 21:49:58,618 [Cloud Action Views] Request Data: {u'device_id': 150}
INFO 2019-08-28 21:49:58,618 [Cloud Action Views] Fetch cloud action V1
INFO 2019-08-28 21:49:58,618 [Cloud Action Views] User: 6382 - Local Server

My filter:

filter {

    grok {

        match => { "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] %{GREEDYDATA:extra}"

          }
    }

    if [class] =~ "User App Mixins" {

        grok {

                match => { "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] URL: %{URIPATHPARAM:url},
                          User: %{NUMBER:user_id} - %{GREEDYDATA:username}, (Resp Status: %{NUMBER:status}|Resp Time: %{NUMBER:duration})"
                          overwrite => ["message"]
                }
          }

          if "_grokparsefailure" in [tags] {
                grok {
                        match => {"message" => "%{GREEDYDATA:message}"}
                }
         }
}
elseif [class] =~ "Operator App Mixins"{

            grok {

                    match => { "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] URL: %{URIPATHPARAM:url},
                              (Operator: %{NUMBER:operator}|User: %{NUMBER:User}) - %{GREEDYDATA:gateName}, (Resp Status: %{NUMBER:status}|Resp Time: %{NUMBER:duration})"
                              overwrite => ["message"]
                }
         }

          if "_grokparsefailure" in [tags] {
                                        grok {
                        match => {"message" => "%{GREEDYDATA:message}"}
                }
         }

    }

    elseif [class] =~ "RBS Operator Views"{

            grok {

                    match => {
                            "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] %{GREEDYDATA:junk}"
                             overwrite => ["message"]
                    }
            }

    }

    elseif [class] =~ "Society System Views"{
            grok {
                    match => {
                            "message" => "%{GREEDYDATA:junk}"
                             remove_field => "message"
                             overwrite => ["message"]
                    }
            }
    }

    elseif [class] =~ "Society RFID Logic" {
            grok {

                    match => {
                            "message" => "%{GREEDYDATA:junk}"
                             remove_field => "message"
                             overwrite => "message"
                   }

           }
    }

My output:

{
          "path" => "/home/rajdeep/Desktop/lg5",
          "host" => "rajdeep-ThinkPad-T460s",
       "message" => [
        [0] "INFO 2019-08-29 00:44:00,206 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, Operator: 10290 - Palm Grove Exit, Resp Status: 200",
        [1] "INFO 2019-08-29 00:44:00,206 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, Operator: 10290 - Palm Grove Exit, Resp Status: 200"
    ],
         "extra" => "URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, Operator: 10290 - Palm Grove Exit, Resp Status: 200",
          "tags" => [
        [0] "_grokparsefailure"
    ],
      "@version" => "1",
     "timestamp" => "2019-08-29 00:44:00,206",
         "class" => "Operator App Mixins",
    "@timestamp" => 2019-09-09T07:30:52.175Z,
      "severity" => "INFO"
}
{
          "path" => "/home/rajdeep/Desktop/lg5",
          "host" => "rajdeep-ThinkPad-T460s",
       "message" => [
        [0] "INFO 2019-08-29 00:44:00,206 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, User: 10290 - Palm Grove Exit, Resp Time: 0.01766705513",
        [1] "INFO 2019-08-29 00:44:00,206 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, User: 10290 - Palm Grove Exit, Resp Time: 0.01766705513"
    ],
         "extra" => "URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, User: 10290 - Palm Grove Exit, Resp Time: 0.01766705513",
          "tags" => [
        [0] "_grokparsefailure"
    ],
      "@version" => "1",
     "timestamp" => "2019-08-29 00:44:00,206",
         "class" => "Operator App Mixins",
    "@timestamp" => 2019-09-09T07:30:52.175Z,
      "severity" => "INFO"
}

Those example outputs are being parsed in the "Operator App Mixins" elseif. The first grok in that branch does not match, because it is a multiline pattern being matched against a single line, so the second grok is called and converts message into an array.

Hi @Badger
Can i do something like if "Operator App Mixins" in [class] use this multiline pattern.
Also none of the patterns are matching. Basically my logic was when a log line comes store it in message with few fields as written in the first grok pattern. Then with the help of if statement
i will check what kind of pattern is required by this file and if few lines that are not giving useful information will give me _grokparsefailure tag and i will just pass that info with greedydata, segregate the information i require and if it does not matches with any pattern just pass it as greedydata.

Basically that is why i am overwriting the previous message (the message from first ever grok pattern) in every match in every if statement.

You cannot use a multiline pattern unless you are using a multiline codec on the input. Each line is processed independently.

Yeah i get that but i don't wanna use multiline codec. The information that i need from log lines i have written the respective pattern for them. I just want rest to be parsed in a separate event where everything is in message field. The patterns that i have written in my code i want only those fields.
But it is not working.

A multiline pattern like this will never ever match a single line.

            match => { "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] URL: %{URIPATHPARAM:url},
                      User: %{NUMBER:user_id} - %{GREEDYDATA:username}, (Resp Status: %{NUMBER:status}|Resp Time: %{NUMBER:duration})"

It is matching for 2 types of lines in grok debugger in kibana.

It has a newline and 21 spaces embedded in the pattern. A single line will not have a newline embedded in it.

But logstash parses every log line as a new event. So logstash knows it is a newline and will try to match it with a pattern instead. I am so confused now.

Logstash will break input at every Belize and start a new event. Without a multiline codec you will not find a single event with a new line in the message field.

Hi @Christian_Dahlqvist i don't want all the information from the log lines. All i want is to parse few lines and push other lines as GREEDYDATA. I think we have been confused with for example if a class is [operator app mixins] i want all the lines under that class in a single event, but that is not the case.

If you want multiple lines in a single message field you need to use a multiline codec irrespective of what you want to do with them later in. It might be easier to explain if you provide a sample from s log file together with what you are expecting.

HI @Christian_Dahlqvist

INFO 2019-08-28 21:49:57,953 [Operator App Mixins] Request URL: /api/v1/operatorapp/societySystem/manualGateEvent/
INFO 2019-08-28 21:49:57,953 [Operator App Mixins] Request Query Params: <QueryDict: {}>
INFO 2019-08-28 21:49:57,954 [Operator App Mixins] Request Data: {u'gate_number': 2, u'action_type': u'open_gate', u'created': u'28-08-2019 09:49 PM'}
INFO 2019-08-28 21:49:57,958 [Operator App Mixins] Logged In operator- 3374 - M2K Aura Exit, URL: /api/v1/operatorapp/societySystem/manualGateEvent/
INFO 2019-08-28 21:49:57,959 [Operator App Mixins] Event Gate: M2K Aura, Gate-2, Exit
INFO 2019-08-28 21:49:57,967 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/manualGateEvent/, Operator: 3374 - M2K Aura Exit, Resp Status: 200
INFO 2019-08-28 21:49:57,967 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/manualGateEvent/, User: 3374 - M2K Aura Exit, Resp Time: 0.024612903595 

Consider these log lines. These lines have one thing in common i.e the class [Operator app mixins]. What i am saying is that i do not want the lines with the same class in a single event. For ex. i only want information from last and second last line and that would work in separate event as well. As you can see in my code basically i am trying to do is if i find class == operator app mixins i is have defined a grok pattern to match

and if the pattern is not matching even if class is [operator app mixins], that would issue a _grokparsefailure tag and thereby just store the unmatched line as greedydata.

As per my knowledge logstash processes every log line as single event and thats what i want every line in a single log event.

I used multiline codec for stacktrace where i wanted logstash to put all the stacktrace in the event itself. But in this case separate event would also work.

AS Badger pointed out earlier the problem seems to be that you have broken up the match pattern into two lines in your config. Bring this all back into a single line and it should be fine.

It should read:

 match => { "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] URL: %{URIPATHPARAM:url}, User: %{NUMBER:user_id} - %{GREEDYDATA:username}, (Resp Status: %{NUMBER:status}|Resp Time: %{NUMBER:duration})"

and not:

 match => { "message" => "%{LOGLEVEL:severity} %{TIMESTAMP_ISO8601:timestamp} \[%{DATA:class}\] URL: %{URIPATHPARAM:url},
                      User: %{NUMBER:user_id} - %{GREEDYDATA:username}, (Resp Status: %{NUMBER:status}|Resp Time: %{NUMBER:duration})"

Lol my bad. I misunderstood what badger pointed out. It is working now. Thanks a lot.

{
      "gateName" => "M2K Aura Exit",
         "extra" => "URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, Operator: 3374 - M2K Aura Exit, Resp Status: 200",
      "operator" => "3374",
          "path" => "/home/rajdeep/Desktop/lg7",
       "message" => "INFO 2019-08-29 00:55:51,543 [Operator App Mixins] URL: /api/v1/operatorapp/societySystem/mqttDisconnected/, Operator: 3374 - M2K Aura Exit, Resp Status: 200",
    "@timestamp" => 2019-09-11T05:41:59.159Z,
     "timestamp" => [
        [0] "2019-08-29 00:55:51,543",
        [1] "2019-08-29 00:55:51,543"
    ],
          "host" => "rajdeep-ThinkPad-T460s",
      "@version" => "1",
      "severity" => [
        [0] "INFO",
        [1] "INFO"
    ],
           "url" => "/api/v1/operatorapp/societySystem/mqttDisconnected/",
         "class" => [
        [0] "Operator App Mixins",
        [1] "Operator App Mixins"
    ],
        "status" => "200"
}

I am gettting same tags in an even as you can see from the output. As it is an array i am not really sure how i can delete specific element from an array. For ex. i am getting 2 elements in class and wish to remove one.

The reason for the arrays is that you are running multiple grok messages to extract the same fields. After you have run the first grok you have already parsed out timestamp, severity and class and stored everything else in extra. You should use the remaining grok expressions to just parse the extra field, not message. That way you only extract these fields once and avoid arrays.

You can also stop overwriting the message field and potentially also remove the following structure which I see no point in:

if "_grokparsefailure" in [tags] {
                grok {
                        match => {"message" => "%{GREEDYDATA:message}"}
                }
         }

oh coool cleared a lot of my doubts. I thought overwriting message should be enough to replace old message field with the new one matched with pattern and hence it should print only once.
Thanks sir.

If you would like to add any more information in any regards that would be appreciated.