Hi all,
I have had filebeat 2.3 running successfully for several months on several Ubuntu 16.04 servers. The other week I installed logrotate and configured cron to run it every hour.
After logrotate was installed filebeat stopped processing new events between 20.00 and 24.00 UTC. Every day.. At 00.00 it starts processing new events again. This happens also if I disable the cron job that runs logrotate. If the log file is rotated sometime between 20 and 24, filebeat recognises that, sends the first event, and then refuses to send any more events.
Enabling debug logs shows that filebeat gets EOF when reading the log file from the saved offset. Restarts of filebeat doesn't help. If I manually set the the offset in the registry file to the next byte, filebeat reads an event, and then stops reading again.
This happens also with latest filebeat 5.x.
I have verified that filebeat use the correct inode.
Using lsof doesn't show anything unexpected.
Filebeat conf:
filebeat:
prospectors:
-
paths:
- "/var/log/disco/*/*.log"
document_type: beats
input_type: log
fields_under_root: true
scan_frequency: 2s
multiline:
pattern: ^xyz
negate: true
match: after
output:
logstash:
hosts: ["10.0.3.55:5044", ]
loadbalance: true
logging:
level: info
to_files: true
to_syslog: false
files:
path: /var/log/filebeat
name: mybeat.log
keepfiles: 7
Log example:
2017-03-07T19:59:34Z INFO Events sent: 393
2017-03-07T19:59:34Z INFO Registry file updated. 1 states written.
2017-03-07T19:59:42Z INFO Events sent: 446
2017-03-07T19:59:42Z INFO Registry file updated. 1 states written.
2017-03-07T19:59:47Z INFO Events sent: 368
2017-03-07T19:59:47Z INFO Registry file updated. 1 states written.
2017-03-07T19:59:55Z INFO Events sent: 650
2017-03-07T19:59:55Z INFO Registry file updated. 1 states written.
2017-03-07T20:00:03Z INFO Events sent: 471
2017-03-07T20:00:03Z INFO Registry file updated. 1 states written.
2017-03-07T20:00:09Z INFO Events sent: 12
2017-03-07T20:00:09Z INFO Registry file updated. 1 states written.
And then complete silence. Until 00.00 when it starts again.
Some debug logs:
2017-03-07T20:38:06Z DBG Start next scan
2017-03-07T20:38:06Z DBG scan path /var/log/disco/*/*.log
2017-03-07T20:38:06Z DBG Check file for harvesting: /var/log/disco/haproxy/haproxy.log
2017-03-07T20:38:06Z DBG Same file as before found. Fetch the state.
2017-03-07T20:38:06Z DBG Update existing file for harvesting: /var/log/disco/haproxy/haproxy.log
2017-03-07T20:38:06Z DBG Not harvesting, file didn't change: /var/log/disco/haproxy/haproxy.log
2017-03-07T20:38:07Z DBG Flushing spooler because of timeout. Events flushed: 0
2017-03-07T20:38:07Z DBG End of file reached: /var/log/disco/haproxy/haproxy.log; Backoff now.
2017-03-07T20:38:08Z DBG End of file reached: /var/log/disco/haproxy/haproxy.log; Backoff now.
2017-03-07T20:38:08Z DBG Start next scan
2017-03-07T20:38:08Z DBG scan path /var/log/disco/*/*.log
2017-03-07T20:38:08Z DBG Check file for harvesting: /var/log/disco/haproxy/haproxy.log
2017-03-07T20:38:08Z DBG Same file as before found. Fetch the state.
2017-03-07T20:38:08Z DBG Update existing file for harvesting: /var/log/disco/haproxy/haproxy.log
2017-03-07T20:38:08Z DBG Not harvesting, file didn't change: /var/log/disco/haproxy/haproxy.log
2017-03-07T20:38:09Z DBG End of file reached: /var/log/disco/haproxy/haproxy.log; Backoff now.
2017-03-07T20:38:10Z DBG End of file reached: /var/log/disco/haproxy/haproxy.log; Backoff now.
Any ideas?
BR / Jonas
