After filebeat upgrades & preserving registry it sending duplicate events

I am having a trouble with duplicate events in elasticsearch after updating it to 7.17.3 from 5.6.5. In case of Linux its working as expected but in windows its sending duplicate events. Below are my configurations:

========filebeat.yml========>

filebeat.inputs:
- type: filestream

filebeat.config.inputs:
  path: C:/opt/filebeat-7.17.3-windows-x86_64/conf.d

# ------------------------------ Logstash Output -------------------------------
output.logstash:
  # The Logstash hosts
  hosts: ["do-test:12203"]

# ================================== Logging ===================================

# Sets log level. The default log level is info.
logging:
  level: debug
  to_files: true
  files:
    rotateeverybytes: 10485760
    keepfiles: 7

========Extra Configuration============>

- paths:
    - D:\wsod\Logs\iis\*\*
    exclude_files:
    - HTTPERR
    exclude_lines:
    - "^#"
    - "\\/monitor\\/wsod.asp - \\d+ [\\d\\.]+ - 200"
    ignore_older: 25h
    fields:
      type: iis
      environment: development
      datacenter: ptc1
    tags:
    - iis
    - webdev
    fields_under_root: true

In Linux, Registry is working as expected but in case of windows its sending duplicate events not sure what configuration am doing wrong. Please help me out.

@steffens

Can anyone please help me out??

Hi @krish0608

It is not clear what your problem is you have not provide enough information.

That was a very long time between upgrades 7.17.3 from 5.6.5. so it is hard to know what the issues is.

How many duplicate events... just some or every event?

Are you receiving duplicate events ongoing?

or just when you start it the first time after the upgrade?

Is there any errors in the filebeat logs?

Are the permission correct on the filebeat data directory?

Hi @stephenb

Thanks for your revert. Please find the answers to your questions below:-

  1. How many duplicate events:- its sending current date log file again.
  2. Are you receiving duplicate events ongoing?- The process i followed was i checked no of Logs count in Kibana before upgrade and after upgrade it resend current date events from Logfile. And yes it the first time after the upgrade.
  3. Yes Permission were correct.

Just FYI, We are facing challenges in case of windows, for Linux its working fine. Also regestry preservation is working as expected in both case i have checked offset value after upgrade it was present in new registry file.

Please find the attached filebeat Logs:-

