Port provisioner scripts to updated framework

Updates all the example provisioner scripts to use the new functions
exposed by the VMBuilder class as an illustration of how best to use
them.

Also adds a wrapper fail() handler to ensure the cleanup of the script,
as well as the global cleanup, are run on an exception.

api-daemon/provisioner/examples/script/1-noop.py

@@ -31,6 +31,20 @@
 # function is provided in context of the example; see the other examples for
 # more potential uses.
 
+# Within the VMBuilderScript class, several helper functions are exposed through
+# the parent VMBuilder class:
+#  self.log_info(message):
+#    Use this function to log an "informational" message instead of "print()"
+#  self.log_warn(message):
+#    Use this function to log a "warning" message
+#  self.log_err(message):
+#    Use this function to log an "error" message outside of an exception (see below)
+#  self.fail(message, exception=<ExceptionClass>):
+#    Use this function to bail out of the script safely instead if raising a
+#    normal Python exception. You may pass an optional exception class keyword
+#    argument for posterity in the logs if you wish; otherwise, ProvisioningException
+#    is used. This function implicitly calls a "self.log_err" with the passed message
+
 # Within the VMBuilderScript class, several common variables are exposed through
 # the parent VMBuilder class:
 #  self.vm_name: The name of the VM from PVC's perspective
@@ -132,9 +146,8 @@
 # since they could still do destructive things to /dev and the like!
 
 
-# This import is always required here, as VMBuilder is used by the VMBuilderScript class
+# This import is always required here, as VMBuilder is used by the VMBuilderScript class.
-# and ProvisioningError is the primary exception that should be raised within the class.
+from pvcapid.vmbuilder import VMBuilder
-from pvcapid.vmbuilder import VMBuilder, ProvisioningError
 
 
 # The VMBuilderScript class must be named as such, and extend VMBuilder.

api-daemon/provisioner/examples/script/2-ova.py

@@ -32,6 +32,20 @@
 # function is provided in context of the example; see the other examples for
 # more potential uses.
 
+# Within the VMBuilderScript class, several helper functions are exposed through
+# the parent VMBuilder class:
+#  self.log_info(message):
+#    Use this function to log an "informational" message instead of "print()"
+#  self.log_warn(message):
+#    Use this function to log a "warning" message
+#  self.log_err(message):
+#    Use this function to log an "error" message outside of an exception (see below)
+#  self.fail(message, exception=<ExceptionClass>):
+#    Use this function to bail out of the script safely instead if raising a
+#    normal Python exception. You may pass an optional exception class keyword
+#    argument for posterity in the logs if you wish; otherwise, ProvisioningException
+#    is used. This function implicitly calls a "self.log_err" with the passed message
+
 # Within the VMBuilderScript class, several common variables are exposed through
 # the parent VMBuilder class:
 #  self.vm_name: The name of the VM from PVC's perspective
@@ -133,9 +147,8 @@
 # since they could still do destructive things to /dev and the like!
 
 
-# This import is always required here, as VMBuilder is used by the VMBuilderScript class
+# This import is always required here, as VMBuilder is used by the VMBuilderScript class.
-# and ProvisioningError is the primary exception that should be raised within the class.
+from pvcapid.vmbuilder import VMBuilder
-from pvcapid.vmbuilder import VMBuilder, ProvisioningError
 
 
 # The VMBuilderScript class must be named as such, and extend VMBuilder.
@@ -283,9 +296,9 @@ class VMBuilderScript(VMBuilder):
         import os
 
         # First loop: Create the destination disks
-        print("Creating destination disk volumes")
+        self.log_info("Creating destination disk volumes")
         for volume in self.vm_data["volumes"]:
-            print(f"Processing volume {volume['volume_name']}")
+            self.log_info(f"Processing volume {volume['volume_name']}")
             with open_zk(config) as zkhandler:
                 success, message = pvc_ceph.add_volume(
                     zkhandler,
@@ -293,16 +306,14 @@ class VMBuilderScript(VMBuilder):
                     f"{self.vm_name}_{volume['disk_id']}",
                     f"{volume['disk_size_gb']}G",
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(
+                    self.fail(f"Failed to create volume '{volume['disk_id']}'.")
-                        f"Failed to create volume '{volume['disk_id']}'."
-                    )
 
         # Second loop: Map the destination disks
-        print("Mapping destination disk volumes")
+        self.log_info("Mapping destination disk volumes")
         for volume in self.vm_data["volumes"]:
-            print(f"Processing volume {volume['volume_name']}")
+            self.log_info(f"Processing volume {volume['volume_name']}")
             dst_volume_name = f"{self.vm_name}_{volume['disk_id']}"
             dst_volume = f"{volume['pool']}/{dst_volume_name}"
 
@@ -312,14 +323,14 @@ class VMBuilderScript(VMBuilder):
                     volume["pool"],
                     dst_volume_name,
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(f"Failed to map volume '{dst_volume}'.")
+                    self.fail(f"Failed to map volume '{dst_volume}'.")
 
         # Third loop: Map the source disks
-        print("Mapping source disk volumes")
+        self.log_info("Mapping source disk volumes")
         for volume in self.vm_data["volumes"]:
-            print(f"Processing volume {volume['volume_name']}")
+            self.log_info(f"Processing volume {volume['volume_name']}")
             src_volume_name = volume["volume_name"]
             src_volume = f"{volume['pool']}/{src_volume_name}"
 
@@ -329,9 +340,9 @@ class VMBuilderScript(VMBuilder):
                     volume["pool"],
                     src_volume_name,
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(f"Failed to map volume '{src_volume}'.")
+                    self.fail(f"Failed to map volume '{src_volume}'.")
 
     def install(self):
         """
@@ -351,14 +362,14 @@ class VMBuilderScript(VMBuilder):
             dst_volume = f"{volume['pool']}/{dst_volume_name}"
             dst_devpath = f"/dev/rbd/{dst_volume}"
 
-            print(
+            self.log_info(
                 f"Converting {volume['volume_format']} {src_volume} at {src_devpath} to {dst_volume} at {dst_devpath}"
             )
             retcode, stdout, stderr = pvc_common.run_os_command(
                 f"qemu-img convert -C -f {volume['volume_format']} -O raw {src_devpath} {dst_devpath}"
             )
             if retcode:
-                raise ProvisioningError(
+                self.fail(
                     f"Failed to convert {volume['volume_format']} volume '{src_volume}' to raw volume '{dst_volume}' with qemu-img: {stderr}"
                 )
 
@@ -368,7 +379,7 @@ class VMBuilderScript(VMBuilder):
 
         This function is also called if there is ANY exception raised in the prepare()
         or install() steps. While this doesn't mean you shouldn't or can't raise exceptions
-        here, be warned that doing so might cause loops. Do this only if you really need to.
+        here, be warned that doing so might cause loops. Do this only if you really need to!
         """
 
         # Run any imports first
@@ -388,7 +399,7 @@ class VMBuilderScript(VMBuilder):
                     src_volume_name,
                 )
                 if not success:
-                    raise ProvisioningError(
+                    self.log_err(
                         f"Failed to unmap source volume '{src_volume_name}': {message}"
                     )
 
@@ -404,6 +415,6 @@ class VMBuilderScript(VMBuilder):
                     dst_volume_name,
                 )
                 if not success:
