Nested JSON


(Tim Desrochers) #1

Filebeat 6.2

I am using filebeat to pick up a file from osquery. The file contains windows events from WEL.

Sample data:

{
  "_index": "win_osquery-2018.05.02",
  "_type": "doc",
  "_id": "5xRGImMBm7muvmysFsee",
  "_version": 1,
  "_score": null,
  "_source": {
    "tags": [
      "osquery_windows",
      "beats_input_raw_event"
    ],
    "counter": "0",
    "unixTime": "1525288272",
    "type": "win_osquery",
    "calendarTime": "Wed May  2 19:11:12 2018 UTC",
    "name": "windows_events",
    "columns": {
      "provider_guid": "{5770385F-C22A-43E0-BF4C-06F5698FFBD9}",
      "data": "{\"EventData\":{\"<xmlattr>\":\"\",\"CallTrace\":\"C:\\\\WINDOWS\\\\SYSTEM32\\\\ntdll.dll+a6594|C:\\\\WINDOWS\\\\System32\\\\KERNELBASE.dll+20edd|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+6fb3|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+7471|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+5899|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+adc4|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+aaf1|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+a704|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+77de3|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+443ef|C:\\\\WINDOWS\\\\System32\\\\combase.dll+3b00|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+a92b|C:\\\\WINDOWS\\\\System32\\\\combase.dll+967bc|C:\\\\WINDOWS\\\\System32\\\\combase.dll+96e02|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ae8b8|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ac81d|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aaf74|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aa1fc|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5a194|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+590ad|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+59bfe|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39927|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39f7c|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5426c\",\"GrantedAccess\":\"0x1410\",\"Name\":\"UtcTime,SourceProcessGUID,SourceProcessId,SourceThreadId,SourceImage,TargetProcessGUID,TargetProcessId,TargetImage,GrantedAccess,CallTrace\",\"SourceImage\":\"C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe\",\"SourceProcessGUID\":\"{AD35859D-6702-5A8D-0000-00103B690200}\",\"SourceProcessId\":\"2832\",\"SourceThreadId\":\"30988\",\"TargetImage\":\"C:\\\\WINDOWS\\\\system32\\\\lsass.exe\",\"TargetProcessGUID\":\"{AD35859D-66FC-5A8D-0000-0010F4A50000}\",\"TargetProcessId\":\"684\",\"UtcTime\":\"2018-05-02 19:11:05.020\"}}\\x0A",
      "eventid": "10",
      "source": "Microsoft-Windows-Sysmon/Operational",
      "datetime": "2018-05-02T19:11:05.027156300Z",
      "time": "1525288265",
      "keywords": "-1",
      "provider_name": "Microsoft-Windows-Sysmon",
      "task": "10",
      "level": "4"
    },
    "epoch": "0",
    "hostIdentifier": "HOSTNAME",
    "@version": "1",
    "@timestamp": "2018-05-02T19:11:19.145Z",
    "decorations": {
      "os_name": "Microsoft Windows 10 Enterprise",
      "username": "USERNAME",
      "os_version": "10.0.14393",
      "host_uuid": "BD804D56-9368-07D4-B37E-FB9038ABD62D"
    },
    "offset": 17676584,
    "action": "added"
  },
  "fields": {
    "@timestamp": [
      "2018-05-02T19:11:19.145Z"
    ],
    "columns.datetime": [
      "2018-05-02T19:11:05.027Z"
    ]
  },
  "sort": [
    1525288279145
  ]
}

How can I parse the columns.data field for value EventData. This data as a blob is pretty useless but if filebeat could parse this and like it does columns it would make the data much more useful.

filebeat.conf:

---
filebeat.prospectors:
- type: log
  enabled: true
  json.keys_under_root: true
  json.add_error_key: true
  paths:
    - /path/to/file.log
tags: ["tags1","tags2"]

processors:
- drop_fields:
    fields: ["fields","to","drop"]
- decod_json_fields:
    fields: ["columns.data"]
    process_array: true
    max_depth: 6
    overwrite_keys: true

