Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[filebeat iptables] Ubiquiti Firewall field [raw_date] not present as part of path [iptables.raw_date] #24878

Closed
PrplHaz4 opened this issue Mar 31, 2021 · 12 comments · Fixed by #24928

Comments

@PrplHaz4
Copy link

This error received when processing events from an Ubiquiti Firewall Log. I'm pretty sure this problem was not present in 7.10.1, but have not been able to trace it back to where it started.

This causes data to be missing from the Kibana Ubiquiti Firewall Overview ECS dashboard.

  • Version: 7.12.0
  • Operating System: Docker

Steps to Reproduce:

  1. Configure iptables input
  2. Point Firewall syslog at filebeat input
  3. See error: field [raw_date] not present as part of path [iptables.raw_date]

Configuration

- module: iptables
  log:
    enabled: true
    var.syslog_host: "0.0.0.0"
    var.syslog_port: "6514"

Event

{
  "_index": "filebeat-7.12.0-2021.03.24-000001",
  "_type": "_doc",
  "_id": "VXbMiHgBQf4FhkA2s-IK",
  "_version": 1,
  "_score": null,
  "fields": {
    "rule.id": [
      "2000"
    ],
    "event.category": [
      "network"
    ],
    "iptables.id": [
      0
    ],
    "host.hostname": [
      "net-rt-usg"
    ],
    "iptables.input_device": [
      "eth0"
    ],
    "suricata.eve.src_port": [
      443
    ],
    "traefik.access.geoip.location": [
      {
        "coordinates": [
          30.5233,
          50.45
        ],
        "type": "Point"
      }
    ],
    "iptables.tos": [
      8
    ],
    "destination.mac": [
      "74:8a:20:42:d2:d4"
    ],
    "service.type": [
      "iptables"
    ],
    "hostname": [
      "net-rt-usg"
    ],
    "iptables.precedence_bits": [
      32
    ],
    "iptables.ubiquiti.rule_number": [
      "2000"
    ],
    "iptables.length": [
      60
    ],
    "source.ip": [
      "37.19.198.61"
    ],
    "agent.name": [
      "srv-filebeat"
    ],
    "network.community_id": [
      "1:0V4q42mcC43EU24xc89rPXriMxY="
    ],
    "host.name": [
      "net-rt-usg"
    ],
    "event.kind": [
      "event"
    ],
    "log.original": [
      "[WAN_IN-2000-D]IN=eth0 OUT=eth1 MAC=74:8a:20:42:d2:d4:3e:41:04:04:a4:f4:08:00 SRC=37.19.198.61 DST=192.168.1.115 LEN=60 TOS=0x08 PREC=0x20 TTL=54 ID=0 DF PROTO=TCP SPT=443 DPT=37097 WINDOW=65160 RES=0x00 ACK SYN URGP=0 "
    ],
    "event.severity": [
      4
    ],
    "suricata.eve.proto": [
      "tcp"
    ],
    "rule.name": [
      "WAN_IN"
    ],
    "traefik.access.geoip.country_iso_code": [
      "UA"
    ],
    "fileset.name": [
      "log"
    ],
    "iptables.ubiquiti.rule_set": [
      "WAN_IN"
    ],
    "input.type": [
      "syslog"
    ],
    "iptables.tcp.flags": [
      "ACK",
      "SYN"
    ],
    "agent.hostname": [
      "srv-filebeat"
    ],
    "tags": [
      "iptables"
    ],
    "iptables.fragment_flags": [
      "DF"
    ],
    "agent.id": [
      "dd4a0411-0ba3-42d8-9b7d-0261b2c6244f"
    ],
    "source.port": [
      443
    ],
    "ecs.version": [
      "1.8.0"
    ],
    "log.source.address": [
      "192.168.1.1:44303"
    ],
    "agent.version": [
      "7.12.0"
    ],
    "iptables.tcp.window": [
      65160
    ],
    "iptables.output_device": [
      "eth1"
    ],
    "source.as.number": [
      31343
    ],
    "suricata.eve.src_ip": [
      "37.19.198.61"
    ],
    "destination.port": [
      37097
    ],
    "process.program": [
      "kernel"
    ],
    "syslog.facility": [
      0
    ],
    "source.geo.location": [
      {
        "coordinates": [
          40.5233,
          60.45
        ],
        "type": "Point"
      }
    ],
    "suricata.eve.alert.severity": [
      4
    ],
    "agent.type": [
      "filebeat"
    ],
    "source.mac": [
      "3e:41:04:04:a4:f4"
    ],
    "iptables.tcp.reserved_bits": [
      0
    ],
    "event.module": [
      "iptables"
    ],
    "related.ip": [
      "37.19.198.61",
      "192.168.1.115"
    ],
    "source.geo.country_iso_code": [
      "UA"
    ],
    "network.type": [
      "ipv4"
    ],
    "event.timezone": [
      "-04:00"
    ],
    "source.as.organization.name.text": [
      "Intertelecom Ltd"
    ],
    "syslog.priority": [
      4
    ],
    "source.geo.continent_name": [
      "Europe"
    ],
    "source.as.organization.name": [
      "Intertelecom Ltd"
    ],
    "iptables.ether_type": [
      2048
    ],
    "traefik.access.geoip.continent_name": [
      "Europe"
    ],
    "destination.ip": [
      "192.168.1.115"
    ],
    "network.transport": [
      "tcp"
    ],
    "suricata.eve.dest_ip": [
      "192.168.1.115"
    ],
    "event.ingested": [
      "2021-03-31T15:00:19.848Z"
    ],
    "event.action": [
      "drop"
    ],
    "iptables.ttl": [
      54
    ],
    "@timestamp": [
      "2021-03-31T15:00:19.000Z"
    ],
    "syslog.severity_label": [
      "Warning"
    ],
    "suricata.eve.dest_port": [
      37097
    ],
    "error.message": [
      "field [raw_date] not present as part of path [iptables.raw_date]"
    ],
    "event.type": [
      "denied",
      "connection"
    ],
    "agent.ephemeral_id": [
      "f4936f35-3ad9-4606-ab6e-edc02ebd9657"
    ],
    "syslog.facility_label": [
      "kernel"
    ],
    "source.geo.country_name": [
      "Ukraine"
    ],
    "event.dataset": [
      "iptables.log"
    ]
  },
  "sort": [
    1617202819000
  ]
}
@botelastic botelastic bot added the needs_team Indicates that the issue/PR needs a Team:* label label Mar 31, 2021
@elasticmachine
Copy link
Collaborator

