IIS module timestamp incorrect

I'm testing out Filebeat's IIS module. I noticed that it doesn't seem to use the time from the log as the timestamp. It's using the time it was sent to Logstash.


According to the \module\iis\access\ingest\default.json, it's supposed to rename @timestamp to event.created. This is followed with a date filter that targets @timestamp. I tested my log formats against the grok filters that are in this JSON file and they match as expected.

Any ideas? Is this a bug, a misunderstanding, or expected behavior?

Hmm the timestamp here should be the timestamp from iis log iis.access.time. What does you full json look like?

The JSON has the incorrect date in the timestamp field as well.
{
"_index": "filebeat-7.3.2-2019.09.27",
"_type": "_doc",
"_id": "fopQcm0BhpCvjL4hPPst",
"_version": 1,
"_score": null,
"_source": {
"tags": [
"beats",
"beats_input_codec_plain_applied"
],
"event": {
"dataset": "iis.access",
"module": "iis"
},
"ecs": {
"version": "1.0.1"
},
"agent.name": "LOGSTASH_SERVER",
"message": "2019-09-25 23:58:37 1.1.1.1 POST /signalr/poll transport=longPolling&clientProtocol=1.5&connectionToken=xnlE6XOdj2rszG3D1%2BDtTI6VTxAq3FQ%2BkFNkGtsQLnk2%2BsUcbBzoFf0k99MZumULjpKGwD%2F8plOPscLJKGlPElGgiD7raKDeuu7NU7x%2Fn86j2h3bzig%2FANQd%2BLC%2BOOrU&connectionData=%5B%7B%22name%22%3A%22systemeventhub%22%7D%5D 80 - 172.24.46.66 Mozilla/5.0+(Windows+NT+10.0;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/75.0.3770.142+Safari/537.36 http://example.com/Bko 200 0 0 110247",
"@version": "1",
"log": {
"offset": 3167844,
"file": {
"path": "C:\inetpub\logs\LogFiles\W3SVC1\u_ex190925.log"
}
},
"fileset": {
"name": "access"
},
"host": {
"name": "IIS_SERVER",
"architecture": "x86_64",
"os": {
"kernel": "10.0.14393.3179 (rs1_release_1.190806-2245)",
"build": "14393.3181",
"family": "windows",
"platform": "windows",
"name": "Windows Server 2016 Datacenter",
"version": "10.0"
},
"hostname": "IIS_SERVER",
"id": "deb520fa-902b-4146-949d-1bbed00b4d31"
},
"agent": {
"ephemeral_id": "c4f5daad-5740-4946-8efa-6f353e6d7120",
"version": "7.3.2",
"type": "filebeat",
"hostname": "IIS_SERVER",
"id": "df3b0ae6-093e-4339-ac90-c69ef1264237"
},
"service": {
"type": "iis"
},
"@timestamp": "2019-09-27T10:41:59.332Z",
"agent.type": "logstash",
"input": {
"type": "log"
}
},
"fields": {
"@timestamp": [
"2019-09-27T10:41:59.332Z"
],
"suricata.eve.timestamp": [
"2019-09-27T10:41:59.332Z"
]
},
"highlight": {
"service.type": [
"@kibana-highlighted-field@iis@/kibana-highlighted-field@"
],
"event.dataset": [
"@kibana-highlighted-field@iis.access@/kibana-highlighted-field@"
]
},
"sort": [
1569580919332
]
}
Sorry for the lack of formatting. The forum doesn't seem to want to cooperate.

Thanks! @timestamp field should be the timestamp from your iis log for sure. For example https://github.com/elastic/beats/blob/master/filebeat/module/iis/access/test/test-iis-7.2.log-expected.json#L3 you can see the @timestamp is from the log not local time when the test was ran.

You are running filebeat 7.3.2 on windows 10?

Sorry for the delay. It's a Windows 2016 server.

Looking at the JSON you posted earlier, I realized there is no field actually get parsed at all. With a working pipeline, the message field is actually should be removed as well. But it seems to only have the messgae field, which seems to me only from the filebeat input but not after any iis pipeline.

Could you check if the pipeline is installed correctly? If you open kibana Dev Tools, and run GET _ingest/pipeline, you should see all the pipelines installed. For this specific case, you should see the iis access pipeline and if you run GET _ingest/pipeline/filebeat-7.3.2-iis-access-default, you should see the pipeline for iis access fileset.

I do see the pipelines when looking at _ingest/pipeline/filebeat-7.3.2-iis-access-default.

