_grokparsefailure still happening for a small number of IIS log entries - how to track them down?

Elastic Stack Logstash
1

So, moving on from my previous 2 posts. I am making good progress, slowly admittedly, but I am learning a heck of a lot as I go!

I am still having a very small number (approx <0.1%) of my IIS log entries failing with _grokparsefailure and I am at a loss how to track them down to see why they fail!

My latest /etc/logstash/conf.d/logstash-iis.conf file is

input {  
	tcp {
		type => "iis"
		port => "3516"
		host => "10.4.10.8"
	}
}

filter {
 
  #ignore log comments
  if [message] =~ "^#" {
    drop {}
  }

grok {
    match => ["message", "%{TIMESTAMP_ISO8601:timestamp} %{IPORHOST:hostip} %{WORD:method} %{NOTSPACE:page} %{NOTSPACE:query} %{NUMBER:port} %{NOTSPACE:username} %{IPORHOST:clientip} %{NOTSPACE:useragent} %{NOTSPACE:referrer} %{NUMBER:response} %{NUMBER:subresponse} %{NUMBER:scstatus} %{NUMBER:timetaken}"]
	}
  
  #Set the Event Timestamp from the log
	date {
		match => [ "timestamp", "YYYY-MM-dd HH:mm:ss" ]
		target => "@timestamp"
		timezone => "Europe/London"
    }	
	
useragent {
	source=> "useragent"
	prefix=> "browser"
	}

mutate {
	remove_field => [ "timestamp"]
    }
}

output {
  if "_grokparsefailure" in [tags] {
		elasticsearch_http { 
		index => [ "gpf-%{+YYYY.MM.dd}" ]
		host => "10.4.10.8"
        port => "9200"
	}
  } else {
		elasticsearch_http {
        host => "10.4.10.8"
        port => "9200"	
        }
  }
}

I am temporarily separating out the _grokparsefailures into a different index ( gpf-%{+YYYY.MM.dd} ) so I can easily delete them later, as currently they serve little purpose as they have no usable IIS data recorded with them.

Before I drop them entirely, is there any way (on just the failures) to force a second GROK match, but this time use GREEDYDATA to capture everything? (so I have some reference data points from the IIS logs to start looking into to understand why the first match fails).

I have tested the below with the GROK debugger & my sample IIS data; it captures everything in a single entry - this will be perfect for fault finding.

match => ["message", "%{GREEDYDATA:badiisdata}"]

The question is how do I get this second match to run only if the first fails?

Any suggestions will be appreciated.

Martin

2

Just use a conditional after the first grok filter (plus the rest) so that if grokparsefailure in tags, then use your customer pattern.

1 Like
3

If grok fails the full original message will be in the message field, no? So unless you explicitly delete that field you can inspect it afterwards to debug the pattern.

1 Like
4

@warkolm - Thank you Mark. I am not a programmer. Would you be kind enough to give me a contextual example?

@magnusbaeck - Thank you again Magnus. The message field is always empty for the messages that are tagged _grokparsefailure. I do not believe I am explicitly deleting it.

Cheers,
Martin

5

@warkolm, @magnusbaeck

I am genuinely grateful for both of your help so far, but I am still struggling with this.

What ever I do the _grokparsefailure messages always have an empty message field.

My very limited knowledge was exhausted days ago.

I have asked sales for a cost on a year of gold support (just to solve this problem), but all of them seem to be out on the elastic{on} jolly. They wont even email me a quote! They reply to emails but insist on speaking to me (when they get back).

Thanks
M

6

What ever I do the _grokparsefailure messages always have an empty message field.

Maybe they are empty and the grok problem is caused by that—have you tried dropping empty lines?

7

Yesterday's log file has 3.2 million lines and there were 50 failures!

I cannot see any empty/blank lines. They all look the same!

If I could add a numerical counter tag to each entry passed through Logstash, maybe I could zero in on the offending lines.

I have a call with Elastic sales on Monday so I may have a support contract in place within the next few weeks - hopefully they will be able to work out what is going wrong.

Thank you
Martin