Receiving partial messages in elastic

[ytld]

We have a problem in our ELK-stack of which I'm unsure how to solve. We're running 8.3 version of the ELK-stack on Centos 7 machines and whereas everything worked fine before, since this week we're only seeing partial messages appear in elastic/kibana.

A typical IIS event log shows up as below, where you can see the data has been truncated at different for some reason.

• -20 05:45:08 W3SVC5 prd-web 10.233.97.10 POST /GetData - 443 - 10.233.97.11 HTTP/1.1 - - - domain.com 200 0 0 134549 824 15530

• com 200 0 0 988 1049 62

The grok-filters work fine when applied to single lines in the debugger, however once connected to our servers this truncating starts. How should I go about resolving this?

[leandrojmp (Leandro Pereira)]

You need to share your Logstash configuration, or at least the grok filters you are using, and also a sample of the messages that are failing and giving you this issue.

[ytld]

I noticed that when I wait for a few hours logs from the same server and with the same grok-logic applied get parsed correctly. Wouldn't this indicate there might be some kind of performance issue which generates incomplete log-lines is going on?

Screenshot made on july 15th:

Screenshot made on july 16th:

[leandrojmp (Leandro Pereira)]

As I said, you need to share your Logstash configuration and a sambple of the messages, without it is not possible to understand what is happening.

Also, avoiding sharing screenshots as they can be hard to read sometimes and some people may not be even able to see it.

[ytld]

Hi Leandro,

This is my grok-filter:

input{
  beats {
    port => 5044
  }
}
filter {
  if [fields][type] == "iis"{
    grok {
      match => { "message" => "%{TIMESTAMP_ISO8601:log_timestamp} %{WORD:S-SiteName} %{NOTSPACE:S-ComputerName} %{IPORHOST:S-IP} %{WORD:CS-Method} %{NOTSPACE:CS-URI-Stem} %{NOTSPACE:CS-URI-Query} %{NUMBER:S-Port:int} %{NOTSPACE:CS-Username} %{IPORHOST:C-IP} %{NOTSPACE:CS-Version} %{NOTSPACE:CS-UserAgent} %{NOTSPACE:CS-Cookie} %{NOTSPACE:CS-Referer} %{NOTSPACE:CS-Host} %{NUMBER:SC-Status:int} %{NUMBER:SC-SubStatus:int} %{NUMBER:SC-Win32-Status:int} %{NUMBER:SC-Bytes:int} %{NUMBER:CS-Bytes:int} %{NUMBER:Time-Taken:int}"}
    }
    
    # Filter polling calls
    if [CS-URI-Stem] == "/Transactions/CheckTransactionType"{ drop{ } }
    if [CS-URI-Stem] == "/home/CheckStatus"{ drop{ } }
    
    # Map logging timestamp to timestamp index
    date{
      match => ["log_timestamp","yyyy-MM-dd HH:mm:ss"]
      target => "@timestamp"
    }
  }
  
  if [fields][type] == "app"{
    grok {
       match => { "message" => "(^#@@#%{TIMESTAMP_ISO8601:log_timestamp}%{SPACE}%{WORD:LogLevel}%{SPACE}{\"LogRefId\":\"%{DATA:LogRefId}\",\"LogLevel\":(%{NUMBER})?(\"%{WORD}\")?,\"BuildVersion\":(\"\")?(null)?(\"%{NUMBER:BuildVersion}\")?(\"%{WORD:BuildVersionString}\")?,\"Source\":(\"\")?(null)?(\"%{NOTSPACE:Source}\")?,\"Environment\":(\"\")?(null)?(\"%{NOTSPACE:Environment}\")?,\"ExternalRefId\":(\"\")?(null)?(\"%{UUID:ExternalRefId}\")?(\"%{WORD:ExternalRefIdString}\")?,\"Message\":(\"%{NUMBER:ErrorCode}-%{SPACE}?%{DATA:Payload}\")?(\"%{DATA:Payload}\")?(%{DATA:Payload})?}($\n%{GREEDYDATA:Payload})?)?"}
    }

    # Map logging timestamp to timestamp index
    date{
      match => ["log_timestamp","yyyy-MM-dd HH:mm:ss,SSS","ISO8601"]
    }
  }
  
  if [fields][type] == "worker"{
    grok {
       match => { "message" => "(^#@@#%{TIMESTAMP_ISO8601:log_timestamp}%{SPACE}%{WORD:LogLevel}%{SPACE}{\"LogRefId\":\"%{DATA:LogRefId}\",\"LogLevel\":(%{NUMBER})?(\"%{WORD}\")?,\"BuildVersion\":(\"\")?(null)?(\"%{NUMBER:BuildVersion}\")?(\"%{WORD:BuildVersionString}\")?,\"Source\":(\"\")?(null)?(\"%{NOTSPACE:Source}\")?,\"Environment\":(\"\")?(null)?(\"%{NOTSPACE:Environment}\")?,\"ExternalRefId\":(\"\")?(null)?(\"%{UUID:ExternalRefId}\")?(\"%{WORD:ExternalRefIdString}\")?,\"Message\":(\"%{NUMBER:ErrorCode}-%{SPACE}?%{DATA:Payload}\")?(\"%{DATA:Payload}\")?(%{DATA:Payload})?}($\n%{GREEDYDATA:Payload})?)?"}
    }
    # Filter high-frequency calls
    if [Payload] == "GetToken"{ drop{ } }
    if [Payload] == "Data saved successfully"{ drop{ } }

    # Map logging timestamp to timestamp index
    date{
      match => ["log_timestamp","yyyy-MM-dd HH:mm:ss,SSS","ISO8601"]
    }
  }

  if "_grokparsefailure" in [tags] {
    mutate { add_field => { "_grok" => "failed" } }
  }
}

