From 65b316c0149d754ac29f4a79ff560ce86d1d2e40 Mon Sep 17 00:00:00 2001 From: brent s Date: Sat, 28 Dec 2019 02:20:50 -0500 Subject: [PATCH] logging to network providers --- aif/disk/block_fallback.py | 15 +++++++++------ aif/disk/mdadm_fallback.py | 17 +++++++---------- aif/network/__init__.py | 9 +++++++++ aif/network/_common.py | 24 +++++++++++++++++++++--- aif/network/netctl.py | 14 +++++++++++++- aif/network/networkd.py | 14 ++++++++++++++ aif/network/networkmanager.py | 14 +++++++++++++- aif/utils/sources.py | 2 +- 8 files changed, 87 insertions(+), 22 deletions(-) diff --git a/aif/disk/block_fallback.py b/aif/disk/block_fallback.py index d10ba68..3efcd26 100644 --- a/aif/disk/block_fallback.py +++ b/aif/disk/block_fallback.py @@ -44,14 +44,16 @@ class Disk(object): if self.devpath == 'auto': self.devpath = '/dev/{0}'.format(blkinfo.BlkDiskInfo().get_disks()[0]['kname']) if not os.path.isfile(self.devpath): - raise ValueError('{0} does not exist; please specify an explicit device path'.format(self.devpath)) + _logger.error('Disk {0} does not exist; please specify an explicit device path'.format(self.devpath)) + raise ValueError('Disk not found') self.table_type = self.xml.attrib.get('diskFormat', 'gpt').lower() if self.table_type in ('bios', 'mbr', 'dos'): self.table_type = 'msdos' validlabels = parted.getLabels() if self.table_type not in validlabels: - raise ValueError(('Disk format {0} is not valid for this architecture;' - 'must be one of: {1}'.format(self.table_type, ', '.join(list(validlabels))))) + _logger.error(('Disk format ({0}) is not valid for this architecture;' + 'must be one of: {1}'.format(self.table_type, ', '.join(list(validlabels))))) + raise ValueError('Invalid disk format') self.device = parted.getDevice(self.devpath) self.disk = parted.freshDisk(self.device, self.table_type) _logger.debug('Configured parted device for {0}.'.format(self.devpath)) @@ -152,9 +154,10 @@ class Partition(object): self.part_type = parted.PARTITION_NORMAL self.fs_type = self.xml.attrib['fsType'].lower() if self.fs_type not in aif.constants.PARTED_FSTYPES: - raise ValueError(('{0} is not a valid partition filesystem type; ' - 'must be one of: {1}').format(self.xml.attrib['fsType'], - ', '.join(sorted(aif.constants.PARTED_FSTYPES)))) + _logger.error(('{0} is not a valid partition filesystem type; must be one of: ' + '{1}').format(self.xml.attrib['fsType'], + ', '.join(sorted(aif.constants.PARTED_FSTYPES)))) + raise ValueError('Invalid partition filesystem type') self.disk = diskobj self.device = self.disk.device self.devpath = '{0}{1}'.format(self.device.path, self.partnum) diff --git a/aif/disk/mdadm_fallback.py b/aif/disk/mdadm_fallback.py index 62916a5..c5f84be 100644 --- a/aif/disk/mdadm_fallback.py +++ b/aif/disk/mdadm_fallback.py @@ -92,9 +92,8 @@ class Member(object): elif k == 'unused_space': r = _mdblock_unused_re.search(v) if not r: - raise ValueError(('Could not parse {0} for ' - '{1}\'s superblock').format(orig_k, - self.devpath)) + _logger.error('Could not parse {0} for {1}\'s superblock'.format(orig_k, self.devpath)) + raise RuntimeError('Could not parse unused space in superblock') v = {} for i in ('before', 'after'): v[i] = int(r.group(i)) # in sectors @@ -102,9 +101,8 @@ class Member(object): k = 'badblock_log_entries' r = _mdblock_badblock_re.search(v) if not r: - raise ValueError(('Could not parse {0} for ' - '{1}\'s superblock').format(orig_k, - self.devpath)) + _logger.error('Could not parse {0} for {1}\'s superblock'.format(orig_k, self.devpath)) + raise RuntimeError('Could not parse badblocks in superblock') v = {} for i in ('entries', 'offset'): v[i] = int(r.group(i)) # offset is in sectors @@ -118,9 +116,8 @@ class Member(object): elif re.search(r'^((avail|used)_dev|array)_size$', k): r = _mdblock_size_re.search(v) if not r: - raise ValueError(('Could not parse {0} for ' - '{1}\'s superblock').format(orig_k, - self.devpath)) + _logger.error('Could not parse {0} for {1}\'s superblock'.format(orig_k, self.devpath)) + raise RuntimeError('Could not parse size value in superblock') v = {} for i in ('sectors', 'GB', 'GiB'): v[i] = float(r.group(i)) @@ -204,7 +201,7 @@ class Array(object): def addMember(self, memberobj): if not isinstance(memberobj, Member): _logger.error('memberobj must be of type aif.disk.mdadm.Member') - raise ValueError('Invalid memberobj type') + raise TypeError('Invalid memberobj type') memberobj.prepare() self.members.append(memberobj) return(None) diff --git a/aif/network/__init__.py b/aif/network/__init__.py index fa224cf..0ab5345 100644 --- a/aif/network/__init__.py +++ b/aif/network/__init__.py @@ -1,5 +1,8 @@ +import logging import os ## +from lxml import etree +## from . import _common from . import netctl from . import networkd @@ -21,11 +24,16 @@ from . import networkmanager # from . import networkd_fallback as networkd +_logger = logging.getLogger(__name__) + + class Net(object): def __init__(self, chroot_base, network_xml): self.xml = network_xml + # We don't bother logging the entirety of network_xml here because we do it in the respective networks self.chroot_base = chroot_base self.hostname = self.xml.attrib['hostname'].strip() + _logger.info('Hostname: {0}'.format(self.hostname)) self.provider = self.xml.attrib.get('provider', 'networkd').strip() if self.provider == 'netctl': self.provider = netctl @@ -46,6 +54,7 @@ class Net(object): elif e.tag == 'wireless': conn = self.provider.Wireless(e) self.connections.append(conn) + _logger.info('Added connection of type {0}.'.format(type(conn).__name__)) def apply(self, chroot_base): cfg = os.path.join(chroot_base, 'etc', 'hostname') diff --git a/aif/network/_common.py b/aif/network/_common.py index 5d17e92..19e7c9c 100644 --- a/aif/network/_common.py +++ b/aif/network/_common.py @@ -1,9 +1,11 @@ import binascii import ipaddress +import logging import os import pathlib import re ## +from lxml import etree from passlib.crypto.digest import pbkdf2_hmac from pyroute2 import IPDB ## @@ -15,8 +17,10 @@ import aif.utils # from gi.repository import GObject, NM, GLib +_logger = logging.getLogger('net:_common') + + def canonizeEUI(phyaddr): - # The easy transformations first. phyaddr = re.sub(r'[.:-]', '', phyaddr.upper().strip()) eui = ':'.join(['{0}'.format(phyaddr[i:i+2]) for i in range(0, 12, 2)]) return(eui) @@ -33,6 +37,7 @@ def convertIpTuples(addr_xmlobj): else: components = addr_xmlobj.text.strip().split('/') if len(components) > 2: + _logger.error('Too many slashes in IP/CIDR string.') raise ValueError('Invalid IP/CIDR format: {0}'.format(addr_xmlobj.text)) if len(components) == 1: addr = ipaddress.ip_address(components[0]) @@ -45,6 +50,8 @@ def convertIpTuples(addr_xmlobj): try: gw = ipaddress.ip_address(addr_xmlobj.attrib.get('gateway').strip()) except (ValueError, AttributeError): + _logger.warning(('Non-conformant gateway value (attempting automatic gateway address): ' + '{0}').format(addr_xmlobj.attrib.get('gateway'))) gw = next(net.hosts()) return((addr, net, gw)) @@ -53,20 +60,24 @@ def convertPSK(ssid, passphrase): try: passphrase = passphrase.encode('utf-8').decode('ascii').strip('\r').strip('\n') except UnicodeDecodeError: - raise ValueError('passphrase must be an ASCII string') + _logger.error('WPA passphrase must be an ASCII string') + raise ValueError('Passed invalid encoding for WPA PSK string') if len(ssid) > 32: + _logger.error('') raise ValueError('ssid must be <= 32 characters') if not 7 < len(passphrase) < 64: raise ValueError('passphrase must be >= 8 and <= 32 characters') raw_psk = pbkdf2_hmac('sha1', str(passphrase), str(ssid), 4096, 32) hex_psk = binascii.hexlify(raw_psk) str_psk = hex_psk.decode('utf-8') + _logger.debug('Converted ({0}){1} to {2}'.format(str(passphrase), str(ssid), str_psk)) return(str_psk) def convertWifiCrypto(crypto_xmlobj, ssid): crypto = {'type': crypto_xmlobj.find('type').text.strip(), 'auth': {}} + _logger.info('Parsing a WiFi crypto object.') creds_xml = crypto_xmlobj.xpath('psk|enterprise')[0] # if crypto['type'] in ('wpa', 'wpa2', 'wpa3'): if crypto['type'] in ('wpa', 'wpa2'): @@ -88,6 +99,7 @@ def convertWifiCrypto(crypto_xmlobj, ssid): # TODO: enterprise support # elif crypto['mode'] == 'enterprise': # pass + _logger.debug('Rendered crypto settings: {0}'.format(crypto)) return(crypto) @@ -100,7 +112,8 @@ def getDefIface(ifacetype): elif ifacetype == 'wireless': prefix = 'wl' else: - raise ValueError('ifacetype must be one of "ethernet" or "wireless"') + _logger.error('ifacetype must be one of "ethernet" or "wireless"') + raise ValueError('Invalid iface type') ifname = None with IPDB() as ipdb: for iface in ipdb.interfaces.keys(): @@ -108,6 +121,7 @@ def getDefIface(ifacetype): ifname = iface break if not ifname: + _logger.warning('Unable to find default interface') return(None) return(ifname) @@ -125,13 +139,16 @@ def isNotPersistent(chroot_base = '/'): return(True) cmds = aif.utils.kernelCmdline(chroot_base) if 'net.ifnames' in cmds.keys() and cmds['net.ifnames'] == '0': + _logger.debug('System network interfaces are not persistent') return(True) + _logger.debug('System network interfaces are persistent') return(False) class BaseConnection(object): def __init__(self, iface_xml): self.xml = iface_xml + _logger.debug('iface_xml: {0}'.format(etree.tostring(self.xml, with_tail = False).decode('utf-8'))) self.id = self.xml.attrib['id'].strip() self.device = self.xml.attrib['device'].strip() self.is_defroute = aif.utils.xmlBool(self.xml.attrib.get('defroute', 'false').strip()) @@ -197,6 +214,7 @@ class BaseConnection(object): self._initAddrs() self._initResolvers() self._initRoutes() + _logger.info('Instantiated network provider {0}'.format(type(self).__name__)) def _initAddrs(self): for addrtype in ('ipv4', 'ipv6'): diff --git a/aif/network/netctl.py b/aif/network/netctl.py index 1d42841..4f735a6 100644 --- a/aif/network/netctl.py +++ b/aif/network/netctl.py @@ -1,11 +1,15 @@ import configparser import io +import logging import os ## import aif.utils from . import _common +_logger = logging.getLogger(__name__) + + class Connection(_common.BaseConnection): def __init__(self, iface_xml): super().__init__(iface_xml) @@ -28,6 +32,7 @@ class Connection(_common.BaseConnection): self.desc = None def _initCfg(self): + _logger.info('Building config.') if self.device == 'auto': self.device = _common.getDefIface(self.connection_type) self.desc = ('A {0} profile for {1} (generated by AIF-NG)').format(self.connection_type, @@ -76,6 +81,7 @@ class Connection(_common.BaseConnection): elif self.addrs[addrtype]: if 'IPCustom' not in self._cfg['BASE']: # TODO: do this more cleanly somehow? Might conflict with other changes earlier/later. + # Could I shlex it? # Weird hack because netctl doesn't natively support assigning add'l addrs to # a dhcp/dhcp6/slaac iface. self._cfg['BASE']['IPCustom'] = [] @@ -105,6 +111,9 @@ class Connection(_common.BaseConnection): # Weird hack because netctl doesn't natively support assigning add'l addrs to a dhcp/dhcp6/slaac iface. if 'IPCustom' in self._cfg['BASE'].keys() and isinstance(self._cfg['BASE']['IPCustom'], list): self._cfg['BASE']['IPCustom'] = '({0})'.format(' '.join(self._cfg['BASE']['IPCustom'])) + _logger.info('Config built successfully.') + # TODO: does this render correctly? + _logger.debug('Config: {0}'.format(dict(self._cfg['BASE']))) return(None) def writeConf(self, chroot_base): @@ -128,6 +137,7 @@ class Connection(_common.BaseConnection): 'After': 'sys-subsystem-net-devices-{0}.device'.format(self.device)} with open(systemd_file, 'w') as fh: systemd_cfg.write(fh, space_around_delimiters = False) + _logger.info('Wrote systemd unit: {0}'.format(systemd_file)) # This is where it gets... weird. # Gross hacky workarounds because netctl, while great for simple setups, sucks for complex/advanced ones. no_auto = not all((self.auto['resolvers']['ipv4'], @@ -200,7 +210,7 @@ class Connection(_common.BaseConnection): 'ipv4': tuple(), 'ipv6': tuple()}}} # This ONLY works for DHCPv6 on the IPv6 side. Not SLAAC. Netctl doesn't use a dhcp client for - # SLAAC. + # SLAAC, just iproute2. :| # x = routers, addresses, resolvers # t = ipv4/ipv6 dicts # i = ipv4/ipv6 key @@ -249,6 +259,7 @@ class Connection(_common.BaseConnection): fh.write('\n') os.chmod(custom_cfg, 0o0644) os.chown(custom_cfg, 0, 0) + _logger.info('Wrote: {0}'.format(custom_cfg)) # And we have to strip out the section from the ini. cfgbuf = io.StringIO() self._cfg.write(cfgbuf, space_around_delimiters = False) @@ -260,6 +271,7 @@ class Connection(_common.BaseConnection): fh.write(line) os.chmod(netctl_file, 0o0600) os.chown(netctl_file, 0, 0) + _logger.info('Wrote: {0}'.format(netctl_file)) return(None) diff --git a/aif/network/networkd.py b/aif/network/networkd.py index c4e2e93..3e056a7 100644 --- a/aif/network/networkd.py +++ b/aif/network/networkd.py @@ -1,3 +1,4 @@ +import logging import os ## # We have to use Jinja2 because while there are ways to *parse* an INI with duplicate keys @@ -9,6 +10,9 @@ import aif.utils from . import _common +_logger = logging.getLogger(__name__) + + class Connection(_common.BaseConnection): def __init__(self, iface_xml): super().__init__(iface_xml) @@ -35,6 +39,7 @@ class Connection(_common.BaseConnection): self._initJ2() def _initCfg(self): + _logger.info('Building config.') if self.device == 'auto': self.device = _common.getDefIface(self.connection_type) self._cfg = {'Match': {'Name': self.device}, @@ -90,9 +95,11 @@ class Connection(_common.BaseConnection): if 'IPv6AcceptRA' not in self._cfg.keys(): self._cfg['IPv6AcceptRA'] = {'UseDNS': ('true' if self.auto['resolvers']['ipv6'] else 'false')} self._initConnCfg() + _logger.info('Config built successfully.') return(None) def _initJ2(self): + _logger.debug('Fetching template from networkd.conf.j2') self.j2_env = jinja2.Environment(loader = jinja2.FileSystemLoader(searchpath = './')) self.j2_env.filters.update(aif.utils.j2_filters) self.j2_tpl = self.j2_env.get_template('networkd.conf.j2') @@ -109,6 +116,9 @@ class Connection(_common.BaseConnection): os.chmod(cfgfile, 0o0644) os.chown(cfgfile, 0, 0) self._writeConnCfg(chroot_base) + _logger.info('Wrote: {0}'.format(cfgfile)) + _logger.debug('Rendering variables: {0}'.format(self._cfg)) + _logger.debug('Rendered template: {0}'.format(self.j2_tpl.render(cfg = self._cfg))) return(None) @@ -149,6 +159,7 @@ class Wireless(Connection): self._wpasupp['psk'] = crypto['auth']['psk'] else: self._wpasupp['key_mgmt'] = 'NONE' + _logger.debug('Fetching template from wpa_supplicant.conf.j2') self.wpasupp_tpl = self.j2_env.get_template('wpa_supplicant.conf.j2') self.services[('/usr/lib/systemd/system/wpa_supplicant@.service')] = ('etc/systemd/' 'system/' @@ -167,4 +178,7 @@ class Wireless(Connection): fh.write(self.wpasupp_tpl.render(wpa = self._wpasupp)) os.chown(cfgfile, 0, 0) os.chmod(cfgfile, 0o0640) + _logger.info('Wrote: {0}'.format(cfgfile)) + _logger.debug('Rendering variables: {0}'.format(self._wpasupp)) + _logger.debug('Rendered template: {0}'.format(self.wpasupp_tpl.render(wpa = self._wpasupp))) return(None) diff --git a/aif/network/networkmanager.py b/aif/network/networkmanager.py index a4a2124..bb6113a 100644 --- a/aif/network/networkmanager.py +++ b/aif/network/networkmanager.py @@ -1,12 +1,15 @@ import configparser import datetime +import logging import os import uuid ## -import aif.utils from . import _common +_logger = logging.getLogger(__name__) + + class Connection(_common.BaseConnection): def __init__(self, iface_xml): super().__init__(iface_xml) @@ -26,6 +29,7 @@ class Connection(_common.BaseConnection): self.uuid = uuid.uuid4() def _initCfg(self): + _logger.info('Building config.') if self.device == 'auto': self.device = _common.getDefIface(self.connection_type) self._cfg = configparser.ConfigParser() @@ -89,6 +93,13 @@ class Connection(_common.BaseConnection): str(net.prefixlen), str(gw)) self._initConnCfg() + _logger.info('Config built successfully.') + # TODO: does this render correctly? + # This is only for debug logging. + _logout = {} + for s in self._cfg.sections(): + _logout[s] = dict(self._cfg[s]) + _logger.debug('Config: {0}'.format(_logout)) return(None) def writeConf(self, chroot_base): @@ -109,6 +120,7 @@ class Connection(_common.BaseConnection): os.chmod(cfgroot, 0o0755) os.chmod(cfgdir, 0o0700) os.chmod(cfgpath, 0o0600) + _logger.info('Wrote: {0}'.format(cfgpath)) return(None) diff --git a/aif/utils/sources.py b/aif/utils/sources.py index d22fde3..d075350 100644 --- a/aif/utils/sources.py +++ b/aif/utils/sources.py @@ -187,7 +187,7 @@ class Downloader(object): dl.data.seek(0, 0) if not fnargs['keys']: _logger.debug('Found no keys in keys_xml') - raise ValueError('Could not find any keys') + raise RuntimeError('Could not find any keys') if sigs_xml is not None: for sig_text_xml in sigs_xml.findall('signature'): _logger.debug('Found ')