When logstash shutdown, renam file and data can be lost or duplicated

Elastic Stack Logstash
3

I would have expected the file input to handle that. Basically, if you rename a file while logstash is down it thinks it is a new file even though it has a matching sincedb entry.

With this configuration

file { path => "/tmp/test/*" sincedb_path => "/tmp/since.db" start_position => beginning }
filter {}
output { stdout { codec => rubydebug { metadata => false } } }

then

mkdir /tmp/test
echo foo >> /tmp/test/test.log
# Run logstash and it ingests foo, kill logstash

sincedb contains

8420933 0 51713 4 1564492539.4538882 /tmp/test/test.log

Then

mv /tmp/test/test.log /tmp/test/test.log.1

Running logstash again we get

[2019-07-30T13:18:08,423][TRACE][filewatch.sincedbcollection] open: reading from /tmp/since.db
[2019-07-30T13:18:08,453][DEBUG][logstash.agent           ] Trying to start WebServer {:port=>9600}
[2019-07-30T13:18:08,544][TRACE][filewatch.sincedbcollection] open: importing ... '8420933 0 51713' => '4 1564492539.4538882 /tmp/test/test.log'
[2019-07-30T13:18:08,571][TRACE][filewatch.sincedbcollection] open: setting #<struct FileWatch::InodeStruct inode="8420933", maj=0, min=51713> to #<FileWatch::SincedbValue:0x3050973 @last_changed_at=1564492539.4538882, @path_in_sincedb="/tmp/test/test.log", @watched_file=nil, @position=4>
[2019-07-30T13:18:08,575][TRACE][filewatch.sincedbcollection] open: count of keys read: 1
[2019-07-30T13:18:08,695][DEBUG][logstash.api.service     ] [api-service] start
[2019-07-30T13:18:08,756][TRACE][filewatch.discoverer     ] discover_files {"count"=>1}
[2019-07-30T13:18:08,984][TRACE][filewatch.discoverer     ] discover_files handling: {"new discovery"=>true, "watched_file details"=>"<FileWatch::WatchedFile: @filename='test.log.1', @state='watched', @recent_states='[:watched]', @bytes_read='0', @bytes_unread='0', current_size='4', last_stat_size='4', file_open?='false', @initial=true, @sincedb_key='8420933 0 51713'>"}
[2019-07-30T13:18:09,005][TRACE][filewatch.sincedbcollection] associate: finding {"inode"=>"8420933", "path"=>"/tmp/test/test.log.1"}
[2019-07-30T13:18:09,024][TRACE][filewatch.sincedbcollection] associate: found sincedb record {"filename"=>"test.log.1", "sincedb key"=>#<struct FileWatch::InodeStruct inode="8420933", maj=0, min=51713>, "sincedb_value"=>#<FileWatch::SincedbValue:0x3050973 @last_changed_at=1564492539.4538882, @path_in_sincedb="/tmp/test/test.log", @watched_file=nil, @position=4>}
[2019-07-30T13:18:09,058][TRACE][filewatch.sincedbcollection] associate: matched but allocated to another
[2019-07-30T13:18:09,252][TRACE][filewatch.tailmode.processor] Delayed Delete processing
[2019-07-30T13:18:09,267][TRACE][filewatch.tailmode.processor] Watched + Active restat processing
[2019-07-30T13:18:09,297][INFO ][logstash.agent           ] Successfully started Logstash API endpoint {:port=>9600}
[2019-07-30T13:18:09,358][TRACE][filewatch.tailmode.processor] Rotation In Progress processing
[2019-07-30T13:18:09,373][TRACE][filewatch.tailmode.processor] Watched processing
[2019-07-30T13:18:09,414][TRACE][filewatch.tailmode.handlers.createinitial] handling: test.log.1
[2019-07-30T13:18:09,447][TRACE][filewatch.tailmode.handlers.createinitial] opening test.log.1
[2019-07-30T13:18:07,424][DEBUG][org.logstash.config.ir.CompiledPipeline] [...]
[2019-07-30T13:18:09,564][TRACE][filewatch.tailmode.handlers.createinitial] handle_specifically opened file handle: 89, path: test.log.1
[2019-07-30T13:18:09,660][TRACE][filewatch.tailmode.handlers.createinitial] add_new_value_sincedb_collection {"position"=>0, "watched_file details"=>"<FileWatch::WatchedFile: @filename='test.log.1', @state='active', @recent_states='[:watched, :watched]', @bytes_read='0', @bytes_unread='4', current_size='4', last_stat_size='4', file_open?='true', @initial=true, @sincedb_key='8420933 0 51713'>"}
[2019-07-30T13:18:09,712][TRACE][filewatch.tailmode.processor] Active - file grew: test.log.1: new size is 4, bytes read 0
[2019-07-30T13:18:09,715][TRACE][filewatch.tailmode.handlers.grow] handling: test.log.1
[2019-07-30T13:18:09,764][TRACE][filewatch.tailmode.handlers.grow] reading... {"iterations"=>1, "amount"=>4, "filename"=>"test.log.1"}
[2019-07-30T13:18:09,779][DEBUG][filewatch.tailmode.handlers.grow] read_to_eof: get chunk
[2019-07-30T13:18:09,838][DEBUG][logstash.inputs.file     ] Received line {:path=>"/tmp/test/test.log.1", :text=>"foo"}
[2019-07-30T13:18:10,092][DEBUG][filewatch.sincedbcollection] writing sincedb (delta since last write = 1564492690)
[2019-07-30T13:18:10,096][TRACE][filewatch.sincedbcollection] sincedb_write: to: /tmp/since.db
{
       "message" => "foo",
    "@timestamp" => 2019-07-30T13:18:09.996Z,
      "@version" => "1",
          "path" => "/tmp/test/test.log.1"
}

@guyboertje would you expect it detect the file had been rotated while logstash was down?