My "need to restart filebeat for it to send logs" problem

Elastic Stack Beats
1

Hello,

I'm sorry because this have been brought up before, but none of the solutions seemed to apply to my case so I'm opening this topic.

So basically, what happens is that filebeat sends logs after starting, but then won't send new lines.
Environment is windows server 2012.

Here's both of my yml's : (have already tried with only one to see if that was the problem and it wasn't)
(I removed all the comments)
First one :
filebeat:

  prospectors:
    
    -
      paths:
        - C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log

      encoding: utf-8

      input_type: log

      include_lines: ['^[0-9]{2}\/[0-9]{2}\/[0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2}[ ]+Statistiques']

      multiline:
        pattern: '^[0-9]{2}\/[0-9]{2}\/[0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2} (Commande de sauvegarde de la machine virtuelle terminée)|(Nombre total|Le nombre total|Dur.e de transfert|D.bit de transfert|Taux de compression|Rapport de r.duction|Temps de traitement).+'
        negate: false
        match: after
  
  registry_file: "C:/ProgramData/filebeat/registry"

  config_dir: C:\Program Files\Filebeat\Beats

output:
  logstash:
    hosts: ["10.2.2.21:5047","10.2.2.22:5047","10.2.2.23:5047"]
    loadbalance: true

shipper:
  name: tsm

logging:
  files:
    rotateeverybytes: 10485760

Second one :

filebeat:
  
  prospectors:
    
    -

      paths:
        - C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
      encoding: utf-8

      input_type: log

      include_lines: ['^[0-9]{2}\/[0-9]{2}\/[0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2}[ ]+Machine virtuelle [^ ]+.+ sauvegard.e', '^[0-9]{2}\/[0-9]{2}\/[0-9]{4} [0-9]{2}:[0-9]{2}:[0-9]{2}[ ]+Machine virtuelle [^ ]+$']

  registry_file: "C:/ProgramData/filebeat/registry"

  config_dir: C:\Program Files\Filebeat\Beats

output:

  logstash:
    
    hosts: ["10.2.2.21:5047","10.2.2.22:5047","10.2.2.23:5047"]

    loadbalance: true

shipper:

  name: tsm

logging:

  files:

    rotateeverybytes: 10485760

As I said, the shipping works totally fine, the multiline and include_lines work exactly how I want it to. The problem is that I need to restart filebeat every morning for it to see the new lines and ship them.
I thought that maybe the useless logging block was causing the problem, but I have done the same for other systems and the problem never appeared there.

Thanks!

Edit : the version is 1.3

2

Can you share the log output from your filebeat instance?

3

Well, I will do so tomorrow since the logging wasn't enabled.
I just enabled it with debug as the level. Will post some logs later.
Thanks.

4

Here are the logs at the time where the new lines started to appear :

Start next scan
2016-10-25T00:00:09+04:00 DBG  scan path C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Start next scan
2016-10-25T00:00:09+04:00 DBG  scan path C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Check file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Check file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Same file as before found. Fetch the state.
2016-10-25T00:00:09+04:00 DBG  Update existing file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Same file as before found. Fetch the state.
2016-10-25T00:00:09+04:00 DBG  Update existing file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Not harvesting, file didn't change: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Not harvesting, file didn't change: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:09+04:00 DBG  Flushing spooler because of timeout. Events flushed: 0
2016-10-25T00:00:14+04:00 DBG  Flushing spooler because of timeout. Events flushed: 0
2016-10-25T00:00:19+04:00 DBG  Start next scan
2016-10-25T00:00:19+04:00 DBG  Start next scan
2016-10-25T00:00:19+04:00 DBG  scan path C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  scan path C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  Check file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  Check file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  Same file as before found. Fetch the state.
2016-10-25T00:00:19+04:00 DBG  Update existing file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  Same file as before found. Fetch the state.
2016-10-25T00:00:19+04:00 DBG  Update existing file for harvesting: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  Not harvesting, file didn't change: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:19+04:00 DBG  Not harvesting, file didn't change: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
2016-10-25T00:00:22+04:00 DBG  Flushing spooler because of timeout. Events flushed: 0
2016-10-25T00:00:27+04:00 DBG  Flushing spooler because of timeout. Events flushed: 0
2016-10-25T00:00:29+04:00 DBG  Start next scan

Etc.

It will just repeat the same block (and already was before the lines were appearing by the way). So it seems that filebeat isn't seeing that new lines are being added unless it is restarted.

5

Here are all the INFO lines too (since the restart I did yesterday with the logging enabled), just in case :

Line 3: 2016-10-24T12:36:50+04:00 INFO GeoIP disabled: No paths were set under output.geoip.paths
	Line 4: 2016-10-24T12:36:50+04:00 INFO Max Retries set to: 3
	Line 8: 2016-10-24T12:36:50+04:00 INFO Activated logstash as output plugin.
	Line 11: 2016-10-24T12:36:50+04:00 INFO Publisher name: tsm
	Line 12: 2016-10-24T12:36:50+04:00 INFO Flush Interval set to: 1s
	Line 13: 2016-10-24T12:36:50+04:00 INFO Max Bulk Size set to: 2048
	Line 15: 2016-10-24T12:36:50+04:00 INFO Init Beat: filebeat; Version: 1.3.0
	Line 16: 2016-10-24T12:36:50+04:00 INFO Additional config files are fetched from: C:\Program Files\Filebeat\Beats
	Line 17: 2016-10-24T12:36:50+04:00 INFO Additional configs loaded from: C:\Program Files\Filebeat\Beats\brighton dsmsched.yml
	Line 18: 2016-10-24T12:36:50+04:00 INFO filebeat sucessfully setup. Start running.
	Line 20: 2016-10-24T12:36:50+04:00 INFO Registry file set to: C:\ProgramData\filebeat\registry
	Line 21: 2016-10-24T12:36:50+04:00 INFO Loading registrar data from C:\ProgramData\filebeat\registry
	Line 24: 2016-10-24T12:36:50+04:00 INFO Set ignore_older duration to 0s
	Line 25: 2016-10-24T12:36:50+04:00 INFO Set close_older duration to 1h0m0s
	Line 26: 2016-10-24T12:36:50+04:00 INFO Set scan_frequency duration to 10s
	Line 27: 2016-10-24T12:36:50+04:00 INFO Input type set to: log
	Line 28: 2016-10-24T12:36:50+04:00 INFO Set backoff duration to 1s
	Line 29: 2016-10-24T12:36:50+04:00 INFO Set max_backoff duration to 10s
	Line 30: 2016-10-24T12:36:50+04:00 INFO force_close_file is disabled
	Line 32: 2016-10-24T12:36:50+04:00 INFO Set ignore_older duration to 0s
	Line 33: 2016-10-24T12:36:50+04:00 INFO Set close_older duration to 1h0m0s
	Line 34: 2016-10-24T12:36:50+04:00 INFO Set scan_frequency duration to 10s
	Line 35: 2016-10-24T12:36:50+04:00 INFO Input type set to: log
	Line 36: 2016-10-24T12:36:50+04:00 INFO Starting prospector of type: log
	Line 37: 2016-10-24T12:36:50+04:00 INFO Starting spooler: spool_size: 2048; idle_timeout: 5s
	Line 38: 2016-10-24T12:36:50+04:00 INFO Set backoff duration to 1s
	Line 39: 2016-10-24T12:36:50+04:00 INFO Set max_backoff duration to 10s
	Line 40: 2016-10-24T12:36:50+04:00 INFO force_close_file is disabled
	Line 43: 2016-10-24T12:36:50+04:00 INFO Starting prospector of type: log
	Line 60: 2016-10-24T12:36:50+04:00 INFO All prospectors initialised with 1 states to persist
	Line 61: 2016-10-24T12:36:50+04:00 INFO Starting Registrar
	Line 62: 2016-10-24T12:36:50+04:00 INFO Start sending events to output
	Line 65: 2016-10-24T12:36:50+04:00 INFO Harvester started for file: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
	Line 67: 2016-10-24T12:36:50+04:00 INFO Harvester started for file: C:\Program Files\Tivoli\TSM\baclient\dsmsched.VMWARE_DCPRODUCTION_DM.log
	Line 5807: 2016-10-24T13:36:55+04:00 INFO Read line error: file inactive
	Line 5809: 2016-10-24T13:36:55+04:00 INFO Read line error: file inactive

Thanksf or the help.

Edit : I should mention that the file we are fetching is adding new lines only between 0:00 to 3:30 am (GMT +4)

6

This issue looks line this one : https://github.com/elastic/beats/issues/1974

I will try with filebeat 5.0 to see if it fixes this isssue and will update.

Thanks.

7

@Houss Great. Let me know if 5.0 will fix the issue. In 5.0 we compare size of the file instead of modtime (which can be old on Windows), so I hope this helps.

8

Hello,

Filebeat 5.0 solved the issue.

Cheers.

9

This topic was automatically closed after 21 days. New replies are no longer allowed.