From cf06a872e74b45588c2e64903f7fc99cf2aafe27 Mon Sep 17 00:00:00 2001 From: Pádraig Brady Date: Tue, 5 May 2015 22:11:24 +0100 Subject: tail: fix inotify startup races The previous fixes to races in the various tail tests, identified actual races in the tail inotify implementation. With --follow=descriptor, if the tailed file was replaced before the inotify watch was added, then any subsequent changes were ignored. Similarly in --follow=name mode, all changes to a new name were effectively ignored if that name was created after the original open() but before the inotify_add_watch(). * src/tail.c (tail_forever_inotify): Fix 3 cases. 1. With -f, don't stop tailing when file removed before watch. 2. With -f, watch right file when file replaced before watch. 3. With -F, inspect correct file when replaced before watch. Existing tests identify these when tail compiled with TAIL_TEST_SLEEP. * tests/tail-2/inotify-rotate-resources.sh: This test also identifies the issue with --follow=name when TAIL_TEST_SLEEP is used. Adjust so the test is immune to such races, and also fail quicker on remote file systems. * tests/tail-2/inotify-race2.sh: A new test using GDB, based on inotify-race.sh, which tests the -F race without needed recompilation with sleeps. * tests/local.mk: Reference the new test. * NEWS: Mention the bug. --- tests/local.mk | 1 + tests/tail-2/inotify-race2.sh | 103 +++++++++++++++++++++++++++++++ tests/tail-2/inotify-rotate-resources.sh | 29 +++++---- 3 files changed, 122 insertions(+), 11 deletions(-) create mode 100755 tests/tail-2/inotify-race2.sh (limited to 'tests') diff --git a/tests/local.mk b/tests/local.mk index 0d4f9df75..025276332 100644 --- a/tests/local.mk +++ b/tests/local.mk @@ -161,6 +161,7 @@ check-root: all_tests = \ tests/misc/help-version.sh \ tests/tail-2/inotify-race.sh \ + tests/tail-2/inotify-race2.sh \ tests/misc/invalid-opt.pl \ tests/rm/ext3-perf.sh \ tests/rm/cycle.sh \ diff --git a/tests/tail-2/inotify-race2.sh b/tests/tail-2/inotify-race2.sh new file mode 100755 index 000000000..6d996eba7 --- /dev/null +++ b/tests/tail-2/inotify-race2.sh @@ -0,0 +1,103 @@ +#!/bin/sh +# Ensure that tail does not ignore a tailed-forever file that has been +# replaced between tail's initial read-to-EOF, and when the inotify watches +# are established in tail_forever_inotify. That new file would be ignored +# indefinitely. + +# 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 + +# Terminate any background gdb/tail process +cleanup_() { + kill $pid 2>/dev/null && wait $pid + kill $sleep 2>/dev/null && wait $sleep +} + +touch file || framework_failure_ +touch tail.out || framework_failure_ + +( timeout 10s gdb --version ) > gdb.out 2>&1 +case $(cat gdb.out) in + *'GNU gdb'*) ;; + *) skip_ "can't run gdb";; +esac + +# Break on a line rather than a symbol, to cater for inline functions +break_src="$abs_top_srcdir/src/tail.c" +break_line=$(grep -n ^tail_forever_inotify "$break_src") || framework_failure_ +break_line=$(echo "$break_line" | cut -d: -f1) || framework_failure_ + + +# Note we get tail to monitor a background sleep process +# rather than using timeout(1), as timeout sends SIGCONT +# signals to its monitored process, and gdb (7.9 at least) +# has _intermittent_ issues with this. +# Sending SIGCONT resulted in either delayed child termination, +# or no child termination resulting in a hung test. +# See https://sourceware.org/bugzilla/show_bug.cgi?id=18364 + +env sleep 10 & sleep=$! + +# See if gdb works and +# tail_forever_inotify is compiled and run +gdb -nx --batch-silent \ + --eval-command="break $break_line" \ + --eval-command="run --pid=$sleep -f file" \ + --eval-command='quit' \ + tail < /dev/null > gdb.out 2>&1 + +kill $sleep || skip_ 'breakpoint not hit' +wait $sleep + +# FIXME: The above is seen to _intermittently_ fail with: +# warning: .dynamic section for "/lib/libc.so.6" is not at the expected address +# warning: difference appears to be caused by prelink, adjusting expectations +compare /dev/null gdb.out || skip_ "can't set breakpoints in tail" + +env sleep 10 & sleep=$! + +echo never-seen-with-tail-8.23 > file.new || framework_failure_ + +# Run "tail -F file", stopping to replace with a new file before +# inotify initialization, and then continue. Before the fix, +# changes to the new file would effectively be ignored. +gdb -nx --batch-silent \ + --eval-command="break $break_line" \ + --eval-command="run --pid=$sleep -F file 2>tail.err >>tail.out" \ + --eval-command='shell mv file.new file' \ + --eval-command='continue' \ + --eval-command='quit' \ + tail < /dev/null > /dev/null 2>&1 & pid=$! + +# Note even updating the watched 'file' wouldn't have output +# anything between coreutils 7.5 and 8.23 inclusive as +# The old file descriptor (still held open by tail) was being fstat(). + +tail --pid=$pid -f tail.out | (read; kill $pid) + +# gdb has a bug in Debian's gdb-6.8-3 at least that causes it to not +# cleanup and exit correctly when it receives a SIGTERM, but +# killing sleep, should cause the tail process and thus gdb to exit. +kill $sleep +wait $sleep + +wait $pid + +compare /dev/null tail.out && { cat tail.err; fail=1; } + +Exit $fail diff --git a/tests/tail-2/inotify-rotate-resources.sh b/tests/tail-2/inotify-rotate-resources.sh index 792236516..c13959e22 100755 --- a/tests/tail-2/inotify-rotate-resources.sh +++ b/tests/tail-2/inotify-rotate-resources.sh @@ -22,7 +22,11 @@ print_ver_ tail grep '^#define HAVE_INOTIFY 1' "$CONFIG_HEADER" >/dev/null \ || skip_ 'inotify required' -require_strace_ inotify_rm_watch +require_strace_ 'inotify_add_watch,inotify_rm_watch' + +# Quickly skip on remote file systems +df --local . >/dev/null 2>&1 || + skip_ 'inotify not used on remote file system' check_tail_output() { @@ -59,7 +63,7 @@ touch k || framework_failure_ # however without it strace will ignore SIGTERM. # strace does always honor SIGTERM with the -I2 option, # though that's not available on RHEL6 for example. -timeout 180 strace -e inotify_rm_watch -o strace.out \ +timeout 180 strace -e inotify_add_watch,inotify_rm_watch -o strace.out \ tail -F $fastpoll k >> out 2>&1 & pid=$! reverted_to_polling_=0 @@ -67,19 +71,24 @@ for i in $(seq 2); do echo $i echo 'tailed' > k; - # wait for 'tailed' in (after first iteration; new) file and then in 'out' - grep_timeout 'tailed' || { cleanup_fail 'failed to find "tailed"'; break; } + + # Wait for watch on (new) file + strace_re='inotify_add_watch.*MODIFY' retry_delay_ check_strace .1 8 || + no_watch_=1 + + # Assume this is not because we're leaking + # (resources may already be depleted) + # The explicit check for inotify_rm_watch should confirm that. + grep -F 'reverting to polling' out >/dev/null && skip_ 'inotify unused' + + # Otherwise failure is unknown + test "$no_watch_" && { cat out; framework_failure_ 'no inotify_add_watch'; } mv k k.tmp # wait for tail to detect the rename grep_timeout 'inaccessible' || { cleanup_fail 'failed to detect rename'; break; } - # Assume this is not because we're leaking. - # The explicit check for inotify_rm_watch should confirm that. - grep -F 'reverting to polling' out >/dev/null && - { reverted_to_polling_=1; break; } - # Note we strace here rather than consuming all available watches # to be more efficient, but more importantly avoid depleting resources. # Note also available resources can currently be tuned with: @@ -95,8 +104,6 @@ for i in $(seq 2); do >out && >strace.out || framework_failure_ 'failed to reset output files' done -test "$reverted_to_polling_" = 1 && skip_ 'inotify resources already depleted' - cleanup_ Exit $fail -- cgit v1.2.3-54-g00ecf