ticket 2022 - modify codebase to utilize IPALogManager, obsoletes logging

change default_logger_level to debug in configure_standard_logging

add new ipa_log_manager module, move log_mgr there, also export
root_logger from log_mgr.

change all log_manager imports to ipa_log_manager and change
log_manager.root_logger to root_logger.

add missing import for parse_log_level()

6 files changed, 323 insertions, 298 deletions

diff --git a/ipapython/dogtag.py b/ipapython/dogtag.py
index c5317166a..20f2643b9 100644
--- a/ipapython/dogtag.py
+++ b/ipapython/dogtag.py
@@ -25,7 +25,7 @@ import nss.nss as nss
 from nss.error import NSPRError
 from ipalib.errors import NetworkError, CertificateOperationError
 from urllib import urlencode
-import logging
+from ipapython.ipa_log_manager import *
 
 def get_ca_certchain(ca_host=None):
     """
@@ -74,8 +74,8 @@ def https_request(host, port, url, secdir, password, nickname, **kw):
         host = host.encode('utf-8')
     uri = 'https://%s%s' % (ipautil.format_netloc(host, port), url)
     post = urlencode(kw)
-    logging.info('sslget %r', uri)
-    logging.debug('sslget post %r', post)
+    root_logger.info('sslget %r', uri)
+    root_logger.debug('sslget post %r', post)
     request_headers = {"Content-type": "application/x-www-form-urlencoded",
                        "Accept": "text/plain"}
     try:
@@ -112,8 +112,8 @@ def http_request(host, port, url, **kw):
             host = host.encode('utf-8')
         uri = 'http://%s%s' % (ipautil.format_netloc(host, port), url)
         post = urlencode(kw)
-        logging.info('request %r', uri)
-        logging.debug('request post %r', post)
+        root_logger.info('request %r', uri)
+        root_logger.debug('request post %r', post)
         conn = httplib.HTTPConnection(host, port)
         try:
             conn.request('POST', url,
@@ -130,9 +130,9 @@ def http_request(host, port, url, **kw):
         except NSPRError, e:
             raise NetworkError(uri=uri, error=str(e))
 
-        logging.debug('request status %d',        http_status)
-        logging.debug('request reason_phrase %r', http_reason_phrase)
-        logging.debug('request headers %s',       http_headers)
-        logging.debug('request body %r',          http_body)
+        root_logger.debug('request status %d',        http_status)
+        root_logger.debug('request reason_phrase %r', http_reason_phrase)
+        root_logger.debug('request headers %s',       http_headers)
+        root_logger.debug('request body %r',          http_body)
 
         return http_status, http_reason_phrase, http_headers, http_body
diff --git a/ipapython/ipa_log_manager.py b/ipapython/ipa_log_manager.py
new file mode 100644
index 000000000..11e30d11a
--- /dev/null
+++ b/ipapython/ipa_log_manager.py
@@ -0,0 +1,270 @@
+# Authors: John Dennis <jdennis@redhat.com>
+#
+# Copyright (C) 2011  Red Hat
+# see file 'COPYING' for use and warranty information
+#
+# This program is free software; you can redistribute it and/or modify
+# it under the terms of the GNU General Public License as published by
+# the Free Software Foundation, either version 3 of the License, or
+# (at your option) any later version.
+#
+# This program is distributed in the hope that it will be useful,
+# but WITHOUT ANY WARRANTY; without even the implied warranty of
+# MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+# GNU General Public License for more details.
+#
+# You should have received a copy of the GNU General Public License
+# along with this program.  If not, see <http://www.gnu.org/licenses/>.
+
+#-------------------------------------------------------------------------------
+
+# Module exports
+__all__ = ['log_mgr', 'root_logger', 'standard_logging_setup',
+           'IPA_ROOT_LOGGER_NAME', 'ISO8601_UTC_DATETIME_FMT',
+           'LOGGING_FORMAT_STDERR', 'LOGGING_FORMAT_STDOUT', 'LOGGING_FORMAT_FILE']
+
+#-------------------------------------------------------------------------------
+
+import sys
+import re
+import copy
+
+from log_manager import LogManager, parse_log_level
+
+#-------------------------------------------------------------------------------
+
+# Our root logger, all loggers will be descendents of this.
+IPA_ROOT_LOGGER_NAME = 'ipa'
+
+# Format string for time.strftime() to produce a ISO 8601 date time
+# formatted string in the UTC time zone.
+ISO8601_UTC_DATETIME_FMT = '%Y-%m-%dT%H:%M:%SZ'
+
+# Logging format string for use with logging stderr handlers
+LOGGING_FORMAT_STDERR = 'ipa: %(levelname)s: %(message)s'
+
+# Logging format string for use with logging stdout handlers
+LOGGING_FORMAT_STDOUT = '[%(asctime)s %(name)s] <%(levelname)s>: %(message)s'
+
+# Logging format string for use with logging file handlers
+LOGGING_FORMAT_FILE = '\t'.join([
+    '%(asctime)s',
+    '%(process)d',
+    '%(threadName)s',
+    '%(name)s',
+    '%(levelname)s',
+    '%(message)s',
+])
+
+# Used by standard_logging_setup() for console message
+LOGGING_FORMAT_STANDARD_CONSOLE = '%(name)-12s: %(levelname)-8s %(message)s'
+
+# Used by standard_logging_setup() for file message
+LOGGING_FORMAT_STANDARD_FILE = '%(asctime)s %(levelname)s %(message)s'
+
+#-------------------------------------------------------------------------------
+
+class IPALogManager(LogManager):
+    '''
+    Subclass the LogManager to enforce some IPA specfic logging
+    conventions.
+
+    * Default to timestamps in UTC.
+    * Default to ISO 8601 timestamp format.
+    * Default the message format.
+    '''
+
+    log_logger_level_config_re = re.compile(r'^log_logger_level_(debug|info|warn|warning|error|critical|\d+)$')
+    log_handler_level_config_re = re.compile(r'^log_handler_(\S+)_level$')
+
+    def __init__(self, configure_state=None):
+        '''
+        :parameters:
+          configure_state
+            Used by clients of the log manager to track the
+            configuration state, may be any object.
+        '''
+
+        super(IPALogManager, self).__init__(IPA_ROOT_LOGGER_NAME, configure_state)
+
+    def configure_from_env(self, env, configure_state=None):
+        '''
+        Read the loggger configuration from the Env config. The
+        following items may be configured:
+
+        Logger Levels
+          *log_logger_XXX = comma separated list of regexps*
+
+          Logger levels can be explicitly specified for specific loggers as
+          opposed to a global logging level. Specific loggers are indiciated
+          by a list of regular expressions bound to a level. If a logger's
+          name matches the regexp then it is assigned that level. The keys
+          in the Env config must begin with "log_logger_level\_" and then be
+          followed by a symbolic or numeric log level, for example::
+
+            log_logger_level_debug = ipalib\.dn\..*
+            log_logger_level_35 = ipalib\.plugins\.dogtag
+
+          The first line says any logger belonging to the ipalib.dn module
+          will have it's level configured to debug.
+
+          The second line say the ipa.plugins.dogtag logger will be
+          configured to level 35.
+
+          Note: logger names are a dot ('.') separated list forming a path
+          in the logger tree.  The dot character is also a regular
+          expression metacharacter (matches any character) therefore you
+          will usually need to escape the dot in the logger names by
+          preceeding it with a backslash.
+
+        Handler Levels
+          *log_handler_XXX_level = level*
+
+          Handler levels may be specified with a key containing the
+          name of the handler (XXX) and whose value is the level. For
+          example::
+
+            log_handler_console_level = debug
+
+          Would set the console handler level to debug.
+
+          These are the predefined log handlers:
+
+          console
+            Writes to stderr.
+          file
+            Writes to the default log file.
+
+
+        The return value of this function is a dict with the following
+        format:
+
+        logger_regexps
+          List of (regexp, level) tuples
+        handlers
+          Dict, key is handler name, value is dict of handler config.
+
+          Handler config dict:
+
+          level
+            handler log level
+
+        :parameters:
+          env
+            Env object configuration values are read from.
+          configure_state
+            If other than None update the log manger's configure_state
+            variable to this object. Clients of the log manager can
+            use configure_state to track the state of the log manager.
+        '''
+        logger_regexps = []
+        handlers = {}
+        config = {'logger_regexps' : logger_regexps,
+                  'handlers'       : handlers,
+                 }
+
+        for attr in ('debug', 'verbose'):
+            value = getattr(env, attr, None)
+            if value is not None:
+                config[attr] = value
+
+        for attr in list(env):
+            # Get logger level configuration
+            match = IPALogManager.log_logger_level_config_re.search(attr)
+            if match:
+                value = match.group(1)
+                level = parse_log_level(value)
+                value = getattr(env, attr)
+                regexps = re.split('\s*,\s*', value)
+                # Add the regexp, it maps to the configured level
+                for regexp in regexps:
+                    print "%s %s" % (regexp, level)
+                    logger_regexps.append((regexp, level))
+                continue
+
+            # Get handler configuration
+            match = IPALogManager.log_handler_level_config_re.search(attr)
+            if match:
+                value = getattr(env, attr)
+                try:
+                    level = parse_log_level(value)
+                except Exception, e:
+                    print >>sys.stderr, 'ERROR could not parse log handler level: %s=%s' % (attr, value)
+                    continue
+                name = match.group(1)
+                print "%s %s" % (name, level)
+                handler_config = handlers.get(name)
+                if handler_config is None:
+                    handler_config = {'name' : name}
+                handler_config['level'] = level
+                continue
+
+        self.configure(config, configure_state)
+        return config
+
+    def create_log_handlers(self, configs, logger=None, configure_state=None):
+        'Enforce some IPA specific configurations'
+        configs = copy.copy(configs)
+
+        for cfg in configs:
+            if not 'time_zone_converter' in cfg:
+                cfg['time_zone_converter'] = 'utc'
+            if not 'datefmt' in cfg:
+                cfg['datefmt'] = ISO8601_UTC_DATETIME_FMT
+            if not 'format' in cfg:
+                cfg['format'] = LOGGING_FORMAT_STDOUT
+
+        return super(IPALogManager, self).create_log_handlers(configs, logger, configure_state)
+
+#-------------------------------------------------------------------------------
+
+def standard_logging_setup(filename=None, verbose=False, debug=False, filemode='w'):
+    handlers = []
+
+    # File output is always logged at debug level
+    if filename is not None:
+        file_handler = dict(name='file',
+                            filename=filename,
+                            filemode=filemode,
+                            permission=0600,
+                            level='debug',
+                            format=LOGGING_FORMAT_STANDARD_FILE)
+        handlers.append(file_handler)
+
+    if log_mgr.handlers.has_key('console'):
+        log_mgr.remove_handler('console')
+    level = 'error'
+    if verbose:
+        level = 'info'
+    if debug:
+        level = 'debug'
+
+    console_handler = dict(name='console',
+                           stream=sys.stderr,
+                           level=level,
+                           format=LOGGING_FORMAT_STANDARD_CONSOLE)
+    handlers.append(console_handler)
+
+
+    # default_level must be debug becuase we want the file handler to
+    # always log at the debug level.
+    log_mgr.configure(dict(default_level='debug',
+                           handlers=handlers),
+                      configure_state='standard')
+
+    return log_mgr.root_logger
+
+#-------------------------------------------------------------------------------
+
+# Single shared instance of log manager
+#
+# By default always starts with stderr console handler at error level
+# so messages generated before logging is fully configured have some
+# place to got and won't get lost.
+
+log_mgr = IPALogManager()
+log_mgr.configure(dict(default_level='error',
+                       handlers=[dict(name='console',
+                                      stream=sys.stderr)]),
+                  configure_state='default')
+root_logger = log_mgr.root_logger
diff --git a/ipapython/ipautil.py b/ipapython/ipautil.py
index 718f209b3..c06e7bbcf 100644
--- a/ipapython/ipautil.py
+++ b/ipapython/ipautil.py
@@ -26,7 +26,7 @@ IPA_BASEDN_INFO = 'ipa v2.0'
 
 import string
 import tempfile
-import logging
+from ipapython.ipa_log_manager import *
 import subprocess
 import random
 import os, sys, traceback, readline
@@ -264,10 +264,10 @@ def run(args, stdin=None, raiseonerr=True,
                 stderr = stderr.replace(nolog_value, 'XXXXXXXX')
             args = args.replace(nolog_value, 'XXXXXXXX')
 
-    logging.debug('args=%s' % args)
+    root_logger.debug('args=%s' % args)
     if capture_output:
-        logging.debug('stdout=%s' % stdout)
-        logging.debug('stderr=%s' % stderr)
+        root_logger.debug('stdout=%s' % stdout)
+        root_logger.debug('stderr=%s' % stderr)
 
     if p.returncode != 0 and raiseonerr:
         raise CalledProcessError(p.returncode, args)
@@ -1172,21 +1172,21 @@ def get_ipa_basedn(conn):
 
     contexts = entries[0][1]['namingcontexts']
     for context in contexts:
-        logging.debug("Check if naming context '%s' is for IPA" % context)
+        root_logger.debug("Check if naming context '%s' is for IPA" % context)
         try:
             entry = conn.search_s(context, ldap.SCOPE_BASE, "(info=IPA*)")
         except ldap.NO_SUCH_OBJECT:
-            logging.debug("LDAP server did not return info attribute to check for IPA version")
+            root_logger.debug("LDAP server did not return info attribute to check for IPA version")
             continue
         if len(entry) == 0:
-            logging.debug("Info attribute with IPA server version not found")
+            root_logger.debug("Info attribute with IPA server version not found")
             continue
         info = entry[0][1]['info'][0].lower()
         if info != IPA_BASEDN_INFO:
-            logging.debug("Detected IPA server version (%s) did not match the client (%s)" \
+            root_logger.debug("Detected IPA server version (%s) did not match the client (%s)" \
                 % (info, IPA_BASEDN_INFO))
             continue
-        logging.debug("Naming context '%s' is a valid IPA context" % context)
+        root_logger.debug("Naming context '%s' is a valid IPA context" % context)
         return context
 
     return None
diff --git a/ipapython/log_manager.py b/ipapython/log_manager.py
index 6fa5ec5a1..736d95310 100644
--- a/ipapython/log_manager.py
+++ b/ipapython/log_manager.py
@@ -508,42 +508,11 @@ import pwd
 import logging
 import re
 import time
-import copy
 
 #-------------------------------------------------------------------------------
-# Our root logger, all loggers will be descendents of this.
-IPA_ROOT_LOGGER_NAME = 'ipa'
-
-# Format string for time.strftime() to produce a ISO 8601 date time
-# formatted string in the UTC time zone.
-ISO8601_UTC_DATETIME_FMT = '%Y-%m-%dT%H:%M:%SZ'
-
 # Default format
 LOGGING_DEFAULT_FORMAT = '%(levelname)s %(message)s'
 
-# Logging format string for use with logging stderr handlers
-LOGGING_FORMAT_STDERR = 'ipa: %(levelname)s: %(message)s'
-
-# Logging format string for use with logging stdout handlers
-LOGGING_FORMAT_STDOUT = '[%(asctime)s %(name)s] <%(levelname)s>: %(message)s'
-
-# Logging format string for use with logging file handlers
-LOGGING_FORMAT_FILE = '\t'.join([
-    '%(asctime)s',
-    '%(process)d',
-    '%(threadName)s',
-    '%(name)s',
-    '%(levelname)s',
-    '%(message)s',
-])
-
-# Used by standard_logging_setup() for console message
-LOGGING_FORMAT_STANDARD_CONSOLE = '%(name)-12s: %(levelname)-8s %(message)s'
-
-# Used by standard_logging_setup() for file message
-LOGGING_FORMAT_STANDARD_FILE = '%(asctime)s %(levelname)s %(message)s'
-
-
 # Maps a logging level name to it's numeric value
 log_level_name_map = {
     'notset'   : logging.NOTSET,
@@ -1100,7 +1069,7 @@ class LogManager(object):
           # Create a logger for my_app.foo.bar
           foo_bar_log = log_mgr.get_logger('foo.bar')
 
-          log_mgr.root_logger.info("Ready to process requests")
+          root_logger.info("Ready to process requests")
           foo_bar_log.error("something went boom")
 
         In the file my_app.log you would see::
@@ -1544,205 +1513,3 @@ class LogManager(object):
         return logger
 
 
-class IPALogManager(LogManager):
-    '''
-    Subclass the LogManager to enforce some IPA specfic logging
-    conventions.
-
-    * Default to timestamps in UTC.
-    * Default to ISO 8601 timestamp format.
-    * Default the message format.
-    '''
-
-    log_logger_level_config_re = re.compile(r'^log_logger_level_(debug|info|warn|warning|error|critical|\d+)$')
-    log_handler_level_config_re = re.compile(r'^log_handler_(\S+)_level$')
-
-    def __init__(self, configure_state=None):
-        '''
-        :parameters:
-          configure_state
-            Used by clients of the log manager to track the
-            configuration state, may be any object.
-        '''
-
-        super(IPALogManager, self).__init__(IPA_ROOT_LOGGER_NAME, configure_state)
-
-    def configure_from_env(self, env, configure_state=None):
-        '''
-        Read the loggger configuration from the Env config. The
-        following items may be configured:
-
-        Logger Levels
-          *log_logger_XXX = comma separated list of regexps*
-
-          Logger levels can be explicitly specified for specific loggers as
-          opposed to a global logging level. Specific loggers are indiciated
-          by a list of regular expressions bound to a level. If a logger's
-          name matches the regexp then it is assigned that level. The keys
-          in the Env config must begin with "log_logger_level\_" and then be
-          followed by a symbolic or numeric log level, for example::
-
-            log_logger_level_debug = ipalib\.dn\..*
-            log_logger_level_35 = ipalib\.plugins\.dogtag
-
-          The first line says any logger belonging to the ipalib.dn module
-          will have it's level configured to debug.
-
-          The second line say the ipa.plugins.dogtag logger will be
-          configured to level 35.
-
-          Note: logger names are a dot ('.') separated list forming a path
-          in the logger tree.  The dot character is also a regular
-          expression metacharacter (matches any character) therefore you
-          will usually need to escape the dot in the logger names by
-          preceeding it with a backslash.
-
-        Handler Levels
-          *log_handler_XXX_level = level*
-
-          Handler levels may be specified with a key containing the
-          name of the handler (XXX) and whose value is the level. For
-          example::
-
-            log_handler_console_level = debug
-
-          Would set the console handler level to debug.
-
-          These are the predefined log handlers:
-
-          console
-            Writes to stderr.
-          file
-            Writes to the default log file.
-
-
-        The return value of this function is a dict with the following
-        format:
-
-        logger_regexps
-          List of (regexp, level) tuples
-        handlers
-          Dict, key is handler name, value is dict of handler config.
-
-          Handler config dict:
-
-          level
-            handler log level
-
-        :parameters:
-          env
-            Env object configuration values are read from.
-          configure_state
-            If other than None update the log manger's configure_state
-            variable to this object. Clients of the log manager can
-            use configure_state to track the state of the log manager.
-        '''
-        logger_regexps = []
-        handlers = {}
-        config = {'logger_regexps' : logger_regexps,
-                  'handlers'       : handlers,
-                 }
-
-        for attr in ('debug', 'verbose'):
-            value = getattr(env, attr, None)
-            if value is not None:
-                config[attr] = value
-
-        for attr in list(env):
-            # Get logger level configuration
-            match = IPALogManager.log_logger_level_config_re.search(attr)
-            if match:
-                value = match.group(1)
-                level = parse_log_level(value)
-                value = getattr(env, attr)
-                regexps = re.split('\s*,\s*', value)
-                # Add the regexp, it maps to the configured level
-                for regexp in regexps:
-                    print "%s %s" % (regexp, level)
-                    logger_regexps.append((regexp, level))
-                continue
-
-            # Get handler configuration
-            match = IPALogManager.log_handler_level_config_re.search(attr)
-            if match:
-                value = getattr(env, attr)
-                try:
-                    level = parse_log_level(value)
-                except Exception, e:
-                    print >>sys.stderr, 'ERROR could not parse log handler level: %s=%s' % (attr, value)
-                    continue
-                name = match.group(1)
-                print "%s %s" % (name, level)
-                handler_config = handlers.get(name)
-                if handler_config is None:
-                    handler_config = {'name' : name}
-                handler_config['level'] = level
-                continue
-
-        self.configure(config, configure_state)
-        return config
-
-    def create_log_handlers(self, configs, logger=None, configure_state=None):
-        'Enforce some IPA specific configurations'
-        configs = copy.copy(configs)
-
-        for cfg in configs:
-            if not 'time_zone_converter' in cfg:
-                cfg['time_zone_converter'] = 'utc'
-            if not 'datefmt' in cfg:
-                cfg['datefmt'] = ISO8601_UTC_DATETIME_FMT
-            if not 'format' in cfg:
-                cfg['format'] = LOGGING_FORMAT_STDOUT
-
-        return super(IPALogManager, self).create_log_handlers(configs, logger, configure_state)
-
-#-------------------------------------------------------------------------------
-
-def standard_logging_setup(filename=None, verbose=False, debug=False, filemode='w'):
-    handlers = []
-
-    # File output is always logged at debug level
-    if filename is not None:
-        file_handler = dict(name='file',
-                            filename=filename,
-                            filemode=filemode,
-                            permission=0600,
-                            level='debug',
-                            format=LOGGING_FORMAT_STANDARD_FILE)
-        handlers.append(file_handler)
-
-    if log_mgr.handlers.has_key('console'):
-        log_mgr.remove_handler('console')
-    level = 'error'
-    if verbose:
-        level = 'info'
-    if debug:
-        level = 'debug'
-
-    console_handler = dict(name='console',
-                           stream=sys.stderr,
-                           level=level,
-                           format=LOGGING_FORMAT_STANDARD_CONSOLE)
-    handlers.append(console_handler)
-
-
-    log_mgr.configure(dict(default_level=level,
-                           handlers=handlers),
-                      configure_state='standard')
-
-    return log_mgr.root_logger
-
-#-------------------------------------------------------------------------------
-
-# Single shared instance of log manager
-#
-# By default always starts with stderr console handler at error level
-# so messages generated before logging is fully configured have some
-# place to got and won't get lost.
-
-log_mgr = IPALogManager()
-log_mgr.configure(dict(default_level='error',
-                       handlers=[dict(name='console',
-                                      stream=sys.stderr)]),
-                  configure_state='default')
-
diff --git a/ipapython/nsslib.py b/ipapython/nsslib.py
index 467de1c42..37b02f929 100644
--- a/ipapython/nsslib.py
+++ b/ipapython/nsslib.py
@@ -22,7 +22,7 @@ import sys
 import httplib
 import getpass
 import socket
-import logging
+from ipapython.ipa_log_manager import *
 
 from nss.error import NSPRError
 import nss.io as io
@@ -35,8 +35,8 @@ def auth_certificate_callback(sock, check_sig, is_server, certdb):
 
     cert = sock.get_peer_certificate()
 
-    logging.debug("auth_certificate_callback: check_sig=%s is_server=%s\n%s",
-                  check_sig, is_server, str(cert))
+    root_logger.debug("auth_certificate_callback: check_sig=%s is_server=%s\n%s",
+                              check_sig, is_server, str(cert))
 
     pin_args = sock.get_pkcs11_pin_arg()
     if pin_args is None:
@@ -56,13 +56,13 @@ def auth_certificate_callback(sock, check_sig, is_server, certdb):
         # and the strerror attribute will contain a string describing the reason.
         approved_usage = cert.verify_now(certdb, check_sig, intended_usage, *pin_args)
     except Exception, e:
-        logging.error('cert validation failed for "%s" (%s)', cert.subject, e.strerror)
+        root_logger.error('cert validation failed for "%s" (%s)', cert.subject, e.strerror)
         cert_is_valid = False
         return cert_is_valid
 
-    logging.debug("approved_usage = %s intended_usage = %s",
-                  ', '.join(nss.cert_usage_flags(approved_usage)),
-                  ', '.join(nss.cert_usage_flags(intended_usage)))
+    root_logger.debug("approved_usage = %s intended_usage = %s",
+                              ', '.join(nss.cert_usage_flags(approved_usage)),
+                              ', '.join(nss.cert_usage_flags(intended_usage)))
 
     # Is the intended usage a proper subset of the approved usage
     if approved_usage & intended_usage:
@@ -72,7 +72,7 @@ def auth_certificate_callback(sock, check_sig, is_server, certdb):
 
     # If this is a server, we're finished
     if is_server or not cert_is_valid:
-        logging.debug('cert valid %s for "%s"', cert_is_valid,  cert.subject)
+        root_logger.debug('cert valid %s for "%s"', cert_is_valid,  cert.subject)
         return cert_is_valid
 
     # Certificate is OK.  Since this is the client side of an SSL
@@ -85,12 +85,12 @@ def auth_certificate_callback(sock, check_sig, is_server, certdb):
         # If the cert fails validation it will raise an exception
         cert_is_valid = cert.verify_hostname(hostname)
     except Exception, e:
-        logging.error('failed verifying socket hostname "%s" matches cert subject "%s" (%s)',
-                      hostname, cert.subject, e.strerror)
+        root_logger.error('failed verifying socket hostname "%s" matches cert subject "%s" (%s)',
+                                  hostname, cert.subject, e.strerror)
         cert_is_valid = False
         return cert_is_valid
 
-    logging.debug('cert valid %s for "%s"', cert_is_valid,  cert.subject)
+    root_logger.debug('cert valid %s for "%s"', cert_is_valid,  cert.subject)
     return cert_is_valid
 
 def client_auth_data_callback(ca_names, chosen_nickname, password, certdb):
@@ -142,8 +142,8 @@ class NSSAddressFamilyFallback(object):
         self.sock = io.Socket(family=self.family)
 
     def _connect_socket_family(self, host, port, family):
-        logging.debug("connect_socket_family: host=%s port=%s family=%s",
-                      host, port, io.addr_family_name(family))
+        root_logger.debug("connect_socket_family: host=%s port=%s family=%s",
+                                  host, port, io.addr_family_name(family))
         try:
             addr_info = [ ai for ai in io.AddrInfo(host) if ai.family == family ]
             # No suitable families
@@ -154,12 +154,12 @@ class NSSAddressFamilyFallback(object):
             # Try connecting to the NetworkAddresses
             for net_addr in addr_info:
                 net_addr.port = port
-                logging.debug("connecting: %s", net_addr)
+                root_logger.debug("connecting: %s", net_addr)
                 try:
                     self.sock.connect(net_addr)
                 except Exception, e:
-                    logging.debug("Could not connect socket to %s, error: %s, retrying..",
-                                  net_addr, str(e))
+                    root_logger.debug("Could not connect socket to %s, error: %s, retrying..",
+                                              net_addr, str(e))
                     continue
                 else:
                     return
@@ -181,7 +181,7 @@ class NSSAddressFamilyFallback(object):
                     self._create_socket()
                     self._connect_socket_family(host, port, self.family)
                 else:
-                    logging.debug('No next family to try..')
+                    root_logger.debug('No next family to try..')
                     raise e
             else:
                 raise e
@@ -197,7 +197,7 @@ class NSSConnection(httplib.HTTPConnection, NSSAddressFamilyFallback):
         if not dbdir:
             raise RuntimeError("dbdir is required")
 
-        logging.debug('%s init %s', self.__class__.__name__, host)
+        root_logger.debug('%s init %s', self.__class__.__name__, host)
         if nss.nss_is_initialized():
             # close any open NSS database and use the new one
             ssl.clear_session_cache()
@@ -243,7 +243,7 @@ class NSSConnection(httplib.HTTPConnection, NSSAddressFamilyFallback):
         """
         Verify callback. If we get here then the certificate is ok.
         """
-        logging.debug("handshake complete, peer = %s", sock.get_peer_name())
+        root_logger.debug("handshake complete, peer = %s", sock.get_peer_name())
         pass
 
     def connect(self):
@@ -307,20 +307,8 @@ class NSSHTTPS(httplib.HTTP):
 #------------------------------------------------------------------------------
 
 if __name__ == "__main__":
-    logging.basicConfig(level=logging.DEBUG,
-                        format='%(asctime)s %(levelname)-8s %(message)s',
-                        datefmt='%m-%d %H:%M',
-                        filename='nsslib.log',
-                        filemode='a')
-    # Create a seperate logger for the console
-    console_logger = logging.StreamHandler()
-    console_logger.setLevel(logging.DEBUG)
-    # set a format which is simpler for console use
-    formatter = logging.Formatter('%(levelname)s %(message)s')
-    console_logger.setFormatter(formatter)
-    # add the handler to the root logger
-    logging.getLogger('').addHandler(console_logger)
-    logging.info("Start")
+    standard_logging_setup('nsslib.log', debug=True, filemode='a')
+    root_logger.info("Start")
 
     if False:
         conn = NSSConnection("www.verisign.com", 443, dbdir="/etc/pki/nssdb")
diff --git a/ipapython/sysrestore.py b/ipapython/sysrestore.py
index e22b4d4fa..8177a1bf2 100644
--- a/ipapython/sysrestore.py
+++ b/ipapython/sysrestore.py
@@ -26,7 +26,7 @@
 import os
 import os.path
 import shutil
-import logging
+from ipapython.ipa_log_manager import *
 import ConfigParser
 import random
 import string
@@ -61,7 +61,7 @@ class FileStore:
         be an empty dictionary if the file doesn't exist.
         """
 
