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

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

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

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

@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

@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

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?

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