[prev in list] [next in list] [prev in thread] [next in thread]
List: busybox
Subject: [PATCH] Fix 'tail -F' skipping data when file descriptor changes
From: "Taylor, Bob (Temp Worker)" <t_Bob.Taylor () viasat ! com>
Date: 2021-05-27 17:36:24
Message-ID: c3cd730ee0b84e8ca65307d94630b29d () viasat ! com
[Download RAW message or body]
Hi All,
We noticed that `tail -F` has a problem with losing data when watching a log file \
when it rotates. With high logging rates for debugging, this can be a real problem \
if the logs are being captured from the console output of tail.
The code shows that the current method for follow/retry in the file is to cycle \
through the list of files, first verifying the file descriptor hasn't changed, then \
reading any data, sleep after all files are handled, and repeat. The problem is that \
data is missed when this happens since the check for fd changes is after a sleep, but \
as soon as tail sees the name references a different file, it switches over and gets \
data from that file instead of making sure it shows all the data in the first one. \
For log rotations, this will miss data from the end of the rotated logfile (e.g., \
/var/log/messages.1).
Patch included below. Now when it sees that the fd has changed it will save the new \
one (if opened), process the rest of the data from the current fd, and then skip the \
next sleep to start processing the new file if it has one (it seemed prudent with the \
high data rates). Test results show tail misses no data when the logs rotate, even \
under higher logging rates (hundreds or thousands/sec).
Thanks,
Bob Taylor
Software Engineer
t_Bob.Taylor@viasat.com<mailto:t_Bob.Taylor@viasat.com>
From 23fe6efca3867ca035c7ca066c2e0ae279c84612 Mon Sep 17 00:00:00 2001
From: Bob Taylor <t_Bob.Taylor@viasat.com>
Date: Thu, 27 May 2021 11:40:22 -0400
Subject: [PATCH] Fix missing data with tail -F
Signed-off-by: Bob Taylor <t_Bob.Taylor@viasat.com>
---
coreutils/tail.c | 37 ++++++++++++++++++++++++++++++-------
1 file changed, 30 insertions(+), 7 deletions(-)
diff --git a/coreutils/tail.c b/coreutils/tail.c
index 08fde6cdd..dbbbf738c 100644
--- a/coreutils/tail.c
+++ b/coreutils/tail.c
@@ -125,6 +125,7 @@ int tail_main(int argc, char **argv)
int *fds;
const char *fmt;
int prev_fd;
+ int skip_sleep = 0;
INIT_G();
@@ -338,13 +339,19 @@ int tail_main(int argc, char **argv)
fmt = NULL;
if (FOLLOW) while (1) {
- sleep(sleep_period);
+ if (0 == skip_sleep) {
+ sleep(sleep_period);
+ }
+ else {
+ skip_sleep = 0;
+ }
i = 0;
do {
int nread;
const char *filename = argv[i];
int fd = fds[i];
+ int new_fd = -1;
if (FOLLOW_RETRY) {
struct stat sbuf, fsbuf;
@@ -355,19 +362,27 @@ int tail_main(int argc, char **argv)
|| fsbuf.st_dev != sbuf.st_dev
|| fsbuf.st_ino != sbuf.st_ino
) {
- int new_fd;
-
- if (fd >= 0)
- close(fd);
+ /* We know the file has been created or \
renamed and the + * producer now has a newly \
created file if it can be + * opened by name. \
Since we were sleeping, go through + * one \
more loop if the old file still has a handle to + \
* make sure that we haven't missed any more data. */ new_fd = open(filename, \
O_RDONLY); if (new_fd >= 0) {
bb_error_msg("%s has %s; following \
end of new file",
filename, (fd < 0) ? \
"appeared" : "been replaced" );
} else if (fd >= 0) {
- bb_perror_msg("%s has become \
inaccessible", filename); + \
bb_perror_msg("%s has been renamed or deleted", filename); + \
} + if (fd < 0)
+ {
+ /* If the original file isn't open, \
there's no more data + * to process \
(or the file is just appearing), + * \
start using the new file immediately */ + \
fds[i] = fd = new_fd; + new_fd = -1;
}
- fds[i] = fd = new_fd;
}
}
if (ENABLE_FEATURE_FANCY_TAIL && fd < 0)
@@ -395,6 +410,14 @@ int tail_main(int argc, char **argv)
}
xwrite(STDOUT_FILENO, tailbuf, nread);
}
+ if (new_fd >= 0)
+ {
+ /* We are switching files to a new one, use new_fd \
and skip the + * next sleep to start processing it. */
+ close(fd);
+ fds[i] = fd = new_fd;
+ skip_sleep = 1;
+ }
} while (++i < nfiles);
} /* while (1) */
--
2.20.1
[Attachment #3 (text/html)]
<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=us-ascii">
<meta name="Generator" content="Microsoft Exchange Server">
<!-- converted from rtf -->
<style><!-- .EmailQuote { margin-left: 1pt; padding-left: 4pt; border-left: #800000 \
2px solid; } --></style> </head>
<body>
<font face="Calibri" size="2"><span style="font-size:11pt;">
<div>Hi All,</div>
<div> </div>
<div>We noticed that `tail -F` has a problem with losing data when watching a log \
file when it rotates. With high logging rates for debugging, this can be a real \
problem if the logs are being captured from the console output of tail. </div> \
<div> </div> <div>The code shows that the current method for follow/retry in the \
file is to cycle through the list of files, first verifying the file descriptor \
hasn’t changed, then reading any data, sleep after all files are handled, and \
repeat. The problem is that data is missed when this happens since the check \
for fd changes is after a sleep, but as soon as tail sees the name references a \
different file, it switches over and gets data from that file instead of making sure \
it shows all the data in the first one. For log rotations, this will miss data \
from the end of the rotated logfile (e.g., <font face="Courier \
New">/var/log/</font><font face="Courier New">messages.</font><font face="Courier \
New">1</font>).</div> <div> </div>
<div>Patch included below. Now when it sees that the fd has changed it will \
save the new one (if opened), process the rest of the data from the current fd, and \
then skip the next sleep to start processing the new file if it has one (it seemed \
prudent with the high data rates). Test results show tail misses no data when \
the logs rotate, even under higher logging rates (hundreds or thousands/sec).</div> \
<div> </div> <div>Thanks,</div>
<div>Bob Taylor</div>
<div> </div>
<div>Software Engineer</div>
<div><a href="mailto:t_Bob.Taylor@viasat.com"><font \
color="#0563C1"><u>t_Bob.Taylor@viasat.com</u></font></a></div> <div> </div>
<div> </div>
<div><font face="Courier New" size="2"><span style="font-size:10pt;">From \
23fe6efca3867ca035c7ca066c2e0ae279c84612 Mon Sep 17 00:00:00 2001</span></font></div> \
<div><font face="Courier New" size="2"><span style="font-size:10pt;">From: Bob Taylor \
<t_Bob.Taylor@viasat.com></span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">Date: Thu, 27 May 2021 11:40:22 \
-0400</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">Subject: [PATCH] Fix missing data with tail \
-F</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">Signed-off-by: Bob Taylor \
<t_Bob.Taylor@viasat.com></span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">---</span></font></div> <div><font \
face="Courier New" size="2"><span style="font-size:10pt;"> coreutils/tail.c | 37 \
+++++++++++++++++& \
#43;++++++++++++-------</span></font></div>
<div><font face="Courier New" size="2"><span style="font-size:10pt;"> 1 file \
changed, 30 insertions(+), 7 deletions(-)</span></font></div> <div><font \
face="Courier New" size="2"><span style="font-size:10pt;"> </span></font></div> \
<div><font face="Courier New" size="2"><span style="font-size:10pt;">diff --git \
a/coreutils/tail.c b/coreutils/tail.c</span></font></div> <div><font face="Courier \
New" size="2"><span style="font-size:10pt;">index 08fde6cdd..dbbbf738c \
100644</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">--- a/coreutils/tail.c</span></font></div> <div><font \
face="Courier New" size="2"><span style="font-size:10pt;">+++ \
b/coreutils/tail.c</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">@@ -125,6 +125,7 @@ int tail_main(int argc, char \
**argv)</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> int \
*fds;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> const char \
*fmt;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> int \
prev_fd;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ int skip_sleep = \
0;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;"> \
INIT_G();</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">@@ -338,13 +339,19 @@ int tail_main(int \
argc, char **argv)</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> fmt = \
NULL;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;"> \
if (FOLLOW) while (1) {</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">- \
sleep(sleep_period);</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
if (0 == skip_sleep) {</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">+ \
\
sleep(sleep_period);</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
else {</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
skip_sleep = 0;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;"> \
i = 0;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> \
do {</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; \
int nread;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; \
const char *filename = argv[i];</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; \
int fd = fds[i];</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
int new_fd = -1;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; \
if (FOLLOW_RETRY) {</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; \
struct stat sbuf, fsbuf;</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">@@ -355,19 +362,27 @@ int tail_main(int \
argc, char **argv)</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; \
|| fsbuf.st_dev != sbuf.st_dev</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; \
|| fsbuf.st_ino != sbuf.st_ino</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; \
) {</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">- & \
nbsp; &nb \
sp; int \
new_fd;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">-</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">- &nbs \
p; \
\
if (fd >= 0)</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">- & \
nbsp; &nb \
sp; \
close(fd);</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
/* We know the file has been created or renamed and the</span></font></div> \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
* producer now has a newly created file if it can be</span></font></div> <div><font \
face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
* opened by name. Since we were sleeping, go through</span></font></div> \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
* one more loop if the old file still has a handle to</span></font></div> <div><font \
face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
* make sure that we haven't missed any more data. */</span></font></div> <div><font \
face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; &nbs \
p; \
new_fd = open(filename, O_RDONLY);</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; & \
nbsp; \
if (new_fd >= 0) {</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; & \
nbsp; \
bb_error_msg("%s has %s; following end of new file",</span></font></div> \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; &nbs \
p; \
\
filename, (fd < 0) ? "appeared" : "been \
replaced"</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; &nbs \
p; \
);</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; &nbs \
p; \
} else if (fd >= 0) {</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">- &nbs \
p; \
\
bb_perror_msg("%s has become inaccessible", filename);</span></font></div> \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
bb_perror_msg("%s has been renamed or deleted", \
filename);</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
if (fd < 0)</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
{</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
/* If the original file isn't open, there's no more data</span></font></div> \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
* to process (or the file is just appearing),</span></font></div> <div><font \
face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
* start using the new file immediately */</span></font></div> <div><font \
face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp;   \
; \
fds[i] = fd = new_fd;</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">+ \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; &nbs \
p; \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">- & \
nbsp; &nb \
sp; \
fds[i] = fd = new_fd;</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">   \
; \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; if \
(ENABLE_FEATURE_FANCY_TAIL && fd < 0)</span></font></div> <div><font \
face="Courier New" size="2"><span style="font-size:10pt;">@@ -395,6 +410,14 @@ \
int tail_main(int argc, char **argv)</span></font></div> <div><font face="Courier \
New" size="2"><span style="font-size:10pt;"> \
\
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> &n \
bsp; \
xwrite(STDOUT_FILENO, tailbuf, nread);</span></font></div> <div><font face="Courier \
New" size="2"><span style="font-size:10pt;"> \
\
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
if (new_fd >= 0)</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
{</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp; \
/* We are switching files to a new one, use new_fd and skip the</span></font></div> \
<div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp; \
* next sleep to start processing it. */</span></font></div> <div><font face="Courier \
New" size="2"><span style="font-size:10pt;">+ & \
nbsp; \
close(fd);</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ &nb \
sp; \
fds[i] = fd = new_fd;</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">+ \
\
skip_sleep = 1;</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;">+ \
}</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> \
} while (++i < nfiles);</span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;"> \
} /* while (1) */</span></font></div> <div><font face="Courier New" size="2"><span \
style="font-size:10pt;"> </span></font></div> <div><font face="Courier New" \
size="2"><span style="font-size:10pt;">-- </span></font></div> <div><font \
face="Courier New" size="2"><span style="font-size:10pt;">2.20.1</span></font></div> \
<div> </div> <div> </div>
<div> </div>
</span></font>
</body>
</html>
_______________________________________________
busybox mailing list
busybox@busybox.net
http://lists.busybox.net/mailman/listinfo/busybox
--===============5247053498955427061==--
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic