With my latest venture into ElasticSearch and log aggregation I wanted to get my IIS logs put into it. That was easy using the FileBeat and turning on the IIS module. There's plenty of instructions and guides on ElasticSearch's website on how to do that.

Searching them with the default log config in IIS was a bit problematic. I had to look them up by the site number which is server specific. I have 8 sites on 1 server. So there was W3SVC1, W3SVC2, W3SVC3, etc. On another server I have 2, W3SVC1, W3SVC2. This starts causing some pretty good confusion when keep sites seperate.

Also, I have gotten in the habbit of adding every field into the IIS log except for the cookie field. That field is too big and I have yet to ever need it in past 12 years.

Since there are by default 3 log field combinations that are supported by the file beat and the only one that had the hostname in it included the cookie, I set out to create the 4th one that I needed.

Figuring out the grok statement was easy. I just copied the line with everything and removed the cookie field. Here's what I came up with:

%{TIMESTAMP_ISO8601:iis.access.time} %{NOTSPACE:iis.access.site_name} %{NOTSPACE:iis.access.server_name} %{IPORHOST:iis.access.server_ip} %{WORD:iis.access.method} %{URIPATH:iis.access.url} %{NOTSPACE:iis.access.query_string} %{NUMBER:iis.access.port} %{NOTSPACE:iis.access.user_name} %{IPORHOST:iis.access.remote_ip} HTTP/%{NUMBER:iis.access.http_version} %{NOTSPACE:iis.access.agent} %{NOTSPACE:iis.access.referrer} %{NOTSPACE:iis.access.hostname} %{NUMBER:iis.access.response_code} %{NUMBER:iis.access.sub_status} %{NUMBER:iis.access.win32_status} %{NUMBER:iis.access.body_sent.bytes} %{NUMBER:iis.access.body_received.bytes} %{NUMBER:iis.access.request_time_ms}

Nice and long, but pretty easy. You'll need to add that line into the list of available grok statements. So with that, throw quotes around it, with a comma at the end and put in the <filebeat install dir>\module\iis\access\ingest\default.json.

