mdadm logging done, some value errors converted to type errors

aif/config/parser.py

@@ -166,8 +166,9 @@ class Config(object):
                 _logger.debug('Converting instance\'s stripped XML to a string')
                 obj = self.xml
         else:
-            raise ValueError(('obj parameter must be "tree", "xml", or of type '
+            _logger.error(('obj parameter must be "tree", "xml", or of type '
                            'lxml.etree._Element or lxml.etree._ElementTree'))
+            raise TypeError('Invalid obj type')
         obj = copy.deepcopy(obj)
         strxml = etree.tostring(obj,
                                 encoding = 'utf-8',
@@ -263,7 +264,7 @@ def getConfig(cfg_ref, validate = True, populate_defaults = True, xsd_path = Non
             ptrn = re.compile(detector['raw'][0].pattern.encode('utf-8'))
             if not ptrn.search(cfg_ref):
                 _logger.error('Could not detect which configuration type was passed.')
-                raise ValueError('Unespected/unparseable cfg_ref.')
+                raise ValueError('Unexpected/unparseable cfg_ref.')
             else:
                 _logger.info('Config detected as ConfigBin.')
                 cfgobj = ConfigBin(cfg_ref, xsd_path = xsd_path)

aif/disk/filesystem.py

@@ -37,7 +37,7 @@ class FS(object):
                            'aif.disk.luks.LUKS, '
                            'aif.disk.lvm.LV, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid sourceobj type')
+            raise TypeError('Invalid sourceobj type')
         self.source = sourceobj
         self.devpath = sourceobj.devpath
         self.formatted = False
@@ -83,7 +83,7 @@ class Mount(object):
         _logger.debug('mount_xml: {0}'.format(etree.tostring(self.xml, with_tail = False).decode('utf-8')))
         if not isinstance(fsobj, FS):
             _logger.error('partobj must be of type aif.disk.filesystem.FS.')
-            raise ValueError('Invalid type for fsobj')
+            raise TypeError('Invalid fsobj type')
         _common.addBDPlugin('fs')  # We *could* use the UDisks dbus to mount too, but best to stay within libblockdev.
         self.id = self.xml.attrib['id']
         self.fs = fsobj

aif/disk/filesystem_fallback.py

@@ -32,7 +32,7 @@ class FS(object):
                            'aif.disk.luks.LUKS, '
                            'aif.disk.lvm.LV, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid sourceobj type')
+            raise TypeError('Invalid sourceobj type')
         self.id = self.xml.attrib['id']
         self.source = sourceobj
         self.devpath = sourceobj.devpath
@@ -77,7 +77,7 @@ class Mount(object):
         self.id = self.xml.attrib['id']
         if not isinstance(fsobj, FS):
             _logger.error('partobj must be of type aif.disk.filesystem.FS.')
-            raise ValueError('Invalid type for fsobj')
+            raise TypeError('Invalid fsobj type')
         self.id = self.xml.attrib['id']
         self.fs = fsobj
         self.source = self.fs.devpath

aif/disk/luks.py

@@ -72,7 +72,7 @@ class LUKS(object):
                            'aif.disk.block.Partition, '
                            'aif.disk.lvm.LV, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid partobj type')
+            raise TypeError('Invalid partobj type')
         _common.addBDPlugin('crypto')
         self.devpath = '/dev/mapper/{0}'.format(self.name)
         self.info = None
@@ -83,7 +83,7 @@ class LUKS(object):
                           'aif.disk.luks.LuksSecret '
                           '(aif.disk.luks.LuksSecretPassphrase or '
                           'aif.disk.luks.LuksSecretFile).')
-            raise ValueError('Invalid secretobj type')
+            raise TypeError('Invalid secretobj type')
         self.secrets.append(secretobj)
         return(None)
 

aif/disk/luks_fallback.py

@@ -71,7 +71,7 @@ class LUKS(object):
                            'aif.disk.block.Partition, '
                            'aif.disk.lvm.LV, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid partobj type')
+            raise TypeError('Invalid partobj type')
         self.devpath = '/dev/mapper/{0}'.format(self.name)
         self.info = None
 
@@ -81,7 +81,7 @@ class LUKS(object):
                           'aif.disk.luks.LuksSecret '
                           '(aif.disk.luks.LuksSecretPassphrase or '
                           'aif.disk.luks.LuksSecretFile).')
-            raise ValueError('Invalid secretobj type')
+            raise TypeError('Invalid secretobj type')
         self.secrets.append(secretobj)
         return(None)
 

aif/disk/lvm.py

