17

I have a program whose output I redirect to a log file:

./my_app > log

I would like to clear (i.e. empty) the log from time to time (on demand) and tried various things like

cat "" > log

However it always seems that the original pipe is then disrupted and the program doesn't redirect its output to the log file anymore.

Is there some way to do that?

Update

Note that I cannot modify the application producing the output. It just spits it out to stdout and I want to save it in a log so that I can inspect it when I need it, and clear it when I want. However I shouldn't need to restart the application.

6
  • that's why you usually use a logging daemon to log things...
    – Kiwy
    Apr 3, 2014 at 10:54
  • @Kiwy can you elaborate on how that would solve the problem?
    – bangnab
    Apr 3, 2014 at 11:15
  • well you usually use a log daemon or let your app handle the log, because writing things to output and redirecting it is not reliable. you should take a look at syslogd or logrotate
    – Kiwy
    Apr 3, 2014 at 11:21
  • 2
    Do things work if you do ./my_app >> log (to force appending) and cp /dev/null log to truncate it? Apr 3, 2014 at 14:32
  • 1
    What error message do you get? What behavior do you see? "Doesn't redirect its output to the log file anymore" isn't very specific. Also, cat "" > log isn't a valid cat command since there's no file called "".
    – Mikel
    Apr 3, 2014 at 15:52

5 Answers 5

15

Another form of this problem occurs with long running applications whose logs are periodically rotated. Even if you move the original log (e.g., mv log.txt log.1) and replace it immediately with a file of the same name before any actual logging occurs, if the process is holding the file open, it will either end up writing to log.1 (because that may still be the open inode) or to nothing.

A common way to deal with this (the system logger itself works this way) is to implement a signal handler in the process which will close and reopen its logs. Then, when ever you want to move or clear (by deleting) the log, send that signal to the process immediately afterward.

Here's a simple demonstration for bash -- forgive my cruddy shell skills (but if you are going to edit this for best practices, etc., please make sure you understand the functionality first and test your revision before you edit):

#!/bin/bash

trap sighandler INT

function sighandler () {
    touch log.txt
    exec &> log.txt
}

echo $BASHPID
exec &> log.txt

count=0;
while [ $count -lt 60 ]; do
    echo "$BASHPID Count is now $count"
    sleep 2
    ((count++))
done          

Start this by forking into the background:

> ./test.sh &
12356

Notice it reports its PID to the terminal and then begins logging to log.txt. You now have 2 minutes to play around. Wait a few seconds and try:

> mv log.txt log.1 && kill -s 2 12356

Just plain kill -2 12356 may work for you here too. Signal 2 is SIGINT (it's also what Ctrl-C does, so you could try this in the foreground and move or remove the logfile from another terminal), which the trap should trap. To check;

> cat log.1
12356 Count is now 0
12356 Count is now 1
12356 Count is now 2
12356 Count is now 3
12356 Count is now 4
12356 Count is now 5
12356 Count is now 6
12356 Count is now 7
12356 Count is now 8
12356 Count is now 9
12356 Count is now 10
12356 Count is now 11
12356 Count is now 12
12356 Count is now 13
12356 Count is now 14

Now let's see if it is still writing to a log.txt even though we moved it:

> cat log.txt
12356 Count is now 15
12356 Count is now 16
12356 Count is now 17
12356 Count is now 18
12356 Count is now 19
12356 Count is now 20
12356 Count is now 21

Notice it kept going right where it left off. If you don't want to keep the record simply clear the log by deleting it

> rm -f log.txt && kill -s 2 12356

Check:

> cat log.txt
12356 Count is now 29
12356 Count is now 30
12356 Count is now 31
12356 Count is now 32
12356 Count is now 33
12356 Count is now 34
12356 Count is now 35
12356 Count is now 36

Still going.

You can't do this in a shell script for an executed subprocess, unfortunately, because if it is in the foreground, bash's own signal handlers (traps) are suspended, and if you fork it into the background, you can't reassign its output. I.e., this is something you have to implement in your application.

However...

If you can't modify the application (e.g., because you did not write it), I have a CLI utility you can use as an intermediary. You could also implement a simple version of this in a script which serves as a pipe to the log:

#!/bin/bash

trap sighandler INT

function sighandler () {
    touch log.txt
    exec 1> log.txt
}

echo "$0 $BASHPID"
exec 1> log.txt

count=0;
while read; do
    echo $REPLY
done  

Let's call this pipetrap.sh. Now we need a separate program to test with, mimicking the application you want to log:

#!/bin/bash

count=0
while [ $count -lt 60 ]; do
    echo "$BASHPID Count is now $count"
    sleep 2
    ((count++))
done           

That will be test.sh:

> (./test.sh | ./pipetrap.sh) &
./pipetrap.sh 15859

These are two separate processes with separate PIDs. To clear test.sh's output, which is being funnelled through pipetrap.sh:

> rm -f log.txt && kill -s 2 15859

Check:

>cat log.txt
15858 Count is now 6
15858 Count is now 7
15858 Count is now 8

15858, test.sh, is still running and its output is being logged. In this case, no modifications to the application are needed.

4
  • Thanks for the nice explanations. However in my case I cannot modify the application to implement your solution.
    – bangnab
    Apr 3, 2014 at 12:38
  • 2
    If you can't implement a signal handler in your application (because you can't modify it period), you can use this technique to pipe the log through a signal trap -- see the stuff after "However..."
    – goldilocks
    Apr 3, 2014 at 12:56
  • Ok I'll give it a try and let you know how it went.
    – bangnab
    Apr 3, 2014 at 14:11
  • I finally have a CLI app written in C for this (sorry it took a bit longer than originally intended): cognitivedissonance.ca/cogware/pipelog
    – goldilocks
    Apr 28, 2014 at 13:44