Pinging @elastic/security-external-integrations (Team:Security-External Integrations)

@botelastic botelastic bot removed the needs_team Indicates that the issue/PR needs a Team:* label label Apr 1, 2021
@legoguy1000
Copy link
Contributor

legoguy1000 commented Apr 2, 2021

It appears your original log message doesn't contain a timestamp [WAN_IN-2000-D]IN=eth0 OUT=eth1... so there is nothing for the date processor to parse and such produces that message as coded,

What exactly is missing in the dashboard as it appears the document finished ingest and was indexed? Are you just saying that the error message is bad?

@PrplHaz4
Copy link
Author

PrplHaz4 commented Apr 3, 2021

It appears your original log message doesn't contain a timestamp [WAN_IN-2000-D]IN=eth0 OUT=eth1... so there is nothing for the date processor to parse and such produces that message as coded,


What exactly is missing in the dashboard as it appears the document finished ingest and was indexed? Are you just saying that the error message is bad?

Thanks for the response. It appears I'm seeing two different issues:

  1. Pulling the log from the router, it does start with a timestamp, and looks identical to an existing test case:
Mar 31 15:01:03 net-rt-usg kernel: [WAN_IN-2000-D]IN=eth0 OUT=eth1 MAC=74:8a:20:42:d2:d4:3e:61:04:06:a4:f4:08:00 SRC=37.19.198.61 DST=192.168.1.115 LEN=60 TOS=0x08 PREC=0x20 TTL=54 ID=0 DF PROTO=TCP SPT=443 DPT=37566 WINDOW=65160 RES=0x00 ACK SYN URGP=0
  1. event.outcome is empty (previously, I believe this was event.action), so the Event Timeline has everything show as "Missing", and it appears all the other graphs on the dashboard are impacted too.

image

@legoguy1000
Copy link
Contributor

Ok, so looking at the pipeline. It sets the event.action field to drop or accept but doesn't set the event.outcome. Originally the the pipeline was setting event.outcome but it was changed to event.action March 2020 and the visualizations weren't updated. I can get a PR in pronto for that.

@PrplHaz4
Copy link
Author

PrplHaz4 commented Apr 5, 2021

Thanks a ton for this!

@legoguy1000
Copy link
Contributor

PR is updated, should be good to go

@PrplHaz4
Copy link
Author

PrplHaz4 commented Apr 6, 2021