@@ -28,7 +28,7 @@ class LV(object):
         self.pvs = []
         if not isinstance(self.vg, VG):
             _logger.debug('vgobj must be of type aif.disk.lvm.VG')
-            raise ValueError('Invalid vgobj type')
+            raise TypeError('Invalid vgobj type')
         _common.addBDPlugin('lvm')
         self.info = None
         self.devpath = '/dev/{0}/{1}'.format(self.vg.name, self.name)
@@ -150,7 +150,7 @@ class PV(object):
                            'aif.disk.block.Partition, '
                            'aif.disk.luks.LUKS, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid partobj type')
+            raise TypeError('Invalid partobj type')
         _common.addBDPlugin('lvm')
         self.devpath = self.device.devpath
         self.is_pooled = False
@@ -263,7 +263,7 @@ class VG(object):
     def addPV(self, pvobj):
         if not isinstance(pvobj, PV):
             _logger.error('pvobj must be of type aif.disk.lvm.PV.')
-            raise ValueError('Invalid pvbobj type')
+            raise TypeError('Invalid pvbobj type')
         pvobj.prepare()
         self.pvs.append(pvobj)
         return(None)

aif/disk/lvm_fallback.py

@@ -26,7 +26,7 @@ class LV(object):
         self.pvs = []
         if not isinstance(self.vg, VG):
             _logger.debug('vgobj must be of type aif.disk.lvm.VG')
-            raise ValueError('Invalid vgobj type')
+            raise TypeError('Invalid vgobj type')
         self.info = None
         self.devpath = '/dev/{0}/{1}'.format(self.vg.name, self.name)
         self.created = False
@@ -211,7 +211,7 @@ class PV(object):
                            'aif.disk.block.Partition, '
                            'aif.disk.luks.LUKS, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid partobj type')
+            raise TypeError('Invalid partobj type')
         self.devpath = self.device.devpath
         self.is_pooled = False
         self.meta = None
@@ -327,7 +327,7 @@ class VG(object):
     def addPV(self, pvobj):
         if not isinstance(pvobj, PV):
             _logger.error('pvobj must be of type aif.disk.lvm.PV.')
-            raise ValueError('Invalid pvbobj type')
+            raise TypeError('Invalid pvbobj type')
         pvobj.prepare()
         self.pvs.append(pvobj)
         return(None)

aif/disk/mdadm.py

@@ -36,7 +36,7 @@ class Member(object):
                            'aif.disk.luks.LUKS, '
                            'aif.disk.lvm.LV, or'
                            'aif.disk.mdadm.Array.'))
-            raise ValueError('Invalid partobj type')
+            raise TypeError('Invalid partobj type')
         _common.addBDPlugin('mdraid')
         self.devpath = self.device.devpath
         self.is_superblocked = None
@@ -145,7 +145,8 @@ class Array(object):
 
     def create(self):
         if not self.members:
-            raise RuntimeError('Cannot create an array with no members')
+            _logger.error('Cannot create an array with no members.')
+            raise RuntimeError('Missing members')
         opts = [_BlockDev.ExtraArg.new('--homehost',
                                        self.homehost),
                 _BlockDev.ExtraArg.new('--name',
@@ -170,8 +171,10 @@ class Array(object):
         return(None)
 
     def start(self, scan = False):
+        _logger.info('Starting array {0}.'.format(self.name))
         if not any((self.members, self.devpath)):
-            raise RuntimeError('Cannot assemble an array with no members (for hints) or device path')
+            _logger.error('Cannot assemble an array with no members (for hints) or device path.')
+            raise RuntimeError('Cannot start unspecified array')
         if scan:
             target = None
         else:
@@ -185,6 +188,7 @@ class Array(object):
         return(None)
 
     def stop(self):
+        _logger.error('Stopping aray {0}.'.format(self.name))
         _BlockDev.md.deactivate(self.name)
         self.state = 'disassembled'
         return(None)
@@ -209,10 +213,11 @@ class Array(object):
                 v = uuid.UUID(hex = v)
             info[k] = v
         self.info = info
+        _logger.debug('Rendered info: {0}'.format(info))
         return(None)
 
-    def writeConf(self, conf = '/etc/mdadm.conf'):
+    def writeConf(self, chroot_base):
-        conf = os.path.realpath(conf)
+        conf = os.path.join(chroot_base, 'etc', 'mdadm.conf')
         with open(conf, 'r') as fh:
             conflines = fh.read().splitlines()
         arrayinfo = ('ARRAY '
@@ -227,10 +232,9 @@ class Array(object):
             for l in conflines:
                 if r.search(l):
                     nodev = False
-                    # TODO: logging?
+                    # TODO: warning and skip instead?
-                    # and/or Raise an exception here;
+                    _logger.error('An array already exists with that name but not with the same opts/GUID/etc.')
-                    # an array already exists with that name but not with the same opts/GUID/etc.
+                    raise RuntimeError('Duplicate array')
-                    break
             if nodev:
                 with open(conf, 'a') as fh:
                     fh.write('{0}\n'.format(arrayinfo))

aif/disk/mdadm_fallback.py

@@ -16,6 +16,9 @@ import aif.utils
 import aif.constants
 
 
+_logger = logging.getLogger(__name__)
+
+
 _mdblock_size_re = re.compile(r'^(?P<sectors>[0-9]+)\s+'
                               r'\((?P<GiB>[0-9.]+)\s+GiB\s+'
                               r'(?P<GB>[0-9.]+)\s+GB\)')
@@ -29,14 +32,18 @@ _mdblock_badblock_re = re.compile(r'^(?P<entries>[0-9]+)\s+entries'
 class Member(object):
     def __init__(self, member_xml, partobj):
         self.xml = member_xml
+        _logger.debug('member_xml: {0}'.format(etree.tostring(self.xml, with_tail = False).decode('utf-8')))
         self.device = partobj
         if not isinstance(self.device, (block.Partition,
                                         block.Disk,
                                         Array,
                                         lvm.LV,
                                         luks.LUKS)):
-            raise ValueError(('partobj must be of type aif.disk.block.Partition, '
+            _logger.error(('partobj must be of type '
-                              'aif.disk.block.Disk, or aif.disk.mdadm.Array'))
+                           'aif.disk.block.Partition, '
+                           'aif.disk.block.Disk, or '
+                           'aif.disk.mdadm.Array'))
+            raise TypeError('Invalid partobj type')
         self.devpath = self.device.devpath
         self.is_superblocked = None
         self.superblock = None
@@ -47,8 +54,14 @@ class Member(object):
         _super = subprocess.run(['mdadm', '--examine', self.devpath],
                                 stdout = subprocess.PIPE,
                                 stderr = subprocess.PIPE)
+        _logger.info('Executed: {0}'.format(' '.join(_super.args)))
         if _super.returncode != 0:
-            # TODO: logging?
+            _logger.warning('Command returned non-zero status')
+            _logger.debug('Exit status: {0}'.format(str(_super.returncode)))
+            for a in ('stdout', 'stderr'):
+                x = getattr(_super, a)
+                if x:
+                    _logger.debug('{0}: {1}'.format(a.upper(), x.decode('utf-8').strip()))
             self.is_superblocked = False
             self.superblock = None
             return(None)
@@ -117,13 +130,23 @@ class Member(object):
                 v = int(v.split(None, 1)[0])
             block[k] = v
         self.superblock = block
+        _logger.debug('Rendered superblock info: {0}'.format(block))
         self.is_superblocked = True
         return(None)
 
     def prepare(self):
         if self.is_superblocked:
-            # TODO: logging
+            cmd = subprocess.run(['mdadm', '--misc', '--zero-superblock', self.devpath],
-            subprocess.run(['mdadm', '--misc', '--zero-superblock', self.devpath])
+                                 stdout = subprocess.PIPE,
+                                 stderr = subprocess.PIPE)
+            _logger.info('Executed: {0}'.format(' '.join(cmd.args)))
+            if cmd.returncode != 0:
+                _logger.warning('Command returned non-zero status')
+                _logger.debug('Exit status: {0}'.format(str(cmd.returncode)))
+                for a in ('stdout', 'stderr'):
+                    x = getattr(cmd, a)
+                    if x:
+                        _logger.debug('{0}: {1}'.format(a.upper(), x.decode('utf-8').strip()))
             self.is_superblocked = False
         self._parseDeviceBlock()
         return(None)
@@ -132,25 +155,31 @@ class Member(object):
 class Array(object):
     def __init__(self, array_xml, homehost, devpath = None):
         self.xml = array_xml
+        _logger.debug('array_xml: {0}'.format(etree.tostring(self.xml, with_tail = False).decode('utf-8')))
         self.id = self.xml.attrib['id']
         self.level = int(self.xml.attrib['level'])
         if self.level not in aif.constants.MDADM_SUPPORTED_LEVELS:
-            raise ValueError('RAID level must be one of: {0}'.format(', '.join([str(i)
+            _logger.error(('RAID level ({0}) must be one of: '
-                                                                                for i in
+                           '{1}').format(self.level, ', '.join([str(i) for i in aif.constants.MDADM_SUPPORTED_LEVELS])))
-                                                                                aif.constants.MDADM_SUPPORTED_LEVELS])))
+            raise ValueError('Invalid RAID level')
         self.metadata = self.xml.attrib.get('meta', '1.2')
         if self.metadata not in aif.constants.MDADM_SUPPORTED_METADATA:
-            raise ValueError('Metadata version must be one of: {0}'.format(', '.join(
+            _logger.error(('Metadata version ({0}) must be one of: '
-                                                                            aif.constants.MDADM_SUPPORTED_METADATA)))
+                           '{1}').format(self.metadata, ', '.join(aif.constants.MDADM_SUPPORTED_METADATA)))
+            raise ValueError('Invalid metadata version')
         self.chunksize = int(self.xml.attrib.get('chunkSize', 512))
         if self.level in (4, 5, 6, 10):
             if not aif.utils.isPowerofTwo(self.chunksize):
-                # TODO: log.warn instead of raise exception? Will mdadm lose its marbles if it *isn't* a proper number?
+                # TODO: warn instead of raise exception? Will mdadm lose its marbles if it *isn't* a proper number?
-                raise ValueError('chunksize must be a power of 2 for the RAID level you specified')
+                _logger.error('Chunksize ({0}) must be a power of 2 for RAID level {1}.'.format(self.chunksize,
+                                                                                                self.level))
+                raise ValueError('Invalid chunksize')
         if self.level in (0, 4, 5, 6, 10):
             if not aif.utils.hasSafeChunks(self.chunksize):
-                # TODO: log.warn instead of raise exception? Will mdadm lose its marbles if it *isn't* a proper number?
+                # TODO: warn instead of raise exception? Will mdadm lose its marbles if it *isn't* a proper number?
-                raise ValueError('chunksize must be divisible by 4 for the RAID level you specified')
+                _logger.error('Chunksize ({0}) must be divisible by 4 for RAID level {1}'.format(self.chunksize,
+                                                                                                 self.level))
+                raise ValueError('Invalid chunksize')
         self.layout = self.xml.attrib.get('layout', 'none')
         if self.level in aif.constants.MDADM_SUPPORTED_LAYOUTS.keys():
             matcher, layout_default = aif.constants.MDADM_SUPPORTED_LAYOUTS[self.level]
@@ -158,7 +187,8 @@ class Array(object):
                 if layout_default:
                     self.layout = layout_default
                 else:
-                    self.layout = None  # TODO: log.warn?
+                    _logger.warning('Did not detect a valid layout.')
+                    self.layout = None
         else:
             self.layout = None
         self.name = self.xml.attrib['name']
@@ -173,15 +203,17 @@ class Array(object):
 
     def addMember(self, memberobj):
         if not isinstance(memberobj, Member):
-            raise ValueError('memberobj must be of type aif.disk.mdadm.Member')
+            _logger.error('memberobj must be of type aif.disk.mdadm.Member')
+            raise ValueError('Invalid memberobj type')
         memberobj.prepare()
         self.members.append(memberobj)
         return(None)
 
     def create(self):
         if not self.members:
-            raise RuntimeError('Cannot create an array with no members')
+            _logger.error('Cannot create an array with no members.')
-        cmd = ['mdadm', '--create',
+            raise RuntimeError('Missing members')
+        cmd_str = ['mdadm', '--create',
                    '--name={0}'.format(self.name),
                    '--bitmap=internal',
                    '--level={0}'.format(self.level),
@@ -190,12 +222,21 @@ class Array(object):
                    '--homehost={0}'.format(self.homehost),
                    '--raid-devices={0}'.format(len(self.members))]
         if self.layout:
-            cmd.append('--layout={0}'.format(self.layout))
+            cmd_str.append('--layout={0}'.format(self.layout))
-        cmd.append(self.devpath)
+        cmd_str.append(self.devpath)
         for m in self.members:
-            cmd.append(m.devpath)
+            cmd_str.append(m.devpath)
         # TODO: logging!
-        subprocess.run(cmd)
+        cmd = subprocess.run(cmd_str, stdout = subprocess.PIPE, stderr = subprocess.PIPE)
+        _logger.info('Executed: {0}'.format(' '.join(cmd.args)))
+        if cmd.returncode != 0:
+            _logger.warning('Command returned non-zero status')
+            _logger.debug('Exit status: {0}'.format(str(cmd.returncode)))
+            for a in ('stdout', 'stderr'):
+                x = getattr(cmd, a)
+                if x:
+                    _logger.debug('{0}: {1}'.format(a.upper(), x.decode('utf-8').strip()))
+            raise RuntimeError('Failed to create array successfully')
         for m in self.members:
             m._parseDeviceBlock()
         self.updateStatus()
@@ -204,23 +245,44 @@ class Array(object):
         return(None)
 
     def start(self, scan = False):
+        _logger.info('Starting array {0}.'.format(self.name))
         if not any((self.members, self.devpath)):
-            raise RuntimeError('Cannot assemble an array with no members (for hints) or device path')
+            _logger.error('Cannot assemble an array with no members (for hints) or device path.')
-        cmd = ['mdadm', '--assemble', self.devpath]
+            raise RuntimeError('Cannot start unspecified array')
+        cmd_str = ['mdadm', '--assemble', self.devpath]
         if not scan:
             for m in self.members:
-                cmd.append(m.devpath)
+                cmd_str.append(m.devpath)
         else:
-            cmd.append('--scan')
+            cmd_str.append('--scan')
-        # TODO: logging!
+        cmd = subprocess.run(cmd_str, stdout = subprocess.PIPE, stderr = subprocess.PIPE)
-        subprocess.run(cmd)
+        _logger.info('Executed: {0}'.format(' '.join(cmd.args)))
+        if cmd.returncode != 0:
+            _logger.warning('Command returned non-zero status')
+            _logger.debug('Exit status: {0}'.format(str(cmd.returncode)))
+            for a in ('stdout', 'stderr'):
+                x = getattr(cmd, a)
+                if x:
+                    _logger.debug('{0}: {1}'.format(a.upper(), x.decode('utf-8').strip()))
+            raise RuntimeError('Failed to start array successfully')
         self.updateStatus()
         self.state = 'assembled'
         return(None)
 
     def stop(self):
-        # TODO: logging
+        _logger.error('Stopping aray {0}.'.format(self.name))
-        subprocess.run(['mdadm', '--stop', self.devpath])
+        cmd = subprocess.run(['mdadm', '--stop', self.devpath],
+                             stdout = subprocess.PIPE,
+                             stderr = subprocess.PIPE)
+        _logger.info('Executed: {0}'.format(' '.join(cmd.args)))
+        if cmd.returncode != 0:
+            _logger.warning('Command returned non-zero status')
+            _logger.debug('Exit status: {0}'.format(str(cmd.returncode)))
+            for a in ('stdout', 'stderr'):
+                x = getattr(cmd, a)
+                if x:
+                    _logger.debug('{0}: {1}'.format(a.upper(), x.decode('utf-8').strip()))
+            raise RuntimeError('Failed to stop array successfully')
         self.state = 'disassembled'
         return(None)
 
@@ -230,25 +292,35 @@ class Array(object):
             if k != self.name:
                 del(_info['devices'][k])
         self.info = copy.deepcopy(_info)
+        _logger.debug('Rendered info: {0}'.format(_info))
         return(None)
 
-    def writeConf(self, conf = '/etc/mdadm.conf'):
+    def writeConf(self, chroot_base):
-        conf = os.path.realpath(conf)
+        conf = os.path.join(chroot_base, 'etc', 'mdadm.conf')
         with open(conf, 'r') as fh:
             conflines = fh.read().splitlines()
-        # TODO: logging
+        cmd = subprocess.run(['mdadm', '--detail', '--brief', self.devpath],
-        arrayinfo = subprocess.run(['mdadm', '--detail', '--brief', self.devpath],
+                             stdout = subprocess.PIPE,
-                                   stdout = subprocess.PIPE).stdout.decode('utf-8').strip()
+                             stderr = subprocess.PIPE)
+        _logger.info('Executed: {0}'.format(' '.join(cmd.args)))
+        if cmd.returncode != 0:
+            _logger.warning('Command returned non-zero status')
+            _logger.debug('Exit status: {0}'.format(str(cmd.returncode)))
+            for a in ('stdout', 'stderr'):
+                x = getattr(cmd, a)
+                if x:
+                    _logger.debug('{0}: {1}'.format(a.upper(), x.decode('utf-8').strip()))
+            raise RuntimeError('Failed to get information about array successfully')
+        arrayinfo = cmd.stdout.decode('utf-8').strip()
         if arrayinfo not in conflines:
             r = re.compile(r'^ARRAY\s+{0}'.format(self.devpath))
             nodev = True
             for l in conflines:
                 if r.search(l):
                     nodev = False
-                    # TODO: logging?
+                    # TODO: warning and skip instead?
-                    # and/or Raise an exception here;
+                    _logger.error('An array already exists with that name but not with the same opts/GUID/etc.')
-                    # an array already exists with that name but not with the same opts/GUID/etc.
+                    raise RuntimeError('Duplicate array')
-                    break
             if nodev:
                 with open(conf, 'a') as fh:
                     fh.write('{0}\n'.format(arrayinfo))