logging: do not log into the root logger

Deprecate `ipa_log_manager.root_logger` and replace all calls to it with
module-level logger calls.

Reviewed-By: Martin Basti <mbasti@redhat.com>

ipaserver/advise/base.py

@@ -29,7 +29,7 @@ from ipalib.plugable import Plugin, API
 from ipalib.errors import ValidationError
 from ipaplatform.paths import paths
 from ipapython import admintool
-from ipapython.ipa_log_manager import Filter, root_logger
+from ipapython.ipa_log_manager import Filter
 
 
 """
@@ -508,6 +508,7 @@ class IpaAdvise(admintool.AdminTool):
         if not self.options.verbose:
             # Do not print connection information by default
             logger_name = r'ipalib\.rpc'
+            root_logger = logging.getLogger()
             root_logger.addFilter(Filter(logger_name, logging.WARNING))
 
         # With no argument, print the list out and exit

ipaserver/dcerpc.py

@@ -29,7 +29,6 @@ import time
 from ipalib import api, _
 from ipalib import errors
 from ipapython import ipautil
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 from ipaserver.install import installutils
 from ipalib.util import normalize_name
@@ -470,7 +469,7 @@ class DomainValidator(object):
         return pysss_type_key_translation_dict.get(object_type)
 
     def get_trusted_domain_object_from_sid(self, sid):
-        root_logger.debug("Converting SID to object name: %s" % sid)
+        logger.debug("Converting SID to object name: %s", sid)
 
         # Check if the given SID is valid
         if not self.is_trusted_sid_valid(sid):
@@ -488,7 +487,7 @@ class DomainValidator(object):
                 return result.get(pysss_nss_idmap.NAME_KEY)
 
         # If unsuccessful, search AD DC LDAP
-        root_logger.debug("Searching AD DC LDAP")
+        logger.debug("Searching AD DC LDAP")
 
         escaped_sid = escape_filter_chars(
             security.dom_sid(sid).__ndr_pack__(),
@@ -659,7 +658,7 @@ class DomainValidator(object):
         (principal, password) = self._admin_creds.split('%', 1)
 
         # Destroy the contents of the ccache
-        root_logger.debug('Destroying the contents of the separate ccache')
+        logger.debug('Destroying the contents of the separate ccache')
 
         ipautil.run(
             [paths.KDESTROY, '-A', '-c', ccache_path],
@@ -667,7 +666,7 @@ class DomainValidator(object):
             raiseonerr=False)
 
         # Destroy the contents of the ccache
-        root_logger.debug('Running kinit with credentials of AD administrator')
+        logger.debug('Running kinit with credentials of AD administrator')
 
         result = ipautil.run(
             [paths.KINIT, principal],
@@ -743,9 +742,9 @@ class DomainValidator(object):
                     msg = "Search on AD DC {host}:{port} failed with: {err}"\
                           .format(host=host, port=str(port), err=str(e))
                     if quiet:
-                        root_logger.debug(msg)
+                        logger.debug('%s', msg)
                     else:
-                        root_logger.warning(msg)
+                        logger.warning('%s', msg)
 
                 return entries
 
@@ -944,15 +943,15 @@ class TrustDomainInstance(object):
             search_result = res['defaultNamingContext'][0]
             self.info['dns_hostname'] = res['dnsHostName'][0]
         except _ldap.LDAPError as e:
-            root_logger.error(
-                "LDAP error when connecting to %(host)s: %(error)s" %
-                dict(host=unicode(result.pdc_name), error=str(e)))
+            logger.error(
+                "LDAP error when connecting to %s: %s",
+                unicode(result.pdc_name), str(e))
         except KeyError as e:
-            root_logger.error("KeyError: {err}, LDAP entry from {host} "
-                              "returned malformed. Your DNS might be "
-                              "misconfigured."
-                              .format(host=unicode(result.pdc_name),
-                                      err=unicode(e)))
+            logger.error("KeyError: %s, LDAP entry from %s "
+                         "returned malformed. Your DNS might be "
+                         "misconfigured.",
+                         unicode(e),
+                         unicode(result.pdc_name))
 
         if search_result:
             self.info['sid'] = self.parse_naming_context(search_result)
@@ -1110,7 +1109,7 @@ class TrustDomainInstance(object):
         # Collision information contains entries for specific trusted domains
         # we collide with. Look into TLN collisions and add a TLN exclusion
         # entry to the specific domain trust.
-        root_logger.error("Attempt to solve forest trust topology conflicts")
+        logger.error("Attempt to solve forest trust topology conflicts")
         for rec in cinfo.entries:
             if rec.type == lsa.LSA_FOREST_TRUST_COLLISION_TDO:
                 dominfo = self._pipe.lsaRQueryForestTrustInformation(
@@ -1122,14 +1121,14 @@ class TrustDomainInstance(object):
                 # trusted domain (forest).
                 if not dominfo:
                     result.append(rec)
-                    root_logger.error("Unable to resolve conflict for "
-                                      "DNS domain %s in the forest %s "
-                                      "for domain trust %s. Trust cannot "
-                                      "be established unless this conflict "
-                                      "is fixed manually."
-                                      % (another_domain.info['dns_domain'],
-                                         self.info['dns_domain'],
-                                         rec.name.string))
+                    logger.error("Unable to resolve conflict for "
+                                 "DNS domain %s in the forest %s "
+                                 "for domain trust %s. Trust cannot "
+                                 "be established unless this conflict "
+                                 "is fixed manually.",
+                                 another_domain.info['dns_domain'],
+                                 self.info['dns_domain'],
+                                 rec.name.string)
                     continue
 
                 # Copy over the entries, extend with TLN exclusion
@@ -1165,27 +1164,27 @@ class TrustDomainInstance(object):
                              fti, 0)
                 if cninfo:
                     result.append(rec)
-                    root_logger.error("When defining exception for DNS "
-                                      "domain %s in forest %s for "
-                                      "trusted forest %s, "
-                                      "got collision info back:\n%s"
-                                      % (another_domain.info['dns_domain'],
-                                         self.info['dns_domain'],
-                                         rec.name.string,
-                                         ndr_print(cninfo)))
+                    logger.error("When defining exception for DNS "
+                                 "domain %s in forest %s for "
+                                 "trusted forest %s, "
+                                 "got collision info back:\n%s",
+                                 another_domain.info['dns_domain'],
+                                 self.info['dns_domain'],
+                                 rec.name.string,
+                                 ndr_print(cninfo))
             else:
                 result.append(rec)
-                root_logger.error("Unable to resolve conflict for "
-                                  "DNS domain %s in the forest %s "
-                                  "for in-forest domain %s. Trust cannot "
-                                  "be established unless this conflict "
-                                  "is fixed manually."
-                                  % (another_domain.info['dns_domain'],
-                                     self.info['dns_domain'],
-                                     rec.name.string))
+                logger.error("Unable to resolve conflict for "
+                             "DNS domain %s in the forest %s "
+                             "for in-forest domain %s. Trust cannot "
+                             "be established unless this conflict "
+                             "is fixed manually.",
+                             another_domain.info['dns_domain'],
+                             self.info['dns_domain'],
+                             rec.name.string)
 
         if len(result) == 0:
-            root_logger.error("Successfully solved all conflicts")
+            logger.error("Successfully solved all conflicts")
             raise TrustTopologyConflictSolved()
 
         # Otherwise, raise TrustTopologyConflictError() exception
@@ -1217,9 +1216,9 @@ class TrustDomainInstance(object):
                         ftlevel,
                         ftinfo, 0)
             if cinfo:
-                root_logger.error("When setting forest trust information, "
-                                  "got collision info back:\n%s"
-                                  % (ndr_print(cinfo)))
+                logger.error("When setting forest trust information, "
+                             "got collision info back:\n%s",
+                             ndr_print(cinfo))
                 self.clear_ftinfo_conflict(another_domain, cinfo)
 
     def establish_trust(self, another_domain, trustdom_secret,
@@ -1310,8 +1309,8 @@ class TrustDomainInstance(object):
                                       trustdom_handle,
                                       lsa.LSA_TRUSTED_DOMAIN_INFO_INFO_EX, info)
             except RuntimeError as e:
-                root_logger.error(
-                      'unable to set trust transitivity status: %s' % (str(e)))
+                logger.error(
+                      'unable to set trust transitivity status: %s', str(e))
 
         # Updating forest trust info may fail
         # If it failed due to topology conflict, it may be fixed automatically

ipaserver/dns_data_management.py

@@ -4,6 +4,8 @@
 
 from __future__ import absolute_import
 
+import logging
+
 import six
 
 from collections import defaultdict
@@ -20,11 +22,12 @@ from time import sleep, time
 from ipalib import errors
 from ipalib.dns import record_name_format
 from ipapython.dnsutil import DNSName, resolve_rrsets
-from ipapython.ipa_log_manager import root_logger
 
 if six.PY3:
     unicode=str
 
+logger = logging.getLogger(__name__)
+
 
 IPA_DEFAULT_MASTER_SRV_REC = (
     # srv record name, port
@@ -142,8 +145,8 @@ class IPASystemRecords(object):
             sleep(5)
 
         if not rrsets:
-            root_logger.error('unable to resolve host name %s to IP address, '
-                              'ipa-ca DNS record will be incomplete', hostname)
+            logger.error('unable to resolve host name %s to IP address, '
+                         'ipa-ca DNS record will be incomplete', hostname)
             return
 
         for rrset in rrsets:

ipaserver/dnssec/ldapkeydb.py

@@ -415,7 +415,6 @@ if __name__ == '__main__':
     # print information we think are useful to stdout
     # other garbage goes via logger to stderr
     ipa_log_manager.standard_logging_setup(debug=True)
-    log = ipa_log_manager.root_logger
 
     # IPA framework initialization
     # no logging to file
@@ -425,10 +424,10 @@ if __name__ == '__main__':
     # LDAP initialization
     dns_dn = DN(ipalib.api.env.container_dns, ipalib.api.env.basedn)
     ldap = ipaldap.LDAPClient(ipalib.api.env.ldap_uri)
-    log.debug('Connecting to LDAP')
+    logger.debug('Connecting to LDAP')
     # GSSAPI will be used, used has to be kinited already
     ldap.gssapi_bind()
-    log.debug('Connected')
+    logger.debug('Connected')
 
     ldapkeydb = LdapKeyDB(ldap, DN(('cn', 'keys'),
                                    ('cn', 'sec'),

ipaserver/dnssec/odsmgr.py

@@ -209,4 +209,4 @@ if __name__ == '__main__':
     ipa_log_manager.standard_logging_setup(debug=True)
     ods = ODSMgr()
     reader = ods.get_ods_zonelist()
-    ipa_log_manager.root_logger.info('ODS zones: %s', reader.mapping)
+    logger.info('ODS zones: %s', reader.mapping)

ipaserver/install/adtrust.py

@@ -8,6 +8,7 @@ AD trust installer module
 
 from __future__ import print_function
 
+import logging
 import os
 
 import six
@@ -21,7 +22,6 @@ from ipapython.admintool import ScriptError
 from ipapython import ipaldap, ipautil
 from ipapython.dn import DN
 from ipapython.install.core import group, knob
-from ipapython.ipa_log_manager import root_logger
 from ipaserver.install import adtrustinstance
 from ipaserver.install import service
 
@@ -29,13 +29,15 @@ from ipaserver.install import service
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 netbios_name = None
 reset_netbios_name = False
 
 
 def netbios_name_error(name):
-    root_logger.error("\nIllegal NetBIOS name [%s].\n" % name)
-    root_logger.error(
+    logger.error("\nIllegal NetBIOS name [%s].\n", name)
+    logger.error(
         "Up to 15 characters and only uppercase ASCII letters, digits "
         "and dashes are allowed. Empty string is not allowed.")
 
@@ -72,7 +74,7 @@ def retrieve_netbios_name(api):
             [flat_name_attr])
     except errors.NotFound:
         # trust not configured
-        root_logger.debug("No previous trust configuration found")
+        logger.debug("No previous trust configuration found")
         return None
     else:
         return entry.get(flat_name_attr)[0]
@@ -98,7 +100,7 @@ def set_and_check_netbios_name(netbios_name, unattended, api):
     if api.Backend.ldap2.isconnected():
         cur_netbios_name = retrieve_netbios_name(api)
     else:
-        root_logger.debug(
+        logger.debug(
             "LDAP is not connected, can not retrieve NetBIOS name")
 
     if cur_netbios_name and not netbios_name:
@@ -192,7 +194,7 @@ def retrieve_entries_without_sid(api):
              '(objectclass=ipaidobject))(!(ipantsecurityidentifier=*)))'
     base_dn = api.env.basedn
     try:
-        root_logger.debug(
+        logger.debug(
             "Searching for objects with missing SID with "
             "filter=%s, base_dn=%s", filter, base_dn)
         entries, _truncated = api.Backend.ldap2.find_entries(
@@ -202,7 +204,7 @@ def retrieve_entries_without_sid(api):
         # All objects have SIDs assigned
         pass
     except (errors.DatabaseError, errors.NetworkError) as e:
-        root_logger.error(
+        logger.error(
             "Could not retrieve a list of objects that need a SID "
             "identifier assigned: %s", e)
 
@@ -214,7 +216,7 @@ def retrieve_and_ask_about_sids(api, options):
     if api.Backend.ldap2.isconnected():
         entries = retrieve_entries_without_sid(api)
     else:
-        root_logger.debug(
+        logger.debug(
             "LDAP backend not connected, can not retrieve entries "
             "with missing SID")
 
@@ -258,7 +260,7 @@ def retrieve_potential_adtrust_agents(api):
         dl_enabled_masters = api.Command.server_find(
             ipamindomainlevel=DOMAIN_LEVEL_0, all=True)['result']
     except (errors.DatabaseError, errors.NetworkError) as e:
-        root_logger.error(
+        logger.error(
             "Could not retrieve a list of existing IPA masters: %s", e)
         return
 
@@ -267,7 +269,7 @@ def retrieve_potential_adtrust_agents(api):
         adtrust_agents = api.Command.server_find(
             servrole=u'AD trust agent', all=True)['result']
     except (errors.DatabaseError, errors.NetworkError) as e:
-        root_logger.error("Could not retrieve a list of adtrust agents: %s", e)
+        logger.error("Could not retrieve a list of adtrust agents: %s", e)
         return
 
     dl_enabled_master_cns = {m['cn'][0] for m in dl_enabled_masters}

ipaserver/install/adtrustinstance.py

@@ -19,6 +19,7 @@
 
 from __future__ import print_function
 
+import logging
 import os
 import errno
 import ldap
@@ -40,7 +41,6 @@ from ipalib import errors, api
 from ipalib.util import normalize_zone
 from ipapython.dn import DN
 from ipapython import ipautil
-from ipapython.ipa_log_manager import root_logger
 import ipapython.errors
 
 import ipaclient.install.ipachangeconf
@@ -52,6 +52,8 @@ from ipaplatform.tasks import tasks
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 ALLOWED_NETBIOS_CHARS = string.ascii_uppercase + string.digits + '-'
 
 UPGRADE_ERROR = """
@@ -339,8 +341,8 @@ class ADTRUSTInstance(service.Service):
 
             # Abort if RID base needs to be added to more than one range
             if len(ranges_with_no_rid_base) != 1:
-                root_logger.critical("Found more than one local domain ID "
-                                     "range with no RID base set.")
+                logger.critical("Found more than one local domain ID "
+                                "range with no RID base set.")
                 raise RuntimeError("Too many ID ranges\n")
 
             # Abort if RID bases are too close
@@ -372,8 +374,8 @@ class ADTRUSTInstance(service.Service):
                 raise RuntimeError("Constraint violation.\n")
 
         except errors.NotFound as e:
-            root_logger.critical("ID range of the local domain not found, "
-                                 "define it and run again.")
+            logger.critical("ID range of the local domain not found, "
+                            "define it and run again.")
             raise e
 
     def __reset_netbios_name(self):
@@ -487,8 +489,8 @@ class ADTRUSTInstance(service.Service):
             wait_for_task(api.Backend.ldap2, task_dn)
 
         except Exception as e:
