Looking for an explanation of shell redirect interleaving behavior

Question

Given the following script (t.sh):

#!/bin/bash if [ $# -eq 0 ]; then log() { { if [ $# -gt 0 ]; then printf -- %s\\n "$*" else cat fi } | tee -a logged.out } else log() { if [ $# -gt 0 ]; then printf -- %s\\n "$*" else cat fi } > >(tee -a logged.out) fi declare -xf log : > logged.out ./t2.sh 2>&1 | tee verbose.out 

where t2.sh:

 #!/bin/bash echo outone echo errone >&2 echo logged pipe | log echo outtwo echo errtwo >&2 log logged message echo outthree echo errthree >&2 

I do not understand the difference in output between the two versions of the log function.

The default function (first) does what I want it to correctly interleave stdout, stderr and the log function in the verbose.out file when sending the logged output to logged.out.

The second function, however, incorrectly interleaves the logged output with the output of stdout and stderr and instead seems to delay the logged output, and therefore it ends at the end of the verbose.out file (although this output order is not even consistent, and logged messages are sometimes occur in reverse order at the output, and the first of the messages may appear earlier at the output somewhere).

Correct work:

 $ ./t.sh; more {logged,verbose}.out | cat outone errone logged pipe outtwo errtwo logged message outthree errthree :::::::::::::: logged.out :::::::::::::: logged pipe logged message :::::::::::::: verbose.out :::::::::::::: outone errone logged pipe outtwo errtwo logged message outthree errthree 

Incorrect work:

 $ ./t.sh broken; more {logged,verbose}.out | cat outone errone outtwo errtwo outthree errthree logged message logged pipe :::::::::::::: logged.out :::::::::::::: logged message logged pipe :::::::::::::: verbose.out :::::::::::::: outone errone outtwo errtwo outthree errthree logged message logged pipe 

I am sure that there is a reason for this behavior, I just do not know what it is. Can anyone enlighten me?

Answer 1

Here's a simpler test case. Why

 echo foo | cat echo bar 

print foo followed by bar , and

 echo foo > >(cat) echo bar 

first prints them in reverse order with bar ?

This is because for the pipe, bash expects all stages of the pipeline to complete. To replace the process, the process simply forks and does not wait.

This means that there is a race condition, whether the process substitution command can start, read and process what is written to it before the following statements are executed, and in your case it loses.

You can see this effect more clearly with a simple experiment:

 echo foo | sleep 10 # Waits 10 seconds echo foo > >(sleep 10) # Finishes immediately