Parsing Windows DHCP Logs with Filebeat Microsoft Module

Elastic Stack Beats
,
1

Hello,

We're trying to use the new microsoft.yml module in Filebeat 7.9.0 to ingest and parse Windows DHCP logs. The configuration seems pretty straightfoward, we just pointed it to the default C:\Windows\System32\dhcp\Dhcp*.log path and it's successfully picking up and ingesting logs to Elasticsearch using the filebeat-7.9.0-microsoft-dhcp-pipeline pipeline.

The problem is that we're not seeing the actual log message (event.original field) being parsed and the log.flags field says "dissect_parsing_error". There isn't much in the elasticsearch pipeline other than GeoIP and AS Number lookups, so the parsing is probably being done on the filebeat microsoft module itself. Does this module in fact support Windows DHCP log files? Are we doing something wrong here?

Here's a redacted sample document.

    {
      "_index" : "filebeat-****",
      "_type" : "_doc",
      "_id" : "X8E7rnUBMjJeomsYIKY4",
      "_version" : 1,
      "_seq_no" : 11126638,
      "_primary_term" : 1,
      "found" : true,
      "_source" : {
        "agent" : {
          "hostname" : "****",
          "name" : "****",
          "id" : "c709e499-2a95-42e4-abf2-6ce37248dc81",
          "type" : "filebeat",
          "ephemeral_id" : "fce124aa-9f0d-4be6-8809-edb2c7661c13",
          "version" : "7.9.0"
        },
        "log" : {
          "file" : {
            "path" : """C:\Windows\system32\dhcp\DhcpSrvLog-Mon.log"""
          },
          "offset" : 456993,
          "flags" : [
            "dissect_parsing_error"
          ]
        },
        "fileset" : {
          "name" : "dhcp"
        },
        "tags" : [
          "microsoft.dhcp",
          "forwarded",
          "beats_input_raw_event"
        ],
        "input" : {
          "type" : "log"
        },
        "observer" : {
          "product" : "DHCP",
          "vendor" : "Microsoft",
          "type" : "Application"
        },
        "@timestamp" : "2020-11-09T18:18:30.788Z",
        "ecs" : {
          "version" : "1.5.0"
        },
        "service" : {
          "type" : "microsoft"
        },
        "organization" : {
          "name" : "****",
          "id" : "****"
        },
        "host" : {
          "hostname" : "****",
          "os" : {
            "name" : "Windows Server 2012 Standard"
          },
          "ip" : [
            "10.3.1.2",
            "fe80::5efe:a03:102"
          ],
          "mac" : [
            "00:0c:29:c1:37:5a",
            "00:00:00:00:00:00:00:e0"
          ]
        },
        "@version" : "1",
        "event" : {
          "original" : "11,11/09/20,13:18:29,Renew,172.16.1.90,****.****.corp,00073BB23E92,,317371525,0,,,,0x6363702E61766179612E636F6D,ccp.avaya.com,,,",
          "module" : "microsoft",
          "dataset" : "microsoft.dhcp"
        }
      }
    }

Thanks,
Kam

1 Like
2

Did you try to enable debug logs and once again try to parse DHCP logs? BTW could you please post sample log lines?

3

Hi Marcin,

There is nothing really interesting in the filebeat debug logs either. I'm seeing the same "dissect_parsing_error" in the JSON document generated by Filebeat. Please see below. Am I under the right impression that the module is supposed to actually parse event.original into its components or is that perhaps still work in progress?

