Arjan Opmeer wrote: > Since coreutils 7.5 tail uses inotify. However it is not capable to follow > the sequence of file operations that happen when /var/log/syslog is rotated > by its daily cron job. This means that 'tail -F /var/log/syslog' will stop > producing output as soon as the file is rotated. > > Let me give a demonstration. Open two terminal windows and enter the > following commands: > > Terminal 1 Terminal 2 > ---------- ---------- > > echo "line 1" > somefile > tail -F somefile > > echo "line 2" >> somefile > savelog -m 640 -c 7 somefile > echo "line 3" >> somefile > echo "line 4" >> somefile > > This results in the following output from the tail command: > > line 1 > line 2 > tail: `somefile' has been replaced; following end of new file > > Notice that tail fails to follow the newly created somefile and never shows > lines 3 and 4. That this is caused by the new inotify code can be > demonstrated by using the latest git checkout of coreutils. This version > still fails the above scenario, but by supplying the undocumented > '---disable-inotify' flag the inotify code is disabled and the old polling > behaviour is used. This old behaviour can cope with the logrotate sequence > and will correctly show the contents of the new file. > > Could you use this information to file a bug report for GNU coreutils to > have the inotify implementation of tail fixed? In the meantime should the > Debian version of tail maybe be build without inotify support because it no > longer functions the way that users have come to expect?
Thanks a lot for that bug report. At first I thought it must have been fixed, because a few attempts to reproduce it showed no problem. However, with repeated tests, I'd see a failure in ~1 of 7 trials on one system, and about 1 of 4 on another. Those were multi-core systems. I found it much easier to trigger the failure on a slower, single-core system. touch k x && timeout 1 strace -o log-$(date +%j.%T) ./tail -F k & \ echo b >> k; sleep .1; env mv x k; sleep .1; echo ok >> k Here's output from a hacked tail.c that decodes the events and demonstrates the problem. The first one worked, and the following one, run just a couple of seconds later failed: ============================= ok ============================ read(4, "\2\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0\2\0\0\0\0\4\0\0\0\0\0\0\0\0\0\0", 36) = 32 write(2, "IN_ATTRIB 0\n", 12) = 12 write(2, "name: ***\n", 10) = 10 write(2, "IN_DELETE_SELF 0\n", 17) = 17 write(2, "name: ***\n", 10) = 10 read(4, "\2\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_IGNORED 0\n", 13) = 13 write(2, "name: ***\n", 10) = 10 read(4, "\3\0\0\0\2\0\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_MODIFY 0\n", 12) = 12 write(2, "name: k\n", 8) = 8 fstat(5, {st_mode=S_IFREG|0644, st_size=3, ...}) = 0 read(5, "ok\n", 8192) = 3 write(1, "ok\n", 3) = 3 read(5, "", 8192) = 0 read(4, 0x12d21a0, 36) = -1 EINTR (Interrupted system call) ============================= bad ============================ read(4, "\2\0\0\0\4\0\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_ATTRIB 0\n", 12) = 12 write(2, "name: ***\n", 10) = 10 read(4, "\3\0\0\0\0\10\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_MOVE_SELF 0\n", 15) = 15 write(2, "name: k\n", 8) = 8 inotify_rm_watch(4, 3) = 0 open("k", O_RDONLY|O_NONBLOCK) = 3 fstat(3, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0 close(3) = 0 read(4, "\3\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_IGNORED 0\n", 13) = 13 write(2, "name: ***\n", 10) = 10 read(4, "\2\0\0\0\0\4\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_DELETE_SELF 0\n", 17) = 17 write(2, "name: ***\n", 10) = 10 read(4, "\2\0\0\0\0\200\0\0\0\0\0\0\0\0\0\0", 36) = 16 write(2, "IN_IGNORED 0\n", 13) = 13 write(2, "name: ***\n", 10) = 10 read(4, 0x13f91a0, 36) = -1 EINTR (Interrupted system call) Here's a patch that fixes it. I'll write a test before pushing the result. So far, I've used this: #!/bin/sh for i in $(seq 1000); do d=d-$i mkdir $d ( cd $d :>k && :>x && timeout 1 ../tail -F k > out 2>/dev/null & echo b >> k; sleep .01; env mv x k; sleep .01; echo ok >> k sleep .01; grep ok out > /dev/null && ok=. || ok=X; printf $ok ) rm -rf $d done Interestingly, on one system (modern, quad-core), it printed this for the unpatched version of tail (replacing ../tail above): "X" represents failure ........................X.....................................................\ ........X...............................XX....................................\ ....................................XX......................X.................\ ...................X...................XX.............X.............X.......X.\ .................................X..............................X.....X.......\ ............................X.......X...X................................X....\ ..............................................................................\ ..........................................X...................................\ ..X...................................X.......................................\ .X..................................................X.....................X.X.\ .......X..............................X.......................................\ ......................X....X...........................X......................\ .................X....X.XX.......X......X.....................X. Running the same script on an aging uniprocessor system gave this: XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ X.XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ XXXXXXXXXXXXXXXXXXXXXXXX......X.....X....XXX.X........................XXXXXXXX\ XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ XXXXX.....XXX.XXXXXXXXX.XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ X.XXXXXXXXXXXXXXXXXXXXXXX.XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ X.XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX.X\ XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX.....\ XXXXXXXXXXXXXXXXXX.XXXXXXXXXXX.XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX\ XX.XXXXXXXXXXXXXXXXXXXX..XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX.X.....X\ XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX..X....X.XXXXXXXXXXXXXXXXXXXXXXXXXX\ XXXXXXXXXXXXXXXX.......XXXXXXXXXXXXXXXXXXXX.XX..XXXXXXXXXX.XXXXX >From 203d51c2425f87811bd388c654466b7d24d1f1a1 Mon Sep 17 00:00:00 2001 From: Jim Meyering <meyer...@redhat.com> Date: Sun, 15 Nov 2009 09:25:29 +0100 Subject: [PATCH] tail -F: fix a bug in the inotify-based code Tailing forever and by-name (--follow=name, -F), tail would sometimes fail to follow a file that had been removed via rename. * src/tail.c (tail_forever_inotify): When tailing by name (-F), do not un-watch a file upon receipt of the IN_MOVE_SELF event. Reported by Arjan Opmeer in http://bugs.debian.org/548439. * NEWS (Bug fixes): Mention it. --- NEWS | 5 +++++ THANKS | 3 ++- src/tail.c | 8 +++++++- 3 files changed, 14 insertions(+), 2 deletions(-) diff --git a/NEWS b/NEWS index c9fe6ca..e3763cd 100644 --- a/NEWS +++ b/NEWS @@ -48,6 +48,11 @@ GNU coreutils NEWS -*- outline -*- were first renamed or unlinked or never modified. [The race was introduced in coreutils-7.5] + tail -F (inotify-enabled) now consistently tails a file that has been + replaced via renaming. That operation provokes either of two sequences + of inotify events. The less common sequence is now handled as well. + [The bug came with the implementation change in coreutils-7.5] + timeout now doesn't exit unless the command it is monitoring does, for any specified signal. [bug introduced in coreutils-7.0]. diff --git a/THANKS b/THANKS index 7955da7..f9bc476 100644 --- a/THANKS +++ b/THANKS @@ -52,6 +52,7 @@ Andy Longton along...@metamark.com Anthony Thyssen anth...@griffith.edu.au Antonio Rendas ajren...@yahoo.com Ariel Faigon ar...@cthulhu.engr.sgi.com +Arjan Opmeer arjan.opm...@gmail.com Arne H. Juul ar...@solan.unit.no Arne Henrik Juul ar...@imf.unit.no Arnold Robbins arn...@skeeve.com @@ -401,7 +402,7 @@ Max Chang maxch...@ucla.edu Meelis Roos mr...@tartu.cyber.ee Michael mich...@aplatform.com Michael ??? mich...@roka.net -Michael Bacarella m...@netgraft.com> +Michael Bacarella m...@netgraft.com Michael Deutschmann mich...@talamasca.ocis.net Michael Elizabeth Chastain mec....@mindspring.com Michael Gaughen mgaug...@polyserve.com diff --git a/src/tail.c b/src/tail.c index 09afeec..9a2f5ae 100644 --- a/src/tail.c +++ b/src/tail.c @@ -1404,7 +1404,13 @@ tail_forever_inotify (int wd, struct File_spec *f, size_t n_files, if (ev->mask & (IN_ATTRIB | IN_DELETE_SELF | IN_MOVE_SELF)) { - if (ev->mask & (IN_DELETE_SELF | IN_MOVE_SELF)) + /* For IN_DELETE_SELF, we always want to remove the watch. + However, for IN_MOVE_SELF (the file we're watching has + been clobbered via a rename), when tailing by NAME, we + must continue to watch the file. It's only when following + by file descriptor that we must remove the watch. */ + if ((ev->mask & IN_DELETE_SELF) + || ((ev->mask & IN_MOVE_SELF) && follow_mode == Follow_descriptor)) { inotify_rm_watch (wd, f[i].wd); hash_delete (wd_table, &(f[i])); -- 1.6.5.2.372.gc0502 -- To UNSUBSCRIBE, email to debian-bugs-dist-requ...@lists.debian.org with a subject of "unsubscribe". Trouble? Contact listmas...@lists.debian.org