-                    raise ProvisioningError(
+                    self.log_err(
                         f"Failed to unmap destination volume '{dst_volume_name}': {message}"
                     )

api-daemon/provisioner/examples/script/3-debootstrap.py

@@ -31,6 +31,20 @@
 # function is provided in context of the example; see the other examples for
 # more potential uses.
 
+# Within the VMBuilderScript class, several helper functions are exposed through
+# the parent VMBuilder class:
+#  self.log_info(message):
+#    Use this function to log an "informational" message instead of "print()"
+#  self.log_warn(message):
+#    Use this function to log a "warning" message
+#  self.log_err(message):
+#    Use this function to log an "error" message outside of an exception (see below)
+#  self.fail(message, exception=<ExceptionClass>):
+#    Use this function to bail out of the script safely instead if raising a
+#    normal Python exception. You may pass an optional exception class keyword
+#    argument for posterity in the logs if you wish; otherwise, ProvisioningException
+#    is used. This function implicitly calls a "self.log_err" with the passed message
+
 # Within the VMBuilderScript class, several common variables are exposed through
 # the parent VMBuilder class:
 #  self.vm_name: The name of the VM from PVC's perspective
@@ -132,9 +146,8 @@
 # since they could still do destructive things to /dev and the like!
 
 
-# This import is always required here, as VMBuilder is used by the VMBuilderScript class
+# This import is always required here, as VMBuilder is used by the VMBuilderScript class.
-# and ProvisioningError is the primary exception that should be raised within the class.
+from pvcapid.vmbuilder import VMBuilder
-from pvcapid.vmbuilder import VMBuilder, ProvisioningError
 
 
 # The VMBuilderScript class must be named as such, and extend VMBuilder.
@@ -159,7 +172,7 @@ class VMBuilderScript(VMBuilder):
         if retcode:
             # Raise a ProvisioningError for any exception; the provisioner will handle
             # this gracefully and properly, avoiding dangling mounts, RBD maps, etc.
-            raise ProvisioningError("Failed to find critical dependency: debootstrap")
+            self.fail("Failed to find critical dependency: debootstrap")
 
     def create(self):
         """
@@ -312,9 +325,9 @@ class VMBuilderScript(VMBuilder):
                         volume["source_volume"],
                         f"{self.vm_name}_{volume['disk_id']}",
                     )
-                    print(message)
+                    self.log_info(message)
                     if not success:
-                        raise ProvisioningError(
+                        self.fail(
                             f"Failed to clone volume '{volume['source_volume']}' to '{volume['disk_id']}'."
                         )
             else:
@@ -325,11 +338,9 @@ class VMBuilderScript(VMBuilder):
                         f"{self.vm_name}_{volume['disk_id']}",
                         f"{volume['disk_size_gb']}G",
                     )
-                    print(message)
+                    self.log_info(message)
                     if not success:
-                        raise ProvisioningError(
+                        self.fail(f"Failed to create volume '{volume['disk_id']}'.")
-                            f"Failed to create volume '{volume['disk_id']}'."
-                        )
 
         # Second loop: Map the disks to the local system
         for volume in self.vm_data["volumes"]:
@@ -342,9 +353,9 @@ class VMBuilderScript(VMBuilder):
                     volume["pool"],
                     dst_volume_name,
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(f"Failed to map volume '{dst_volume}'.")
+                    self.fail(f"Failed to map volume '{dst_volume}'.")
 
         # Third loop: Create filesystems on the volumes
         for volume in self.vm_data["volumes"]:
@@ -370,19 +381,17 @@ class VMBuilderScript(VMBuilder):
                     f"mkswap -f /dev/rbd/{dst_volume}"
                 )
                 if retcode:
-                    raise ProvisioningError(
+                    self.fail(f"Failed to create swap on '{dst_volume}': {stderr}")
-                        f"Failed to create swap on '{dst_volume}': {stderr}"
-                    )
             else:
                 retcode, stdout, stderr = pvc_common.run_os_command(
                     f"mkfs.{volume['filesystem']} {filesystem_args} /dev/rbd/{dst_volume}"
                 )
                 if retcode:
-                    raise ProvisioningError(
+                    self.fail(
                         f"Faield to create {volume['filesystem']} file on '{dst_volume}': {stderr}"
                     )
 
-            print(stdout)
+            self.log_info(stdout)
 
         # Create a temporary directory to use during install
         temp_dir = "/tmp/target"
@@ -413,7 +422,7 @@ class VMBuilderScript(VMBuilder):
                 f"mount {mapped_dst_volume} {mount_path}"
             )
             if retcode:
-                raise ProvisioningError(
+                self.fail(
                     f"Failed to mount '{mapped_dst_volume}' on '{mount_path}': {stderr}"
                 )
 
@@ -480,10 +489,10 @@ class VMBuilderScript(VMBuilder):
             if volume["mountpoint"] == "/":
                 root_volume = volume
         if not root_volume:
-            raise ProvisioningError("Failed to find root volume in volumes list")
+            self.fail("Failed to find root volume in volumes list")
 
         # Perform a debootstrap installation
-        print(
+        self.log_info(
             f"Installing system with debootstrap: debootstrap --include={','.join(deb_packages)} {deb_release} {temp_dir} {deb_mirror}"
         )
         os.system(
@@ -735,7 +744,7 @@ GRUB_DISABLE_LINUX_UUID=false
                     f"umount {mount_path}"
                 )
                 if retcode:
-                    raise ProvisioningError(
+                    self.log_err(
                         f"Failed to unmount '{mapped_dst_volume}' on '{mount_path}': {stderr}"
                     )
 
@@ -747,6 +756,4 @@ GRUB_DISABLE_LINUX_UUID=false
                         dst_volume_name,
                     )
                 if not success:
-                    raise ProvisioningError(
+                    self.log_err(f"Failed to unmap '{mapped_dst_volume}': {stderr}")
-                        f"Failed to unmap '{mapped_dst_volume}': {stderr}"
-                    )

api-daemon/provisioner/examples/script/4-rinse.py

@@ -31,6 +31,20 @@
 # function is provided in context of the example; see the other examples for
 # more potential uses.
 
+# Within the VMBuilderScript class, several helper functions are exposed through
+# the parent VMBuilder class:
+#  self.log_info(message):
+#    Use this function to log an "informational" message instead of "print()"
+#  self.log_warn(message):
+#    Use this function to log a "warning" message
+#  self.log_err(message):
+#    Use this function to log an "error" message outside of an exception (see below)
+#  self.fail(message, exception=<ExceptionClass>):
+#    Use this function to bail out of the script safely instead if raising a
+#    normal Python exception. You may pass an optional exception class keyword
+#    argument for posterity in the logs if you wish; otherwise, ProvisioningException
+#    is used. This function implicitly calls a "self.log_err" with the passed message
+
 # Within the VMBuilderScript class, several common variables are exposed through
 # the parent VMBuilder class:
 #  self.vm_name: The name of the VM from PVC's perspective
@@ -132,9 +146,8 @@
 # since they could still do destructive things to /dev and the like!
 
 
-# This import is always required here, as VMBuilder is used by the VMBuilderScript class
+# This import is always required here, as VMBuilder is used by the VMBuilderScript class.
-# and ProvisioningError is the primary exception that should be raised within the class.
+from pvcapid.vmbuilder import VMBuilder
-from pvcapid.vmbuilder import VMBuilder, ProvisioningError
 
 
 # The VMBuilderScript class must be named as such, and extend VMBuilder.
@@ -159,7 +172,7 @@ class VMBuilderScript(VMBuilder):
         if retcode:
             # Raise a ProvisioningError for any exception; the provisioner will handle
             # this gracefully and properly, avoiding dangling mounts, RBD maps, etc.
-            raise ProvisioningError("Failed to find critical dependency: rinse")
+            self.fail("Failed to find critical dependency: rinse")
 
     def create(self):
         """
@@ -312,9 +325,9 @@ class VMBuilderScript(VMBuilder):
                         volume["source_volume"],
                         f"{self.vm_name}_{volume['disk_id']}",
                     )
