2
0
mirror of https://github.com/xcat2/xcat-core.git synced 2026-09-21 16:39:30 +00:00

fix(xcat-core): xcattest reports only the check where a case stopped

A failing case named one failed check and no result at all for the checks after it,
although the commands of the case kept running. The first [Failed] line was read as
the cause of the failure three times this week, and each time the real fault was a
later check: a riscv64 cell reported a makedns check 160 lines before rpower could
not start the domain.

run_case in xCAT-test/xcattest used one variable, $failflag, for two facts: the
result of the case, and the result of the check being reported. Every branch read
$failflag to decide whether to print [Pass] or [Failed], so a check that ran after a
failed one always read as failed. The guard "last if ($failflag)" at the top of the
check loop hid that, and hid every later check with it.

The result of a check is now $checkfail, set and read inside one iteration. A
continue block carries it into $failflag, which keeps the result of the case. The
guard and the per-branch "last" statements are gone, so each check reports what it
found. The output ~~ branch no longer clears $failflag on a match, which without the
guard would have turned a failed case into a passing one.

xCAT-test/unit/xcattest_report_every_check.t runs the harness over a fixture case and
asserts on the CHECK lines it writes. Without this change it reports two of four
checks, and one of two failed checks. A case whose checks all pass logs the same text
before and after: no truncation could happen while $failflag stayed 0.

