GNU bug report logs - #25475
tail -f behaviour

Previous Next

To add a comment to this bug, you must first unarchive it, by sending
a message to control AT debbugs.gnu.org, with unarchive 25475 in the body.
You can then email your comments to 25475 AT debbugs.gnu.org in the normal way.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: f0rhum <f0rhum <at> free.fr>
To: bug-coreutils <at> gnu.org
Subject: tail -f behaviour
Date: Wed, 18 Jan 2017 17:39:07 +0100

Hi
This is about tail v5.97
I have a log file that is updated every 5mn, a timestamped message being
appended to a new line at the end
On the third time an indentical message would be writen, the last line
is replaced by "..." then the message is writen

Tracking changes with tail -f stops after this, which may be intended
behaviour as man states "as the file grows".

Although, when pruning a bunch of lines from the head of the file, then a
yet running tracking still won't update even the file size grows, like if the file size was
grabbed on the very beginning of the command and never updated on each
iteration.

To be honest, I didn't try to see what happens if I prune a single line
and see what the next 2nd and further iterations show.

Message #8 received at 25475 <at> debbugs.gnu.org (full text, mbox):

From: Bernhard Voelker <mail <at> bernhard-voelker.de>
To: f0rhum <f0rhum <at> free.fr>, 25475 <at> debbugs.gnu.org
Subject: Re: bug#25475: tail -f behaviour
Date: Wed, 18 Jan 2017 19:33:29 +0100

On 01/18/2017 05:39 PM, f0rhum wrote:
> Hi
> This is about tail v5.97

First of all, this is a ~10 years old version.
Even if this turns out to be a bug in the software, you won't get any support
for it.  Did you try the latest version (8.26)?

> I have a log file that is updated every 5mn, a timestamped message being
> appended to a new line at the end
> On the third time an indentical message would be writen, the last line
> is replaced by "..." then the message is writen
> 
> Tracking changes with tail -f stops after this, which may be intended
> behaviour as man states "as the file grows".
> 
> Although, when pruning a bunch of lines from the head of the file, then a
> yet running tracking still won't update even the file size grows, like if the file size was
> grabbed on the very beginning of the command and never updated on each
> iteration.
> 
> To be honest, I didn't try to see what happens if I prune a single line
> and see what the next 2nd and further iterations show.

To be honest, I do not understand what you mean by "pruning" in this
context, so I'm confused about what is going on.
Can you provide a simple example like:

  touch file
  tail -f file &
  sleep 2
  printf "some line\n" >> file
  sleep 2
  printf "only some words ..." >> file
  sleep 2
  printf "... on a continued line ..." >> file
  sleep 2
  printf "... which is now terminated\n" >> file
  sleep 2
  kill $!
  wait $!


Thanks & have a nice day,
Berny

Message #11 received at 25475 <at> debbugs.gnu.org (full text, mbox):

From: Pádraig Brady <P <at> draigBrady.com>
To: f0rhum <f0rhum <at> free.fr>, 25475 <at> debbugs.gnu.org
Subject: Re: bug#25475: tail -f behaviour
Date: Wed, 18 Jan 2017 18:37:01 +0000

On 18/01/17 16:39, f0rhum wrote:
> Hi
> This is about tail v5.97
> I have a log file that is updated every 5mn, a timestamped message being
> appended to a new line at the end
> On the third time an indentical message would be writen, the last line
> is replaced by "..." then the message is writen
> 
> Tracking changes with tail -f stops after this, which may be intended
> behaviour as man states "as the file grows".
> 
> Although, when pruning a bunch of lines from the head of the file, then a
> yet running tracking still won't update even the file size grows, like if the file size was
> grabbed on the very beginning of the command and never updated on each
> iteration.
> 
> To be honest, I didn't try to see what happens if I prune a single line
> and see what the next 2nd and further iterations show.

I think you're saying that your file is truncated in place.
tail(1) doesn't handle that well and expects files to be increasing,
and maybe rotated (which is handled with -F).
Newer versions of tail(1) will show the whole file again once
it detects truncation (as usually a truncated file is truncated to nothing
before new data is written).

cheers,
Padraig

Message #14 received at 25475 <at> debbugs.gnu.org (full text, mbox):

From: f0rhum <f0rhum <at> free.fr>
To: 25475 <at> debbugs.gnu.org
Subject: Re: bug#25475: tail -f behaviour
Date: Thu, 19 Jan 2017 00:44:29 +0100

tail -fn20 -s30 file
...
2017-01-18 22:55:00  10  0V18  +1C 0A00 500mA 11V70  20% 2A30 11861
Date            Heure   Mes. Vpan. Tmp.  Ich.  Conso   Vbat.   SoC  Sta 
Vin mV
2017-01-18 23:00:01  10  0V17  +1C 0A00 500mA 11V71  19% 2A30 11879
2017-01-18 23:05:00  10  0V17  +0C 0A00 480mA 11V71  20% 2A30 11868
2017-01-18 23:10:00  10  0V18  +0C 0A00 500mA 11V70  19% 2A30 11865
2017-01-18 23:15:00  10  0V16  +0C 0A00 510mA 11V69  19% 2A30 11832
  --> Vbat<11V70: Delestage automatique de 9h08mn
2017-01-18 23:20:21 Controleur inaccessible
2017-01-18 23:25:21 Controleur inaccessible
^C
tail -fn20 -s30 file
...
2017-01-18 22:55:00  10  0V18  +0C 0A00 500mA 11V70  20% 2A30 11861
Date            Heure   Mes. Vpan. Tmp.  Ich.  Conso   Vbat.   SoC  Sta 
Vin mV
2017-01-18 23:00:01  10  0V17  +1C 0A00 500mA 11V71  19% 2A30 11879
2017-01-18 23:05:00  10  0V17  +0C 0A00 480mA 11V71  20% 2A30 11868
2017-01-18 23:10:00  10  0V18  +0C 0A00 500mA 11V70  19% 2A30 11865
2017-01-18 23:15:00  10  0V16  +0C 0A00 510mA 11V69  19% 2A30 11832
  --> Vbat<11V70: Delestage automatique de 9h08mn