2022-09-13T08:34:15.357-0400	INFO	instance/beat.go:685	Home path: [c:\program files\filebeat] Config path: [c:\program files\filebeat] Data path: [c:\program files\filebeat\data] Logs path: [D:\wsod\logs\filebeat] Hostfs Path: [/]
2022-09-13T08:34:15.365-0400	INFO	instance/beat.go:693	Beat ID: 2906c257-019f-4da2-b6a7-450ff28165fc
2022-09-13T08:34:15.366-0400	INFO	[beat]	instance/beat.go:1039	Beat info	{"system_info": {"beat": {"path": {"config": "c:\\program files\\filebeat", "data": "c:\\program files\\filebeat\\data", "home": "c:\\program files\\filebeat", "logs": "D:\\wsod\\logs\\filebeat"}, "type": "filebeat", "uuid": "2906c257-019f-4da2-b6a7-450ff28165fc"}}}
2022-09-13T08:34:15.366-0400	INFO	[beat]	instance/beat.go:1048	Build info	{"system_info": {"build": {"commit": "1993ee88a11cb34f61a1fb45c7c3cf50533682cb", "libbeat": "7.17.3", "time": "2022-04-19T09:27:20.000Z", "version": "7.17.3"}}}
2022-09-13T08:34:15.366-0400	INFO	[beat]	instance/beat.go:1051	Go runtime info	{"system_info": {"go": {"os":"windows","arch":"amd64","max_procs":2,"version":"go1.17.8"}}}
2022-09-13T08:34:15.371-0400	INFO	[beat]	instance/beat.go:1055	Host info	{"system_info": {"host": {"architecture":"x86_64","boot_time":"2022-08-13T18:36:19.28-04:00","name":"MD-WWWD702A","ip":["fe80::ad8a:626:83ab:1cd5/64","10.124.0.81/23","::1/128","127.0.0.1/8","fe80::5efe:a7c:51/128"],"kernel_version":"6.3.9600.20512 (winblue_ltsb_escrow.220711-1746)","mac":["00:50:56:ab:32:4c","00:00:00:00:00:00:00:e0"],"os":{"type":"windows","family":"windows","platform":"windows","name":"Windows Server 2012 R2 Standard","version":"6.3","major":3,"minor":0,"patch":0,"build":"9600.20520"},"timezone":"EDT","timezone_offset_sec":-14400,"id":"871f492a-4abc-4714-9af1-0171c375f116"}}}
2022-09-13T08:34:15.371-0400	INFO	[beat]	instance/beat.go:1084	Process info	{"system_info": {"process": {"cwd": "C:\\Windows\\system32", "exe": "C:\\Program Files\\filebeat\\filebeat.exe", "name": "filebeat.exe", "pid": 6408, "ppid": 628, "start_time": "2022-09-13T08:34:14.152-0400"}}}
2022-09-13T08:34:15.371-0400	INFO	instance/beat.go:328	Setup Beat: filebeat; Version: 7.17.3
2022-09-13T08:34:15.372-0400	INFO	[publisher]	pipeline/module.go:113	Beat name: MD-WWWD702A
2022-09-13T08:34:15.372-0400	WARN	beater/filebeat.go:202	Filebeat is unable to load the ingest pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the ingest pipelines or are using Logstash pipelines, you can ignore this warning.
2022-09-13T08:34:15.373-0400	INFO	instance/beat.go:492	filebeat start running.
2022-09-13T08:34:15.373-0400	INFO	registrar/migrate.go:129	Migrate registry file to registry directory
2022-09-13T08:34:15.373-0400	INFO	registrar/migrate.go:134	Move registry file to backup file: C:\\Program Files\\filebeat\\data\\registry.bak
2022-09-13T08:34:15.373-0400	INFO	registrar/migrate.go:163	No registry home found. Create: C:\Program Files\filebeat\data\registry\filebeat
2022-09-13T08:34:15.374-0400	INFO	registrar/migrate.go:171	Initialize registry meta file
2022-09-13T08:34:15.375-0400	INFO	[monitoring]	log/log.go:142	Starting metrics logging every 30s
2022-09-13T08:34:15.376-0400	INFO	registrar/migrate.go:151	Migrate old registry file to new data file
2022-09-13T08:34:15.376-0400	INFO	registrar/migrate.go:185	Migrate registry version 0 to version 1
2022-09-13T08:34:15.377-0400	INFO	memlog/store.go:119	Loading data file of 'C:\Program Files\filebeat\data\registry\filebeat' succeeded. Active transaction id=0
2022-09-13T08:34:15.377-0400	INFO	memlog/store.go:124	Finished loading transaction log file for 'C:\Program Files\filebeat\data\registry\filebeat'. Active transaction id=0
2022-09-13T08:34:15.384-0400	INFO	memlog/store.go:119	Loading data file of 'C:\Program Files\filebeat\data\registry\filebeat' succeeded. Active transaction id=4
2022-09-13T08:34:15.384-0400	INFO	memlog/store.go:124	Finished loading transaction log file for 'C:\Program Files\filebeat\data\registry\filebeat'. Active transaction id=4
2022-09-13T08:34:15.384-0400	WARN	beater/filebeat.go:411	Filebeat is unable to load the ingest pipelines for the configured modules because the Elasticsearch output is not configured/enabled. If you have already loaded the ingest pipelines or are using Logstash pipelines, you can ignore this warning.
2022-09-13T08:34:15.385-0400	INFO	[registrar]	registrar/registrar.go:109	States Loaded from registrar: 3
2022-09-13T08:34:15.385-0400	INFO	[crawler]	beater/crawler.go:71	Loading Inputs: 1
2022-09-13T08:34:15.385-0400	INFO	[crawler]	beater/crawler.go:117	starting input, keys present on the config: [filebeat.inputs.0.enabled filebeat.inputs.0.type]
2022-09-13T08:34:15.385-0400	INFO	[crawler]	beater/crawler.go:121	input disabled, skipping it
2022-09-13T08:34:15.386-0400	WARN	[cfgwarn]	log/input.go:89	DEPRECATED: Log input. Use Filestream input instead.
2022-09-13T08:34:15.386-0400	INFO	[input]	log/input.go:171	Configured paths: [D:\wsod\Logs\iis\httperr\*.log]	{"input_id": "5705bceb-9bde-40a1-94f5-8b4fcfd31857"}
2022-09-13T08:34:15.386-0400	INFO	[input]	log/input.go:171	Configured paths: [D:\wsod\Logs\iis\*\*.log]	{"input_id": "fff6014b-db7e-45cf-bd41-0b5d5b9bbb5c"}
2022-09-13T08:34:15.387-0400	INFO	[input]	log/input.go:171	Configured paths: [D:\wsod\Logs\web\*\*.log]	{"input_id": "e6232215-2907-4203-975d-66b9ae9c60ae"}
2022-09-13T08:34:15.387-0400	INFO	[crawler]	beater/crawler.go:106	Loading and starting Inputs completed. Enabled inputs: 0
2022-09-13T08:34:15.387-0400	INFO	cfgfile/reload.go:164	Config reloader started
2022-09-13T08:34:15.388-0400	INFO	[input]	log/input.go:171	Configured paths: [D:\wsod\Logs\iis\httperr\*.log]	{"input_id": "311a10dd-85d3-4a00-84f3-fe27a78a01a1"}
2022-09-13T08:34:15.388-0400	INFO	[input]	log/input.go:171	Configured paths: [D:\wsod\Logs\iis\*\*.log]	{"input_id": "dc698c8a-cd69-4039-b7c3-773b19e41b18"}
2022-09-13T08:34:15.389-0400	INFO	[input]	log/input.go:171	Configured paths: [D:\wsod\Logs\web\*\*.log]	{"input_id": "9d261f77-31fc-4d79-a475-9f31835d08b6"}
2022-09-13T08:34:15.389-0400	INFO	cfgfile/reload.go:224	Loading of config files completed.
2022-09-13T08:34:15.389-0400	INFO	[input.harvester]	log/harvester.go:309	Harvester started for paths: [D:\wsod\Logs\iis\httperr\*.log]	{"input_id": "311a10dd-85d3-4a00-84f3-fe27a78a01a1", "source": "D:\\wsod\\Logs\\iis\\httperr\\httperr10587.log", "state_id": "native::475398144-56586-2282207034", "finished": false, "os_id": "475398144-56586-2282207034", "harvester_id": "ab30fbe2-13d3-421f-9045-47caf2e56f31"}
2022-09-13T08:34:15.391-0400	INFO	[input.harvester]	log/harvester.go:309	Harvester started for paths: [D:\wsod\Logs\iis\*\*.log]	{"input_id": "dc698c8a-cd69-4039-b7c3-773b19e41b18", "source": "D:\\wsod\\Logs\\iis\\W3SVC12345\\u_ex220913.log", "state_id": "native::201916416-65048-2282207034", "finished": false, "os_id": "201916416-65048-2282207034", "harvester_id": "9563af3a-5edf-4541-a5bf-76ae5fbb07df"}
2022-09-13T08:34:15.391-0400	INFO	[input.harvester]	log/harvester.go:309	Harvester started for paths: [D:\wsod\Logs\iis\*\*.log]	{"input_id": "dc698c8a-cd69-4039-b7c3-773b19e41b18", "source": "D:\\wsod\\Logs\\iis\\W3SVC12345\\u_ex220912.log", "state_id": "native::192806912-65201-2282207034", "finished": false, "os_id": "192806912-65201-2282207034", "harvester_id": "02e2ec64-18d8-4667-af17-301afb68efc6"}
2022-09-13T08:34:15.439-0400	INFO	[publisher_pipeline_output]	pipeline/output.go:143	Connecting to failover(backoff(async(tcp://do-logd701.dev1.mdgapp.net:12203)),backoff(async(tcp://do-logd702.dev1.mdgapp.net:12203)))
2022-09-13T08:34:15.447-0400	INFO	[publisher]	pipeline/retry.go:219	retryer: send unwait signal to consumer
2022-09-13T08:34:15.447-0400	INFO	[publisher]	pipeline/retry.go:223	  done
2022-09-13T08:34:15.470-0400	INFO	[publisher_pipeline_output]	pipeline/output.go:151	Connection to failover(backoff(async(tcp://do-logd701.dev1.mdgapp.net:12203)),backoff(async(tcp://do-logd702.dev1.mdgapp.net:12203))) established
2022-09-13T08:34:45.391-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1109,"time":{"ms":1109}},"total":{"ticks":8671,"time":{"ms":8671},"value":8671},"user":{"ticks":7562,"time":{"ms":7562}}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":30498},"version":"7.17.3"},"memstats":{"gc_next":32619232,"memory_alloc":18205648,"memory_sys":49340440,"memory_total":1255245816,"rss":72171520},"runtime":{"goroutines":59}},"filebeat":{"events":{"added":279429,"done":279429},"harvester":{"open_files":3,"running":3,"started":3}},"libbeat":{"config":{"module":{"running":3,"starts":3},"reloads":1,"scans":1},"output":{"events":{"acked":271451,"active":0,"batches":133,"total":271451},"read":{"bytes":798},"type":"logstash","write":{"bytes":10626131}},"pipeline":{"clients":3,"events":{"active":0,"filtered":7978,"published":271451,"retry":2048,"total":279429},"queue":{"acked":271451,"max_events":4096}}},"registrar":{"states":{"current":3,"update":279429},"writes":{"success":161,"total":161}},"system":{"cpu":{"cores":2}}}}}
2022-09-13T08:35:15.392-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1125,"time":{"ms":16}},"total":{"ticks":8703,"time":{"ms":32},"value":8703},"user":{"ticks":7578,"time":{"ms":16}}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":60502},"version":"7.17.3"},"memstats":{"gc_next":32619232,"memory_alloc":19969560,"memory_total":1257009728,"rss":72663040},"runtime":{"goroutines":59}},"filebeat":{"events":{"added":52,"done":52},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":52,"active":0,"batches":1,"total":52},"read":{"bytes":6},"write":{"bytes":2581}},"pipeline":{"clients":3,"events":{"active":0,"published":52,"total":52},"queue":{"acked":52}}},"registrar":{"states":{"current":3,"update":52},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:35:45.409-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1125},"total":{"ticks":8703,"value":8703},"user":{"ticks":7578}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":90511},"version":"7.17.3"},"memstats":{"gc_next":32619232,"memory_alloc":20215232,"memory_total":1257255400,"rss":72683520},"runtime":{"goroutines":59}},"filebeat":{"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:36:15.411-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1125},"total":{"ticks":8703,"value":8703},"user":{"ticks":7578}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":120516},"version":"7.17.3"},"memstats":{"gc_next":32619232,"memory_alloc":22084568,"memory_total":1259124736,"rss":73654272},"runtime":{"goroutines":59}},"filebeat":{"events":{"added":86,"done":86},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":86,"active":0,"batches":1,"total":86},"read":{"bytes":6},"write":{"bytes":3876}},"pipeline":{"clients":3,"events":{"active":0,"published":86,"total":86},"queue":{"acked":86}}},"registrar":{"states":{"current":3,"update":86},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:36:45.400-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1125},"total":{"ticks":8703,"value":8703},"user":{"ticks":7578}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":150496},"version":"7.17.3"},"memstats":{"gc_next":21038528,"memory_alloc":10519256,"memory_total":1259371880,"rss":57937920},"runtime":{"goroutines":59}},"filebeat":{"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:37:15.409-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1125,"time":{"ms":15}},"total":{"ticks":8703,"time":{"ms":15},"value":8703},"user":{"ticks":7578}},"handles":{"open":165},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":180504},"version":"7.17.3"},"memstats":{"gc_next":21038528,"memory_alloc":12436504,"memory_total":1261289128,"rss":57913344},"runtime":{"goroutines":59}},"filebeat":{"events":{"added":121,"done":121},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":121,"active":0,"batches":1,"total":121},"read":{"bytes":6},"write":{"bytes":5335}},"pipeline":{"clients":3,"events":{"active":0,"published":121,"total":121},"queue":{"acked":121}}},"registrar":{"states":{"current":3,"update":121},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:37:45.410-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1140},"total":{"ticks":8718,"time":{"ms":15},"value":8718},"user":{"ticks":7578,"time":{"ms":15}}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":210502},"version":"7.17.3"},"memstats":{"gc_next":21038528,"memory_alloc":12760944,"memory_total":1261613568,"rss":57933824},"runtime":{"goroutines":59}},"filebeat":{"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:38:15.415-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1171,"time":{"ms":31}},"total":{"ticks":8764,"time":{"ms":31},"value":8764},"user":{"ticks":7593}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":240508},"version":"7.17.3"},"memstats":{"gc_next":21038528,"memory_alloc":14508560,"memory_sys":262144,"memory_total":1263361184,"rss":57950208},"runtime":{"goroutines":59}},"filebeat":{"events":{"added":52,"done":52},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":52,"active":0,"batches":1,"total":52},"read":{"bytes":6},"write":{"bytes":2654}},"pipeline":{"clients":3,"events":{"active":0,"published":52,"total":52},"queue":{"acked":52}}},"registrar":{"states":{"current":3,"update":52},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:38:45.419-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1203,"time":{"ms":32}},"total":{"ticks":8796,"time":{"ms":32},"value":8796},"user":{"ticks":7593}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":270506},"version":"7.17.3"},"memstats":{"gc_next":21009840,"memory_alloc":10504712,"memory_total":1263606336,"rss":53972992},"runtime":{"goroutines":59}},"filebeat":{"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:39:15.413-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1234,"time":{"ms":31}},"total":{"ticks":8827,"time":{"ms":31},"value":8827},"user":{"ticks":7593}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":300497},"version":"7.17.3"},"memstats":{"gc_next":21009840,"memory_alloc":12219616,"memory_total":1265321240,"rss":54321152},"runtime":{"goroutines":59}},"filebeat":{"events":{"added":55,"done":55},"harvester":{"open_files":3,"running":3}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":55,"active":0,"batches":1,"total":55},"read":{"bytes":6},"write":{"bytes":2714}},"pipeline":{"clients":3,"events":{"active":0,"published":55,"total":55},"queue":{"acked":55}}},"registrar":{"states":{"current":3,"update":55},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:39:20.638-0400	INFO	[input.harvester]	log/harvester.go:340	File is inactive. Closing because close_inactive of 5m0s reached.	{"input_id": "311a10dd-85d3-4a00-84f3-fe27a78a01a1", "source": "D:\\wsod\\Logs\\iis\\httperr\\httperr10587.log", "state_id": "native::475398144-56586-2282207034", "finished": false, "os_id": "475398144-56586-2282207034", "harvester_id": "ab30fbe2-13d3-421f-9045-47caf2e56f31"}
2022-09-13T08:39:45.415-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1234},"total":{"ticks":8827,"value":8827},"user":{"ticks":7593}},"handles":{"open":168},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":330496},"version":"7.17.3"},"memstats":{"gc_next":21009840,"memory_alloc":12555032,"memory_total":1265656656,"rss":54325248},"runtime":{"goroutines":54}},"filebeat":{"events":{"added":1,"done":1},"harvester":{"closed":1,"open_files":2,"running":2}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0,"filtered":1,"total":1}}},"registrar":{"states":{"current":3,"update":1},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:39:45.638-0400	INFO	[input.harvester]	log/harvester.go:340	File is inactive. Closing because close_inactive of 5m0s reached.	{"input_id": "dc698c8a-cd69-4039-b7c3-773b19e41b18", "source": "D:\\wsod\\Logs\\iis\\W3SVC12345\\u_ex220912.log", "state_id": "native::192806912-65201-2282207034", "finished": false, "os_id": "192806912-65201-2282207034", "harvester_id": "02e2ec64-18d8-4667-af17-301afb68efc6"}
2022-09-13T08:40:15.429-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1234,"time":{"ms":16}},"total":{"ticks":8843,"time":{"ms":32},"value":8843},"user":{"ticks":7609,"time":{"ms":16}}},"handles":{"open":165},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":360513},"version":"7.17.3"},"memstats":{"gc_next":21009840,"memory_alloc":14460872,"memory_total":1267562496,"rss":55193600},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":93,"done":93},"harvester":{"closed":1,"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":92,"active":0,"batches":1,"total":92},"read":{"bytes":6},"write":{"bytes":4174}},"pipeline":{"clients":3,"events":{"active":0,"filtered":1,"published":92,"total":93},"queue":{"acked":92}}},"registrar":{"states":{"current":3,"update":93},"writes":{"success":2,"total":2}}}}}
2022-09-13T08:40:45.425-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1265,"time":{"ms":15}},"total":{"ticks":8874,"time":{"ms":15},"value":8874},"user":{"ticks":7609}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":390505},"version":"7.17.3"},"memstats":{"gc_next":20932096,"memory_alloc":10546056,"memory_total":1267883256,"rss":53850112},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:41:15.433-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1265,"time":{"ms":16}},"total":{"ticks":8874,"time":{"ms":16},"value":8874},"user":{"ticks":7609}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":420505},"version":"7.17.3"},"memstats":{"gc_next":20932096,"memory_alloc":12241280,"memory_total":1269578480,"rss":54198272},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":72,"done":72},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":72,"active":0,"batches":1,"total":72},"read":{"bytes":6},"write":{"bytes":3335}},"pipeline":{"clients":3,"events":{"active":0,"published":72,"total":72},"queue":{"acked":72}}},"registrar":{"states":{"current":3,"update":72},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:41:45.437-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1312,"time":{"ms":31}},"total":{"ticks":8921,"time":{"ms":31},"value":8921},"user":{"ticks":7609}},"handles":{"open":165},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":450504},"version":"7.17.3"},"memstats":{"gc_next":20932096,"memory_alloc":12562600,"memory_total":1269899800,"rss":54198272},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:42:15.429-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1343,"time":{"ms":31}},"total":{"ticks":8952,"time":{"ms":31},"value":8952},"user":{"ticks":7609}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":480497},"version":"7.17.3"},"memstats":{"gc_next":20932096,"memory_alloc":14493696,"memory_total":1271830896,"rss":55070720},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":114,"done":114},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":114,"active":0,"batches":1,"total":114},"read":{"bytes":6},"write":{"bytes":5056}},"pipeline":{"clients":3,"events":{"active":0,"published":114,"total":114},"queue":{"acked":114}}},"registrar":{"states":{"current":3,"update":114},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:42:45.433-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1359,"time":{"ms":16}},"total":{"ticks":8968,"time":{"ms":16},"value":8968},"user":{"ticks":7609}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":510497},"version":"7.17.3"},"memstats":{"gc_next":21075760,"memory_alloc":10538096,"memory_total":1272152472,"rss":54050816},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:43:15.438-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1390,"time":{"ms":31}},"total":{"ticks":9015,"time":{"ms":47},"value":9015},"user":{"ticks":7625,"time":{"ms":16}}},"handles":{"open":165},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":540501},"version":"7.17.3"},"memstats":{"gc_next":21075760,"memory_alloc":12255288,"memory_total":1273869664,"rss":54386688},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":65,"done":65},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":65,"active":0,"batches":1,"total":65},"read":{"bytes":6},"write":{"bytes":3139}},"pipeline":{"clients":3,"events":{"active":0,"published":65,"total":65},"queue":{"acked":65}}},"registrar":{"states":{"current":3,"update":65},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:43:45.438-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1421,"time":{"ms":31}},"total":{"ticks":9077,"time":{"ms":62},"value":9077},"user":{"ticks":7656,"time":{"ms":31}}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":570508},"version":"7.17.3"},"memstats":{"gc_next":21075760,"memory_alloc":12574416,"memory_total":1274188792,"rss":54386688},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:44:15.447-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1421,"time":{"ms":16}},"total":{"ticks":9077,"time":{"ms":16},"value":9077},"user":{"ticks":7656}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":600504},"version":"7.17.3"},"memstats":{"gc_next":21075760,"memory_alloc":14196312,"memory_total":1275810688,"rss":55074816},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":41,"done":41},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":41,"active":0,"batches":1,"total":41},"read":{"bytes":6},"write":{"bytes":2210}},"pipeline":{"clients":3,"events":{"active":0,"published":41,"total":41},"queue":{"acked":41}}},"registrar":{"states":{"current":3,"update":41},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:44:45.446-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1453,"time":{"ms":16}},"total":{"ticks":9140,"time":{"ms":47},"value":9140},"user":{"ticks":7687,"time":{"ms":31}}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":630501},"version":"7.17.3"},"memstats":{"gc_next":21015184,"memory_alloc":10508752,"memory_total":1276136952,"rss":53592064},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:45:15.449-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1453},"total":{"ticks":9140,"value":9140},"user":{"ticks":7687}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":660499},"version":"7.17.3"},"memstats":{"gc_next":21015184,"memory_alloc":12191328,"memory_total":1277819528,"rss":53927936},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":56,"done":56},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":56,"active":0,"batches":1,"total":56},"read":{"bytes":6},"write":{"bytes":2774}},"pipeline":{"clients":3,"events":{"active":0,"published":56,"total":56},"queue":{"acked":56}}},"registrar":{"states":{"current":3,"update":56},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:45:45.465-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1453},"total":{"ticks":9140,"value":9140},"user":{"ticks":7687}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":690511},"version":"7.17.3"},"memstats":{"gc_next":21015184,"memory_alloc":12515664,"memory_total":1278143864,"rss":53927936},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:46:15.458-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1468,"time":{"ms":31}},"total":{"ticks":9155,"time":{"ms":31},"value":9155},"user":{"ticks":7687}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":720504},"version":"7.17.3"},"memstats":{"gc_next":21015184,"memory_alloc":14216896,"memory_total":1279845096,"rss":54558720},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":62,"done":62},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":62,"active":0,"batches":1,"total":62},"read":{"bytes":6},"write":{"bytes":2958}},"pipeline":{"clients":3,"events":{"active":0,"published":62,"total":62},"queue":{"acked":62}}},"registrar":{"states":{"current":3,"update":62},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:46:45.457-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1484},"total":{"ticks":9171,"value":9171},"user":{"ticks":7687}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":750498},"version":"7.17.3"},"memstats":{"gc_next":21143760,"memory_alloc":10568096,"memory_total":1280166128,"rss":53723136},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}
2022-09-13T08:47:15.456-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1500,"time":{"ms":16}},"total":{"ticks":9187,"time":{"ms":16},"value":9187},"user":{"ticks":7687}},"handles":{"open":169},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":780497},"version":"7.17.3"},"memstats":{"gc_next":21143760,"memory_alloc":12459080,"memory_total":1282057112,"rss":53727232},"runtime":{"goroutines":49}},"filebeat":{"events":{"added":111,"done":111},"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"acked":111,"active":0,"batches":1,"total":111},"read":{"bytes":6},"write":{"bytes":4787}},"pipeline":{"clients":3,"events":{"active":0,"published":111,"total":111},"queue":{"acked":111}}},"registrar":{"states":{"current":3,"update":111},"writes":{"success":1,"total":1}}}}}
2022-09-13T08:47:45.459-0400	INFO	[monitoring]	log/log.go:184	Non-zero metrics in the last 30s	{"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":1500},"total":{"ticks":9187,"value":9187},"user":{"ticks":7687}},"handles":{"open":167},"info":{"ephemeral_id":"ef115b3f-bc86-4802-8e8d-cb95d43930ac","uptime":{"ms":810502},"version":"7.17.3"},"memstats":{"gc_next":21143760,"memory_alloc":12859752,"memory_total":1282457784,"rss":53731328},"runtime":{"goroutines":49}},"filebeat":{"harvester":{"open_files":1,"running":1}},"libbeat":{"config":{"module":{"running":3}},"output":{"events":{"active":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":3}}}}}

These look odd to me..are those log lines present every time you start filebeat?

Particularly this
No registry home found.

When you upgraded did you use the latest filebeat.yml or did you leave the old 5.6 filebeat.yml?

@andrewkroh do you have any thoughts?

No after upgrade it was my latest filebeat.yml. I was only preserving old registry file and after upgrade it automatically convert registry file with regsitry folder and under that it add older offset values.

And regarding that error "No registry home found" I have resolved that i was doing some testing because of that we got that error.

Thanks...

So to be clear every time you restart filebeat on windows it is reloading ALL the log files from the beginning..

Or does it only re-load the ALL log files at Once at startup and then ongoing is fine.

I am still unclear... apologies.

Yes it only re-load the ALL log files at Once at startup and then ongoing is fine.

It looks to me that your original 5.6.5 registry file / data is missing or perhaps corrupted and thus a new registry is created.

Do you have a copy of the old registry data / file?

Unfortunately I am not an expert on the internals of registry files especially ones that are from 5.6 which is years old... but it you can find it perhaps you can copy it into the Directory before you start filebeat.

C:\Program Files\filebeat\data\registry\filebeat

Yes we are following same steps. we copy registry file of 5.6.5 to new location. And after upgrade before restarting filebeat service we copy 5.6.5 registry file to / data directory.
And after restart it automatically convert 5.6.5 registry file into registry folder( adding offset of5.6.5).

I am guessing there might some configuration i need to add to prevent it from to read file again from strach. After upgrade it should only look for delta or newly added Logs from file.

To me it seems like it is not reading the old registry correctly ... (obvious :slight_smile: )

Not sure if you are going to get it to work correctly because of the very old version.

Perhaps you could look at this setting to help with the problem

ignore_older

If this option is enabled, Filebeat ignores any files that were modified before the specified timespan. Configuring ignore_older can be especially useful if you keep log files for a long time. For example, if you want to start Filebeat, but only want to send the newest files and files from last week, you can configure this option.

We are already using ignore_older:24h but its not helped us from data duplicacy.

Apologies, I am not sure what to tell you at this point... if you are getting duplicated events in the last 24 hours.

It could be a bug in the conversion from 5.6 to 7.17 on windows... 5.6 is several years old / very very old.

You could try running a 6.x filebeat then a 7.x filebeat and see if the registry conversion works.

I do not think there is a simple answer at this point, you may just need to de-dup your data another way.

Perhaps looking at one of the older threads will help

Thanks @stephenb for your support. Do you have any idea how to tell filebeat/what i have to define in my configuration so that it should read only newly logs instead of whole file i am already using ignore_older:24h.

Perhaps you are not putting the ignore_older in the right place in your ymls

I can not tell with the .yml snippets above where you actually have ignore_older set those snippets are not consistent / malformed... the indentation is wrong.... etc...

Also you have just this.. with nothing under it... I can not tell what you are trying to do

filebeat.inputs:
- type: filestream

Then the second snippet of code is malformed and I do not know what it is

What I can tell you .... I tested and ignore_older and it worked as designed

This is a test I just ran and the file is older than 24h and it did not read it
I took out ignore_older and it read it... so it does work. (I do not have a windows box so I can not test there but I think there would be a bug or something filed if it did not work, I can not find one with a quick look)

filebeat.inputs:
- type: filestream
  id: my-filestream-id
  enabled: true
  ignore_older: 24h
  paths:
    - /Users/sbrown/workspace/sample-data/discuss/container-mixed/*.log

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