Logstash log unable to complete log read and throws error

Elastic Stack Logstash
1

I have setup logstash to read log files generated by another application realtime. The input config is like this. it is throwing the below error in logstash log. I am unable to track if it has been able to read the finished log file and move correctly to new one or there is some lines that logstash is unable to read while the log got rotated?

indent preformatted text by 4 spaces

input {
file {
path => "xxxxx/lsb.strea*"
exclude => [ ".lock", ".tmp" ]
file_completed_action => "log"
file_completed_log_path => "/tmp/streamfile_completed_log"
start_position => "beginning"
# sincedb_path => "/dev/null"
}
}
filter {
indent preformatted text by 4 spaces

[2020-11-27T09:26:37,766][WARN ][filewatch.tailmode.processor] >>> Rotation In Progress - inode change detected and original
content is not fully read, file is closed and path points to new content {"watched_file details"=>"<FileWatch::WatchedFile: @
filename='lsb.stream.1606449395', @state='rotation_in_progress', @recent_states='[:watched, :watched]', @bytes_read='0', @byt
es_unread='0', current_size='2097159274', last_stat_size='2097159274', file_open?='false', @initial=false, @sincedb_key='1420
201497 0 38'>"}

The above error is about below file in Italics at the time 09:26 Nov-27 which is equivalent to 1606449335. The application always writes to lsb.stream and rotate it with unix-time suffix as soon as it reaches 2GB size as given below. It keeps only 3 files max and purges the last one.

ls -l
-rw-r--r-- 1 admin admin 808909092 Nov 28 15:50 lsb.stream
-rw-r--r-- 1 admin admin 2097188023 Nov 24 00:21 lsb.stream.1606157486
-rw-r--r-- 1 admin admin 2097159274 Nov 27 09:26 lsb.stream.1606449395

2

The code is here. The all_read? flag was false, so it knew it had data to read from the file, but the file_open? flag was also false, so it did not have a handle open to the now rotated file.

bytes_read is zero, but bytes_unread is also zero. Perhaps filewatch does not realize that lsb.stream.1606449395 is a file it has already read when it was called lsb.stream. Did you restart logstash? Did lsb.stream.1606449395 exist when logstash started?

3

Thanks Badger for your answer!

No, logstash was not re-started and even lsb.stream.1606449395 still exist in the path.
I think the sequence of events of log rotation was as follows

  1. logstash was reading lsb.stream file( which now after rotation has been renamed as lsb.stream.1606449395).
  2. The application renamed the file lsb.stream to lsb.stream.1606449395 as it reaches 2GB in size.
  3. new lsb.stream file got created by application and pushing new incoming data to new lsb.stream file.

From the error in the log file, It seems logstash is unable to recognize that file has been rotated? or else?

The problem for me is that it is happening repeatedly and i am not sure if logstash here is missing some records or generated duplicate records by re-reading same file again?
it is not easy for me to analyze as the data volume is too high.

please help how to investigate?

4

Not sure what to say. It might be a bug in the detection of file rotation, but I cannot think what the bug would be.

5

Anyone else who can suggest.
Can someone suggest the way logstash is able to handle file rotation? I would copy the files to another directory and do the log file rotation the way logstash can handle without giving error?

6

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