last few seconds' Zeek logs prior to log rotation may be lost

[mmguero]

(Reported to us by a partner organization:)

When using Malcolm with several Hedgehogs, we encountered the following issue:

Some Zeek logs under /home/sensor/bro_logs/logs/ cannot be found in the OpenSearch database.

We noticed the following pattern: The “last” entries of a Zeek log (e.g ntp.00:00:00-01:00:00.log.gz) are often missing in OpenSearch. These are always log entries that were added shortly before Zeek's log rotation. Usually, within the last seconds of each hour.

Is it possible that individual entries are lost due to Zeek's log rotation [1], as Filebeat only checks these files every 10s [2]?

[1] https://github.com/cisagov/Malcolm/blob/main/shared/bin/zeekdeploy.sh#L100
[2]https://github.com/cisagov/Malcolm/blob/main/sensor-iso/interface/sensor_ctl/filebeat/filebeat.yml#L15

[mmguero]

Looking closer at the configuration, I don't think it has to do with the scan frequency. As the documentation for filebeat states, that 10s value is "How often Filebeat checks for new files in the paths that are specified for harvesting". The files are left open, and are continually monitored, only being closed once the close inactive setting is hit, which is 90 minutes. So the only way it should be losing events is if the file has been inactive for 90 minutes, then all of a sudden within the last 10 seconds before rotation got some data before it was rechecked.

I think the more likely scenario is how I'm handling the renamed files in logstash on the Malcolm side, which is basically "not handling it." Rather than doing what I'm doing, I should check and adjust for the temporarily-renamed files and log those events like normal.

[mmguero]

I think my commit (mmguero-dev/Malcolm@43e63a4) addresses this issue, at least as far as I've been able to come up with something to test it.

What I did to test this solution was to set up Hedgehog and increase the Zeek rollover from 1 hour (3600 seconds) to 1 minute (60 seconds) to try to exacerbate the issue even more. I let this run for about 30 minutes so that it would rollover (rename then zip) about 30 times, resulting in just under 10,000 conn.log entries. After that I shut the sensor down, found and unzip all of the conn.log files that had been archived, and saved all of the zeek UID values out of them. I then went over to the Malcolm that had been receiving the events and did an individual document lookup for each of the UID values to make sure none had been lost. All were accounted for.

I'm going to mark this as closed, but if this is encountered by our partner organization again or anyone, please feel free to reopen.