bug#21459: Race condition in tests/tail-2/assert.sh

bug#21459: Race condition in tests/tail-2/assert.sh

[Ludovic Courtès]

Hello,

We have observed intermittent failures of tests/tail-2/assert.sh
(Coreutils 8.24, libc 2.22), especially showing up on relatively slow
machines (armhf and mips64el.)

The failure is with ‘tail --follow=name’, which, in inotify mode, would
fail to report that file ‘foo’ has been deleted.

The strace of a correct execution (x86_64) is like this:

--8<---------------cut here---------------start------------->8---
lstat("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
lstat("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
inotify_init()                          = 5
write(1, "==> a <==\nx\n\n==> foo <==\n", 25) = 25
inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
inotify_add_watch(5, "a", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 2
inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
inotify_add_watch(5, "foo", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 3
open("a", O_RDONLY|O_NONBLOCK)          = 6
lstat("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
fstat(6, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
fstatfs(6, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=16738210, f_bfree=1219533, f_bavail=367617, f_files=4259840, f_ffree=2406492, f_fsid={1622537548, 1497272261}, f_namelen=255, f_frsize=4096}) = 0
close(6)                                = 0
fstat(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
open("foo", O_RDONLY|O_NONBLOCK)        = 6
lstat("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstat(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstatfs(6, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=16738210, f_bfree=1219533, f_bavail=367617, f_files=4259840, f_ffree=2406492, f_fsid={1622537548, 1497272261}, f_namelen=255, f_frsize=4096}) = 0
close(6)                                = 0
fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
read(5, "\3\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0", 20) = 16
open("foo", O_RDONLY|O_NONBLOCK)        = -1 ENOENT (No such file or directory)
lstat("foo", 0x7ffee174c3b0)            = -1 ENOENT (No such file or directory)
write(2, "tail: ", 6)                   = 6
write(2, "foo", 3)                      = 3
write(2, ": No such file or directory", 27) = 27
write(2, "\n", 1)                       = 1
close(4)                                = 0
read(5, "\3\0\0\0\0\4\0\0\0\0\0\0\0\0\0\0", 20) = 16
inotify_rm_watch(5, 3)                  = -1 EINVAL (Invalid argument)
--8<---------------cut here---------------end--------------->8---

For a *failing* execution (armhf), we get:

--8<---------------cut here---------------start------------->8---
lstat64("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
lstat64("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
inotify_init()                          = 5
write(1, "==> a <==\nx\n\n==> foo <==\n", 25) = 25
inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
inotify_add_watch(5, "a", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 2
inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
inotify_add_watch(5, "foo", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 3
open("a", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 6
lstat64("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
fstat64(6, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
fstatfs64(6, 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=37378337, f_bfree=36178942, f_bavail=34274471, f_files=9502720, f_ffree=9405759, f_fsid={1592050960, 1812457140}, f_namelen=255, f_frsize=4096, f_flags=4128}) = 0
close(6)                                = 0
fstat64(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
open("foo", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 6
lstat64("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstat64(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstatfs64(6, 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=37378337, f_bfree=36178942, f_bavail=34274471, f_files=9502720, f_ffree=9405759, f_fsid={1592050960, 1812457140}, f_namelen=255, f_frsize=4096, f_flags=4128}) = 0
close(6)                                = 0
fstat64(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
read(5, "\3\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0", 20) = 16
open("foo", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 6
lstat64("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstat64(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
fstatfs64(6, 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=37378337, f_bfree=36178938, f_bavail=34274467, f_files=9502720, f_ffree=9405759, f_fsid={1592050960, 1812457140}, f_namelen=255, f_frsize=4096, f_flags=4128}) = 0
close(6)                                = 0
read(5,
--8<---------------cut here---------------end--------------->8---

In both cases, reading from the inotify file descriptor (number 5)
returns a notification for watch #3 (corresponding to ‘foo’), with mask
IN_ATTRIB (value 4).

However, the open("foo") call that immediately follows does *not* return
ENOENT in the failing case: The file is still there.

The kernel’s ‘vfs_unlink’ goes like this:

        fsnotify_link_count(target);                    /* IN_ATTRIB */
        d_delete(dentry); /* fsnotify_nameremove → IN_DELETE for “.” */

So, ‘tail’ first receives the IN_ATTRIB notification corresponding to
the link count decrease on ‘foo’; at that point, ‘foo’ is still
available.  And then, ‘tail’ should receive the IN_DELETE_SELF
notification, at which point ‘foo’ would have been actually been
unlinked.  But in practice we don’t seem to be receiving IN_DELETE_SELF,
even in the succeeding case.

I think the problem happens when ‘tail’ opens ‘foo’ right in between of
the two notifications: ‘foo’ is still there, and so ‘tail’ doesn’t
report anything.

Does that make sense?

Thanks,
Ludo’.

bug#21460: Race condition in tests/tail-2/assert.sh

[Paul Eggert]

Ludovic Courtès wrote:
> I think the problem happens when ‘tail’ opens ‘foo’ right in between of
> the two notifications: ‘foo’ is still there, and so ‘tail’ doesn’t
> report anything.
>
> Does that make sense?

Yes, though if the link count is indeed zero, I'm surprised that 'tail' can open 
the file -- that sounds like a bug in the kernel.

If there is such a kernel bug and 'tail' can open a file with a link count of 
zero, that would explain why 'tail' does not immediately receive an 
IN_DELETE_SELF notification: after all, the file is open (by 'tail' itself) so 
it should not be deleted even if it has a link count of zero.  If so, it appears 
that there's another kernel bug later: when 'tail' closes the file's last file 
descriptor, the file should be deleted and an IN_DELETE_SELF notification should 
be sent to 'tail'.

bug#21459: Race condition in tests/tail-2/assert.sh

[Pádraig Brady]

On 11/09/15 17:23, Ludovic Courtès wrote:
> Hello,
> 
> We have observed intermittent failures of tests/tail-2/assert.sh
> (Coreutils 8.24, libc 2.22), especially showing up on relatively slow
> machines (armhf and mips64el.)
> 
> The failure is with ‘tail --follow=name’, which, in inotify mode, would
> fail to report that file ‘foo’ has been deleted.
> 
> The strace of a correct execution (x86_64) is like this:
> 
> --8<---------------cut here---------------start------------->8---
> lstat("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> lstat("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> inotify_init()                          = 5
> write(1, "==> a <==\nx\n\n==> foo <==\n", 25) = 25
> inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
> inotify_add_watch(5, "a", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 2
> inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
> inotify_add_watch(5, "foo", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 3
> open("a", O_RDONLY|O_NONBLOCK)          = 6
> lstat("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> fstat(6, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> fstatfs(6, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=16738210, f_bfree=1219533, f_bavail=367617, f_files=4259840, f_ffree=2406492, f_fsid={1622537548, 1497272261}, f_namelen=255, f_frsize=4096}) = 0
> close(6)                                = 0
> fstat(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> open("foo", O_RDONLY|O_NONBLOCK)        = 6
> lstat("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> fstat(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> fstatfs(6, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=16738210, f_bfree=1219533, f_bavail=367617, f_files=4259840, f_ffree=2406492, f_fsid={1622537548, 1497272261}, f_namelen=255, f_frsize=4096}) = 0
> close(6)                                = 0
> fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> read(5, "\3\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0", 20) = 16
> open("foo", O_RDONLY|O_NONBLOCK)        = -1 ENOENT (No such file or directory)
> lstat("foo", 0x7ffee174c3b0)            = -1 ENOENT (No such file or directory)
> write(2, "tail: ", 6)                   = 6
> write(2, "foo", 3)                      = 3
> write(2, ": No such file or directory", 27) = 27
> write(2, "\n", 1)                       = 1
> close(4)                                = 0
> read(5, "\3\0\0\0\0\4\0\0\0\0\0\0\0\0\0\0", 20) = 16
> inotify_rm_watch(5, 3)                  = -1 EINVAL (Invalid argument)
> --8<---------------cut here---------------end--------------->8---
> 
> For a *failing* execution (armhf), we get:
> 
> --8<---------------cut here---------------start------------->8---
> lstat64("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> lstat64("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> inotify_init()                          = 5
> write(1, "==> a <==\nx\n\n==> foo <==\n", 25) = 25
> inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
> inotify_add_watch(5, "a", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 2
> inotify_add_watch(5, ".", IN_ATTRIB|IN_MOVED_TO|IN_CREATE) = 1
> inotify_add_watch(5, "foo", IN_MODIFY|IN_ATTRIB|IN_DELETE_SELF|IN_MOVE_SELF) = 3
> open("a", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 6
> lstat64("a", {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> fstat64(6, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> fstatfs64(6, 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=37378337, f_bfree=36178942, f_bavail=34274471, f_files=9502720, f_ffree=9405759, f_fsid={1592050960, 1812457140}, f_namelen=255, f_frsize=4096, f_flags=4128}) = 0
> close(6)                                = 0
> fstat64(3, {st_mode=S_IFREG|0644, st_size=2, ...}) = 0
> open("foo", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 6
> lstat64("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> fstat64(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> fstatfs64(6, 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=37378337, f_bfree=36178942, f_bavail=34274471, f_files=9502720, f_ffree=9405759, f_fsid={1592050960, 1812457140}, f_namelen=255, f_frsize=4096, f_flags=4128}) = 0
> close(6)                                = 0
> fstat64(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> read(5, "\3\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0", 20) = 16
> open("foo", O_RDONLY|O_NONBLOCK|O_LARGEFILE) = 6
> lstat64("foo", {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> fstat64(6, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
> fstatfs64(6, 88, {f_type="EXT2_SUPER_MAGIC", f_bsize=4096, f_blocks=37378337, f_bfree=36178938, f_bavail=34274467, f_files=9502720, f_ffree=9405759, f_fsid={1592050960, 1812457140}, f_namelen=255, f_frsize=4096, f_flags=4128}) = 0
> close(6)                                = 0
> read(5,
> --8<---------------cut here---------------end--------------->8---
> 
> In both cases, reading from the inotify file descriptor (number 5)
> returns a notification for watch #3 (corresponding to ‘foo’), with mask
> IN_ATTRIB (value 4).
> 
> However, the open("foo") call that immediately follows does *not* return
> ENOENT in the failing case: The file is still there.
> 
> The kernel’s ‘vfs_unlink’ goes like this:
> 
>         fsnotify_link_count(target);                    /* IN_ATTRIB */
>         d_delete(dentry); /* fsnotify_nameremove → IN_DELETE for “.” */
> 
> So, ‘tail’ first receives the IN_ATTRIB notification corresponding to
> the link count decrease on ‘foo’; at that point, ‘foo’ is still
> available.  And then, ‘tail’ should receive the IN_DELETE_SELF
> notification, at which point ‘foo’ would have been actually been
> unlinked.  But in practice we don’t seem to be receiving IN_DELETE_SELF,
> even in the succeeding case.
> 
> I think the problem happens when ‘tail’ opens ‘foo’ right in between of
> the two notifications: ‘foo’ is still there, and so ‘tail’ doesn’t
> report anything.
> 
> Does that make sense?

Thanks for looking into it in such detail.
IN_DELETE_SELF is only sent when the inode is removed,
not on the unlink itself (as tail has the file open).
One of the awkward gotchas with inotify being inode oriented.

I.E. I wonder is this a cache coherency issue,
with tail referencing the stale inode in the open()
before the dcache is updated.

It'll be a while before I can look at this.

thanks again,
Pádraig.

bug#21460: Race condition in tests/tail-2/assert.sh

[Ludovic Courtès]

[-- Attachment #1: Type: text/plain, Size: 1135 bytes --]

Paul Eggert <eggert@cs.ucla.edu> skribis:

> Ludovic Courtès wrote:
>> I think the problem happens when ‘tail’ opens ‘foo’ right in between of
>> the two notifications: ‘foo’ is still there, and so ‘tail’ doesn’t
>> report anything.
>>
>> Does that make sense?
>
> Yes, though if the link count is indeed zero, I'm surprised that
> 'tail' can open the file -- that sounds like a bug in the kernel.

Attached is a reproducer; just run it in a loop for a couple of seconds:

--8<---------------cut here---------------start------------->8---
$ while ./a.out ; do : ; done
funny, errno = Success, nlink = 0
Aborted (core dumped)
--8<---------------cut here---------------end--------------->8---

I’m not sure if that’s a kernel bug.  Strictly speaking, inotify works
as expected: we get a notification for nlink--, which doesn’t mean the
file has vanished.

The conclusion for ‘tail’ would be to wait for the IN_DELETE_SELF event
before considering the file to be gone.  WDYT?

(That ‘inotify_rm_watch’ returns EINVAL *is* a bug IMO, but not
worrisome.)

Thanks,
Ludo’.


[-- Attachment #2: the inotify race --]
[-- Type: text/plain, Size: 1257 bytes --]

#define _GNU_SOURCE 1

#include <stdlib.h>
#include <unistd.h>
#include <sys/inotify.h>
#include <sys/types.h>
#include <sys/stat.h>
#include <fcntl.h>
#include <errno.h>
#include <stdio.h>
#include <assert.h>

int
main ()
{
  int file = creat ("foo", S_IRUSR | S_IWUSR);
  assert_perror (errno);
  close (file);

  int notifications = inotify_init ();
  assert_perror (errno);

  int watch = inotify_add_watch (notifications, "foo",
				 IN_MODIFY | IN_ATTRIB
				 | IN_DELETE_SELF | IN_MOVE_SELF);
  assert_perror (errno);

  if (fork () == 0)
    {
      unlink ("foo");
      assert_perror (errno);
      exit (EXIT_SUCCESS);
    }

  struct inotify_event event;
  ssize_t count = read (notifications, &event, sizeof event);

  assert (count == sizeof event);
  assert (event.mask == IN_ATTRIB);

  struct stat st;
  stat ("foo", &st);
  if (errno != ENOENT)
    {
      printf ("funny, errno = %m, nlink = %li\n",
	      st.st_nlink);
      abort ();
    }

  count = read (notifications, &event, sizeof event);

  assert (count == sizeof event);
  assert (event.mask == IN_DELETE_SELF);

  /* Bug #2: this returns EINVAL for no good reason.  */
  /* inotify_rm_watch (notifications, watch); */
  /* assert_perror (errno); */

  return EXIT_SUCCESS;
}

bug#21460: Race condition in tests/tail-2/assert.sh

[Pádraig Brady]

On 11/09/15 21:55, Ludovic Courtès wrote:
> Paul Eggert <eggert@cs.ucla.edu> skribis:
> 
>> Ludovic Courtès wrote:
>>> I think the problem happens when ‘tail’ opens ‘foo’ right in between of
>>> the two notifications: ‘foo’ is still there, and so ‘tail’ doesn’t
>>> report anything.
>>>
>>> Does that make sense?
>>
>> Yes, though if the link count is indeed zero, I'm surprised that
>> 'tail' can open the file -- that sounds like a bug in the kernel.
> 
> Attached is a reproducer; just run it in a loop for a couple of seconds:
> 
> --8<---------------cut here---------------start------------->8---
> $ while ./a.out ; do : ; done
> funny, errno = Success, nlink = 0
> Aborted (core dumped)
> --8<---------------cut here---------------end--------------->8---
> 
> I’m not sure if that’s a kernel bug.  Strictly speaking, inotify works
> as expected: we get a notification for nlink--, which doesn’t mean the
> file has vanished.

Interesting.  It does seem that the IN_ATTRIB is sent before the st_nlink--
takes effect?  That could be a bug.  Or it could be a dcache coherency
issue where the name still references the st_nlink==0 inode.

Note recheck() just open() and close() the file in this case,
but since it doesn't close() the original fd, then there will be
no IN_DELETE_SELF event.

If the above kernel behavior can be explained and is acceptable,
I suppose we could augment recheck() with something like:

diff --git a/src/tail.c b/src/tail.c
index f916d74..e9d5337 100644
--- a/src/tail.c
+++ b/src/tail.c
@@ -1046,6 +1046,18 @@ recheck (struct File_spec *f, bool blocking)
       close_fd (f->fd, pretty_name (f));

     }
+  else if (new_stats.st_nlink == 0) /* XXX: what about multi-linked files.  */
+    {
+      /* It was seen on Linux that a file could be opened
+         even though unlinked as the directory entry (cache)
+         is updated after the IN_ATTRIB is sent for the nlink--.  */
+
+      error (0, f->errnum, _("%s has become inaccessible"),
+             quote (pretty_name (f)));
+
+      close_fd (fd, pretty_name (f));
+      close_fd (f->fd, pretty_name (f));
+      f->fd = -1;
   else
     {
       /* No changes detected, so close new fd.  */

> The conclusion for ‘tail’ would be to wait for the IN_DELETE_SELF event
> before considering the file to be gone.  WDYT?

As mentioned above, tail references the file until it can't open it,
so the IN_DELETE_SELF is only generated upon the close_fd(f->fd) above.

thanks,
Pádraig.

bug#21460: Race condition in tests/tail-2/assert.sh

[Pádraig Brady]

On 11/09/15 23:49, Pádraig Brady wrote:
> On 11/09/15 21:55, Ludovic Courtès wrote:
>> Paul Eggert <eggert@cs.ucla.edu> skribis:
>>
>>> Ludovic Courtès wrote:
>>>> I think the problem happens when ‘tail’ opens ‘foo’ right in between of
>>>> the two notifications: ‘foo’ is still there, and so ‘tail’ doesn’t
>>>> report anything.
>>>>
>>>> Does that make sense?
>>>
>>> Yes, though if the link count is indeed zero, I'm surprised that
>>> 'tail' can open the file -- that sounds like a bug in the kernel.
>>
>> Attached is a reproducer; just run it in a loop for a couple of seconds:
>>
>> --8<---------------cut here---------------start------------->8---
>> $ while ./a.out ; do : ; done
>> funny, errno = Success, nlink = 0
>> Aborted (core dumped)
>> --8<---------------cut here---------------end--------------->8---
>>
>> I’m not sure if that’s a kernel bug.  Strictly speaking, inotify works
>> as expected: we get a notification for nlink--, which doesn’t mean the
>> file has vanished.
> 
> Interesting.  It does seem that the IN_ATTRIB is sent before the st_nlink--
> takes effect?  That could be a bug.  Or it could be a dcache coherency
> issue where the name still references the st_nlink==0 inode.
> 
> Note recheck() just open() and close() the file in this case,
> but since it doesn't close() the original fd, then there will be
> no IN_DELETE_SELF event.
> 
> If the above kernel behavior can be explained and is acceptable,
> I suppose we could augment recheck() with something like:
> 
> diff --git a/src/tail.c b/src/tail.c
> index f916d74..e9d5337 100644
> --- a/src/tail.c
> +++ b/src/tail.c
> @@ -1046,6 +1046,18 @@ recheck (struct File_spec *f, bool blocking)
>        close_fd (f->fd, pretty_name (f));
> 
>      }
> +  else if (new_stats.st_nlink == 0) /* XXX: what about multi-linked files.  */
> +    {
> +      /* It was seen on Linux that a file could be opened
> +         even though unlinked as the directory entry (cache)
> +         is updated after the IN_ATTRIB is sent for the nlink--.  */
> +
> +      error (0, f->errnum, _("%s has become inaccessible"),
> +             quote (pretty_name (f)));
> +
> +      close_fd (fd, pretty_name (f));
> +      close_fd (f->fd, pretty_name (f));
> +      f->fd = -1;
> +    }
>    else
>      {
> 
>> The conclusion for ‘tail’ would be to wait for the IN_DELETE_SELF event
>> before considering the file to be gone.  WDYT?
> 
> As mentioned above, tail references the file until it can't open it,
> so the IN_DELETE_SELF is only generated upon the close_fd(f->fd) above.

Google reminded me of this!
https://lists.gnu.org/archive/html/coreutils/2015-07/msg00015.html
I.E. this is the same issue that Assaf noticed,
and that I though was restricted to older kernels.
That has an alternate fix attached.

cheers,
Pádraig.

bug#21460: Race condition in tests/tail-2/assert.sh

[Paul Eggert]

Pádraig Brady wrote:
> +  else if (new_stats.st_nlink == 0) /* XXX: what about multi-linked files.  */

That comment was my thought exactly.  It appears to be a kernel bug that really 
needs to get fixed in the kernel; there just doesn't seem to be a reliable 
workaround in user space.

bug#21460: Race condition in tests/tail-2/assert.sh

[Pádraig Brady]

On 12/09/15 02:09, Paul Eggert wrote:
> Pádraig Brady wrote:
>> +  else if (new_stats.st_nlink == 0) /* XXX: what about multi-linked files.  */
> 
> That comment was my thought exactly.  It appears to be a kernel bug that really 
> needs to get fixed in the kernel; there just doesn't seem to be a reliable 
> workaround in user space.

I double checked with kernel guys, and Al Viro
essentially said the inode and directory operations are independent.
https://lkml.org/lkml/2015/9/11/790

So we probably need to handle the IN_DELETE event
on the directory to cater for this race, as done in:
https://lists.gnu.org/archive/html/coreutils/2015-07/msg00015.html

cheers,
Pádraig.

bug#21460: Race condition in tests/tail-2/assert.sh

[Pádraig Brady]

[-- Attachment #1: Type: text/plain, Size: 776 bytes --]

On 12/09/15 03:22, Pádraig Brady wrote:
> On 12/09/15 02:09, Paul Eggert wrote:
>> Pádraig Brady wrote:
>>> +  else if (new_stats.st_nlink == 0) /* XXX: what about multi-linked files.  */
>>
>> That comment was my thought exactly.  It appears to be a kernel bug that really 
>> needs to get fixed in the kernel; there just doesn't seem to be a reliable 
>> workaround in user space.
> 
> I double checked with kernel guys, and Al Viro
> essentially said the inode and directory operations are independent.
> https://lkml.org/lkml/2015/9/11/790
> 
> So we probably need to handle the IN_DELETE event
> on the directory to cater for this race, as done in:
> https://lists.gnu.org/archive/html/coreutils/2015-07/msg00015.html

I'll apply the attached later.

thanks,
Pádraig


[-- Warning: decoded text below may be mangled, UTF-8 assumed --]
[-- Attachment #2: tail-unlink-notification-race.patch --]
[-- Type: text/x-patch; name="tail-unlink-notification-race.patch", Size: 3421 bytes --]

From 07ca8a227e04f9fb7bb0b21968056a562b8c2f83 Mon Sep 17 00:00:00 2001
From: =?UTF-8?q?P=C3=A1draig=20Brady?= <P@draigBrady.com>
Date: Thu, 2 Jul 2015 08:41:25 +0100
Subject: [PATCH] tail: handle kernel dentry unlink race
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Avoid the intermittent loss of "... has become inaccessible" messages.
That would cause tests/tail-2/assert.sh to fail sometimes,
mainly on uniprocessor systems.

* src/tail.c (tail_forever_inotify): Also monitor IN_DELETE
events on the directory, to avoid a dentry unlink()..open() race,
where the open() on the deleted file was seen to succeed after an,
unlink() and a subsequent IN_ATTRIB, was sent to tail.  Note an
IN_ATTRIB is sent on the monitored file to indicate the change in
number of links, and we can't just use a decrease in the number of
links to determine the file being unlinked, due to the possibility
of the file having multiple links.

Reported by Assaf Gordon and Ludovic Courtès.
Fixes http://bugs.gnu.org/21460
---
 src/tail.c | 21 ++++++++++++++-------
 1 file changed, 14 insertions(+), 7 deletions(-)

diff --git a/src/tail.c b/src/tail.c
index f916d74..7a34b0b 100644
--- a/src/tail.c
+++ b/src/tail.c
@@ -1429,8 +1429,8 @@ tail_forever_inotify (int wd, struct File_spec *f, size_t n_files,
                /* It's fine to add the same directory more than once.
                   In that case the same watch descriptor is returned.  */
               f[i].parent_wd = inotify_add_watch (wd, dirlen ? f[i].name : ".",
-                                                  (IN_CREATE | IN_MOVED_TO
-                                                   | IN_ATTRIB));
+                                                  (IN_CREATE | IN_DELETE
+                                                   | IN_MOVED_TO | IN_ATTRIB));
 
               f[i].name[dirlen] = prev;
 
@@ -1619,9 +1619,16 @@ tail_forever_inotify (int wd, struct File_spec *f, size_t n_files,
 
           fspec = &(f[j]);
 
-          /* Adding the same inode again will look up any existing wd.  */
-          int new_wd = inotify_add_watch (wd, f[j].name, inotify_wd_mask);
-          if (new_wd < 0)
+          int new_wd = -1;
+          bool deleting = !! (ev->mask & IN_DELETE);
+
+          if (! deleting)
+            {
+              /* Adding the same inode again will look up any existing wd.  */
+              new_wd = inotify_add_watch (wd, f[j].name, inotify_wd_mask);
+            }
+
+          if (! deleting && new_wd < 0)
             {
               if (errno == ENOSPC || errno == ENOMEM)
                 {
@@ -1641,7 +1648,7 @@ tail_forever_inotify (int wd, struct File_spec *f, size_t n_files,
           /* This will be false if only attributes of file change.  */
           bool new_watch = fspec->wd < 0 || new_wd != fspec->wd;
 
-          if (new_watch)
+          if (! deleting && new_watch)
             {
               if (0 <= fspec->wd)
                 {
@@ -1683,7 +1690,7 @@ tail_forever_inotify (int wd, struct File_spec *f, size_t n_files,
       if (! fspec)
         continue;
 
-      if (ev->mask & (IN_ATTRIB | IN_DELETE_SELF | IN_MOVE_SELF))
+      if (ev->mask & (IN_ATTRIB | IN_DELETE | IN_DELETE_SELF | IN_MOVE_SELF))
         {
           /* Note for IN_MOVE_SELF (the file we're watching has
              been clobbered via a rename) we leave the watch
-- 
2.5.0