v4.1 : regression - new files are not detected by plugin

[fbaligand]

If I use input file plugin (in its last version 4.1.3) with a path containing wildcard, new files matching the pattern are not detected, and so, not processed by Logstash.
If I do exactly the same test with version 4.0.5, it works perfectly : new files are detected and processed from the first line.
I reproduce the issue on Windows 7 and RHEL 6.

Here's my input configuration :

	file {
		path => "/path/to/test-file-*.log"
	}

[fbaligand]

Hi @guyboertje ,

Could you look at this issue ?

[guyboertje]

@fbaligand
Strange. Many of our tests use a similar pattern, but they use start_position => "beginning".
With debug logging you should see plenty of:

[2018-06-28T13:05:06,250][DEBUG][filewatch.discoverer     ] Discoverer found files, count: 1
[2018-06-28T13:05:06,252][DEBUG][filewatch.discoverer     ] Discoverer found file, path: /elastic/tmp/testing/logs/testing-a.txt
[2018-06-28T13:05:06,256][DEBUG][filewatch.discoverer     ] Discoverer discover_files: /elastic/tmp/testing/logs/testing-*.txt: new: /elastic/tmp/testing/logs/testing-a.txt (exclude is [])
[2018-06-28T13:05:06,287][DEBUG][filewatch.sincedbcollection] associate: finding: /elastic/tmp/testing/logs/testing-a.txt
[2018-06-28T13:05:06,296][DEBUG][filewatch.sincedbcollection] find for path: /elastic/tmp/testing/logs/testing-a.txt, found: 'false'

Then later when I added testing-b.txt

[2018-06-28T13:05:35,693][DEBUG][filewatch.discoverer     ] Discoverer found files, count: 2
[2018-06-28T13:05:35,694][DEBUG][filewatch.discoverer     ] Discoverer found file, path: /elastic/tmp/testing/logs/testing-b.txt
[2018-06-28T13:05:35,695][DEBUG][filewatch.discoverer     ] Discoverer discover_files: /elastic/tmp/testing/logs/testing-*.txt: new: /elastic/tmp/testing/logs/testing-b.txt (exclude is [])
[2018-06-28T13:05:35,702][DEBUG][filewatch.sincedbcollection] associate: finding: /elastic/tmp/testing/logs/testing-b.txt
[2018-06-28T13:05:35,703][DEBUG][filewatch.sincedbcollection] find for path: /elastic/tmp/testing/logs/testing-b.txt, found: 'false'

My config

input {
  file {
    path => "/elastic/tmp/testing/logs/testing-*.txt"
    start_position => "beginning"
    sincedb_path => "/dev/null"
  }
}

output {
  stdout {
    codec => rubydebug
  }
}

[fbaligand]

Hi @guyboertje,

Well, yes, with start_position => "beginning", it works, but not with start_position => "end" (default value). And this is a regression.
Until 4.0.x, existing files discovered at startup are read from the end of file. But new files created after startup are read from the beginning.

Another issue related to this one is file rotation.
When Log4j does file rotation (say app.log), it closes the app.log, renames it with date suffix, and creates a new file app.log.
And in this case also, version 4.1 does not process new app.log file, which is another regression.

Up to me, these are two major regressions, that prevent me to migrate to 4.1.

[guyboertje]

@fbaligand

When Log4j does file rotation

Yes, this is known - PR 192 will fix this. The final changes are done, I'm waiting on a PR for the multiline codec to make the rspec tests v dependable.

Until 4.0.x, existing files discovered at startup are read from the end of file. But new files created after startup are read from the beginning.

So you are saying that start_position only applies to the files that exist when LS starts that don't have a sincedb entry.
But from version 3.0.0 of file.rb the description of start_position is (and it has not changed since):

# Choose where Logstash starts initially reading files: at the beginning or
# at the end. The default behavior treats files like live streams and thus
# starts at the end. If you have old data you want to import, set this
# to 'beginning'.
#
# This option only modifies "first contact" situations where a file
# is new and not seen before, i.e. files that don't have a current
# position recorded in a sincedb file read by Logstash. If a file
# has already been seen before, this option has no effect and the
# position recorded in the sincedb file will be used.

I accept that this is a regression.

When I moved filewatch code in this plugin, much of that logic was redone and moved around and I applied the logic in the docs as is.
I don't recall whether there was a specifically described test to verify the previous behaviour but if there was I probably made it pass by adding start_postion = "beginning" to the test.
Clearly the docs need more detail to this behaviour open and public.

[fbaligand]

@guyboertje
Thanks to accept that it is a regression.
Up to me, there is some coherence : "start_position=beginning" was created to read historical data from beginning.
But once Logstash is started, each time a new file is created, this is new data, and as a user, I don't want to loose this new data.

Finally, I agree that documentation was not accurate concerning this point, and needs precisions.

[guyboertje]

I will have to make Discoverer have two phases - startup + ongoing.

[fbaligand]

Great !

[guyboertje]

I fixed this in the rotation improvements branch, now in review.

[fbaligand]

Great ! Thanks !