-        logging.debug("Loading Index file from '%s'", self._index)
+        root_logger.debug("Loading Index file from '%s'", self._index)
 
         self.files = {}
 
@@ -78,10 +78,10 @@ class FileStore:
         """Save the file list to @_index. If @files is an empty
         dict, then @_index should be removed.
         """
-        logging.debug("Saving Index File to '%s'", self._index)
+        root_logger.debug("Saving Index File to '%s'", self._index)
 
         if len(self.files) == 0:
-            logging.debug("  -> no files, removing file")
+            root_logger.debug("  -> no files, removing file")
             if os.path.exists(self._index):
                 os.remove(self._index)
             return
@@ -101,13 +101,13 @@ class FileStore:
         does not already exist - which will be restored to its
         original location by restore_files().
         """
-        logging.debug("Backing up system configuration file '%s'", path)
+        root_logger.debug("Backing up system configuration file '%s'", path)
 
         if not os.path.isabs(path):
             raise ValueError("Absolute path required")
 
         if not os.path.isfile(path):
-            logging.debug("  -> Not backing up - '%s' doesn't exist", path)
+            root_logger.debug("  -> Not backing up - '%s' doesn't exist", path)
             return
 
         (reldir, backupfile) = os.path.split(path)
@@ -120,7 +120,7 @@ class FileStore:
 
         backup_path = os.path.join(self._path, filename)
         if os.path.exists(backup_path):
-            logging.debug("  -> Not backing up - already have a copy of '%s'", path)
+            root_logger.debug("  -> Not backing up - already have a copy of '%s'", path)
             return
 
         shutil.copy2(path, backup_path)
@@ -151,7 +151,7 @@ class FileStore:
         was no backup file to restore
         """
 