output.logstash:
  hosts: ["host.com:80]
  loadbalance: true

What am I missing. Is it not possible for filebeat to parse the nested json fields?


(ruflin) #2

Can you share the log output from Filebeat? Best even the log set to debug mode?

As far as I understand the first deconding of json works but the json document has a json string inside the data file?

Could you share the raw log line?


(Tim Desrochers) #3

Original log entry:

{"name":"windows_events","hostIdentifier":"HOST","calendarTime":"Wed May  2 19:11:40 2018 UTC","unixTime":"1525288300","epoch":"0","counter":"0","decorations":{"host_uuid":"BD804D56-9368-07D4-B37E-FB9038ABD62D","os_name":"Microsoft Windows 10 Enterprise","os_version":"10.0.14393","username":"USER"},"columns":{"data":"{\"EventData\":{\"<xmlattr>\":\"\",\"CallTrace\":\"C:\\\\WINDOWS\\\\SYSTEM32\\\\ntdll.dll+a6594|C:\\\\WINDOWS\\\\System32\\\\KERNELBASE.dll+20edd|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+6fb3|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+7471|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+5899|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+adc4|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+aaf1|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+a704|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+77de3|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+443ef|C:\\\\WINDOWS\\\\System32\\\\combase.dll+3b00|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+a92b|C:\\\\WINDOWS\\\\System32\\\\combase.dll+967bc|C:\\\\WINDOWS\\\\System32\\\\combase.dll+96e02|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ae8b8|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ac81d|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aaf74|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aa1fc|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5a194|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+590ad|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+59bfe|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39927|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39f7c|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5426c\",\"GrantedAccess\":\"0x1410\",\"Name\":\"UtcTime,SourceProcessGUID,SourceProcessId,SourceThreadId,SourceImage,TargetProcessGUID,TargetProcessId,TargetImage,GrantedAccess,CallTrace\",\"SourceImage\":\"C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe\",\"SourceProcessGUID\":\"{AD35859D-6702-5A8D-0000-00103B690200}\",\"SourceProcessId\":\"2832\",\"SourceThreadId\":\"34840\",\"TargetImage\":\"C:\\\\WINDOWS\\\\system32\\\\lsass.exe\",\"TargetProcessGUID\":\"{AD35859D-66FC-5A8D-0000-0010F4A50000}\",\"TargetProcessId\":\"684\",\"UtcTime\":\"2018-05-02 19:11:18.908\"}}\\x0A","datetime":"2018-05-02T19:11:18.916273300Z","eventid":"10","keywords":"-1","level":"4","provider_guid":"{5770385F-C22A-43E0-BF4C-06F5698FFBD9}","provider_name":"Microsoft-Windows-Sysmon","source":"Microsoft-Windows-Sysmon\/Operational","task":"10","time":"1525288279"},"action":"added"}

Pretty Printed log:

{
  "name": "windows_events",
  "hostIdentifier": "HOST",
  "calendarTime": "Wed May  2 19:11:40 2018 UTC",
  "unixTime": "1525288300",
  "epoch": "0",
  "counter": "0",
  "decorations": {
    "host_uuid": "BD804D56-9368-07D4-B37E-FB9038ABD62D",
    "os_name": "Microsoft Windows 10 Enterprise",
    "os_version": "10.0.14393",
    "username": "USER"
  },
  "columns": {
    "data": "{\"EventData\":{\"<xmlattr>\":\"\",\"CallTrace\":\"C:\\\\WINDOWS\\\\SYSTEM32\\\\ntdll.dll+a6594|C:\\\\WINDOWS\\\\System32\\\\KERNELBASE.dll+20edd|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+6fb3|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+7471|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+5899|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+adc4|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+aaf1|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+a704|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+77de3|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+443ef|C:\\\\WINDOWS\\\\System32\\\\combase.dll+3b00|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+a92b|C:\\\\WINDOWS\\\\System32\\\\combase.dll+967bc|C:\\\\WINDOWS\\\\System32\\\\combase.dll+96e02|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ae8b8|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ac81d|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aaf74|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aa1fc|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5a194|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+590ad|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+59bfe|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39927|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39f7c|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5426c\",\"GrantedAccess\":\"0x1410\",\"Name\":\"UtcTime,SourceProcessGUID,SourceProcessId,SourceThreadId,SourceImage,TargetProcessGUID,TargetProcessId,TargetImage,GrantedAccess,CallTrace\",\"SourceImage\":\"C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe\",\"SourceProcessGUID\":\"{AD35859D-6702-5A8D-0000-00103B690200}\",\"SourceProcessId\":\"2832\",\"SourceThreadId\":\"34840\",\"TargetImage\":\"C:\\\\WINDOWS\\\\system32\\\\lsass.exe\",\"TargetProcessGUID\":\"{AD35859D-66FC-5A8D-0000-0010F4A50000}\",\"TargetProcessId\":\"684\",\"UtcTime\":\"2018-05-02 19:11:18.908\"}}\\x0A",
    "datetime": "2018-05-02T19:11:18.916273300Z",
    "eventid": "10",
    "keywords": "-1",
    "level": "4",
    "provider_guid": "{5770385F-C22A-43E0-BF4C-06F5698FFBD9}",
    "provider_name": "Microsoft-Windows-Sysmon",
    "source": "Microsoft-Windows-Sysmon/Operational",
    "task": "10",
    "time": "1525288279"
  },
  "action": "added"
}

(Tim Desrochers) #4

Log with filebeat config above but output settings using command C:\Program Files\Filebeat\filebeat.exe'-c 'C:\Program Files\Filebeat\filebeat.yml' -e -v:

output:
  codec.json:
    pretty: true
PS C:\WINDOWS\system32> & 'C:\Program Files\Filebeat\filebeat.exe'-c 'C:\Program Files\Filebeat\filebeat.yml' -e -v
2018-05-02T15:48:00.192-0400    INFO    instance/beat.go:468    Home path: [C:\Program Files\Filebeat] Config path: [C:\Program Files\Filebeat] Data path: [C:\Program Files\Filebeat\data] Logs path: [C:\Program Files\Filebeat\logs]
2018-05-02T15:48:00.212-0400    INFO    instance/beat.go:475    Beat UUID: 19dadf8d-0c58-4257-afb9-85fe82c2c30a
2018-05-02T15:48:00.212-0400    INFO    instance/beat.go:213    Setup Beat: filebeat; Version: 6.2.4
2018-05-02T15:48:00.213-0400    INFO    pipeline/module.go:76   Beat name: NAME
2018-05-02T15:48:00.218-0400    INFO    instance/beat.go:301    filebeat start running.
2018-05-02T15:48:00.219-0400    INFO    registrar/registrar.go:110      Loading registrar data from C:\Program Files\Filebeat\data\registry
2018-05-02T15:48:00.220-0400    INFO    registrar/registrar.go:121      States Loaded from registrar: 1
2018-05-02T15:48:00.221-0400    WARN    beater/filebeat.go:261  Filebeat is unable to load the Ingest Node pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the Ingest Node pipelines or are using Logstash pipelines, you
 can ignore this warning.
2018-05-02T15:48:00.219-0400    INFO    [monitoring]    log/log.go:97   Starting metrics logging every 30s
2018-05-02T15:48:00.246-0400    INFO    crawler/crawler.go:48   Loading Prospectors: 1
2018-05-02T15:48:00.296-0400    INFO    log/prospector.go:111   Configured paths: [C:\ProgramData\osquery\log\osqueryd.results.log]
2018-05-02T15:48:00.300-0400    INFO    crawler/crawler.go:82   Loading and starting Prospectors completed. Enabled prospectors: 1
2018-05-02T15:48:00.313-0400    INFO    log/harvester.go:216    Harvester started for file: C:\ProgramData\osquery\log\osqueryd.results.log
{
  "@timestamp": "2018-05-02T19:48:00.315Z",
  "@metadata": {
    "beat": "filebeat",
    "type": "doc",
    "version": "6.2.4"
  },
  "offset": 2388,
  "counter": "0",
  "action": "added",
  "name": "windows_events",
  "calendarTime": "Wed May  2 19:11:40 2018 UTC",
  "epoch": "0",
  "hostIdentifier": "HOST",
  "unixTime": "1525288300",
  "decorations": {
    "host_uuid": "BD804D56-9368-07D4-B37E-FB9038ABD62D",
    "os_name": "Microsoft Windows 10 Enterprise",
    "os_version": "10.0.14393",
    "username": "USER"
  },
  "columns": {
    "keywords": "-1",
    "provider_guid": "{5770385F-C22A-43E0-BF4C-06F5698FFBD9}",
    "datetime": "2018-05-02T19:11:18.916273300Z",
    "level": "4",
    "provider_name": "Microsoft-Windows-Sysmon",
    "source": "Microsoft-Windows-Sysmon/Operational",
    "data": "{\"EventData\":{\"\u003cxmlattr\u003e\":\"\",\"CallTrace\":\"C:\\\\WINDOWS\\\\SYSTEM32\\\\ntdll.dll+a6594|C:\\\\WINDOWS\\\\System32\\\\KERNELBASE.dll+20edd|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+6fb3|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\cimwin32.dll+7471|C:\\\\WINDOWS\
\\\SYSTEM32\\\\framedynos.dll+5899|C:\\\\WINDOWS\\\\SYSTEM32\\\\framedynos.dll+adc4|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+aaf1|C:\\\\WINDOWS\\\\system32\\\\wbem\\\\wmiprvse.exe+a704|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+77de3|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+443ef|C:\\\\W
INDOWS\\\\System32\\\\combase.dll+3b00|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+a92b|C:\\\\WINDOWS\\\\System32\\\\combase.dll+967bc|C:\\\\WINDOWS\\\\System32\\\\combase.dll+96e02|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ae8b8|C:\\\\WINDOWS\\\\System32\\\\combase.dll+ac81d|C:\\\\WINDOWS\\\\Syst
em32\\\\combase.dll+aaf74|C:\\\\WINDOWS\\\\System32\\\\combase.dll+aa1fc|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5a194|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+590ad|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+59bfe|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+39927|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.
dll+39f7c|C:\\\\WINDOWS\\\\System32\\\\RPCRT4.dll+5426c\",\"GrantedAccess\":\"0x1410\",\"Name\":\"UtcTime,SourceProcessGUID,SourceProcessId,SourceThreadId,SourceImage,TargetProcessGUID,TargetProcessId,TargetImage,GrantedAccess,CallTrace\",\"SourceImage\":\"C:\\\\WINDOWS\\\\system32\\\\wbem\\\
\wmiprvse.exe\",\"SourceProcessGUID\":\"{AD35859D-6702-5A8D-0000-00103B690200}\",\"SourceProcessId\":\"2832\",\"SourceThreadId\":\"34840\",\"TargetImage\":\"C:\\\\WINDOWS\\\\system32\\\\lsass.exe\",\"TargetProcessGUID\":\"{AD35859D-66FC-5A8D-0000-0010F4A50000}\",\"TargetProcessId\":\"684\",\"
UtcTime\":\"2018-05-02 19:11:18.908\"}}\\x0A",
    "eventid": "10",
    "task": "10",
    "time": "1525288279"
  },
  "tags": [
    "osquery_windows"
  ]
}
2018-05-02T15:48:23.454-0400    INFO    beater/filebeat.go:323  Stopping filebeat
2018-05-02T15:48:23.454-0400    INFO    crawler/crawler.go:109  Stopping Crawler
2018-05-02T15:48:23.454-0400    INFO    crawler/crawler.go:119  Stopping 1 prospectors
2018-05-02T15:48:23.455-0400    INFO    prospector/prospector.go:121    Prospector ticker stopped
2018-05-02T15:48:23.455-0400    INFO    prospector/prospector.go:138    Stopping Prospector: 6301417932810513829
2018-05-02T15:48:23.455-0400    INFO    log/harvester.go:237    Reader was closed: C:\ProgramData\osquery\log\osqueryd.results.log. Closing.
2018-05-02T15:48:23.455-0400    INFO    crawler/crawler.go:135  Crawler stopped
2018-05-02T15:48:23.455-0400    INFO    registrar/registrar.go:239      Stopping Registrar
2018-05-02T15:48:23.456-0400    INFO    registrar/registrar.go:167      Ending Registrar
2018-05-02T15:48:23.480-0400    INFO    instance/beat.go:308    filebeat stopped.

Same result as above.


(ruflin) #5

I tried this locally and saw in the debug logs there is a decoding error. The reason is that at the end of the encoded json there is a \\x0A" which makes it invalid. Removing it makes it work as expected.

Note: There is also a typo in your processor name: decode_json_fields (missing e)


(system) #6

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