diff --git a/src/cephadm/cephadm b/src/cephadm/cephadm index 870ca6f6d8c..b763f313d6e 100755 --- a/src/cephadm/cephadm +++ b/src/cephadm/cephadm @@ -86,6 +86,7 @@ CUSTOM_PS1 = r'[ceph: \u@\h \W]\$ ' DEFAULT_TIMEOUT = None # in seconds DEFAULT_RETRY = 15 DATEFMT = '%Y-%m-%dT%H:%M:%S.%fZ' +QUIET_LOG_LEVEL = 9 # DEBUG is 10, so using 9 to be lower level than DEBUG logger: logging.Logger = None # type: ignore @@ -238,7 +239,7 @@ class Podman(ContainerEngine): return self._version def get_version(self, ctx: CephadmContext) -> None: - out, _, _ = call_throws(ctx, [self.path, 'version', '--format', '{{.Client.Version}}']) + out, _, _ = call_throws(ctx, [self.path, 'version', '--format', '{{.Client.Version}}'], verbosity=CallVerbosity.QUIET) self._version = _parse_podman_version(out) def __str__(self) -> str: @@ -619,14 +620,14 @@ class Monitoring(object): _, err, code = call(ctx, [ ctx.container_engine.path, 'exec', container_id, cmd, '--version' - ], verbosity=CallVerbosity.DEBUG) + ], verbosity=CallVerbosity.QUIET) if code == 0: break cmd = 'alertmanager' # reset cmd for version extraction else: _, err, code = call(ctx, [ ctx.container_engine.path, 'exec', container_id, cmd, '--version' - ], verbosity=CallVerbosity.DEBUG) + ], verbosity=CallVerbosity.QUIET) if code == 0 and \ err.startswith('%s, version ' % cmd): version = err.split(' ')[2] @@ -717,7 +718,7 @@ class NFSGanesha(object): out, err, code = call(ctx, [ctx.container_engine.path, 'exec', container_id, NFSGanesha.entrypoint, '-v'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if code == 0: match = re.search(r'NFS-Ganesha Release\s*=\s*[V]*([\d.]+)', out) if match: @@ -849,7 +850,7 @@ class CephIscsi(object): out, err, code = call(ctx, [ctx.container_engine.path, 'exec', container_id, '/usr/bin/python3', '-c', "import pkg_resources; print(pkg_resources.require('ceph_iscsi')[0].version)"], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if code == 0: version = out.strip() return version @@ -1483,20 +1484,21 @@ class FileLock(object): try: while True: if not self.is_locked: - logger.debug('Acquiring lock %s on %s', lock_id, - lock_filename) + logger.log(QUIET_LOG_LEVEL, 'Acquiring lock %s on %s', lock_id, + lock_filename) self._acquire() if self.is_locked: - logger.debug('Lock %s acquired on %s', lock_id, - lock_filename) + logger.log(QUIET_LOG_LEVEL, 'Lock %s acquired on %s', lock_id, + lock_filename) break elif timeout >= 0 and time.time() - start_time > timeout: logger.warning('Timeout acquiring lock %s on %s', lock_id, lock_filename) raise Timeout(self._lock_file) else: - logger.debug( + logger.log( + QUIET_LOG_LEVEL, 'Lock %s not acquired on %s, waiting %s seconds ...', lock_id, lock_filename, poll_intervall ) @@ -1575,14 +1577,47 @@ class FileLock(object): # Popen wrappers, lifted from ceph-volume class CallVerbosity(Enum): + ##### + # Format: + # Normal Operation: , Errors: + # + # NOTE: QUIET log level is custom level only used when --verbose is passed + ##### + + # Normal Operation: None, Errors: None SILENT = 0 - # log stdout/stderr to logger.debug - DEBUG = 1 - # On a non-zero exit status, it will forcefully set - # logging ON for the terminal - VERBOSE_ON_FAILURE = 2 - # log at info (instead of debug) level. - VERBOSE = 3 + # Normal Operation: QUIET, Error: QUIET + QUIET = 1 + # Normal Operation: DEBUG, Error: DEBUG + DEBUG = 2 + # Normal Operation: QUIET, Error: INFO + QUIET_UNLESS_ERROR = 3 + # Normal Operation: DEBUG, Error: INFO + VERBOSE_ON_FAILURE = 4 + # Normal Operation: INFO, Error: INFO + VERBOSE = 5 + + def success_log_level(self) -> int: + _verbosity_level_to_log_level = { + self.SILENT: 0, + self.QUIET: QUIET_LOG_LEVEL, + self.DEBUG: logging.DEBUG, + self.QUIET_UNLESS_ERROR: QUIET_LOG_LEVEL, + self.VERBOSE_ON_FAILURE: logging.DEBUG, + self.VERBOSE: logging.INFO + } + return _verbosity_level_to_log_level[self] # type: ignore + + def error_log_level(self) -> int: + _verbosity_level_to_log_level = { + self.SILENT: 0, + self.QUIET: QUIET_LOG_LEVEL, + self.DEBUG: logging.DEBUG, + self.QUIET_UNLESS_ERROR: logging.INFO, + self.VERBOSE_ON_FAILURE: logging.INFO, + self.VERBOSE: logging.INFO + } + return _verbosity_level_to_log_level[self] # type: ignore if sys.version_info < (3, 8): @@ -1730,10 +1765,6 @@ def call(ctx: CephadmContext, async for line in reader: message = line.decode('utf-8') collected.write(message) - if verbosity == CallVerbosity.VERBOSE: - logger.info(prefix + message.rstrip()) - elif verbosity != CallVerbosity.SILENT: - logger.debug(prefix + message.rstrip()) return collected.getvalue() async def run_with_timeout() -> Tuple[str, str, int]: @@ -1755,13 +1786,14 @@ def call(ctx: CephadmContext, return stdout, stderr, returncode stdout, stderr, returncode = async_run(run_with_timeout()) - if returncode != 0 and verbosity == CallVerbosity.VERBOSE_ON_FAILURE: - logger.info('Non-zero exit code %d from %s', - returncode, ' '.join(command)) - for line in stdout.splitlines(): - logger.info(prefix + 'stdout ' + line) - for line in stderr.splitlines(): - logger.info(prefix + 'stderr ' + line) + log_level = verbosity.success_log_level() + if returncode != 0: + log_level = verbosity.error_log_level() + logger.log(log_level, f'Non-zero exit code {returncode} from {" ".join(command)}') + for line in stdout.splitlines(): + logger.log(log_level, prefix + 'stdout ' + line) + for line in stderr.splitlines(): + logger.log(log_level, prefix + 'stderr ' + line) return stdout, stderr, returncode @@ -2438,7 +2470,7 @@ def check_unit(ctx, unit_name): installed = False try: out, err, code = call(ctx, ['systemctl', 'is-enabled', unit_name], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if code == 0: enabled = True installed = True @@ -2452,7 +2484,7 @@ def check_unit(ctx, unit_name): state = 'unknown' try: out, err, code = call(ctx, ['systemctl', 'is-active', unit_name], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) out = out.strip() if out in ['active']: state = 'running' @@ -3115,7 +3147,7 @@ def extract_uid_gid(ctx, img='', file_path='/var/lib/ceph'): image=img, entrypoint='stat', args=['-c', '%u %g', fp] - ).run() + ).run(verbosity=CallVerbosity.QUIET_UNLESS_ERROR) uid, gid = out.split(' ') return int(uid), int(gid) except RuntimeError as e: @@ -4040,10 +4072,10 @@ class CephContainer: ] return ret - def run(self, timeout=DEFAULT_TIMEOUT): - # type: (Optional[int]) -> str + def run(self, timeout=DEFAULT_TIMEOUT, verbosity=CallVerbosity.VERBOSE_ON_FAILURE): + # type: (Optional[int], CallVerbosity) -> str out, _, _ = call_throws(self.ctx, self.run_cmd(), - desc=self.entrypoint, timeout=timeout) + desc=self.entrypoint, timeout=timeout, verbosity=verbosity) return out @@ -4590,7 +4622,7 @@ def _pull_image(ctx, image, insecure=False): cmd_str = ' '.join(cmd) for sleep_secs in [1, 4, 25]: - out, err, ret = call(ctx, cmd) + out, err, ret = call(ctx, cmd, verbosity=CallVerbosity.QUIET_UNLESS_ERROR) if not ret: return @@ -5073,7 +5105,8 @@ def wait_for_mon( timeout = ctx.timeout if ctx.timeout else 60 # seconds out, err, ret = call(ctx, c.run_cmd(), desc=c.entrypoint, - timeout=timeout) + timeout=timeout, + verbosity=CallVerbosity.QUIET_UNLESS_ERROR) return ret == 0 is_available(ctx, 'mon', is_mon_available) @@ -5100,7 +5133,9 @@ def create_mgr( # type: () -> bool timeout = ctx.timeout if ctx.timeout else 60 # seconds try: - out = clifunc(['status', '-f', 'json-pretty'], timeout=timeout) + out = clifunc(['status', '-f', 'json-pretty'], + timeout=timeout, + verbosity=CallVerbosity.QUIET_UNLESS_ERROR) j = json.loads(out) return j.get('mgrmap', {}).get('available', False) except Exception as e: @@ -5543,8 +5578,8 @@ def command_bootstrap(ctx): tmp_config = write_tmp(config, uid, gid) # a CLI helper to reduce our typing - def cli(cmd, extra_mounts={}, timeout=DEFAULT_TIMEOUT): - # type: (List[str], Dict[str, str], Optional[int]) -> str + def cli(cmd, extra_mounts={}, timeout=DEFAULT_TIMEOUT, verbosity=CallVerbosity.VERBOSE_ON_FAILURE): + # type: (List[str], Dict[str, str], Optional[int], CallVerbosity) -> str mounts = { log_dir: '/var/log/ceph:z', admin_keyring.name: '/etc/ceph/ceph.client.admin.keyring:z', @@ -5559,7 +5594,7 @@ def command_bootstrap(ctx): entrypoint='/usr/bin/ceph', args=cmd, volume_mounts=mounts, - ).run(timeout=timeout) + ).run(timeout=timeout, verbosity=verbosity) wait_for_mon(ctx, mon_id, mon_dir, admin_keyring.name, tmp_config.name) @@ -5596,9 +5631,9 @@ def command_bootstrap(ctx): # stat' command first, then fall back to 'mgr dump' if # necessary try: - j = json_loads_retry(lambda: cli(['mgr', 'stat'])) + j = json_loads_retry(lambda: cli(['mgr', 'stat'], verbosity=CallVerbosity.QUIET_UNLESS_ERROR)) except Exception: - j = json_loads_retry(lambda: cli(['mgr', 'dump'])) + j = json_loads_retry(lambda: cli(['mgr', 'dump'], verbosity=CallVerbosity.QUIET_UNLESS_ERROR)) epoch = j['epoch'] # wait for mgr to have it @@ -6090,7 +6125,7 @@ def command_ceph_volume(ctx): volume_mounts=mounts, ) - out, err, code = call_throws(ctx, c.run_cmd()) + out, err, code = call_throws(ctx, c.run_cmd(), verbosity=CallVerbosity.QUIET_UNLESS_ERROR) if not code: print(out) @@ -6155,7 +6190,7 @@ def _list_ipv4_networks(ctx: CephadmContext) -> Dict[str, Dict[str, Set[str]]]: execstr: Optional[str] = find_executable('ip') if not execstr: raise FileNotFoundError("unable to find 'ip' command") - out, _, _ = call_throws(ctx, [execstr, 'route', 'ls']) + out, _, _ = call_throws(ctx, [execstr, 'route', 'ls'], verbosity=CallVerbosity.QUIET_UNLESS_ERROR) return _parse_ipv4_route(out) @@ -6183,8 +6218,8 @@ def _list_ipv6_networks(ctx: CephadmContext) -> Dict[str, Dict[str, Set[str]]]: execstr: Optional[str] = find_executable('ip') if not execstr: raise FileNotFoundError("unable to find 'ip' command") - routes, _, _ = call_throws(ctx, [execstr, '-6', 'route', 'ls']) - ips, _, _ = call_throws(ctx, [execstr, '-6', 'addr', 'ls']) + routes, _, _ = call_throws(ctx, [execstr, '-6', 'route', 'ls'], verbosity=CallVerbosity.QUIET_UNLESS_ERROR) + ips, _, _ = call_throws(ctx, [execstr, '-6', 'addr', 'ls'], verbosity=CallVerbosity.QUIET_UNLESS_ERROR) return _parse_ipv6_route(routes, ips) @@ -6290,14 +6325,14 @@ def list_daemons(ctx, detail=True, legacy_dir=None): out, err, code = call( ctx, [container_path, 'stats', '--format', '{{.ID}},{{.MemUsage}}', '--no-stream'], - verbosity=CallVerbosity.DEBUG + verbosity=CallVerbosity.QUIET ) seen_memusage_cid_len, seen_memusage = _parse_mem_usage(code, out) out, err, code = call( ctx, [container_path, 'stats', '--format', '{{.ID}},{{.CPUPerc}}', '--no-stream'], - verbosity=CallVerbosity.DEBUG + verbosity=CallVerbosity.QUIET ) seen_cpuperc_cid_len, seen_cpuperc = _parse_cpu_perc(code, out) @@ -6326,7 +6361,7 @@ def list_daemons(ctx, detail=True, legacy_dir=None): try: out, err, code = call(ctx, ['ceph', '-v'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if not code and out.startswith('ceph version '): host_version = out.split(' ')[2] except Exception: @@ -6377,7 +6412,7 @@ def list_daemons(ctx, detail=True, legacy_dir=None): container_path, 'image', 'inspect', image_id, '--format', '{{.RepoDigests}}', ], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if not code: image_digests = list(set(map( normalize_image_digest, @@ -6396,7 +6431,7 @@ def list_daemons(ctx, detail=True, legacy_dir=None): out, err, code = call(ctx, [container_path, 'exec', container_id, 'ceph', '-v'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if not code and \ out.startswith('ceph version '): version = out.split(' ')[2] @@ -6405,7 +6440,7 @@ def list_daemons(ctx, detail=True, legacy_dir=None): out, err, code = call(ctx, [container_path, 'exec', container_id, 'grafana-server', '-v'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if not code and \ out.startswith('Version '): version = out.split(' ')[1] @@ -6421,7 +6456,7 @@ def list_daemons(ctx, detail=True, legacy_dir=None): out, err, code = call(ctx, [container_path, 'exec', container_id, 'haproxy', '-v'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if not code and \ out.startswith('HA-Proxy version '): version = out.split(' ')[2] @@ -6430,7 +6465,7 @@ def list_daemons(ctx, detail=True, legacy_dir=None): out, err, code = call(ctx, [container_path, 'exec', container_id, 'keepalived', '--version'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) if not code and \ err.startswith('Keepalived '): version = err.split(' ')[1] @@ -6540,7 +6575,7 @@ def get_container_stats(ctx: CephadmContext, container_path: str, fsid: str, dae '--format', '{{.Id}},{{.Config.Image}},{{.Image}},{{.Created}},{{index .Config.Labels "io.ceph.version"}}', name ] - out, err, code = call(ctx, cmd, verbosity=CallVerbosity.DEBUG) + out, err, code = call(ctx, cmd, verbosity=CallVerbosity.QUIET) if not code: break return out, err, code @@ -8632,7 +8667,7 @@ class HostFacts(): security = {} try: out, err, code = call(self.ctx, ['sestatus'], - verbosity=CallVerbosity.DEBUG) + verbosity=CallVerbosity.QUIET) security['type'] = 'SELinux' status, mode, policy = '', '', '' for line in out.split('\n'): @@ -9542,6 +9577,7 @@ def cephadm_init_logging(ctx: CephadmContext, args: List[str]) -> None: """Configure the logging for cephadm as well as updating the system to have the expected log dir and logrotate configuration. """ + logging.addLevelName(QUIET_LOG_LEVEL, 'QUIET') global logger if not os.path.exists(LOG_DIR): os.makedirs(LOG_DIR) @@ -9552,6 +9588,7 @@ def cephadm_init_logging(ctx: CephadmContext, args: List[str]) -> None: dictConfig(logging_config) logger = logging.getLogger() + logger.setLevel(QUIET_LOG_LEVEL) if not os.path.exists(ctx.logrotate_dir + '/cephadm'): with open(ctx.logrotate_dir + '/cephadm', 'w') as f: @@ -9568,8 +9605,8 @@ def cephadm_init_logging(ctx: CephadmContext, args: List[str]) -> None: if ctx.verbose: for handler in logger.handlers: - if handler.name == 'console': - handler.setLevel(logging.DEBUG) + if handler.name in ['console', 'log_file', 'console_stdout']: + handler.setLevel(QUIET_LOG_LEVEL) logger.debug('%s\ncephadm %s' % ('-' * 80, args))