Re: Separating stdout and stderr

[Christophe Lyon]

On 31 March 2016 at 11:06, Maxim Kuvyrkov <address@hidden> wrote:
> On Mar 30, 2016, at 6:36 PM, Christophe Lyon <address@hidden> wrote:
>>
>> On 30 March 2016 at 15:44, Maxim Kuvyrkov <address@hidden> wrote:
>>> Hi Ben,
>>> Hi Christophe,
>>>
>>> [TL;DR] Will it be a problem for dejagnu to merge test's stderr into stderr 
>>> with an equivalent of bash's 2>&1 ?
>>>
>>> From my investigations of the sanitizer testsuite, it seems to be hitting 
>>> several unrelated issues in DejaGnu.  Ben's patch is addressing one of 
>>> those, but there is at least one other issue that also related to handling 
>>> of stdout and stderr.
>>>
>>> The sanitizer testsuite is maintained as part of LLVM project, and it is 
>>> using a different testing framework.  In the LLVM copy of the sanitizer 
>>> testsuite every testcase has an annotation to call itself with stderr 
>>> merged into stdout via 2>&1 shell syntax.  This is done [at least in part] 
>>> to avoid races between output to stdout and stderr streams.  [Note that 
>>> tests tend to print using printf, while sanitizer libraries print to stderr 
>>> with fprintf.]
>>>
>>> Dejagnu, on the other hand, seems to be giving the test process separate 
>>> stdout and stderr streams, and then merges the output from the two 
>>> internally.  This causes non-determinism in output due to races in how 
>>> kernel flushes the two streams.
>>>
>>> I understand that this is, primarily, an issue with the test itself, and, 
>>> indeed, it can be avoided by the test using exclusively stderr or 
>>> exclusively stdout, but I don't think any dejagnu testsuite is relying on 
>>> separate stdout and stderr.  So maybe we should just merge the two?
>>>
>>
>> In our current setup, we are using ssh.exp (a variant of rsh.exp) to
>> connect to the board where the tests are executed.
>> I've noticed that at least for the sanitizers tests, and probably most
>> of the others, we do:
>> if { $inp == "" } {
>>     set inp "/dev/null"
>> }
>>
>> which in turn means that local_exec will choose to:
>> set outp "|& cat"
>>
>> So in practice, we currently execute:
>> ssh board sh -c '/tmp/TEST.exe \; echo XYZ\${?}ZYX' < /dev/null |& cat
>> which merges stdout & stderr on the local machine.
>
> So should we be doing instead
>
> ssh board sh -c '/tmp/TEST.exe 2>&1\; echo XYZ\${?}ZYX' < /dev/null |& cat
>
> ?
>
We can try that, yes.

>>
>> Interestingly, I replaced "|& cat" with "2>/dev/null" in local_exec
>> (right before calling open, and just before leaving local_exec when
>> building the output value), and the asan test I'm using as a candidate
>> still passes. It does send its output to stderr, so I expected the test
>> to fail given its output was discarded.
>>
>> Any idea why stderr it still reaching dejagnu?
>
> Isn't stderr of ssh process merged into stdout of ssh process?  The [remote] 
> test then gets two separate file descriptors for stdout and stderr, and the 
> data from those is merge on the dejagnu side and this is why the test's 
> stderr output is present on dejagnu's stdout.
>

It seems that the remote stdout/stderr are merged by tcl, rather than
dejagnu, since replacing "|&cat" in dejagnu with "2>/dev/null" does
not discard the remote stderr contents.

> Note, that merging stdout and stderr of the ssh process (as opposed to 
> merging stdout and stderr of the test process on the remote side) will not 
> avoid the flush race.
Indeed, that's why I wanted to separate the two streams.


> --
> Maxim Kuvyrkov
> www.linaro.org
>
>