Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

in_tail: prevent wrongly unwatching with follow_inodes #4221

Closed
wants to merge 1 commit into from
Closed

in_tail: prevent wrongly unwatching with follow_inodes #4221

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
10 changes: 7 additions & 3 deletions lib/fluent/plugin/in_tail.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -502,9 +502,13 @@ def update_watcher(tail_watcher, pe, new_inode)
new_target_info = TargetInfo.new(path, new_inode)

if @follow_inodes
# When follow_inodes is true, it's not cleaned up by refresh_watcher.
# So it should be unwatched here explicitly.
tail_watcher.unwatched = true
# If the old inode still exists, we can't unwatch it.
# If the old inode disappears, we should unwatch it here because
# `refresh_watcher` can't detect that the inode disappears.
# (It is because the path of `@tails` will be overwritten here.)
# (It is not a big problem if we don't unwatch here, as long as we make
# sure to detach it. The position will be cleared on restart eventually.)
tail_watcher.unwatched = true unless expand_paths.key?(tail_watcher.ino)
Copy link
Member

@ashie ashie Jun 29, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm worry calling expand_paths here, because it's relatively high cost.
It might be too high cost on heavy rotated environment.
In addition, the file might be disappear soon just after calling expand_paths, as described in

fluentd/lib/fluent/plugin/in_tail.rb

Lines 337 to 348 in 691b2e0

# Even we just checked for existence, there is a race condition here as
# of which stat() might fail with ENOENT. See #3224.
begin
target_info = TargetInfo.new(path, Fluent::FileWrapper.stat(path).ino)
if @follow_inodes
hash[target_info.ino] = target_info
else
hash[target_info.path] = target_info
end
rescue Errno::ENOENT, Errno::EACCES => e
$log.warn "expand_paths: stat() for #{path} failed with #{e.class.name}. Skip file."
end

(Although it might not so big problem as you described in the comment).

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for your review!

I'm worry calling expand_paths here, because it's relatively high cost.
It might be too high cost on heavy rotated environment.

I see.
I thought it would be okay since it was only called on rotation, but certainly, this is worrisome considering the case of so many files being rotated so often...

It may be better to cache the list in refresh_watcher and use it here...
However, I'm unsure if I should go this far for unwatching here.

(Although it might not so big problem as you described in the comment).

What we should be concerned about is that, without unwatching here, the memory and file for PositionFile would be larger.
(It will be cleared only when restarting. We can't use pos_file_compaction_interval to clear this because it doesn't check the target existence.)

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Possible fix:

  • A: Don't unwatch here.
  • B: Fix refresh_watcher to refresh PositionFile as well.
  • C: Cache the list in refresh_watcher and use it in update_watcher
  • D: Change the key of @tails to inode when enabling follow_inodes

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more. 

* A: Don't unwatch here.

We want to avoid this if possible since the memory and file for PositionFile would be larger.

* B: Fix `refresh_watcher` to refresh PositionFile as well.

It could be possible.

* C: Cache the list in `refresh_watcher` and use it in `update_watcher`

This is not good. It depends on the interval of refresh_watcher.

* D: Change the key of `@tails` to inode when enabling `follow_inodes`

It could be possible.
We should consider the following PR for this.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I close this PR since it should be fixed by B or D.
Are you OK for closing it?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes! I close this! Thanks!


new_position_entry = @pf[new_target_info]
# If `refresh_watcher` find the new file before, this will not be zero.
Expand Down
31 changes: 8 additions & 23 deletions test/plugin/test_in_tail.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -2704,22 +2704,14 @@ def test_updateTW_before_refreshTW_and_detach_before_refreshTW