After manually applying the changes as of f7073f3, the dashboard appears to be fixed, but the raw_date issue is still showing. I'm not sure what (if any) the effect of this is yet, and it may have been fixed somewhere after the 7.12.0 release (it seems some hostname handling differs btw that and master).

Oddly, for single-digit dates, it looks like there are 2 spaces btw the month and day (!?) in the Ubiquiti syslog - that might be an issue with the new grok pattern? (see log msg below)

Thanks for fixing the dashboard!

Here's the data for the raw_date issue...

Apr  5 22:25:07 net-rt-usg kernel: [WAN_OUT-4000-D]IN=eth1 OUT=eth0 MAC=78:8a:20:42:d2:da:4c:4e:cd:20:31:0d:04:00 SRC=192.168.1.33 DST=54.84.228.44 LEN=60 TOS=0x00 PREC=0x00 TTL=63 ID=50931 DF PROTO=TCP SPT=45471 DPT=80 WINDOW=14600 RES=0x00 SYN URGP=0
{
  "_index": "filebeat-7.12.0-2021.03.24-000001",
  "_type": "_doc",
  "_id": "-Uf_pHgBfuDoCTrwdmvp",
  "_version": 1,
  "_score": null,
  "fields": {
    "rule.id": [
      "4000"
    ],
    "event.category": [
      "network"
    ],
    "iptables.id": [
      50931
    ],
    "host.hostname": [
      "net-rt-usg"
    ],
    "iptables.input_device": [
      "eth1"
    ],
    "suricata.eve.src_port": [
      45471
    ],
    "iptables.tos": [
      0
    ],
    "destination.mac": [
      "78:8a:20:42:d2:da"
    ],
    "service.type": [
      "iptables"
    ],
    "hostname": [
      "net-rt-usg"
    ],
    "iptables.precedence_bits": [
      0
    ],
    "iptables.ubiquiti.rule_number": [
      "4000"
    ],
    "destination.geo.region_name": [
      "Virginia"
    ],
    "iptables.length": [
      60
    ],
    "source.ip": [
      "192.168.1.33"
    ],
    "agent.name": [
      "srv-filebeat"
    ],
    "network.community_id": [
      "1:e/XuZhmcS7GbkDqM2S3x4Lze/4o="
    ],
    "host.name": [
      "net-rt-usg"
    ],
    "event.kind": [
      "event"
    ],
    "log.original": [
      "[WAN_OUT-4000-D]IN=eth1 OUT=eth0 MAC=78:8a:20:42:d2:da:4c:4e:cd:20:31:0d:04:00 SRC=192.168.1.33 DST=54.84.228.44 LEN=60 TOS=0x00 PREC=0x00 TTL=63 ID=50931 DF PROTO=TCP SPT=45471 DPT=80 WINDOW=14600 RES=0x00 SYN URGP=0 "
    ],
    "event.outcome": [
      "failure"
    ],
    "event.severity": [
      4
    ],
    "suricata.eve.proto": [
      "tcp"
    ],
    "rule.name": [
      "WAN_OUT"
    ],
    "destination.geo.continent_name": [
      "North America"
    ],
    "fileset.name": [
      "log"
    ],
    "iptables.ubiquiti.rule_set": [
      "WAN_OUT"
    ],
    "input.type": [
      "syslog"
    ],
    "iptables.tcp.flags": [
      "SYN"
    ],
    "agent.hostname": [
      "srv-filebeat"
    ],
    "tags": [
      "iptables"
    ],
    "destination.geo.city_name": [
      "Ashburn"
    ],
    "iptables.fragment_flags": [
      "DF"
    ],
    "agent.id": [
      "74022d74-b4c2-4ec7-b749-12b85b2cd40d"
    ],
    "source.port": [
      45471
    ],
    "ecs.version": [
      "1.8.0"
    ],
    "log.source.address": [
      "172.44.0.1:43733"
    ],
    "agent.version": [
      "7.12.0"
    ],
    "iptables.tcp.window": [
      14600
    ],
    "destination.geo.region_iso_code": [
      "US-VA"
    ],
    "destination.geo.country_name": [
      "United States"
    ],
    "iptables.output_device": [
      "eth0"
    ],
    "suricata.eve.src_ip": [
      "192.168.1.33"
    ],
    "destination.port": [
      80
    ],
    "process.program": [
      "kernel"
    ],
    "syslog.facility": [
      0
    ],
    "suricata.eve.alert.severity": [
      4
    ],
    "destination.geo.location": [
      {
        "coordinates": [
          -77.4728,
          39.0481
        ],
        "type": "Point"
      }
    ],
    "suricata.eve.alert.action": [
      "failure"
    ],
    "agent.type": [
      "filebeat"
    ],
    "source.mac": [
      "9c:8e:cd:20:31:0d"
    ],
    "iptables.tcp.reserved_bits": [
      0
    ],
    "event.module": [
      "iptables"
    ],
    "related.ip": [
      "192.168.1.33",
      "54.84.228.44"
    ],
    "network.type": [
      "ipv4"
    ],
    "event.timezone": [
      "-04:00"
    ],
    "syslog.priority": [
      4
    ],
    "destination.as.number": [
      14618
    ],
    "iptables.ether_type": [
      2048
    ],
    "destination.as.organization.name.text": [
      "Amazon.com, Inc."
    ],
    "destination.ip": [
      "54.84.228.44"
    ],
    "network.transport": [
      "tcp"
    ],
    "suricata.eve.dest_ip": [
      "54.84.228.44"
    ],
    "event.ingested": [
      "2021-04-06T02:25:08.840Z"
    ],
    "event.action": [
      "drop"
    ],
    "iptables.ttl": [
      63
    ],
    "@timestamp": [
      "2021-04-06T02:25:07.000Z"
    ],
    "syslog.severity_label": [
      "Warning"
    ],
    "destination.geo.country_iso_code": [
      "US"
    ],
    "suricata.eve.dest_port": [
      80
    ],
    "error.message": [
      "field [raw_date] not present as part of path [iptables.raw_date]"
    ],
    "event.type": [
      "denied",
      "connection"
    ],
    "agent.ephemeral_id": [
      "e437f6c6-aff9-43b0-b5ec-802756b2f5a7"
    ],
    "syslog.facility_label": [
      "kernel"
    ],
    "event.dataset": [
      "iptables.log"
    ],
    "destination.as.organization.name": [
      "Amazon.com, Inc."
    ]
  },
  "sort": [
    1617675907000
  ]
}