2020-11-17T12:52:01.649-0500	DEBUG	[processors]	processing/processors.go:112	Fail to apply processor global{add_host_metadata=[netinfo.enabled=[true], cache.ttl=[5m0s]], add_cloud_metadata={}, add_fields={"****":{"key":"****","version":"1.2.0"}}, drop_fields={"Fields":["host.architecture","host.id","host.os.build","host.os.family","host.os.kernel","host.os.platform","host.os.version"],"IgnoreMissing":false}, drop_event, condition=contains: map[] or contains: map[] or contains: map[] or contains: map[]}: failed to drop field [winlog.api]: key not found
2020-11-17T12:52:01.649-0500	DEBUG	[processors]	processing/processors.go:187	Publish event: {
  "@timestamp": "2020-11-17T17:52:01.649Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "_doc",
    "version": "7.9.0",
    "pipeline": "filebeat-7.9.0-microsoft-dhcp-pipeline"
  },
  "agent": {
    "id": "58bdba40-0b44-4e50-9dc7-fd2f6ab2954e",
    "name": "****",
    "type": "filebeat",
    "version": "7.9.0",
    "hostname": "****",
    "ephemeral_id": "1681ed74-3680-47cc-a3b3-0234b1314b69"
  },
  "host": {
    "os": {
      "name": "Windows Server 2012 Standard"
    },
    "ip": [
      "10.3.1.2",
      "fe80::5efe:a03:102"
    ],
    "mac": [
      "00:0c:29:c1:37:5a",
      "00:00:00:00:00:00:00:e0"
    ],
    "hostname": "****"
  },
  "****": {
    "version": "****",
    "key": "****"
  },
  "log": {
    "offset": 390230,
    "file": {
      "path": "C:\\Windows\\system32\\dhcp\\DhcpSrvLog-Sun.log"
    },
    "flags": [
      "dissect_parsing_error"
    ]
  },
  "observer": {
    "type": "Application",
    "vendor": "Microsoft",
    "product": "DHCP"
  },
  "service": {
    "type": "microsoft"
  },
  "event": {
    "module": "microsoft",
    "dataset": "microsoft.dhcp",
    "original": "11,11/15/20,11:33:06,Renew,172.16.1.115,AVTB23FC5.****.****,00073BB23FC5,,657818244,0,,,,0x6363702E61766179612E636F6D,ccp.avaya.com,,,"
  },
  "ecs": {
    "version": "1.5.0"
  },
  "tags": [
    "microsoft.dhcp",
    "forwarded"
  ],
  "fileset": {
    "name": "dhcp"
  },
  "input": {
    "type": "log"
  }
}
1 Like
4

I am seeing this as well. I had previously picked up the files just in filebeat.yml, and parsed them myself in Logstash, but decided to give this new Microsoft module a try. We are running 7.10.0 throughout the stack.

5

Thanks for raising this issue @kkojouri and @MakoWish. Could you post some sample log lines from dhcp.log so we can look at the format and adjust the DHCP pipeline if needed? Sanitised logs are fine. If you prefer to send them to me privately, I can provide my details.

Thanks!

6

Hi @jamie.hynds!

Absolutely! Here are the first 34 header/intro lines followed by what should be a pretty decent sample of messages from today's DHCP log, DhcpSrvLog-Fri.log, on one of our Domain Controllers:

		Microsoft DHCP Service Activity Log


Event ID  Meaning
00	The log was started.
01	The log was stopped.
02	The log was temporarily paused due to low disk space.
10	A new ip_address was leased to a client.
11	A lease was renewed by a client.
12	A lease was released by a client.
13	An ip_address was found to be in use on the network.
14	A lease request could not be satisfied because the scope's address pool was exhausted.
15	A lease was denied.
16	A lease was deleted.
17	A lease was expired and DNS records for an expired leases have not been deleted.
18	A lease was expired and DNS records were deleted.
20	A BOOTP address was leased to a client.
21	A dynamic BOOTP address was leased to a client.
22	A BOOTP request could not be satisfied because the scope's address pool for BOOTP was exhausted.
23	A BOOTP ip_address was deleted after checking to see it was not in use.
24	ip_address cleanup operation has began.
25	ip_address cleanup statistics.
30	DNS update request to the named DNS server.
31	DNS update failed.
32	DNS update successful.
33	Packet dropped due to NAP policy.
34	DNS update request failed.as the DNS update request queue limit exceeded.
35	DNS update request failed.
36	Packet dropped because the server is in failover standby role or the hash of the client ID does not match.
50+	Codes above 50 are used for Rogue Server Detection information.

QResult: 0: NoQuarantine, 1:Quarantine, 2:Drop Packet, 3:Probation,6:No Quarantine Information ProbationTime:Year-Month-Day Hour:Minute:Second:MilliSecond.

ID,Date,Time,Description,ip_address,Host Name,MAC Address,User Name, TransactionID, QResult,Probationtime, CorrelationID,Dhcid,VendorClass(Hex),VendorClass(ASCII),UserClass(Hex),UserClass(ASCII),RelayAgentInformation,DnsRegError.
24,11/20/20,00:00:05,Database Cleanup Begin,,,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
17,11/20/20,00:00:05,DNS record not deleted,<ip_address>,,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
31,11/20/20,00:00:05,DNS Update Failed,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,9005
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
30,11/20/20,00:00:05,DNS Update Request,<ip_address>,hostname.contoso.com,,,0,6,,,,,,,,,0
1 Like
7

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