Subject: Re: Format of test programs' output
To: None <atf-devel@NetBSD.org>
From: Julio M.Merino Vidal <jmmv84@gmail.com>
List: atf-devel
Date: 08/26/2007 12:04:32
On Aug 25, 2007, at 4:03 PM, Julio M. Merino Vidal wrote:

> As regards stdout and stderr, it is important to separate the  
> output generated by each test case (if any) for reporting  
> purposes.  E.g. when a test case fails, we want to show all its  
> output to the user (read, developer) for diagnosis purposes.  I  
> haven't found any way to synchronize different streams with each  
> other... so I force test programs to print "__atf_tcs_separator__"  
> on a line of its own when they have finished.

Let me elaborate some more on this point, because it can be difficult  
to see the real need for this.  (This has nothing to do with parallel  
execution of test cases/programs, by the way, which is not yet  
implemented and won't be for a long while.)

A test program has three outputs:
1) stdout
2) stderr
3) the results output, which I call resout

1 and 2 are there because we are talking of a program, and a program  
always has those two outputs.  We cannot impose a test program to not  
send any message to stderr because that is very difficult to  
control.  Specially if the program is written in shell, where you  
launch all kinds of external utilities.  And even in this last case,  
any messages sent to stderr will surely be useful for debugging  
purposes.

3 is where the test program writes a summary of the results of each  
test case in a machine-parseable format.  This is, by default, sent  
to stdout, but can be tuned through the '-r' flag of a test program.   
The reason for this default is that launching a test program from the  
console by hand will show meaningful information, but that default is  
never used internally.  atf-run always uses '-r9' to separate the  
machine-parseable data from the stdout information.

Now imagine a test program with three test cases, each of which sends  
some message to stdout and stderr, and all of them are successful.   
For example:

-----
tc-1:
     echo 'foo'
     echo 'bar' 1>&2
tc-2:
     echo 'foo'
     echo 'bar' 1>&2
tc-3:
     echo 'foo'
     echo 'bar' 1>&2
-----

The outputs for the *program* above, which includes the execution of  
the three test cases, are (minus the indentation):

stdout:
     foo
     foo
     foo
stderr:
     bar
     bar
     bar
resout:
     tcs-cout: 3
     tc-start: tc-1
     tc-end: tc-1, passed
     tc-start: tc-2
     tc-end: tc-2, passed
     tc-start: tc-3
     tc-end: tc-3, passed

The question is... how do you match each line of stdout and stderr to  
the test cases described in resout?  You can't without the separator.

Try to imagine how a program (atf-run) has to read the above three  
descriptors.  To read more than one you have to use poll (or select,  
or kqueue, but it does not matter).  It will start reading resout  
waiting for a tc-start line.  When the tc-start line arrives, it  
knows that everything that arrives from now on through its stdout and  
stderr, until the matching tc-end, will be part of that specific test  
case.  So far, so good...

But, and this is the big but, tc-start/tc-end pairs are sent to a  
descriptor that is completely separate from stdout/stderr, so you  
cannot guarantee any ordering between them as regards *reading*.  The  
system will do buffering on these which prevents any synchronization  
from the point of view of the reader.  Imagine it in another way: if  
you were presented the three streams all at once, would you be able  
to deduce which parts of stdout/stderr belong to each test case?  No.

By having the separators, reading the three descriptors is easy:
1) Wait for tc-start on resout.
2) Poll stdout and stderr.
3) Fetch any line sent to stdout and stderr until they receive the
    separator or eof.
4) Wait for tc-end on resout.
5) Repeat 1.

There you go: now you have the exact output of each test case matched  
with it.

Of course we could send the tc-start and tc-end messages both to  
stdout and stderr, but I don't like that.  Polluting these two  
streams with magic strings is not something I like...

Another possibility could be to monitor, from *within* the test  
program, what the test cases send to stdout and stderr and multiplex  
those two descriptors into resout (as atf-run does later on),  
effectively making stdout and stderr silent without losing data.   
However, I feel that adds much more logic to the test programs, which  
is specially difficult to achieve in the shell case...

Hope it is clearer now.

-- 
Julio M. Merino Vidal <jmmv84@gmail.com>