Improve error handling of Packages plugin.

Provide a descriptive error message that avoids logging a traceback.

Error out (instead of continuing) upon receiving an HTTP error or an
indication that the URL is malformed.

Only write data to the cache file if it was successfully retrieved
from the URL.

Make log messages for Packages plugin use consistent "Packages:" prefix.

7 files changed, 42 insertions, 40 deletions

diff --git a/src/lib/Server/Plugins/Packages/Apt.py b/src/lib/Server/Plugins/Packages/Apt.py
index ad3ebcabd..ed954af3b 100644
--- a/src/lib/Server/Plugins/Packages/Apt.py
+++ b/src/lib/Server/Plugins/Packages/Apt.py
@@ -9,7 +9,7 @@ logger = logging.getLogger("Packages")
 
 class AptCollection(Collection):
     def get_group(self, group):
-        self.logger.warning("Package groups are not supported by APT")
+        self.logger.warning("Packages: Package groups are not supported by APT")
         return []
 
 class AptSource(Source):
@@ -72,7 +72,7 @@ class AptSource(Source):
             try:
                 reader = gzip.GzipFile(fname)
             except:
-                logger.error("Failed to read file %s" % fname)
+                logger.error("Packages: Failed to read file %s" % fname)
                 raise
             for line in reader.readlines():
                 words = str(line.strip()).split(':', 1)
diff --git a/src/lib/Server/Plugins/Packages/Collection.py b/src/lib/Server/Plugins/Packages/Collection.py
index ab87257e1..cde290d5e 100644
--- a/src/lib/Server/Plugins/Packages/Collection.py
+++ b/src/lib/Server/Plugins/Packages/Collection.py
@@ -35,7 +35,7 @@ class Collection(object):
         return md5(self.get_config()).hexdigest()
 
     def get_config(self):