{
  "filebeat-7.3.2-iis-access-default" : {
    "processors" : [
      {
        "grok" : {
          "pattern_definitions" : {
            "URIPATHWITHBRACKET" : """(?:/[A-Za-z0-9$.+!*'(){},~:;=@#%&_\-\[\]]*)+"""
          },
          "ignore_missing" : true,
          "field" : "message",
          "patterns" : [
            "%{TIMESTAMP_ISO8601:iis.access.time} %{IPORHOST:destination.address} %{WORD:http.request.method} %{URIPATHWITHBRACKET:url.path} %{NOTSPACE:url.query} %{NUMBER:destination.port:long} %{NOTSPACE:user.name} %{IPORHOST:source.address} %{NOTSPACE:user_agent.original} %{NOTSPACE:http.request.referrer} %{NUMBER:http.response.status_code:long} %{NUMBER:iis.access.sub_status:long} %{NUMBER:iis.access.win32_status:long} %{NUMBER:temp.duration:long}",
            "%{TIMESTAMP_ISO8601:iis.access.time} %{NOTSPACE:iis.access.site_name} %{WORD:http.request.method} %{URIPATH:url.path} %{NOTSPACE:url.query} %{NUMBER:destination.port:long} %{NOTSPACE:user.name} %{IPORHOST:source.address} %{NOTSPACE:user_agent.original} %{NOTSPACE:iis.access.cookie} %{NOTSPACE:http.request.referrer} %{NOTSPACE:destination.domain} %{NUMBER:http.response.status_code:long} %{NUMBER:iis.access.sub_status:long} %{NUMBER:iis.access.win32_status:long} %{NUMBER:http.response.body.bytes:long} %{NUMBER:http.request.body.bytes:long} %{NUMBER:temp.duration:long}",
            "%{TIMESTAMP_ISO8601:iis.access.time} %{NOTSPACE:iis.access.site_name} %{NOTSPACE:iis.access.server_name} %{IPORHOST:destination.address} %{WORD:http.request.method} %{URIPATH:url.path} %{NOTSPACE:url.query} %{NUMBER:destination.port:long} %{NOTSPACE:user.name} %{IPORHOST:source.address} HTTP/%{NUMBER:http.version} %{NOTSPACE:user_agent.original} %{NOTSPACE:iis.access.cookie} %{NOTSPACE:http.request.referrer} %{NOTSPACE:destination.domain} %{NUMBER:http.response.status_code:long} %{NUMBER:iis.access.sub_status:long} %{NUMBER:iis.access.win32_status:long} %{NUMBER:http.response.body.bytes:long} %{NUMBER:http.request.body.bytes:long} %{NUMBER:temp.duration:long}",
            """%{TIMESTAMP_ISO8601:iis.access.time} \[%{IPORHOST:destination.address}\]\(http://%{IPORHOST:destination.address}\) %{WORD:http.request.method} %{URIPATH:url.path} %{NOTSPACE:url.query} %{NUMBER:destination.port:long} %{NOTSPACE:user.name} \[%{IPORHOST:source.address}\]\(http://%{IPORHOST:source.address}\) %{NOTSPACE:user_agent.original} %{NUMBER:http.response.status_code:long} %{NUMBER:iis.access.sub_status:long} %{NUMBER:iis.access.win32_status:long} %{NUMBER:temp.duration:long}""",
            "%{TIMESTAMP_ISO8601:iis.access.time} %{IPORHOST:destination.address} %{WORD:http.request.method} %{URIPATH:url.path} %{NOTSPACE:url.query} %{NUMBER:destination.port:long} %{NOTSPACE:user.name} %{IPORHOST:source.address} %{NOTSPACE:user_agent.original} %{NUMBER:http.response.status_code:long} %{NUMBER:iis.access.sub_status:long} %{NUMBER:iis.access.win32_status:long} %{NUMBER:temp.duration:long}"
          ]
        }
      },
      {
        "remove" : {
          "field" : "message"
        }
      },
      {
        "rename" : {
          "field" : "@timestamp",
          "target_field" : "event.created"
        }
      },
      {
        "date" : {
          "field" : "iis.access.time",
          "target_field" : "@timestamp",
          "formats" : [
            "yyyy-MM-dd HH:mm:ss"
          ]
        }
      },
      {
        "remove" : {
          "field" : "iis.access.time"
        }
      },
      {
        "script" : {
          "params" : {
            "scale" : 1000000.0
          },
          "if" : "ctx.temp?.duration != null",
          "lang" : "painless",
          "source" : "ctx.event.duration = Math.round(ctx.temp.duration * params.scale)"
        }
      },
      {
        "remove" : {
          "field" : "temp.duration",
          "ignore_missing" : true
        }
      },
      {
        "urldecode" : {
          "field" : "user_agent.original"
        }
      },
      {
        "user_agent" : {
          "field" : "user_agent.original"
        }
      },
      {
        "grok" : {
          "pattern_definitions" : {
            "NOZONEIP" : "[^%]*"
          },
          "field" : "destination.address",
          "ignore_failure" : true,
          "patterns" : [
            "%{NOZONEIP:destination.ip}"
          ]
        }
      },
      {
        "grok" : {
          "patterns" : [
            "%{NOZONEIP:source.ip}"
          ],
          "pattern_definitions" : {
            "NOZONEIP" : "[^%]*"
          },
          "field" : "source.address",
          "ignore_failure" : true
        }
      },
      {
        "geoip" : {
          "field" : "source.ip",
          "target_field" : "source.geo",
          "ignore_missing" : true
        }
      }
    ],
    "on_failure" : [
      {
        "set" : {
          "field" : "error.message",
          "value" : "{{ _ingest.on_failure_message }}"
        }
      }
    ],
    "description" : "Pipeline for parsing IIS access logs. Requires the geoip and user_agent plugins."
  }
}

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.