-            root_logger.warning("Exception occured during SID generation: {0}"
-                                .format(str(e)))
+            logger.warning("Exception occured during SID generation: %s",
+                           str(e))
 
     def __add_s4u2proxy_target(self):
         """
@@ -549,8 +551,8 @@ class ADTRUSTInstance(service.Service):
                              "-k", self.keytab])
             except ipautil.CalledProcessError as e:
                 if e.returncode != 5:
-                    root_logger.critical("Failed to remove old key for %s"
-                                         % self.principal)
+                    logger.critical("Failed to remove old key for %s",
+                                    self.principal)
 
     def srv_rec(self, host, port, prio):
         return "%(prio)d 100 %(port)d %(host)s" % dict(host=host,prio=prio,port=port)
@@ -672,7 +674,8 @@ class ADTRUSTInstance(service.Service):
                             self.cifs_hosts.append(normalize_zone(fqdn))
 
         except Exception as e:
-            root_logger.critical("Checking replicas for cifs principals failed with error '%s'" % e)
+            logger.critical("Checking replicas for cifs principals failed "
+                            "with error '%s'", e)
 
     def __enable_compat_tree(self):
         try:
@@ -686,7 +689,8 @@ class ADTRUSTInstance(service.Service):
                     current[lookup_nsswitch_name] = [config[1]]
                     api.Backend.ldap2.update_entry(current)
         except Exception as e:
-            root_logger.critical("Enabling nsswitch support in slapi-nis failed with error '%s'" % e)
+            logger.critical("Enabling nsswitch support in slapi-nis failed "
+                            "with error '%s'", e)
 
     def __validate_server_hostname(self):
         hostname = socket.gethostname()
@@ -702,7 +706,7 @@ class ADTRUSTInstance(service.Service):
             self.start()
             services.service('winbind', api).start()
         except Exception:
-            root_logger.critical("CIFS services failed to start")
+            logger.critical("CIFS services failed to start")
 
     def __stop(self):
         self.backup_state("running", self.is_running())
@@ -734,12 +738,12 @@ class ADTRUSTInstance(service.Service):
         try:
             self.ldap_enable('ADTRUST', self.fqdn, None, self.suffix)
         except (ldap.ALREADY_EXISTS, errors.DuplicateEntry):
-            root_logger.info("ADTRUST Service startup entry already exists.")
+            logger.info("ADTRUST Service startup entry already exists.")
 
         try:
             self.ldap_enable('EXTID', self.fqdn, None, self.suffix)
         except (ldap.ALREADY_EXISTS, errors.DuplicateEntry):
-            root_logger.info("EXTID Service startup entry already exists.")
+            logger.info("EXTID Service startup entry already exists.")
 
     def __setup_sub_dict(self):
         self.sub_dict = dict(REALM = self.realm,

ipaserver/install/bindinstance.py

@@ -20,6 +20,7 @@
 from __future__ import absolute_import
 from __future__ import print_function
 
+import logging
 import tempfile
 import os
 import pwd
@@ -42,7 +43,6 @@ from ipaserver.install import sysupgrade
 from ipapython import ipautil
 from ipapython import dnsutil
 from ipapython.dnsutil import DNSName
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 from ipapython.admintool import ScriptError
 import ipalib
@@ -62,6 +62,8 @@ from ipalib.util import (validate_zonemgr_str, normalize_zonemgr,
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 NAMED_CONF = paths.NAMED_CONF
 RESOLV_CONF = paths.RESOLV_CONF
 
@@ -285,15 +287,15 @@ def read_reverse_zone(default, ip_address, allow_zone_overlap=False):
         if not zone:
             return None
         if not verify_reverse_zone(zone, ip_address):
-            root_logger.error("Invalid reverse zone %s for IP address %s"
-                              % (zone, ip_address))
+            logger.error("Invalid reverse zone %s for IP address %s",
+                         zone, ip_address)
             continue
         if not allow_zone_overlap:
             try:
                 dnsutil.check_zone_overlap(zone, raise_on_error=False)
             except ValueError as e:
-                root_logger.error("Reverse zone %s will not be used: %s"
-                                  % (zone, e))
+                logger.error("Reverse zone %s will not be used: %s",
+                             zone, e)
                 continue
         break
 
@@ -305,15 +307,14 @@ def get_auto_reverse_zones(ip_addresses):
     for ip in ip_addresses:
         if ipautil.reverse_record_exists(ip):
             # PTR exist there is no reason to create reverse zone
-            root_logger.info("Reverse record for IP address %s already "
-                             "exists" % ip)
+            logger.info("Reverse record for IP address %s already exists", ip)
             continue
         default_reverse = get_reverse_zone_default(ip)
         try:
             dnsutil.check_zone_overlap(default_reverse)
         except ValueError:
-            root_logger.info("Reverse zone %s for IP address %s already exists"
-                             % (default_reverse, ip))
+            logger.info("Reverse zone %s for IP address %s already exists",
+                        default_reverse, ip)
             continue
         auto_zones.append((ip, default_reverse))
     return auto_zones
@@ -463,7 +464,7 @@ def check_reverse_zones(ip_addresses, reverse_zones, options, unattended,
                 if unattended:
                     raise ScriptError(msg)
                 else:
-                    root_logger.warning(msg)
+                    logger.warning('%s', msg)
                 continue
         checked_reverse_zones.append(normalize_zone(rz))
 
@@ -483,11 +484,10 @@ def check_reverse_zones(ip_addresses, reverse_zones, options, unattended,
     # create reverse zone for IP addresses that does not have one
     for (ip, rz) in get_auto_reverse_zones(ips_missing_reverse):
         if options.auto_reverse:
-            root_logger.info("Reverse zone %s will be created" % rz)
+            logger.info("Reverse zone %s will be created", rz)
             checked_reverse_zones.append(rz)
         elif unattended:
-            root_logger.warning("Missing reverse record for IP address %s"
-                                % ip)
+            logger.warning("Missing reverse record for IP address %s", ip)
         else:
             if ipautil.user_input("Do you want to create reverse zone for IP "
                                   "%s" % ip, True):
@@ -497,7 +497,7 @@ def check_reverse_zones(ip_addresses, reverse_zones, options, unattended,
     return checked_reverse_zones
 
 
-def check_forwarders(dns_forwarders, logger):
+def check_forwarders(dns_forwarders):
     print("Checking DNS forwarders, please wait ...")
     forwarders_dnssec_valid = True
     for forwarder in dns_forwarders:
@@ -508,8 +508,10 @@ def check_forwarders(dns_forwarders, logger):
             forwarders_dnssec_valid = False
             logger.warning("DNS server %s does not support DNSSEC: %s",
                            forwarder, e)
-            logger.warning("Please fix forwarder configuration to enable DNSSEC support.\n"
-                "(For BIND 9 add directive \"dnssec-enable yes;\" to \"options {}\")")
+            logger.warning("Please fix forwarder configuration to enable "
+                           "DNSSEC support.\n"
+                           "(For BIND 9 add directive \"dnssec-enable yes;\" "
+                           "to \"options {}\")")
             print("DNS server %s: %s" % (forwarder, e))
             print("Please fix forwarder configuration to enable DNSSEC support.")
             print("(For BIND 9 add directive \"dnssec-enable yes;\" to \"options {}\")")
@@ -534,7 +536,7 @@ def remove_master_dns_records(hostname, realm):
     bind.remove_server_ns_records(hostname)
 
 
-def ensure_dnsserver_container_exists(ldap, api_instance, logger=None):
+def ensure_dnsserver_container_exists(ldap, api_instance, logger=logger):
     """
     Create cn=servers,cn=dns,$SUFFIX container. If logger is not None, emit a
     message that the container already exists when DuplicateEntry is raised
@@ -550,8 +552,7 @@ def ensure_dnsserver_container_exists(ldap, api_instance, logger=None):
     try:
         ldap.add_entry(entry)
     except errors.DuplicateEntry:
-        if logger is not None:
-            logger.debug('cn=servers,cn=dns container already exists')
+        logger.debug('cn=servers,cn=dns container already exists')
 
 
 class DnsBackup(object):
@@ -729,7 +730,7 @@ class BindInstance(service.Service):
                 self.backup_state("running", self.is_running())
             self.restart()
         except Exception as e:
-            root_logger.error("Named service failed to start (%s)", e)
+            logger.error("Named service failed to start (%s)", e)
             print("named service failed to start")
 
     def __enable(self):
@@ -745,7 +746,7 @@ class BindInstance(service.Service):
         except errors.DuplicateEntry:
             # service already exists (forced DNS reinstall)
             # don't crash, just report error
-            root_logger.error("DNS service already exists")
+            logger.error("DNS service already exists")
 
         # disable named, we need to run named-pkcs11 only
         if self.get_state("named-regular-running") is None:
@@ -755,12 +756,12 @@ class BindInstance(service.Service):
         try:
             self.named_regular.stop()
         except Exception as e:
-            root_logger.debug("Unable to stop named (%s)", e)
+            logger.debug("Unable to stop named (%s)", e)
 
         try:
             self.named_regular.mask()
         except Exception as e:
