# Unexpected file opening error: File info is not identical with opened file **URL:** \ **Category:** Beats\ **Tags:** filebeat\ **Created:** [April 28, 2017, 3:06pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026 "2017-04-28T15:06:49Z")\ **Posts on this page:** 20\ **Page:** 1
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [April 28, 2017, 3:06pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/1 "2017-04-28T15:06:49Z")
I'm trying to collect smtp logs of a windows system environment using filbeat, but I don't get any data because the logfile change very quickly This is the error in filbeat log: 2017-04-28T11:47:02-03:00 ERR Harvester could not be started on existing file: C:\Windows\System32\LogFiles\SMTPSVC1\in170428.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. What option could I use to fix this behavior? Here is my environment: - Filebeat 5.3 for windows - Windows 2012 with SMTP service Enable - Logfile size \>= 50MB Filebeat YML config file: ``` filebeat_content_yml: | filebeat: prospectors: - input_type: log paths: - C:\Windows\System32\LogFiles\SMTPSVC1\in* document_type: smtp-relay-log ignore_older: 24h fields_under_root: true fields: env: prd tags: ["smtp-relay"] output: logstash: hosts: ["{{ logstash_server }}:5044"] timeout: 15 logging: level: info ``` Thanks ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [April 28, 2017, 7:21pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/2 "2017-04-28T19:21:16Z")
What kind of logging schedule in windows you have configured. I assume it's `daily`. Is the timestamp modified after the log was changed? Filebeat use `os.SameFile` to compare if two files are the same. On windows it uses `GetFileInformationByHandle` and compare the volume serial number and the high-order and the low-order part of a unique identifier that is associated with a file. See [here](https://msdn.microsoft.com/de-de/library/windows/desktop/aa363788(v=vs.85).aspx) for more information about this. What kind of filesystem you use? ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [April 28, 2017, 7:52pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/3 "2017-04-28T19:52:45Z")
The logging schedule is daily (default), and the filesystem is NTFS (Default too). I will see your link. Thanks ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 2, 2017, 10:37am UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/4 "2017-05-02T10:37:34Z")
Can you post the complete filebeat.log. ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 2, 2017, 1:21pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/5 "2017-05-02T13:21:58Z")
Sure! Here is an example [Logfile Filebeat 5.3.0 - Windows](https://raw.githubusercontent.com/jenciso/logs/master/filebeat.1) ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 2, 2017, 1:57pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/6 "2017-05-02T13:57:54Z")
Same error happened with filebeat 5.3.2, recently installed. ``` 2017-05-02T10:54:21-03:00 INFO Home path: [C:\Program Files\Filebeat] Config path: [C:\Program Files\Filebeat] Data path: [C:\\ProgramData\\filebeat] Logs path: [C:\Program Files\Filebeat\logs] 2017-05-02T10:54:21-03:00 INFO Setup Beat: filebeat; Version: 5.3.2 2017-05-02T10:54:21-03:00 INFO Max Retries set to: 3 2017-05-02T10:54:21-03:00 INFO Activated logstash as output plugin. 2017-05-02T10:54:21-03:00 INFO Publisher name: eridanus 2017-05-02T10:54:21-03:00 INFO Flush Interval set to: 1s 2017-05-02T10:54:21-03:00 INFO Max Bulk Size set to: 2048 2017-05-02T10:54:21-03:00 INFO filebeat start running. 2017-05-02T10:54:21-03:00 INFO Registry file set to: C:\ProgramData\filebeat\registry 2017-05-02T10:54:21-03:00 INFO Loading registrar data from C:\ProgramData\filebeat\registry 2017-05-02T10:54:21-03:00 INFO States Loaded from registrar: 5 2017-05-02T10:54:21-03:00 INFO Loading Prospectors: 1 2017-05-02T10:54:21-03:00 INFO Prospector with previous states loaded: 5 2017-05-02T10:54:21-03:00 INFO Starting prospector of type: log; id: 17305170178307357983 2017-05-02T10:54:21-03:00 INFO Loading and starting Prospectors completed. Enabled prospectors: 1 2017-05-02T10:54:21-03:00 INFO Starting Registrar 2017-05-02T10:54:21-03:00 INFO Start sending events to output 2017-05-02T10:54:21-03:00 INFO Starting spooler: spool_size: 2048; idle_timeout: 5s 2017-05-02T10:54:21-03:00 ERR Harvester could not be started on existing file: C:\Windows\System32\LogFiles\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2017-05-02T10:54:31-03:00 ERR Harvester could not be started on existing file: C:\Windows\System32\LogFiles\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. ``` ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 2, 2017, 2:11pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/7 "2017-05-02T14:11:22Z")
Is it possible that you can move the smtp logfile to another folder, maybe c:\temp. Or better to another drive and then try again. ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 2, 2017, 6:00pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/8 "2017-05-02T18:00:20Z")
Sure. I moved the smtp logfile to E:\ drive, but It didn't work. Here are the logs. Also changed the directory permissions, but it don't resolve. ``` 2017-05-02T14:53:21-03:00 INFO Metrics logging every 30s 2017-05-02T14:53:21-03:00 INFO Setup Beat: filebeat; Version: 5.3.2 2017-05-02T14:53:21-03:00 INFO Max Retries set to: 3 2017-05-02T14:53:21-03:00 INFO Activated logstash as output plugin. 2017-05-02T14:53:21-03:00 INFO Publisher name: eridanus 2017-05-02T14:53:21-03:00 INFO Flush Interval set to: 1s 2017-05-02T14:53:21-03:00 INFO Max Bulk Size set to: 2048 2017-05-02T14:53:21-03:00 INFO filebeat start running. 2017-05-02T14:53:21-03:00 INFO Registry file set to: C:\ProgramData\filebeat\registry 2017-05-02T14:53:21-03:00 INFO Loading registrar data from C:\ProgramData\filebeat\registry 2017-05-02T14:53:21-03:00 INFO States Loaded from registrar: 6 2017-05-02T14:53:21-03:00 INFO Loading Prospectors: 1 2017-05-02T14:53:21-03:00 INFO Prospector with previous states loaded: 0 2017-05-02T14:53:21-03:00 INFO Starting prospector of type: log; id: 11639715767759128819 2017-05-02T14:53:21-03:00 ERR Harvester could not be started on new file: E:\SMTPLogs\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2017-05-02T14:53:21-03:00 INFO Starting Registrar 2017-05-02T14:53:21-03:00 INFO Start sending events to output 2017-05-02T14:53:21-03:00 INFO Starting spooler: spool_size: 2048; idle_timeout: 5s 2017-05-02T14:53:21-03:00 INFO Loading and starting Prospectors completed. Enabled prospectors: 1 2017-05-02T14:53:31-03:00 ERR Harvester could not be started on existing file: E:\SMTPLogs\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2017-05-02T14:53:41-03:00 ERR Harvester could not be started on existing file: E:\SMTPLogs\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2017-05-02T14:53:51-03:00 INFO Non-zero metrics in the last 30s: publish.events=6 registrar.states.current=6 registrar.states.update=6 registrar.writes=3 2017-05-02T14:53:51-03:00 ERR Harvester could not be started on existing file: E:\SMTPLogs\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. ``` ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 2, 2017, 6:15pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/9 "2017-05-02T18:15:06Z")
Can you stop the SMTP server and then try to start filebeat. ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 2, 2017, 6:30pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/10 "2017-05-02T18:30:23Z")
Yes, but in this time, I can't. We have many applications using this smtp-relay. At non-business hours I could stop it for a fews minutes. ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 2, 2017, 6:58pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/11 "2017-05-02T18:58:57Z")
Ok. I think it has to do that the SMTP server has open a handle to the file while filebeat also trying to access it. @andrewkroh, do you have any idea? ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 2, 2017, 8:06pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/12 "2017-05-02T20:06:26Z")
I think that you're right, but If it's the problema, How filebeat could deal the matter? Exist another alternative for services that has blocking files? ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 3, 2017, 2:56am UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/13 "2017-05-03T02:56:59Z")
Hi maddin2016, Recently, I stopped my smtp server. In this condition, the filebeat haven't problem in read the file, and logstash work without any problems. But when I started the smtp server, the problem appear again. Could be it a filebeat bug, and it can't read windows logfile management by windows services like smtp? ``` 2017-05-02T23:50:48-03:00 INFO Home path: [C:\Program Files\Filebeat] Config path: [C:\Program Files\Filebeat] Data path: [C:\\ProgramData\\filebeat] Logs path: [C:\Program Files\Filebeat\logs] 2017-05-02T23:50:48-03:00 INFO Setup Beat: filebeat; Version: 5.3.2 2017-05-02T23:50:48-03:00 INFO Max Retries set to: 3 2017-05-02T23:50:48-03:00 INFO Activated logstash as output plugin. 2017-05-02T23:50:48-03:00 INFO Publisher name: eridanus 2017-05-02T23:50:48-03:00 INFO Flush Interval set to: 1s 2017-05-02T23:50:48-03:00 INFO Max Bulk Size set to: 2048 2017-05-02T23:50:48-03:00 INFO filebeat start running. 2017-05-02T23:50:48-03:00 INFO Registry file set to: C:\ProgramData\filebeat\registry 2017-05-02T23:50:48-03:00 INFO Loading registrar data from C:\ProgramData\filebeat\registry 2017-05-02T23:50:48-03:00 INFO States Loaded from registrar: 7 2017-05-02T23:50:48-03:00 INFO Loading Prospectors: 1 2017-05-02T23:50:48-03:00 INFO Prospector with previous states loaded: 6 2017-05-02T23:50:48-03:00 INFO Starting prospector of type: log; id: 17305170178307357983 2017-05-02T23:50:48-03:00 INFO Loading and starting Prospectors completed. Enabled prospectors: 1 2017-05-02T23:50:48-03:00 INFO Starting Registrar 2017-05-02T23:50:48-03:00 INFO Start sending events to output 2017-05-02T23:50:48-03:00 INFO Starting spooler: spool_size: 2048; idle_timeout: 5s 2017-05-02T23:50:48-03:00 INFO Harvester started for file: C:\Windows\System32\LogFiles\SMTPSVC1\in170502.log 2017-05-02T23:51:18-03:00 INFO Non-zero metrics in the last 30s: filebeat.harvester.open_files=1 filebeat.harvester.running=1 filebeat.harvester.started=1 libbeat.logstash.call_count.PublishEvents=37 libbeat.logstash.publish.read_bytes=336 libbeat.logstash.publish.write_bytes=3734167 libbeat.logstash.published_and_acked_events=73721 libbeat.publisher.published_events=75769 publish.events=73728 registrar.states.current=7 registrar.states.update=73728 registrar.writes=35 2017-05-02T23:51:38-03:00 ERR Harvester could not be started on existing file: C:\Windows\System32\LogFiles\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2017-05-02T23:51:48-03:00 INFO Non-zero metrics in the last 30s: libbeat.logstash.call_count.PublishEvents=3 libbeat.logstash.publish.read_bytes=36 libbeat.logstash.publish.write_bytes=146495 libbeat.logstash.published_and_acked_events=5085 libbeat.publisher.published_events=3037 publish.events=5087 registrar.states.update=5087 registrar.writes=6 2017-05-02T23:51:48-03:00 ERR Harvester could not be started on existing file: C:\Windows\System32\LogFiles\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2017-05-02T23:51:58-03:00 ERR Harvester could not be started on existing file: C:\Windows\System32\LogFiles\SMTPSVC1\in170502.log, Err: Error setting up harvester: Harvester setup failed. Unexpected file opening error: File info is not identical with opened file. Aborting harvesting and retrying file later again. 2 ``` ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 3, 2017, 6:29am UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/14 "2017-05-03T06:29:53Z")
One more thing. Can you post what is inside your `registry` file and maybe `registry.old`. Just to check if `idxhi, idxlo and vol` are the same. ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 3, 2017, 12:47pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/15 "2017-05-03T12:47:15Z")
Sure!. Here are the files: [https://raw.githubusercontent.com/jenciso/logs/master/registry](https://raw.githubusercontent.com/jenciso/logs/master/registry) [https://raw.githubusercontent.com/jenciso/logs/master/registry.old](https://raw.githubusercontent.com/jenciso/logs/master/registry.old) ---
**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:** [May 3, 2017, 2:46pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/16 "2017-05-03T14:46:19Z")
I haven't checked the whole thread but the error you see is something that should only happen in very rare cases. For it to happen lots of files have to be rotated at the same time with a potentially low scan\_frequency. Strangely in your case it happens quite often. The error shows when a file name changes between the time it was found during a scan and a harvester tries to open it. How many files are in the directory to be harvested by filebeat? ---
**Author:** ![jenciso](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/jenciso/32/28653_2.png) [@jenciso](https://discuss.elastic.co/u/jenciso)\ **Post date:** [May 3, 2017, 7:51pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/17 "2017-05-03T19:51:47Z")
I ruflin. I have six files ![](https://us1.discourse-cdn.com/elastic/original/3X/0/6/06eb6cd2cbf4d6b943aadd8f6643e1012718e3a5.png) I tried using one file only (without regexp) in filebeat yaml file ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 4, 2017, 7:44am UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/18 "2017-05-04T07:44:20Z")
Hi @ruflin. The filename doesn't change during the scan. I think the error comes from [here](https://github.com/elastic/beats/blob/master/filebeat/prospector/prospector_log.go#L298). And at this point it doesn't check if the name has changed. It validates the file [https://github.com/elastic/beats/blob/master/filebeat/harvester/log.go#L261](https://github.com/elastic/beats/blob/master/filebeat/harvester/log.go#L261). And the fact that it works if the smtp service is stopped shows that it has to do that the service maybe change the `fileid` or something else while it has access to it. ---
**Author:** ![maddin2016](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/maddin2016/32/16599_2.png) [@maddin2016](https://discuss.elastic.co/u/maddin2016)\ **Post date:** [May 4, 2017, 7:53am UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/19 "2017-05-04T07:53:35Z")
And if you look at the last modification date its always after it has closed the file. for example `in170502` (the log for `02/05/2017`) was closed on `03/05/2017 00:00`. So the smtp service had an open handle to the file all the day. ---
**Author:** ![andrewkroh](https://sea2.discourse-cdn.com/elastic/user_avatar/discuss.elastic.co/andrewkroh/32/3784_2.png) [@andrewkroh](https://discuss.elastic.co/u/andrewkroh)\ **Post date:** [May 4, 2017, 9:47pm UTC](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026/20 "2017-05-04T21:47:28Z")
@ruflin This maybe a complete red herring, but I wanted to add a data point. While running the Filebeat system tests on Windows I see the same error message in the output of most test cases. Although, I am running the test cases in our win2012 vagrant VM which means these tests execute on a network share. [Next page](https://discuss.elastic.co/t/unexpected-file-opening-error-file-info-is-not-identical-with-opened-file/84026.md?page=2)