#189 Zero byte read from NFS - Fix method file_read in watched_file.rb #190
Conversation
…, method file_read
sv-gh
changed the title
There was a problem hiding this comment.
@sv-gh while this approach may work for your specific setup, it's not an approach that I believe scales to the wide user-base of this plugin. I appreciate the work you put in, and will work to get an acceptable solution put together shortly.
The primary reason is that the presence of a null-byte isn't necessarily a reliable indicator that the sysread has returned bytes beyond the end of the file:
- a null byte is valid in gzipped log files, which means that when reading gzipped logs in this implementation we will frequently need to fall through all attempts, reading, sleeping, and un-seeking repeatedly before finally emitting each chunk.
- When reading beyond the end of a file using
sysread, the behaviour is undefined; on your system it may be observed to emit one or more null bytes, but this is not specified nor guaranteed.
In order to reliably ensure that we don't read beyond the end of our source files, each time we sysread we will need to first stat the file to determine how much is available.
There is currently work in-flight to improve support for file rotation, which touches this and many other methods, and a follow-up is already planned by @guyboertje to address the root cause of #189 to ensure that we don't sysread beyond the end of a file.
I'll work with him to ensure that the right solution gets implemented in the coming weeks.
| set_accessed_at | ||
| buf = @file.sysread(amount) | ||
| # return if no zero byte inside | ||
| return buf unless zc = buf.index("\0") |
There was a problem hiding this comment.
The zc variable is bound, but unused.
Additionally, for readability we prefer that variables are descriptive and unabiguous, and while I can tell what buf is, variables like cc and dt would be better off with more descriptive names like attempts_remaining and backoff_delay.
| # return if no zero byte inside | ||
| return buf unless zc = buf.index("\0") | ||
| # update amount to read | ||
| amount = buf.bytesize |
There was a problem hiding this comment.
amount here has multiple meanings (amount requested vs amount retrieved), and the mutation of the input parameter combined with the retry pattern means that on each subsequent attempt we will read potentially fewer bytes than initially requested. This is rather opaque and can present surprises later on that would be hard to debug, so we try to avoid overloading variables like this.
|
Thanks for your reply,
Looking forwards for working final result of your changes,
Thanks again,
Sergey Volkov
…On Wed, Jun 27, 2018 at 4:44 PM Ry Biesemeyer ***@***.***> wrote:
***@***.**** requested changes on this pull request.
@sv-gh <https://github.com/sv-gh> while this approach may work for your
specific setup, it's not an approach that I believe scales to the wide
user-base of this plugin. I appreciate the work you put in, and will work
to get an acceptable solution put together shortly.
------------------------------
The primary reason is that the presence of a null-byte isn't necessarily a
reliable indicator that the sysread has returned bytes beyond the end of
the file:
- a null byte is valid in gzipped log files, which means that when
reading gzipped logs in this implementation we will frequently need to fall
through all attempts, reading, sleeping, and un-seeking repeatedly before
finally emitting each chunk.
- When reading beyond the end of a file using sysread, the behaviour
is *undefined*; on your system it may be observed to emit one or more
null bytes, but this is not specified nor guaranteed.
In order to reliably ensure that we don't read beyond the end of our
source files, each time we sysread we will need to first stat the file to
determine how much is available.
------------------------------
There is currently work in-flight to improve support for file rotation
<#192>, which
touches this and many other methods, and a follow-up is already planned by
@guyboertje <https://github.com/guyboertje> to address the root cause of
#189 <#189>
to ensure that we don't sysread beyond the end of a file.
I'll work with him to ensure that the right solution gets implemented in
the coming weeks.
------------------------------
In lib/filewatch/watched_file.rb
<#190 (comment)>
:
> @@ -89,8 +89,27 @@ def file_seek(amount, whence = IO::SEEK_SET)
end
def file_read(amount)
- set_accessed_at
- @file.sysread(amount)
+ #debug "*** file_read #{path}"
+ cc = 3 # max attempts
+ dt = 1.0/128 # delay beetwen attempts
+ loop do
+ set_accessed_at
+ buf = @file.sysread(amount)
+ # return if no zero byte inside
+ return buf unless zc = buf.index("\0")
The zc variable is bound, but unused.
Additionally, for readability we prefer that variables are descriptive and
unabiguous, and while I can tell what buf is, variables like cc and dt
would be better off with more descriptive names like attempts_remaining
and backoff_delay.
------------------------------
In lib/filewatch/watched_file.rb
<#190 (comment)>
:
> @@ -89,8 +89,27 @@ def file_seek(amount, whence = IO::SEEK_SET)
end
def file_read(amount)
- set_accessed_at
- @file.sysread(amount)
+ #debug "*** file_read #{path}"
+ cc = 3 # max attempts
+ dt = 1.0/128 # delay beetwen attempts
+ loop do
+ set_accessed_at
+ buf = @file.sysread(amount)
+ # return if no zero byte inside
+ return buf unless zc = buf.index("\0")
+ # update amount to read
+ amount = buf.bytesize
amount here has multiple meanings (amount requested vs amount retrieved),
and the mutation of the input parameter combined with the retry pattern
means that on each subsequent attempt we will read potentially *fewer*
bytes than initially requested. This is rather opaque and can present
surprises later on that would be hard to debug, so we try to avoid
overloading variables like this.
—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
<#190 (review)>,
or mute the thread
<https://github.com/notifications/unsubscribe-auth/AMsw0aaz4tflX1IA197VCE-vvL9w8Rb1ks5uA-7IgaJpZM4T8BHK>
.
|
This change has no any impact on currently working code, ment to improve reliability of logs reading in case when size/content update in file write implementation is not atomic in underlying FS software (as in NFSv3). Please approve/accept this fix for the nearest release.
This issue is blocking for our project and logstash use in jeopardy.