From 57787dab5499a38915b5e2f702844553abd2ea2a Mon Sep 17 00:00:00 2001
From: Alejandro Sirgo Rica <asirgo@soleta.eu>
Date: Wed, 20 Mar 2024 12:42:26 +0100
Subject: live: improve lzop and partclone error handling

Control non 0 returncode of the lzop and partclone subprocess
in image creation and restoration because this means that either
lzop or partclone has failed.
The implementation must cover cases such as not enough storage
space and log errors into /tmp/command.log and the log file of
the client handling the request.
Check the returncode of lzop and partclone subprocesses and
log the stderr of the process reporting non zero returncode.
---
 src/live/ogOperations.py | 74 ++++++++++++++++++++++++++++++------------------
 1 file changed, 47 insertions(+), 27 deletions(-)

diff --git a/src/live/ogOperations.py b/src/live/ogOperations.py
index 05c6a10..364f3bd 100644
--- a/src/live/ogOperations.py
+++ b/src/live/ogOperations.py
@@ -183,20 +183,35 @@ class OgLiveOperations:
     def _restore_image(self, image_path, devpath):
         logging.debug(f'Restoring image at {image_path} into {devpath}')
         logging.debug(f'This process can take some time, please *DO NOT SHUT DOWN OR REBOOT* this client')
+
         cmd_lzop = shlex.split(f'lzop -dc {image_path}')
         cmd_pc = shlex.split(f'partclone.restore -d0 -C -I -o {devpath}')
 
         if not os.path.exists(image_path):
             raise RuntimeError(f'Image not found at {image_path} during image restore')
 
+        proc_lzop = subprocess.Popen(cmd_lzop,
+                                     stdout=subprocess.PIPE,
+                                     stderr=subprocess.PIPE)
+        proc_pc = subprocess.Popen(cmd_pc,
+                                   stdin=proc_lzop.stdout,
+                                   stderr=subprocess.PIPE)
+
+        pc_stderr = proc_pc.communicate()[1]
+        lzop_stderr = proc_lzop.stderr.read()
+        proc_lzop.poll() # update returncode
+
         with open('/tmp/command.log', 'wb', 0) as logfile:
-            proc_lzop = subprocess.Popen(cmd_lzop,
-                                         stdout=subprocess.PIPE)
-            proc_pc = subprocess.Popen(cmd_pc,
-                                       stdin=proc_lzop.stdout,
-                                       stderr=logfile)
-            proc_lzop.stdout.close()
-            proc_pc.communicate()
+                logfile.write(lzop_stderr)
+                logfile.write(pc_stderr)
+
+        if proc_lzop.returncode != 0:
+            raise OSError(f'lzop subprocess failed: {lzop_stderr.decode("utf-8")}')
+
+        if proc_pc.returncode != 0:
+            raise OSError(f'partclone subprocess failed: {pc_stderr.decode("utf-8")}')
+
+        logging.info('Image restore successful')
 
     def _ogbrowser_clear_logs(self):
         logfiles = ['/tmp/command.log', '/tmp/session.log']
@@ -450,32 +465,37 @@ class OgLiveOperations:
             if ogReduceFs(disk, partition) == -1:
                 raise ValueError(f'Failed to shrink {fstype} filesystem in {padev}')
 
-            cmd1 = shlex.split(f'partclone.{fstype} -I -C --clone -s {padev} -O -')
-            cmd2 = shlex.split(f'lzop -1 -fo {image_path}')
-
-            logfile = open('/tmp/command.log', 'wb', 0)
-
             if os.path.exists(image_path) and backup:
                 shutil.move(image_path, f'{image_path}.ant')
 
-            p1 = Popen(cmd1, stdout=PIPE, stderr=logfile)
-            p2 = Popen(cmd2, stdin=p1.stdout)
-            p1.stdout.close()
-
             logging.info(f'Creating image at {image_path} from {padev} using {fstype}')
             logging.info('*DO NOT REBOOT OR POWEROFF* the client during this time')
 
-            try:
-                retdata = p2.communicate()
-            except OSError as e:
-                raise OSError(f'Unexpected error when running partclone and lzop commands: {e}') from e
-            finally:
-                logfile.close()
-                p2.terminate()
-                p1.poll()
-
-            logging.info(f'partclone process exited with code {p1.returncode}')
-            logging.info(f'lzop process exited with code {p2.returncode}')
+            cmd_pc = shlex.split(f'partclone.{fstype} -I -C --clone -s {padev} -O -')
+            cmd_lzop = shlex.split(f'lzop -1 -fo {image_path}')
+
+            proc_pc = subprocess.Popen(cmd_pc,
+                                       stdout=subprocess.PIPE,
+                                       stderr=subprocess.PIPE)
+            proc_lzop = subprocess.Popen(cmd_lzop,
+                                         stdin=proc_pc.stdout,
+                                         stderr=subprocess.PIPE)
+
+            lzop_stderr = proc_lzop.communicate()[1]
+            pc_stderr = proc_pc.stderr.read()
+            proc_pc.poll() # update returncode
+
+            with open('/tmp/command.log', 'wb', 0) as logfile:
+                logfile.write(pc_stderr)
+                logfile.write(lzop_stderr)
+
+            if proc_pc.returncode != 0:
+                raise OSError(f'partclone subprocess failed: {pc_stderr.decode("utf-8")}')
+
+            if proc_lzop.returncode != 0:
+                raise OSError(f'lzop subprocess failed: {lzop_stderr.decode("utf-8")}')
+
+            logging.info('Image creation successful')
 
             ogExtendFs(disk, partition)
 
-- 
cgit v1.2.3-18-g5258