added toggle_debug back to Packages (#1091)

9 files changed, 124 insertions, 97 deletions

diff --git a/src/lib/Server/Plugin.py b/src/lib/Server/Plugin.py
index 294d97853..1d473fdb7 100644
--- a/src/lib/Server/Plugin.py
+++ b/src/lib/Server/Plugin.py
@@ -63,7 +63,25 @@ class PluginExecutionError(Exception):
     pass
 
 
-class Plugin(object):
+class Debuggable(object):
+    __rmi__ = ['toggle_debug']
+
+    def __init__(self, name=None):
+        if name is None:
+            name = "%s.%s" % (self.__class__.__module__,
+                              self.__class__.__name__)
+        self.debug_flag = False
+        self.logger = logging.getLogger(name)
+        
+    def toggle_debug(self):
+        self.debug_flag = not self.debug_flag
+
+    def debug_log(self, message, flag=None):
+        if (flag is None and self.debug_flag) or flag:
+            self.logger.error(message)
+
+
+class Plugin(Debuggable):
     """This is the base class for all Bcfg2 Server plugins.
     Several attributes must be defined in the subclass:
     name : the name of the plugin
@@ -78,7 +96,6 @@ class Plugin(object):
     name = 'Plugin'
     __version__ = '$Id$'
     __author__ = 'bcfg-dev@mcs.anl.gov'
-    __rmi__ = ['toggle_debug']
     experimental = False
     deprecated = False
     conflicts = []
@@ -98,16 +115,8 @@ class Plugin(object):
         self.Entries = {}
         self.core = core
         self.data = "%s/%s" % (datastore, self.name)
-        self.logger = logging.getLogger('Bcfg2.Plugins.%s' % (self.name))
         self.running = True
-        self.debug_flag = False
-
-    def toggle_debug(self):
-        self.debug_flag = not self.debug_flag
-
-    def debug_log(self, message, flag=None):
-        if (flag is None) and self.debug_flag or flag:
-            self.logger.error(message)
+        Debuggable.__init__(self, name=self.name)
 
     @classmethod
     def init_repo(cls, repo):
diff --git a/src/lib/Server/Plugins/Packages/Apt.py b/src/lib/Server/Plugins/Packages/Apt.py
index ed954af3b..f76bf7fa1 100644
--- a/src/lib/Server/Plugins/Packages/Apt.py
+++ b/src/lib/Server/Plugins/Packages/Apt.py
@@ -1,12 +1,9 @@
 import re
 import gzip
-import logging
 from Bcfg2.Server.Plugins.Packages.Collection import Collection
 from Bcfg2.Server.Plugins.Packages.Source import Source
 from Bcfg2.Bcfg2Py3k import cPickle, file
 
-logger = logging.getLogger("Packages")
-
 class AptCollection(Collection):
     def get_group(self, group):
         self.logger.warning("Packages: Package groups are not supported by APT")
@@ -72,7 +69,7 @@ class AptSource(Source):
             try:
                 reader = gzip.GzipFile(fname)
             except:
-                logger.error("Packages: Failed to read file %s" % fname)
+                self.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 f8cd8e690..32eeda1ec 100644
--- a/src/lib/Server/Plugins/Packages/Collection.py
+++ b/src/lib/Server/Plugins/Packages/Collection.py
@@ -1,13 +1,14 @@
 import copy
 import logging
+import Bcfg2.Server.Plugin
+
+logger = logging.getLogger(__name__)
 
 try:
     from hashlib import md5
 except ImportError:
     from md5 import md5
 
-logger = logging.getLogger("Packages")
-
 # we have to cache Collection objects so that calling Packages.Refresh
 # or .Reload can tell the collection objects to clean up their cache,
 # but we don't actually use the cache to return a Collection object
@@ -20,12 +21,13 @@ logger = logging.getLogger("Packages")
 # sources to that client.)
 collections = dict()
 
-class Collection(object):
-    def __init__(self, metadata, sources, basepath):
-        """ don't call this directly; use the Factory method """
+class Collection(Bcfg2.Server.Plugin.Debuggable):
+    def __init__(self, metadata, sources, basepath, debug=False):
+        """ don't call this directly; use the factory function """
+        Bcfg2.Server.Plugin.Debuggable.__init__(self)
+        self.debug_flag = debug
         self.metadata = metadata
         self.sources = sources
-        self.logger = logging.getLogger("Packages")
         self.basepath = basepath
         self.virt_pkgs = dict()
 
@@ -193,14 +195,14 @@ class Collection(object):
                 # direct packages; current can be added, and all deps
                 # should be resolved
                 current = pkgs.pop()
-                self.logger.debug("Packages: handling package requirement %s" %
-                                  current)
+                self.debug_log("Packages: handling package requirement %s" %
+                               current)
                 packages.add(current)
                 deps = self.get_deps(current)
                 newdeps = set(deps).difference(examined)
                 if newdeps:
-                    self.logger.debug("Packages: Package %s added "
-                                      "requirements %s" % (current, newdeps))
+                    self.debug_log("Packages: Package %s added requirements %s"
+                                   % (current, newdeps))
                 unclassified.update(newdeps)
 
             satisfied_vpkgs = set()
@@ -208,16 +210,15 @@ class Collection(object):
                 # virtual dependencies, satisfied if one of N in the
                 # config, or can be forced if only one provider
                 if len(vpkg_cache[current]) == 1:
-                    self.logger.debug("Packages: requirement %s satisfied by "
-                                      "%s" % (current,
-                                              vpkg_cache[current]))
+                    self.debug_log("Packages: requirement %s satisfied by %s" %
+                                   (current, vpkg_cache[current]))
                     unclassified.update(vpkg_cache[current].difference(examined))
                     satisfied_vpkgs.add(current)
                 else:
                     satisfiers = [item for item in vpkg_cache[current]
                                   if item in packages]
-                    self.logger.debug("Packages: requirement %s satisfied by "
-                                      "%s" % (current, satisfiers))
+                    self.debug_log("Packages: requirement %s satisfied by %s" %
+                                   (current, satisfiers))
                     satisfied_vpkgs.add(current)
             vpkgs.difference_update(satisfied_vpkgs)
 
@@ -230,8 +231,8 @@ class Collection(object):
                 satisfiers = [item for item in vpkg_cache[current]
                               if item in packages]
                 if satisfiers:
-                    self.logger.debug("Packages: requirement %s satisfied by "
-                                      "%s" % (current, satisfiers))
+                    self.debug_log("Packages: requirement %s satisfied by %s" %
+                                   (current, satisfiers))
                     satisfied_both.add(current)
                 elif current in packagelist or final_pass:
                     pkgs.add(current)
@@ -287,7 +288,7 @@ def clear_cache():
     global collections
     collections = dict()
 
-def factory(metadata, sources, basepath):
+def factory(metadata, sources, basepath, debug=False):
     global collections
 
     if not sources.loaded:
@@ -314,7 +315,9 @@ def factory(metadata, sources, basepath):
         # have multiple Bcfg2 servers and Packages-relevant groups set
         # by probes); and b) templates that query all or multiple
         # machines (e.g., with metadata.query.all_clients())
-        logger.debug("Packages: No sources found for %s" % metadata.hostname)
+        if debug:
+            logger.error("Packages: No sources found for %s" %
+                         metadata.hostname)
         cclass = Collection
     else:
         stype = sclasses.pop().__name__.replace("Source", "")
@@ -330,10 +333,11 @@ def factory(metadata, sources, basepath):
             logger.warning("Packages: No collection class found for %s sources"
                            % stype)
 
-    logger.debug("Packages: Using %s for Collection of sources for %s" %
-                 (cclass.__name__, metadata.hostname))
+    if debug:
+        logger.error("Packages: Using %s for Collection of sources for %s" %
+                     (cclass.__name__, metadata.hostname))
 
-    collection = cclass(metadata, relevant, basepath)
+    collection = cclass(metadata, relevant, basepath, debug=debug)
     collections[metadata.hostname] = collection
     return collection
 
diff --git a/src/lib/Server/Plugins/Packages/Pac.py b/src/lib/Server/Plugins/Packages/Pac.py
index 35fb39d02..9db6b0535 100644
--- a/src/lib/Server/Plugins/Packages/Pac.py
+++ b/src/lib/Server/Plugins/Packages/Pac.py
@@ -1,12 +1,9 @@
 import gzip
 import tarfile
-import logging
 from Bcfg2.Bcfg2Py3k import cPickle, file
 from Bcfg2.Server.Plugins.Packages.Collection import Collection
 from Bcfg2.Server.Plugins.Packages.Source import Source
 
-logger = logging.getLogger("Packages")
-
 class PacCollection(Collection):
     def get_group(self, group):
         self.logger.warning("Packages: Package groups are not supported by APT")
@@ -71,17 +68,18 @@ class PacSource(Source):
                 bdeps[barch] = dict()
                 bprov[barch] = dict()
             try:
-                logger.debug("Packages: try to read : " + fname)
+                self.debug_log("Packages: try to read %s" % fname)
                 tar = tarfile.open(fname, "r")
                 reader = gzip.GzipFile(fname)
             except:
-                logger.error("Packages: Failed to read file %s" % fname)
+                self.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("Packages: added : " + tarinfo.name.rsplit("-", 2)[0])
+                    self.debug_log("Packages: added %s" %
+                                   tarinfo.name.rsplit("-", 2)[0])
             tar.close()
 
         self.deps['global'] = dict()
diff --git a/src/lib/Server/Plugins/Packages/PackagesConfig.py b/src/lib/Server/Plugins/Packages/PackagesConfig.py
index dd39bb495..75ff7a3b7 100644
--- a/src/lib/Server/Plugins/Packages/PackagesConfig.py
+++ b/src/lib/Server/Plugins/Packages/PackagesConfig.py
@@ -1,8 +1,5 @@
-import logging
 import Bcfg2.Server.Plugin
 
-logger = logging.getLogger('Packages')
-
 class PackagesConfig(Bcfg2.Server.Plugin.SimpleConfig):
     _required = False
     
diff --git a/src/lib/Server/Plugins/Packages/PackagesSources.py b/src/lib/Server/Plugins/Packages/PackagesSources.py
index 4fbccab30..35759879d 100644
--- a/src/lib/Server/Plugins/Packages/PackagesSources.py
+++ b/src/lib/Server/Plugins/Packages/PackagesSources.py
@@ -1,17 +1,16 @@
 import os
 import sys
 import lxml.etree
-import logging
 import Bcfg2.Server.Plugin
 from Bcfg2.Server.Plugins.Packages.Source import SourceInitError
 
-logger = logging.getLogger("Packages")
-
 class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
-                      Bcfg2.Server.Plugin.StructFile):
+                      Bcfg2.Server.Plugin.StructFile,
+                      Bcfg2.Server.Plugin.Debuggable):
     __identifier__ = None
     
     def __init__(self, filename, cachepath, fam, packages, config):