@legoguy1000
Copy link
Contributor

So the timestamp accounts for the extra space so that should be fine. What I don't understand is why the log.orignal doesn't have the timestamp. I'v only been looking at master so idk if something is different in 7.12 but according to blame, it hasn't been touched in a year.

@legoguy1000
Copy link
Contributor

Also even though it gives an error, it appears to have parsed and set the date to @timestamp just fine

@legoguy1000
Copy link
Contributor

legoguy1000 commented Apr 6, 2021

I think I know. You're getting the raw log from the file but ur receiving the log via syslog. The syslog message doesn't have the extra stuff in front because its part of the syslog header. The text in the log file adds it. So that's why it's matching the 3rd grok pattern with no raw date. I just need to add a conditional to check for the field.

@legoguy1000
Copy link
Contributor

legoguy1000 commented Apr 6, 2021

@PrplHaz4 Try it now.
The syslog input sets a few fields like the hostname and the syslog.* fields and the @timestamp field. So i added an if condition to the date processors and to set the observer.name to the hostname field value get the name of the system sending the syslog.

@PrplHaz4
Copy link
Author

PrplHaz4 commented Apr 6, 2021

@PrplHaz4 Try it now.
The syslog input sets a few fields like the hostname and the syslog.* fields and the @timestamp field. So i added an if condition to the date processors and to set the observer.name to the hostname field value get the name of the system sending the syslog.

No longer seeing that error, and everything looks ok to me @ dda2b8a

Nice work - thanks!

legoguy1000 added a commit to legoguy1000/beats that referenced this issue Apr 12, 2021
leehinman pushed a commit that referenced this issue Apr 12, 2021
* #24878: Fix IPtables pipeline
  - fix dashboards
  - populate additional event.actions
  - move community_id processor to ingest node
  - set observer.name
mergify bot pushed a commit that referenced this issue Apr 12, 2021
* #24878: Fix IPtables pipeline
  - fix dashboards
  - populate additional event.actions
  - move community_id processor to ingest node
  - set observer.name

(cherry picked from commit ddcf8f1)
leehinman pushed a commit that referenced this issue Apr 13, 2021
* #24878: Fix IPtables pipeline
  - fix dashboards
  - populate additional event.actions
  - move community_id processor to ingest node
  - set observer.name

(cherry picked from commit ddcf8f1)

Co-authored-by: Alex Resnick <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants