[PATCH] Fix 'tail -F' skipping data when file descriptor changes

[Taylor, Bob (Temp Worker)]

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 at viasat.com<mailto:t_Bob.Taylor at viasat.com>


>From 23fe6efca3867ca035c7ca066c2e0ae279c84612 Mon Sep 17 00:00:00 2001
From: Bob Taylor <t_Bob.Taylor at 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 at 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



-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.busybox.net/pipermail/busybox/attachments/20210527/fa8fd012/attachment-0001.html>