Filebeat Windows | Time sync

Elastic Stack Beats
1

Hi! While using Filebeat on Windows Server 2008 R2 I've encountered problem with keeping time in sync.
filebeat.yml:

filebeat.prospectors:
- type: log
  enabled: true
  paths:
    - E:\logs\log1\*.log
    - E:\logs\log2\*.log

filebeat.config.modules:
  path: ${path.config}/modules.d/*.yml
  reload.enabled: false

setup.template.settings:
  index.number_of_shards: 1

setup.kibana:

output.elasticsearch:
  hosts: ["10.10.10.10:9200"]
  pipeline: pipeone

Time checked using w32tm /stripchart /computer:local.time.server

timesync
timesync.png1898×362 25 KB

16:30:15 d:+00.0086430s o:+00.0419900s [ * ]
16:30:17 d:-00.0001663s o:-00.0703118s [ * ]
16:30:19 d:-00.0013052s o:-00.0521541s [ * ]
16:30:21 d:+00.0005373s o:-00.0363865s [ * ]
16:30:23 d:-00.0000926s o:-00.1217061s [ * ]
16:30:25 d:-00.0001562s o:-00.1161234s [ * ]
16:30:27 d:-00.0001356s o:-00.1730637s [ * ]
>>>>FILEBEAT STARTED<<<<
16:30:29 d:+00.0151207s o:-00.2354836s [ *| ]
16:30:31 d:-00.0005937s o:-00.2812407s [ *| ]
16:30:33 d:-00.0003368s o:-00.3129549s [ *| ]
16:30:35 d:-00.0001306s o:-00.3237276s [ *| ]
16:30:37 d:-00.0001889s o:-00.3423157s [ *| ]
16:30:39 d:-00.0009166s o:-00.3785393s [ *| ]
16:30:41 d:-00.0000977s o:-00.4444199s [ *| ]
16:30:43 d:-00.0002783s o:-00.5130465s [ *| ]
16:30:45 d:-00.0001818s o:-00.6004722s [ * | ]
16:30:47 d:-00.0001156s o:-00.6263772s [ * | ]
16:30:49 d:-00.0001021s o:-00.6975589s [ * | ]
16:30:51 d:-00.0002422s o:-00.7829291s [ * | ]
16:30:52 d:-00.0001615s o:-00.3098583s [ *| ]
16:30:54 d:+00.0151390s o:-00.2030070s [ *| ]
16:30:56 d:-00.0001489s o:-00.2381942s [ *| ]
16:30:58 d:-00.0000952s o:-00.3051694s [ *| ]
16:31:00 d:-00.0001233s o:-00.3934417s [ *| ]
16:31:02 d:-00.0001389s o:-00.4359527s [ *| ]
16:31:04 d:-00.0001413s o:-00.4796767s [ *| ]
16:31:06 d:-00.0000852s o:-00.5553451s [ * | ]
16:31:08 d:-00.0001489s o:-00.6395647s [ * | ]
16:31:10 d:-00.0001941s o:-00.7211694s [ * | ]
16:31:12 d:-00.0000883s o:-00.7702362s [ * | ]
16:31:14 d:-00.0002636s o:-00.8222141s [ * | ]
16:31:16 d:-00.0005851s o:-00.8561937s [ * | ]
16:31:18 d:-00.0001022s o:-00.8825711s [ * | ]
16:31:20 d:-00.0001282s o:-00.8880557s [ * | ]
16:31:22 d:-00.0001076s o:-00.9516177s [ * | ]
16:31:23 d:-00.0002801s o:-00.0821727s [ * ]
16:31:25 d:-00.0001054s o:-00.1352967s [ * ]
16:31:27 d:-00.0001246s o:-00.2611943s [ *| ]
16:31:29 d:-00.0001594s o:-00.3034458s [ *| ]
16:31:31 d:-00.0001097s o:-00.3153836s [ *| ]
16:31:33 d:-00.0001257s o:-00.3396538s [ *| ]
16:31:35 d:-00.0001404s o:-00.4100220s [ *| ]
16:31:37 d:-00.0001446s o:-00.5507578s [ * | ]
16:31:39 d:-00.0001197s o:-00.6320808s [ * | ]
16:31:41 d:-00.0001122s o:-00.6426351s [ * | ]
16:31:43 d:-00.0001213s o:-00.6344965s [ * | ]
16:31:45 d:-00.0001695s o:-00.6158208s [ * | ]
16:31:47 d:-00.0002422s o:-00.6236461s [ * | ]
16:31:49 d:-00.0001159s o:-00.6198303s [ * | ]
16:31:51 d:-00.0045402s o:-00.6132371s [ * | ]
16:31:53 d:-00.0003799s o:-00.6219039s [ * | ]
>>>>FILEBEAT STOPPED<<<<
16:31:55 d:-00.0001142s o:-00.3300722s [ *| ]
16:31:57 d:-00.0002606s o:-00.0341674s [ * ]
16:31:59 d:-00.0002198s o:-00.0050161s [ * ]
16:32:00 d:-00.0001393s o:+00.0069701s [ * ]
16:32:02 d:-00.0001213s o:+00.0114333s [ * ]
16:32:04 d:-00.0001206s o:+00.0188902s [ * ]
16:32:06 d:-00.0002180s o:+00.0242616s [ * ]

CPU\HDD\Memory graphs didn't show significant changes.
Is there a way, maybe some config settings to prevent filebeat affecting time on server this much?

2

I'm not sure yet how Filebeat could affect the system time. One potential way could be that Filebeat saturates the Network connection because of all the logs shipped.

How many log lines per second do you ship? Do you have any data on how saturated your network connection is?

3

13 files - ~22mb each, around 180k lines per file

net_in
net_in.png1898×362 33.4 KB

net_out
net_out.png1898×362 33.4 KB

alternatively I've tried using logstash - works fine without time issues.
also tried copying large files to saturate network - no issues either.

4

If you need any additional data I'll gladly provide it.
Currently using logstash as workaround.

ps. adding to prospector:

ignore_older: 1h
close_inactive: 5m
tail_files: true

did nothing to prevent time from desynchronizing,
currently filebeat only gets 2 files to tail

5

I honestly have a hard time to see how Filebeat could affect NTP as in the end it's just a binary that is execute as is Logstash or any other app.

Perhaps we can start from an other angle: What are the things on Windows that can have an affect on the NTP sync? Perhaps then I can think of ways how FB could affect these.

6

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.

7

@adachi This issue popped up today: https://github.com/elastic/beats/issues/7308 It reminded me a lot of your issue.