Steps to reproduce: 1) cat > testcase1.sh <<EOF #!/bin/sh ( set -x i=`echo f|cut -d' ' -f4|sort` ) 2>&1 EOF 2) ensure that /bin/sh is dash 3) while true; do ./testcase1.sh > a; grep cut a; done Expected results: 3) since echo, cut and sort are deterministic the output of this program should be determistic too and always just print + cut -d -f4 Actual results: 3) The output of the program seems to be quite non-deterministic: + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut+ d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 cut -d -f4 cut -d -f4 + cut -d -f4 cut -d -f4 cut -d -f4 cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4sort cut -d -f4 + cut -d -f4 cut -d -f4 cut -d -f4 cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4sort + cut -d -f4sort + cut -d -f4sort cut -d -f4 + + cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4sort + cut -d -f4sort + cut -d -f4 cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4 + cut -d -f4sort + cut -d -f4 + cut -d -f4 + cut -d -f4 More info: 1) I do not know if this behavior is a bug or not but I think it at least should be documented in the manual page. 2) I built dash git revision 72811e307d07c8e5902a7f73ea6491eabb93a4ce and was able to reproduce the behavior with it. 3) Suggested improvement to manual page: diff --git a/src/dash.1 b/src/dash.1 index c7771d0..82b8c8e 100644 --- a/src/dash.1 +++ b/src/dash.1 @@ -228,6 +228,11 @@ Write each command to standard error (preceded by a .Sq +\ ) before it is executed. Useful for debugging. +However, note that debugging output from +subshells can get mixed with parent's debugging output in a +non-deterministic fashion. This can lead to lines with two +.Sq \+ +prefixes or no prefixes at all. .It Fl I Em ignoreeof Ignore EOF's from input when interactive. .It Fl i Em interactive 4) Non-determinism is a problem when one wants to compare huge "set -x logs" of a program P on machines A and B to figure out why P works on A but does not work on B. It took me a long time to figure out that if I run the program multiple times I sometimes get different results. 5) This non-determinism also happens on a non-SMP armel system so it is not related to SMP. 6) If the whole line was printed with a single syscall the probability of getting mixed lines would be much lower (bash seems to print the whole line with a single syscall but dash apparently tries to save memory by printing it in small pieces).
This behaviour is easy to observe with the following command line: $ rm -f daao.*; strace -ff -o daao dash -c 'set -x; z=`echo | cut -f1 | sort`' and then $ grep write daao.* daao.6716:write(2, "+ ", 2) = 2 daao.6716:write(2, "z=", 2) = 2 daao.6716:write(2, "\n", 1) = 1 daao.6718:write(2, "+ ", 2) = 2 daao.6718:write(2, "echo", 4) = 4 daao.6718:write(2, "\n", 1) = 1 daao.6718:write(1, "\n", 1) = 1 daao.6719:write(2, "+ ", 2) = 2 daao.6719:write(2, "cut", 3) = 3 daao.6719:write(2, " -f1", 4) = 4 daao.6719:write(2, "\n", 1) = 1 daao.6719:write(1, "\n", 1) = 1 daao.6720:write(2, "+ ", 2) = 2 daao.6720:write(2, "sort", 4) = 4 daao.6720:write(2, "\n", 1) = 1 daao.6720:write(1, "\n", 1) = 1 The subshells in pipeline prints their own commands before executing it, using multiple syscalls giving possibility of intermixed output when context switches happen in between... For comparison this is what bash gives: zao.6858:write(2, "+ z=\n", 5) = 5 zao.6860:write(2, "++ echo\n", 8) = 8 zao.6860:write(1, "\n", 1) = 1 zao.6861:write(2, "++ cut -f1\n", 11) = 11 zao.6861:write(1, "\n", 1) = 1 zao.6862:write(2, "++ sort\n", 8) = 8 zao.6862:write(1, "\n", 1) = 1 An alternative to concatenate strings to a buffer before writing one could try using gather write with writev() (I don't know the SMOP factor there as I did not peek the dash source code :) Tomi
Just FYI, there is a simple patch (mostly) fixing this problem now at https://salsa.debian.org/debian/dash/merge_requests/7 VZ