Re: tail is reading already rotated file.

[Bernhard Voelker]

On 02/05/2015 11:57 PM, Pádraig Brady wrote:
> From 9dc26e14cbd66a76acfc5265676decddde0d0c5f Mon Sep 17 00:00:00 2001
> From: =?UTF-8?q?P=C3=A1draig=20Brady?= <address@hidden>
> Date: Thu, 5 Feb 2015 13:10:49 +0000
> Subject: [PATCH] tail: return inotify resources where possible

Thanks. I only have some minor nits.

> 
> Each user has a maximum numer of inotify watches,

s/numer/number/

tail.c LGTM.

> diff --git a/tests/tail-2/inotify-rotate-resources.sh 
> b/tests/tail-2/inotify-rotate-resources.sh
> new file mode 100755
> index 0000000..2b6747f
> --- /dev/null
> +++ b/tests/tail-2/inotify-rotate-resources.sh
> @@ -0,0 +1,94 @@
> +#!/bin/sh
> +# ensure that tail -F doesn't leak inotify resources
> +
> +# 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 <http://www.gnu.org/licenses/>.
> +
> +. "${srcdir=.}/tests/init.sh"; path_prepend_ ./src
> +print_ver_ tail
> +
> +grep '^#define HAVE_INOTIFY 1' "$CONFIG_HEADER" >/dev/null \
> +  || skip_ 'inotify required'
> +
> +require_strace_ inotify_rm_watch
> +
> +check_tail_output()
> +{
> +  local delay="$1"
> +  grep "$tail_re" out > /dev/null ||
> +    { sleep $delay; return 1; }
> +}
> +
> +# Wait up to 25.5 seconds for grep REGEXP 'out' to succeed.
> +grep_timeout() { tail_re="$1" retry_delay_ check_tail_output .1 8; }
> +
> +strace_output()
> +{
> +  local delay="$1"
> +  test -s strace.out ||
> +    { sleep $delay; return 1; }
> +}
> +
> +cleanup_fail()
> +{
> +  cat out
> +  warn_ $1

same here (as in your other patch: warn_ does not prefix the
message with "$ME_: ...". Should we do this here?

> +  fail=1
> +}
> +
> +# Normally less than a second is required here, but with heavy load
> +# and a lot of disk activity, even 20 seconds is insufficient, which
> +# leads to this timeout killing tail before processing is completed.
> +touch k || framework_failure_
> +timeout 500 strace -e inotify_rm_watch -o strace.out tail -F k >> out 2>&1 &
> +pid=$!

500s = 8min 20s ... sounds much.

> +
> +for i in $(seq 6); do
> +    echo $i
> +
> +    echo 'tailed' > k;
> +    # wait for 'tailed' to appear in _new_ file and then in out
> +    grep_timeout 'tailed' || { cleanup_fail 'failed to find "tailed"'; 
> break; }
> +
> +    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:
> +    #  sudo sysctl -w fs.inotify.max_user_watches=$smallish_number
> +    # However that impacts all processes for the current user, and also
> +    # may not be supported in future, instead being auto scaled to RAM
> +    # like the Linux epoll resources were.
> +    if test "$i" -gt 1; then
> +      retry_delay_ 'strace_output' .1 8 ||
> +        { cleanup_fail 'failed to find inotify_rm_watch syscall'; break; }

no need to protect the strace_output function name as it was a string.

> +    fi
> +
> +    # truncate files (opened O_APPEND above)
> +    >out && >strace.out || framework_failure_ 'failed to reset output files'

strace.out isn't opened with O_APPEND, so at least the comment is misleading.

> +done
> +
> +test "$reverted_to_polling" && skip_ 'inotify resources already depleted'

'reverted_to_polling' should better be unset at the beginning.

> +kill $pid
> +wait
> +Exit $fail


> diff --git a/tests/tail-2/retry.sh b/tests/tail-2/retry.sh
> index 4f84225..a9f8639 100755
> --- a/tests/tail-2/retry.sh
> +++ b/tests/tail-2/retry.sh

...

> @@ -53,10 +60,11 @@ retry_delay_ wait4lines_ .1 6 3 || fail=1  # Wait for the 
> expected output.
>  kill $pid
>  wait $pid
>  # Expect 3 lines in the output file.
> -[ $( wc -l < out ) = 3 ]   || { fail=1; cat out; }
> +[ "$(countlines_)" = 3 ]   || { fail=1; cat out; }
>  grep -F 'cannot open' out  || { fail=1; cat out; }
>  grep -F 'has appeared' out || { fail=1; cat out; }
>  grep '^X$' out             || { fail=1; cat out; }
> +cp out /tmp/pb.tail

oops! A remainder from debugging.

Otherwise: nice work!

Should we add another test for "chmod -r/chmod +r"ed files?

Thanks & have a nice day,
Berny