Signed-off-by: Daniel Hilst <392820+dhilst@users.noreply.github.com>
This commit is contained in:
Daniel Hilst
2026-09-04 16:39:33 -03:00
parent 506069061b
commit f7462389b6
2 changed files with 159 additions and 14 deletions
@@ -0,0 +1,142 @@
#!/usr/bin/env perl
use strict;
use warnings;
use FindBin;
use File::Copy qw(copy);
use File::Path qw(make_path);
use File::Temp qw(tempdir);
use Test::More;
my $program = "$FindBin::Bin/../xcattest";
BAIL_OUT("xcattest is not at $program") unless -f $program;
#---
=head3 run_harness
Descriptions: Run xcattest over one fixture case file and return its log lines.
Arguments:
$case_text - the content of the fixture case file
@names - the case names to run
Returns: a reference to the array of log lines, and the failed-cases report lines
=cut
#---
sub run_harness {
my ($case_text, @names) = @_;
# xcattest derives its result directory from the location of the program, so the copy
# under the scratch tree keeps every file the run writes inside that tree.
my $root = tempdir(CLEANUP => 1);
make_path("$root/bin", "$root/cases");
copy($program, "$root/bin/xcattest") or BAIL_OUT("copy xcattest: $!");
chmod 0755, "$root/bin/xcattest";
open(my $case_fh, '>', "$root/cases/fixture") or BAIL_OUT("write the fixture case: $!");
print $case_fh $case_text;
close($case_fh) or BAIL_OUT("close the fixture case: $!");
local $ENV{XCATTEST_CASEDIR} = "$root/cases";
system($^X, "$root/bin/xcattest", '-q', '-t', join(',', @names));
my $slurp = sub {
my ($path) = @_;
open(my $fh, '<', $path) or BAIL_OUT("open $path: $!");
my @lines = <$fh>;
close($fh) or BAIL_OUT("close $path: $!");
chomp(@lines);
return @lines;
};
my ($log) = glob("$root/share/xcat/tools/autotest/result/xcattest.log.*");
BAIL_OUT("the harness wrote no running log under $root") unless $log;
my ($failed) = glob("$root/share/xcat/tools/autotest/result/failedcases.*");
BAIL_OUT("the harness wrote no failed-cases report under $root") unless $failed;
return ([ $slurp->($log) ], [ $slurp->($failed) ]);
}
#---
=head3 reported_checks
Descriptions: Select the check results the harness reported.
Arguments:
$lines - a reference to the array of log lines
Returns: a reference to the array of CHECK lines, in the order they were reported
=cut
#---
sub reported_checks {
my ($lines) = @_;
return [ grep { /^CHECK:/ } @{$lines} ];
}
# The second command fails its first check. The check after it on the same command, and the
# checks of every command after it, describe the same run and must report their own result.
my $mixed = <<'CASE';
start:mixedchecks
description:a failed check between checks that pass
cmd:echo alpha
check:rc==0
cmd:echo beta
check:rc!=0
check:output=~beta
cmd:echo gamma
check:output=~gamma
end
CASE
my ($log, $failed) = run_harness($mixed, 'mixedchecks');
is_deeply(reported_checks($log),
[ "CHECK:rc == 0\t[Pass]",
"CHECK:rc != 0\t[Failed]",
"CHECK:output =~ beta\t[Pass]",
"CHECK:output =~ gamma\t[Pass]" ],
'every check reports its own result, and a failed check does not silence the checks after it');
is_deeply(reported_checks($failed), reported_checks($log),
'the failed-cases report carries the same check results as the running log');
ok(scalar(grep { /^------END::mixedchecks::Failed::/ } @{$log}),
'a check that passes after a failed check does not make the case pass');
# A case that fails more than one check names every one of them.
my $twofails = <<'CASE';
start:twofailedchecks
description:two commands, each with a check that fails
cmd:echo one
check:rc!=0
cmd:echo two
check:rc!=0
end
CASE
($log, $failed) = run_harness($twofails, 'twofailedchecks');
is_deeply(reported_checks($log),
[ "CHECK:rc != 0\t[Failed]", "CHECK:rc != 0\t[Failed]" ],
'both failed checks are reported, not just the first');
# A case where every check passes is unchanged.
my $allpass = <<'CASE';
start:allcheckspass
description:every check passes
cmd:echo alpha
check:rc==0
check:output=~alpha
cmd:echo beta
check:output=~beta
end
CASE
($log, $failed) = run_harness($allpass, 'allcheckspass');
is_deeply(reported_checks($log),
[ "CHECK:rc == 0\t[Pass]", "CHECK:output =~ alpha\t[Pass]", "CHECK:output =~ beta\t[Pass]" ],
'a case whose checks all pass reports every check');
ok(scalar(grep { /^------END::allcheckspass::Passed::/ } @{$log}),
'a case whose checks all pass still reports Passed');
done_testing();
+17 -14
View File
@@ -1417,8 +1417,12 @@ sub run_case {
log_this($running_log_fd, ("ElapsedTime:$diffduration sec", "RETURN rc = $rc", "OUTPUT:", @output));
push(@caselog, ("ElapsedTime:$diffduration sec", "RETURN rc = $rc", "OUTPUT:", @output));
# $checkfail is the result of this check, $failflag the result of the case. They
# were one variable, so a failed check made every later check read as failed, and
# the guard that hid that also hid the checks (issue #76).
my $checkfail = 0;
foreach my $check (@{ $cases_ref->[ $case_name_index_map_ref->{$case} ]->{check}->[$j] }) {
last if ($failflag);
$checkfail = 0;
if ($check =~ /rc\s*([=!]+)\s*(\d+)/) {
my $lvalue = $rc;
@@ -1426,12 +1430,11 @@ sub run_case {
my $rvalue = $2;
if ((($op eq '!=') && ($lvalue == $rvalue))
|| (($op eq '==') && ($lvalue != $rvalue))) {
$failflag = 1;
$checkfail = 1;
}
if ($failflag) {
if ($checkfail) {
log_this($running_log_fd, "CHECK:rc $op $rvalue\t[Failed]");
push(@caselog, "CHECK:rc $op $rvalue\t[Failed]");
last;
} else {
log_this($running_log_fd, "CHECK:rc $op $rvalue\t[Pass]");
push(@caselog, "CHECK:rc $op $rvalue\t[Pass]");
@@ -1446,17 +1449,16 @@ sub run_case {
|| (($op eq '!~') && ($lvalue =~ /$rvalue/))
|| (($op eq '==') && ($lvalue ne $rvalue))
|| (($op eq '!=') && ($lvalue eq $rvalue))) {
$failflag = 1;
$checkfail = 1;
} elsif (($op ne '=~') && ($op ne '!~') && ($op ne '==') && ($op ne '!=')) {
$failflag = 1;
$checkfail = 1;
log_this($running_log_fd, "CHECK:output unrecognized operator: $op\t[Failed]");
push(@caselog, "CHECK:output unrecognized operator: $op\t[Failed]");
last;
next;
}
if ($failflag) {
if ($checkfail) {
log_this($running_log_fd, "CHECK:output $op $rvalue\t[Failed]");
push(@caselog, "CHECK:output $op $rvalue\t[Failed]");
last;
} else {
log_this($running_log_fd, "CHECK:output $op $rvalue\t[Pass]");
push(@caselog, "CHECK:output $op $rvalue\t[Pass]");
@@ -1464,7 +1466,7 @@ sub run_case {
} elsif ($check =~ /output\s*~~\s*(\S.*)/) {
my $op = "~~";
#my $failflag = 1;
# This operator only sets $checkfail to 0, so the check always reports Pass.
my $rvalue = $1;
$rvalue = getfunc($rvalue);
@@ -1481,7 +1483,7 @@ sub run_case {
my $min = $num * 0.9;
$line =~ /.*:.*: (\d+) /;
if ($1 < $max && $1 > $min) {
$failflag = 0;
$checkfail = 0;
last;
}
} else {
@@ -1489,19 +1491,20 @@ sub run_case {
}
}
}
if ($failflag) {
if ($checkfail) {
log_this($running_log_fd, "CHECK:output $op $rvalue\t[Failed]");
push(@caselog, "CHECK:output $op $rvalue\t[Failed]");
last;
} else {
log_this($running_log_fd, "CHECK:output $op $rvalue\t[Pass]");
push(@caselog, "CHECK:output $op $rvalue\t[Pass]");
}
} else {
$failflag = 1;
$checkfail = 1;
log_this($running_log_fd, "Unrecognized testcase syntax: CHECK:$check\t[Failed]");
push(@caselog, "Unrecognized testcase syntax: CHECK:$check\t[Failed]");
}
} continue {
$failflag = 1 if ($checkfail);
}
foreach my $cmdcheck (@{ $cases_ref->[ $case_name_index_map_ref->{$case} ]->{cmdcheck}->[$j] }) {
if ($cmdcheck) {