Dear Community,
I'm evaluating Winlogbeat-5.0.0 alpha 1 and noticed that all events shipped to elasticsearch were duplicated. This issue appears on all events shipped from my Windows servers.
I don't know if it bug of winlogbeat or elasticsearch, so please help me to find out the cause of the issue.
This is my winlogbeat.yml
winlogbeat:
registry_file: C:/ProgramData/winlogbeat/.winlogbeat.yml
event_logs:
- name: Security
ignore_older: 48h
event_id: 4720,1102,4625,4725,4740
output:
logstash:
hosts: ["xxxx.xxx:9998"]
tls:
certificate_authorities:
- "c://Program Files//ELK//logstash-forwarder.crt"
Winlogbeat and Filebeat have at-least-once delivery semantics. Delivery of duplicates to Logstash should only occur when there are connection problems to Logstash. For example, if the connection to Logstash is severed while sending a batch of events, the whole batch must be resent even though it is possible that part of the batch was delivered. If the Beat does not receive the acknowledgement from Logstash it must resend the whole batch. This enhancement request to add a UUID to events will help prevent duplicates in this scenario.
I recommend checking all of your logs for issues (WInlogbeat, Logstash, Elasticsearch).
Duplicates can also occur if you delete/modify the registry file used by Winlogbeat or run multiple instances on the same machine.
Could you attach (or post to pastebin) the output of the following query?
curl 'http://elasticsearch:9200/winlogbeat-*/_search?pretty' -d '
{
"size": 0,
"aggs": {
"hosts": {
"terms": {
"field": "beat.hostname",
"size": 10,
"order": {
"_count": "desc"
}
},
"aggs": {
"logs": {
"terms": {
"field": "log_name",
"size": 0,
"order": {
"_count": "desc"
}
},
"aggs": {
"duplicate_record_numbers": {
"terms": {
"field": "record_number",
"size": 0,
"min_doc_count": 2,
"order": {
"_count": "desc"
}
}
}
}
}
}
}
}
}'
Hi Andrew,
Thank you for your answer.
In my case Filebeat is working normal without duplicates. The issue is only with Winlogbeat. I don't have multiple instances of winlogbeat on my servers.
I've just checked logs of Elasticsearch and Logstash and have not found any errors.
Output of the query is here I couldn't upload to pastebin because it is too large.
As you can see, all events shipped from the servers using winglobeat are duplicated. I tried to delete indexes winlogbeat-* but it didn't help.
Please post the config file that you are using for Winlogbeat. Thanks
# cat /etc/logstash/conf.d/logstash-winlogbeat.conf
input {
beats {
port => 9998
ssl => true
ssl_certificate => "/etc/pki/tls/certs/logstash-forwarder.crt"
ssl_key => "/etc/pki/tls/private/logstash-forwarder.key"
}
}
filter{
if ([host] == "srv-fs-0") and ("ReadData" in [message] or "WriteAttributes" in [message] or ".tmp" in [message] or ":Zone.Identifier" in [message] or "Thumbs.db" in [message] or "~$" in [message] or ".partial" in [message] or "WRITE_DAC" in [message])
{
drop{}
}
}
output {
if [type] == "wineventlog"{
elasticsearch {
hosts => ["localhost:9200"]
index => "winlogbeat-%{+YYYY.MM.dd}"
}
}
}
That's a Logstash config... Post your winlogbeat.yml please.
I posted the winlogbeat.yml in my first message 
haha sorry, I guess I'm losing my mind.
I'm surprised that in the elasticsearch output that the log name is "security", but in your configuration it is "Security". I'm still not sure what's going on. Can you collect some debug logs from Winlogbeat? Let it run for a bit while it's producing duplicates then upload the logs, the config, and the registry file. And I'll take a look and see if there or any clues.
I think the interesting debug selectors (without producing too much data) would be "winlogbeat" , "eventlog", and "checkpoint". But if that doesn't produce any clues to the problem then we might need to try selectors: ["*"].
logging:
to_files: true
files:
path: C:/ProgramData/winlogbeat/Logs
level: debug
selectors: [winlogbeat, eventlog, checkpoint]
Done.
Please, find the winlogbeat.log here
The registry file contains this information:
update_time: 2016-05-06T13:29:19.2615248Z
event_logs:
- name: Security
record_number: 1700879517
timestamp: 2016-05-06T13:29:16.0739498Z
That output looks normal. I think we need selectors: ["*"].
And it would be useful to see which events are duplicated during the test period so either run the query below and adjust the time window, or delete the daily index before the test and run the query without the filter.
POST winlogbeat-2016.05.06/_search?pretty
{
"filter": {
"range": {
"timestamp": {
"gt": "now-10m"
}
}
},
"size": 0,
"aggs": {
"hosts": {
"terms": {
"field": "beat.hostname",
"size": 10,
"order": {
"_count": "desc"
}
},
"aggs": {
"logs": {
"terms": {
"field": "log_name",
"size": 0,
"order": {
"_count": "desc"
}
},
"aggs": {
"duplicate_record_numbers": {
"terms": {
"field": "record_number",
"size": 0,
"min_doc_count": 2,
"order": {
"_count": "desc"
}
}
}
}
}
}
}
}
}
Another test you could perform would be to use the file output in Winlogbeat and see if you get duplicates.
Andrew, it was a good idea to use the file output.
After the test I found duplicates in the file.
Please, find the response of POST query and part of the file output here
All of the events in the output file are unique based on their record_numbers.
$ jq . file-output.json | grep record_number | sort | wc -l
11
$ jq . file-output.json | grep record_number | sort | uniq | wc -l
11
Is there more to your Logstash config than you posted? Are there more files in /etc/logstash/conf.d/? Could there be something else in your Logstash configuration that is causing the event to be posted to Elasticsearch twice? Do you have any other output blocks that are possibly missing an if conditional?
How about outputting the data coming into Logstash to a file then checking it for duplicates.
output {
file {
path => "/path/to/output.json"
}
}
If we make the assumption that Winlogbeat is not sending duplicates, then by adding a unique document ID in Logstash it should stop the duplicate events from appearing in Elasticsearch. If this stops the problem then it points to a problem in the Logstash config.
For example:
filter {
uuid {
target => "[@metadata][document_id]"
}
}
output {
elasticsearch {
hosts => "localhost:9200"
manage_template => false
index => "%{[@metadata][beat]}-%{+YYYY.MM.dd}"
document_type => "%{[@metadata][type]}"
document_id => "%{[@metadata][document_id]}"
}
}
Hi Andrew,
Sorry for the late answer - I had a vacation.
I've changed my config as you suggested. It did not help.
After that I've tried to start logstash using the only winlogbeat config:
logstash -f /etc/logstash/conf.d/logstash-winlogbeat.conf
In that case all worked fine. There was not duplicated events.
You were right about over config files in /etc/logstash/conf.d/. I also have the filebeat.conf that contains this lines:
output {
elasticsearch {
hosts => ["localhost:9200"]
sniffing => true
manage_template => false
index => "%{[@metadata][beat]}-%{+YYYY.MM.dd}"
document_type => "%{[@metadata][type]}"
}
}
And like as you suggested, the events were posted to logstash twice. I've just commented output section in the winlogbeat.conf and now all work perfectly!
Thank you very much for your help!