+        Bcfg2.Server.Plugin.Debuggable.__init__(self)
         try:
             Bcfg2.Server.Plugin.SingleXMLFileBacked.__init__(self,
                                                              filename,
@@ -21,7 +20,7 @@ class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
             msg = "Packages: Failed to read configuration file: %s" % err
             if not os.path.exists(self.name):
                 msg += " Have you created it?"
-            logger.error(msg)
+            self.logger.error(msg)
             raise Bcfg2.Server.Plugin.PluginInitError(msg)
         Bcfg2.Server.Plugin.StructFile.__init__(self, filename)
         self.cachepath = cachepath
@@ -33,13 +32,18 @@ class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
         self.parsed = set()
         self.loaded = False
 
+    def toggle_debug(self):
+        Bcfg2.Server.Plugin.Debuggable.toggle_debug(self)
+        for source in self.entries:
+            source.toggle_debug()
+
     def HandleEvent(self, event=None):
         Bcfg2.Server.Plugin.SingleXMLFileBacked.HandleEvent(self, event=event)
         if event.filename != self.name:
             self.parsed.add(os.path.basename(event.filename))
 
         if sorted(list(self.parsed)) == sorted(self.extras):
-            logger.info("Reloading Packages plugin")
+            self.logger.info("Reloading Packages plugin")
             self.pkg_obj.Reload()
             self.loaded = True
 
@@ -56,7 +60,8 @@ class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
         sources.xml """
         stype = xsource.get("type")
         if stype is None:
-            logger.error("Packages: No type specified for source, skipping")
+            self.logger.error("Packages: No type specified for source, "
+                              "skipping")
             return None
 
         try:
@@ -65,14 +70,14 @@ class PackagesSources(Bcfg2.Server.Plugin.SingleXMLFileBacked,
                              stype.title())
             cls = getattr(module, "%sSource" % stype.title())
         except (ImportError, AttributeError):
-            logger.error("Packages: Unknown source type %s" % stype)
+            self.logger.error("Packages: Unknown source type %s" % stype)
             return None
 
         try:
             source = cls(self.cachepath, xsource, self.config)
         except SourceInitError:
             err = sys.exc_info()[1]
-            logger.error("Packages: %s" % err)
+            self.logger.error("Packages: %s" % err)
             source = None
 
         return source
diff --git a/src/lib/Server/Plugins/Packages/Source.py b/src/lib/Server/Plugins/Packages/Source.py
index dbb510053..797250fbc 100644
--- a/src/lib/Server/Plugins/Packages/Source.py
+++ b/src/lib/Server/Plugins/Packages/Source.py
@@ -2,7 +2,7 @@ import os
 import re
 import sys
 import base64
-import logging
+import Bcfg2.Server.Plugin
 from Bcfg2.Bcfg2Py3k import HTTPError, HTTPBasicAuthHandler, \
      HTTPPasswordMgrWithDefaultRealm, install_opener, build_opener, \
      urlopen, file, cPickle
@@ -12,8 +12,6 @@ try:
 except ImportError:
     from md5 import md5
 
-logger = logging.getLogger('Packages')
-
 def fetch_url(url):
     if '@' in url:
         mobj = re.match('(\w+://)([^:]+):([^@]+)@(.*)$', url)
@@ -32,11 +30,12 @@ class SourceInitError(Exception):
     pass
 
 
-class Source(object):
+class Source(Bcfg2.Server.Plugin.Debuggable):
     reponame_re = re.compile(r'.*/(?:RPMS\.)?([^/]+)')
     basegroups = []
 
     def __init__(self, basepath, xsource, config):
+        Bcfg2.Server.Plugin.Debuggable.__init__(self)
         self.basepath = basepath
         self.xsource = xsource
         self.config = config
@@ -113,14 +112,14 @@ class Source(object):
                 self.load_state()
                 should_read = False 
             except:
-                logger.error("Packages: Cachefile %s load failed; "
-                             "falling back to file read" % self.cachefile)
+                self.logger.error("Packages: Cachefile %s load failed; "
+                                  "falling back to file read" % self.cachefile)
         if should_read:
             try:
                 self.read_files()
             except:
-                logger.error("Packages: File read failed; "
-                             "falling back to file download")
+                self.logger.error("Packages: File read failed; "
+                                  "falling back to file download")
                 should_download = True
 
         if should_download or force_update:
@@ -128,9 +127,10 @@ class Source(object):
                 self.update()
                 self.read_files()
             except:
-                logger.error("Packages: Failed to load data for Source of %s. "
-                             "Some Packages will be missing."
-                             % self.urls)
+                raise
+                self.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
@@ -194,18 +194,18 @@ class Source(object):
 
     def update(self):
         for url in self.urls:
-            logger.info("Packages: Updating %s" % url)
+            self.logger.info("Packages: Updating %s" % url)
             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)
+                self.logger.error("Packages: Bad url string %s" % url)
                 raise
             except HTTPError:
                 err = sys.exc_info()[1]
-                logger.error("Packages: Failed to fetch url %s. HTTP response code=%s" %
-                             (url, err.code))
+                self.logger.error("Packages: Failed to fetch url %s. HTTP "
+                                  "response code=%s" % (url, err.code))
                 raise
 
     def applies(self, metadata):
diff --git a/src/lib/Server/Plugins/Packages/Yum.py b/src/lib/Server/Plugins/Packages/Yum.py
index 2dc9651cf..76ea62060 100644
--- a/src/lib/Server/Plugins/Packages/Yum.py
+++ b/src/lib/Server/Plugins/Packages/Yum.py
@@ -16,7 +16,7 @@ from Bcfg2.Server.Plugins.Packages.Collection import Collection
 from Bcfg2.Server.Plugins.Packages.Source import SourceInitError, Source, \
      fetch_url
 
-logger = logging.getLogger("Packages")
+logger = logging.getLogger(__name__)
 
 try:
     from pulp.client.consumer.config import ConsumerConfig
@@ -86,8 +86,8 @@ class YumCollection(Collection):
     # not be included in the temporary yum.conf we write out
     option_blacklist = ["use_yum_libraries", "helper"]
     
-    def __init__(self, metadata, sources, basepath):
-        Collection.__init__(self, metadata, sources, basepath)
+    def __init__(self, metadata, sources, basepath, debug=False):
+        Collection.__init__(self, metadata, sources, basepath, debug=debug)
         self.keypath = os.path.join(self.basepath, "keys")
 
         if len(sources):
@@ -248,10 +248,12 @@ class YumCollection(Collection):
             pass
         except socket.error:
             err = sys.exc_info()[1]
-            logger.error("Packages: Could not contact Pulp server: %s" % err)
+            self.logger.error("Packages: Could not contact Pulp server: %s" %
+                              err)
         except:
             err = sys.exc_info()[1]
-            logger.error("Packages: Unknown error querying Pulp server: %s" % err)
+            self.logger.error("Packages: Unknown error querying Pulp server: %s"
+                              % err)
         return consumer
 
     def _add_gpg_instances(self, keyentry, keydata, localkey, remotekey):
@@ -356,8 +358,11 @@ class YumCollection(Collection):
         # get the 'setup' variable, so we don't know how verbose
         # bcfg2-server is.  It'd also be nice if we could tell yum to
         # log to syslog.  So would a unicorn.
-        cmd = [self.helper, "-c", self.cfgfile, command]
-        self.logger.debug("Packages: running %s" % " ".join(cmd))
+        cmd = [self.helper, "-c", self.cfgfile]
+        if self.debug_flag:
+            cmd.append("-v")
+        cmd.append(command)
+        self.debug_log("Packages: running %s" % " ".join(cmd))
         try:
             helper = Popen(cmd, stdin=PIPE, stdout=PIPE, stderr=PIPE)
         except OSError:
@@ -499,17 +504,17 @@ class YumSource(Source):
             repomd = fetch_url(rmdurl)
             xdata = lxml.etree.XML(repomd)
         except ValueError:
-            logger.error("Packages: Bad url string %s" % rmdurl)
+            self.logger.error("Packages: Bad url string %s" % rmdurl)
             return []
         except HTTPError:
             err = sys.exc_info()[1]
-            logger.error("Packages: Failed to fetch url %s. code=%s" %
-                         (rmdurl, err.code))
+            self.logger.error("Packages: Failed to fetch url %s. code=%s" %
+                              (rmdurl, err.code))
             return []
         except lxml.etree.XMLSyntaxError:
             err = sys.exc_info()[1]
-            logger.error("Packages: Failed to process metadata at %s: %s" %
-                         (rmdurl, err))
+            self.logger.error("Packages: Failed to process metadata at %s: %s" %
+                              (rmdurl, err))
             return []
 
         urls = []
@@ -583,8 +588,8 @@ class YumSource(Source):
             self.packages[arch].add(pkgname)
 
             pdata = pkg.find(XP + 'format')
-            pre = pdata.find(RP + 'requires')
             self.deps[arch][pkgname] = set()
+            pre = pdata.find(RP + 'requires')
             for entry in pre.getchildren():
                 self.deps[arch][pkgname].add(entry.get('name'))
                 if entry.get('name').startswith('/'):
diff --git a/src/lib/Server/Plugins/Packages/__init__.py b/src/lib/Server/Plugins/Packages/__init__.py
index 699e349b4..daa20404c 100644
--- a/src/lib/Server/Plugins/Packages/__init__.py
+++ b/src/lib/Server/Plugins/Packages/__init__.py
@@ -4,7 +4,6 @@ import time
 import copy
 import glob
 import shutil
-import logging
 import lxml.etree
 import Bcfg2.Logger
 import Bcfg2.Server.Plugin
@@ -13,8 +12,6 @@ from Bcfg2.Server.Plugins.Packages import Collection
 from Bcfg2.Server.Plugins.Packages.PackagesSources import PackagesSources
 from Bcfg2.Server.Plugins.Packages.PackagesConfig import PackagesConfig
 
-logger = logging.getLogger('Packages')
-
 class Packages(Bcfg2.Server.Plugin.Plugin,
                Bcfg2.Server.Plugin.StructureValidator,
                Bcfg2.Server.Plugin.Generator,
@@ -44,6 +41,10 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
                                        self.cachepath, core.fam, self,
                                        self.config)
 
+    def toggle_debug(self):
+        Bcfg2.Server.Plugin.Plugin.toggle_debug(self)
+        self.sources.toggle_debug()
+
     @property
     def disableResolver(self):
         return self.config.get("global", "resolver",
@@ -62,14 +63,16 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
                   'type': 'file',
                   'perms': '0644'}
 
-        collection = Collection.factory(metadata, self.sources, self.data)
+        collection = Collection.factory(metadata, self.sources, self.data,
+                                        debug=self.debug_flag)
         entry.text = collection.get_config()
         for (key, value) in list(attrib.items()):
             entry.attrib.__setitem__(key, value)
 
     def HandleEntry(self, entry, metadata):
         if entry.tag == 'Package':
-            collection = Collection.factory(metadata, self.sources, self.data)
+            collection = Collection.factory(metadata, self.sources, self.data,
+                                            debug=self.debug_flag)
             entry.set('version', 'auto')
             entry.set('type', collection.ptype)
         elif entry.tag == 'Path':
@@ -81,8 +84,14 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
 
     def HandlesEntry(self, entry, metadata):
         if entry.tag == 'Package':
-            collection = Collection.factory(metadata, self.sources, self.data)
-            if collection.magic_groups_match():
+            if self.config.getboolean("global", "magic_groups",
+                                      default=True) == True:
+                collection = Collection.factory(metadata, self.sources,
+                                                self.data,
+                                                debug=self.debug_flag)
+                if collection.magic_groups_match():
+                    return True
+            else:
                 return True
         elif entry.tag == 'Path':
             # managed entries for yum/apt configs
@@ -100,7 +109,8 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
         metadata - client metadata instance
         structures - a list of structure-stage entry combinations
         '''
-        collection = Collection.factory(metadata, self.sources, self.data)
+        collection = Collection.factory(metadata, self.sources, self.data,
+                                        debug=self.debug_flag)
         indep = lxml.etree.Element('Independent')
         self._build_packages(metadata, indep, structures,
                              collection=collection)
@@ -116,7 +126,8 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
             return
 
         if collection is None:
-            collection = Collection.factory(metadata, self.sources, self.data)
+            collection = Collection.factory(metadata, self.sources, self.data,
+                                            debug=self.debug_flag)
         # initial is the set of packages that are explicitly specified
         # in the configuration
         initial = set()
@@ -152,8 +163,8 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
             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("Packages: %d initial, %d complete, %d new" %
-                          (len(initial), len(packages), len(newpkgs)))
+        self.debug_log("Packages: %d initial, %d complete, %d new" %
+                       (len(initial), len(packages), len(newpkgs)))
         newpkgs.sort()
         for pkg in newpkgs:
             lxml.etree.SubElement(independent, 'BoundPackage', name=pkg,
@@ -209,8 +220,8 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
                         os.unlink(cfile)
                 except OSError:
                     err = sys.exc_info()[1]
-                    logger.error("Packages: Could not remove cache file %s: %s"
-                                 % (cfile, err))
+                    self.logger.error("Packages: Could not remove cache file "
+                                      "%s: %s" % (cfile, err))
 
     def _load_gpg_keys(self, force_update):
         """ Load gpg keys from the config """
@@ -234,5 +245,6 @@ class Packages(Bcfg2.Server.Plugin.Plugin,
                 os.unlink(kfile)
 
     def get_additional_data(self, metadata):
-        collection = Collection.factory(metadata, self.sources, self.data)
+        collection = Collection.factory(metadata, self.sources, self.data,
+                                        debug=self.debug_flag)
         return dict(sources=collection.get_additional_data())