Run update package version check on installer environments

As discussed in https://pagure.io/releng/failed-composes/issue/6538
we noticed a gap in openQA coverage here. We don't check the
versions of packages lorax installs to the installer environment,
and those packages do not make it to the installed system, so if
there's a dep issue that prevents a package in the update from
being included in the installer environment, but the same dep
issue isn't caught on any other path, we miss the problem. This
wires the updvercheck.py script into the _installer_build and
_ostree_build tests to catch this kind of problem, and makes it
capable of parsing pylorax.log files into its preferred format
to enable that.

Signed-off-by: Adam Williamson <awilliam@redhat.com>

lib/utils.pm

@@ -7,7 +7,7 @@ use Exporter;
 
 use lockapi;
 use testapi qw(is_serial_terminal :DEFAULT);
-our @EXPORT = qw/run_with_error_check type_safely type_very_safely desktop_vt boot_to_login_screen console_login console_switch_layout desktop_switch_layout console_loadkeys_us do_bootloader boot_decrypt check_release menu_launch_type setup_repos repo_setup get_workarounds disable_updates_repos cleanup_workaround_repo console_initial_setup handle_welcome_screen gnome_initial_setup anaconda_create_user check_desktop download_modularity_tests quit_firefox advisory_get_installed_packages advisory_check_nonmatching_packages start_with_launcher quit_with_shortcut disable_firefox_studies select_rescue_mode copy_devcdrom_as_isofile get_release_number check_left_bar check_top_bar check_prerelease check_version spell_version_number _assert_and_click is_branched rec_log repos_mirrorlist register_application get_registered_applications solidify_wallpaper check_and_install_git download_testdata make_serial_writable set_update_notification_timestamp kde_doublek_workaround/;
+our @EXPORT = qw/run_with_error_check type_safely type_very_safely desktop_vt boot_to_login_screen console_login console_switch_layout desktop_switch_layout console_loadkeys_us do_bootloader boot_decrypt check_release menu_launch_type setup_repos repo_setup get_workarounds disable_updates_repos cleanup_workaround_repo console_initial_setup handle_welcome_screen gnome_initial_setup anaconda_create_user check_desktop download_modularity_tests quit_firefox advisory_get_installed_packages acnp_handle_output advisory_check_nonmatching_packages start_with_launcher quit_with_shortcut disable_firefox_studies select_rescue_mode copy_devcdrom_as_isofile get_release_number check_left_bar check_top_bar check_prerelease check_version spell_version_number _assert_and_click is_branched rec_log repos_mirrorlist register_application get_registered_applications solidify_wallpaper check_and_install_git download_testdata make_serial_writable set_update_notification_timestamp kde_doublek_workaround/;
 
 
 # We introduce this global variable to hold the list of applications that have
@@ -1235,6 +1235,27 @@ sub advisory_get_installed_packages {
     upload_logs "/mnt/testedpkgs.txt", failok => 1;
 }
 
