[v1,1/9] selftests: Line buffer test program's stdout

  The selftests runner pipes the test program's stdout to tap_prefix. The
presence of the pipe means that the test program sets its stdout to be
fully buffered (as aposed to line buffered when directly connected to
the terminal). The block buffering means that there is often content in
the buffer at fork() time, which causes the output to end up duplicated.
This was causing problems for mm:cow where test results were duplicated
20-30x.

Solve this by using `stdbuf`, when available to force the test program
to use line buffered mode. This means previously printf'ed results are
flushed out of the program before any fork().

Signed-off-by: Ryan Roberts <ryan.roberts@arm.com>
---
 tools/testing/selftests/kselftest/runner.sh | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)
  

On Thu, Jul 13, 2023 at 02:54:32PM +0100, Ryan Roberts wrote:
> The selftests runner pipes the test program's stdout to tap_prefix. The
> presence of the pipe means that the test program sets its stdout to be
> fully buffered (as aposed to line buffered when directly connected to
> the terminal). The block buffering means that there is often content in
> the buffer at fork() time, which causes the output to end up duplicated.
> This was causing problems for mm:cow where test results were duplicated
> 20-30x.
> 
> Solve this by using `stdbuf`, when available to force the test program
> to use line buffered mode. This means previously printf'ed results are
> flushed out of the program before any fork().

This is going to be useful in general since not all selftests use the
kselftest helpers but it'd probably also be good to make
ksft_print_header() also make the output unbuffered so that if setbuf
isn't installed on the target system or the tests are run standalone we
don't run into issues there.  Even if the test isn't corrupting data
having things unbuffered is going to be good for making sure we don't
drop any output if the test dies.

> +		if [ -x /usr/bin/stdbuf ]; then
> +			stdbuf="/usr/bin/stdbuf --output=L "
> +		fi

Might be more robust to use type -p to find stdbuf in case it's in /bin
or something?
  

On 13/07/2023 15:16, Mark Brown wrote:
> On Thu, Jul 13, 2023 at 02:54:32PM +0100, Ryan Roberts wrote:
>> The selftests runner pipes the test program's stdout to tap_prefix. The
>> presence of the pipe means that the test program sets its stdout to be
>> fully buffered (as aposed to line buffered when directly connected to
>> the terminal). The block buffering means that there is often content in
>> the buffer at fork() time, which causes the output to end up duplicated.
>> This was causing problems for mm:cow where test results were duplicated
>> 20-30x.
>>
>> Solve this by using `stdbuf`, when available to force the test program
>> to use line buffered mode. This means previously printf'ed results are
>> flushed out of the program before any fork().
> 
> This is going to be useful in general since not all selftests use the
> kselftest helpers but it'd probably also be good to make
> ksft_print_header() also make the output unbuffered 

Yeah sounds reasonable.

> so that if setbuf
> isn't installed on the target system or the tests are run standalone we
> don't run into issues there.  Even if the test isn't corrupting data
> having things unbuffered is going to be good for making sure we don't
> drop any output if the test dies.

Note that currently I've set stdbuf to encourage line buffering rather than no
buffering. Are you saying no buffering is preferred? I took the view that line
buffering is a good middle ground, and and aligns with what people see when
developing and running the program manually in the terminal.

> 
>> +		if [ -x /usr/bin/stdbuf ]; then
>> +			stdbuf="/usr/bin/stdbuf --output=L "
>> +		fi
> 
> Might be more robust to use type -p to find stdbuf in case it's in /bin
> or something?

Yep good idea.
  

On Thu, Jul 13, 2023 at 03:32:19PM +0100, Ryan Roberts wrote:
> On 13/07/2023 15:16, Mark Brown wrote:

> > so that if setbuf
> > isn't installed on the target system or the tests are run standalone we
> > don't run into issues there.  Even if the test isn't corrupting data
> > having things unbuffered is going to be good for making sure we don't
> > drop any output if the test dies.

> Note that currently I've set stdbuf to encourage line buffering rather than no
> buffering. Are you saying no buffering is preferred? I took the view that line
> buffering is a good middle ground, and and aligns with what people see when
> developing and running the program manually in the terminal.

TBH with the way KTAP is specified line buffered and unbuffered are
probably equivalent, I was just defaulting to unbuffered since it's the
more conservative (if less performant for lots of I/O) option.
  

On 13/07/2023 15:16, Mark Brown wrote:
> On Thu, Jul 13, 2023 at 02:54:32PM +0100, Ryan Roberts wrote:
>> The selftests runner pipes the test program's stdout to tap_prefix. The
>> presence of the pipe means that the test program sets its stdout to be
>> fully buffered (as aposed to line buffered when directly connected to
>> the terminal). The block buffering means that there is often content in
>> the buffer at fork() time, which causes the output to end up duplicated.
>> This was causing problems for mm:cow where test results were duplicated
>> 20-30x.
>>
>> Solve this by using `stdbuf`, when available to force the test program
>> to use line buffered mode. This means previously printf'ed results are
>> flushed out of the program before any fork().
> 
> This is going to be useful in general since not all selftests use the
> kselftest helpers but it'd probably also be good to make
> ksft_print_header() also make the output unbuffered so that if setbuf
> isn't installed on the target system or the tests are run standalone we
> don't run into issues there.  Even if the test isn't corrupting data
> having things unbuffered is going to be good for making sure we don't
> drop any output if the test dies.
> 
>> +		if [ -x /usr/bin/stdbuf ]; then
>> +			stdbuf="/usr/bin/stdbuf --output=L "
>> +		fi
> 
> Might be more robust to use type -p to find stdbuf in case it's in /bin
> or something?

Just looking at making this change; run_selftest.sh's shebang is for sh, and
sh's type doesn't support the -p option. So I'm inclined to leave it as is.
There are multiple other places in the script where /usr/bin is hardcoded when
looking for programs too. Shout if you violently disagree.