Re: [PATCH v4 3/3] parallel-tests: allow each test to have multiple results

[Stefano Lattarini]

On Monday 20 June 2011, Ralf Wildenhues wrote:
> * Stefano Lattarini wrote on Fri, Jun 17, 2011 at 09:33:13AM CEST:
> > On Friday 17 June 2011, Ralf Wildenhues wrote:
> > 
> > > Actually, why not s/testcase/test/g globally in all your text.
> > >
> > Because I'm trying to make a distinction between test scripts and
> > test cases.  With the new interface, a single test script can contain
> > multiple testcases, and thus have multiple test results.  It is a
> > simple concept, but not immediate to get for someone who was used
> > the older Automake tests drivers (which obeyed the principle "one
> > test script, one test result", so that you could call a test script
> > also a "testcase", or simply a "test", without risk of confusion.
> 
> As I said, use the name other testsuite environments use.
> :test-result: seems better.
>
That's what I had already done in my previous squash-in.  In the attached
squash-in, I've removed few more uses of the "test case" terminology, when
the use the simpler term "test" was just as clear.  I guess that a follow
up will be required where we remove ambiguous or unclear uses of the
"test", "test case" and "test script" terms from the manual.

> > > > (EXTRA_DIST): Distribute `ostp-driver'.
> > > > (test-driver-custom-multitest.log): Depend on `ostp-driver'.
> > > > (test-driver-custom-multitest-recheck.log): Likewise.
> > > > (test-driver-custom-multitest-recheck2.log): Likewise.
> > > > (test-driver-custom-html.log): Likewise.
> > > > * doc/automake.texi (API for Custom Test Drivers): Update (still
> > > > in Texinfo comments only).
> > > 
> > > I don't like TODO and comments stuff in finished patches documentation
> > > if we can help it (and here, we surely can).
> > >
> > While I mostly agree, I'd like to point out that I had already rewritten
> > and revesited the documentation several times, and after some point you
> > risk more harm than good in tweaking and re-shaping the same text again;
> > also, you're somewhat fed up with it, so that the risk of becoming sloppy
> > or of producing confused text increases.  I'll fix the TODOs in this patch
> > if you insist, but honestly I'd rather to that in a follow-up patch if
> > possible.
> 
> Why not just split the whole documentation change into a followup patch
> then?
>
Because that would only postpone, not avoid, the continous tweaking and
amending the documentation; what I'd like instead is to improve it
organically and incrementally, in separate patches; i.e., commit a sketchy
but correct (even if incomplete) documentation first, and then improve it
with follow-ups (maybe handling one concept or one part at the time).

> > > >  @b{TODO!}  @i{Options and flags that the driver must handle.  
> > > > Generation
> > > > -of ``.log'' files.  Console output the driver is expected to produce.
> > > > -Support for colored output, XFAIL_TESTS, and DISABLE_HARD_ERRORS}
> > > > +of ``.log'' files, and format they must obey.  Console output the 
> > > > driver
> > > 
> > > @file{.log}
> > > 
> > > You should almost never need to use ``...'' in texinfo, at least not for
> > > any entity that has a meaning in code.
> > >
> > Note that this hunk is just temporary, and bounded to be removed by 
> > follow-up
> > patches that will (or would have) completed the TODOs.
> 
> See above.
> 
> > > > address@hidden    executes two test cases, one successful and one 
> > > > failing, and skip
> > > > address@hidden    another test case, the driver should end up writing 
> > > > the following
> > > > address@hidden    in the test log:
> > > > address@hidden      :am-testcase-result: PASS [passed testcase name or 
> > > > details]
> > > > address@hidden      :am-testcase-result: FAIL [failed testcase name or 
> > > > details]
> > > > address@hidden      :am-testcase-result: SKIP [skipped testcase name or 
> > > > details]
> > > 
> > > is the [...] literal or metasyntactic?
> > >
> > Metasyntactic.
> > 
> > > Please use proper notation here.
> > >
> > What would that be?  Sorry if it's a stupid question, but my grasp of
> > Texinfo is still pretty limited.
> 
> @example would seem appropriate.
> 
> > > > address@hidden    The above lines (each of which *must* be followed by 
> > > > a blank line
> > > > address@hidden    in order for the HTML output generation to work) are 
> > > > used only
> > > > address@hidden    when generating the `test-suite.log' from the 
> > > > individual test
> > > 
> > > See above.
> > >
> > About what exactly?
> 
> @file{test-suite.log}
> 
> > > > +         results2=`sed -n "s/^$$rst_magic[     ]*//p" $$list2`; \
> > > 
> > > tab space
> > >
> > That's deliberate, we don't want to be too strict in parsing user's
> > output (or in this case, third-party drivers output).
> 
> Sorry.  I just meant the tab should come before the space, not after.
> My editor highlights the space otherwise (which, granted, is a
> limitation in the highlighting rule, but also helps prevent other
> editors, human or programmatic, to mangle the code in an unwanted way).
>
OK, fixed.

> > > > +"$@" 2>&1 | tee $tmp_out | (
> > > > +  i=0 st=0
> > > > +  : > $tmp_res
> > > > +  while read line; do
> > > > +    case $line in
> > > > +      PASS:*|FAIL:*|XPASS:*|XFAIL:*|SKIP:*)
> > > > +        i=`expr $i + 1`
> > > > +        result=`LC_ALL=C expr "$line" : '\([A-Z]*\):.*'`
> > > 
> > > This will be quite fork expensive, if done in real-world code.
> > >
> > But this is in a script used only for testing.  I don't think
> > it's worth optimizing it.
> 
> No, it's not, but your real scripts won't look all that different.
> Besides, why not do it right the first time?
>
I still don't see the point this honestly, but I've thrown in a couple
optimizations for bash, zsh and XSI shells (see attached squash-in).
Is that enough?

> > > Might just want to use one single sed script replacing this
> > > while while loop.
> > > 
> > > But then again, measuring is king.
> > >
> > And BTW, "premature optimization is the root of all evil" ;-)
> 
> True.  If we'd "do it right the first time" then there would be no need
> to fix efficiency regressions afterwards.
> 
> I don't actually care much about micro optimizations like the above at
> this point, but I do care when the whole set of code changes will
> introduce a factor of 2 slowdown in the test suite overhead.  It looks
> like it may eventually, judging from your measurements done, and that's
> what I am trying to prevent.  On w32, that would cause real pain.
>
But maybe it would be worth trying to instead optimize stuff like
$(am__check_pre) and $(am__vpath_adj_setup), where we could trim
extra forks in the case of XSI shells or bash.  I.e., optimize an
existing and tested implementation instead of holding back a
promising design due to *possible* future performance problems.

Also, "execing" the test driver in check2.am instead of "spawning" it
could avoid an expensive fork.  But we should then test at configure
time that $SHELL can gracefully handle such "execing" w.r.t. the use
of $(TESTS_ENVIRONMENT); i.e., that an usage like:
  "9>&2 foo=bar exec sh -c 'echo $foo >&9'"
does the expected thing (hint: it does with dash, bash, zsh, NetBSD
/bin/sh and Debian ksh; it doesn't with Solaris /bin/ksh and /bin/sh).

> > I agree that we should improve my code for speed later (after all, we
> > expect it to be used in so many place that developer's time invested
> > into making it faster should be well invested).  But first I say we
> > should get the behaviour, interfaces and testsuite additions right.
> 
> We should get the design right.  If the design cannot be reasonably
> fast, then we'll abandon it, and that also means making sure it's not
> too bad.
>
> Just compare with dejagnu for a second, to realize that it starts a
> guessed 20 times as many tests per second as the Automake test driver
> does.
>
> That's already very bad.  Making it worse will not make the
> driver look appealing.
>
See above.

Regards,
  Stefano

diff --git a/ChangeLog b/ChangeLog
index 0a3b021..e011191 100644
--- a/ChangeLog
+++ b/ChangeLog
@@ -5,11 +5,12 @@
        global log and the console testsuite summary to make it able to
        grasp multiple results per test script.  This is required in order
        to introduce the planned support for test protocols, like TAP and
-       SubUnit, which can run multiple testcases per test script.
+       SubUnit, which can indeed run multiple tests per test script, each
+       with its individual result.
        The implementation makes use of a custom reStructuredText field
        `:test-result:'.
        * lib/check.am ($(TEST_SUITE_LOG)): When processing .log files,
-       recognize a testcase result report only if it is declared with
+       recognize a report of a test's result only if it is declared with
        the custom `:test-result:' reStructuredText field placed at the
        beginning of a line.  Extend and add explanatory comments.
        (recheck, recheck-html): Add explanatory comments.
diff --git a/doc/automake.texi b/doc/automake.texi
index e66c847..19432f9 100644
--- a/doc/automake.texi
+++ b/doc/automake.texi
@@ -9093,25 +9093,25 @@ DISABLE_HARD_ERRORS.}
 @c    driver can use temporary files if it needs to, only it should clean
 @c    them up properly).
 @c
address@hidden  * The result of each testcase run by a test script/program 
*must*
address@hidden  * The result of each test run in a test script/program *must*
 @c    be registered in the test log using a custom reStructuredText
 @c    field ``test-result''.  For example, if the test script executes
 @c    two test cases, one successful and one failing, and skip another
 @c    test case, the driver should end up writing the following in the
 @c    test log:
address@hidden      :test-result: PASS [passed testcase name or details]
address@hidden      :test-result: FAIL [failed testcase name or details]
address@hidden      :test-result: SKIP [skipped testcase name or details]
address@hidden      :test-result: PASS [name of passed test, and/or details 
about it]
address@hidden      :test-result: FAIL [name of failed test, and/or details 
about it]
address@hidden      :test-result: SKIP [name of skipped test, and/or details 
about it]
 @c    The above lines (each of which *must* be followed by a blank line
 @c    in order for the HTML output generation to work) are used only
 @c    when generating the `test-suite.log' from the individual test
 @c    logs, and can be placed in any order and position within the logs
 @c    itself.
 @c
address@hidden  * The result of each testcase run by a test script/program 
*must*
address@hidden    be registered by the test driver in the *first* line of the 
test
address@hidden    log (FIXME: this seems too strict; maybe we could use another
address@hidden    custom reStructuredText directive instead?).  This line is 
used by
address@hidden  * The global result of a test script/program *must* be 
registered
address@hidden    by the test driver in the *first* line of the test log
address@hidden    (FIXME: this seems too strict; maybe we could use another 
custom
address@hidden    reStructuredText directive instead?).  This line is used by
 @c    the "recheck" target.  A test will be considered failed by this
 @c    target, and thus to be re-run, if the first line in its log file
 @c    begins with either `FAIL' or `XPASS'.
diff --git a/lib/am/check.am b/lib/am/check.am
index 3171688..062c59c 100644
--- a/lib/am/check.am
+++ b/lib/am/check.am
@@ -154,7 +154,7 @@ $(TEST_SUITE_LOG): $(TEST_LOGS)
 ## Extract the outcome of all the testcases from the test logs.
        results2=''; \
        if test -n "$$list2"; then \
-         results2=`sed -n "s/^$$rst_magic[     ]*//p" $$list2`; \
+         results2=`sed -n "s/^$$rst_magic[      ]*//p" $$list2`; \
        fi; \
 ## Prepare the test suite summary.
        results=`echo "$$results1" && echo "$$results2"` \
diff --git a/tests/trivial-test-driver b/tests/trivial-test-driver
index f06eb1c..c840d62 100644
--- a/tests/trivial-test-driver
+++ b/tests/trivial-test-driver
@@ -31,6 +31,16 @@
 # Help to avoid typo-related bugs.
 set -u
 
+# For minor optimizations, later.
+if test -n "${BASH_VERSION-}${ZSH_VERSION-}"; then
+  is_xsi_shell=yes
+elif (eval 'test $((1+1)) = 2 && foo=a:b:c && test ${foo%%:*} = a') \
+       >/dev/null 2>&1; then
+  is_xsi_shell=yes
+else
+  is_xsi_shell=no
+fi
+
 ## Option parsing.
 
 test_name=INVALID.NAME
@@ -62,8 +72,13 @@ tmp_res=$log_file-res.tmp
   while read line; do
     case $line in
       PASS:*|FAIL:*|XPASS:*|XFAIL:*|SKIP:*)
-        i=`expr $i + 1`
-        result=`LC_ALL=C expr "$line" : '\([A-Z]*\):.*'`
+        if test $is_xsi_shell = yes; then
+          # Eval required to protect dumber shells, e.g., Solaris /bin/sh.
+          eval 'i=$(($i + 1)); result=${line%%:*}'
+        else
+          i=`expr $i + 1`
+          result=`LC_ALL=C expr "$line" : '\([^:]*\):.*'`
+        fi
         case $result in FAIL|XPASS) st=1;; esac
         # Output testcase result to console.
         echo "$result: $test_name, testcase $i"