-            root_logger.debug("Unable to mask named (%s)", e)
+            logger.debug("Unable to mask named (%s)", e)
 
     def __setup_sub_dict(self):
         self.sub_dict = dict(
@@ -823,7 +824,7 @@ class BindInstance(service.Service):
         result = self.api.Command.dnszone_find()
         for zone in result['result']:
             zone = unicode(zone['idnsname'][0])  # we need unicode due to backup
-            root_logger.debug("adding self NS to zone %s apex", zone)
+            logger.debug("adding self NS to zone %s apex", zone)
             add_ns_rr(zone, ns_hostname, self.dns_backup, force=True,
                       api=self.api)
 
@@ -864,7 +865,7 @@ class BindInstance(service.Service):
 
             addrs = installutils.resolve_ip_addresses_nss(fqdn)
 
-            root_logger.debug("Adding DNS records for master %s" % fqdn)
+            logger.debug("Adding DNS records for master %s", fqdn)
             self.__add_master_records(fqdn, addrs)
 
     def __setup_principal(self):
@@ -898,8 +899,8 @@ class BindInstance(service.Service):
         except ldap.TYPE_OR_VALUE_EXISTS:
             pass
         except Exception as e:
-            root_logger.critical("Could not modify principal's %s entry: %s" \
-                    % (dns_principal, str(e)))
+            logger.critical("Could not modify principal's %s entry: %s",
+                            dns_principal, str(e))
             raise
 
         # bind-dyndb-ldap persistent search feature requires both size and time
@@ -911,8 +912,8 @@ class BindInstance(service.Service):
         try:
             api.Backend.ldap2.modify_s(dns_principal, mod)
         except Exception as e:
-            root_logger.critical("Could not set principal's %s LDAP limits: %s" \
-                    % (dns_principal, str(e)))
+            logger.critical("Could not set principal's %s LDAP limits: %s",
+                            dns_principal, str(e))
             raise
 
     def __setup_named_conf(self):
@@ -983,7 +984,7 @@ class BindInstance(service.Service):
             resolv_fd.write(resolv_txt)
             resolv_fd.close()
         except IOError as e:
-            root_logger.error('Could not write to resolv.conf: %s', e)
+            logger.error('Could not write to resolv.conf: %s', e)
         else:
             # python DNS might have global resolver cached in this variable
             # we have to re-initialize it because resolv.conf has changed
@@ -1017,7 +1018,7 @@ class BindInstance(service.Service):
         if not cnames:
             return
 
-        root_logger.info('Removing IPA CA CNAME records')
+        logger.info('Removing IPA CA CNAME records')
 
         # create CNAME to FQDN mapping
         cname_fqdn = {}
@@ -1043,7 +1044,7 @@ class BindInstance(service.Service):
         for cname in cnames:
             fqdn = cname_fqdn[cname]
             if fqdn not in masters:
-                root_logger.warning(
+                logger.warning(
                     "Cannot remove IPA CA CNAME please remove them manually "
                     "if necessary")
                 return
@@ -1088,18 +1089,18 @@ class BindInstance(service.Service):
 
         # remove records
         if entries:
-            root_logger.debug("Removing all NS records pointing to %s:", ns_rdata)
+            logger.debug("Removing all NS records pointing to %s:", ns_rdata)
 
         for entry in entries:
             if 'idnszone' in entry['objectclass']:
                 # zone record
                 zone = entry.single_value['idnsname']
-                root_logger.debug("zone record %s", zone)
+                logger.debug("zone record %s", zone)
                 del_ns_rr(zone, u'@', ns_rdata, api=self.api)
             else:
                 zone = entry.dn[1].value  # get zone from DN
                 record = entry.single_value['idnsname']
-                root_logger.debug("record %s in zone %s", record, zone)
+                logger.debug("record %s in zone %s", record, zone)
                 del_ns_rr(zone, record, ns_rdata, api=self.api)
 
     def update_system_records(self):
@@ -1111,18 +1112,18 @@ class BindInstance(service.Service):
                 (_loc_rec, failed_loc_rec)
             ) = system_records.update_dns_records()
         except IPADomainIsNotManagedByIPAError:
-            root_logger.error(
+            logger.error(
                 "IPA domain is not managed by IPA, please update records "
                 "manually")
         else:
             if failed_ipa_rec or failed_loc_rec:
-                root_logger.error("Update of following records failed:")
+                logger.error("Update of following records failed:")
                 for attr in (failed_ipa_rec, failed_loc_rec):
                     for rname, node, error in attr:
                         for record in IPASystemRecords.records_list_from_node(
                                 rname, node
                         ):
-                            root_logger.error("%s (%s)", record, error)
+                            logger.error("%s (%s)", record, error)
 
     def check_global_configuration(self):
         """
@@ -1173,7 +1174,7 @@ class BindInstance(service.Service):
             try:
                 self.fstore.restore_file(f)
             except ValueError as error:
-                root_logger.debug(error)
+                logger.debug('%s', error)
 
         # disabled by default, by ldap_enable()
         if enabled:

ipaserver/install/ca.py

@@ -9,6 +9,7 @@ CA installer module
 from __future__ import print_function
 
 import enum
+import logging
 import os.path
 
 import six
@@ -31,7 +32,6 @@ from ipaserver.install import installutils, certs
 from ipaserver.install.replication import replica_conn_check
 from ipalib import api, errors, x509
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 
 from . import conncheck, dogtag
 
@@ -47,6 +47,8 @@ VALID_SUBJECT_BASE_ATTRS = {
 }
 VALID_SUBJECT_ATTRS = {'cn'} | VALID_SUBJECT_BASE_ATTRS
 
+logger = logging.getLogger(__name__)
+
 external_cert_file = None
 external_ca_file = None
 
@@ -132,7 +134,7 @@ def install_check(standalone, replica_config, options):
                 principal=principal, ca_cert_file=options.ca_cert_file)
 
         if options.skip_schema_check:
-            root_logger.info("Skipping CA DS schema check")
+            logger.info("Skipping CA DS schema check")
         else:
             cainstance.replica_ca_install_check(replica_config, options.promote)
 

ipaserver/install/cainstance.py

@@ -56,7 +56,7 @@ from ipapython import ipautil
 from ipapython import ipaldap
 from ipapython.certdb import get_ca_nickname
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import standard_logging_setup, root_logger
+from ipapython.ipa_log_manager import standard_logging_setup
 from ipaserver.secrets.kem import IPAKEMKeys
 
 from ipaserver.install import certs
@@ -114,7 +114,7 @@ def get_preop_pin(instance_root, instance_name):
     try:
         f = open(filename)
     except IOError as e:
-        root_logger.error("Cannot open configuration file." + str(e))
+        logger.error("Cannot open configuration file.%s", str(e))
         raise e
     data = f.read()
     data = data.split('\n')
@@ -633,7 +633,7 @@ class CAInstance(DogtagInstance):
         try:
             backup_config()
         except Exception as e:
-            root_logger.warning("Failed to backup CS.cfg: %s", e)
+            logger.warning("Failed to backup CS.cfg: %s", e)
 
     def create_certstore_passwdfile(self):
         """
@@ -1045,7 +1045,7 @@ class CAInstance(DogtagInstance):
         try:
             certmonger.stop_tracking(certfile=paths.RA_AGENT_PEM)
         except RuntimeError as e:
-            root_logger.error(
+            logger.error(
                 "certmonger failed to stop tracking certificate: %s", e)
 
         services.knownservices.certmonger.stop()
@@ -1206,12 +1206,12 @@ class CAInstance(DogtagInstance):
         if sysupgrade.get_upgrade_state('dogtag', 'setup_lwca_key_retrieval'):
             return
 
-        root_logger.info('[Set up lightweight CA key retrieval]')
+        logger.info('[Set up lightweight CA key retrieval]')
 
         self.__setup_lightweight_ca_key_retrieval_kerberos()
         self.__setup_lightweight_ca_key_retrieval_custodia()
 
-        root_logger.info('Configuring key retriever')
+        logger.info('Configuring key retriever')
         directives = [
             ('features.authority.keyRetrieverClass',
                 'com.netscape.ca.ExternalProcessKeyRetriever'),
@@ -1227,12 +1227,12 @@ class CAInstance(DogtagInstance):
     def __setup_lightweight_ca_key_retrieval_kerberos(self):
         pent = pwd.getpwnam(self.service_user)
 
-        root_logger.info('Creating principal')
+        logger.info('Creating principal')
         installutils.kadmin_addprinc(self.principal)
         self.suffix = ipautil.realm_to_suffix(self.realm)
         self.move_service(self.principal)
 
-        root_logger.info('Retrieving keytab')
+        logger.info('Retrieving keytab')
         installutils.create_keytab(self.keytab, self.principal)
         os.chmod(self.keytab, 0o600)
         os.chown(self.keytab, pent.pw_uid, pent.pw_gid)
@@ -1240,7 +1240,7 @@ class CAInstance(DogtagInstance):
     def __setup_lightweight_ca_key_retrieval_custodia(self):
         pent = pwd.getpwnam(self.service_user)
 
-        root_logger.info('Creating Custodia keys')
+        logger.info('Creating Custodia keys')
         custodia_basedn = DN(
             ('cn', 'custodia'), ('cn', 'ipa'), ('cn', 'etc'), api.env.basedn)
         ensure_entry(
@@ -1269,7 +1269,7 @@ class CAInstance(DogtagInstance):
             add_lightweight_ca_tracking_requests(lwcas)
         except errors.NotFound:
             # shouldn't happen, but don't fail if it does
-            root_logger.warning(
+            logger.warning(
                 "Did not find any lightweight CAs; nothing to track")
 
     def __dogtag10_migration(self):
@@ -1289,7 +1289,7 @@ def replica_ca_install_check(config, promote):
     # Check if the master has the necessary schema in its CA instance
     ca_ldap_url = 'ldap://%s:%s' % (config.ca_host_name, config.ca_ds_port)
     objectclass = 'ipaObject'
-    root_logger.debug('Checking if IPA schema is present in %s', ca_ldap_url)
+    logger.debug('Checking if IPA schema is present in %s', ca_ldap_url)
     try:
         with ipaldap.LDAPClient(
                 ca_ldap_url,
@@ -1302,14 +1302,14 @@ def replica_ca_install_check(config, promote):
             result = rschema.get_obj(ldap.schema.models.ObjectClass,
                                      objectclass)
     except Exception:
-        root_logger.critical(
+        logger.critical(
             'CA DS schema check failed. Make sure the PKI service on the '
             'remote master is operational.')
         raise
     if result:
-        root_logger.debug('Check OK')
+        logger.debug('Check OK')
     else:
-        root_logger.critical(
+        logger.critical(
             'The master CA directory server does not have necessary schema. '
             'Please run copy-schema-to-ca.py on all CA masters.\n'
             'If you are certain that this is a false positive, use '
@@ -1604,7 +1604,7 @@ def import_included_profiles():
             # Create the profile, replacing any existing profile of same name
             profile_data = __get_profile_config(profile_id)
             _create_dogtag_profile(profile_id, profile_data, overwrite=True)
-            root_logger.info("Imported profile '%s'", profile_id)
+            logger.info("Imported profile '%s'", profile_id)
 
     api.Backend.ra_certprofile.override_port = None
     conn.disconnect()
@@ -1644,12 +1644,12 @@ def repair_profile_caIPAserviceCert():
     need_repair = all(l in cur_config for l in indicators)
 
     if need_repair:
-        root_logger.debug(
-            "Detected that profile '{}' has been replaced with "
-            "incorrect version; begin repair.".format(profile_id))
+        logger.debug(
+            "Detected that profile '%s' has been replaced with "
+            "incorrect version; begin repair.", profile_id)
         _create_dogtag_profile(
             profile_id, __get_profile_config(profile_id), overwrite=True)
-        root_logger.debug("Repair of profile '{}' complete.".format(profile_id))
+        logger.debug("Repair of profile '%s' complete.", profile_id)
 
     api.Backend.ra_certprofile.override_port = None
 
@@ -1678,7 +1678,7 @@ def migrate_profiles_to_ldap():
             cs_cfg, re.MULTILINE
         )
         if match is None:
-            root_logger.info("No file for profile '%s'; skipping", profile_id)
+            logger.info("No file for profile '%s'; skipping", profile_id)
             continue
         filename = match.group(1)
 
@@ -1687,7 +1687,7 @@ def migrate_profiles_to_ldap():
             cs_cfg, re.MULTILINE
         )
         if match is None:
-            root_logger.info("No class_id for profile '%s'; skipping", profile_id)
+            logger.info("No class_id for profile '%s'; skipping", profile_id)
             continue
         class_id = match.group(1)
 
@@ -1712,29 +1712,30 @@ def _create_dogtag_profile(profile_id, profile_data, overwrite):
         # import the profile
         try:
             profile_api.create_profile(profile_data)
-            root_logger.info("Profile '%s' successfully migrated to LDAP",
-                             profile_id)
+            logger.info("Profile '%s' successfully migrated to LDAP",
+                        profile_id)
         except errors.RemoteRetrieveError as e:
-            root_logger.debug("Error migrating '{}': {}".format(
-                profile_id, e))
+            logger.debug("Error migrating '%s': %s", profile_id, e)
 
             # profile already exists
             if overwrite:
                 try:
                     profile_api.disable_profile(profile_id)
                 except errors.RemoteRetrieveError:
-                    root_logger.debug(
+                    logger.debug(
                         "Failed to disable profile '%s' "
-                        "(it is probably already disabled)")
+                        "(it is probably already disabled)",
+                        profile_id)
                 profile_api.update_profile(profile_id, profile_data)
 
         # enable the profile
         try:
             profile_api.enable_profile(profile_id)
         except errors.RemoteRetrieveError:
-            root_logger.debug(
+            logger.debug(
                 "Failed to enable profile '%s' "
-                "(it is probably already enabled)")
+                "(it is probably already enabled)",
+                profile_id)
 
 
 def ensure_ipa_authority_entry():

ipaserver/install/certs.py

@@ -17,6 +17,7 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
+import logging
 import os
 import stat
 import sys
@@ -34,7 +35,6 @@ import six
 from six.moves import configparser
 
 from ipalib.install import certmonger, sysrestore
-from ipapython.ipa_log_manager import root_logger
 from ipapython import dogtag
 from ipapython import ipautil
 from ipapython.certdb import EMPTY_TRUST_FLAGS, IPA_CA_TRUST_FLAGS
@@ -45,6 +45,8 @@ from ipalib.errors import CertificateOperationError
 from ipalib.text import _
 from ipaplatform.paths import paths
 
+logger = logging.getLogger(__name__)
+
 
 def get_cert_nickname(cert):
     """
@@ -355,7 +357,8 @@ class CertDB(object):
                 self.secdir, nickname=nickname, pinfile=password_file,
                 post_command=command)
         except RuntimeError as e:
-            root_logger.error("certmonger failed starting to track certificate: %s" % str(e))
+            logger.error("certmonger failed starting to track certificate: %s",
+                         str(e))
             return
 
         cert = self.get_cert_from_db(nickname)
@@ -371,7 +374,8 @@ class CertDB(object):
         try:
             certmonger.stop_tracking(self.secdir, nickname=nickname)
         except RuntimeError as e:
-            root_logger.error("certmonger failed to stop tracking certificate: %s" % str(e))
+            logger.error("certmonger failed to stop tracking certificate: %s",
+                         str(e))
 
     def create_server_cert(self, nickname, hostname, subject=None):
         """
@@ -446,7 +450,7 @@ class CertDB(object):
             client_keyfile=paths.RA_AGENT_KEY,
             **params)
         http_status, _http_headers, http_body = result
-        root_logger.debug("CA answer: %s", http_body)
+        logger.debug("CA answer: %s", http_body)
 
         if http_status != 200:
             raise CertificateOperationError(
@@ -553,7 +557,8 @@ class CertDB(object):
 
     def trust_root_cert(self, root_nickname, trust_flags):
         if root_nickname is None:
-            root_logger.debug("Unable to identify root certificate to trust. Continuing but things are likely to fail.")
+            logger.debug("Unable to identify root certificate to trust. "
+                         "Continuing but things are likely to fail.")
             return
 
         try:

ipaserver/install/custodiainstance.py

@@ -1,12 +1,13 @@
 # Copyright (C) 2015 FreeIPa Project Contributors, see 'COPYING' for license.
 
+import logging
+
 from ipaserver.secrets.kem import IPAKEMKeys, KEMLdap
 from ipaserver.secrets.client import CustodiaClient
 from ipaplatform.paths import paths
 from ipaplatform.constants import constants
 from ipaserver.install.service import SimpleServiceInstance
 from ipapython import ipautil
-from ipapython.ipa_log_manager import root_logger
 from ipapython.certdb import NSSDatabase
 from ipaserver.install import installutils
 from ipaserver.install import ldapupdate
@@ -20,6 +21,8 @@ import tempfile
 import time
 import pwd
 
+logger = logging.getLogger(__name__)
+
 
 class CustodiaInstance(SimpleServiceInstance):
     def __init__(self, host_name=None, realm=None):
@@ -64,19 +67,19 @@ class CustodiaInstance(SimpleServiceInstance):
 
     def upgrade_instance(self):
         if not sysupgrade.get_upgrade_state("custodia", "installed"):
-            root_logger.info("Custodia service is being configured")
+            logger.info("Custodia service is being configured")
             self.create_instance()
         else:
             old_config = open(self.config_file).read()
             self.__config_file()
             new_config = open(self.config_file).read()
             if new_config != old_config:
-                root_logger.info("Restarting Custodia")
+                logger.info("Restarting Custodia")
                 self.restart()
 
         mode = os.stat(self.server_keys).st_mode
         if stat.S_IMODE(mode) != 0o600:
-            root_logger.info("Secure server.keys mode")
+            logger.info("Secure server.keys mode")
             os.chmod(self.server_keys, 0o600)
 
     def create_replica(self, master_host_name):
@@ -118,8 +121,8 @@ class CustodiaInstance(SimpleServiceInstance):
     def __wait_keys(self, host, timeout=300):
         ldap_uri = 'ldap://%s' % host
         deadline = int(time.time()) + timeout
-        root_logger.info("Waiting up to {} seconds to see our keys "
-                         "appear on host: {}".format(timeout, host))
+        logger.info("Waiting up to %s seconds to see our keys "
+                    "appear on host: %s", timeout, host)
 
         konn = KEMLdap(ldap_uri)
         saved_e = None
@@ -129,8 +132,8 @@ class CustodiaInstance(SimpleServiceInstance):
             except Exception as e:
                 # log only once for the same error
                 if not isinstance(e, type(saved_e)):
-                    root_logger.debug(
-                        "Transient error getting keys: '{err}'".format(err=e))
+                    logger.debug(
+                        "Transient error getting keys: '%s'", e)
                     saved_e = e
                 if int(time.time()) > deadline:
                     raise RuntimeError("Timed out trying to obtain keys.")

ipaserver/install/dns.py

@@ -10,6 +10,7 @@ from __future__ import absolute_import
 from __future__ import print_function
 
 import enum
+import logging
 
 # absolute import is necessary because IPA module dns clashes with python-dns
 from dns import resolver
@@ -33,7 +34,6 @@ from ipapython.dn import DN
 from ipapython.dnsutil import check_zone_overlap
 from ipapython.install import typing
 from ipapython.install.core import group, knob
-from ipapython.ipa_log_manager import root_logger
 from ipapython.admintool import ScriptError
 from ipapython.ipautil import user_input
 from ipaserver.install.installutils import get_server_ip_address
@@ -47,6 +47,8 @@ from ipaserver.install import opendnssecinstance
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 ip_addresses = []
 reverse_zones = []
 
@@ -129,9 +131,9 @@ def install_check(standalone, api, replica, options, hostname):
             dnsutil.check_zone_overlap(domain, raise_on_error=False)
         except ValueError as e:
             if options.force or options.allow_zone_overlap:
-                root_logger.warning("%s Please make sure that the domain is "
-                                    "properly delegated to this IPA server.",
-                                    e)
+                logger.warning("%s Please make sure that the domain is "
+                               "properly delegated to this IPA server.",
+                               e)
             else:
                 raise e
 
@@ -140,7 +142,7 @@ def install_check(standalone, api, replica, options, hostname):
             dnsutil.check_zone_overlap(reverse_zone)
         except ValueError as e:
             if options.force or options.allow_zone_overlap:
-                root_logger.warning(six.text_type(e))
+                logger.warning('%s', six.text_type(e))
             else:
                 raise e
 
@@ -239,7 +241,7 @@ def install_check(standalone, api, replica, options, hostname):
                             runas=constants.ODS_USER,
                             suplementary_groups=[constants.NAMED_GROUP])
             except CalledProcessError as e:
-                root_logger.debug("%s", e)
+                logger.debug("%s", e)
                 raise RuntimeError("This IPA server cannot be promoted to "
                                    "DNSSEC master role because some keys were "
                                    "not replicated from the original "
@@ -273,8 +275,8 @@ def install_check(standalone, api, replica, options, hostname):
         for ip in ip_addresses:
             if dnsutil.inside_auto_empty_zone(dnsutil.DNSName(ip.reverse_dns)):
                 options.forward_policy = 'only'
-                root_logger.debug('IP address %s belongs to a private range, '
-                                  'using forward policy only', ip)
+                logger.debug('IP address %s belongs to a private range, '
+                             'using forward policy only', ip)
                 break
 
     if options.no_forwarders:
@@ -289,13 +291,12 @@ def install_check(standalone, api, replica, options, hostname):
 
     # test DNSSEC forwarders
     if options.forwarders:
-        if (not bindinstance.check_forwarders(options.forwarders,
-                                              root_logger)
+        if (not bindinstance.check_forwarders(options.forwarders)
                 and not options.no_dnssec_validation):
             options.no_dnssec_validation = True
             print("WARNING: DNSSEC validation will be disabled")
 
-    root_logger.debug("will use DNS forwarders: %s\n", options.forwarders)
+    logger.debug("will use DNS forwarders: %s\n", options.forwarders)
 
     if not standalone:
         search_reverse_zones = False

ipaserver/install/dnskeysyncinstance.py

@@ -17,7 +17,6 @@ from ipaserver import p11helper as _ipap11helper
 from ipapython.dnsutil import DNSName
 from ipaserver.install import service
 from ipaserver.install import installutils
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 from ipapython import ipautil
 from ipaplatform.constants import constants
@@ -46,7 +45,7 @@ def remove_replica_public_keys(hostname):
 
 
 class DNSKeySyncInstance(service.Service):
-    def __init__(self, fstore=None, logger=root_logger):
+    def __init__(self, fstore=None, logger=logger):
         super(DNSKeySyncInstance, self).__init__(
             "ipa-dnskeysyncd",
             service_desc="DNS key synchronization service",

ipaserver/install/dsinstance.py

@@ -20,6 +20,7 @@
 
 from __future__ import print_function
 
+import logging
 import shutil
 import pwd
 import os
@@ -36,7 +37,6 @@ from ipalib.install import certmonger, certstore
 from ipapython.certdb import (IPA_CA_TRUST_FLAGS,
                               EXTERNAL_CA_TRUST_FLAGS,
                               TrustFlags)
-from ipapython.ipa_log_manager import root_logger
 from ipapython import ipautil, ipaldap
 from ipapython import dogtag
 from ipaserver.install import service
@@ -55,6 +55,8 @@ from ipapython.admintool import ScriptError
 from ipaplatform import services
 from ipaplatform.paths import paths
 
+logger = logging.getLogger(__name__)
+
 DS_USER = platformconstants.DS_USER
 DS_GROUP = platformconstants.DS_GROUP
 
@@ -104,16 +106,16 @@ def remove_ds_instance(serverid, force=False):
     args = [paths.REMOVE_DS_PL, '-i', instance_name]
     if force:
         args.append('-f')
-        root_logger.debug("Forcing instance removal")
+        logger.debug("Forcing instance removal")
 
     try:
         ipautil.run(args)
     except ipautil.CalledProcessError:
         if force:
-            root_logger.error("Instance removal failed.")
+            logger.error("Instance removal failed.")
             raise
-        root_logger.debug("'%s' failed. "
-                          "Attempting to force removal" % paths.REMOVE_DS_PL)
+        logger.debug("'%s' failed. "
+                     "Attempting to force removal", paths.REMOVE_DS_PL)
         remove_ds_instance(serverid, force=True)
 
 
@@ -452,11 +454,11 @@ class DsInstance(service.Service):
                 try:
                     api.Backend.ldap2.delete_entry(r)
                 except Exception as e:
-                    root_logger.critical(
+                    logger.critical(
                         "Error during SASL mapping removal: %s", e)
                     raise
         except Exception as e:
-            root_logger.critical("Error while enumerating SASL mappings %s", e)
+            logger.critical("Error while enumerating SASL mappings %s", e)
             raise
 
         entry = api.Backend.ldap2.make_entry(
@@ -530,7 +532,7 @@ class DsInstance(service.Service):
 
         self.sub_dict['BASEDC'] = self.realm.split('.')[0].lower()
         base_txt = ipautil.template_str(BASE_TEMPLATE, self.sub_dict)
-        root_logger.debug(base_txt)
+        logger.debug("%s", base_txt)
 
         target_fname = paths.DIRSRV_BOOT_LDIF
         base_fd = open(target_fname, "w")
@@ -542,19 +544,19 @@ class DsInstance(service.Service):
         os.chown(target_fname, pent.pw_uid, pent.pw_gid)
 
         inf_txt = ipautil.template_str(INF_TEMPLATE, self.sub_dict)
-        root_logger.debug("writing inf template")
+        logger.debug("writing inf template")
         inf_fd = ipautil.write_tmp_file(inf_txt)
         inf_txt = re.sub(r"RootDNPwd=.*\n", "", inf_txt)
-        root_logger.debug(inf_txt)
+        logger.debug("%s", inf_txt)
         args = [
             paths.SETUP_DS_PL, "--silent",
             "--logfile", "-",
             "-f", inf_fd.name,
         ]
-        root_logger.debug("calling setup-ds.pl")
+        logger.debug("calling setup-ds.pl")
         try:
             ipautil.run(args)
-            root_logger.debug("completed creating DS instance")
+            logger.debug("completed creating DS instance")
         except ipautil.CalledProcessError as e:
             raise RuntimeError("failed to create DS instance %s" % e)
 
@@ -597,7 +599,7 @@ class DsInstance(service.Service):
         try:
             os.remove(temp_filename)
         except OSError as e:
-            root_logger.debug("Failed to clean temporary file: %s" % e)
+            logger.debug("Failed to clean temporary file: %s", e)
 
     def __add_default_schemas(self):
         pent = pwd.getpwnam(DS_USER)
@@ -638,13 +640,15 @@ class DsInstance(service.Service):
         try:
             super(DsInstance, self).restart(instance)
             if not is_ds_running(instance):
-                root_logger.critical("Failed to restart the directory server. See the installation log for details.")
+                logger.critical("Failed to restart the directory server. "
+                                "See the installation log for details.")
                 raise ScriptError()
         except SystemExit as e:
             raise e
         except Exception as e:
             # TODO: roll back here?
-            root_logger.critical("Failed to restart the directory server (%s). See the installation log for details." % e)
+            logger.critical("Failed to restart the directory server (%s). "
+                            "See the installation log for details.", e)
         api.Backend.ldap2.connect()
 
     def __start_instance(self):
@@ -671,7 +675,7 @@ class DsInstance(service.Service):
         # Note, keep dn in sync with dn in install/share/memberof-task.ldif
         dn = DN(('cn', 'IPA install %s' % self.sub_dict["TIME"]), ('cn', 'memberof task'),
                 ('cn', 'tasks'), ('cn', 'config'))
-        root_logger.debug("Waiting for memberof task to complete.")
+        logger.debug("Waiting for memberof task to complete.")
         ldap_uri = ipaldap.get_ldap_uri(self.fqdn)
         conn = ipaldap.LDAPClient(ldap_uri)
         if self.dm_password:
@@ -955,7 +959,7 @@ class DsInstance(service.Service):
         self._ldap_mod("default-hbac.ldif", self.sub_dict)
 
     def change_admin_password(self, password):
-        root_logger.debug("Changing admin password")
+        logger.debug("Changing admin password")
 
         dir_ipa = paths.VAR_LIB_IPA
         with tempfile.NamedTemporaryFile("w", dir=dir_ipa) as dmpwdfile, \
@@ -974,10 +978,10 @@ class DsInstance(service.Service):
                 env = {'LDAPTLS_CACERTDIR': os.path.dirname(paths.IPA_CA_CRT),
                        'LDAPTLS_CACERT': paths.IPA_CA_CRT}
                 ipautil.run(args, env=env)
-                root_logger.debug("ldappasswd done")
+                logger.debug("ldappasswd done")
             except ipautil.CalledProcessError as e:
                 print("Unable to set admin password", e)
-                root_logger.debug("Unable to set admin password %s" % e)
+                logger.debug("Unable to set admin password %s", e)
 
     def uninstall(self):
         if self.is_configured():
@@ -992,7 +996,7 @@ class DsInstance(service.Service):
             self.fstore.restore_file(paths.LIMITS_CONF)
             self.fstore.restore_file(paths.SYSCONFIG_DIRSRV)
         except ValueError as error:
-            root_logger.debug(error)
+            logger.debug("%s", error)
 
         # disabled during IPA installation
         if enabled:
@@ -1001,14 +1005,14 @@ class DsInstance(service.Service):
         serverid = self.restore_state("serverid")
         if serverid is not None:
             self.stop_tracking_certificates(serverid)
-            root_logger.debug("Removing DS instance %s" % serverid)
+            logger.debug("Removing DS instance %s", serverid)
             try:
                 remove_ds_instance(serverid)
                 installutils.remove_keytab(paths.DS_KEYTAB)
                 installutils.remove_ccache(run_as=DS_USER)
             except ipautil.CalledProcessError:
-                root_logger.error("Failed to remove DS instance. You may "
-                                  "need to remove instance data manually")
+                logger.error("Failed to remove DS instance. You may "
+                             "need to remove instance data manually")
 
         # Just eat this state
         self.restore_state("user_exists")
@@ -1025,7 +1029,7 @@ class DsInstance(service.Service):
             try:
                 services.knownservices.dirsrv.restart(ds_instance, wait=False)
             except Exception as e:
-                root_logger.error(
+                logger.error(
                     'Unable to restart DS instance %s: %s', ds_instance, e)
 
     def stop_tracking_certificates(self, serverid=None):
@@ -1059,12 +1063,12 @@ class DsInstance(service.Service):
         # first make sure we have a valid cacert_fname
         try:
             if not os.access(cacert_fname, os.R_OK):
-                root_logger.critical("The given CA cert file named [%s] could not be read" %
-                                             cacert_fname)
+                logger.critical("The given CA cert file named [%s] could not "
+                                "be read", cacert_fname)
                 return False
         except OSError as e:
-            root_logger.critical("The given CA cert file named [%s] could not be read: %s" %
-                                         (cacert_fname, str(e)))
+            logger.critical("The given CA cert file named [%s] could not "
+                            "be read: %s", cacert_fname, str(e))
             return False
         # ok - ca cert file can be read
         # shutdown the server
@@ -1085,8 +1089,8 @@ class DsInstance(service.Service):
         try:
             certdb.load_cacert(cacert_fname, EXTERNAL_CA_TRUST_FLAGS)
         except ipautil.CalledProcessError as e:
-            root_logger.critical("Error importing CA cert file named [%s]: %s" %
-                                         (cacert_fname, str(e)))
+            logger.critical("Error importing CA cert file named [%s]: %s",
+                            cacert_fname, str(e))
             status = False
         # restart the directory server
         self.start()
@@ -1150,7 +1154,7 @@ class DsInstance(service.Service):
         except errors.NotFound:
             self._ldap_mod('ipa-sidgen-conf.ldif', dict(SUFFIX=suffix))
         else:
-            root_logger.debug("sidgen plugin is already configured")
+            logger.debug("sidgen plugin is already configured")
 
     def _add_extdom_plugin(self):
         """
@@ -1168,7 +1172,7 @@ class DsInstance(service.Service):
         except errors.NotFound:
             self._ldap_mod('ipa-extdom-extop-conf.ldif', dict(SUFFIX=suffix))
         else:
-            root_logger.debug("extdom plugin is already configured")
+            logger.debug("extdom plugin is already configured")
 
     def find_subject_base(self):
         """
@@ -1181,20 +1185,20 @@ class DsInstance(service.Service):
         is configured, the api is initialized elsewhere and
         that a ticket already have been acquired.
         """
-        root_logger.debug(
+        logger.debug(
             'Trying to find certificate subject base in sysupgrade')
         subject_base = sysupgrade.get_upgrade_state(
             'certmap.conf', 'subject_base')
 
         if subject_base:
-            root_logger.debug(
+            logger.debug(
                 'Found certificate subject base in sysupgrade: %s',
                 subject_base)
             return subject_base
 
-        root_logger.debug(
+        logger.debug(
             'Unable to find certificate subject base in sysupgrade')
-        root_logger.debug(
+        logger.debug(
             'Trying to find certificate subject base in DS')
 
         ds_is_running = is_ds_running()
@@ -1203,25 +1207,24 @@ class DsInstance(service.Service):
                 self.start()
                 ds_is_running = True
             except ipautil.CalledProcessError as e:
-                root_logger.error('Cannot start DS to find certificate '
-                                  'subject base: %s', e)
+                logger.error('Cannot start DS to find certificate '
+                             'subject base: %s', e)
 
         if ds_is_running:
             try:
                 ret = api.Command['config_show']()
                 subject_base = str(
                     ret['result']['ipacertificatesubjectbase'][0])
-                root_logger.debug(
+                logger.debug(
                     'Found certificate subject base in DS: %s', subject_base)
             except errors.PublicError as e:
-                root_logger.error('Cannot connect to DS to find certificate '
-                                  'subject base: %s', e)
+                logger.error('Cannot connect to DS to find certificate '
+                             'subject base: %s', e)
 
         if subject_base:
             return subject_base
 
-        root_logger.debug('Unable to find certificate subject base in '
-                          'certmap.conf')
+        logger.debug('Unable to find certificate subject base in certmap.conf')
         return None
 
     def __set_domain_level(self):

ipaserver/install/httpinstance.py

@@ -19,6 +19,7 @@
 
 from __future__ import print_function
 
+import logging
 import os
 import os.path
 import pwd
@@ -42,7 +43,6 @@ from ipaserver.install import installutils
 from ipapython import dogtag
 from ipapython import ipautil
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 import ipapython.errors
 from ipaserver.install import sysupgrade
 from ipalib import api
@@ -51,6 +51,8 @@ from ipaplatform.tasks import tasks
 from ipaplatform.paths import paths
 from ipaplatform import services
 
+logger = logging.getLogger(__name__)
+
 HTTPD_USER = constants.HTTPD_USER
 KDCPROXY_USER = constants.KDCPROXY_USER
 
@@ -369,7 +371,7 @@ class HTTPInstance(service.Service):
                                  capture_output=True)
         except ipautil.CalledProcessError as e:
             if e.returncode == 29:  # ERROR: Module not found in database.
-                root_logger.debug(
+                logger.debug(
                     'Module %s not available, treating as disabled', name)
                 return False
             raise
@@ -495,7 +497,7 @@ class HTTPInstance(service.Service):
             oddjobd.enable()
             oddjobd.start()
         except Exception as e:
-            root_logger.critical("Unable to start oddjobd: {0}".format(str(e)))
+            logger.critical("Unable to start oddjobd: %s", str(e))
 
     def update_httpd_service_ipa_conf(self):
         tasks.configure_httpd_service_ipa_conf()
@@ -545,7 +547,7 @@ class HTTPInstance(service.Service):
             try:
                 self.fstore.restore_file(f)
             except ValueError as error:
-                root_logger.debug(error)
+                logger.debug("%s", error)
 
         installutils.remove_keytab(self.keytab)
         installutils.remove_file(paths.HTTP_CCACHE)

ipaserver/install/installutils.py

@@ -21,6 +21,7 @@ from __future__ import absolute_import
 from __future__ import print_function
 
 import errno
+import logging
 import socket
 import getpass
 import gssapi
@@ -55,7 +56,6 @@ import ipaplatform
 from ipapython import ipautil, admintool, version
 from ipapython.admintool import ScriptError
 from ipapython.certdb import EXTERNAL_CA_TRUST_FLAGS
-from ipapython.ipa_log_manager import root_logger
 from ipapython.ipaldap import DIRMAN_DN, LDAPClient
 from ipalib.util import validate_hostname
 from ipalib import api, errors, x509
@@ -68,6 +68,8 @@ from ipaplatform.tasks import tasks
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 # Used to determine install status
 IPA_MODULES = [
     'httpd', 'kadmin', 'dirsrv', 'pki-tomcatd', 'install', 'krb5kdc', 'ntpd',
@@ -166,16 +168,17 @@ def verify_fqdn(host_name, no_host_dns=False, local_hostname=True):
 
     if local_hostname:
         try:
-            root_logger.debug('Check if %s is a primary hostname for localhost', host_name)
+            logger.debug('Check if %s is a primary hostname for localhost',
+                         host_name)
             ex_name = socket.gethostbyaddr(host_name)
-            root_logger.debug('Primary hostname for localhost: %s', ex_name[0])
+            logger.debug('Primary hostname for localhost: %s', ex_name[0])
             if host_name != ex_name[0]:
                 raise HostLookupError("The host name %s does not match the primary host name %s. "\
                         "Please check /etc/hosts or DNS name resolution" % (host_name, ex_name[0]))
         except socket.gaierror:
             pass
         except socket.error as e:
-            root_logger.debug(
+            logger.debug(
                 'socket.gethostbyaddr() error: %d: %s',
                 e.errno, e.strerror)  # pylint: disable=no-member
 
@@ -184,10 +187,10 @@ def verify_fqdn(host_name, no_host_dns=False, local_hostname=True):
         return
 
     try:
-        root_logger.debug('Search DNS for %s', host_name)
+        logger.debug('Search DNS for %s', host_name)
         hostaddr = socket.getaddrinfo(host_name, None)
     except Exception as e:
-        root_logger.debug('Search failed: %s', e)
+        logger.debug('Search failed: %s', e)
         raise HostForwardLookupError("Unable to resolve host name, check /etc/hosts or DNS name resolution")
 
     if len(hostaddr) == 0:
@@ -195,7 +198,7 @@ def verify_fqdn(host_name, no_host_dns=False, local_hostname=True):
 
     # Verify this is NOT a CNAME
     try:
-        root_logger.debug('Check if %s is not a CNAME', host_name)
+        logger.debug('Check if %s is not a CNAME', host_name)
         resolver.query(host_name, rdatatype.CNAME)
         raise HostReverseLookupError("The IPA Server Hostname cannot be a CNAME, only A and AAAA names are allowed.")
     except DNSException:
@@ -210,17 +213,17 @@ def verify_fqdn(host_name, no_host_dns=False, local_hostname=True):
         if address == '127.0.0.1' or address == '::1':
             raise HostForwardLookupError("The IPA Server hostname must not resolve to localhost (%s). A routable IP address must be used. Check /etc/hosts to see if %s is an alias for %s" % (address, host_name, address))
         try:
-            root_logger.debug('Check reverse address of %s', address)
+            logger.debug('Check reverse address of %s', address)
             revname = socket.gethostbyaddr(address)[0]
         except Exception as e:
-            root_logger.debug('Check failed: %s', e)
-            root_logger.error(
+            logger.debug('Check failed: %s', e)
+            logger.error(
                 "Unable to resolve the IP address %s to a host name, "
                 "check /etc/hosts and DNS name resolution", address)
         else:
-            root_logger.debug('Found reverse name: %s', revname)
+            logger.debug('Found reverse name: %s', revname)
             if revname != host_name:
-                root_logger.error(
+                logger.error(
                     "The host name %s does not match the value %s obtained "
                     "by reverse lookup on IP address %s", host_name, revname,
                     address)
@@ -523,7 +526,7 @@ def create_keytab(path, principal):
         if ipautil.file_exists(path):
             os.remove(path)
     except os.error:
-        root_logger.critical("Failed to remove %s." % path)
+        logger.critical("Failed to remove %s.", path)
 
     return kadmin("ktadd -k " + path + " " + principal)
 
@@ -540,8 +543,7 @@ def resolve_ip_addresses_nss(fqdn):
                                        socket.AF_UNSPEC, socket.SOCK_STREAM)
     except socket.error as ex:
         if ex.errno == socket.EAI_NODATA or ex.errno == socket.EAI_NONAME:
-            root_logger.debug('Name %s does not have any address: %s',
-                              fqdn, ex)
+            logger.debug('Name %s does not have any address: %s', fqdn, ex)
             return set()
         else:
             raise
@@ -554,11 +556,11 @@ def resolve_ip_addresses_nss(fqdn):
         except ValueError as ex:
             # getaddinfo may return link-local address other similar oddities
             # which are not accepted by CheckedIPAddress - skip these
-            root_logger.warning('Name %s resolved to an unacceptable IP '
-                                'address %s: %s', fqdn, ai[4][0], ex)
+            logger.warning('Name %s resolved to an unacceptable IP '
+                           'address %s: %s', fqdn, ai[4][0], ex)
         else:
             ip_addresses.add(ip)
-    root_logger.debug('Name %s resolved to %s', fqdn, ip_addresses)
+    logger.debug('Name %s resolved to %s', fqdn, ip_addresses)
     return ip_addresses
 
 def get_host_name(no_host_dns):
@@ -592,7 +594,8 @@ def get_server_ip_address(host_name, unattended, setup_dns, ip_addresses):
             try:
                 ips.append(ipautil.CheckedIPAddress(ha))
             except ValueError as e:
-                root_logger.warning("Invalid IP address %s for %s: %s", ha, host_name, unicode(e))
+                logger.warning("Invalid IP address %s for %s: %s",
+                               ha, host_name, unicode(e))
 
     if not ips and not ip_addresses:
         if not unattended:
@@ -773,8 +776,8 @@ def read_replica_info_dogtag_port(config_dir):
             try:
                 dogtag_master_ds_port = int(fd.read())
             except (ValueError, IOError) as e:
-                root_logger.debug('Cannot parse dogtag DS port: %s', e)
-                root_logger.debug('Default to %d', default_port)
+                logger.debug('Cannot parse dogtag DS port: %s', e)
+                logger.debug('Default to %d', default_port)
                 dogtag_master_ds_port = default_port
 
     return dogtag_master_ds_port
@@ -785,31 +788,33 @@ def create_replica_config(dirman_password, filename, options):
     try:
         top_dir, dir = expand_replica_info(filename, dirman_password)
     except Exception as e:
-        root_logger.error("Failed to decrypt or open the replica file.")
+        logger.error("Failed to decrypt or open the replica file.")
         raise ScriptError(
             "ERROR: Failed to decrypt or open the replica file.\n"
             "Verify you entered the correct Directory Manager password.")
     config = ReplicaConfig(top_dir)
     read_replica_info(dir, config)
-    root_logger.debug(
-        'Installing replica file with version %d (0 means no version in prepared file).',
+    logger.debug(
+        'Installing replica file with version %d '
+        '(0 means no version in prepared file).',
         config.version)
     if config.version and config.version > version.NUM_VERSION:
-        root_logger.error(
-            'A replica file from a newer release (%d) cannot be installed on an older version (%d)',
+        logger.error(
+            'A replica file from a newer release (%d) cannot be installed on '
+            'an older version (%d)',
             config.version, version.NUM_VERSION)
         raise ScriptError()
     config.dirman_password = dirman_password
     try:
         host = get_host_name(options.no_host_dns)
     except BadHostError as e:
-        root_logger.error(str(e))
+        logger.error("%s", str(e))
         raise ScriptError()
     if config.host_name != host:
         try:
             print("This replica was created for '%s' but this machine is named '%s'" % (config.host_name, host))
             if not ipautil.user_input("This may cause problems. Continue?", False):
-                root_logger.debug(
+                logger.debug(
                     "Replica was created for %s but machine is named %s  "
                     "User chose to exit",
                     config.host_name, host)
@@ -817,7 +822,7 @@ def create_replica_config(dirman_password, filename, options):
             config.host_name = host
             print("")
         except KeyboardInterrupt:
-            root_logger.debug("Keyboard Interrupt")
+            logger.debug("Keyboard Interrupt")
             raise ScriptError(rval=0)
     config.dir = dir
     config.ca_ds_port = read_replica_info_dogtag_port(config.dir)
@@ -849,7 +854,7 @@ def remove_file(filename):
         if os.path.lexists(filename):
             os.unlink(filename)
     except Exception as e:
-        root_logger.error('Error removing %s: %s' % (filename, str(e)))
+        logger.error('Error removing %s: %s', filename, str(e))
 
 
 def rmtree(path):
@@ -860,7 +865,7 @@ def rmtree(path):
         if os.path.exists(path):
             shutil.rmtree(path)
     except Exception as e:
-        root_logger.error('Error removing %s: %s' % (path, str(e)))
+        logger.error('Error removing %s: %s', path, str(e))
 
 
 def is_ipa_configured():
@@ -875,16 +880,16 @@ def is_ipa_configured():
 
     for module in IPA_MODULES:
         if sstore.has_state(module):
-            root_logger.debug('%s is configured' % module)
+            logger.debug('%s is configured', module)
             installed = True
         else:
-            root_logger.debug('%s is not configured' % module)
+            logger.debug('%s is not configured', module)
 
     if fstore.has_files():
-        root_logger.debug('filestore has files')
+        logger.debug('filestore has files')
         installed = True
     else:
-        root_logger.debug('filestore is tracking no files')
+        logger.debug('filestore is tracking no files')
 
     return installed
 
@@ -905,7 +910,7 @@ def run_script(main_function, operation_name, log_file_name=None,
     :param fail_message: Optional message displayed on failure
     """
 
-    root_logger.info('Starting script: %s', operation_name)
+    logger.info('Starting script: %s', operation_name)
     try:
         try:
             return_value = main_function()
@@ -915,26 +920,24 @@ def run_script(main_function, operation_name, log_file_name=None,
                 (e.code is None or e.code == 0)  # pylint: disable=no-member
             ):
                 # Not an error after all
-                root_logger.info('The %s command was successful',
-                    operation_name)
+                logger.info('The %s command was successful', operation_name)
             else:
                 # Log at the DEBUG level, which is not output to the console
                 # (unless in debug/verbose mode), but is written to a logfile
                 # if one is open.
                 tb = sys.exc_info()[2]
-                root_logger.debug('\n'.join(traceback.format_tb(tb)))
-                root_logger.debug('The %s command failed, exception: %s: %s',
-                                  operation_name, type(e).__name__, e)
+                logger.debug("%s", '\n'.join(traceback.format_tb(tb)))
+                logger.debug('The %s command failed, exception: %s: %s',
+                             operation_name, type(e).__name__, e)
                 if fail_message and not isinstance(e, SystemExit):
                     print(fail_message)
                 raise
         else:
             if return_value:
-                root_logger.info('The %s command failed, return value %s',
-                    operation_name, return_value)
+                logger.info('The %s command failed, return value %s',
+                            operation_name, return_value)
             else:
-                root_logger.info('The %s command was successful',
-                    operation_name)
+                logger.info('The %s command was successful', operation_name)
             sys.exit(return_value)
 
     except BaseException as error:
@@ -1116,25 +1119,25 @@ def stopped_service(service, instance_name=""):
     else:
         log_instance_name = ""
 
-    root_logger.debug('Ensuring that service %s%s is not running while '
-                      'the next set of commands is being executed.', service,
-                      log_instance_name)
+    logger.debug('Ensuring that service %s%s is not running while '
+                 'the next set of commands is being executed.', service,
+                 log_instance_name)
 
     service_obj = services.service(service, api)
 
     # Figure out if the service is running, if not, yield
     if not service_obj.is_running(instance_name):
-        root_logger.debug('Service %s%s is not running, continue.', service,
-                          log_instance_name)
+        logger.debug('Service %s%s is not running, continue.', service,
+                     log_instance_name)
         yield
     else:
         # Stop the service, do the required stuff and start it again
-        root_logger.debug('Stopping %s%s.', service, log_instance_name)
+        logger.debug('Stopping %s%s.', service, log_instance_name)
         service_obj.stop(instance_name)
         try:
             yield
         finally:
-            root_logger.debug('Starting %s%s.', service, log_instance_name)
+            logger.debug('Starting %s%s.', service, log_instance_name)
             service_obj.start(instance_name)
 
 
@@ -1148,12 +1151,12 @@ def check_entropy():
                 emsg = 'WARNING: Your system is running out of entropy, ' \
                         'you may experience long delays'
                 service.print_msg(emsg)
-                root_logger.debug(emsg)
+                logger.debug("%s", emsg)
     except IOError as e:
-        root_logger.debug(
+        logger.debug(
             "Could not open %s: %s", paths.ENTROPY_AVAIL, e)
     except ValueError as e:
-        root_logger.debug("Invalid value in %s %s", paths.ENTROPY_AVAIL, e)
+        logger.debug("Invalid value in %s %s", paths.ENTROPY_AVAIL, e)
 
 
 def load_external_cert(files, ca_subject):
@@ -1285,13 +1288,13 @@ def check_creds(options, realm_name):
     # Check if ccache is available
     default_cred = None
     try:
-        root_logger.debug('KRB5CCNAME set to %s' %
-                          os.environ.get('KRB5CCNAME', None))
+        logger.debug('KRB5CCNAME set to %s',
+                     os.environ.get('KRB5CCNAME', None))
         # get default creds, will raise if none found
         default_cred = gssapi.creds.Credentials()
         principal = str(default_cred.name)
     except gssapi.raw.misc.GSSError as e:
-        root_logger.debug('Failed to find default ccache: %s' % e)
+        logger.debug('Failed to find default ccache: %s', e)
         principal = None
 
     # Check if the principal matches the requested one (if any)
@@ -1300,9 +1303,9 @@ def check_creds(options, realm_name):
         if op.find('@') == -1:
             op = '%s@%s' % (op, realm_name)
         if principal != op:
-            root_logger.debug('Specified principal %s does not match '
-                              'available credentials (%s)' %
-                              (options.principal, principal))
+            logger.debug('Specified principal %s does not match '
+                         'available credentials (%s)',
+                         options.principal, principal)
             principal = None
 
     if principal is None:
@@ -1326,16 +1329,16 @@ def check_creds(options, realm_name):
                 except EOFError:
                     stdin = None
                 if not stdin:
-                    root_logger.error(
+                    logger.error(
                         "Password must be provided for %s.", principal)
                     raise ScriptError("Missing password for %s" % principal)
             else:
                 if sys.stdin.isatty():
-                    root_logger.error("Password must be provided in " +
-                                      "non-interactive mode.")
-                    root_logger.info("This can be done via " +
-                                     "echo password | ipa-client-install " +
-                                     "... or with the -w option.")
+                    logger.error("Password must be provided in "
+                                 "non-interactive mode.")
+                    logger.info("This can be done via "
+                                "echo password | ipa-client-install "
+                                "... or with the -w option.")
                     raise ScriptError("Missing password for %s" % principal)
                 else:
                     stdin = sys.stdin.readline()
@@ -1346,7 +1349,7 @@ def check_creds(options, realm_name):
         try:
             kinit_password(principal, stdin, ccache_name)
         except RuntimeError as e:
-            root_logger.error("Kerberos authentication failed: %s" % e)
+            logger.error("Kerberos authentication failed: %s", e)
             raise ScriptError("Invalid credentials: %s" % e)
 
         os.environ['KRB5CCNAME'] = ccache_name
@@ -1450,9 +1453,9 @@ class ModifyLDIF(ldif.LDIFParser):
                         raise ValueError("add: {dn}, {attr}: values are "
                                          "missing".format(dn=dn, attr=attr))
             else:
-                root_logger.error("Ignoring entry: %s : only modifications "
-                                  "are allowed (missing \"changetype: "
-                                  "modify\")", dn)
+                logger.error("Ignoring entry: %s : only modifications "
+                             "are allowed (missing \"changetype: "
+                             "modify\")", dn)
 
     def handle(self, dn, entry):
         if dn in self.modifications:
@@ -1485,7 +1488,7 @@ class ModifyLDIF(ldif.LDIFParser):
         # check if there are any remaining modifications
         remaining_changes = set(self.modifications.keys()) - self.dn_updated
         for dn in remaining_changes:
-            root_logger.error(
+            logger.error(
                 "DN: %s does not exists or haven't been updated", dn)
 
 
@@ -1496,13 +1499,13 @@ def remove_keytab(keytab_path):
     :param keytab_path: path to the keytab file
     """
     try:
-        root_logger.debug("Removing service keytab: {}".format(keytab_path))
+        logger.debug("Removing service keytab: %s", keytab_path)
         os.remove(keytab_path)
     except OSError as e:
         if e.errno != errno.ENOENT:
-            root_logger.warning("Failed to remove Kerberos keytab '{}': "
-                                "{}".format(keytab_path, e))
-            root_logger.warning("You may have to remove it manually")
+            logger.warning("Failed to remove Kerberos keytab '%s': %s",
+                           keytab_path, e)
+            logger.warning("You may have to remove it manually")
 
 
 def remove_ccache(ccache_path=None, run_as=None):
@@ -1512,17 +1515,17 @@ def remove_ccache(ccache_path=None, run_as=None):
     :param ccache_path: path to the ccache file
     :param run_as: run kdestroy as this user
     """
-    root_logger.debug("Removing service credentials cache")
+    logger.debug("Removing service credentials cache")
     kdestroy_cmd = [paths.KDESTROY]
     if ccache_path is not None:
-        root_logger.debug("Ccache path: '{}'".format(ccache_path))
+        logger.debug("Ccache path: '%s'", ccache_path)
         kdestroy_cmd.extend(['-c', ccache_path])
 
     try:
         ipautil.run(kdestroy_cmd, runas=run_as, env={})
     except ipautil.CalledProcessError as e:
-        root_logger.warning(
-            "Failed to clear Kerberos credentials cache: {}".format(e))
+        logger.warning(
+            "Failed to clear Kerberos credentials cache: %s", e)
 
 
 def restart_dirsrv(instance_name="", capture_output=True):

ipaserver/install/krbinstance.py

@@ -20,6 +20,7 @@
 from __future__ import absolute_import
 from __future__ import print_function
 
+import logging
 import os
 import pwd
 import socket
@@ -37,7 +38,6 @@ from ipapython import kernel_keyring
 from ipalib import api, errors
 from ipalib.constants import ANON_USER
 from ipalib.install import certmonger
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 from ipapython.dogtag import KDC_PROFILE
 
@@ -49,6 +49,8 @@ from ipaplatform.constants import constants
 from ipaplatform.tasks import tasks
 from ipaplatform.paths import paths
 
+logger = logging.getLogger(__name__)
+
 PKINIT_ENABLED = 'pkinitEnabled'
 
 
@@ -246,7 +248,7 @@ class KrbInstance(service.Service):
         try:
             self.start()
         except Exception:
-            root_logger.critical("krb5kdc service failed to start")
+            logger.critical("krb5kdc service failed to start")
 
     def __setup_sub_dict(self):
         if os.path.exists(paths.COMMON_KRB5_CONF_DIR):
@@ -277,11 +279,11 @@ class KrbInstance(service.Service):
         domain = dns.name.from_text(self.domain)
         fqdn = dns.name.from_text(self.fqdn)
         if not fqdn.is_subdomain(domain):
-            root_logger.debug("IPA FQDN '%s' is not located in default domain '%s'",
-                    fqdn, domain)
+            logger.debug("IPA FQDN '%s' is not located in default domain '%s'",
+                         fqdn, domain)
             server_domain = fqdn.parent().to_unicode(omit_final_dot=True)
-            root_logger.debug("Domain '%s' needs additional mapping in krb5.conf",
-                server_domain)
+            logger.debug("Domain '%s' needs additional mapping in krb5.conf",
+                         server_domain)
             dr_map = " .%(domain)s = %(realm)s\n %(domain)s = %(realm)s\n" \
                         % dict(domain=server_domain, realm=self.realm)
         else:
@@ -290,11 +292,11 @@ class KrbInstance(service.Service):
 
         # Configure KEYRING CCACHE if supported
         if kernel_keyring.is_persistent_keyring_supported():
-            root_logger.debug("Enabling persistent keyring CCACHE")
+            logger.debug("Enabling persistent keyring CCACHE")
             self.sub_dict['OTHER_LIBDEFAULTS'] = \
                 " default_ccache_name = KEYRING:persistent:%{uid}\n"
         else:
-            root_logger.debug("Persistent keyring CCACHE is not enabled")
+            logger.debug("Persistent keyring CCACHE is not enabled")
             self.sub_dict['OTHER_LIBDEFAULTS'] = ''
 
     def __add_krb_container(self):
@@ -444,7 +446,7 @@ class KrbInstance(service.Service):
             # if the certificate is already tracked, ignore the error
             name = e.get_dbus_name()
             if name != 'org.fedorahosted.certmonger.duplicate':
-                root_logger.error("Failed to initiate the request: %s", e)
+                logger.error("Failed to initiate the request: %s", e)
             return
         finally:
             if prev_helper is not None:
@@ -500,8 +502,8 @@ class KrbInstance(service.Service):
             self._install_pkinit_ca_bundle()
             self.pkinit_enable()
         except RuntimeError as e:
-            root_logger.error("PKINIT certificate request failed: %s", e)
-            root_logger.error("Failed to configure PKINIT")
+            logger.error("PKINIT certificate request failed: %s", e)
+            logger.error("Failed to configure PKINIT")
             self.stop_tracking_certs()
             self.issue_selfsigned_pkinit_certs()
 
@@ -542,7 +544,7 @@ class KrbInstance(service.Service):
         try:
             self.restart()
         except Exception:
-            root_logger.critical("krb5kdc service failed to restart")
+            logger.critical("krb5kdc service failed to restart")
             raise
 
     def get_anonymous_principal_name(self):
@@ -590,7 +592,7 @@ class KrbInstance(service.Service):
             try:
                 self.fstore.restore_file(f)
             except ValueError as error:
-                root_logger.debug(error)
+                logger.debug("%s", error)
 
         # disabled by default, by ldap_enable()
         if enabled:

ipaserver/install/ntpinstance.py

@@ -18,11 +18,14 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
+import logging
+
 from ipaserver.install import service
 from ipaserver.install import sysupgrade
 from ipaplatform.constants import constants
 from ipaplatform.paths import paths
-from ipapython.ipa_log_manager import root_logger
+
+logger = logging.getLogger(__name__)
 
 NTPD_OPTS_VAR = constants.NTPD_OPTS_VAR
 NTPD_OPTS_QUOTE = constants.NTPD_OPTS_QUOTE
@@ -160,7 +163,7 @@ class NTPInstance(service.Service):
         try:
             self.fstore.restore_file(paths.NTP_CONF)
         except ValueError as error:
-            root_logger.debug(error)
+            logger.debug("%s", error)
 
         if enabled:
             self.enable()

ipaserver/install/odsexporterinstance.py

@@ -2,6 +2,7 @@
 # Copyright (C) 2014  FreeIPA Contributors see COPYING for license
 #
 
+import logging
 import os
 import pwd
 import grp
@@ -10,7 +11,6 @@ import ldap
 
 from ipaserver.install import service
 from ipaserver.install import installutils
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 from ipapython import ipautil
 from ipaplatform.constants import constants
@@ -18,6 +18,8 @@ from ipaplatform.paths import paths
 from ipaplatform import services
 from ipalib import errors, api
 
+logger = logging.getLogger(__name__)
+
 
 class ODSExporterInstance(service.Service):
     def __init__(self, fstore=None):
@@ -72,7 +74,7 @@ class ODSExporterInstance(service.Service):
             self.ldap_enable('DNSKeyExporter', self.fqdn, None,
                              self.suffix)
         except errors.DuplicateEntry:
-            root_logger.error("DNSKeyExporter service already exists")
+            logger.error("DNSKeyExporter service already exists")
 
     def __setup_key_exporter(self):
         installutils.set_directive(paths.SYSCONFIG_IPA_ODS_EXPORTER,
@@ -116,8 +118,8 @@ class ODSExporterInstance(service.Service):
         except ldap.TYPE_OR_VALUE_EXISTS:
             pass
         except Exception as e:
-            root_logger.critical("Could not modify principal's %s entry: %s"
-                                 % (dns_exporter_principal_dn, str(e)))
+            logger.critical("Could not modify principal's %s entry: %s",
+                            dns_exporter_principal_dn, str(e))
             raise
 
         # limit-free connection
@@ -129,8 +131,8 @@ class ODSExporterInstance(service.Service):
         try:
             api.Backend.ldap2.modify_s(dns_exporter_principal_dn, mod)
         except Exception as e:
-            root_logger.critical("Could not set principal's %s LDAP limits: %s"
-                                 % (dns_exporter_principal_dn, str(e)))
+            logger.critical("Could not set principal's %s LDAP limits: %s",
+                            dns_exporter_principal_dn, str(e))
             raise
 
     def __disable_signerd(self):

ipaserver/install/opendnssecinstance.py

@@ -2,6 +2,7 @@
 # Copyright (C) 2014  FreeIPA Contributors see COPYING for license
 #
 
+import logging
 import os
 import pwd
 import grp
@@ -12,7 +13,6 @@ from subprocess import CalledProcessError
 from ipalib.install import sysrestore
 from ipaserver.install import service
 from ipaserver.install import installutils
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 from ipapython import ipautil
 from ipaplatform import services
@@ -22,6 +22,8 @@ from ipalib import errors, api
 from ipaserver import p11helper
 from ipalib.constants import SOFTHSM_DNSSEC_TOKEN_LABEL
 
+logger = logging.getLogger(__name__)
+
 KEYMASTER = u'dnssecKeyMaster'
 
 
@@ -139,7 +141,7 @@ class OpenDNSSECInstance(service.Service):
             self.ldap_enable('DNSSEC', self.fqdn, None,
                              self.suffix, self.extra_config)
         except errors.DuplicateEntry:
-            root_logger.error("DNSSEC service already exists")
+            logger.error("DNSSEC service already exists")
 
         # add the KEYMASTER identifier into ipaConfigString
         # this is needed for the re-enabled DNSSEC master
@@ -148,7 +150,7 @@ class OpenDNSSECInstance(service.Service):
         try:
             entry = api.Backend.ldap2.get_entry(dn, ['ipaConfigString'])
         except errors.NotFound as e:
-            root_logger.error(
+            logger.error(
                 "DNSSEC service entry not found in the LDAP (%s)", e)
         else:
             config = entry.setdefault('ipaConfigString', [])
@@ -240,11 +242,11 @@ class OpenDNSSECInstance(service.Service):
             SOFTHSM_DNSSEC_TOKEN_LABEL, pin, paths.LIBSOFTHSM2_SO)
         try:
             # generate master key
-            root_logger.debug("Creating master key")
+            logger.debug("Creating master key")
             p11helper.generate_master_key(p11)
 
             # change tokens mod/owner
-            root_logger.debug("Changing ownership of token files")
+            logger.debug("Changing ownership of token files")
             for (root, dirs, files) in os.walk(paths.DNSSEC_TOKENS_DIR):
                 for directory in dirs:
                     dir_path = os.path.join(root, directory)
@@ -261,7 +263,7 @@ class OpenDNSSECInstance(service.Service):
     def __setup_dnssec(self):
         # run once only
         if self.get_state("kasp_db_configured") and not self.kasp_db_file:
-            root_logger.debug("Already configured, skipping step")
+            logger.debug("Already configured, skipping step")
             return
 
         self.backup_state("kasp_db_configured", True)
@@ -344,18 +346,18 @@ class OpenDNSSECInstance(service.Service):
                 self.print_msg("Exporting DNSSEC data before uninstallation")
                 ipautil.run(cmd, runas=constants.ODS_USER)
             except CalledProcessError:
-                root_logger.error("DNSSEC data export failed")
+                logger.error("DNSSEC data export failed")
 
             try:
                 shutil.copy(paths.OPENDNSSEC_KASP_DB,
                             paths.IPA_KASP_DB_BACKUP)
             except IOError as e:
-                root_logger.error(
+                logger.error(
                     "Unable to backup OpenDNSSEC database %s, "
                     "restore will be skipped: %s", paths.OPENDNSSEC_KASP_DB, e)
             else:
-                root_logger.info("OpenDNSSEC database backed up in %s",
-                                 paths.IPA_KASP_DB_BACKUP)
+                logger.info("OpenDNSSEC database backed up in %s",
+                            paths.IPA_KASP_DB_BACKUP)
                 # restore OpenDNSSEC's KASP DB only if backup succeeded
                 # removing the file without backup could totally break DNSSEC
                 restore_list.append(paths.OPENDNSSEC_KASP_DB)
@@ -364,7 +366,7 @@ class OpenDNSSECInstance(service.Service):
             try:
                 self.fstore.restore_file(f)
             except ValueError as error:
-                root_logger.debug(error)
+                logger.debug("%s", error)
 
         self.restore_state("kasp_db_configured")  # just eat state
 

ipaserver/install/plugins/adtrust.py

@@ -22,7 +22,6 @@ import logging
 from ipalib import Registry, errors
 from ipalib import Updater
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 from ipaserver.install import sysupgrade
 from ipaserver.install.adtrustinstance import ADTRUSTInstance
 
@@ -49,7 +48,8 @@ class update_default_range(Updater):
         except errors.NotFound:
             pass
         else:
-            root_logger.debug("default_range: ipaDomainIDRange entry found, skip plugin")
+            logger.debug("default_range: ipaDomainIDRange entry found, skip "
+                         "plugin")
             return False, []
 
         dn = DN(('cn', 'admins'), self.api.env.container_group,
@@ -57,8 +57,8 @@ class update_default_range(Updater):
         try:
             admins_entry = ldap.get_entry(dn, ['gidnumber'])
         except errors.NotFound:
-            root_logger.error("default_range: No local ID range and no admins "
-                              "group found. Cannot create default ID range")
+            logger.error("default_range: No local ID range and no admins "
+                         "group found. Cannot create default ID range")
             return False, []
 
         id_range_base_id = admins_entry['gidnumber'][0]
@@ -92,8 +92,8 @@ class update_default_range(Updater):
         try:
             (entries, _truncated) = ldap.find_entries(search_filter, attrs, dn)
         except errors.NotFound:
-            root_logger.warning("default_range: no dnaSharedConfig object found. "
-                                "Cannot check default range size.")
+            logger.warning("default_range: no dnaSharedConfig object found. "
+                           "Cannot check default range size.")
         else:
             masters = set()
             remaining_values_sum = 0
@@ -105,8 +105,9 @@ class update_default_range(Updater):
                 try:
                     remaining_values = int(remaining_values)
                 except ValueError:
-                    root_logger.warning("default_range: could not parse "
-                        "remaining values from '%s'", remaining_values)
+                    logger.warning("default_range: could not parse "
+                                   "remaining values from '%s'",
+                                   remaining_values)
                     continue
                 else:
                     remaining_values_sum += remaining_values
@@ -122,7 +123,7 @@ class update_default_range(Updater):
                        '  RANGE_SIZE = (--idmax) - (--idstart) + 1'
                       ]
 
-                root_logger.error("default_range: %s", "\n".join(msg))
+                logger.error("default_range: %s", "\n".join(msg))
 
         return False, [update]
 

ipaserver/install/plugins/dns.py

@@ -32,7 +32,6 @@ from ipalib import Registry, errors, util
 from ipalib import Updater
 from ipapython.dn import DN
 from ipapython import dnsutil
-from ipapython.ipa_log_manager import root_logger
 from ipaserver.install import sysupgrade
 from ipaserver.install.bindinstance import ensure_dnsserver_container_exists
 from ipaserver.plugins.dns import dns_container_exists
@@ -246,11 +245,13 @@ class update_dns_limits(Updater):
             entry = ldap.get_entry(dns_service_dn, self.limit_attributes)
         except errors.NotFound:
             # this host may not have DNS service set
-            root_logger.debug("DNS: service %s not found, no need to update limits" % dns_service_dn)
+            logger.debug("DNS: service %s not found, no need to update limits",
+                         dns_service_dn)
             return False, []
 
         if all(entry.get(limit.lower(), [None])[0] == self.limit_value for limit in self.limit_attributes):
-            root_logger.debug("DNS: limits for service %s already set" % dns_service_dn)
+            logger.debug("DNS: limits for service %s already set",
+                         dns_service_dn)
             # service is already updated
             return False, []
 
@@ -261,7 +262,8 @@ class update_dns_limits(Updater):
                                       value=self.limit_value))
 
         dnsupdate = {'dn': dns_service_dn, 'updates': limit_updates}
-        root_logger.debug("DNS: limits for service %s will be updated" % dns_service_dn)
+        logger.debug("DNS: limits for service %s will be updated",
+                     dns_service_dn)
 
 
         return False, [dnsupdate]

ipaserver/install/plugins/update_idranges.py

@@ -17,10 +17,13 @@
 # You should have received a copy of the GNU General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+import logging
+
 from ipalib import Registry, errors
 from ipalib import Updater
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
+
+logger = logging.getLogger(__name__)
 
 register = Registry()
 
@@ -37,8 +40,8 @@ class update_idrange_type(Updater):
 
         base_dn = DN(self.api.env.container_ranges, self.api.env.basedn)
         search_filter = ("(&(objectClass=ipaIDrange)(!(ipaRangeType=*)))")
-        root_logger.debug("update_idrange_type: search for ID ranges with no "
-                          "type set")
+        logger.debug("update_idrange_type: search for ID ranges with no "
+                     "type set")
 
         while True:
             # Run the search in loop to avoid issues when LDAP limits are hit
@@ -49,24 +52,23 @@ class update_idrange_type(Updater):
                     ['objectclass'], base_dn, time_limit=0, size_limit=0)
 
             except errors.NotFound:
-                root_logger.debug("update_idrange_type: no ID range without "
-                                  "type set found")
+                logger.debug("update_idrange_type: no ID range without "
+                             "type set found")
                 return False, []
 
             except errors.ExecutionError as e:
-                root_logger.error("update_idrange_type: cannot retrieve list "
-                                  "of ranges with no type set: %s", e)
+                logger.error("update_idrange_type: cannot retrieve list "
+                             "of ranges with no type set: %s", e)
                 return False, []
 
             if not entries:
                 # No entry was returned, rather break than continue cycling
-                root_logger.debug("update_idrange_type: no ID range was "
-                                  "returned")
+                logger.debug("update_idrange_type: no ID range was returned")
                 return False, []
 
-            root_logger.debug("update_idrange_type: found %d "
-                              "idranges to update, truncated: %s",
-                              len(entries), truncated)
+            logger.debug("update_idrange_type: found %d "
+                         "idranges to update, truncated: %s",
+                         len(entries), truncated)
 
             error = False
 
@@ -83,30 +85,30 @@ class update_idrange_type(Updater):
                     entry['ipaRangeType'] = ['ipa-local']
                 else:
                     entry['ipaRangeType'] = ['unknown']
-                    root_logger.error("update_idrange_type: could not detect "
-                                      "range type for entry: %s" % str(entry.dn))
-                    root_logger.error("update_idrange_type: ID range type set "
-                                      "to 'unknown' for entry: %s" % str(entry.dn))
+                    logger.error("update_idrange_type: could not detect "
+                                 "range type for entry: %s", str(entry.dn))
+                    logger.error("update_idrange_type: ID range type set "
+                                 "to 'unknown' for entry: %s", str(entry.dn))
 
                 try:
                     ldap.update_entry(entry)
                 except (errors.EmptyModlist, errors.NotFound):
                     pass
                 except errors.ExecutionError as e:
-                    root_logger.debug("update_idrange_type: cannot "
-                                      "update idrange type: %s", e)
+                    logger.debug("update_idrange_type: cannot "
+                                 "update idrange type: %s", e)
                     error = True
 
             if error:
                 # Exit loop to avoid infinite cycles
-                root_logger.error("update_idrange_type: error(s) "
-                                  "detected during idrange type update")
+                logger.error("update_idrange_type: error(s) "
+                             "detected during idrange type update")
                 return False, []
 
             elif not truncated:
                 # All affected entries updated, exit the loop
-                root_logger.debug("update_idrange_type: all affected idranges "
-                                  "were assigned types")
+                logger.debug("update_idrange_type: all affected idranges "
+                             "were assigned types")
                 return False, []
 
         return False, []
@@ -126,7 +128,7 @@ class update_idrange_baserid(Updater):
         search_filter = ("(&(objectClass=ipaTrustedADDomainRange)"
                          "(ipaRangeType=ipa-ad-trust-posix)"
                          "(!(ipaBaseRID=0)))")
-        root_logger.debug(
+        logger.debug(
             "update_idrange_baserid: search for ipa-ad-trust-posix ID ranges "
             "with ipaBaseRID != 0"
         )
@@ -137,18 +139,18 @@ class update_idrange_baserid(Updater):
                 paged_search=True, time_limit=0, size_limit=0)
 
         except errors.NotFound:
-            root_logger.debug("update_idrange_baserid: no AD domain "
-                              "range with posix attributes found")
+            logger.debug("update_idrange_baserid: no AD domain "
+                         "range with posix attributes found")
             return False, []
 
         except errors.ExecutionError as e:
-            root_logger.error("update_idrange_baserid: cannot retrieve "
-                              "list of affected ranges: %s", e)
+            logger.error("update_idrange_baserid: cannot retrieve "
+                         "list of affected ranges: %s", e)
             return False, []
 
-        root_logger.debug("update_idrange_baserid: found %d "
-                          "idranges possible to update",
-                          len(entries))
+        logger.debug("update_idrange_baserid: found %d "
+                     "idranges possible to update",
+                     len(entries))
 
         error = False
 
@@ -156,22 +158,22 @@ class update_idrange_baserid(Updater):
         for entry in entries:
             entry['ipabaserid'] = 0
             try:
-                root_logger.debug("Updating existing idrange: %s" % (entry.dn))
+                logger.debug("Updating existing idrange: %s", entry.dn)
                 ldap.update_entry(entry)
-                root_logger.info("Done")
+                logger.info("Done")
             except (errors.EmptyModlist, errors.NotFound):
                 pass
             except errors.ExecutionError as e:
-                root_logger.debug("update_idrange_type: cannot "
-                                  "update idrange: %s", e)
+                logger.debug("update_idrange_type: cannot "
+                             "update idrange: %s", e)
                 error = True
 
         if error:
-            root_logger.error("update_idrange_baserid: error(s) "
-                              "detected during idrange baserid update")
+            logger.error("update_idrange_baserid: error(s) "
+                         "detected during idrange baserid update")
         else:
             # All affected entries updated, exit the loop
-            root_logger.debug("update_idrange_baserid: all affected "
-                              "idranges updated")
+            logger.debug("update_idrange_baserid: all affected "
+                         "idranges updated")
 
         return False, []

ipaserver/install/plugins/update_passsync.py

@@ -2,12 +2,15 @@
 # Copyright (C) 2014  FreeIPA Contributors see COPYING for license
 #
 
+import logging
+
 from ipalib import Registry, errors
 from ipalib import Updater
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 from ipaserver.install import sysupgrade
 
+logger = logging.getLogger(__name__)
+
 register = Registry()
 
 
@@ -17,10 +20,10 @@ class update_passync_privilege_check(Updater):
     def execute(self, **options):
         update_done = sysupgrade.get_upgrade_state('winsync', 'passsync_privilege_updated')
         if update_done:
-            root_logger.debug("PassSync privilege update pre-check not needed")
+            logger.debug("PassSync privilege update pre-check not needed")
             return False, []
 
-        root_logger.debug("Check if there is existing PassSync privilege")
+        logger.debug("Check if there is existing PassSync privilege")
 
         passsync_privilege_dn = DN(('cn','PassSync Service'),
                 self.api.env.container_privilege,
@@ -30,10 +33,10 @@ class update_passync_privilege_check(Updater):
         try:
             ldap.get_entry(passsync_privilege_dn, [''])
         except errors.NotFound:
-            root_logger.debug("PassSync privilege not found, this is a new update")
+            logger.debug("PassSync privilege not found, this is a new update")
             sysupgrade.set_upgrade_state('winsync', 'passsync_privilege_updated', False)
         else:
-            root_logger.debug("PassSync privilege found, skip updating PassSync")
+            logger.debug("PassSync privilege found, skip updating PassSync")
             sysupgrade.set_upgrade_state('winsync', 'passsync_privilege_updated', True)
 
         return False, []
@@ -48,10 +51,10 @@ class update_passync_privilege_update(Updater):
     def execute(self, **options):
         update_done = sysupgrade.get_upgrade_state('winsync', 'passsync_privilege_updated')
         if update_done:
-            root_logger.debug("PassSync privilege update not needed")
+            logger.debug("PassSync privilege update not needed")
             return False, []
 
-        root_logger.debug("Add PassSync user as a member of PassSync privilege")
+        logger.debug("Add PassSync user as a member of PassSync privilege")
         ldap = self.api.Backend.ldap2
         passsync_dn = DN(('uid','passsync'), ('cn', 'sysaccounts'), ('cn', 'etc'),
             self.api.env.basedn)
@@ -62,11 +65,11 @@ class update_passync_privilege_update(Updater):
         try:
             ldap.get_entry(passsync_dn, [''])
         except errors.NotFound:
-            root_logger.debug("PassSync user not found, no update needed")
+            logger.debug("PassSync user not found, no update needed")
             sysupgrade.set_upgrade_state('winsync', 'passsync_privilege_updated', True)
             return False, []
         else:
-            root_logger.debug("PassSync user found, do update")
+            logger.debug("PassSync user found, do update")
 
         update = {'dn': passsync_privilege_dn,
                   'updates': [

ipaserver/install/plugins/update_referint.py

@@ -2,10 +2,13 @@
 # Copyright (C) 2014  FreeIPA Contributors see COPYING for license
 #
 
+import logging
+
 from ipalib import Registry, errors
 from ipalib import Updater
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
+
+logger = logging.getLogger(__name__)
 
 register = Registry()
 
@@ -30,39 +33,39 @@ class update_referint(Updater):
 
     def execute(self, **options):
 
-        root_logger.debug("Upgrading referential integrity plugin configuration")
+        logger.debug("Upgrading referential integrity plugin configuration")
         ldap = self.api.Backend.ldap2
         try:
             entry = ldap.get_entry(self.referint_dn)
         except errors.NotFound:
-            root_logger.error("Referential integrity configuration not found")
+            logger.error("Referential integrity configuration not found")
             return False, []
 
         referint_membership_attrs = []
 
-        root_logger.debug("Initial value: %s", repr(entry))
+        logger.debug("Initial value: %s", repr(entry))
 
         # nsslapd-pluginArg0    -> referint-update-delay
         update_delay = entry.get('nsslapd-pluginArg0')
         if update_delay:
-            root_logger.debug("add: referint-update-delay: %s", update_delay)
+            logger.debug("add: referint-update-delay: %s", update_delay)
             entry['referint-update-delay'] = update_delay
             entry['nsslapd-pluginArg0'] = None
         else:
-            root_logger.debug("Plugin already uses new style, skipping")
+            logger.debug("Plugin already uses new style, skipping")
             return False, []
 
         # nsslapd-pluginArg1    -> referint-logfile
         logfile = entry.get('nsslapd-pluginArg1')
         if logfile:
-            root_logger.debug("add: referint-logfile: %s", logfile)
+            logger.debug("add: referint-logfile: %s", logfile)
             entry['referint-logfile'] = logfile
             entry['nsslapd-pluginArg1'] = None
 
         # nsslapd-pluginArg2    -> referint-logchanges
         logchanges = entry.get('nsslapd-pluginArg2')
         if logchanges:
-            root_logger.debug("add: referint-logchanges: %s", logchanges)
+            logger.debug("add: referint-logchanges: %s", logchanges)
             entry['referint-logchanges'] = logchanges
             entry['nsslapd-pluginArg2'] = None
 
@@ -79,11 +82,11 @@ class update_referint(Updater):
             # mixing old and new style
             entry['referint-membership-attr'] = referint_membership_attrs
 
-        root_logger.debug("Final value: %s", repr(entry))
+        logger.debug("Final value: %s", repr(entry))
         try:
             ldap.update_entry(entry)
         except errors.EmptyModlist:
-            root_logger.debug("No modifications required")
+            logger.debug("No modifications required")
             return False, []
 
         return False, []

ipaserver/install/plugins/update_services.py

@@ -17,10 +17,13 @@
 # You should have received a copy of the GNU General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+import logging
+
 from ipalib import Registry, errors
 from ipalib import Updater
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
+
+logger = logging.getLogger(__name__)
 
 register = Registry()
 
@@ -39,8 +42,8 @@ class update_service_principalalias(Updater):
         base_dn = DN(self.api.env.container_service, self.api.env.basedn)
         search_filter = ("(&(objectclass=krbprincipal)(objectclass=ipaservice)"
                          "(!(objectclass=ipakrbprincipal)))")
-        root_logger.debug("update_service_principalalias: search for affected "
-                          "services")
+        logger.debug("update_service_principalalias: search for affected "
+                     "services")
 
         while True:
             # run the search in loop to avoid issues when LDAP limits are hit
@@ -50,21 +53,21 @@ class update_service_principalalias(Updater):
                     ['objectclass', 'krbprincipalname'], base_dn,
                     time_limit=0, size_limit=0)
             except errors.NotFound:
-                root_logger.debug("update_service_principalalias: no service "
-                                  "to update found")
+                logger.debug("update_service_principalalias: no service "
+                             "to update found")
                 return False, []
             except errors.ExecutionError as e:
-                root_logger.error("update_service_principalalias: cannot "
-                                  "retrieve list of affected services: %s", e)
+                logger.error("update_service_principalalias: cannot "
+                             "retrieve list of affected services: %s", e)
                 return False, []
             if not entries:
                 # no entry was returned, rather break than continue cycling
-                root_logger.debug("update_service_principalalias: no service "
-                                  "was returned")
+                logger.debug("update_service_principalalias: no service "
+                             "was returned")
                 return False, []
-            root_logger.debug("update_service_principalalias: found %d "
-                              "services to update, truncated: %s",
-                              len(entries), truncated)
+            logger.debug("update_service_principalalias: found %d "
+                         "services to update, truncated: %s",
+                         len(entries), truncated)
 
             error = False
             for entry in entries:
@@ -76,18 +79,18 @@ class update_service_principalalias(Updater):
                 except (errors.EmptyModlist, errors.NotFound):
                     pass
                 except errors.ExecutionError as e:
-                    root_logger.debug("update_service_principalalias: cannot "
-                                      "update service: %s", e)
+                    logger.debug("update_service_principalalias: cannot "
+                                 "update service: %s", e)
                     error = True
 
             if error:
                 # exit loop to avoid infinite cycles
-                root_logger.error("update_service_principalalias: error(s)"
-                                  "detected during service update")
+                logger.error("update_service_principalalias: error(s)"
+                             "detected during service update")
                 return False, []
             elif not truncated:
                 # all affected entries updated, exit the loop
-                root_logger.debug("update_service_principalalias: all affected"
-                                  " services updated")
+                logger.debug("update_service_principalalias: all affected"
+                             " services updated")
                 return False, []
         return False, []

ipaserver/install/plugins/update_uniqueness.py

@@ -17,10 +17,13 @@
 # You should have received a copy of the GNU General Public License
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+import logging
+
 from ipalib import Registry, errors
 from ipalib import Updater
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
+
+logger = logging.getLogger(__name__)
 
 register = Registry()
 
@@ -182,8 +185,8 @@ class update_uniqueness_plugins_to_new_syntax(Updater):
                 base_dn=self.plugins_dn,
             )
         except errors.NotFound:
-            root_logger.debug("No uniqueness plugin entries with old style "
-                              "configuration found")
+            logger.debug("No uniqueness plugin entries with old style "
+                         "configuration found")
             return False, []
 
         update_list = []
@@ -198,14 +201,14 @@ class update_uniqueness_plugins_to_new_syntax(Updater):
         for entry in entries:
             # test for mixed configuration
             if any(attr in entry for attr in new_attributes):
-                root_logger.critical("Mixed old and new style configuration "
-                                     "for plugin %s. Plugin will not work. "
-                                     "Skipping plugin migration, please fix it "
-                                     "manually",
-                                     entry.dn)
+                logger.critical("Mixed old and new style configuration "
+                                "for plugin %s. Plugin will not work. "
+                                "Skipping plugin migration, please fix it "
+                                "manually",
+                                entry.dn)
                 continue
-            root_logger.debug("Configuration of plugin %s will be migrated "
-                             "to new style", entry.dn)
+            logger.debug("Configuration of plugin %s will be migrated "
+                         "to new style", entry.dn)
             try:
                 # detect which configuration was used
                 arg0 = entry.get('nsslapd-pluginarg0')
@@ -214,9 +217,9 @@ class update_uniqueness_plugins_to_new_syntax(Updater):
                 else:
                     update = self.__subtree_style(entry)
             except ValueError as e:
-                root_logger.error("Unable to migrate configuration of "
-                                  "plugin %s (%s)",
-                                  entry.dn, e)
+                logger.error("Unable to migrate configuration of "
+                             "plugin %s (%s)",
+                             entry.dn, e)
             else:
                 update_list.append(update)
 

ipaserver/install/replication.py

@@ -19,6 +19,8 @@
 
 from __future__ import print_function
 
+import logging
+
 import six
 import time
 import datetime
@@ -30,7 +32,6 @@ import ldap
 
 from ipalib import api, errors
 from ipalib.cli import textui
-from ipapython.ipa_log_manager import root_logger
 from ipapython import ipautil, ipaldap, kerberos
 from ipapython.admintool import ScriptError
 from ipapython.dn import DN
@@ -40,6 +41,8 @@ from ipaserver.install import installutils
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 # the default container used by AD for user entries
 WIN_USER_CONTAINER = DN(('cn', 'Users'))
 # the default container used by IPA for user entries
@@ -176,7 +179,7 @@ def wait_for_entry(connection, dn, timeout=7200, attr='', quiet=True):
         except errors.NotFound:
             pass  # no entry yet
         except Exception as e:  # badness
-            root_logger.error("Error reading entry %s: %s", dn, e)
+            logger.error("Error reading entry %s: %s", dn, e)
             raise
         if not entry:
             if not quiet:
@@ -188,7 +191,7 @@ def wait_for_entry(connection, dn, timeout=7200, attr='', quiet=True):
         raise errors.NotFound(
             reason="wait_for_entry timeout for %s for %s" % (connection, dn))
     elif entry and not quiet:
-        root_logger.error("The waited for entry is: %s", entry)
+        logger.error("The waited for entry is: %s", entry)
 
 
 class ReplicationManager(object):
@@ -268,12 +271,13 @@ class ReplicationManager(object):
 
         for a in range(1, attempts + 1):
             try:
-                root_logger.debug('Fetching nsDS5ReplicaId from master '
-                                  '[attempt %d/%d]', a, attempts)
+                logger.debug('Fetching nsDS5ReplicaId from master '
+                             '[attempt %d/%d]', a, attempts)
                 replica = master_conn.get_entry(dn)
                 id_values = replica.get('nsDS5ReplicaId')
                 if not id_values:
-                    root_logger.debug("Unable to retrieve nsDS5ReplicaId from remote server")
+                    logger.debug("Unable to retrieve nsDS5ReplicaId from "
+                                 "remote server")
                     raise RuntimeError("Unable to retrieve nsDS5ReplicaId from remote server")
                 # nsDS5ReplicaId is single-valued now, but historically it could
                 # contain multiple values, of which we need the highest.
@@ -285,22 +289,22 @@ class ReplicationManager(object):
                             (ldap.MOD_ADD, 'nsDS5ReplicaId', str(retval + 1))]
 
                 master_conn.modify_s(dn, mod_list)
-                root_logger.debug('Successfully updated nsDS5ReplicaId.')
+                logger.debug('Successfully updated nsDS5ReplicaId.')
                 return retval
 
             except errors.NotFound:
-                root_logger.debug("Unable to retrieve nsDS5ReplicaId from remote server")
+                logger.debug("Unable to retrieve nsDS5ReplicaId from remote "
+                             "server")
                 raise
             # these errors signal a conflict in updating replica ID.
             # We then wait for a random time interval and try again
             except (ldap.NO_SUCH_ATTRIBUTE, ldap.OBJECT_CLASS_VIOLATION) as e:
                 sleep_interval = randint(1, 5)
-                root_logger.debug("Update failed (%s). Conflicting operation?",
-                                  e)
+                logger.debug("Update failed (%s). Conflicting operation?", e)
                 time.sleep(sleep_interval)
             # in case of other error we bail out
             except ldap.LDAPError as e:
-                root_logger.debug("Problem updating nsDS5ReplicaID %s" % e)
+                logger.debug("Problem updating nsDS5ReplicaID %s", e)
                 raise
 
         raise RuntimeError("Failed to update nsDS5ReplicaId in %d attempts"
@@ -457,7 +461,7 @@ class ReplicationManager(object):
             try:
                 r_conn.modify_s(entry.dn, mod)
             except ldap.UNWILLING_TO_PERFORM:
-                root_logger.debug(
+                logger.debug(
                     "nsds5replicabinddngroup attribute not supported on "
                     "remote master.")
 
@@ -560,8 +564,8 @@ class ReplicationManager(object):
             conn.modify_s(self.db_suffix, [(ldap.MOD_ADD, 'aci',
                                     [ "(targetattr = \"*\")(version 3.0; acl \"Proxied authorization for database links\"; allow (proxy) userdn = \"ldap:///%s\";)" % self.repl_man_dn ])])
         except ldap.TYPE_OR_VALUE_EXISTS:
-            root_logger.debug("proxy aci already exists in suffix %s on %s"
-                              % (self.db_suffix, conn.ldap_uri))
+            logger.debug("proxy aci already exists in suffix %s on %s",
+                         self.db_suffix, conn.ldap_uri)
 
     def get_mapping_tree_entry(self):
         try:
@@ -572,7 +576,7 @@ class ReplicationManager(object):
             # TODO: Check we got only one entry
             return entries[0]
         except errors.NotFound:
-            root_logger.debug(
+            logger.debug(
                 "failed to find mapping tree entry for %s", self.db_suffix)
             raise
 
@@ -595,8 +599,8 @@ class ReplicationManager(object):
         try:
             self.conn.modify_s(dn, mod)
         except ldap.TYPE_OR_VALUE_EXISTS:
-            root_logger.debug("chainOnUpdate already enabled for %s"
-                              % self.db_suffix)
+            logger.debug("chainOnUpdate already enabled for %s",
+                         self.db_suffix)
 
     def setup_chain_on_update(self, other_conn):
         chainbe = self.setup_chaining_backend(other_conn)
@@ -628,8 +632,8 @@ class ReplicationManager(object):
         try:
             conn.modify_s(extop_dn, mod)
         except ldap.TYPE_OR_VALUE_EXISTS:
-            root_logger.debug("Plugin '%s' already '%s' in passSyncManagersDNs",
-                    extop_dn, pass_dn)
+            logger.debug("Plugin '%s' already '%s' in passSyncManagersDNs",
+                         extop_dn, pass_dn)
 
         # And finally add it is a member of PassSync privilege to allow
         # displaying user NT attributes and reset passwords
@@ -642,8 +646,8 @@ class ReplicationManager(object):
         try:
             conn.modify_s(passsync_privilege_dn, mod)
         except ldap.TYPE_OR_VALUE_EXISTS:
-            root_logger.debug("PassSync service '%s' already have '%s' as member",
-                    passsync_privilege_dn, pass_dn)
+            logger.debug("PassSync service '%s' already have '%s' as member",
+                         passsync_privilege_dn, pass_dn)
 
     def setup_winsync_agmt(self, entry, win_subtree=None):
         if win_subtree is None:
@@ -757,7 +761,8 @@ class ReplicationManager(object):
         error_message = ''
 
         while (retries > 0 ):
-            root_logger.info('Getting ldap service principals for conversion: %s and %s' % (filter_a, filter_b))
+            logger.info('Getting ldap service principals for conversion: '
+                        '%s and %s', filter_a, filter_b)
             try:
                 a_entry = b.get_entries(self.suffix, ldap.SCOPE_SUBTREE,
                                         filter=filter_a)
@@ -771,20 +776,20 @@ class ReplicationManager(object):
                 pass
 
             if a_entry and b_entry:
-                root_logger.debug('Found both principals.')
+                logger.debug('Found both principals.')
                 break
 
             # One or both is missing, force sync again
             if not a_entry:
-                root_logger.debug('Unable to find entry for %s on %s'
-                    % (filter_a, str(b)))
+                logger.debug('Unable to find entry for %s on %s',
+                             filter_a, str(b))
                 self.force_sync(a, b.host)
                 _cn, dn = self.agreement_dn(b.host)
                 _haserror, error_message = self.wait_for_repl_update(a, dn, 60)
 
             if not b_entry:
-                root_logger.debug('Unable to find entry for %s on %s'
-                    % (filter_b, str(a)))
+                logger.debug('Unable to find entry for %s on %s',
+                             filter_b, str(a))
                 self.force_sync(b, a.host)
                 _cn, dn = self.agreement_dn(a.host)
                 _haserror, error_message = self.wait_for_repl_update(b, dn, 60)
@@ -888,7 +893,7 @@ class ReplicationManager(object):
         try:
             self.conn.modify_s(dn, mod)
         except Exception as e:
-            root_logger.debug("Failed to remove referral value: %s" % str(e))
+            logger.debug("Failed to remove referral value: %s", str(e))
 
     def check_repl_init(self, conn, agmtdn, start):
         done = False
@@ -957,8 +962,9 @@ class ReplicationManager(object):
                 end = 0
             # incremental update is done if inprogress is false and end >= start
             done = inprogress and inprogress.lower() == 'false' and start <= end
-            root_logger.info("Replication Update in progress: %s: status: %s: start: %d: end: %d" %
-                         (inprogress, status, start, end))
+            logger.info("Replication Update in progress: %s: status: %s: "
+                        "start: %d: end: %d",
+                        inprogress, status, start, end)
             if status: # always check for errors
                 # status will usually be a number followed by a string
                 # number != 0 means error
@@ -1084,14 +1090,14 @@ class ReplicationManager(object):
             for dn,entry in res:
                 if dn == "":
                     self.ad_suffix = entry['defaultNamingContext'][0]
-                    root_logger.info("AD Suffix is: %s" % self.ad_suffix)
+                    logger.info("AD Suffix is: %s", self.ad_suffix)
             if self.ad_suffix == "":
                 raise RuntimeError("Failed to lookup AD's Ldap suffix")
             ad_conn.unbind_s()
             del ad_conn
         except Exception as e:
-            root_logger.info("Failed to connect to AD server %s" % ad_dc_name)
-            root_logger.info("The error was: %s" % e)
+            logger.info("Failed to connect to AD server %s", ad_dc_name)
+            logger.info("The error was: %s", e)
             raise RuntimeError("Failed to setup winsync replication")
 
         # Setup the only half.
@@ -1106,10 +1112,11 @@ class ReplicationManager(object):
         self.setup_agreement(self.conn, ad_dc_name,
                              repl_man_dn=ad_binddn, repl_man_passwd=ad_pwd,
                              iswinsync=True, win_subtree=ad_subtree)
-        root_logger.info("Added new sync agreement, waiting for it to become ready . . .")
+        logger.info("Added new sync agreement, waiting for it to become "
+                    "ready . . .")
         _cn, dn = self.agreement_dn(ad_dc_name)
         self.wait_for_repl_update(self.conn, dn, 300)
-        root_logger.info("Agreement is ready, starting replication . . .")
+        logger.info("Agreement is ready, starting replication . . .")
 
         # Add winsync replica to the public DIT
         dn = DN(('cn',ad_dc_name),('cn','replicas'),('cn','ipa'),('cn','etc'), self.suffix)
@@ -1123,7 +1130,7 @@ class ReplicationManager(object):
         try:
             self.conn.add_entry(entry)
         except Exception as e:
-            root_logger.info("Failed to create public entry for winsync replica")
+            logger.info("Failed to create public entry for winsync replica")
 
         #Finally start replication
         ret = self.start_replication(self.conn, ad_dc_name)
@@ -1195,12 +1202,12 @@ class ReplicationManager(object):
             entries = conn.get_entries(
                 DN(('cn', 'config')), ldap.SCOPE_SUBTREE, filter)
         except errors.NotFound:
-            root_logger.error("Unable to find replication agreement for %s" %
-                          (hostname))
+            logger.error("Unable to find replication agreement for %s",
+                         hostname)
             raise RuntimeError("Unable to proceed")
         if len(entries) > 1:
-            root_logger.error("Found multiple agreements for %s" % hostname)
-            root_logger.error("Using the first one only (%s)" % entries[0].dn)
+            logger.error("Found multiple agreements for %s", hostname)
+            logger.error("Using the first one only (%s)", entries[0].dn)
 
         dn = entries[0].dn
         schedule = entries[0].single_value.get('nsds5replicaupdateschedule')
@@ -1210,13 +1217,13 @@ class ReplicationManager(object):
         if schedule is not None:
             if newschedule == schedule:
                 newschedule = '2358-2359 1'
-        root_logger.info("Setting agreement %s schedule to %s to force synch" %
-                     (dn, newschedule))
+        logger.info("Setting agreement %s schedule to %s to force synch",
+                    dn, newschedule)
         mod = [(ldap.MOD_REPLACE, 'nsDS5ReplicaUpdateSchedule', [ newschedule ])]
         conn.modify_s(dn, mod)
         time.sleep(1)
-        root_logger.info("Deleting schedule %s from agreement %s" %
-                     (newschedule, dn))
+        logger.info("Deleting schedule %s from agreement %s",
+                    newschedule, dn)
         mod = [(ldap.MOD_DELETE, 'nsDS5ReplicaUpdateSchedule', None)]
         conn.modify_s(dn, mod)
 
@@ -1280,8 +1287,9 @@ class ReplicationManager(object):
                 mod = [(ldap.MOD_DELETE, 'memberPrincipal', member_principal)]
                 self.conn.modify_s(dn, mod)
             except (ldap.NO_SUCH_OBJECT, ldap.NO_SUCH_ATTRIBUTE):
-                root_logger.debug("Replica (%s) memberPrincipal (%s) not found in %s" % \
-                        (replica, member_principal, dn))
+                logger.debug("Replica (%s) memberPrincipal (%s) not found in "
+                             "%s",
+                             replica, member_principal, dn)
             except Exception as e:
                 if not force:
                     raise e
@@ -1375,14 +1383,15 @@ class ReplicationManager(object):
             # This usually isn't a show-stopper.
             if critical:
                 raise e
-            root_logger.debug("No permission to modify replica read-only status, continuing anyway")
+            logger.debug("No permission to modify replica read-only status, "
+                         "continuing anyway")
 
     def cleanallruv(self, replicaId):
         """
         Create a CLEANALLRUV task and monitor it until it has
         completed.
         """
-        root_logger.debug("Creating CLEANALLRUV task for replica id %d" % replicaId)
+        logger.debug("Creating CLEANALLRUV task for replica id %d", replicaId)
 
         dn = DN(('cn', 'clean %d' % replicaId), ('cn', 'cleanallruv'),('cn', 'tasks'), ('cn', 'config'))
         e = self.conn.make_entry(
@@ -1410,7 +1419,8 @@ class ReplicationManager(object):
         """
         Create a task to abort a CLEANALLRUV operation.
         """
-        root_logger.debug("Creating task to abort a CLEANALLRUV operation for replica id %d" % replicaId)
+        logger.debug("Creating task to abort a CLEANALLRUV operation for "
+                     "replica id %d", replicaId)
 
         dn = DN(('cn', 'abort %d' % replicaId), ('cn', 'abort cleanallruv'),('cn', 'tasks'), ('cn', 'config'))
         e = self.conn.make_entry(
@@ -1735,7 +1745,7 @@ class CSReplicationManager(ReplicationManager):
                 (ipautil.format_netloc(hostname, port), self.db_suffix))
             self.conn.update_entry(entry)
         except Exception as e:
-            root_logger.debug("Failed to remove referral value: %s" % e)
+            logger.debug("Failed to remove referral value: %s", e)
 
     def has_ipaca(self):
         try:
@@ -1761,14 +1771,14 @@ def get_cs_replication_manager(realm, host, dirman_passwd):
     # If it doesn't, raise exception.
     ports = [389, 7389]
     for port in ports:
-        root_logger.debug('Looking for PKI DS on %s:%s' % (host, port))
+        logger.debug('Looking for PKI DS on %s:%s', host, port)
         replication_manager = CSReplicationManager(
             realm, host, dirman_passwd, port)
         if replication_manager.has_ipaca():
-            root_logger.debug('PKI DS found on %s:%s' % (host, port))
+            logger.debug('PKI DS found on %s:%s', host, port)
             return replication_manager
         else:
-            root_logger.debug('PKI tree not found on %s:%s' % (host, port))
+            logger.debug('PKI tree not found on %s:%s', host, port)
 
     raise errors.NotFound(reason='Cannot reach PKI DS at %s on ports %s' % (host, ports))
 

ipaserver/install/server/install.py

@@ -5,6 +5,7 @@
 from __future__ import print_function
 
 import errno
+import logging
 import os
 import pickle
 import shutil
@@ -16,7 +17,6 @@ import six
 
 from ipalib.install import certmonger, sysrestore
 from ipapython import ipautil
-from ipapython.ipa_log_manager import root_logger
 from ipapython.ipautil import (
     format_netloc, ipa_generate_password, run, user_input)
 from ipapython.admintool import ScriptError
@@ -51,6 +51,8 @@ except ImportError:
 
 NoneType = type(None)
 
+logger = logging.getLogger(__name__)
+
 SYSRESTORE_DIR_PATH = paths.SYSRESTORE
 
 
@@ -257,9 +259,9 @@ def common_cleanup(func):
                     try:
                         dsinstance.remove_ds_instance(ds.serverid)
                     except ipautil.CalledProcessError:
-                        root_logger.error("Failed to remove DS instance. You "
-                                          "may need to remove instance data "
-                                          "manually")
+                        logger.error("Failed to remove DS instance. You "
+                                     "may need to remove instance data "
+                                     "manually")
             raise ScriptError()
         finally:
             if not success and installer._installation_cleanup:
@@ -288,7 +290,7 @@ def remove_master_from_managed_topology(api_instance, options):
         raise ScriptError(str(e))
     except Exception as e:
         # if the master was already deleted we will just get a warning
-        root_logger.warning("Failed to delete master: {}".format(e))
+        logger.warning("Failed to delete master: %s", e)
 
 
 @common_cleanup
@@ -451,12 +453,12 @@ def install_check(installer):
         raise ScriptError(e)
 
     host_name = host_name.lower()
-    root_logger.debug("will use host_name: %s\n" % host_name)
+    logger.debug("will use host_name: %s\n", host_name)
 
     if not options.domain_name:
         domain_name = read_domain_name(host_name[host_name.find(".")+1:],
                                        not installer.interactive)
-        root_logger.debug("read domain_name: %s\n" % domain_name)
+        logger.debug("read domain_name: %s\n", domain_name)
         try:
             validate_domain_name(domain_name)
         except ValueError as e:
@@ -468,7 +470,7 @@ def install_check(installer):
 
     if not options.realm_name:
         realm_name = read_realm_name(domain_name, not installer.interactive)
-        root_logger.debug("read realm_name: %s\n" % realm_name)
+        logger.debug("read realm_name: %s\n", realm_name)
     else:
         realm_name = options.realm_name.upper()
 
@@ -1103,24 +1105,24 @@ def uninstall(installer):
     sysupgrade.remove_upgrade_file()
 
     if fstore.has_files():
-        root_logger.error('Some files have not been restored, see '
-                          '%s/sysrestore.index' % SYSRESTORE_DIR_PATH)
+        logger.error('Some files have not been restored, see '
+                     '%s/sysrestore.index', SYSRESTORE_DIR_PATH)
     has_state = False
     for module in IPA_MODULES:  # from installutils
         if sstore.has_state(module):
-            root_logger.error('Some installation state for %s has not been '
-                              'restored, see %s/sysrestore.state' %
-                              (module, SYSRESTORE_DIR_PATH))
+            logger.error('Some installation state for %s has not been '
+                         'restored, see %s/sysrestore.state',
+                         module, SYSRESTORE_DIR_PATH)
             has_state = True
             rv = 1
 
     if has_state:
-        root_logger.error('Some installation state has not been restored.\n'
-                          'This may cause re-installation to fail.\n'
-                          'It should be safe to remove %s/sysrestore.state '
-                          'but it may\n'
-                          'mean your system hasn\'t be restored to its '
-                          'pre-installation state.' % SYSRESTORE_DIR_PATH)
+        logger.error('Some installation state has not been restored.\n'
+                     'This may cause re-installation to fail.\n'
+                     'It should be safe to remove %s/sysrestore.state '
+                     'but it may\n'
+                     'mean your system hasn\'t be restored to its '
+                     'pre-installation state.', SYSRESTORE_DIR_PATH)
 
     # Note that this name will be wrong after the first uninstall.
     dirname = dsinstance.config_dirname(
@@ -1128,23 +1130,23 @@ def uninstall(installer):
     dirs = [dirname, paths.PKI_TOMCAT_ALIAS_DIR, paths.HTTPD_ALIAS_DIR]
     ids = certmonger.check_state(dirs)
     if ids:
-        root_logger.error('Some certificates may still be tracked by '
-                          'certmonger.\n'
-                          'This will cause re-installation to fail.\n'
-                          'Start the certmonger service and list the '
-                          'certificates being tracked\n'
-                          ' # getcert list\n'
-                          'These may be untracked by executing\n'
-                          ' # getcert stop-tracking -i <request_id>\n'
-                          'for each id in: %s' % ', '.join(ids))
+        logger.error('Some certificates may still be tracked by '
+                     'certmonger.\n'
+                     'This will cause re-installation to fail.\n'
+                     'Start the certmonger service and list the '
+                     'certificates being tracked\n'
+                     ' # getcert list\n'
+                     'These may be untracked by executing\n'
+                     ' # getcert stop-tracking -i <request_id>\n'
+                     'for each id in: %s', ', '.join(ids))
 
     # Remove the cert renewal lock file
     try:
         os.remove(paths.IPA_RENEWAL_LOCK)
     except OSError as e:
         if e.errno != errno.ENOENT:
-            root_logger.warning("Failed to remove file %s: %s",
-                                paths.IPA_RENEWAL_LOCK, e)
+            logger.warning("Failed to remove file %s: %s",
+                           paths.IPA_RENEWAL_LOCK, e)
 
     print("Removing IPA client configuration")
     try:

ipaserver/install/server/replicainstall.py

@@ -5,6 +5,8 @@
 from __future__ import print_function
 
 import contextlib
+import logging
+
 import dns.exception as dnsexception
 import dns.name as dnsname
 import dns.resolver as dnsresolver
@@ -25,7 +27,6 @@ from ipalib.install.kinit import kinit_keytab
 from ipapython import ipaldap, ipautil
 from ipapython.certdb import IPA_CA_TRUST_FLAGS, EXTERNAL_CA_TRUST_FLAGS
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 from ipapython.admintool import ScriptError
 from ipaplatform import services
 from ipaplatform.tasks import tasks
@@ -50,6 +51,8 @@ if six.PY3:
 
 NoneType = type(None)
 
+logger = logging.getLogger(__name__)
+
 
 def get_dirman_password():
     return installutils.read_password("Directory Manager (existing master)",
@@ -185,13 +188,13 @@ def install_dns_records(config, options, remote_api):
                                         config.domain_name,
                                         reverse_zone)
     except errors.NotFound as e:
-        root_logger.debug('Replica DNS records could not be added '
-                          'on master: %s', str(e))
+        logger.debug('Replica DNS records could not be added '
+                     'on master: %s', str(e))
 
     # we should not fail here no matter what
     except Exception as e:
-        root_logger.info('Replica DNS records could not be added '
-                         'on master: %s', str(e))
+        logger.info('Replica DNS records could not be added '
+                    'on master: %s', str(e))
 
 
 def create_ipa_conf(fstore, config, ca_enabled):
@@ -270,14 +273,14 @@ def check_dns_resolution(host_name, dns_servers):
         else:
             break
     if not server_ips:
-        root_logger.error(
+        logger.error(
             'Could not resolve any DNS server hostname: %s', dns_servers)
         return False
     resolver = dnsresolver.Resolver()
     resolver.nameservers = server_ips
 
-    root_logger.debug('Search DNS server %s (%s) for %s',
-                      dns_server, server_ips, host_name)
+    logger.debug('Search DNS server %s (%s) for %s',
+                 dns_server, server_ips, host_name)
 
     # Get IP addresses of host_name
     addresses = set()
@@ -292,7 +295,7 @@ def check_dns_resolution(host_name, dns_servers):
             addresses.update(r.address for r in result.rrset)
 
     if not addresses:
-        root_logger.error(
+        logger.error(
             'Could not resolve hostname %s using DNS. '
             'Clients may not function properly. '
             'Please check your DNS setup. '
@@ -310,13 +313,12 @@ def check_dns_resolution(host_name, dns_servers):
             continue
         checked.add(address)
         try:
-            root_logger.debug('Check reverse address %s (%s)',
-                              address, host_name)
+            logger.debug('Check reverse address %s (%s)', address, host_name)
             revname = dnsreversename.from_address(address)
             rrset = resolver.query(revname, 'PTR').rrset
         except Exception as e:
-            root_logger.debug('Check failed: %s %s', type(e).__name__, e)
-            root_logger.error(
+            logger.debug('Check failed: %s %s', type(e).__name__, e)
+            logger.error(
                 'Reverse DNS resolution of address %s (%s) failed. '
                 'Clients may not function properly. '
                 'Please check your DNS setup. '
@@ -330,11 +332,11 @@ def check_dns_resolution(host_name, dns_servers):
                 names = [r.target.to_text() for r in rrset]
             else:
                 names = []
-            root_logger.debug(
+            logger.debug(
                 'Address %s resolves to: %s. ', address, ', '.join(names))
             if not rrset or not any(
                     r.target == host_name_obj for r in rrset):
-                root_logger.error(
+                logger.error(
                     'The IP address %s of host %s resolves to: %s. '
                     'Clients may not function properly. '
                     'Please check your DNS setup. '
@@ -455,7 +457,7 @@ def promote_sssd(host_name):
         try:
             sssd.restart()
         except CalledProcessError:
-            root_logger.warning("SSSD service restart was unsuccessful.")
+            logger.warning("SSSD service restart was unsuccessful.")
 
 
 def promote_openldap_conf(hostname, master):
@@ -497,7 +499,7 @@ def promote_openldap_conf(hostname, master):
         ldap_change_conf.newConf(ldap_conf, new_opts)
         ldap_change_conf.changeConf(ldap_conf, change_opts)
     except Exception as e:
-        root_logger.info("Failed to update {}: {}".format(ldap_conf, e))
+        logger.info("Failed to update %s: %s", ldap_conf, e)
 
 
 @contextlib.contextmanager
@@ -610,7 +612,7 @@ def check_domain_level_is_supported(current):
                    "raised before installing a replica with "
                    "this version is allowed to be installed "
                    "within this domain.")
-        root_logger.error(message)
+        logger.error("%s", message)
         raise ScriptError(message, rval=3)
 
 
@@ -622,7 +624,7 @@ def enroll_dl0_replica(installer, fstore, remote_api, debug=False):
         * configure client-like /etc/krb5.conf to enable GSSAPI auth further
           down the replica installation
     """
-    root_logger.info("Enrolling host to IPA domain")
+    logger.info("Enrolling host to IPA domain")
     config = installer._config
     hostname = config.host_name
 
@@ -749,7 +751,7 @@ def install_check(installer):
                     "Could not find a suitable server cert in import in %s" %
                     pkcs12_info[0])
         except Exception as e:
-            root_logger.error('%s', e)
+            logger.error('%s', e)
             raise RuntimeError(
                 "Server cert is not valid. Please run ipa-replica-prepare to "
                 "create a new replica file.")
@@ -777,8 +779,8 @@ def install_check(installer):
 
         # Check that we don't already have a replication agreement
         if replman.get_replication_agreement(config.host_name):
-            root_logger.info('Error: A replication agreement for this '
-                             'host already exists.')
+            logger.info('Error: A replication agreement for this '
+                        'host already exists.')
             msg = ("A replication agreement for this host already exists. "
                    "It needs to be removed.\n"
                    "Run this on the master that generated the info file:\n"
@@ -802,8 +804,8 @@ def install_check(installer):
         except errors.NotFound:
             pass
         else:
-            root_logger.info('Error: Host %s already exists on the master '
-                             'server.' % config.host_name)
+            logger.info('Error: Host %s already exists on the master '
+                        'server.', config.host_name)
             msg = ("The host %s already exists on the master server.\n"
                    "You should remove it before proceeding:\n"
                    "    %% ipa host-del %s" %
@@ -814,7 +816,7 @@ def install_check(installer):
         if dns_masters:
             if not options.no_host_dns:
                 master = config.master_host_name
-                root_logger.debug('Check forward/reverse DNS resolution')
+                logger.debug('Check forward/reverse DNS resolution')
                 resolution_ok = (
                     check_dns_resolution(master, dns_masters) and
                     check_dns_resolution(config.host_name, dns_masters))
@@ -822,8 +824,8 @@ def install_check(installer):
                     if not ipautil.user_input("Continue?", False):
                         raise ScriptError(rval=0)
         else:
-            root_logger.debug('No IPA DNS servers, '
-                              'skipping forward/reverse resolution check')
+            logger.debug('No IPA DNS servers, '
+                         'skipping forward/reverse resolution check')
 
         kra_enabled = remote_api.Command.kra_is_enabled()['result']
 
@@ -949,7 +951,7 @@ def promotion_check_ipa_domain(master_ldap_conn, basedn):
         raise RuntimeError('IPA domain not found in LDAP.')
 
     if len(entry['associatedDomain']) > 1:
-        root_logger.critical(
+        logger.critical(
             "Multiple IPA domains found. We are so sorry :-(, you are "
             "probably experiencing this bug "
             "https://fedorahosted.org/freeipa/ticket/5976. Please contact us "
@@ -1200,13 +1202,13 @@ def promote_check(installer):
                    "Upgrade the peer master or use the ipa-replica-prepare "
                    "command on the master and use a prep file to install "
                    "this replica.")
-            root_logger.error(msg)
+            logger.error("%s", msg)
             raise ScriptError(rval=3)
 
         dns_masters = remote_api.Object['dnsrecord'].get_dns_masters()
         if dns_masters:
             if not options.no_host_dns:
-                root_logger.debug('Check forward/reverse DNS resolution')
+                logger.debug('Check forward/reverse DNS resolution')
                 resolution_ok = (
                     check_dns_resolution(config.master_host_name,
                                          dns_masters) and
@@ -1215,8 +1217,8 @@ def promote_check(installer):
                     if not ipautil.user_input("Continue?", False):
                         raise ScriptError(rval=0)
         else:
-            root_logger.debug('No IPA DNS servers, '
-                              'skipping forward/reverse resolution check')
+            logger.debug('No IPA DNS servers, '
+                         'skipping forward/reverse resolution check')
 
         entry_attrs = conn.get_ipa_config()
         subject_base = entry_attrs.get('ipacertificatesubjectbase', [None])[0]
@@ -1230,20 +1232,20 @@ def promote_check(installer):
             config.ca_host_name = ca_host
             ca_enabled = True
             if options.dirsrv_cert_files:
-                root_logger.error("Certificates could not be provided when "
-                                  "CA is present on some master.")
+                logger.error("Certificates could not be provided when "
+                             "CA is present on some master.")
                 raise ScriptError(rval=3)
         else:
             if options.setup_ca:
-                root_logger.error("The remote master does not have a CA "
-                                  "installed, can't set up CA")
+                logger.error("The remote master does not have a CA "
+                             "installed, can't set up CA")
                 raise ScriptError(rval=3)
             ca_enabled = False
             if not options.dirsrv_cert_files:
-                root_logger.error("Cannot issue certificates: a CA is not "
-                                  "installed. Use the --http-cert-file, "
-                                  "--dirsrv-cert-file options to provide "
-                                  "custom certificates.")
+                logger.error("Cannot issue certificates: a CA is not "
+                             "installed. Use the --http-cert-file, "
+                             "--dirsrv-cert-file options to provide "
+                             "custom certificates.")
                 raise ScriptError(rval=3)
 
         kra_host = service.find_providing_server(
@@ -1253,8 +1255,8 @@ def promote_check(installer):
             kra_enabled = True
         else:
             if options.setup_kra:
-                root_logger.error("There is no KRA server in the domain, "
-                                  "can't setup a KRA clone")
+                logger.error("There is no KRA server in the domain, "
+                             "can't setup a KRA clone")
                 raise ScriptError(rval=3)
             kra_enabled = False
 
@@ -1285,14 +1287,14 @@ def promote_check(installer):
             adtrust.install_check(False, options, remote_api)
 
     except errors.ACIError:
-        root_logger.debug(traceback.format_exc())
+        logger.debug("%s", traceback.format_exc())
         raise ScriptError("\nInsufficient privileges to promote the server."
                           "\nPossible issues:"
                           "\n- A user has insufficient privileges"
                           "\n- This client has insufficient privileges "
                           "to become an IPA replica")
     except errors.LDAPError:
-        root_logger.debug(traceback.format_exc())
+        logger.debug("%s", traceback.format_exc())
         raise ScriptError("\nUnable to connect to LDAP server %s" %
                           config.master_host_name)
     finally:

ipaserver/install/service.py

@@ -17,6 +17,7 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
+import logging
 import sys
 import os
 import pwd
@@ -30,12 +31,12 @@ import six
 from ipalib.install import certstore, sysrestore
 from ipapython import ipautil
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 from ipapython import kerberos
 from ipalib import api, errors
 from ipaplatform import services
 from ipaplatform.paths import paths
 
+logger = logging.getLogger(__name__)
 
 if six.PY3:
     unicode = str
@@ -60,7 +61,7 @@ SERVICE_LIST = {
 }
 
 def print_msg(message, output_fd=sys.stdout):
-    root_logger.debug(message)
+    logger.debug("%s", message)
     output_fd.write(message)
     output_fd.write("\n")
     output_fd.flush()
@@ -184,7 +185,7 @@ def set_service_entry_config(name, fqdn, config_values,
         existing_values = entry.get('ipaConfigString', [])
         for value in config_values:
             if case_insensitive_attr_has_value(existing_values, value):
-                root_logger.debug(
+                logger.debug(
                     "service %s: config string %s already set", name, value)
 
             entry.setdefault('ipaConfigString', []).append(value)
@@ -192,15 +193,15 @@ def set_service_entry_config(name, fqdn, config_values,
         try:
             api.Backend.ldap2.update_entry(entry)
         except errors.EmptyModlist:
-            root_logger.debug(
+            logger.debug(
                 "service %s has already enabled config values %s", name,
                 config_values)
             return
         except:
-            root_logger.debug("failed to set service %s config values", name)
+            logger.debug("failed to set service %s config values", name)
             raise
 
-        root_logger.debug("service %s has all config values set", name)
+        logger.debug("service %s has all config values set", name)
         return
 
     entry = api.Backend.ldap2.make_entry(
@@ -213,7 +214,7 @@ def set_service_entry_config(name, fqdn, config_values,
     try:
         api.Backend.ldap2.add_entry(entry)
     except (errors.DuplicateEntry) as e:
-        root_logger.debug("failed to add service entry %s", name)
+        logger.debug("failed to add service entry %s", name)
         raise e
 
 
@@ -307,7 +308,7 @@ class Service(object):
             try:
                 ipautil.run(args, nolog=nologlist)
             except ipautil.CalledProcessError as e:
-                root_logger.critical("Failed to load %s: %s" % (ldif, str(e)))
+                logger.critical("Failed to load %s: %s", ldif, str(e))
                 if raise_on_err:
                     raise
         finally:
@@ -373,7 +374,8 @@ class Service(object):
         try:
             api.Backend.ldap2.update_entry(entry)
         except Exception as e:
-            root_logger.critical("Could not add certificate to service %s entry: %s" % (self.principal, str(e)))
+            logger.critical("Could not add certificate to service %s entry: "
+                            "%s", self.principal, str(e))
 
     def import_ca_certs(self, db, ca_is_configured, conn=None):
         if conn is None:
@@ -494,7 +496,7 @@ class Service(object):
             method()
             e = datetime.datetime.now()
             d = e - s
-            root_logger.debug("  duration: %d seconds" % d.seconds)
+            logger.debug("  duration: %d seconds", d.seconds)
 
         step = 0
         steps_iter = iter(self.steps)
@@ -507,7 +509,7 @@ class Service(object):
             if not (isinstance(e, SystemExit) and
                     e.code == 0):  # pylint: disable=no-member
                 # show the traceback, so it's not lost if cleanup method fails
-                root_logger.debug("%s" % traceback.format_exc())
+                logger.debug("%s", traceback.format_exc())
                 self.print_msg('  [error] %s: %s' % (type(e).__name__, e))
 
                 # run through remaining methods marked run_after_failure
@@ -551,7 +553,7 @@ class Service(object):
                 base_dn=entry_dn,
                 scope=api.Backend.ldap2.SCOPE_BASE)
         except errors.NotFound:
-            root_logger.debug("service %s startup entry already disabled", name)
+            logger.debug("service %s startup entry already disabled", name)
             return
 
         assert len(entries) == 1  # only one entry is expected
@@ -568,10 +570,10 @@ class Service(object):
         except errors.EmptyModlist:
             pass
         except:
-            root_logger.debug("failed to disable service %s startup entry", name)
+            logger.debug("failed to disable service %s startup entry", name)
             raise
 
-        root_logger.debug("service %s startup entry disabled", name)
+        logger.debug("service %s startup entry disabled", name)
 
     def ldap_remove_service_container(self, name, fqdn, ldap_suffix):
         entry_dn = DN(('cn', name), ('cn', fqdn), ('cn', 'masters'),
@@ -579,9 +581,9 @@ class Service(object):
         try:
             api.Backend.ldap2.delete_entry(entry_dn)
         except errors.NotFound:
-            root_logger.debug("service %s container already removed", name)
+            logger.debug("service %s container already removed", name)
         else:
-            root_logger.debug("service %s container sucessfully removed", name)
+            logger.debug("service %s container sucessfully removed", name)
 
     def _add_service_principal(self):
         try:

ipaserver/install/sysupgrade.py

@@ -17,12 +17,14 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
+import logging
 import os
 import os.path
 
 from ipalib.install import sysrestore
 from ipaplatform.paths import paths
-from ipapython.ipa_log_manager import root_logger
+
+logger = logging.getLogger(__name__)
 
 STATEFILE_FILE = 'sysupgrade.state'
 
@@ -49,4 +51,4 @@ def remove_upgrade_file():
     try:
         os.remove(os.path.join(paths.STATEFILE_DIR, STATEFILE_FILE))
     except Exception as e:
-        root_logger.debug('Cannot remove sysupgrade state file: %s', e)
+        logger.debug('Cannot remove sysupgrade state file: %s', e)

ipaserver/install/upgradeinstance.py

@@ -17,6 +17,8 @@
 # along with this program.  If not, see <http://www.gnu.org/licenses/>.
 #
 
+import logging
+
 import ldif
 import shutil
 import random
@@ -24,13 +26,14 @@ import traceback
 from ipalib import api
 from ipaplatform.paths import paths
 from ipaplatform import services
-from ipapython.ipa_log_manager import root_logger
 
 from ipaserver.install import installutils
 from ipaserver.install import schemaupdate
 from ipaserver.install import ldapupdate
 from ipaserver.install import service
 
+logger = logging.getLogger(__name__)
+
 DSE = 'dse.ldif'
 
 
@@ -219,10 +222,10 @@ class IPAUpgrade(service.Service):
                 self.files = ld.get_all_files(ldapupdate.UPDATES_DIR)
             self.modified = (ld.update(self.files) or self.modified)
         except ldapupdate.BadSyntax as e:
-            root_logger.error('Bad syntax in upgrade %s', e)
+            logger.error('Bad syntax in upgrade %s', e)
             raise
         except Exception as e:
             # Bad things happened, return gracefully
-            root_logger.error('Upgrade failed with %s', e)
-            root_logger.debug('%s', traceback.format_exc())
+            logger.error('Upgrade failed with %s', e)
+            logger.debug('%s', traceback.format_exc())
             raise RuntimeError(e)

ipaserver/plugins/aci.py

@@ -118,6 +118,7 @@ targetattr REPLACES the current attributes, it does not add to them.
 
 """
 from copy import deepcopy
+import logging
 
 import six
 
@@ -129,12 +130,13 @@ from ipalib import output
 from ipalib import _, ngettext
 from ipalib.plugable import Registry
 from .baseldap import gen_pkey_only_option, pkey_to_value
-from ipapython.ipa_log_manager import root_logger
 from ipapython.dn import DN
 
 if six.PY3:
     unicode = str
 
+logger = logging.getLogger(__name__)
+
 register = Registry()
 
 ACI_NAME_PREFIX_SEP = ":"
@@ -394,7 +396,7 @@ def _convert_strings_to_acis(acistrs):
         try:
             acis.append(ACI(a))
         except SyntaxError:
-            root_logger.warning("Failed to parse: %s" % a)
+            logger.warning("Failed to parse: %s", a)
     return acis
 
 def _find_aci_by_name(acis, aciprefix, aciname):

ipaserver/plugins/cert.py

@@ -49,7 +49,6 @@ from ipalib.request import context
 from ipalib import output
 from ipapython import kerberos
 from ipapython.dn import DN
-from ipapython.ipa_log_manager import root_logger
 from ipaserver.plugins.service import normalize_principal, validate_realm
 
 try:
@@ -514,7 +513,7 @@ class BaseCertObject(Object):
                 except Exception:
                     # Invalid GeneralName (i.e. not a valid X.509 cert);
                     # don't fail but log something about it
-                    root_logger.warning(
+                    logger.warning(
                         "Encountered bad GeneralName; skipping", exc_info=True)
 
         serial_number = obj.get('serial_number')

ipaserver/plugins/trust.py

@@ -39,7 +39,6 @@ from .baseldap import (
 from .dns import dns_container_exists
 from ipapython.dn import DN
 from ipapython.ipautil import realm_to_suffix
-from ipapython.ipa_log_manager import root_logger
 from ipalib import api, Str, StrEnum, Password, Bool, _, ngettext, Int, Flag
 from ipalib import Command
 from ipalib import errors
@@ -394,10 +393,10 @@ def add_range(myapi, trustinstance, range_name, dom_sid, *keys, **options):
 
         if not info_list:
             # We were unable to gain UNIX specific info from the AD
-            root_logger.debug("Unable to gain POSIX info from the AD")
+            logger.debug("Unable to gain POSIX info from the AD")
         else:
             if all(attr in info for attr in required_msSFU_attrs):
-                root_logger.debug("Able to gain POSIX info from the AD")
+                logger.debug("Able to gain POSIX info from the AD")
                 range_type = u'ipa-ad-trust-posix'
 
                 max_uid = info.get('msSFU30MaxUidNumber')