refactor: Improved logger usage (#1373)

* refactor: move codebase to new logging syntax

Signed-off-by: Freya Gustavsson <[email protected]>

* refactor: logging stages

This refactors the logging stages that we output when we log in specific
files depending on what we are doing. Meaning that any changes that
has to do with preparing or rollback will now output the stage within
the logger formatter rather than leaving it up to each class

E.g. any logs with "Prepare: text" or "Rollback: text" will now be
handled at the log-level

Signed-off-by: Freya Gustavsson <[email protected]>

* Change format to use new stages style

Signed-off-by: Freya Gustavsson <[email protected]>

* Fixed failing unit tests

Signed-off-by: Freya Gustavsson <[email protected]>

* Added log phase to logger task output

Signed-off-by: Freya Gustavsson <[email protected]>

* chore: remove explicit usages of stages in logs

This removes all the different task log calls that include the stage
it should be in and instead relies on the logger to take care of it

e.g. `.task("Convert: ...")` will now have `Convert:` removed

Signed-off-by: Freya Gustavsson <[email protected]>

* chore: Move phases to prevent circular import

ConversionPhases is now moved outside of utils module so that it doesn't
cause a circular import with logger module

Signed-off-by: Freya Gustavsson <[email protected]>

* Removed convert2rhel logger from conftest

Signed-off-by: Freya Gustavsson <[email protected]>

* Set rollback phase on rollback

Signed-off-by: Freya Gustavsson <[email protected]>
Signed-off-by: Freya Gustavsson <[email protected]>

* Log phases correctly

Signed-off-by: Freya Gustavsson <[email protected]>

* Set log_name to Prepare for pre PONR changes

Signed-off-by: Freya Gustavsson <[email protected]>

* Remove leftover text task stage

* feat: add phase name for analyze

* fix: changed post PONR phase to 'final'

* fix: handle rollback phases in messages

We didn't know what phase we were on before going into rollback. With
this change it now keeps a (soft) linear history where each phase points
to the previous one

* fix: Correctly get the stage we were at

* fix: Update phase from Final to Convert

---------

Signed-off-by: Freya Gustavsson <[email protected]>
Signed-off-by: Freya Gustavsson <[email protected]>

convert2rhel/actions/__init__.py

@@ -520,7 +520,7 @@ def run(self, successes=None, failures=None, skips=None):
             running is WARNING or better (WARNING or SUCCESS) and
             failure as worse than WARNING (OVERRIDABLE, ERROR)
         """
-        logger.task("Prepare: {}".format(self.task_header))
+        logger.task("{}".format(self.task_header))
 
         if self._has_run:
             raise ActionError("Stage {} has already run.".format(self.stage_name))

convert2rhel/actions/conversion/list_non_red_hat_pkgs_left.py

@@ -32,7 +32,8 @@ def run(self):
         Red Hat-signed ones during the conversion.
         """
         super(ListNonRedHatPkgsLeft, self).run()
-        loggerinst.task("Convert: List remaining non-Red Hat packages")
+        loggerinst.task("List remaining non-Red Hat packages")
+
         loggerinst.info("Listing packages not signed by Red Hat")
         non_red_hat_pkgs = get_installed_pkgs_w_different_key_id(system_info.key_ids_rhel)
         if not non_red_hat_pkgs:

convert2rhel/actions/conversion/lock_releasever.py

@@ -39,7 +39,8 @@ def run(self):
         default.
         """
         super(LockReleaseverInRHELRepositories, self).run()
-        loggerinst.task("Convert: Lock releasever in RHEL repositories")
+        loggerinst.task("Lock releasever in RHEL repositories")
+
         # We only lock the releasever on rhel repos if we detect that the running system is an EUS correspondent and if
         # rhsm is used, otherwise, there's no need to lock the releasever as the subscription-manager won't be
         # available.

convert2rhel/actions/conversion/pkg_manager_config.py

@@ -33,6 +33,7 @@ def run(self):
         """
         super(ConfigurePkgManager, self).run()
 
-        logger.task("Convert: Patch package manager configuration file")
+        logger.task("Patch package manager configuration file")
+
         pmc = redhatrelease.PkgManagerConf()
         pmc.patch()

convert2rhel/actions/conversion/preserve_only_rhel_kernel.py

@@ -35,7 +35,7 @@ class InstallRhelKernel(actions.Action):
     def run(self):
         """Install and update the RHEL kernel."""
         super(InstallRhelKernel, self).run()
-        loggerinst.task("Convert: Prepare kernel")
+        loggerinst.task("Prepare kernel")
 
         # Solution for RHELC-1707
         # Update is needed in the UpdateKernel action

convert2rhel/actions/conversion/set_efi_config.py

@@ -34,7 +34,7 @@ def run(self):
         """Check that the expected RHEL UEFI binaries exist."""
         super(NewDefaultEfiBin, self).run()
 
-        logger.task("Convert: Configure the bootloader")
+        logger.task("Configure the bootloader")
 
         if not grub.is_efi():
             logger.info(

convert2rhel/actions/conversion/transaction.py

@@ -31,7 +31,7 @@ def run(self):
         super(ConvertSystemPackages, self).run()
 
         try:
-            logger.task("Convert: Replace system packages")
+            logger.task("Replace system packages")
             transaction_handler = pkgmanager.create_transaction_handler()
             transaction_handler.run_transaction()
         except exceptions.CriticalError as e:

convert2rhel/actions/post_conversion/breadcrumbs_finish_collection.py

@@ -33,5 +33,5 @@ class BreadcumbsFinishCollection(actions.Action):
     def run(self):
         super(BreadcumbsFinishCollection, self).run()
 
-        logger.task("Final: Update breadcrumbs")
+        logger.task("Update breadcrumbs")
         breadcrumbs.breadcrumbs.finish_collection(success=True)

convert2rhel/actions/post_conversion/hostmetering.py

@@ -48,7 +48,7 @@ def run(self):
         :return: True if host-metering is configured successfully, False otherwise.
         :rtype: bool
         """
-        logger.task("Final: Configure host-metering")
+        logger.task("Configure host-metering")
 
         super(ConfigureHostMetering, self).run()
 

convert2rhel/actions/post_conversion/kernel_boot_files.py

@@ -39,7 +39,7 @@ def run(self):
         """Check if the required kernel files exist and are valid under the boot partition."""
         super(KernelBootFiles, self).run()
 
-        logger.task("Final: Check kernel boot files")
+        logger.task("Check kernel boot files")
 
         # For Oracle/CentOS Linux 8 the `kernel` is just a meta package, instead,
         # we check for `kernel-core`. This is not true regarding the 7.* releases.

convert2rhel/actions/post_conversion/modified_rpm_files_diff.py

@@ -36,7 +36,7 @@ def run(self):
         """
         super(ModifiedRPMFilesDiff, self).run()
 
-        logger.task("Final: Show RPM files modified by the conversion")
+        logger.task("Show RPM files modified by the conversion")
 
         system_info.generate_rpm_va(log_filename=utils.rpm.POST_RPM_VA_LOG_FILENAME)
 

convert2rhel/actions/post_conversion/remove_tmp_dir.py

@@ -41,7 +41,7 @@ def run(self):
         """
         super(RemoveTmpDir, self).run()
 
-        loggerinst.task("Final: Remove temporary folder {}".format(TMP_DIR))
+        loggerinst.task("Remove temporary folder {}".format(TMP_DIR))
 
         try:
             shutil.rmtree(self.tmp_dir)

convert2rhel/actions/post_conversion/rhsm_custom_facts_config.py

@@ -30,7 +30,7 @@ class RHSMCustomFactsConfig(actions.Action):
 
     def run(self):
         super(RHSMCustomFactsConfig, self).run()
-        loggerinst.task("Final: Update RHSM custom facts")
+        loggerinst.task("Update RHSM custom facts")
         ret_code, output = subscription.update_rhsm_custom_facts()
 
         if not output:

convert2rhel/actions/post_conversion/update_grub.py

@@ -35,7 +35,7 @@ def run(self):
         """
         super(UpdateGrub, self).run()
 
-        logger.task("Final: Update GRUB2 configuration")
+        logger.task("Update GRUB2 configuration")
 
         backup.backup_control.push(RestorableFile(grub.GRUB2_BIOS_CONFIG_FILE))
         backup.backup_control.push(RestorableFile(grub.GRUB2_BIOS_ENV_FILE))

convert2rhel/actions/pre_ponr_changes/backup_system.py

@@ -52,7 +52,7 @@ class BackupRedhatRelease(actions.Action):
 
     def run(self):
         """Backup redhat release file before starting conversion process"""
-        logger.task("Prepare: Backup Redhat Release Files")
+        logger.task("Backup Redhat Release Files")
 
         super(BackupRedhatRelease, self).run()
 
@@ -79,7 +79,7 @@ class BackupRepository(actions.Action):
 
     def run(self):
         """Backup .repo files in /etc/yum.repos.d/ so the repositories can be restored on rollback."""
-        logger.task("Prepare: Backup Repository Files")
+        logger.task("Backup Repository Files")
 
         super(BackupRepository, self).run()
 
@@ -105,7 +105,7 @@ class BackupYumVariables(actions.Action):
 
     def run(self):
         """Backup varsdir folder in /etc/{yum,dnf}/vars so the variables can be restored on rollback."""
-        logger.task("Prepare: Backup variables")
+        logger.task("Backup variables")
 
         super(BackupYumVariables, self).run()
 
@@ -146,7 +146,7 @@ def run(self):
         """Backup changed package files"""
         super(BackupPackageFiles, self).run()
 
-        logger.task("Prepare: Backup package files")
+        logger.task("Backup package files")
 
         package_files_changes = self._get_changed_package_files()
 

convert2rhel/actions/pre_ponr_changes/custom_repos_are_valid.py

@@ -36,7 +36,7 @@ def run(self):
         - the repository "baseurl" is accessible and contains repository metadata
         """
         super(CustomReposAreValid, self).run()
-        logger.task("Prepare: Check if --enablerepo repositories are accessible")
+        logger.task("Check if --enablerepo repositories are accessible")
 
         if not tool_opts.enablerepo:
             logger.info("Did not perform the check of repositories due to the use of RHSM for the conversion.")

convert2rhel/actions/pre_ponr_changes/handle_packages.py

@@ -38,7 +38,7 @@ def run(self):
         """
         super(ListThirdPartyPackages, self).run()
 
-        logger.task("Prepare: List third-party packages")
+        logger.task("List third-party packages")
         third_party_pkgs = pkghandler.get_third_party_pkgs()
         if third_party_pkgs:
             # RHELC-884 disable the RHEL repos to avoid reaching them when checking original system.
@@ -100,12 +100,10 @@ def run(self):
         all_pkgs = []
         pkgs_removed = []
         try:
-            logger.task("Prepare: Searching for the following excluded packages")
+            logger.task("Searching for the following excluded packages")
             excluded_pkgs = sorted(pkghandler.get_packages_to_remove(system_info.excluded_pkgs))
 
-            logger.task(
-                "Prepare: Searching for packages containing .repo files or affecting variables in the .repo files"
-            )
+            logger.task("Searching for packages containing .repo files or affecting variables in the .repo files")
             repofile_pkgs = sorted(pkghandler.get_packages_to_remove(system_info.repofile_pkgs))
 
             logger.info("\n")

convert2rhel/actions/pre_ponr_changes/kernel_modules.py

@@ -240,7 +240,7 @@ def run(self):
         """Ensure that the host kernel modules are compatible with RHEL."""
         super(EnsureKernelModulesCompatibility, self).run()
 
-        logger.task("Prepare: Ensure kernel modules compatibility with RHEL")
+        logger.task("Ensure kernel modules compatibility with RHEL")
 
         try:
             host_kmods = self._get_loaded_kmods()

convert2rhel/actions/pre_ponr_changes/special_cases.py

@@ -47,7 +47,7 @@ def run(self):
         """
         super(RemoveIwlax2xxFirmware, self).run()
 
-        logger.task("Prepare: Resolve possible edge case")
+        logger.task("Resolve possible edge case")
         iwl7260_firmware = system_info.is_rpm_installed(name="iwl7260-firmware")
         iwlax2xx_firmware = system_info.is_rpm_installed(name="iwlax2xx-firmware")
 

convert2rhel/actions/pre_ponr_changes/subscription.py

@@ -52,7 +52,7 @@ def run(self):
         # The subscription-manager-rhsm-certificates package contains this cert but for
         # example on CentOS Linux 7 this package is missing the cert due to intentional
         # debranding. Thus we need to ensure the cert is in place even when the pkg is installed.
-        logger.task("Prepare: Install cdn.redhat.com SSL CA certificate")
+        logger.task("Install cdn.redhat.com SSL CA certificate")
         repo_cert = RestorablePEMCert(_REDHAT_CDN_CACERT_SOURCE_DIR, _REDHAT_CDN_CACERT_TARGET_DIR)
         backup.backup_control.push(repo_cert)
 
@@ -65,7 +65,7 @@ def run(self):
 
         # Import the Red Hat GPG Keys for installing Subscription-manager
         # and for later.
-        logger.task("Prepare: Import Red Hat GPG keys")
+        logger.task("Import Red Hat GPG keys")
         pkghandler.install_gpg_keys()
 
 
@@ -97,18 +97,18 @@ def run(self):
             return
 
         try:
-            logger.task("Prepare: Subscription Manager - Check for installed packages")
+            logger.task("Subscription Manager - Check for installed packages")
             subscription_manager_pkgs = subscription.needed_subscription_manager_pkgs()
             if not subscription_manager_pkgs:
                 logger.info("Subscription Manager is already present")
             else:
-                logger.task("Prepare: Subscription Manager - Install packages")
+                logger.task("Subscription Manager - Install packages")
                 subscription.install_rhel_subscription_manager(subscription_manager_pkgs)
 
-            logger.task("Prepare: Subscription Manager - Verify installation")
+            logger.task("Subscription Manager - Verify installation")
             subscription.verify_rhsm_installed()
 
-            logger.task("Prepare: Install a RHEL product certificate for RHSM")
+            logger.task("Install a RHEL product certificate for RHSM")
             product_cert = RestorablePEMCert(_RHSM_PRODUCT_CERT_SOURCE_DIR, _RHSM_PRODUCT_CERT_TARGET_DIR)
             backup.backup_control.push(product_cert)
         except SystemExit as e:
@@ -165,7 +165,7 @@ def run(self):
                 )
                 return
 
-            logger.task("Prepare: Subscription Manager - Reload configuration")
+            logger.task("Subscription Manager - Reload configuration")
             # We will use subscription-manager later to enable the RHEL repos so we need to make
             # sure subscription-manager knows about the product certificate. Refreshing
             # subscription info will do that.
@@ -205,19 +205,19 @@ def run(self):
             # condition or a separate Action.  Not doing it now because we
             # have to disentangle the exception handling when we do that.
             if subscription.should_subscribe():
-                logger.task("Prepare: Subscription Manager - Subscribe system")
+                logger.task("Subscription Manager - Subscribe system")
                 restorable_subscription = RestorableSystemSubscription()
                 backup.backup_control.push(restorable_subscription)
 
-            logger.task("Prepare: Subscription Manager - Disable all repositories")
+            logger.task("Subscription Manager - Disable all repositories")
             backup.backup_control.push(RestorableDisableRepositories())
 
-            logger.task("Prepare: Get RHEL repository IDs")
+            logger.task("Get RHEL repository IDs")
             rhel_repoids = repo.get_rhel_repoids()
 
             # we need to enable repos after removing repofile pkgs, otherwise
             # we don't get backups to restore from on a rollback
-            logger.task("Prepare: Subscription Manager - Enable RHEL repositories")
+            logger.task("Subscription Manager - Enable RHEL repositories")
             subscription.enable_repos(rhel_repoids)
         except OSError as e:
             # This should not occur anymore as all the relevant OSError has been changed to a CriticalError

convert2rhel/actions/pre_ponr_changes/transaction.py

@@ -42,7 +42,7 @@ def run(self):
         super(ValidatePackageManagerTransaction, self).run()
 
         try:
-            logger.task("Prepare: Validate the %s transaction", pkgmanager.TYPE)
+            logger.task("Validate the %s transaction", pkgmanager.TYPE)
             transaction_handler = pkgmanager.create_transaction_handler()
             transaction_handler.run_transaction(
                 validate_transaction=True,

convert2rhel/actions/system_checks/check_firewalld_availability.py

@@ -86,7 +86,7 @@ class CheckFirewalldAvailability(actions.Action):
     def run(self):
         """Error out if the firewalld service is running on the system."""
         super(CheckFirewalldAvailability, self).run()
-        logger.task("Prepare: Check that firewalld is running")
+        logger.task("Check that firewalld is running")
 
         if system_info.id == "oracle" and system_info.version.major == 8 and system_info.version.minor >= 8:
             # If firewalld is not present on the system, we can just skip skip.

convert2rhel/actions/system_checks/convert2rhel_latest.py

@@ -44,7 +44,7 @@ class Convert2rhelLatest(actions.Action):
 
     def run(self):
         """Make sure that we are running the latest downstream version of convert2rhel"""
-        logger.task("Prepare: Check if this is the latest version of Convert2RHEL")
+        logger.task("Check if this is the latest version of Convert2RHEL")
 
         super(Convert2rhelLatest, self).run()
 

convert2rhel/actions/system_checks/dbus.py

@@ -30,7 +30,7 @@ class DbusIsRunning(actions.Action):
     def run(self):
         """Error out if we need to register with rhsm and the dbus daemon is not running."""
         super(DbusIsRunning, self).run()
-        logger.task("Prepare: Check that DBus Daemon is running")
+        logger.task("Check that DBus Daemon is running")
 
         if not subscription.should_subscribe():
             logger.info("Did not perform the check because we have been asked not to subscribe this system to RHSM.")

convert2rhel/actions/system_checks/duplicate_packages.py

@@ -31,7 +31,7 @@ def run(self):
         """Ensure that there are no duplicate system packages installed."""
         super(DuplicatePackages, self).run()
 
-        logger.task("Prepare: Check if there are any duplicate installed packages on the system")
+        logger.task("Check if there are any duplicate installed packages on the system")
         output, ret_code = utils.run_subprocess(["/usr/bin/package-cleanup", "--dupes", "--quiet"], print_output=False)
         if not output:
             return

convert2rhel/actions/system_checks/efi.py

@@ -33,7 +33,7 @@ def run(self):
         """Inhibit the conversion when we are not able to handle UEFI."""
         super(Efi, self).run()
 
-        logger.task("Prepare: Check the firmware interface type (BIOS/UEFI)")
+        logger.task("Check the firmware interface type (BIOS/UEFI)")
         if not grub.is_efi():
             logger.info("BIOS detected.")
             return

convert2rhel/actions/system_checks/grub_validity.py

@@ -31,7 +31,7 @@ def run(self):
         is invalid.
         """
         super(GrubValidity, self).run()
-        logger.task("Prepare: Check if the grub file is valid")
+        logger.task("Check if the grub file is valid")
         output, ret_code = utils.run_subprocess(["grub2-mkconfig"], print_output=False)
 
         if ret_code != 0:

convert2rhel/actions/system_checks/is_loaded_kernel_latest.py

@@ -35,7 +35,7 @@ class IsLoadedKernelLatest(actions.Action):
     def run(self):
         """Check if the loaded kernel is behind or of the same version as in yum repos."""
         super(IsLoadedKernelLatest, self).run()
-        logger.task("Prepare: Check if the loaded kernel version is the most recent")
+        logger.task("Check if the loaded kernel version is the most recent")
 
         if system_info.id == "oracle" and system_info.eus_system:
             logger.info(

convert2rhel/actions/system_checks/package_updates.py

@@ -33,7 +33,7 @@ class PackageUpdates(actions.Action):
     def run(self):
         """Ensure that the system packages installed are up-to-date."""
         super(PackageUpdates, self).run()
-        logger.task("Prepare: Check if the installed packages are up-to-date")
+        logger.task("Check if the installed packages are up-to-date")
 
         if system_info.id == "oracle" and system_info.eus_system:
             logger.info(

convert2rhel/actions/system_checks/readonly_mounts.py

@@ -48,7 +48,7 @@ class ReadonlyMountMnt(actions.Action):
 
     def run(self):
         super(ReadonlyMountMnt, self).run()
-        logger.task("Prepare: Check if /mnt is read-write")
+        logger.task("Check if /mnt is read-write")
 
         if readonly_mount_detection("/mnt"):
             self.set_result(
@@ -67,7 +67,7 @@ class ReadonlyMountSys(actions.Action):
 
     def run(self):
         super(ReadonlyMountSys, self).run()
-        logger.task("Prepare: Check if /sys is read-write")
+        logger.task("Check if /sys is read-write")
 
         if readonly_mount_detection("/sys"):
             self.set_result(

convert2rhel/actions/system_checks/rhel_compatible_kernel.py

@@ -58,7 +58,7 @@ def run(self):
         original system.
         """
         super(RhelCompatibleKernel, self).run()
-        logger.task("Prepare: Check kernel compatibility with RHEL")
+        logger.task("Check kernel compatibility with RHEL")
         for check_function in (_bad_kernel_version, _bad_kernel_package_signature, _bad_kernel_substring):
             try:
                 check_function(system_info.booted_kernel)