2

I am using pipelines to implement some functionality with bash on Centos 6. During these pipes I want to export my data in a log file, but this data comes from different pipes in my pipeline and I want to differentiate between them, by injecting a tag before each log line. To be more precise I want to do the following:

COMMAND1 | (create a line in the log file like: "command1: " + output of the command) | COMMAND2 ...

After doing a lot of research, I reached the following point:

COMMAND1 | tee >(ifne echo -n "command1: " >> out.log) | tee -a out.log | COMMAND2

This worked but with a problem. The second tee writes first to the file and then writes the first tee. So I get:

(output of command 1)
command1:

instead of

command1: (output of command 1)

I suspect that ifne delays enough for the second tee to be executed before the first one. If I remove the ifne, it works fine. The problem is that I need the ifne, because I often have null output, that I don't want to log.

How can I make the second tee wait for the first one to finish?

Gilles 'SO- stop being evil'
  • 829,060
Stefanos Kargas
  • 133
  • 1
    Commands in a pipeline are always started concurrently. If you don't want this, then you would have to not use a pipeline. – Kusalananda Mar 06 '19 at 13:18

1 Answers1

4

If I understand correctly, you want to log the output of COMMAND1 with a marker indicating that it comes from COMMAND1. Here's a way to do that:

COMMAND1 | tee >(sed 's/^/command1: /' >>out.log) | COMMAND2

Note that:

  • This puts the command1: marker at the beginning of each line, not just at the beginning of the first line, which I think is desirable but isn't what you seemed to be trying to do.
  • command1 must not contain any sed special characters (or else they need to be protected with a backslash).
  • Since out.log is opened for appending, there's no risk that output will overlap even if multiple commands output to the same log file in parallel.
  • Since out.log is only opened once in this snippet, all the lines will be in order.

  • Now for the bad news: if you log to the same file multiple times in parallel, then there's no guarantee that the lines will appear in the desired order. For example,

    echo hello | tee >(sed 's/^/command1: /' >>out.log) | tr a-z A-Z | tee >(sed 's/^/command2: /' >>out.log)

    may log command2: HELLO before command1: HELLO.

  • If you log to the same file multiple times in parallel, and the content of a line is too long, then lines from different instances may be interspersed. I think that common sed implementations will pass through lines that are less than PIPE_BUF bytes long, but I'm not sure.

Given the ordering and atomicity limitations, I recommend logging to separate files, in which case you don't need the prefixes.

Gilles 'SO- stop being evil'
  • 829,060
  • It works, but indeed it doesn't save the lines in the correct order. Also it seems as if the log of the first command sometimes holds until the second command finishes. In this case I have the log of the second command first and after killing the second command, I get the log of the first command. I might need to find another solution. Actually the first command provides me an input for the second command which creates an output. I want to be able to map input-output in the same log file. – Stefanos Kargas Mar 08 '19 at 08:48
  • @StefanosKargas I still don't know what you define as “correct order”, but if your complaint is that the log of command1 appears later than you expect, turn off buffering. – Gilles 'SO- stop being evil' Mar 08 '19 at 09:10