src: log backtrace in unhandled error cases

Log an error message in known error cases and log a backtrace
otherwise.

Define a new error type OgError to be used in all the 'raise'
blocks to define the error message to log. The exception
propagates until it reaches send_internal_server_error() where
the exception type is checked. If the type is OgError we log
the exception message. Logs the backtrace for other types.

The initial error implementation printed a backtrace everytime
an error ocurred. The next iteration changed it to only print
a backtrace in a very particular case but ended up omiting too
much information such as syntax errors or unknown error context.
The actual implementation only logs the cases we already cover in
the codebase and logs a bracktrace in the others, enabling a
better debugging experience.

8 files changed, 57 insertions, 49 deletions

diff --git a/src/utils/bios.py b/src/utils/bios.py
index 1c16633..9c62b38 100644
--- a/src/utils/bios.py
+++ b/src/utils/bios.py
@@ -8,6 +8,7 @@
 
 import logging
 import os
+from src.log import OgError
 
 
 def get_grub_boot_params(mountpoint, device):
@@ -35,7 +36,7 @@ def get_vmlinuz_path(mountpoint):
             target_file = file
 
     if not target_file:
-        raise FileNotFoundError(f'vmlinuz not found in {initrd_dir}')
+        raise OgError(f'vmlinuz not found in {initrd_dir}')
 
     return os.path.join(linuz_dir, target_file)
 
@@ -48,6 +49,6 @@ def get_initrd_path(mountpoint):
             target_file = file
 
     if not target_file:
-        raise FileNotFoundError(f'initrd not found in {initrd_dir}')
+        raise OgError(f'initrd not found in {initrd_dir}')
 
     return os.path.join(initrd_dir, target_file)
diff --git a/src/utils/boot.py b/src/utils/boot.py
index 9ce5238..6ee7450 100644
--- a/src/utils/boot.py
+++ b/src/utils/boot.py
@@ -17,13 +17,14 @@ from src.utils.disk import get_partition_device, get_efi_partition
 from src.utils.bios import *
 from src.utils.uefi import *
 from src.utils.fs import *
+from src.log import OgError
 
 
 def _boot_bios_linux(disk, part, mountpoint):
     logging.info(f'Booting Linux system')
 
     if not get_linux_distro_id(mountpoint) == 'ubuntu':
-        raise NotImplementedError(f'{os_probe(mountpoint)} detected, only Ubuntu is supported for legacy BIOS boot')
+        raise OgError(f'{os_probe(mountpoint)} detected, only Ubuntu is supported for legacy BIOS boot')
 
     kernel_path = get_vmlinuz_path(mountpoint)
     initrd_path = get_initrd_path(mountpoint)
@@ -39,7 +40,7 @@ def _boot_bios_linux(disk, part, mountpoint):
         subprocess.run(shlex.split(kexec_cmd), check=True, text=True)
         subprocess.run(shlex.split(kexec_reboot_cmd), check=True, text=True)
     except OSError as e:
-        raise OSError(f'Error processing kexec: {e}') from e
+        raise OgError(f'Error processing kexec: {e}') from e
 
 def _boot_bios_windows(disk, part, mountpoint):
     logging.info(f'Booting Windows system')
@@ -52,7 +53,7 @@ def _boot_bios_windows(disk, part, mountpoint):
         with open(f'{mountpoint}/ogboot.secondboot', 'w') as f:
             f.write('\0' * (3072))
     except OSError as e:
-        raise OSError(f'Could not create ogboot files in Windows partition: {e}') from e
+        raise OgError(f'Could not create ogboot files in Windows partition: {e}') from e
 
 def _boot_uefi_windows(disk, part, mountpoint):
     logging.info(f'Booting windows system')
@@ -60,7 +61,7 @@ def _boot_uefi_windows(disk, part, mountpoint):
     esp, esp_disk, esp_part_number = get_efi_partition(disk, enforce_gpt=True)
     esp_mountpoint = esp.replace('dev', 'mnt')
     if not mount_mkdir(esp, esp_mountpoint):