The grok part of my default.json looks like this:

    "grok": {
      "field": "message",
        "%{TIMESTAMP_ISO8601:iis.access.time} %{IPORHOST:iis.access.server_ip} %{WORD:iis.access.method} %{URIPATH:iis.access.url} %{NOTSPACE:iis.access.query_string} %{NUMBER:iis.access.port} %{NOTSPACE:iis.access.user_name} %{IPORHOST:iis.access.remote_ip} %{NOTSPACE:iis.access.agent} %{NOTSPACE:iis.access.referrer} %{NUMBER:iis.access.response_code} %{NUMBER:iis.access.sub_status} %{NUMBER:iis.access.win32_status} %{NUMBER:iis.access.request_time_ms}",
        "%{TIMESTAMP_ISO8601:iis.access.time} %{NOTSPACE:iis.access.site_name} %{WORD:iis.access.method} %{URIPATH:iis.access.url} %{NOTSPACE:iis.access.query_string} %{NUMBER:iis.access.port} %{NOTSPACE:iis.access.user_name} %{IPORHOST:iis.access.remote_ip} %{NOTSPACE:iis.access.agent} %{NOTSPACE:iis.access.cookie} %{NOTSPACE:iis.access.referrer} %{NOTSPACE:iis.access.hostname} %{NUMBER:iis.access.response_code} %{NUMBER:iis.access.sub_status} %{NUMBER:iis.access.win32_status} %{NUMBER:iis.access.body_sent.bytes} %{NUMBER:iis.access.body_received.bytes} %{NUMBER:iis.access.request_time_ms}",
        "%{TIMESTAMP_ISO8601:iis.access.time} %{NOTSPACE:iis.access.site_name} %{NOTSPACE:iis.access.server_name} %{IPORHOST:iis.access.server_ip} %{WORD:iis.access.method} %{URIPATH:iis.access.url} %{NOTSPACE:iis.access.query_string} %{NUMBER:iis.access.port} %{NOTSPACE:iis.access.user_name} %{IPORHOST:iis.access.remote_ip} HTTP/%{NUMBER:iis.access.http_version} %{NOTSPACE:iis.access.agent} %{NOTSPACE:iis.access.referrer} %{NOTSPACE:iis.access.hostname} %{NUMBER:iis.access.response_code} %{NUMBER:iis.access.sub_status} %{NUMBER:iis.access.win32_status} %{NUMBER:iis.access.body_sent.bytes} %{NUMBER:iis.access.body_received.bytes} %{NUMBER:iis.access.request_time_ms}",
        "%{TIMESTAMP_ISO8601:iis.access.time} %{NOTSPACE:iis.access.site_name} %{NOTSPACE:iis.access.server_name} %{IPORHOST:iis.access.server_ip} %{WORD:iis.access.method} %{URIPATH:iis.access.url} %{NOTSPACE:iis.access.query_string} %{NUMBER:iis.access.port} %{NOTSPACE:iis.access.user_name} %{IPORHOST:iis.access.remote_ip} HTTP/%{NUMBER:iis.access.http_version} %{NOTSPACE:iis.access.agent} %{NOTSPACE:iis.access.cookie} %{NOTSPACE:iis.access.referrer} %{NOTSPACE:iis.access.hostname} %{NUMBER:iis.access.response_code} %{NUMBER:iis.access.sub_status} %{NUMBER:iis.access.win32_status} %{NUMBER:iis.access.body_sent.bytes} %{NUMBER:iis.access.body_received.bytes} %{NUMBER:iis.access.request_time_ms}"
      "ignore_missing": true

At first I thought that was it, but it isn't. I was still getting the Provided Grok expressions do not match field value log entries in Kibana and it wasn't parsing the log fields.

Turns out that the file beat just pushes the raw log entry up to the elastic search server and says runs this through a pipeline. I found the name of the pipeline by turning on debug logging in the filebeat. To do that, in the filebeat.yml file, uncomment the logging.debug: true line.

You'll see the name of the pipeline fly by in a debug entry that looks something like this:

2018-12-19T21:30:21.958-0700	DEBUG	[publish]	pipeline/processor.go:308	Publish event: {
  "@timestamp": "2018-12-20T04:30:21.958Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "doc",
    "version": "6.5.3",
    "pipeline": "filebeat-6.5.3-iis-access-default"

As of 6.5.3 the default pipeline name is filebeat-6.5.3-iis-access-default.

With the name of the pipeline we can now update the pipeline in Elasticsearch. To do that we need to send a PUT request to the elastic search server to update the pipeline.

I used PowerShell to do it since I'm on a Windows system and I like PowerShell.
I recommend making a backup of the current pipeline. Here's the PowerShell command to do that, it saves it to a file named old.json

Invoke-WebRequest -uri http://<elasticsearchserver>:9200/_ingest/pipeline/filebeat-6.5.3-iis-access-default | set-content old.json

Here's the PowerShell command to update the pipeline in elastic search.

Invoke-WebRequest -uri http://<elasticsearchserver>:9200/_ingest/pipeline/filebeat-6.5.3-iis-access-default -ContentType "application/json" -InFile '<filebeat install dir>\module\iis\access\ingest\default.json' -Method PUT

Once I updated the pipeline in the elasticsearch server the IIS log entries started getting populated correctly.

Another thing to note, when you look at the backup copy you'll notice that all of the formatting is gone. I personally recommend Visual Studio Code for most file editing. You can open up that json file in there and format it using Ctrl+Shift+F so its readable.

Since I had to dig into the configs to find it, the 3 formats/field combinations supported by the file beat right out of the box are:

Field Elastic Field 1 2 3
Date @timestamp x x x
Time @timestamp x x x
Service Name iis.access.site_name x x
Server Name iis.access.server_name x
Server IP Address iis.access.server_ip x
Method iis.access.method x x x
URI Stem iis.access.url x x x
URI Query iis.access.query_string x x x
Server Port iis.access.port x x x
User Name iis.access.user_name x x x
Client IP Address iis.access.remote_ip x x x
Protocol Version iis.access.http_version x
User Agent iis.access.user_agent.original x x x
Cookie iis.access.cookie x x
Referer iis.access.referrer x x x
Host iis.access.hostname x x
Protocol Status iis.access.response_code x x x
Protocol Substatus iis.access.sub_status x x x
Win32 Status iis.access.win32_status x x x
Bytes Sent iis.access.body_sent.bytes x x
Bytes Received iis.access.body_received.bytes x x
Time Taken iis.access.request_time_ms x x x

These are not in order of the log field dialog. They are in order of the fields in the log file itself.