# Filebeat upgrade requiring multiple restarts

**URL:** <https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414>\
**Category:** Beats\
**Tags:** filebeat\
**Created:** [January 3, 2017, 10:02am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414 "2017-01-03T10:02:15Z")\
**Posts on this page:** 11\
**Page:** 1

<div class="post-metadata">

**Author:** ![Sai\_Birada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sai_birada/32/142367_2.png) [@Sai\_Birada](https://discuss.elastic.co/u/Sai_Birada)\
**Post date:** [January 3, 2017, 10:02am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/1 "2017-01-03T10:02:15Z")

</div>

I am using filebeat-1.2.3 version which stores info in .filebeat file. Now i am upgrading to 5.1.2 and when i copied .filebeat to data/registry and restarted filebeat filebeat doesnt send any old data as expected. But its not sending any new logs to logstash also. I couldnt find any issues on logstash side also. When i stop and start the filebeat now its sending the new data without any issues. It seems i am missing some step in upgradation process. Need help to properly upgrade filebeat from 1.2.3 to 5.1.2. Logstash version i am using is 2.4.1

---

<div class="post-metadata">

**Author:** ![Sai\_Birada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sai_birada/32/142367_2.png) [@Sai\_Birada](https://discuss.elastic.co/u/Sai_Birada)\
**Post date:** [January 4, 2017, 9:58am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/2 "2017-01-04T09:58:35Z")

</div>

There seems to be a bug with filebeat - 5.1.2 version. I copied .filebeat file created by older filebeat version to data/registry. Filebeat is not sending logs to logstash with the first start. Only after restart its sending logs. Following is the logs being logged in both the cases.

First start :

2017/01/04 10:03:45.576818 prospector.go:111: INFO Starting prospector of type: log  
2017/01/04 10:03:45.576830 prospector\_log.go:62: DBG Start next scan  
2017/01/04 10:03:45.576881 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/04 10:03:45.576927 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 36598  
2017/01/04 10:03:45.576937 prospector\_log.go:297: DBG Harvester for file is still running: /var/log/heartbeat.log  
2017/01/04 10:03:45.576952 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
2017/01/04 10:03:50.583110 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 1  
2017/01/04 10:03:50.583169 client.go:128: DBG No events to publish  
2017/01/04 10:03:50.583184 sync.go:68: DBG Events sent: 1  
2017/01/04 10:03:50.583199 registrar.go:269: DBG Processing 1 events  
2017/01/04 10:03:50.583215 registrar.go:255: DBG Registrar states cleaned up. Before: 1, After: 1  
2017/01/04 10:03:50.583227 registrar.go:292: DBG Write registry file: /sc/filebeat/data/registry  
2017/01/04 10:03:50.583442 registrar.go:317: DBG Registry file updated. 1 states written.  
2017/01/04 10:03:55.586849 prospector.go:155: DBG Run prospector  
2017/01/04 10:03:55.586849 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 0  
2017/01/04 10:03:55.586882 prospector\_log.go:62: DBG Start next scan  
2017/01/04 10:03:55.586966 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/04 10:03:55.586984 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 36598  
2017/01/04 10:03:55.586995 prospector\_log.go:297: DBG Harvester for file is still running: /var/log/heartbeat.log  
2017/01/04 10:03:55.587010 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
^C2017/01/04 10:03:57.875554 service.go:32: DBG Received sigterm/sigint, stopping  
2017/01/04 10:03:57.875635 filebeat.go:168: INFO Stopping filebeat

In reality the offset has been updated long back, but filebeat is not able to update it in first start. But if i restart  
second start :

2017/01/04 10:05:57.879692 prospector\_log.go:62: DBG Start next scan  
2017/01/04 10:05:57.879755 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/04 10:05:57.879775 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 40948  
2017/01/04 10:05:57.879786 prospector\_log.go:297: DBG Harvester for file is still running: /var/log/heartbeat.log  
2017/01/04 10:05:57.879801 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
2017/01/04 10:05:57.910264 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 0  
2017/01/04 10:06:02.910948 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 0  
2017/01/04 10:06:02.911028 log\_file.go:84: DBG End of file reached: /var/log/heartbeat.log; Backoff now.  
2017/01/04 10:06:03.930773 log\_file.go:84: DBG End of file reached: /var/log/heartbeat.log; Backoff now.  
2017/01/04 10:06:05.947757 log\_file.go:84: DBG End of file reached: /var/log/heartbeat.log; Backoff now.  
2017/01/04 10:06:07.897223 prospector.go:155: DBG Run prospector  
2017/01/04 10:06:07.897268 prospector\_log.go:62: DBG Start next scan  
2017/01/04 10:06:07.897337 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/04 10:06:07.897356 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 40977  
2017/01/04 10:06:07.897367 prospector\_log.go:297: DBG Harvester for file is still running: /var/log/heartbeat.log  
2017/01/04 10:06:07.897383 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
2017/01/04 10:06:07.927240 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 1  
2017/01/04 10:06:07.927386 client.go:184: DBG Publish: {  
"@timestamp": "2017-01-04T10:06:02.910Z",  
"beat": {  
"hostname": "NSS",  
"name": "NSS",  
"version": "5.1.2"  
},  
"fields": {  
"cloudname": "[zscaler.net](http://zscaler.net)",  
"hostip": "10.10.35.180"  
},  
"input\_type": "log",  
"message": "Wed Jan 4 10:06:00 UTC 2017",  
"offset": 40977,  
"source": "/var/log/heartbeat.log",  
"type": "heartbeat\_Etc/GMT+0"  
}  
2017/01/04 10:06:07.927417 output.go:109: DBG output worker: publish 1 events  
2017/01/04 10:06:07.927432 sync.go:107: DBG Try to publish 1 events to logstash with window size 67  
2017/01/04 10:06:07.959783 client.go:194: DBG handle error: EOF  
2017/01/04 10:06:07.959804 client.go:110: DBG closing  
2017/01/04 10:06:07.959844 sync.go:78: DBG 0 events out of 1 events sent to logstash. Continue sending  
2017/01/04 10:06:07.959856 sync.go:58: DBG close connection  
2017/01/04 10:06:07.959868 sync.go:85: ERR Failed to publish events caused by: EOF  
2017/01/04 10:06:07.959880 single.go:91: INFO Error publishing events (retrying): EOF  
2017/01/04 10:06:07.959890 sync.go:58: DBG close connection  
2017/01/04 10:06:07.959899 single.go:156: DBG send fail  
2017/01/04 10:06:08.977016 sync.go:53: DBG connect  
2017/01/04 10:06:08.977591 sync.go:107: DBG Try to publish 1 events to logstash with window size 33  
2017/01/04 10:06:09.019525 sync.go:78: DBG 1 events out of 1 events sent to logstash. Continue sending  
2017/01/04 10:06:09.019552 single.go:150: DBG send completed

---

<div class="post-metadata">

**Author:** ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)\
**Post date:** [January 5, 2017, 11:17am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/3 "2017-01-05T11:17:41Z")

</div>

Looks like the finished state is incorrect after the migration and a restart resets the finished state. Do you still have your old registry file from the 1.2.3 version?

Also do you still have the 2 log files? The "interesting" part of the migration happens before the log lines you posted. Any chance to share the log files from the beginning?

---

<div class="post-metadata">

**Author:** ![Sai\_Birada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sai_birada/32/142367_2.png) [@Sai\_Birada](https://discuss.elastic.co/u/Sai_Birada)\
**Post date:** [January 5, 2017, 11:56am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/4 "2017-01-05T11:56:12Z")

</div>

HI ruflin,  
I can consistently see this behaviour, i am attaching all the log file you asked.  
**_.filebeat_** file created by 1.2.3  
{"/var/log/heartbeat.log":{"source":"/var/log/heartbeat.log","offset":85724,"FileStateOS":{"inode":5087299,"device":82}}}  
**_data/registry_** file created by 5.1.2  
[{"source":"/var/log/heartbeat.log","offset":85782,"FileStateOS":{"inode":5087299,"device":82},"timestamp":"2017-01-05T11:52:28.338172375Z","ttl":-1}]

---

<div class="post-metadata">

**Author:** ![Sai\_Birada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sai_birada/32/142367_2.png) [@Sai\_Birada](https://discuss.elastic.co/u/Sai_Birada)\
**Post date:** [January 5, 2017, 12:06pm UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/5 "2017-01-05T12:06:31Z")

</div>

1.2.3 logs sample  
2017/01/05 11:46:43.514989 beat.go:135: DBG Initializing output plugins  
2017/01/05 11:46:43.515034 geolite.go:24: INFO GeoIP disabled: No paths were set under output.geoip.paths  
2017/01/05 11:46:43.515588 logstash.go:106: INFO Max Retries set to: 3  
2017/01/05 11:46:43.515609 client.go:100: DBG connect  
2017/01/05 11:46:43.520967 outputs.go:126: INFO Activated logstash as output plugin.  
2017/01/05 11:46:43.520990 publish.go:232: DBG Create output worker  
2017/01/05 11:46:43.521029 publish.go:274: DBG No output is defined to store the topology. The server fields might not be filled.  
2017/01/05 11:46:43.521060 publish.go:288: INFO Publisher name: NSS  
2017/01/05 11:46:43.521138 async.go:78: INFO Flush Interval set to: 1s  
2017/01/05 11:46:43.521151 async.go:84: INFO Max Bulk Size set to: 2048  
2017/01/05 11:46:43.521160 async.go:92: DBG create bulk processing worker (interval=1s, bulk size=2048)  
2017/01/05 11:46:43.521208 beat.go:147: INFO Init Beat: filebeat; Version: 1.2.3  
2017/01/05 11:46:43.521528 beat.go:173: INFO filebeat sucessfully setup. Start running.  
2017/01/05 11:46:43.521571 registrar.go:68: INFO Registry file set to: /sc/filebeat/.filebeat  
2017/01/05 11:46:43.521598 spooler.go:44: DBG Set idleTimeoutDuration to 5s  
2017/01/05 11:46:43.521613 crawler.go:38: DBG File Configs: [/var/log/heartbeat.log]  
2017/01/05 11:46:43.521632 prospector.go:133: INFO Set ignore\_older duration to 0s  
2017/01/05 11:46:43.521642 prospector.go:133: INFO Set close\_older duration to 1h0m0s  
2017/01/05 11:46:43.521651 prospector.go:133: INFO Set scan\_frequency duration to 10s  
2017/01/05 11:46:43.521660 prospector.go:90: INFO Invalid input type set:  
2017/01/05 11:46:43.521668 prospector.go:93: INFO Input type set to: log  
2017/01/05 11:46:43.521676 prospector.go:133: INFO Set backoff duration to 1s  
2017/01/05 11:46:43.521684 prospector.go:133: INFO Set max\_backoff duration to 10s  
2017/01/05 11:46:43.521691 prospector.go:113: INFO force\_close\_file is disabled  
2017/01/05 11:46:43.521701 crawler.go:58: DBG Waiting for 1 prospectors to initialise  
2017/01/05 11:46:43.521722 prospector.go:143: INFO Starting prospector of type: log  
2017/01/05 11:46:43.521752 prospector.go:261: DBG scan path /var/log/heartbeat.log  
2017/01/05 11:46:43.521780 prospector.go:275: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/05 11:46:43.521833 prospector.go:345: DBG Start harvesting unknown file: /var/log/heartbeat.log  
2017/01/05 11:46:43.521846 prospector.go:399: DBG Launching harvester on new file: /var/log/heartbeat.log  
2017/01/05 11:46:43.521868 crawler.go:71: DBG Registrar will re-save state for /var/log/heartbeat.log  
2017/01/05 11:46:43.521879 crawler.go:65: DBG No pending prospectors. Finishing setup  
2017/01/05 11:46:43.521890 crawler.go:78: INFO All prospectors initialised with 1 states to persist  
2017/01/05 11:46:43.521902 registrar.go:87: INFO Starting Registrar  
2017/01/05 11:46:43.521922 publish.go:88: INFO Start sending events to output  
2017/01/05 11:46:43.522003 spooler.go:77: INFO Starting spooler: spool\_size: 2048; idle\_timeout: 5s  
2017/01/05 11:46:43.522055 log.go:283: DBG harvest: "/var/log/heartbeat.log" (offset snapshot:0)  
2017/01/05 11:46:43.522070 log.go:113: INFO Harvester started for file: /var/log/heartbeat.log  
2017/01/05 11:46:43.535784 prospector.go:261: DBG scan path /var/log/heartbeat.log  
2017/01/05 11:46:43.535840 prospector.go:275: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/05 11:46:43.535872 registrar.go:175: DBG Same file as before found. Fetch the state.  
2017/01/05 11:46:43.535901 prospector.go:418: DBG Update existing file for harvesting: /var/log/heartbeat.log  
2017/01/05 11:46:43.535913 prospector.go:465: DBG Not harvesting, file didn't change: /var/log/heartbeat.log  
2017/01/05 11:46:43.535781 util.go:20: DBG full line read  
2017/01/05 11:46:43.575805 spooler.go:91: DBG Flushing spooler because spooler full. Events flushed: 2048  
2017/01/05 11:50:10.509945 publish.go:109: DBG Publish: {

* * *

}  
2017/01/05 11:50:10.509985 output.go:87: DBG output worker: publish 908 events  
2017/01/05 11:50:10.510005 client.go:146: DBG Try to publish 908 events to logstash with window size 857  
2017/01/05 11:50:10.855642 client.go:227: DBG update max ok window size: 608 \< 857  
2017/01/05 11:50:10.855686 client.go:231: DBG increase window size to: 1286  
2017/01/05 11:50:10.855700 client.go:234: DBG set to batchSize: 908  
2017/01/05 11:50:10.855717 client.go:124: DBG 857 events out of 908 events sent to logstash. Continue sending ...  
2017/01/05 11:50:10.855731 client.go:146: DBG Try to publish 51 events to logstash with window size 908  
2017/01/05 11:50:10.906327 client.go:124: DBG 51 events out of 51 events sent to logstash. Continue sending ...  
2017/01/05 11:50:10.906354 single.go:135: DBG send completed  
2017/01/05 11:50:10.906393 publish.go:104: INFO Events sent: 908  
2017/01/05 11:50:10.906419 registrar.go:115: DBG Processing 908 events  
2017/01/05 11:50:10.906911 registrar.go:146: DBG Write registry file: /sc/filebeat/.filebeat  
2017/01/05 11:50:10.907025 registrar.go:162: INFO Registry file updated. 1 states written.  
2017/01/05 11:50:16.809629 service.go:30: DBG Received sigterm/sigint, stopping  
2017/01/05 11:50:16.809692 registrar.go:133: INFO Stopping Registrar  
2017/01/05 11:50:16.809720 registrar.go:97: INFO Ending Registrar  
2017/01/05 11:50:16.809751 registrar.go:146: DBG Write registry file: /sc/filebeat/.filebeat  
2017/01/05 11:50:16.809880 registrar.go:162: INFO Registry file updated. 1 states written.  
2017/01/05 11:50:16.809940 beat.go:183: INFO Cleaning up filebeat before shutting down.

---

<div class="post-metadata">

**Author:** ![Sai\_Birada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sai_birada/32/142367_2.png) [@Sai\_Birada](https://discuss.elastic.co/u/Sai_Birada)\
**Post date:** [January 5, 2017, 12:10pm UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/6 "2017-01-05T12:10:09Z")

</div>

5.1.2 first time logs sample  
2017/01/05 11:51:08.179309 beat.go:267: INFO Home path: [/sc/filebeat] Config path: [/sc/filebeat] Data path: [/sc/filebeat/data] Logs path: [/sc/filebeat/logs]  
2017/01/05 11:51:08.179357 beat.go:177: INFO Setup Beat: filebeat; Version: 5.1.2  
2017/01/05 11:51:08.179384 processor.go:43: DBG Processors:  
2017/01/05 11:51:08.179400 beat.go:183: DBG Initializing output plugins  
2017/01/05 11:51:08.179558 outputs.go:106: INFO Activated logstash as output plugin.  
2017/01/05 11:51:08.179577 publish.go:234: DBG Create output worker  
2017/01/05 11:51:08.179644 publish.go:276: DBG No output is defined to store the topology. The server fields might not be filled.  
2017/01/05 11:51:08.179765 async.go:63: INFO Flush Interval set to: 1s  
2017/01/05 11:51:08.179783 async.go:64: INFO Max Bulk Size set to: 2048  
2017/01/05 11:51:08.179797 async.go:72: DBG create bulk processing worker (interval=1s, bulk size=2048)  
2017/01/05 11:51:08.179958 beat.go:207: INFO filebeat start running.  
2017/01/05 11:51:08.180012 registrar.go:85: INFO Registry file set to: /sc/filebeat/data/registry  
2017/01/05 11:51:08.180060 registrar.go:106: INFO Loading registrar data from /sc/filebeat/data/registry  
2017/01/05 11:51:08.180199 registrar.go:177: INFO Old registry states found: 1  
2017/01/05 11:51:08.180222 registrar.go:292: DBG Write registry file: /sc/filebeat/data/registry  
2017/01/05 11:51:08.180407 registrar.go:317: DBG Registry file updated. 1 states written.  
2017/01/05 11:51:08.180425 registrar.go:184: INFO Old states converted to new states and written to registrar: 1  
2017/01/05 11:51:08.180457 crawler.go:34: INFO Loading Prospectors: 1  
2017/01/05 11:51:08.180545 state.go:64: DBG New state added for /var/log/heartbeat.log  
2017/01/05 11:51:08.180558 prospector\_log.go:57: INFO Prospector with previous states loaded: 1  
2017/01/05 11:51:08.180661 prospector.go:69: DBG File Configs: [/var/log/heartbeat.log]  
2017/01/05 11:51:08.180686 crawler.go:46: INFO Loading Prospectors completed. Number of prospectors: 1  
2017/01/05 11:51:08.180703 crawler.go:61: INFO All prospectors are initialised and running with 1 states to persist  
2017/01/05 11:51:08.181013 logp.go:219: INFO Metrics logging every 30s  
2017/01/05 11:51:08.181091 registrar.go:230: INFO Starting Registrar  
2017/01/05 11:51:08.181125 sync.go:41: INFO Start sending events to output  
2017/01/05 11:51:08.181171 spooler.go:63: INFO Starting spooler: spool\_size: 2048; idle\_timeout: 5s  
2017/01/05 11:51:08.181199 crawler.go:56: DBG Starting prospector 0  
2017/01/05 11:51:08.181225 prospector.go:111: INFO Starting prospector of type: log  
2017/01/05 11:51:08.181237 prospector\_log.go:62: DBG Start next scan  
2017/01/05 11:51:08.181286 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/05 11:51:08.181329 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 85724  
2017/01/05 11:51:08.181342 prospector\_log.go:297: DBG Harvester for file is still running: /var/log/heartbeat.log  
2017/01/05 11:51:08.181359 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
2017/01/05 11:51:13.187254 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 1  
2017/01/05 11:51:13.187328 client.go:128: DBG No events to publish  
2017/01/05 11:51:13.187346 sync.go:68: DBG Events sent: 1  
2017/01/05 11:51:13.187364 registrar.go:269: DBG Processing 1 events  
2017/01/05 11:51:13.187382 registrar.go:255: DBG Registrar states cleaned up. Before: 1, After: 1  
2017/01/05 11:51:13.187395 registrar.go:292: DBG Write registry file: /sc/filebeat/data/registry  
2017/01/05 11:51:13.187604 registrar.go:317: DBG Registry file updated. 1 states written.  
2017/01/05 11:51:18.190895 prospector.go:155: DBG Run prospector  
2017/01/05 11:51:18.190922 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 0  
2017/01/05 11:52:08.263193 prospector\_log.go:62: DBG Start next scan  
2017/01/05 11:52:08.263263 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/05 11:52:08.263286 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 85724  
2017/01/05 11:52:08.263298 prospector\_log.go:297: DBG Harvester for file is still running: /var/log/heartbeat.log  
2017/01/05 11:52:08.263315 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
2017/01/05 11:52:08.323124 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 0  
2017/01/05 11:52:12.071676 service.go:32: DBG Received sigterm/sigint, stopping  
2017/01/05 11:52:12.071760 filebeat.go:168: INFO Stopping filebeat  
2017/01/05 11:52:12.071783 crawler.go:67: INFO Stopping Crawler  
2017/01/05 11:52:12.071799 crawler.go:73: INFO Stopping 1 prospectors  
2017/01/05 11:52:12.071821 prospector.go:181: INFO Stopping Prospector  
2017/01/05 11:52:12.071856 prospector.go:128: INFO Prospector channel stopped  
2017/01/05 11:52:12.071886 prospector.go:152: INFO Prospector ticker stopped  
2017/01/05 11:52:12.071900 crawler.go:54: DBG Prospector 0 stopped  
2017/01/05 11:52:12.071913 crawler.go:80: INFO Crawler stopped  
2017/01/05 11:52:12.071925 spooler.go:101: INFO Stopping spooler  
2017/01/05 11:52:12.071942 spooler.go:109: DBG Spooler has stopped  
2017/01/05 11:52:12.071959 sync.go:47: DBG Shutting down sync publisher  
2017/01/05 11:52:12.071972 registrar.go:285: INFO Stopping Registrar  
2017/01/05 11:52:12.071985 registrar.go:242: INFO Ending Registrar  
2017/01/05 11:52:12.072000 registrar.go:292: DBG Write registry file: /sc/filebeat/data/registry  
2017/01/05 11:52:12.072220 registrar.go:317: DBG Registry file updated. 1 states written.  
2017/01/05 11:52:12.072326 logp.go:245: INFO Total non-zero values: publish.events=1 registar.states.current=1 registrar.writes=3 registrar.states.update=1  
2017/01/05 11:52:12.072347 logp.go:246: INFO Uptime: 1m3.896865454s  
2017/01/05 11:52:12.072358 beat.go:211: INFO filebeat stopped.

---

<div class="post-metadata">

**Author:** ![Sai\_Birada](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/sai_birada/32/142367_2.png) [@Sai\_Birada](https://discuss.elastic.co/u/Sai_Birada)\
**Post date:** [January 5, 2017, 12:13pm UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/7 "2017-01-05T12:13:13Z")

</div>

5.1.2 after restart logs sample  
2017/01/05 11:52:23.305607 beat.go:267: INFO Home path: [/sc/filebeat] Config path: [/sc/filebeat] Data path: [/sc/filebeat/data] Logs path: [/sc/filebeat/logs]  
2017/01/05 11:52:23.305642 beat.go:177: INFO Setup Beat: filebeat; Version: 5.1.2  
2017/01/05 11:52:23.305662 processor.go:43: DBG Processors:  
2017/01/05 11:52:23.305673 beat.go:183: DBG Initializing output plugins  
2017/01/05 11:52:23.305737 logstash.go:90: INFO Max Retries set to: 3  
2017/01/05 11:52:23.305802 outputs.go:106: INFO Activated logstash as output plugin.  
2017/01/05 11:52:23.305816 publish.go:234: DBG Create output worker  
2017/01/05 11:52:23.305884 publish.go:276: DBG No output is defined to store the topology. The server fields might not be filled.  
2017/01/05 11:52:23.305909 publish.go:291: INFO Publisher name: NSS  
2017/01/05 11:52:23.305978 async.go:63: INFO Flush Interval set to: 1s  
2017/01/05 11:52:23.305990 async.go:64: INFO Max Bulk Size set to: 2048  
2017/01/05 11:52:23.306000 async.go:72: DBG create bulk processing worker (interval=1s, bulk size=2048)  
2017/01/05 11:52:23.306119 beat.go:207: INFO filebeat start running.  
2017/01/05 11:52:23.306158 registrar.go:85: INFO Registry file set to: /sc/filebeat/data/registry  
2017/01/05 11:52:23.306192 registrar.go:106: INFO Loading registrar data from /sc/filebeat/data/registry  
2017/01/05 11:52:23.306319 registrar.go:131: INFO States Loaded from registrar: 1  
2017/01/05 11:52:23.306347 crawler.go:34: INFO Loading Prospectors: 1  
2017/01/05 11:52:23.306391 prospector\_log.go:41: DBG exclude\_files: []  
2017/01/05 11:52:23.306411 state.go:64: DBG New state added for /var/log/heartbeat.log  
2017/01/05 11:52:23.306421 prospector\_log.go:57: INFO Prospector with previous states loaded: 1  
2017/01/05 11:52:23.306488 prospector.go:69: DBG File Configs: [/var/log/heartbeat.log]  
2017/01/05 11:52:23.306501 crawler.go:46: INFO Loading Prospectors completed. Number of prospectors: 1  
2017/01/05 11:52:23.306512 crawler.go:61: INFO All prospectors are initialised and running with 1 states to persist  
2017/01/05 11:52:23.306756 logp.go:219: INFO Metrics logging every 30s  
2017/01/05 11:52:23.306826 registrar.go:230: INFO Starting Registrar  
2017/01/05 11:52:23.306852 sync.go:41: INFO Start sending events to output  
2017/01/05 11:52:23.306884 spooler.go:63: INFO Starting spooler: spool\_size: 2048; idle\_timeout: 5s  
2017/01/05 11:52:23.306904 crawler.go:56: DBG Starting prospector 0  
2017/01/05 11:52:23.306922 prospector.go:111: INFO Starting prospector of type: log  
2017/01/05 11:52:23.306930 prospector\_log.go:62: DBG Start next scan  
2017/01/05 11:52:23.306962 prospector\_log.go:212: DBG Check file for harvesting: /var/log/heartbeat.log  
2017/01/05 11:52:23.306990 prospector\_log.go:245: DBG Update existing file for harvesting: /var/log/heartbeat.log, offset: 85724  
2017/01/05 11:52:23.306999 prospector\_log.go:254: DBG Resuming harvesting of file: /var/log/heartbeat.log, offset: 85724  
2017/01/05 11:52:23.307091 log.go:251: DBG Set previous offset for file: /var/log/heartbeat.log. Offset: 85724  
2017/01/05 11:52:23.307106 log.go:241: DBG Setting offset for file: /var/log/heartbeat.log. Offset: 85724  
2017/01/05 11:52:23.307132 prospector\_log.go:83: DBG Prospector states cleaned up. Before: 1, After: 1  
2017/01/05 11:52:23.307168 log.go:84: INFO Harvester started for file: /var/log/heartbeat.log  
2017/01/05 11:52:23.307265 log\_file.go:84: DBG End of file reached: /var/log/heartbeat.log; Backoff now.  
2017/01/05 11:52:28.318070 spooler.go:89: DBG Flushing spooler because of timeout. Events flushed: 4  
2017/01/05 11:52:28.318392 client.go:184: DBG Publish: {

* * *

## } 2017/01/05 11:52:28.318532 output.go:109: DBG output worker: publish 2 events 2017/01/05 11:52:28.318546 sync.go:53: DBG connect 2017/01/05 11:52:28.319078 sync.go:107: DBG Try to publish 2 events to logstash with window size 10 2017/01/05 11:52:28.337983 sync.go:78: DBG 2 events out of 2 events sent to logstash. Continue sending 2017/01/05 11:52:28.338008 single.go:150: DBG send completed 2017/01/05 11:52:28.338045 sync.go:68: DBG Events sent: 4 2017/01/05 11:52:28.338149 registrar.go:269: DBG Processing 4 events 2017/01/05 11:52:28.338178 registrar.go:255: DBG Registrar states cleaned up. Before: 1, After: 1 2017/01/05 11:52:28.338191 registrar.go:292: DBG Write registry file: /sc/filebeat/data/registry 2017/01/05 11:52:28.338470 registrar.go:317: DBG Registry file updated. 1 states written. 2017/01/05 11:52:30.337559 log\_file.go:84: DBG End of file reached: /var/log/heartbeat.log; Backoff now. 2017/01/05 11:52:38.038649 service.go:32: DBG Received sigterm/sigint, stopping 2017/01/05 11:52:38.038707 filebeat.go:168: INFO Stopping filebeat

- 

2017/01/05 11:52:38.039363 logp.go:246: INFO Uptime: 14.736634753s  
2017/01/05 11:52:38.039384 beat.go:211: INFO filebeat stopped.

---

<div class="post-metadata">

**Author:** ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)\
**Post date:** [January 5, 2017, 1:08pm UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/8 "2017-01-05T13:08:05Z")

</div>

Thanks, will have a look at it later. For log files best paste them into a gist and link the gist here.

---

<div class="post-metadata">

**Author:** ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)\
**Post date:** [January 10, 2017, 7:55am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/9 "2017-01-10T07:55:29Z")

</div>

Ok, I managed to reliably reproduce this. Now I need to find the bug. I will keep you posted. Thanks for sharing all the details.

---

<div class="post-metadata">

**Author:** ![ruflin](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/ruflin/32/3116_2.png) [@ruflin](https://discuss.elastic.co/u/ruflin)\
**Post date:** [January 10, 2017, 8:40am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/10 "2017-01-10T08:40:05Z")

</div>

And here is a fix for it: [https://github.com/elastic/beats/pull/3322](https://github.com/elastic/beats/pull/3322)

---

<div class="post-metadata">

**Author:** ![system](https://us1.discourse-cdn.com/elastic/original/3X/1/a/1ac57faf039f6b580b3f104ef42a2a89e41014de.png) [@system](https://discuss.elastic.co/u/system)\
**Post date:** [February 7, 2017, 8:40am UTC](https://discuss.elastic.co/t/filebeat-upgrade-requiring-multiple-restarts/70414/11 "2017-02-07T08:40:09Z")

</div>

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