PMC Tools Test Failure

[Chromatic]

Hi there,

I see one failure with the buildtools tests, run right after make realclean
and a fresh Configure.

t/tools/pmc2cutils/04-dump_pmc.......ok 103/119
# Failed test (t/tools/pmc2cutils/04-dump_pmc.t at line 533)
t/tools/pmc2cutils/04-dump_pmc.......NOK 106/119# got: '1170302523'
# expected: '1170302526'
# Looks like you failed 1 test of 119.
t/tools/pmc2cutils/04-dump_pmc.......dubious
Test returned status 1 (wstat 256, 0x100)
DIED. FAILED test 106
Failed 1/119 tests, 99.16% okay

-- c

[James E Keenan]

I've experienced that once out of the hundreds of times I've run those
tests, and I think it represents a poorly designed test more than a real
failure. IIRC, in order to be able to get full coverage on a branch, I
have to determine whether a file was overwritten or not, which I'm doing
with a comparison of mtimes.

I hope to be able to take a look at it on Friday or Saturday and get
back to you.

jimk

[Chromatic]

On Thursday 01 February 2007 04:07, James E Keenan wrote:

> IIRC, in order to be able to get full coverage on a branch, I
> have to determine whether a file was overwritten or not, which I'm doing
> with a comparison of mtimes.

Hm, that's a tricky test to write. You have to dodge questions of process and
IO ordering, as well as the granularity of time the filesystem can handle.

The last time I wrote a similar test, I used sleep() for a couple of seconds.
That may or may not be desirable.

-- c

[James E Keenan]

chromatic wrote:

And I tried sleep()ing as well; see below.

But first let me note that this was one place in the refactoring of
pmc2c.pl that I found particularly puzzling and difficult to test. The
puzzling code is a foreach loop found in lib/Parrot/Pmc2c/Utils.pm,
method dump_pmc(), which starts at line 371 in the latest revision.
Here's that loop, which starts at line 404 -- complete with my comments
in the code (I rebroke some long lines):

DO_A_DUMP: foreach my $name (keys %{$all}) {
my $file = $all->{$name}->{file};
my $dumpfile = $file;
$dumpfile =~ s/\.\w+$/.dump/;

my $existing = $self->find_file($dumpfile);

# Am confused about what's intended here.
# If the .dump file is OLDER
# than the corresponding .pmc file (e.g., if it's
# some .dump file from
# an earlier run of 'make'), shouldn't it be overwritten
# so that we
# have an up-to-date .dump file?
if (defined $existing && dump_is_newer($existing)) {
if ($dumpfile =~ /default\.dump$/) {
# don't overwrite default.dump
# skip all preparations for dumping
next DO_A_DUMP;
}
else {
# overwrite anything else
# continue with preparations for dumping
# And what good is assigning the name of the existing
# dump file to
# that of the newly-to-be-created dumpfile.
# Wouldn't they have the
# same name in any case? (Or are we dealing
# with the possibility that
# find_file() will return a file of the same basename but in a
# different directory? Is that a real possibility?)
$dumpfile = $existing;
}
}

$all = $self->gen_parent_list($name, $all);

my $class = gen_super_meths($name, $all, $vt);
my $Dumper = Data::Dumper->new([$class], ['class']);
$Dumper->Indent(1);
my $fh = open_file( ">", $dumpfile );
print $fh $Dumper->Dump;
close $fh;
} # end foreach loop

The test that failed for chromatic was one in a block whose purpose was
to test all the conditions implicit in this line:

if (defined $existing && dump_is_newer($existing)) {

I had to construct a test case in which file default.dump was *not*
overwritten but in which any other .dump file (in this case, array.dump)
supplied as an argument *was* overwritten. So the mtimes of
default.dump "before" and "after" had to be identical, while the mtimes
of array.dump "before" and "after" had to differ. "before" and "after"
mean before and after a *second* call to dump_pmc in the same block --
something which may not actually take place when pmc2c.pl is invoked by
'make'. The relevant test code starts at line 474 of
t/tools/pmc2cutils/04-dump_pmc.t; here are excerpts:

# @args hold default.pmc and one other .pmc
# test 2nd calls
{
... # skip setup of temporary directories for testing
my @include = ($tdir, $temppmcdir, @include_orig);

@args = (
qq{$temppmcdir/default.pmc},
qq{$temppmcdir/array.pmc},
);
$self = Parrot::Pmc2c::Utils->new( {
include => \@include,
opt => \%opt,
args => [ @args ],
} );
isa_ok($self, q{Parrot::Pmc2c::Utils});
$dump_file = $self->dump_vtable("$main::topdir/vtable.tbl");
ok(-e $dump_file, "dump_vtable created vtable.dump");

# First call to dump_pmc() is on the next line:
ok($self->dump_pmc(), "dump_pmc succeeded");
ok(-f qq{$temppmcdir/default.dump},
"default.dump created as expected");
ok(-f qq{$temppmcdir/array.dump},
"array.dump created as expected");

my @mtimes;

$mtimes[0]{default} = (stat(qq{$temppmcdir/default.dump}))[9];
$mtimes[0]{array} = (stat(qq{$temppmcdir/array.dump}))[9];

# Take a catnap:
sleep(2);

# Second call to dump_pmc() is on the next line:
ok($self->dump_pmc(), "dump_pmc succeeded");
ok(-f qq{$temppmcdir/default.dump},
"default.dump created as expected");
ok(-f qq{$temppmcdir/array.dump},
"array.dump created as expected");

$mtimes[1]{default} = (stat(qq{$temppmcdir/default.dump}))[9];
$mtimes[1]{array} = (stat(qq{$temppmcdir/array.dump}))[9];

# Compare mtimes; the next test is the one that failed for c
is( $mtimes[0]{default}, $mtimes[1]{default},
"default.dump correctly not overwritten");
isnt( $mtimes[0]{array}, $mtimes[1]{array},
"array.dump correctly overwritten");
...
}

I can't really explain why c got a 3-second difference between the
mtimes of default.dump. That difference suggested that default.dump
*was* overwritten when it should not have. All I can say is that during
the development of Parrot::Pmc2c::Utils I ran this test file hundreds of
times and only once got a test failure at that point.

Perhaps someone (leo? mdiep?) who was involved in the original
development of pmc2c.pl can explain better what is happening inside the
DO_A_DUMP loop excerpted above.

kid51