-                    print(message)
+                    self.log_info(message)
                     if not success:
-                        raise ProvisioningError(
+                        self.fail(
                             f"Failed to clone volume '{volume['source_volume']}' to '{volume['disk_id']}'."
                         )
             else:
@@ -325,11 +338,9 @@ class VMBuilderScript(VMBuilder):
                         f"{self.vm_name}_{volume['disk_id']}",
                         f"{volume['disk_size_gb']}G",
                     )
-                    print(message)
+                    self.log_info(message)
                     if not success:
-                        raise ProvisioningError(
+                        self.fail(f"Failed to create volume '{volume['disk_id']}'.")
-                            f"Failed to create volume '{volume['disk_id']}'."
-                        )
 
         # Second loop: Map the disks to the local system
         for volume in self.vm_data["volumes"]:
@@ -342,9 +353,9 @@ class VMBuilderScript(VMBuilder):
                     volume["pool"],
                     dst_volume_name,
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(f"Failed to map volume '{dst_volume}'.")
+                    self.fail(f"Failed to map volume '{dst_volume}'.")
 
         # Third loop: Create filesystems on the volumes
         for volume in self.vm_data["volumes"]:
@@ -370,19 +381,17 @@ class VMBuilderScript(VMBuilder):
                     f"mkswap -f /dev/rbd/{dst_volume}"
                 )
                 if retcode:
-                    raise ProvisioningError(
+                    self.fail(f"Failed to create swap on '{dst_volume}': {stderr}")
-                        f"Failed to create swap on '{dst_volume}': {stderr}"
-                    )
             else:
                 retcode, stdout, stderr = pvc_common.run_os_command(
                     f"mkfs.{volume['filesystem']} {filesystem_args} /dev/rbd/{dst_volume}"
                 )
                 if retcode:
