Subject: Re: Format of test programs' output
To: None <atf-devel@NetBSD.org>
From: Julio M.Merino Vidal <email@example.com>
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:
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
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.
echo 'bar' 1>&2
echo 'bar' 1>&2
echo 'bar' 1>&2
The outputs for the *program* above, which includes the execution of
the three test cases, are (minus the indentation):
tc-end: tc-1, passed
tc-end: tc-2, passed
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
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 <firstname.lastname@example.org>