2017-01-18 23:20:21 Controleur inaccessible
...
2017-01-19 00:10:04 Controleur inaccessible

For the 2 above, I didn't delete any line above. Only the line 23:25:21
in the first was replaced by my script with
...
23:30:xx ....  <--- which in turn was updated by a new similar messages
until a different message happens (note here this is an additionnal line)
I didn't have the idea that "file grows" can have 2 meaning : grows in
bytes, or grows in line numbers. Whatever, a new line was added between
iterations (one deleted then immediately 2 added), and 3 bytes added (43
deleted (then sed -i '$ d' $LOGF;), then immediately 3 + 43 printed
immediately in a single write (help of printf "...\n%s Controleur
inaccessible\n" "`date "+%F %X"`" >>$LOGF )

I must also clarify something : this not an issue for me, I just wanted
to share what I discovered.
I just discovered -f was great live help while tracking bugs in my script.

Bye bye

Message #17 received at 25475 <at> debbugs.gnu.org (full text, mbox):

From: Bernhard Voelker <mail <at> bernhard-voelker.de>
To: f0rhum <f0rhum <at> free.fr>, 25475 <at> debbugs.gnu.org
Subject: Re: bug#25475: tail -f behaviour
Date: Thu, 19 Jan 2017 01:05:23 +0100

tag 25475 notabug
close 25475
stop


On 01/19/2017 12:44 AM, f0rhum wrote:
> deleted (then sed -i '$ d' $LOGF;), then immediately 3 + 43 printed
________________^^^^^^^^^^^^^^^^^^

That's the reason: "sed -i" opens a new, temporary file and filters the
original content from 'file' to the new one; finally, it renames the
temporary file to the original file name:

  $ strace -e open,read,write,rename sed -i '$ d' file
  ...
  open("file", O_RDONLY)                  = 3
  open("./sedLPtf2x", O_RDWR|O_CREAT|O_EXCL, 0600) = 4
  read(3, "xxx\n"..., 4096) = 953
  write(4, "xxx\n", 4)                      = 4
  ...
  read(3, "", 4096)                       = 0
  read(3, "", 4096)                       = 0
  rename("./sedLPtf2x", "file")           = 0
  +++ exited with 0 +++

The file has the same name, but the file descriptor that tail opened
at startup is a different one.  You can also see that the inode number
of the file changes:

  $ ls -logi file
  5770837 -rw-r--r-- 1 817 Jan 19 00:54 file

  $ sed -i '$ d' file

  $ ls -logi file
  5774048 -rw-r--r-- 1 751 Jan 19 01:00 file

As "tail -f" means to follow the original file descriptor, it is
not supposed to follow the new file (which has the same name):

  -f, --follow[={name|descriptor}]
                           output appended data as the file grows;
                             an absent option argument means 'descriptor'

As such, there is no bug in tail; therefore I'm marking it as such,
and close this issue in our bug tracker.

Have a nice day,
Berny

Message #20 received at 25475 <at> debbugs.gnu.org (full text, mbox):

From: f0rhum <f0rhum <at> free.fr>
To: Bernhard Voelker <mail <at> bernhard-voelker.de>, 25475 <at> debbugs.gnu.org
Subject: Re: bug#25475: tail -f behaviour
Date: Thu, 19 Jan 2017 09:36:09 +0100

Le 19/01/2017 à 01:05, Bernhard Voelker wrote :
> tag 25475 notabug
> close 25475
> stop
>
>
> On 01/19/2017 12:44 AM, f0rhum wrote:
>> deleted (then sed -i '$ d' $LOGF;), then immediately 3 + 43 printed
> ________________^^^^^^^^^^^^^^^^^^
>
> That's the reason: "sed -i" opens a new, temporary file and filters the
> original content from 'file' to the new one; finally, it renames the
> temporary file to the original file name:
>
>   $ strace -e open,read,write,rename sed -i '$ d' file
>   ...
>   open("file", O_RDONLY)                  = 3
>   open("./sedLPtf2x", O_RDWR|O_CREAT|O_EXCL, 0600) = 4
>   read(3, "xxx\n"..., 4096) = 953
>   write(4, "xxx\n", 4)                      = 4
>   ...
>   read(3, "", 4096)                       = 0
>   read(3, "", 4096)                       = 0
>   rename("./sedLPtf2x", "file")           = 0
>   +++ exited with 0 +++
>
> The file has the same name, but the file descriptor that tail opened
> at startup is a different one.  You can also see that the inode number
> of the file changes:
>
>   $ ls -logi file
>   5770837 -rw-r--r-- 1 817 Jan 19 00:54 file
>
>   $ sed -i '$ d' file
>
>   $ ls -logi file
>   5774048 -rw-r--r-- 1 751 Jan 19 01:00 file
>
> As "tail -f" means to follow the original file descriptor, it is
> not supposed to follow the new file (which has the same name):
>
>   -f, --follow[={name|descriptor}]
>                            output appended data as the file grows;
>                              an absent option argument means 'descriptor'
>
> As such, there is no bug in tail; therefore I'm marking it as such,
> and close this issue in our bug tracker.
>
> Have a nice day,
> Berny
Thank you very much Bernie
I won you taught me huge knowledge (descriptor and related, that was
mysterious to me when reading the man)
Thanks too to all you GNU enthusiasts heavy workers
 

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.