-        raise RuntimeError(f'Unable to mount detected EFI System Partition at {esp} into {esp_mountpoint}')
+        raise OgError(f'Unable to mount detected EFI System Partition at {esp} into {esp_mountpoint}')
 
     loader_paths = [f'{esp_mountpoint}/EFI/{bootlabel}/Boot/bootmgfw.efi',
                     f'{esp_mountpoint}/EFI/Microsoft/Boot/bootmgfw.efi']
@@ -71,7 +72,7 @@ def _boot_uefi_windows(disk, part, mountpoint):
                 logging.info(f'Found bootloader at ESP partition: {loader}')
                 break
         else:
-            raise RuntimeError(f'Unable to locate Windows EFI bootloader bootmgfw.efi')
+            raise OgError(f'Unable to locate Windows EFI bootloader bootmgfw.efi')
 
         efibootmgr_delete_bootentry(bootlabel)
         efibootmgr_create_bootentry(esp_disk, esp_part_number, loader, bootlabel)
@@ -85,7 +86,7 @@ def _boot_uefi_linux(disk, part, mountpoint):
     esp, esp_disk, esp_part_number = get_efi_partition(disk, enforce_gpt=False)
     esp_mountpoint = esp.replace('dev', 'mnt')
     if not mount_mkdir(esp, esp_mountpoint):
-        raise RuntimeError(f'Unable to mount detected EFI System Partition at {esp} into {esp_mountpoint}')
+        raise OgError(f'Unable to mount detected EFI System Partition at {esp} into {esp_mountpoint}')
 
     loader_paths = [f'{esp_mountpoint}/EFI/{bootlabel}/Boot/shimx64.efi',
                     f'{esp_mountpoint}/EFI/ubuntu/shimx64.efi']
@@ -96,7 +97,7 @@ def _boot_uefi_linux(disk, part, mountpoint):
                 logging.info(f'Found bootloader at ESP partition: {loader}')
                 break
         else:
-            raise RuntimeError(f'Unable to locate Linux EFI bootloader shimx64.efi')
+            raise OgError(f'Unable to locate Linux EFI bootloader shimx64.efi')
 
         efibootmgr_delete_bootentry(bootlabel)
         efibootmgr_create_bootentry(esp_disk, esp_part_number, loader, bootlabel)
@@ -109,7 +110,7 @@ def boot_os_at(disk, part):
     device = get_partition_device(disk, part)
     mountpoint = device.replace('dev', 'mnt')
     if not mount_mkdir(device, mountpoint):
-        raise RuntimeError(f'Cannot probe OS family. Unable to mount {device} into {mountpoint}')
+        raise OgError(f'Cannot probe OS family. Unable to mount {device} into {mountpoint}')
 
     is_uefi = is_uefi_supported()
     if is_uefi:
@@ -130,6 +131,6 @@ def boot_os_at(disk, part):
         elif not is_uefi and os_family == OSFamily.LINUX:
             _boot_bios_linux(disk, part, mountpoint)
         else:
-            raise RuntimeError(f'Unknown OS family {os_family}')
+            raise OgError(f'Unknown OS family {os_family}')
     finally:
         umount(mountpoint)
diff --git a/src/utils/disk.py b/src/utils/disk.py
index 323994c..a44153d 100644
--- a/src/utils/disk.py
+++ b/src/utils/disk.py
@@ -8,6 +8,7 @@
 
 import os
 import logging
+from src.log import OgError
 
 import fdisk
 
@@ -29,7 +30,7 @@ def get_partition_device(disknum, partnum):
     """
     disk_index = disknum - 1
     if disk_index < 0 or disk_index >= len(get_disks()):
-        raise ValueError(f'Invalid disk number {disknum}, {len(get_disks())} disks available.')
+        raise OgError(f'Invalid disk number {disknum}, {len(get_disks())} disks available.')
 
     disk = get_disks()[disk_index]
     cxt = fdisk.Context(f'/dev/{disk}')
@@ -38,7 +39,7 @@ def get_partition_device(disknum, partnum):
         if pa.partno == partnum - 1:
             return cxt.partition_to_string(pa, fdisk.FDISK_FIELD_DEVICE)
 
-    raise ValueError(f'No such partition with disk index {disknum} and partition index {partnum}')
+    raise OgError(f'No such partition with disk index {disknum} and partition index {partnum}')
 
 
 def get_efi_partition(disknum, enforce_gpt):
@@ -55,16 +56,16 @@ def get_efi_partition(disknum, enforce_gpt):
     """
     disk_index = disknum - 1
     if disk_index < 0 or disk_index >= len(get_disks()):