-        self.logger.error("Cannot generate config for host with multiple "
+        self.logger.error("Packages: Cannot generate config for host with multiple "
                           "source types (%s)" % self.metadata.hostname)
         return ""
 
@@ -64,7 +64,7 @@ class Collection(object):
             pkgs = source.get_group(self.metadata, group)
             if pkgs:
                 return pkgs
-        self.logger.warning("'%s' is not a valid group" % group)
+        self.logger.warning("Packages: '%s' is not a valid group" % group)
         return []
 
     def is_package(self, package):
@@ -305,11 +305,11 @@ def factory(metadata, sources, basepath):
     ckey = tuple(sorted(list(ckeydata)))
     if ckey not in collections:
         if len(sclasses) > 1:
-            logger.warning("Multiple source types found for %s: %s" %
+            logger.warning("Packages: Multiple source types found for %s: %s" %
                            ",".join([s.__name__ for s in sclasses]))
             cclass = Collection
         elif len(sclasses) == 0:
-            logger.warning("No sources found for %s" % metadata.hostname)
+            logger.warning("Packages: No sources found for %s" % metadata.hostname)
             cclass = Collection
         else:
             stype = sclasses.pop().__name__.replace("Source", "")
@@ -320,12 +320,12 @@ def factory(metadata, sources, basepath):
                             stype.title())
                 cclass = getattr(module, "%sCollection" % stype.title())
             except ImportError:
-                logger.error("Unknown source type %s" % stype)
+                logger.error("Packages: Unknown source type %s" % stype)
             except AttributeError:
-                logger.warning("No collection class found for %s sources" %
+                logger.warning("Packages: No collection class found for %s sources" %
                                stype)
         
-        logger.debug("Using %s for Collection of sources for %s" %
+        logger.debug("Packages: Using %s for Collection of sources for %s" %
                      (cclass.__name__, metadata.hostname))
 
         collection = cclass(metadata, relevant, basepath)
diff --git a/src/lib/Server/Plugins/Packages/Pac.py b/src/lib/Server/Plugins/Packages/Pac.py
index 881df0ced..35fb39d02 100644
--- a/src/lib/Server/Plugins/Packages/Pac.py
+++ b/src/lib/Server/Plugins/Packages/Pac.py
@@ -9,7 +9,7 @@ logger = logging.getLogger("Packages")
 
 class PacCollection(Collection):
     def get_group(self, group):
-        self.logger.warning("Package groups are not supported by APT")
+        self.logger.warning("Packages: Package groups are not supported by APT")
         return []
 
 class PacSource(Source):
@@ -71,17 +71,17 @@ class PacSource(Source):
                 bdeps[barch] = dict()
                 bprov[barch] = dict()
             try:
-                logger.debug("try to read : " + fname)
+                logger.debug("Packages: try to read : " + fname)
                 tar = tarfile.open(fname, "r")
                 reader = gzip.GzipFile(fname)
             except:
-                logger.error("Failed to read file %s" % fname)
+                logger.error("Packages: Failed to read file %s" % fname)
                 raise
 
             for tarinfo in tar:
                 if tarinfo.isdir():
                     self.pkgnames.add(tarinfo.name.rsplit("-", 2)[0])
-                    logger.debug("added : " + tarinfo.name.rsplit("-", 2)[0])
+                    logger.debug("Packages: added : " + tarinfo.name.rsplit("-", 2)[0])
             tar.close()
 
         self.deps['global'] = dict()
diff --git a/src/lib/Server/Plugins/Packages/PackagesSources.py b/src/lib/Server/Plugins/Packages/PackagesSources.py
index 5f82deb1f..6d0b1d732 100644
--- a/src/lib/Server/Plugins/Packages/PackagesSources.py
+++ b/src/lib/Server/Plugins/Packages/PackagesSources.py
@@ -48,7 +48,7 @@ class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
         sources.xml """
         stype = xsource.get("type")
         if stype is None:
-            logger.error("No type specified for source, skipping")
+            logger.error("Packages: No type specified for source, skipping")
             return None
 
         try:
@@ -57,7 +57,7 @@ class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
                              stype.title())
             cls = getattr(module, "%sSource" % stype.title())
         except (ImportError, AttributeError):
-            logger.error("Unknown source type %s" % stype)
+            logger.error("Packages: Unknown source type %s" % stype)
             return None
 
         return cls(self.cachepath, xsource, self.config)
diff --git a/src/lib/Server/Plugins/Packages/Source.py b/src/lib/Server/Plugins/Packages/Source.py
index 255f3ea7a..00018ef9a 100644
--- a/src/lib/Server/Plugins/Packages/Source.py
+++ b/src/lib/Server/Plugins/Packages/Source.py
@@ -109,7 +109,7 @@ class Source(object):
                 self.load_state()
                 should_read = False 
             except:
-                logger.error("Cachefile %s load failed; "
+                logger.error("Packages: Cachefile %s load failed; "
                              "falling back to file read" % self.cachefile)
         if should_read:
             try:
@@ -124,7 +124,9 @@ class Source(object):
                 self.update()
                 self.read_files()
             except:
-                logger.error("Failed to update source", exc_info=1)
+                logger.error("Packages: Failed to load data for Source of %s. "
+                             "Some Packages will be missing."
+                             % self.urls)
 
     def get_repo_name(self, url_map):
         # try to find a sensible name for a repo
@@ -192,15 +194,15 @@ class Source(object):
             fname = self.escape_url(url)
             try:
                 data = fetch_url(url)
+                file(fname, 'w').write(data)
             except ValueError:
                 logger.error("Packages: Bad url string %s" % url)
-                continue
+                raise
             except HTTPError:
                 err = sys.exc_info()[1]
-                logger.error("Packages: Failed to fetch url %s. code=%s" %
+                logger.error("Packages: Failed to fetch url %s. HTTP response code=%s" %
                              (url, err.code))
-                continue
-            file(fname, 'w').write(data)
+                raise
 
     def applies(self, metadata):
         # check base groups
diff --git a/src/lib/Server/Plugins/Packages/Yum.py b/src/lib/Server/Plugins/Packages/Yum.py
index 6f108b8bb..4ab6aa269 100644
--- a/src/lib/Server/Plugins/Packages/Yum.py
+++ b/src/lib/Server/Plugins/Packages/Yum.py
@@ -30,7 +30,7 @@ try:
     has_yum = True
 except ImportError:
     has_yum = False
-    logger.info("No yum libraries found; forcing use of internal dependency "
+    logger.info("Packages: No yum libraries found; forcing use of internal dependency "
                 "resolver")
 
 XP = '{http://linux.duke.edu/metadata/common}'
@@ -44,7 +44,7 @@ PULPCONFIG = None
 def _setup_pulp(config):
     global PULPSERVER, PULPCONFIG
     if not has_pulp:
-        logger.error("Cannot create Pulp collection: Pulp libraries not "
+        logger.error("Packages: Cannot create Pulp collection: Pulp libraries not "
                      "found")
         raise Bcfg2.Server.Plugin.PluginInitError
 
@@ -53,11 +53,11 @@ def _setup_pulp(config):
             username = config.get("pulp", "username")
             password = config.get("pulp", "password")
         except ConfigParser.NoSectionError:
-            logger.error("No [pulp] section found in Packages/packages.conf")
+            logger.error("Packages: No [pulp] section found in Packages/packages.conf")
             raise Bcfg2.Server.Plugin.PluginInitError
         except ConfigParser.NoOptionError:
             err = sys.exc_info()[1]
-            logger.error("Required option not found in "
+            logger.error("Packages: Required option not found in "
                          "Packages/packages.conf: %s" % err)
             raise Bcfg2.Server.Plugin.PluginInitError
         
@@ -366,10 +366,10 @@ class YumCollection(Collection):
             pass
         except socket.error:
             err = sys.exc_info()[1]
-            logger.error("Could not contact Pulp server: %s" % err)
+            logger.error("Packages: Could not contact Pulp server: %s" % err)
         except:
             err = sys.exc_info()[1]
-            logger.error("Unknown error querying Pulp server: %s" % err)
+            logger.error("Packages: Unknown error querying Pulp server: %s" % err)
         return consumer
 
     def _add_gpg_instances(self, keyentry, keydata, localkey, remotekey):
@@ -387,7 +387,7 @@ class YumCollection(Collection):
                                       simplefile=remotekey)
             except ValueError:
                 err = sys.exc_info()[1]
-                self.logger.error("Could not read GPG key %s: %s" %
+                self.logger.error("Packages: Could not read GPG key %s: %s" %
                                   (localkey, err))
 
     def is_package(self, package):
@@ -497,7 +497,7 @@ class YumCollection(Collection):
 
     def get_group(self, group):
         if not self.use_yum:
-            self.logger.warning("Package groups are not supported by Bcfg2's "
+            self.logger.warning("Packages: Package groups are not supported by Bcfg2's "
                                 "internal Yum dependency generator")
             return []
 
@@ -719,23 +719,23 @@ class YumSource(Source):
             except server.ServerRequestError:
                 err = sys.exc_info()[1]
                 if err[0] == 401:
-                    msg = "Error authenticating to Pulp: %s" % err[1]
+                    msg = "Packages: Error authenticating to Pulp: %s" % err[1]
                 elif err[0] == 404:
-                    msg = "Pulp repo id %s not found: %s" % (self.pulp_id,
+                    msg = "Packages: Pulp repo id %s not found: %s" % (self.pulp_id,
                                                              err[1])
                 else:
-                    msg = "Error %d fetching pulp repo %s: %s" % (err[0],
+                    msg = "Packages: Error %d fetching pulp repo %s: %s" % (err[0],
                                                                   self.pulp_id,
                                                                   err[1])
                 logger.error(msg)
                 raise Bcfg2.Server.Plugin.PluginInitError
             except socket.error:
                 err = sys.exc_info()[1]
-                logger.error("Could not contact Pulp server: %s" % err)
+                logger.error("Packages: Could not contact Pulp server: %s" % err)
                 raise Bcfg2.Server.Plugin.PluginInitError
             except:
                 err = sys.exc_info()[1]
-                logger.error("Unknown error querying Pulp server: %s" % err)
+                logger.error("Packages: Unknown error querying Pulp server: %s" % err)
                 raise Bcfg2.Server.Plugin.PluginInitError
             self.rawurl = "%s/%s" % (PULPCONFIG.cds['baseurl'],
                                      self.repo['relative_path'])
@@ -851,7 +851,7 @@ class YumSource(Source):
         try:
             self.packages['global'] = copy.deepcopy(sdata.pop())
         except IndexError:
-            logger.error("No packages in repo")
+            logger.error("Packages: No packages in repo")
         while sdata:
             self.packages['global'] = \
                 self.packages['global'].intersection(sdata.pop())
diff --git a/src/lib/Server/Plugins/Packages/__init__.py b/src/lib/Server/Plugins/Packages/__init__.py
index 4fe785f40..3ee4f21dd 100644
--- a/src/lib/Server/Plugins/Packages/__init__.py
+++ b/src/lib/Server/Plugins/Packages/__init__.py
@@ -140,7 +140,7 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
                     base.update(collection.get_group(pkg.get("group")))
                     to_remove.append(pkg)
                 else:
-                    self.logger.error("Malformed Package: %s" %
+                    self.logger.error("Packages: Malformed Package: %s" %
                                       lxml.etree.tostring(pkg))
         base.update(initial)
         for el in to_remove:
@@ -148,10 +148,10 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
 
         packages, unknown = collection.complete(base)
         if unknown:
-            self.logger.info("Got %d unknown entries" % len(unknown))
-            self.logger.info(list(unknown))
+            self.logger.info("Packages: Got %d unknown entries" % len(unknown))
+            self.logger.info("Packages: %s" % list(unknown))
         newpkgs = list(packages.difference(initial))
-        self.logger.debug("%d initial, %d complete, %d new" %
+        self.logger.debug("Packages: %d initial, %d complete, %d new" %
                           (len(initial), len(packages), len(newpkgs)))
         newpkgs.sort()
         for pkg in newpkgs:
@@ -221,7 +221,7 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
                     keyfiles.append(localfile)
                 if ((force_update and key not in keys) or
                     not os.path.exists(localfile)):
-                    self.logger.info("Downloading and parsing %s" % key)
+                    self.logger.info("Packages: Downloading and parsing %s" % key)
                     response = urlopen(key)
                     open(localfile, 'w').write(response.read())
                     keys.append(key)