+sub acnp_handle_output {
+    my ($ret, $wrapper, $fatal) = @_;
+    # handle output of updvercheck.py. Split out so the lorax
+    # tests can use the same logic
+    if ($ret == 2) {
+        record_soft_failure "Some update package(s) not installed, but this is probably OK, see script output";
+    }
+    if ($ret == 1 || $ret == 3) {
+        my $message = "Package(s) from update not installed when it should have been! See script output";
+        $message = "Script failed unexpectedly!" if ($ret == 1);
+        if ($fatal) {
+            set_var("_ACNMP_DONE", "1") unless $wrapper;
+            die $message;
+        }
+        else {
+            # if we're already in post_fail_hook, we don't want to die again
+            record_info $message;
+        }
+    }
+}
+
 sub advisory_check_nonmatching_packages {
     # For update tests (this only works if we've been through
     # _repo_setup_updates), figure out if we have a different version
@@ -1290,23 +1311,7 @@ sub advisory_check_nonmatching_packages {
     my $cmd = 'python3 ./updvercheck.py /mnt/updatepkgs.txt /tmp/installedupdatepkgs.txt';
     $cmd .= " $advisory" if ($advisory);
     my $ret = script_run $cmd;
-    # 2 is warnings only, 3 is problems, 1 means the script died in
+    acnp_handle_output($ret, $wrapper, $args{fatal});
-    # some other way (probably a bug)
-    if ($ret == 2) {
-        record_soft_failure "Some update package(s) not installed, but this is probably OK, see script output";
-    }
-    if ($ret == 1 || $ret == 3) {
-        my $message = "Package(s) from update not installed when it should have been! See script output";
-        $message = "Script failed unexpectedly!" if ($ret == 1);
-        if ($args{fatal}) {
-            set_var("_ACNMP_DONE", "1") unless $wrapper;
-            die $message;
-        }
-        else {
-            # if we're already in post_fail_hook, we don't want to die again
-            record_info $message;
-        }
-    }
 }
 
 sub select_rescue_mode {

tests/_installer_build.pm

@@ -11,7 +11,8 @@ sub run {
     my $repo = $version eq $rawrel ? "fedora-rawhide.repo" : "fedora.repo";
     my $advortask = get_var("ADVISORY_OR_TASK");
     my $arch = get_var("ARCH");
-    my $packages = "lorax";
+    # python3-dnf is for updvercheck.py
+    my $packages = "python3-dnf lorax";
     $packages .= " hfsplus-tools" if ($arch eq "ppc64le");
     assert_script_run "dnf -y install $packages", 120;
     # this 'temporary file cleanup' thing can actually wipe bits of
@@ -31,6 +32,15 @@ sub run {
     $cmd .= " --repo=/etc/yum.repos.d/openqa-testtag.repo" if (get_var("TAG") || get_var("COPR"));
     $cmd .= " ./results";
     assert_script_run $cmd, 2400;
+    # do a package version check on the packages installed to the
+    # installer environment - see
+    # https://pagure.io/releng/failed-composes/issue/6538#comment-917347
+    assert_script_run 'curl --retry-delay 10 --max-time 30 --retry 5 -o updvercheck.py https://pagure.io/fedora-qa/os-autoinst-distri-fedora/raw/lorax-check-packages/f/updvercheck.py', timeout => 180;
+    my $advisory = get_var("ADVISORY");
+    my $cmd = 'python3 ./updvercheck.py /mnt/updatepkgs.txt pylorax.log';
+    $cmd .= " $advisory" if ($advisory);
+    my $ret = script_run $cmd;
+    acnp_handle_output($ret, 0, 1);
     # good to have the log around for checks
     upload_logs "pylorax.log", failok => 1;
     assert_script_run "mv results/images/boot.iso ./${advortask}-netinst-${arch}.iso";

tests/_ostree_build.pm

@@ -103,6 +103,15 @@ sub run {
     $cmd .= " --repo=/etc/yum.repos.d/openqa-testtag.repo" if ($tag || $copr);
     $cmd .= " ./results";
     assert_script_run $cmd, 9000;
+    # do a package version check on the packages installed to the
+    # installer environment - see
+    # https://pagure.io/releng/failed-composes/issue/6538#comment-917347
+    assert_script_run 'curl --retry-delay 10 --max-time 30 --retry 5 -o updvercheck.py https://pagure.io/fedora-qa/os-autoinst-distri-fedora/raw/lorax-check-packages/f/updvercheck.py', timeout => 180;
+    my $advisory = get_var("ADVISORY");
+    my $cmd = 'python3 ./updvercheck.py /mnt/updatepkgs.txt pylorax.log';
+    $cmd .= " $advisory" if ($advisory);
+    my $ret = script_run $cmd;
+    acnp_handle_output($ret, 0, 1);
     # good to have the log around for checks
     upload_logs "lorax.log", failok => 1;
     assert_script_run "mv results/images/boot.iso ./${advortask}-${subv}-ostree-${arch}.iso";

updvercheck.py

@@ -22,6 +22,35 @@ def printver(pname, pepoch, pversion, prelease):
     """Print a NEVR in the typical human-readable format."""
     return f"{pname}-{pepoch}:{pversion}-{prelease}"
 
+def parse_lorax_log(logfile):
+    """
+    Parse a pylorax.log file into a format the rest of the script
+    can work with.
+    """
+    with open(logfile, "r", encoding="utf-8") as logfh:
+        log = logfh.read()
+    log = log.splitlines()
+
+    # Filter to the lines that indicate installed packages
+    installed = [line for line in log if line.startswith("Install ")]
+    # Drop the "Install " prefix
+    installed = [line.split()[1] for line in installed]
+    # Do a split to get (lname, lepoch+lversion, lrelease) tuples
+    installed = [line.rsplit("-", 2) for line in installed]
+    # create an output list
+    out = []
+    for (lname, ev, lrelease) in installed:
+        # fiddle a 0 epoch into all the packages without an explicit one
+        if ":" not in ev:
+            ev = f"0:{ev}"
+        # split the epoch and version out
+        (lepoch, lversion) = ev.split(":")
+        # strip the arch suffix from the release
+        lrelease = lrelease.rsplit(".", 1)[0]
+        # output in the format we expect later
+        out.append(f"unknown {lname} {lepoch} {lversion} {lrelease}")
+    return out
+
 try:
     updfname = sys.argv[1]
     instfname = sys.argv[2]
@@ -44,10 +73,17 @@ warnings = []
 post = set()
 ret = 0
 updstableobs = None
+if "lorax.log" in instfname:
+    ilines = parse_lorax_log(instfname)
+else:
     with open(instfname, "r", encoding="utf-8") as ifh:
-    for iline in ifh.readlines():
+        ilines = ifh.readlines()
+for iline in ilines:
     (_, name, epoch, version, release) = iline.strip().split(" ")
-        res = rpm.labelCompare((epoch, version, release), (updpkgs[name]))
+    if name not in updpkgs:
+        # this happens with lorax logs, as they contain every package
+        continue
+    res = rpm.labelCompare((epoch, version, release), (updpkgs[name]))  # pylint:disable=no-member
     if res == 0:
         continue
     instver = printver(name, epoch, version, release)