-        raise ValueError(f'Invalid disk number {disknum} when trying to find ESP, {len(get_disks())} disks available.')
+        raise OgError(f'Invalid disk number {disknum} when trying to find ESP, {len(get_disks())} disks available.')
 
     disk = get_disks()[disk_index]
     cxt = fdisk.Context(f'/dev/{disk}')
 
     if enforce_gpt and cxt.label == fdisk.FDISK_DISKLABEL_DOS:
-        raise RuntimeError(f'Windows EFI System requires GPT partition scheme, but /dev/{disk} has DOS partition scheme')
+        raise OgError(f'Windows EFI System requires GPT partition scheme, but /dev/{disk} has DOS partition scheme')
 
     for pa in cxt.partitions:
         logging.info(f'Checking partition "{pa.type.name}"...')
         if pa.type.name == 'EFI System':
             return cxt.partition_to_string(pa, fdisk.FDISK_FIELD_DEVICE), f'/dev/{disk}', pa.partno + 1
-    raise RuntimeError(f'Cannot find "EFI System" partition at /dev/{disk}')
+    raise OgError(f'Cannot find "EFI System" partition at /dev/{disk}')
diff --git a/src/utils/fs.py b/src/utils/fs.py
index 7e1d115..83d8d47 100644
--- a/src/utils/fs.py
+++ b/src/utils/fs.py
@@ -10,6 +10,7 @@ import logging
 import os
 import subprocess
 import shlex
+from src.log import OgError
 
 from subprocess import DEVNULL, PIPE, STDOUT
 
@@ -148,12 +149,12 @@ def mkfs(fs, disk, partition, label=None):
     }
 
     if fs not in fsdict:
-        raise ValueError(f'mkfs failed, unsupported target filesystem {fs}')
+        raise OgError(f'mkfs failed, unsupported target filesystem {fs}')
 
     try:
         partdev = get_partition_device(disk, partition)
     except ValueError as e:
-        raise ValueError(f'mkfs aborted: {e}') from e
+        raise OgError(f'mkfs aborted: {e}') from e
 
     fsdict[fs](partdev, label)
 
@@ -249,11 +250,11 @@ def _reduce_ntfsresize(partdev):
         data_split = output_data.split(pattern)
         # If we fail to match pattern in the split then data_split will contain [output_data]
         if len(data_split) == 1:
-            raise ValueError(f'nfsresize: failed to find: {pattern}')
+            raise OgError(f'nfsresize: failed to find: {pattern}')
         value_str = data_split[1].split(' ')[0]
 
         if not value_str.isdigit() or value_str.startswith('-'):
-            raise ValueError(f'nfsresize: failed to parse numeric value at {pattern}')
+            raise OgError(f'nfsresize: failed to parse numeric value at {pattern}')
         return int(value_str)
 
     try:
@@ -307,11 +308,11 @@ def _extend_resize2fs(partdev):
     cmd = shlex.split(f'resize2fs -f {partdev}')
     proc = subprocess.run(cmd)
     if proc.returncode != 0:
-        raise RuntimeError(f'Error growing ext4 filesystem at {partdev}')
+        raise OgError(f'Error growing ext4 filesystem at {partdev}')
 
 
 def _extend_ntfsresize(partdev):
     cmd = shlex.split(f'ntfsresize -f {partdev}')
     proc = subprocess.run(cmd, input=b'y')
     if proc.returncode != 0:
-        raise RuntimeError(f'Error growing ntfs filesystem at {partdev}')
+        raise OgError(f'Error growing ntfs filesystem at {partdev}')
diff --git a/src/utils/hw_inventory.py b/src/utils/hw_inventory.py
index c534101..7341dac 100644
--- a/src/utils/hw_inventory.py
+++ b/src/utils/hw_inventory.py
@@ -10,6 +10,7 @@ import json
 import os.path
 import shlex
 import subprocess
+from src.log import OgError
 
 from collections import namedtuple
 from enum import Enum, auto
@@ -55,16 +56,16 @@ class HardwareInventory():
 
     def add_element(self, elem):
         if elem.type not in HardwareType:
-            raise ValueError(f'Unsupported hardware type, received {elem.type}')
+            raise OgError(f'Unsupported hardware type, received {elem.type}')
         if not elem.name:
-            raise ValueError('Empty hardware element name')
+            raise OgError('Empty hardware element name')
         self.elements.append(elem)
 
 
 def _bytes_to_human(size):
     suffixes = ['B', 'MiB', 'GiB', 'TiB']
     if type(size) is not int:
-        raise TypeError(f'Invalid type in _bytes_to_human, got: {size} {type(size)}')
+        raise OgError(f'Invalid type in _bytes_to_human, got: {size} {type(size)}')
     for exponent, suffix in enumerate(suffixes, start=1):
         conv = size / (1024**exponent)
         if conv < 1024:
@@ -250,7 +251,7 @@ def legacy_hardware_element(element):
     represented as "vga=Foo"
     """
     if type(element) is not HardwareElement:
-        raise TypeError('Invalid hardware element type')
+        raise OgError('Invalid hardware element type')
     elif element.type is HardwareType.MULTIMEDIA:
         nemonic = 'mul'
     elif element.type is HardwareType.BOOTMODE:
@@ -297,7 +298,7 @@ def get_hardware_inventory():
     if type(j) is list:
         root = j[0]
     if type(root) is not dict:
-        raise ValueError('Invalid lshw json output')
+        raise OgError('Invalid lshw json output')
 
     inventory = HardwareInventory()
     _fill_computer_model(inventory, root)
diff --git a/src/utils/legacy.py b/src/utils/legacy.py
index e740450..cdc79c9 100644
--- a/src/utils/legacy.py
+++ b/src/utils/legacy.py
@@ -16,6 +16,7 @@ import shutil
 from subprocess import PIPE, DEVNULL, STDOUT, CalledProcessError
 
 from src.utils.fs import umount
+from src.log import OgError
 
 
 class ImageInfo:
@@ -75,9 +76,9 @@ def image_info_from_partclone(partclone_output):
         fill_imageinfo(line, image_info)
 
     if not image_info.datasize:
-        raise ValueError("Missing device size from partclone.info output")
+        raise OgError("Missing device size from partclone.info output")
     elif not image_info.filesystem:
-        raise ValueError("Missing filesystem from partclone.info output")
+        raise OgError("Missing filesystem from partclone.info output")
 
     return image_info
 
@@ -100,7 +101,7 @@ def run_lzop_partcloneinfo(image_path):
     p2_out, p2_err = p2.communicate()
 
     if p2.returncode != 0:
-        raise ValueError(f'Unable to process image {image_path}')
+        raise OgError(f'Unable to process image {image_path}')
 
     return p2_out
 
@@ -174,7 +175,7 @@ def ogChangeRepo(ip, smb_user='opengnsys', smb_pass='og'):
     try:
         ipaddr = ipaddress.ip_address(ip)
     except ValueError as e:
-        raise ValueError(f'Invalid IP address {ip} received')
+        raise OgError(f'Invalid IP address {ip} received') from e
 
     mounted = False
     with open('/etc/mtab') as f:
@@ -209,7 +210,7 @@ def restoreImageCustom(repo_ip, image_name, disk, partition, method):
     """
     """
     if not shutil.which('restoreImageCustom'):
-        raise OSError('restoreImageCustom not found')
+        raise OgError('restoreImageCustom not found')
 
     cmd = f'restoreImageCustom {repo_ip} {image_name} {disk} {partition} {method}'
     with open('/tmp/command.log', 'wb', 0) as logfile:
@@ -220,7 +221,7 @@ def restoreImageCustom(repo_ip, image_name, disk, partition, method):
                                   shell=True,
                                   check=True)
         except OSError as e:
-            raise OSError(f'Error processing restoreImageCustom: {e}') from e
+            raise OgError(f'Error processing restoreImageCustom: {e}') from e
     return proc.returncode
 
 
@@ -240,6 +241,6 @@ def configureOs(disk, partition):
                               check=True)
         out = proc.stdout
     except OSError as e:
-        raise OSError(f'Error processing configureOsCustom: {e}') from e
+        raise OgError(f'Error processing configureOsCustom: {e}') from e
 
     return out
diff --git a/src/utils/tiptorrent.py b/src/utils/tiptorrent.py
index 18c4df7..83ca052 100644
--- a/src/utils/tiptorrent.py
+++ b/src/utils/tiptorrent.py
@@ -13,6 +13,7 @@ import shlex
 import shutil
 import subprocess
 import urllib.request
+from src.log import OgError
 
 def _compute_md5(path, bs=2**20):
     m = hashlib.md5()
@@ -33,9 +34,9 @@ def tip_fetch_csum(tip_addr, image_name):
         with urllib.request.urlopen(f'{url}') as resp:
             r = resp.readline().rstrip().decode('utf-8')
     except urllib.error.URLError as e:
-        raise urllib.error.URLError(f'URL error when fetching checksum: {e.reason}') from e
+        raise OgError(f'URL error when fetching checksum: {e.reason}') from e
     except urllib.error.HTTPError as e:
-        raise urllib.error.URLError(f'HTTP Error when fetching checksum: {e.reason}') from e
+        raise OgError(f'HTTP Error when fetching checksum: {e.reason}') from e
     return r
 
 
@@ -46,7 +47,7 @@ def tip_write_csum(image_name):
     image_path = f'/opt/opengnsys/cache/opt/opengnsys/images/{image_name}.img'
 
     if not os.path.exists(image_path):
-        raise RuntimeError(f'Invalid image path {image_path} for tiptorrent checksum writing')
+        raise OgError(f'Invalid image path {image_path} for tiptorrent checksum writing')
 
     filename = image_path + ".full.sum"
     csum = _compute_md5(image_path)
@@ -62,7 +63,7 @@ def tip_check_csum(tip_addr, image_name):
     logging.info(f'Verifying checksum for {image_name}.img, please wait...')
     image_path = f'/opt/opengnsys/cache/opt/opengnsys/images/{image_name}.img'
     if not os.path.exists(image_path):
-        raise RuntimeError(f'Invalid image path {image_path} for tiptorrent image csum comparison')
+        raise OgError(f'Invalid image path {image_path} for tiptorrent image csum comparison')
 
     cache_csum = _compute_md5(image_path)
     remote_csum = tip_fetch_csum(tip_addr, image_name)
@@ -85,12 +86,12 @@ def tip_client_get(tip_addr, image_name):
                                 cwd='/opt/opengnsys/cache/opt/opengnsys/images/')
         proc.communicate()
     except OSError as e:
-        raise OSError('Unexpected error running tiptorrent subprocess: {e}') from e
+        raise OgError('Unexpected error running tiptorrent subprocess: {e}') from e
     finally:
         logfile.close()
 
     if proc.returncode != 0:
-        raise RuntimeError(f'Error fetching image {image_name} via tiptorrent')
+        raise OgError(f'Error fetching image {image_name} via tiptorrent')
     else:
         logging.info('Calculating checksum...')
         logging.info('*DO NOT REBOOT OR POWEROFF* the client during this time')
diff --git a/src/utils/uefi.py b/src/utils/uefi.py
index b51d765..17b35cb 100644
--- a/src/utils/uefi.py
+++ b/src/utils/uefi.py
@@ -15,6 +15,7 @@ import shutil
 from src.utils.disk import *
 from src.utils.fs import *
 from src.utils.probe import *
+from src.log import OgError
 
 import fdisk
 
@@ -25,14 +26,14 @@ def _find_bootentry(entries, label):
         if entry['description'] == label:
             return entry
     else:
-        raise NameError('Boot entry {label} not found')
+        raise OgError('Boot entry {label} not found')
 
 
 def _strip_boot_prefix(entry):
     try:
         num = entry['name'][4:]
     except:
-        raise KeyError('Unable to strip "Boot" prefix from boot entry')
+        raise OgError('Unable to strip "Boot" prefix from boot entry')
     return num
 
 
@@ -56,7 +57,7 @@ def is_uefi_supported():
 
 def run_efibootmgr_json():
     if _check_efibootmgr_json() is False:
-        raise RuntimeError(f'{EFIBOOTMGR_BIN} not available')
+        raise OgError(f'{EFIBOOTMGR_BIN} not available')
 
     proc = subprocess.run([EFIBOOTMGR_BIN, '--json'], capture_output=True, text=True)
     dict_json = json.loads(proc.stdout)
@@ -99,14 +100,14 @@ def efibootmgr_create_bootentry(disk, part, loader, label, add_to_bootorder=True
     try:
         proc = subprocess.run(shlex.split(efibootmgr_cmd), check=True, text=True)
     except OSError as e:
-        raise OSError(f'Unexpected error adding boot entry to nvram. UEFI firmware might be buggy') from e
+        raise OgError(f'Unexpected error adding boot entry to nvram. UEFI firmware might be buggy') from e
 
 
 def copy_windows_efi_bootloader(disk, partition):
     device = get_partition_device(disk, partition)
     mountpoint = device.replace('dev', 'mnt')
     if not mount_mkdir(device, mountpoint):
-        raise RuntimeError(f'Cannot probe OS family. Unable to mount {device} into {mountpoint}')
+        raise OgError(f'Cannot probe OS family. Unable to mount {device} into {mountpoint}')
 
     os_family = get_os_family(mountpoint)
     is_uefi = is_uefi_supported()
@@ -119,7 +120,7 @@ def copy_windows_efi_bootloader(disk, partition):
     esp_mountpoint = esp.replace('dev', 'mnt')
     if not mount_mkdir(esp, esp_mountpoint):
         umount(mountpoint)
-        raise RuntimeError(f'Unable to mount detected EFI System Partition at {esp} into {esp_mountpoint}')
+        raise OgError(f'Unable to mount detected EFI System Partition at {esp} into {esp_mountpoint}')
 
     loader_paths = [f'{esp_mountpoint}/EFI/{bootlabel}/Boot/bootmgfw.efi',
                     f'{esp_mountpoint}/EFI/Microsoft/Boot/bootmgfw.efi']
@@ -131,7 +132,7 @@ def copy_windows_efi_bootloader(disk, partition):
                 logging.info(f'Found bootloader at ESP partition: {loader}')
                 break
         else:
-            raise RuntimeError(f'Unable to locate Windows EFI bootloader bootmgfw.efi')
+            raise OgError(f'Unable to locate Windows EFI bootloader bootmgfw.efi')
 
         loader_dir = os.path.dirname(loader)
         destination_dir = f'{mountpoint}/ogBoot'
@@ -139,12 +140,12 @@ def copy_windows_efi_bootloader(disk, partition):
             try:
                 shutil.rmtree(destination_dir)
             except Exception as e:
-                raise OSError(f'Failed to delete {destination_dir}: {e}') from e
+                raise OgError(f'Failed to delete {destination_dir}: {e}') from e
         logging.info(f'Copying {loader_dir} into {destination_dir}')
         try:
             shutil.copytree(loader_dir, destination_dir)
         except Exception as e:
-            raise OSError(f'Failed to copy {loader_dir} into {destination_dir}: {e}') from e
+            raise OgError(f'Failed to copy {loader_dir} into {destination_dir}: {e}') from e
     finally:
         umount(mountpoint)
         umount(esp_mountpoint)