tail+grep woes

rihad · 09-16-2021, 11:08 AM

I have the following code:

timeout 10 sh -c 'tail -q -n50 -F /some/file.log | grep -qE foo'

Which is supposed to work as follows: tail fetches the last 50 files from a log file and continues fetching newly written data until a match is found by grep and it silently exits with success (as instructed by the -q flag). This works if tail writes following lines after grep exits, receives SIGPIPE or similar, and the whole pipeline exits with grep's exit status, which is 0. Nice and candy. The problem is that when both of the following are true: a match is found resulting in grep's successful completion AND no more data is written to the log file, tail doesn't know that the reader of the pipeline has exited and continues "watching" the file for new data (as commanded by -F flag) until the timeout of 10 seconds passes and timeout exits with 143 (128+SIGTERM, which is 15).

Is there any way to make the whole pipeline exit immediately with grep's exit code no matter what?

pan64 · 09-16-2021, 12:10 PM

for me:

Code:

mkfifo /tmp/fifo2
tail -q -n50 -F /tmp/fifo2 | grep -qE aaa
# will stop immediately when I do:
echo adsfasdf aaa sdgfaa > /tmp/fifo2

What do you mean by exit immediately? tail -F reads continuously and grep will [wait for and] stop if match found.

rihad · 09-16-2021, 12:52 PM

Quote:

Originally Posted by pan64

for me:

Code:

mkfifo /tmp/fifo2
tail -q -n50 -F /tmp/fifo2 | grep -qE aaa
# will stop immediately when I do:
echo adsfasdf aaa sdgfaa > /tmp/fifo2

What do you mean by exit immediately? tail -F reads continuously and grep will [wait for and] stop if match found.

Thanks for replying, pan64.
Although I'm facing the problem in FreeBSD, it can easily be repeated in Ubuntu using this script:

Code:

#!/bin/sh

trap 'rm -f "$tmp"' EXIT

tmp="$(mktemp)"
[ "$tmp" ] || exit

strings /vmlinuz > "$tmp"
wc -l "$tmp"
for i in `seq 100`; do
  timeout 1 sh -c "tail -q -n$((100*$i)) -F '$tmp' | grep -qE ."
  echo "Exit $? for $((100*$i))"
done

Code:

rihad@rihad:~$ ./sh
50775 /tmp/tmp.Lf3mMRWjwR
Exit 124 for 100
Exit 124 for 200
Exit 124 for 300
Exit 124 for 400
Exit 124 for 500
Exit 124 for 600
Exit 124 for 700
Exit 124 for 800
Exit 124 for 900
Exit 124 for 1000
Exit 124 for 1100
Exit 124 for 1200
Exit 0 for 1300
Exit 0 for 1400
Exit 0 for 1500
Exit 0 for 1600
Exit 0 for 1700
Exit 0 for 1800
Exit 0 for 1900
Exit 0 for 2000
Exit 124 for 2100
Exit 0 for 2200
Exit 0 for 2300
Exit 0 for 2400
Exit 0 for 2500
Exit 0 for 2600
Exit 0 for 2700
Exit 0 for 2800
Exit 0 for 2900
Exit 0 for 3000
Exit 0 for 3100
Exit 0 for 3200
Exit 0 for 3300
Exit 0 for 3400
Exit 0 for 3500
Exit 0 for 3600
Exit 124 for 3700
Exit 0 for 3800
Exit 0 for 3900
Exit 0 for 4000
Exit 0 for 4100
Exit 0 for 4200
Exit 0 for 4300
Exit 0 for 4400
Exit 0 for 4500
Exit 124 for 4600
Exit 124 for 4700
Exit 124 for 4800
Exit 124 for 4900
Exit 124 for 5000
Exit 124 for 5100
Exit 124 for 5200
Exit 124 for 5300
Exit 124 for 5400
Exit 124 for 5500
Exit 124 for 5600
^C
rihad@rihad:~$

In theory the pipeline should always exit 0 if there's at least one nonempty line for grep to match.
In practice the correctness of the exit status depends on whether tail writes anything to its output after grep exits or not.
When it does, we see "Exit 0" above. When it doesn't, we see Exit 124 (which means timeout had to kill the pipeline after 1 second).

GazL · 09-16-2021, 06:22 PM

The problem is that SIGPIPE is only generated when an additional write to a closed listener is attempted.

timeout 10 grep -q aaa <( tail -n 50 -F somefile.log ) seems to work here. exits 0 when found, 124 when timeout.

Give that a go.

rihad · 09-17-2021, 12:35 AM