assert_equal(
{
# TODO: This is BUG!! We need to fix it and replace this with the next.
record_values: ["file1 log1", "file1 log1", "file1 log2", "file1 log2", "file2 log1", "file2 log2"],
# record_values: ["file1 log1", "file1 log2", "file2 log1", "file2 log2"],
record_values: ["file1 log1", "file1 log2", "file2 log1", "file2 log2"],
tail_watcher_paths: ["#{@tmp_dir}/tail.txt", "#{@tmp_dir}/tail.txt", "#{@tmp_dir}/tail.txt1"],
tail_watcher_inodes: [inode_0, inode_1, inode_0],
tail_watcher_io_handler_opened_statuses: [false, false, false],
# TODO: This is BUG!! We need to fix it and replace this with the next.
position_entries: [
["#{@tmp_dir}/tail.txt", "ffffffffffffffff", inode_0],
["#{@tmp_dir}/tail.txt", "0000000000000016", inode_0],
["#{@tmp_dir}/tail.txt", "0000000000000016", inode_1],
["#{@tmp_dir}/tail.txt1", "0000000000000016", inode_0],
],
# position_entries: [
# ["#{@tmp_dir}/tail.txt", "ffffffffffffffff", inode_0],
# ["#{@tmp_dir}/tail.txt", "0000000000000016", inode_1],
# ],
},
{
record_values: record_values,
Expand Down Expand Up @@ -2802,7 +2794,7 @@ def test_updateTW_before_refreshTW_and_detach_after_refreshTW
tail_watcher_inodes: [inode_0, inode_1, inode_0],
tail_watcher_io_handler_opened_statuses: [false, false, false],
position_entries: [
["#{@tmp_dir}/tail.txt", "ffffffffffffffff", inode_0],
["#{@tmp_dir}/tail.txt", "0000000000000016", inode_0],
["#{@tmp_dir}/tail.txt", "0000000000000016", inode_1],
],
},
Expand Down Expand Up @@ -2861,9 +2853,10 @@ def test_updateTW_after_refreshTW
# This overwrites `@tails["tail.txt"]`
d.instance.refresh_watchers

# `watch_timer` calls `TailWatcher::on_notify`, and then `update_watcher` updates the TailWatcher:
# `watch_timer` calls `TailWatcher::on_notify`, and then `update_watcher` trys to update the TailWatcher:
# TailWatcher(path: "tail.txt", inode: inode_0) => TailWatcher(path: "tail.txt", inode: inode_1)
# The old TailWathcer is detached here since `rotate_wait` is just `1s`.
# However, it is already added in `refresh_watcher`, so `update_watcher` doesn't create the new TailWatcher.
# `update_watcher` only detachs the old TailWathcer here since `rotate_wait` is just `1s`
sleep 3

# This adds a new TailWatcher: TailWatcher(path: "tail.txt1", inode: inode_0)
Expand All @@ -2886,22 +2879,14 @@ def test_updateTW_after_refreshTW

assert_equal(
{
# TODO: This is BUG!! We need to fix it and replace this with the next.
record_values: ["file1 log1", "file1 log1", "file1 log2", "file1 log2", "file2 log1", "file2 log2"],
# record_values: ["file1 log1", "file1 log2", "file2 log1", "file2 log2"],
record_values: ["file1 log1", "file1 log2", "file2 log1", "file2 log2"],
tail_watcher_paths: ["#{@tmp_dir}/tail.txt", "#{@tmp_dir}/tail.txt", "#{@tmp_dir}/tail.txt1"],
tail_watcher_inodes: [inode_0, inode_1, inode_0],
tail_watcher_io_handler_opened_statuses: [false, false, false],
# TODO: This is BUG!! We need to fix it and replace this with the next.
position_entries: [
["#{@tmp_dir}/tail.txt", "ffffffffffffffff", inode_0],
["#{@tmp_dir}/tail.txt", "0000000000000016", inode_0],
["#{@tmp_dir}/tail.txt", "0000000000000016", inode_1],
["#{@tmp_dir}/tail.txt1", "0000000000000016", inode_0],
],
# position_entries: [
# ["#{@tmp_dir}/tail.txt", "ffffffffffffffff", inode_0],
# ["#{@tmp_dir}/tail.txt", "0000000000000016", inode_1],
# ],
},
{
record_values: record_values,
Expand Down