11

TL;DR

Open your log file in append mode:

cmd >> log

Then, you can safely truncate it with:

: > log

Details

With a Bourne-like shell, there are 3 main ways a file can be open for writing. In write-only (>), read+write (<>) or append (and write-only, >>) mode .

In the first two, the kernel remembers the current position you (by you, I mean, the open file description, shared by all the file descriptors that have duplicated or inherited it by forking from the one you opened the file on) are into the file.

When you do:

cmd > log

log is open in write-only mode by the shell for the stdout of cmd.

cmd (its initial process spawned by the shell and all the possible children) when writing to their stdout, write at the current cursor position held by the open file description they share on that file.

For instance, if cmd initially writes zzz, the position will be at byte offset 4 into the file, and the next time cmd or its children write to the file, that's where the data will be written regardless of whether the file has grown or shrunk in the interval.

If the file has shrunk, for instance if it has been truncated with a

: > log

and cmd writes xx, those xx will be written at offset 4, and the first 3 characters will be replaced by NUL characters.

$ exec 3> log # open file on fd 3.
$ printf zzz >&3
$ od -c log
0000000   z   z   z
0000003
$ printf aaaa >> log # other open file description -> different cursor
$ od -c log
0000000   z   z   z   a   a   a   a
0000007
$ printf bb >&3 # still write at the original position
$ od -c log
0000000   z   z   z   b   b   a   a
0000007
$ : > log
$ wc log
0 0 0 log
$ printf x >&3
$ od -c log
0000000  \0  \0  \0  \0  \0   x
0000006

That means you cannot truncate a file that has been open in write-only mode (and that's the same for read+write) as if you do, processes that had file descriptors open on the file, will leave NUL characters at the beginning of the file (those, except on OS/X, usually don't take space on disk though, they become sparse files).

Instead (and you'll notice most applications do that when they write to log files), you should open the file in append mode:

cmd >> log

or

: > log && cmd >> log

if you want to start on an empty file.

In append mode, all writes are made at the end of the file, regardless of where the last write was:

$ exec 4>> log
$ printf aa >&4
$ printf x >> log
$ printf bb >&4
$ od -c log
0000000   a   a   x   b   b
0000005
$ : > log
$ printf cc >&4
$ od -c log
0000000   c   c
0000002

That's also safer as if two processes have open (in that way) the file by mistake (as for instance if you've started two instances of the same daemon), their output will not overwrite each other.

On recent versions of Linux, you can check the current position and whether a file descriptor has been open in append mode by looking at /proc/<pid>/fdinfo/<fd>:

$ cat /proc/self/fdinfo/4
pos:        2
flags:      0102001

Or with:

$ lsof +f G -p "$$" -ad 4
COMMAND  PID USER   FD   TYPE  FILE-FLAG DEVICE SIZE/OFF     NODE NAME
zsh     4870 root    4w   REG 0x8401;0x0 252,18        2 59431479 /home/chazelas/log
~# lsof +f g -p "$$" -ad 4
COMMAND  PID USER   FD   TYPE FILE-FLAG DEVICE SIZE/OFF     NODE NAME
zsh     4870 root    4w   REG   W,AP,LG 252,18        2 59431479 /home/chazelas/log

Those flags correspond to the O..._ flags passed to the open system call.

$ gcc -E - <<< $'#include <fcntl.h>\nO_APPEND O_WRONLY' | tail -n1
02000 01

(O_APPEND is 0x400 or octal 02000)

So the shell's >> opens the file with O_WRONLY|O_APPEND (and 0100000 here is O_LARGEFILE which is not relevant to this question) while > is O_WRONLY only (and <> is O_RDWR only).

If you do a:

sudo lsof -nP +f g | grep ,AP

to search for files open with O_APPEND, you'll find most log files currently open for writing on your system.

2
  • Why do you use the : (colon) in : > ?
    – mvorisek
    Jun 30, 2018 at 12:57
  • 2
    @Mvorisek, that's to redirect the output of command that produces no output: :. Without a command, the behaviour varies between shells. Jun 30, 2018 at 12:59
1

If I'm understanding correctly, tee seems like a reasonable approach:

$ ./myapp-that-echoes-the-date-every-second | tee log > /dev/null &
[1] 20519
$ head log
Thu Apr  3 11:29:34 EDT 2014
Thu Apr  3 11:29:35 EDT 2014
Thu Apr  3 11:29:36 EDT 2014
$ > log
$ head log
Thu Apr  3 11:29:40 EDT 2014
Thu Apr  3 11:29:41 EDT 2014
Thu Apr  3 11:29:42 EDT 2014
1

As fast solution you can use a log with rotation (daily rotation for example):

date=`date +%Y%m%d`
LOGFILE=/home/log$date.log

and redirect logging to it ./my_app >> log$date.log

1
  • I'd like to be able to rotate on demand. This is actually a log that is produced during an automated test and I would like to clear it before running the test.
    – bangnab
    Apr 3, 2014 at 12:30
0

This is a problem that has long been solved with syslog (in all it's variants) but there are two tools that would solve your particular problem with a minimum of effort.

The first, more portable but less versatile solution is logger (a must have for any administrators toolbox). It is a simple utility that copies standard input to syslog. (passing the buck, and making file rotation the problem of logrotate and syslog)

The second, more elegant but less portable solution is syslog-ng which in addition to accepting log messages from the standard syslog sockets can execute programs which output is filtered through the logger. (I have not used this feature yet, but it looks perfect for what you are wanting to do.)

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .