10

Consider the following command: bash -c "echo x; cat 1" | tee 1.

My understanding is that it would fork to a new shell, write x to stdout, write file 1 not found to stderr, exit and return control to the parent process, and write x to stdout and to 1. Hence, I would expect the final output to be x, and the file 1 contains exactly the string x.

However, this is not the case. In actuality, the file 1 usually contains at least two instances of x, and sometimes thousands of lines of xs. On a batch test of running the command ten thousand times, the mean number of xs written to the file was 52.3, and the median was 1. What mechanic is causing this? What probability distribution models this behavior? I suspect that it is conditionally geometric and otherwise uniform.

  • 3
    It has to do with the timing of the execution of the left and right hand side of the pipeline. Both are started simultaneously, or close to it. If tee has opened the file for writing before cat opens it for reading, you may get many x-es in the file. In that case, the "loop" would end whenever cat reads faster than tee writes, reaching the end of the file. – Kusalananda Aug 10 '18 at 18:42
  • From limited testing here, the average number of xs written to the file was of 4.35. I guess it will depends a lot on machine load. – Renan Aug 11 '18 at 0:18
1

This is a very curious one, so I tried to investigate it with the help of strace. Ran your command in a loop 1000 times:

mkdir {000..999}
for i in {000..999}; do
echo $i
(cd $i; strace -f -o trace.log bash -c 'bash -c "echo x; cat 1" | tee 1 >/dev/null'; )
done

Found the file with the most lines (wc -l */1 | sort -nr | head -n2), and checked the corresponding trace.log. I can certainly see lots of:

7567  <... read resumed> "x\n", 8192)   = 2
7567  write(1, "x\n", 2)                = 2
7567  write(3, "x\n", 2)                = 2
7567  read(0,  <unfinished ...>
7568  read(3, "x\n", 131072)            = 2
7568  write(1, "x\n", 2)                = 2
7567  <... read resumed> "x\n", 8192)   = 2
7567  write(1, "x\n", 2)                = 2
7567  write(3, "x\n", 2)                = 2
7567  read(0,  <unfinished ...>
7568  read(3, "x\n", 131072)            = 2
7568  write(1, "x\n", 2)                = 2
7567  <... read resumed> "x\n", 8192)   = 2
7567  write(1, "x\n", 2)                = 2
7567  write(3, "x\n", 2)                = 2
7567  read(0,  <unfinished ...>

Where 7567 is tee 1 and 7568 is cat 1. The two are definitely alternating, so yes, as suspected, this is all about the timing of the execution (and I imagine context switching) of the two commands.

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.