Quote:

Originally Posted by GazL

The problem is that SIGPIPE is only generated when an additional write to a closed listener is attempted.

timeout 10 grep -q aaa <( tail -n 50 -F somefile.log ) seems to work here. exits 0 when found, 124 when timeout.

Give that a go.

Thanks, unfortunately it also blocks for as long as tail is alive even if a match is found (provided that tail doesn't write anything more):

Code:

$ time timeout 10 bash -c "grep -qE . <(timeout 5 tail -q -n50 -F /path/to/some.log)"

real    0m5.006s
user    0m0.001s
sys     0m0.009s
$ echo $?
0
$

Although in this case the exit code is correct.

pan64 · 09-17-2021, 01:04 AM

Quote:

Originally Posted by rihad

In theory the pipeline should always exit 0 if there's at least one nonempty line for grep to match..

So that may mean there was no nonempty line sent within that second.
Adding to post #4, it is not that simple, because SIGPIPE will be generated later, when grep already exited (and tail still wanted to write into it and its buffer is full). (there was a long thread about it on LQ, but I can't find it).

So you may need to implement it differently, probably using pipe:

Code:

mkfifo /tmp/fifo
timeout 10 grep pattern /tmp/fifo &
save timeout_pid
tail -f logfile > /tmp/fifo &
save tail_pid
wait timeout_pid
you get the exit code of grep/timeout here
kill tail_pid

or you can fully reimplement it in python/perl/whatever

MadeInGermany · 09-17-2021, 02:58 AM

Have the timeout(=kill) close to the tail command

Code:

sh -c "timeout 10 tail ...

rihad · 09-17-2021, 03:12 AM

Quote:

Originally Posted by MadeInGermany

Have the timeout(=kill) close to the tail command

Code:

sh -c "timeout 10 tail ...

That's an excellent idea. I've run a few tests and it seems to be doing the right thing. As a plus it doesn't require bash for its "process substitution" feature, which sometimes leaves fifos lying around (/tmp/sh-np*).

pan64 · 09-17-2021, 04:09 AM

Quote:

Originally Posted by rihad

That's an excellent idea. I've run a few tests and it seems to be doing the right thing. As a plus it doesn't require bash for its "process substitution" feature, which sometimes leaves fifos lying around (/tmp/sh-np*).

That is not that safe:

Code:

timeout 10 tail -f /tmp/fifo2 | grep aaa; echo $?
asdfasdf aaa asd fasdfg
Terminated
143

GazL · 09-17-2021, 04:18 AM

Quote:

Originally Posted by rihad

Thanks, unfortunately it also blocks for as long as tail is alive even if a match is found (provided that tail doesn't write anything more):

Not here: it exits immediately on seeing the match. See attached image.

rihad · 09-17-2021, 05:11 AM

Hmm. In FreeBSD moving "timeout" inside and outside -c consistently behaves differently. WEIRD.

Code:

$ time bash -c "timeout 5 grep -qE end <( tail -q -n50 -F /tmp/in.log )"; echo $?

real    0m0.007s
user    0m0.000s
sys     0m0.005s
0
$ time bash -c "timeout 5 grep -qE end <( tail -q -n50 -F /tmp/in.log )"; echo $?

real    0m0.008s
user    0m0.000s
sys     0m0.006s
0
$ time bash -c "timeout 5 grep -qE end <( tail -q -n50 -F /tmp/in.log )"; echo $?

real    0m0.007s
user    0m0.000s
sys     0m0.005s
0
$ time timeout 5 bash -c "grep -qE end <( tail -q -n50 -F /tmp/in.log )"; echo $?

real    0m5.005s
user    0m0.000s
sys     0m0.006s
124
$ time timeout 5 bash -c "grep -qE end <( tail -q -n50 -F /tmp/in.log )"; echo $?

real    0m5.009s
user    0m0.000s
sys     0m0.006s
124
$

rihad · 09-17-2021, 07:15 AM

Quote:

Originally Posted by pan64

That is not that safe:

Code:

timeout 10 tail -f /tmp/fifo2 | grep aaa; echo $?
asdfasdf aaa asd fasdfg
Terminated
143

You left out -q for grep. Without it grep simply keeps reading its input and printing matching lines until it reaches eof. With -q grep doesn't print anything, but exits successfully on the very first match.

pan64 · 09-17-2021, 07:23 AM

Quote:

Originally Posted by rihad

You left out -q for grep. Without it grep simply keeps reading its input and printing matching lines until it reaches eof. With -q grep doesn't print anything, but exits successfully on the very first match.

you are right