[syslog-ng] Behavior when followed files are renamed

[Balazs Scheidler]

On Mon, 2008-12-29 at 07:11 -0800, Evan Rempel wrote:
> Balazs Scheidler wrote:
> > On Thu, 2008-12-11 at 18:01 -0500, Joe Shaw wrote:
> >> Hi,
> >>
> >> On Thu, Dec 11, 2008 at 5:37 PM, Balazs Scheidler <bazsi at balabit.hu> wrote:
> >>> On Thu, 2008-12-11 at 15:23 -0500, Joe Shaw wrote:
> >>>> I couldn't find this anywhere in the online docs.  What's the behavior
> >>>> of syslog-ng OSE when a file which is being followed with
> >>>> follow_freq() is renamed?
> >>> It will be read until EOF, and then if a new file happens to be there at
> >>> the same location, syslog-ng starts reading the new file. e.g. it
> >>> handles rotated logfiles just fine. Although I don't know if this is
> >>> your intention or not.
> >> Ah, ok, thanks for the info!  I think this is probably what I want,
> >> but I am worried about a race condition.  Consider the following
> >> scenario:
> >>
> >> 1. Some app is writing to a log file, and another program is
> >> monitoring when the logs should be rolled.
> >>
> >> 2. The log rolling program renames the file on disk, and the app
> >> continues to write to the renamed file because it still has a file
> >> descriptor open to it.
> >>
> >> 3. The log rolling program signals to the app to close and reopen its
> >> log file; the app is writing out to its fixed log file location again.
> >>
> >> Assuming that syslog-ng is monitoring the file, is there a possibility that:
> >>
> >> 1. The file is renamed
> >> 2. syslog-ng is fully caught up and hits the EOF
> >> 3. The new file isn't created yet, but syslog-ng is waiting for it to be created
> >> 4. The app continues to write some data out to the old, renamed file
> >> 5. The app is signaled and reopens the file; syslog-ng starts monitoring it
> >>
> >> I am making an assumption in #3 which might not be true -- that
> >> syslog-ng when it encounters EOF but the file isn't recreated that
> >> it'll abandon the renamed file.  If that's not true, then there's no
> >> race and I'm happy. :)
> > 
> > It will not abandon it, but will check for the new file every
> > follow_freq() seconds.
> 
> This would still seem to yield a race condition. Consider the following sequence;
> 
> 1. Application is writing to log file named "A".
> 2. External log rotation renames "A" to "A.1"
> 3. External log rotation touches/creates file named "A" and sets appropriate
>     permissions.
> 4. Internal timer of syslog-ng is triggered by follow_freq() setting. Syslog-ng will
>     switch to the new file "A" because it exists, even though it was created only
>     milliseconds earlier.
> 5. log rotation signals the application to switch log files (reload or restart).
> 6. Application flushes log buffers to current file which is now A.1, but syslog-ng
>     is no longer reading this file.
> 7. Application closes current log file "A.1" and opens new log file "A".
> 
> This sequence will result in the last buffer flush (step 6) from the application to
> be missed by syslog-ng.
> 
> In my opinion, the only way to guarantee that you get all of the messages
> is to read from the old file until the first message appears in the new file.
> At that time, you can be assured that the old file has been abandoned by the
> application.

You are right, although this patch does not ensure that a complete line
was written to the new file, but it checks that at least _some_ data was
written there.

I don't see too much risk with this change, so I committed it to the
syslog-ng OSE 3.0 branch.

diff --git a/src/logreader.c b/src/logreader.c
index f9567ff..40e2ae7 100644
--- a/src/logreader.c
+++ b/src/logreader.c
@@ -167,7 +167,7 @@ log_reader_fd_check(GSource *source)
         
       if (self->reader->follow_filename && stat(self->reader->follow_filename, &followed_st) != -1)
         {
-          if (fd < 0 || st.st_ino != followed_st.st_ino)
+          if (fd < 0 || (st.st_ino != followed_st.st_ino && st.st_size > 0))
             {
               msg_trace("log_reader_fd_check file moved eof",
                         evt_tag_int("pos", pos),

-- 
Bazsi