From 01df5d52c132c4874b2cdfff6b7e41fdd48ed07d Mon Sep 17 00:00:00 2001 From: Simon Pichugin Date: Jan 03 2019 16:05:06 +0000 Subject: Issue 49938 - lib389 - Clean up CLI logging Description: We set DEBUG log level if self.verbose is true. So we should properly log the information through self.log.debug when it is necessary. https://pagure.io/389-ds-base/issue/49938 Reviewed by: mreynolds (Thanks!) --- diff --git a/src/lib389/lib389/__init__.py b/src/lib389/lib389/__init__.py index 62fc324..78221df 100644 --- a/src/lib389/lib389/__init__.py +++ b/src/lib389/lib389/__init__.py @@ -536,8 +536,7 @@ class DirSrv(SimpleLDAPObject, object): if self.ldapi_enabled == 'on' and self.ldapi_socket is not None: self.ldapi_autobind = args.get(SER_LDAPI_AUTOBIND, 'off') self.isLocal = True - if self.verbose: - self.log.info("Allocate %s with %s", self.__class__, self.ldapi_socket) + self.log.debug("Allocate %s with %s", self.__class__, self.ldapi_socket) # Settings from args of server attributes self.strict_hostname = args.get(SER_STRICT_HOSTNAME_CHECKING, False) if self.strict_hostname is True: @@ -573,11 +572,10 @@ class DirSrv(SimpleLDAPObject, object): self.agmt = {} self.state = DIRSRV_STATE_ALLOCATED - if self.verbose: - self.log.info("Allocate %s with %s:%s", - self.__class__, - self.host, - (self.sslport or self.port)) + self.log.debug("Allocate %s with %s:%s", + self.__class__, + self.host, + (self.sslport or self.port)) def clone(self, args_instance={}): """ @@ -782,10 +780,9 @@ class DirSrv(SimpleLDAPObject, object): privconfig_head = os.path.join(os.getenv('HOME'), ENV_LOCAL_DIR) if not os.path.isdir(sysconfig_head): privconfig_head = None - if self.verbose: - self.log.info("dir (sys) : %s", sysconfig_head) - if privconfig_head and self.verbose: - self.log.info("dir (priv): %s", privconfig_head) + self.log.debug("dir (sys) : %s", sysconfig_head) + if privconfig_head: + self.log.debug("dir (priv): %s", privconfig_head) # list of the found instances instances = [] @@ -802,10 +799,10 @@ class DirSrv(SimpleLDAPObject, object): pattern = "%s*" % os.path.join(privconfig_head, DEFAULT_ENV_HEAD) found = search_dir(instances, pattern, serverid) - if self.verbose and len(instances) > 0: - self.log.info("List from %s", privconfig_head) + if len(instances) > 0: + self.log.debug("List from %s", privconfig_head) for instance in instances: - self.log.info("list instance %r\n", instance) + self.log.debug("list instance %r\n", instance) if found: assert len(instances) == 1 else: @@ -818,10 +815,10 @@ class DirSrv(SimpleLDAPObject, object): pattern = "%s*" % os.path.join(sysconfig_head, DEFAULT_ENV_HEAD) search_dir(instances, pattern, serverid) - if self.verbose and len(instances) > 0: - self.log.info("List from %s", privconfig_head) + if len(instances) > 0: + self.log.debug("List from %s", privconfig_head) for instance in instances: - self.log.info("list instance %r\n", instance) + self.log.debug("list instance %r\n", instance) else: # all instances must be retrieved @@ -829,17 +826,17 @@ class DirSrv(SimpleLDAPObject, object): pattern = "%s*" % os.path.join(privconfig_head, DEFAULT_ENV_HEAD) search_dir(instances, pattern) - if self.verbose and len(instances) > 0: - self.log.info("List from %s", privconfig_head) + if len(instances) > 0: + self.log.debug("List from %s", privconfig_head) for instance in instances: - self.log.info("list instance %r\n", instance) + self.log.debug("list instance %r\n", instance) pattern = "%s*" % os.path.join(sysconfig_head, DEFAULT_ENV_HEAD) search_dir(instances, pattern) - if self.verbose and len(instances) > 0: - self.log.info("List from %s", privconfig_head) + if len(instances) > 0: + self.log.debug("List from %s", privconfig_head) for instance in instances: - self.log.info("list instance %r\n", instance) + self.log.debug("list instance %r\n", instance) return instances @@ -1141,8 +1138,7 @@ class DirSrv(SimpleLDAPObject, object): elif self.can_autobind(): # Connect via ldapi, and autobind. # do nothing: the bind is complete. - if self.verbose: - self.log.info("open(): Using root autobind ...") + self.log.debug("open(): Using root autobind ...") sasl_auth = ldap.sasl.external() self.sasl_interactive_bind_s("", sasl_auth) @@ -1163,8 +1159,7 @@ class DirSrv(SimpleLDAPObject, object): """ Authenticated, now finish the initialization """ - if self.verbose: - self.log.info("open(): bound as %s", self.binddn) + self.log.debug("open(): bound as %s", self.binddn) if not connOnly: self.__initPart2() self.state = DIRSRV_STATE_ONLINE @@ -1808,8 +1803,7 @@ class DirSrv(SimpleLDAPObject, object): XXX This cannot return None """ - if self.verbose: - self.log.debug("Retrieving entry with %r", [args]) + self.log.debug("Retrieving entry with %r", [args]) if len(args) == 1 and 'scope' not in kwargs: args += (ldap.SCOPE_BASE, ) @@ -1819,8 +1813,7 @@ class DirSrv(SimpleLDAPObject, object): if not obj: raise NoSuchEntryError("no such entry for %r", [args]) - if self.verbose: - self.log.info("Retrieved entry %s", obj) + self.log.debug("Retrieved entry %s", obj) if isinstance(obj, Entry): return obj else: # assume list/tuple @@ -2572,11 +2565,10 @@ class DirSrv(SimpleLDAPObject, object): for ent in (conent, polent, tement, cosent): try: self.add_s(ent) - if self.verbose: - print("created subtree pwpolicy entry", ent.dn) + self.log.debug("created subtree pwpolicy entry", ent.dn) except ldap.ALREADY_EXISTS: - print("subtree pwpolicy entry", ent.dn, - "already exists - skipping") + self.log.debug("subtree pwpolicy entry", ent.dn, + "already exists - skipping") self.setPwdPolicy({'nsslapd-pwpolicy-local': 'on'}) self.setDNPwdPolicy(poldn, pwdpolicy, **pwdargs) @@ -2595,10 +2587,9 @@ class DirSrv(SimpleLDAPObject, object): for ent in (conent, polent): try: self.add_s(ent) - if self.verbose: - print("created user pwpolicy entry", ent.dn) + self.log.debug("created user pwpolicy entry", ent.dn) except ldap.ALREADY_EXISTS: - print("user pwpolicy entry", ent.dn, + self.log.debug("user pwpolicy entry", ent.dn, "already exists - skipping") mod = [(ldap.MOD_REPLACE, 'pwdpolicysubentry', poldn)] self.modify_s(user, mod) diff --git a/src/lib389/lib389/instance/setup.py b/src/lib389/lib389/instance/setup.py index 1b3bf0d..d8fc2a8 100644 --- a/src/lib389/lib389/instance/setup.py +++ b/src/lib389/lib389/instance/setup.py @@ -105,8 +105,7 @@ class SetupDs(object): self.dryrun = dryrun # Expose the logger to our children. self.log = log.getChild('SetupDs') - if self.verbose: - self.log.info('Running setup with verbose') + self.log.debug('Running setup with verbose') # This will indicate that start / stop / status should bypass systemd. self.containerised = containerised @@ -143,16 +142,14 @@ class SetupDs(object): general_options.verify() general = general_options.collect() - if self.verbose: - self.log.info("Configuration general %s", general) + self.log.debug("Configuration general %s", general) slapd_options = Slapd2Base(self.log) slapd_options.parse_inf_config(config) slapd_options.verify() slapd = slapd_options.collect() - if self.verbose: - self.log.info("Configuration slapd %s", slapd) + self.log.debug("Configuration slapd %s", slapd) backends = [] for section in config.sections(): @@ -187,8 +184,7 @@ class SetupDs(object): # Add this backend to the list backends.append(be) - if self.verbose: - self.log.info("Configuration backends %s", backends) + self.log.debug("Configuration backends %s", backends) return (general, slapd, backends) @@ -598,15 +594,13 @@ class SetupDs(object): self.log.info("\nStarting installation...") # Check we have privs to run - if self.verbose: - self.log.info("READY: Preparing installation for %s...", slapd['instance_name']) + self.log.debug("READY: Preparing installation for %s...", slapd['instance_name']) self._prepare_ds(general, slapd, backends) # Call our child api to prepare itself. self._prepare(extra) - if self.verbose: - self.log.info("READY: Beginning installation for %s...", slapd['instance_name']) + self.log.debug("READY: Beginning installation for %s...", slapd['instance_name']) if self.dryrun: self.log.info("NOOP: Dry run requested") @@ -621,9 +615,8 @@ class SetupDs(object): # Call the child api to do anything it needs. self._install(extra) - if self.verbose: - self.log.info("FINISH: Completed installation for %s", slapd['instance_name']) - else: + self.log.debug("FINISH: Completed installation for %s", slapd['instance_name']) + if not self.verbose: self.log.info("Completed installation for %s", slapd['instance_name']) def _install_ds(self, general, slapd, backends): @@ -661,8 +654,7 @@ class SetupDs(object): # Create all the needed paths # we should only need to make bak_dir, cert_dir, config_dir, db_dir, ldif_dir, lock_dir, log_dir, run_dir? for path in ('backup_dir', 'cert_dir', 'config_dir', 'db_dir', 'ldif_dir', 'lock_dir', 'log_dir', 'run_dir'): - if self.verbose: - self.log.info("ACTION: creating %s", slapd[path]) + self.log.debug("ACTION: creating %s", slapd[path]) try: os.umask(0o007) # For parent dirs that get created -> sets 770 for perms os.makedirs(slapd[path], mode=0o770) @@ -731,15 +723,13 @@ class SetupDs(object): ds_suffix = backends[0]['nsslapd-suffix'] # Create certdb in sysconfidir - if self.verbose: - self.log.info("ACTION: Creating certificate database is %s", slapd['cert_dir']) + self.log.debug("ACTION: Creating certificate database is %s", slapd['cert_dir']) # Create dse.ldif with a temporary root password. # The template is in slapd['data_dir']/dirsrv/data/template-dse.ldif # Variables are done with %KEY%. # You could cheat and read it in, do a replace of % to { and } then use format? - if self.verbose: - self.log.info("ACTION: Creating dse.ldif") + self.log.debug("ACTION: Creating dse.ldif") dse = "" with open(os.path.join(slapd['data_dir'], 'dirsrv', 'data', 'template-dse.ldif')) as template_dse: for line in template_dse.readlines(): diff --git a/src/lib389/lib389/ldclt.py b/src/lib389/lib389/ldclt.py index 133f460..f220d60 100644 --- a/src/lib389/lib389/ldclt.py +++ b/src/lib389/lib389/ldclt.py @@ -7,6 +7,7 @@ # --- END COPYRIGHT BLOCK --- import subprocess +from lib389.utils import format_cmd_list """ This class will allow general usage of ldclt. @@ -82,18 +83,16 @@ loginShell: /bin/false "object=/tmp/ldclt_template_lib389.ldif,rdn=uid:user[A=INCRNNOLOOP(%s;%s;%s)]" % (min, max, digits), ] result = None - if self.verbose: - self.log.info("ldclt begining user create ...") - self.log.info(' '.join(cmd)) + self.log.debug("ldclt begining user create ...") + self.log.debug(format_cmd_list(cmd)) try: result = subprocess.check_output(cmd) # If verbose, capture / log the output. except subprocess.CalledProcessError as e: - print(' '.join(cmd)) + print(format_cmd_list(cmd)) print(result) raise(e) - if self.verbose: - self.log.info(result) + self.log.debug(result) def bind_loadtest(self, subtree, min=1000, max=9999, rounds=3): # The bind users will be uid=userXXXX @@ -116,15 +115,13 @@ loginShell: /bin/false 'bindonly', ] result = None - if self.verbose: - self.log.info("ldclt loadtest ...") - self.log.info(' '.join(cmd)) + self.log.debug("ldclt loadtest ...") + self.log.debug(format_cmd_list(cmd)) try: result = subprocess.check_output(cmd) # If verbose, capture / log the output. except subprocess.CalledProcessError as e: - print(' '.join(cmd)) + print(format_cmd_list(cmd)) print(result) raise(e) - if self.verbose: - self.log.info(result) + self.log.debug(result) diff --git a/src/lib389/lib389/replica.py b/src/lib389/lib389/replica.py index ca18374..cc695c7 100644 --- a/src/lib389/lib389/replica.py +++ b/src/lib389/lib389/replica.py @@ -591,23 +591,23 @@ class ReplicaLegacy(object): status = entry.nsds5ReplicaLastInitStatus if not refresh: # done - check status if not status: - print("No status yet") + self.log.info("No status yet") elif status.find(ensure_bytes("replica busy")) > -1: - print("Update failed - replica busy - status", status) + self.log.info("Update failed - replica busy - status", status) done = True hasError = 2 elif status.find(ensure_bytes("Total update succeeded")) > -1: - print("Update succeeded: status ", status) + self.log.info("Update succeeded: status ", status) done = True elif inprogress.lower() == ensure_bytes('true'): - print("Update in progress yet not in progress: status ", + self.log.info("Update in progress yet not in progress: status ", status) else: - print("Update failed: status", status) + self.log.info("Update failed: status", status) hasError = 1 done = True - elif self.verbose: - print("Update in progress: status", status) + else: + self.log.debug("Update in progress: status", status) return done, hasError