[ovs-dev] Spurious test failure?

[Ben Pfaff]

On Sat, Dec 08, 2012 at 11:16:33AM +0200, Jarno Rajahalme wrote:
> On Dec 7, 2012, at 17:40 , ext Ben Pfaff wrote:
> > On Fri, Dec 07, 2012 at 01:57:14PM +0200, Jarno Rajahalme wrote:
> >> On Dec 4, 2012, at 21:06 , ext Ben Pfaff wrote:
> >> 
> >>> On Tue, Dec 04, 2012 at 05:10:29PM +0200, Jarno Rajahalme wrote:
> >>>> It seems to me that depending on test machine load or other
> >>>> scheduling reasons, it is possible that some tests fail sometimes,
> >>>> even if there is no real failure. One such case below, where it
> >>>> seems that the middle reply comes in a bit later than
> >>>> anticipated. On repeat this failure did not occur again.
> >>> 
> >>> From time to time we this kind of problem does get introduced into the
> >>> testsuite.  Sorry about that.  Fixes are welcome; I often fix them if
> >>> I start seeing them in my own testsuite runs.
> >>> 
> >> 
> >> OK. Would a proper fix be to suppress the "sent" line(s) and just
> >> check that the responses match?
> > 
> > At first glance what I've appended is a proper fix.  Will you review it?
> > 
> 
> Runs fine, even though I still was not able to repeat the failure I reported.
> 
> However, I don't know if that is a definitive fix. Isn't it still
> possible, that the flow monitor reply for the 2nd add-flow will
> *arrive* after both the ofctl/barrier request and ofctl/send are
> *sent*? That is, "ovs-appctl -t ovs-ofctl ofctl/barrier" will not wait
> for the barrier response to come back before returning, of does it?

It does wait, as the manpage notes:

       ofctl/barrier
              Sends an OpenFlow barrier request on the OpenFlow connection and
              waits  for a reply.  This command is useful only for the monitor
              command.

I'll apply this to master in a few minutes.

> The real problem seems to be that messages for sent messages and
> received messages are mixed in the same stream, and sometimes,
> depending on scheduling etc. the interleaving of the two might be
> different.

It's true.  So far, I haven't had much trouble fixing up issues where
they arise by adding an occasional barrier.

There are a few tests that instead make allowances for different output
orders.  But I haven't found a good general-purpose way to do that with
shell and the usual tools.

> >> Haven't seen the failure I reported since, though.
> > 
> > Sometimes you can reproduce failures just by running a particular test
> > in a loop.  You can make the test run faster with a technique like this:
> > 
> >    amfilt make -j4 check TESTSUITEFLAGS='-d 541'
> >    while tests/testsuite.dir/0541/run -d; do : ; done
> > 
> 
> What is the function of "amfilt" above, and where should I go to get it?

It's not functional, so you may omit that part if you like (I should
have dropped it before posting).  amfilt is a utility that I wrote, that
I use habitually to make "make" output easier to read.  Here it is, in
case you find it useful too.

#! /usr/bin/perl
use POSIX;
use strict;
use warnings;

if (!open(OUTPUT, '-|')) {
    # Running in child process.
    dup2(1, 2);
    exec @ARGV;
    die "$ARGV[0]: exec failed: $!\n";
}

# Running in parent process.
my @dirstack;
my $dir;
while (<OUTPUT>) {
    while (s/\\\s*$//) {
	$_ .= <OUTPUT>;
    }

    s/^make(\[\d+\])?: //;
    next if /^\*\*\*.*Error \d/;

    if (/^Entering directory `(.*)'$/) {
        push(@dirstack, $1);
        next;
    } elsif (/^Leaving directory `(.*)'$/) {
        pop(@dirstack);
        next;
    }

    s/^libtool: \S+: //;

    next if /^Nothing to be done/;
    next if /^ranlib/ || /^rm.*\.a$/;
    next if /^Making \S+ in/ || /^make\s+/;
    next if /^Soft-linking/ || /^mkdir/ || /^\s*\(\s*cd\s+\.libs/;
    next if /^\`tests\/.*' is up to date.$/;

    if (@dirstack > 0 && (!defined($dir) || $dir ne $dirstack[$#dirstack])) {
        $dir = $dirstack[$#dirstack];
        print "Entering directory `$dir'\n";
    }
    if (/\s-o\s*(\S+)/ || /^ar cru (\S+)/ || />\s*(\S+)$/ || /^mv.*\s(\S)$/) {
	next if $1 =~ m%/\.libs/%;
	print "-> $1\n";
    } elsif (/rm -f configmake.h-t &&/) {
	print "-> configmake.h\n";
    } elsif (/mv -f (.*).Tpo (\1).Po/) {
	print "-> $1.Po\n";
    } else {
	print $_;
    }
}
if (!close(OUTPUT)) {
    die "Error closing pipe: $!\n" if $!;
    exit WEXITSTATUS($?) if WIFEXITED($?);
    die "$ARGV[0] terminated by signal " . WTERMSIG($?) . "\n"
      if WIFSIGNALED($?);
    die "$ARGV[0] stopped by signal " . STOPSIG($?) . "\n"
      if WIFSTOPPED($?);
    die "$ARGV[0] terminated abnormally for unknown reason\n";
}