-                    raise ProvisioningError(
+                    self.fail(
                         f"Faield to create {volume['filesystem']} file on '{dst_volume}': {stderr}"
                     )
 
-            print(stdout)
+            self.log_info(stdout)
 
         # Create a temporary directory to use during install
         temp_dir = "/tmp/target"
@@ -413,7 +422,7 @@ class VMBuilderScript(VMBuilder):
                 f"mount {mapped_dst_volume} {mount_path}"
             )
             if retcode:
-                raise ProvisioningError(
+                self.fail(
                     f"Failed to mount '{mapped_dst_volume}' on '{mount_path}': {stderr}"
                 )
 
@@ -492,7 +501,7 @@ class VMBuilderScript(VMBuilder):
             if volume["mountpoint"] == "/":
                 root_volume = volume
         if not root_volume:
-            raise ProvisioningError("Failed to find root volume in volumes list")
+            self.fail("Failed to find root volume in volumes list")
 
         if rinse_mirror is not None:
             mirror_arg = f"--mirror {rinse_mirror}"
@@ -509,7 +518,7 @@ class VMBuilderScript(VMBuilder):
                 fh.write(f"{pkg}\n")
 
         # Perform a rinse installation
-        print(
+        self.log_info(
             f"Installing system with rinse: rinse --arch {rinse_architecture} --directory {temporary_directory} --distribution {rinse_release} --cache-dir {rinse_cache} --add-pkg-list /tmp/addpkg --verbose {mirror_arg}"
         )
         os.system(
@@ -711,7 +720,7 @@ GRUB_SERIAL_COMMAND="serial --speed=115200 --unit=0 --word=8 --parity=no --stop=
                     f"umount {mount_path}"
                 )
                 if retcode:
-                    raise ProvisioningError(
+                    self.log_err(
                         f"Failed to unmount '{mapped_dst_volume}' on '{mount_path}': {stderr}"
                     )
 
@@ -723,6 +732,4 @@ GRUB_SERIAL_COMMAND="serial --speed=115200 --unit=0 --word=8 --parity=no --stop=
                     dst_volume_name,
                 )
             if not success:
-                raise ProvisioningError(
+                self.log_err(f"Failed to unmap '{mapped_dst_volume}': {stderr}")
-                    f"Failed to unmap '{mapped_dst_volume}': {stderr}"
-                )

api-daemon/provisioner/examples/script/5-pfsense.py

@@ -57,6 +57,20 @@
 # function is provided in context of the example; see the other examples for
 # more potential uses.
 
+# Within the VMBuilderScript class, several helper functions are exposed through
+# the parent VMBuilder class:
+#  self.log_info(message):
+#    Use this function to log an "informational" message instead of "print()"
+#  self.log_warn(message):
+#    Use this function to log a "warning" message
+#  self.log_err(message):
+#    Use this function to log an "error" message outside of an exception (see below)
+#  self.fail(message, exception=<ExceptionClass>):
+#    Use this function to bail out of the script safely instead if raising a
+#    normal Python exception. You may pass an optional exception class keyword
+#    argument for posterity in the logs if you wish; otherwise, ProvisioningException
+#    is used. This function implicitly calls a "self.log_err" with the passed message
+
 # Within the VMBuilderScript class, several common variables are exposed through
 # the parent VMBuilder class:
 #  self.vm_name: The name of the VM from PVC's perspective
@@ -158,9 +172,8 @@
 # since they could still do destructive things to /dev and the like!
 
 
-# This import is always required here, as VMBuilder is used by the VMBuilderScript class
+# This import is always required here, as VMBuilder is used by the VMBuilderScript class.
-# and ProvisioningError is the primary exception that should be raised within the class.
+from pvcapid.vmbuilder import VMBuilder
-from pvcapid.vmbuilder import VMBuilder, ProvisioningError
 
 
 # Set up some variables for later; if you frequently use these tools, you might benefit from
@@ -189,9 +202,7 @@ class VMBuilderScript(VMBuilder):
         # Ensure that our required runtime variables are defined
 
         if self.vm_data["script_arguments"].get("pfsense_wan_iface") is None:
-            raise ProvisioningError(
+            self.fail("Required script argument 'pfsense_wan_iface' not provided")
-                "Required script argument 'pfsense_wan_iface' not provided"
-            )
 
         if self.vm_data["script_arguments"].get("pfsense_wan_dhcp") is None:
             for argument in [
@@ -199,9 +210,7 @@ class VMBuilderScript(VMBuilder):
                 "pfsense_wan_gateway",
             ]:
                 if self.vm_data["script_arguments"].get(argument) is None:
-                    raise ProvisioningError(
+                    self.fail(f"Required script argument '{argument}' not provided")
-                        f"Required script argument '{argument}' not provided"
-                    )
 
         # Ensure we have all dependencies intalled on the provisioner system
         for dependency in "wget", "unzip", "gzip":
@@ -209,9 +218,7 @@ class VMBuilderScript(VMBuilder):
             if retcode:
                 # Raise a ProvisioningError for any exception; the provisioner will handle
                 # this gracefully and properly, avoiding dangling mounts, RBD maps, etc.
-                raise ProvisioningError(
+                self.fail(f"Failed to find critical dependency: {dependency}")
-                    f"Failed to find critical dependency: {dependency}"
-                )
 
         # Create a temporary directory to use for Packer binaries/scripts
         packer_temp_dir = "/tmp/packer"
@@ -361,41 +368,39 @@ class VMBuilderScript(VMBuilder):
         packer_temp_dir = "/tmp/packer"
 
         # Download pfSense image file to temporary target directory
-        print(f"Downloading pfSense ISO image from {PFSENSE_ISO_URL}")
+        self.log_info(f"Downloading pfSense ISO image from {PFSENSE_ISO_URL}")
         retcode, stdout, stderr = pvc_common.run_os_command(
             f"wget --output-document={packer_temp_dir}/dl/pfsense.iso.gz {PFSENSE_ISO_URL}"
         )
         if retcode:
-            raise ProvisioningError(
+            self.fail(f"Failed to download pfSense image from {PFSENSE_ISO_URL}")
-                f"Failed to download pfSense image from {PFSENSE_ISO_URL}"
-            )
 
         # Extract pfSense image file under temporary target directory
-        print(f"Extracting pfSense ISO image")
+        self.log_info(f"Extracting pfSense ISO image")
         retcode, stdout, stderr = pvc_common.run_os_command(
             f"gzip --decompress {packer_temp_dir}/dl/pfsense.iso.gz"
         )
         if retcode:
-            raise ProvisioningError("Failed to extract pfSense ISO image")
+            self.fail("Failed to extract pfSense ISO image")
 
         # Download Packer to temporary target directory
-        print(f"Downloading Packer from {PACKER_URL}")
+        self.log_info(f"Downloading Packer from {PACKER_URL}")
         retcode, stdout, stderr = pvc_common.run_os_command(
             f"wget --output-document={packer_temp_dir}/packer.zip {PACKER_URL}"
         )
         if retcode:
-            raise ProvisioningError(f"Failed to download Packer from {PACKER_URL}")
+            self.fail(f"Failed to download Packer from {PACKER_URL}")
 
         # Extract Packer under temporary target directory
-        print(f"Extracting Packer binary")
+        self.log_info(f"Extracting Packer binary")
         retcode, stdout, stderr = pvc_common.run_os_command(
             f"unzip {packer_temp_dir}/packer.zip -d {packer_temp_dir}"
         )
         if retcode:
-            raise ProvisioningError("Failed to extract Packer binary")
+            self.fail("Failed to extract Packer binary")
 
         # Output the Packer configuration
-        print(f"Generating Packer configurations")
+        self.log_info(f"Generating Packer configurations")
         first_volume = self.vm_data["volumes"][0]
         first_volume_size_mb = int(first_volume["disk_size_gb"]) * 1024
 
@@ -829,7 +834,7 @@ class VMBuilderScript(VMBuilder):
             fh.write(pfsense_config)
 
         # Create the disk(s)
-        print(f"Creating volumes")
+        self.log_info(f"Creating volumes")
         for volume in self.vm_data["volumes"]:
             with open_zk(config) as zkhandler:
                 success, message = pvc_ceph.add_volume(
@@ -838,14 +843,12 @@ class VMBuilderScript(VMBuilder):
                     f"{self.vm_name}_{volume['disk_id']}",
                     f"{volume['disk_size_gb']}G",
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(
+                    self.fail(f"Failed to create volume '{volume['disk_id']}'.")
-                        f"Failed to create volume '{volume['disk_id']}'."
-                    )
 
         # Map the target RBD volumes
-        print(f"Mapping volumes")
+        self.log_info(f"Mapping volumes")
         for volume in self.vm_data["volumes"]:
             dst_volume_name = f"{self.vm_name}_{volume['disk_id']}"
             dst_volume = f"{volume['pool']}/{dst_volume_name}"
@@ -856,9 +859,9 @@ class VMBuilderScript(VMBuilder):
                     volume["pool"],
                     dst_volume_name,
                 )
-                print(message)
+                self.log_info(message)
                 if not success:
-                    raise ProvisioningError(f"Failed to map volume '{dst_volume}'.")
+                    self.fail(f"Failed to map volume '{dst_volume}'.")
 
     def install(self):
         """
@@ -871,7 +874,7 @@ class VMBuilderScript(VMBuilder):
 
         packer_temp_dir = "/tmp/packer"
 
-        print(
+        self.log_info(
             f"Running Packer: PACKER_LOG=1 PACKER_CONFIG_DIR={packer_temp_dir} PACKER_CACHE_DIR={packer_temp_dir} {packer_temp_dir}/packer build {packer_temp_dir}/build.json"
         )
         os.system(
@@ -879,9 +882,9 @@ class VMBuilderScript(VMBuilder):
         )
 
         if not os.path.exists(f"{packer_temp_dir}/bin/{self.vm_name}"):
-            raise ProvisioningError("Packer failed to build output image")
+            self.fail("Packer failed to build output image")
 
-        print("Copying output image to first volume")
+        self.log_info("Copying output image to first volume")
         first_volume = self.vm_data["volumes"][0]
         dst_volume_name = f"{self.vm_name}_{first_volume['disk_id']}"
         dst_volume = f"{first_volume['pool']}/{dst_volume_name}"

api-daemon/pvcapid/vmbuilder.py

@@ -99,13 +99,8 @@ class VMBuilder(object):
     def log_err(self, msg):
         log_err(None, msg)
 
-    def fail(self, msg):
+    def fail(self, msg, exception=ProvisioningError):
-        self.log_err(msg)
+        fail(None, msg, exception=exception)
-        try:
-            self.cleanup()
-        except Exception:
-            pass
-        raise ProvisioningError()
 
     #
     # Primary class functions; implemented by the individual scripts
@@ -693,6 +688,14 @@ def create_vm(
             # We don't care about fails during cleanup, log and continue
             log_warn(celery, f"Suberror during general cleanup script removal: {e}")
 
+    def fail_clean(celery, msg, exception=ProvisioningError):
+        try:
+            vm_builder.cleanup()
+            general_cleanup()
+        except Exception:
+            pass
+        fail(celery, msg, exception=exception)
+
     # Phase 4 - script: setup()
     #  * Run pre-setup steps
     current_stage += 1
@@ -705,7 +708,7 @@ def create_vm(
             vm_builder.setup()
     except Exception as e:
         general_cleanup()
-        fail(
+        fail_clean(
             celery,
             f"Error in script setup() step: {e}",
             exception=ProvisioningError,
@@ -727,7 +730,7 @@ def create_vm(
                 vm_schema = vm_builder.create()
         except Exception as e:
             general_cleanup()
-            fail(
+            fail_clean(
                 celery,
                 f"Error in script create() step: {e}",
                 exception=ProvisioningError,
@@ -775,7 +778,7 @@ def create_vm(
         with chroot(temp_dir):
             vm_builder.cleanup()
         general_cleanup()
-        fail(
+        fail_clean(
             celery,
             f"Error in script prepare() step: {e}",
             exception=ProvisioningError,
@@ -798,7 +801,7 @@ def create_vm(
         with chroot(temp_dir):
             vm_builder.cleanup()
         general_cleanup()
-        fail(
+        fail_clean(
             celery,
             f"Error in script install() step: {e}",
             exception=ProvisioningError,
@@ -818,7 +821,6 @@ def create_vm(
         with chroot(temp_dir):
             vm_builder.cleanup()
     except Exception as e:
-        general_cleanup()
         fail(
             celery,
             f"Error in script cleanup() step: {e}",