From 4418348e78c63a011747d890aa9f0a665afb7ce8 Mon Sep 17 00:00:00 2001 From: brent s Date: Thu, 19 Dec 2019 17:00:16 -0500 Subject: [PATCH] logging added to config parser. --- aif/config/parser.py | 60 ++++++++++++++++++++++++++++++++++++++------ 1 file changed, 52 insertions(+), 8 deletions(-) diff --git a/aif/config/parser.py b/aif/config/parser.py index bd58d32..467615f 100644 --- a/aif/config/parser.py +++ b/aif/config/parser.py @@ -20,6 +20,7 @@ class Config(object): self.xsd = None self.defaultsParser = None self.obj = None + _logger.debug('Instantiated {0}.'.format(type(self).__name__)) def main(self, validate = True, populate_defaults = True): self.fetch() @@ -41,51 +42,68 @@ class Config(object): raw_xsd = None base_url = None if xsdpath: + _logger.debug('XSD path specified.') + orig_xsdpath = xsdpath xsdpath = os.path.abspath(os.path.expanduser(xsdpath)) + _logger.debug('Transformed XSD path: {0} => {1}'.format(orig_xsdpath, xsdpath)) if not os.path.isfile(xsdpath): - raise ValueError(('An explicit XSD path was specified but ' - 'does not exist on the local filesystem')) + _logger.error('The specified XSD path {0} does not exist on the local filesystem.'.format(xsdpath)) + raise ValueError('Specified XSD path does not exist') with open(xsdpath, 'rb') as fh: raw_xsd = fh.read() base_url = os.path.split(xsdpath)[0] else: + _logger.debug('No XSD path specified; getting it from the configuration file.') xsi = self.xml.nsmap.get('xsi', 'http://www.w3.org/2001/XMLSchema-instance') + _logger.debug('xsi: {0}'.format(xsi)) schemaLocation = '{{{0}}}schemaLocation'.format(xsi) schemaURL = self.xml.attrib.get(schemaLocation, 'https://schema.xml.r00t2.io/projects/aif.xsd') + _logger.debug('Detected schema map: {0}'.format(schemaURL)) split_url = schemaURL.split() if len(split_url) == 2: # a properly defined schemaLocation schemaURL = split_url[1] else: schemaURL = split_url[0] # a LAZY schemaLocation + _logger.info('Detected schema location: {0}'.format(schemaURL)) if schemaURL.startswith('file://'): schemaURL = re.sub(r'^file://', r'', schemaURL) + _logger.debug('Fetching local file {0}'.format(schemaURL)) with open(schemaURL, 'rb') as fh: raw_xsd = fh.read() base_url = os.path.dirname(schemaURL) else: + _logger.debug('Fetching remote file: {0}'.format(schemaURL)) req = requests.get(schemaURL) if not req.ok: - # TODO: logging! + _logger.error('Unable to fetch XSD.') raise RuntimeError('Could not download XSD') raw_xsd = req.content base_url = os.path.split(req.url)[0] # This makes me feel dirty. + _logger.debug('Loaded XSD at {0} ({1} bytes).'.format(xsdpath, len(raw_xsd))) + _logger.debug('Parsed XML base URL: {0}'.format(base_url)) self.xsd = etree.XMLSchema(etree.XML(raw_xsd, base_url = base_url)) + _logger.info('Rendered XSD.') return(None) def parseRaw(self, parser = None): - # self.xml = etree.parse(self.raw, parser = parser) self.xml = etree.fromstring(self.raw, parser = parser) - # self.namespaced_xml = etree.parse(self.raw, parser = parser) + _logger.debug('Generated xml.') self.namespaced_xml = etree.fromstring(self.raw, parser = parser) + _logger.debug('Generated namespaced xml.') self.tree = self.xml.getroottree() + _logger.debug('Generated tree.') self.namespaced_tree = self.namespaced_xml.getroottree() + _logger.debug('Generated namespaced tree.') self.tree.xinclude() + _logger.debug('Parsed XInclude for tree.') self.namespaced_tree.xinclude() + _logger.debug('Parsed XInclude for namespaced tree.') self.stripNS() return(None) def populateDefaults(self): + _logger.info('Populating missing values with defaults from XSD.') if not self.xsd: self.getXSD() if not self.defaultsParser: @@ -95,6 +113,7 @@ class Config(object): def pythonize(self, stripped = True, obj = 'tree'): # https://bugs.launchpad.net/lxml/+bug/1850221 + _logger.debug('Pythonizing to native objects') strobj = self.toString(stripped = stripped, obj = obj) self.obj = objectify.fromstring(strobj) objectify.annotate(self.obj) @@ -102,38 +121,49 @@ class Config(object): return(None) def removeDefaults(self): + _logger.info('Removing default values from missing values.') self.parseRaw() return(None) def stripNS(self, obj = None): + _logger.debug('Stripping namespace.') # https://stackoverflow.com/questions/30232031/how-can-i-strip-namespaces-out-of-an-lxml-tree/30233635#30233635 xpathq = "descendant-or-self::*[namespace-uri()!='']" if not obj: + _logger.debug('No XML object selected; using instance\'s xml and tree.') for x in (self.tree, self.xml): for e in x.xpath(xpathq): e.tag = etree.QName(e).localname elif isinstance(obj, (etree._Element, etree._ElementTree)): + _logger.debug('XML object provided: {0}'.format(etree.tostring(obj))) obj = copy.deepcopy(obj) for e in obj.xpath(xpathq): e.tag = etree.QName(e).localname return(obj) else: + _logger.error('A non-XML object was provided.') raise ValueError('Did not know how to parse obj parameter') return(None) def toString(self, stripped = False, obj = None): if isinstance(obj, (etree._Element, etree._ElementTree)): + _logger.debug('Converting an XML object to a string') if stripped: + _logger.debug('Stripping before stringifying.') obj = self.stripNS(obj) elif obj in ('tree', None): if not stripped: + _logger.debug('Converting the instance\'s namespaced tree to a string.') obj = self.namespaced_tree else: + _logger.debug('Converting the instance\'s stripped tree to a string.') obj = self.tree elif obj == 'xml': if not stripped: + _logger.debug('Converting instance\'s namespaced XML to a string') obj = self.namespaced_xml else: + _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 ' @@ -145,11 +175,13 @@ class Config(object): pretty_print = True, with_tail = True, inclusive_ns_prefixes = True) + _logger.debug('Rendered string output successfully.') return(strxml) def validate(self): if not self.xsd: self.getXSD() + _logger.debug('Checking validation against namespaced tree.') self.xsd.assertValid(self.namespaced_tree) return(None) @@ -161,11 +193,15 @@ class LocalFile(Config): self.source = path def fetch(self): - self.source = os.path.realpath(self.source) + orig_src = self.source + self.source = os.path.abspath(os.path.expanduser(self.source)) + _logger.debug('Canonized path: {0} => {1}'.format(orig_src, self.source)) if not os.path.isfile(self.source): - raise ValueError('{0} does not exist'.format(self.source)) + _logger.error('Config at {0} not found.'.format(self.source)) + raise ValueError('Config file does not exist'.format(self.source)) with open(self.source, 'rb') as fh: self.raw = fh.read() + _logger.debug('Fetched configuration ({0} bytes).'.format(len(self.raw))) return(None) @@ -178,8 +214,10 @@ class RemoteFile(Config): def fetch(self): r = requests.get(self.source) if not r.ok(): + _logger.error('Could not fetch {0}'.format(self.source)) raise RuntimeError('Could not download XML') self.raw = r.content + _logger.debug('Fetched configuration ({0} bytes).'.format(len(self.raw))) return(None) @@ -191,6 +229,7 @@ class ConfigStr(Config): def fetch(self): self.raw = self.source.encode('utf-8') + _logger.debug('Raw configuration (str) passed in ({0} bytes); converted to bytes.'.format(len(self.raw))) return(None) @@ -202,6 +241,7 @@ class ConfigBin(Config): def fetch(self): self.raw = self.source + _logger.debug('Raw configuration (binary) passed in ({0} bytes); converted to bytes.'.format(len(self.raw))) return(None) @@ -217,14 +257,18 @@ def getConfig(cfg_ref, validate = True, populate_defaults = True, xsd_path = Non try: if pattern.search(cfg_ref): cfgobj = configClass(cfg_ref, xsd_path = xsd_path) + _logger.info('Config detected as {0}.'.format(configtype)) break except TypeError: ptrn = re.compile(detector['raw'][0].pattern.encode('utf-8')) if not ptrn.search(cfg_ref): - raise ValueError('Received junk data for cfg_ref') + _logger.error('Could not detect which configuration type was passed.') + raise ValueError('Unespected/unparseable cfg_ref.') else: + _logger.info('Config detected as ConfigBin.') cfgobj = ConfigBin(cfg_ref, xsd_path = xsd_path) break if cfgobj: + _logger.info('Parsing configuration.') cfgobj.main(validate = validate, populate_defaults = populate_defaults) return(cfgobj)