output {
  if [fields][type] == "app"{
    if [fields][environment] =="stg"{
      elasticsearch {
        index => "app_stg_alias"
        hosts => ['kibana.infra.domain.com:9200']
        ilm_enabled => true
	      user => 'elastic'
        password => '<<password>>'
      }
    }
    if [fields][environment] =="prd"{
      elasticsearch {
        index => "app_prd_alias"
        hosts => ['kibana.infra.domain.com:9200']
	      ilm_enabled => true
        user => 'elastic'
        password => '<<password>>'
      }
    }
  }
  if [fields][type] == "iis"{
    if [fields][environment] == "stg"{
      elasticsearch {
        index => "wsus_stg_alias"
        hosts => ['kibana.infra.domain.com:9200']
        ilm_enabled => true
	      user => 'elastic'
        password => '<<password>>'
      }
    }
    if [fields][environment] == "prd"{
      elasticsearch {
        index => "wsus_prd_alias"
        hosts => ['kibana.infra.domain.com:9200']
        ilm_enabled => true
	      user => 'elastic'
        password => '<<password>>'
      }
    }
  }
  if [fields][type] == "worker"{
    if [fields][environment] == "prd"{
      elasticsearch {
        index => "worker_prd_alias"
        hosts => ['kibana.infra.domain.com:9200']
	      ilm_enabled => true
	      user => 'elastic'
	      password => '<<password>>'
      }
    }
    if [fields][environment] == "stg"{
      elasticsearch {
    	index => "worker_stg_alias"
    	hosts => ['kibana.infra.domain.com:9200']
    	ilm_enabled => true
    	user => 'elastic'
    	password => '<<password>>'
      }
    }
  }
# Output for Mongo and cleanup-logs
  if [fields][type] == "mongo"{
    if [fields][environment] == "stg"{
      elasticsearch {
        index => "mongo_stg_alias"
        hosts => ['kibana.infra.domain.com:9200']
        ilm_enabled => true
	      user => 'elastic'
        password => '<<password>>'
      }
    }
    if [fields][environment] == "prd"{
      elasticsearch {
        index => "mongo_prd_alias"
        hosts => ['kibana.infra.domain.com:9200']
        ilm_enabled => true
        user => 'elastic'
        password => '<<password>>'
      }
    }
  }
## used for debugging
#  stdout { codec => json }
}

And this is a sample of the data which comes into logstash:
(with fields.environment: iis and fields.type: prd)

2022-07-18 12:46:03 W3SVC5 prd-web 10.233.97.10 POST /GetData - 443 - 10.233.97.11 HTTP/1.1 - - - domain.com 200 0 0 453 851 2080
2022-07-18 12:47:22 W3SVC5 prd-web 10.233.97.10 POST /GetData - 443 - 10.233.97.11 HTTP/1.1 - - - domain.com 200 0 0 158767 800 14618
2022-07-18 12:47:55 W3SVC5 prd-web 10.233.97.10 POST /GetData - 443 - 10.233.97.11 HTTP/1.1 - - - domain.com 200 0 0 61992 801 17339

It ends in Kibana/Elastic as this:

-20 05:45:08 W3SVC5 prd-web 10.233.97.10 POST /GetData - 443 - 10.233.97.11 HTTP/1.1 - - - domain.com 200 0 0 134549 824 15530
com 200 0 0 988 1049 62
e/96.0.4664.104+Mobile+Safari/537.36 - - domain.com 302 0 0 640 558 72