-        logging.debug("Restoring system configuration file '%s'", path)
+        root_logger.debug("Restoring system configuration file '%s'", path)
 
         if not os.path.isabs(path):
             raise ValueError("Absolute path required")
@@ -172,7 +172,7 @@ class FileStore:
 
         backup_path = os.path.join(self._path, filename)
         if not os.path.exists(backup_path):
-            logging.debug("  -> Not restoring - '%s' doesn't exist", backup_path)
+            root_logger.debug("  -> Not restoring - '%s' doesn't exist", backup_path)
             return False
 
         shutil.move(backup_path, path)
@@ -203,7 +203,7 @@ class FileStore:
 
             backup_path = os.path.join(self._path, filename)
             if not os.path.exists(backup_path):
-                logging.debug("  -> Not restoring - '%s' doesn't exist", backup_path)
+                root_logger.debug("  -> Not restoring - '%s' doesn't exist", backup_path)
                 continue
 
             shutil.move(backup_path, path)
@@ -257,7 +257,7 @@ class StateFile:
         """Load the modules from the file @_path. @modules will
         be an empty dictionary if the file doesn't exist.
         """
-        logging.debug("Loading StateFile from '%s'", self._path)
+        root_logger.debug("Loading StateFile from '%s'", self._path)
 
         self.modules = {}
 
@@ -277,14 +277,14 @@ class StateFile:
         """Save the modules to @_path. If @modules is an empty
         dict, then @_path should be removed.
         """
-        logging.debug("Saving StateFile to '%s'", self._path)
+        root_logger.debug("Saving StateFile to '%s'", self._path)
 
         for module in self.modules.keys():
             if len(self.modules[module]) == 0:
                 del self.modules[module]
 
         if len(self.modules) == 0:
-            logging.debug("  -> no modules, removing file")
+            root_logger.debug("  -> no modules, removing file")
             if os.path.exists(self._path):
                 os.remove(self._path)
             return