From 0e506d2c9f769517de3301d96b0077491a2bbcc8 Mon Sep 17 00:00:00 2001 From: =?latin1?q?P=E1draig=20Brady?= Date: Mon, 11 May 2015 14:25:19 +0100 Subject: tail: consistently output all data for truncated files Generally if logs are truncated, they're truncated to 0 length, so output all existing data when our heuristic determines truncation. Note with inotify, truncate() and write() are often determined independently and so all data would be written if that was the case. * src/tail.c (check_fspec): Reset file offset to 0 upon truncation. (tail_forever): Likewise. (recheck): Add a FIXME for the related issue where tail may lose data due to tail discounting older log files too early. * tests/tail-2/truncate.sh: A new test. * tests/local.mk: Reference the new test. * NEWS: Mention the fix. (cherry picked from commit b28ff6a3c6ad25d877b63013af245de5d6c70b10) Conflicts: NEWS --- src/tail.c | 30 +++++++++++++++++++------- tests/local.mk | 1 + tests/tail-2/truncate.sh | 56 ++++++++++++++++++++++++++++++++++++++++++++++++ 3 files changed, 79 insertions(+), 8 deletions(-) create mode 100755 tests/tail-2/truncate.sh diff --git a/src/tail.c b/src/tail.c index 3f42406..609972b 100644 --- a/src/tail.c +++ b/src/tail.c @@ -1026,7 +1026,7 @@ recheck (struct File_spec *f, bool blocking) if (f->fd == -1) { error (0, 0, - _("%s has appeared; following end of new file"), + _("%s has appeared; following new file"), quote (pretty_name (f))); } else @@ -1037,7 +1037,7 @@ recheck (struct File_spec *f, bool blocking) /* File has been replaced (e.g., via log rotation) -- tail the new one. */ error (0, 0, - _("%s has been replaced; following end of new file"), + _("%s has been replaced; following new file"), quote (pretty_name (f))); } } @@ -1056,6 +1056,12 @@ recheck (struct File_spec *f, bool blocking) } } + /* FIXME: When a log is rotated, daemons tend to log to the + old file descriptor until the new file is present and + the daemon is sent a signal. Therefore tail may miss entries + being written to the old file. Perhaps we should keep + the older file open and continue to monitor it until + data is written to a new file. */ if (new_file) { /* Start at the beginning of the file. */ @@ -1194,13 +1200,16 @@ tail_forever (struct File_spec *f, size_t n_files, double sleep_interval) /* reset counter */ f[i].n_unchanged_stats = 0; + /* XXX: This is only a heuristic, as the file may have also + been truncated and written to if st_size >= size + (in which case we ignore new data <= size). */ if (S_ISREG (mode) && stats.st_size < f[i].size) { error (0, 0, _("%s: file truncated"), name); - last = i; - xlseek (fd, stats.st_size, SEEK_SET, name); - f[i].size = stats.st_size; - continue; + /* Assume the file was truncated to 0, + and therefore output all "new" data. */ + xlseek (fd, 0, SEEK_SET, name); + f[i].size = 0; } if (i != last) @@ -1331,12 +1340,17 @@ check_fspec (struct File_spec *fspec, int wd, int *prev_wd) return; } + /* XXX: This is only a heuristic, as the file may have also + been truncated and written to if st_size >= size + (in which case we ignore new data <= size). + Though in the inotify case it's more likely we'll get + separate events for truncate() and write(). */ if (S_ISREG (fspec->mode) && stats.st_size < fspec->size) { error (0, 0, _("%s: file truncated"), name); *prev_wd = wd; - xlseek (fspec->fd, stats.st_size, SEEK_SET, name); - fspec->size = stats.st_size; + xlseek (fspec->fd, 0, SEEK_SET, name); + fspec->size = 0; } else if (S_ISREG (fspec->mode) && stats.st_size == fspec->size && timespec_cmp (fspec->mtime, get_stat_mtime (&stats)) == 0) diff --git a/tests/tail-2/truncate.sh b/tests/tail-2/truncate.sh new file mode 100755 index 0000000..82720fd --- /dev/null +++ b/tests/tail-2/truncate.sh @@ -0,0 +1,56 @@ +#!/bin/sh +# Ensure all logs are output upon file truncation + +# Copyright (C) 2015 Free Software Foundation, Inc. + +# This program is free software: you can redistribute it and/or modify +# it under the terms of the GNU General Public License as published by +# the Free Software Foundation, either version 3 of the License, or +# (at your option) any later version. + +# This program is distributed in the hope that it will be useful, +# but WITHOUT ANY WARRANTY; without even the implied warranty of +# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the +# GNU General Public License for more details. + +# You should have received a copy of the GNU General Public License +# along with this program. If not, see . + +. "${srcdir=.}/tests/init.sh"; path_prepend_ ./src +print_ver_ tail + +check_tail_output() +{ + local delay="$1" + grep "$tail_re" out > /dev/null || + { sleep $delay; return 1; } +} + +# Terminate any background tail process +cleanup_() { kill $pid 2>/dev/null && wait $pid; } + +# Speedup the non inotify case +fastpoll='-s.1 --max-unchanged-stats=1' + +for follow in '-f' '-F'; do + for mode in '' '---disable-inotify'; do + rm -f out + seq 10 > f || framework_failure_ + + tail $follow $mode $fastpoll f > out 2>&1 & pid=$! + + # Wait up to 12.7s for tail to start + tail_re='^10$' retry_delay_ check_tail_output .1 7 || + { cat out; fail=1; } + + seq 11 15 > f || framework_failure_ + + # Wait up to 12.7s for new data + tail_re='^15$' retry_delay_ check_tail_output .1 7 || + { cat out; fail=1; } + + cleanup_ + done +done + +Exit $fail -- 1.7.12.1