From 135cf3dca017cdc753eb9a81651f61f4c24b0e5f Mon Sep 17 00:00:00 2001 From: Gil Bregman Date: Tue, 30 Jul 2024 11:04:07 +0300 Subject: [PATCH] Set SPDK log level on startup and do not lock OMAP for SPDK log commands. Fixes #771 Fixes #772 Signed-off-by: Gil Bregman --- ceph-nvmeof.conf | 4 +- control/grpc.py | 130 ++++++++++++++++++++++------------------------ control/server.py | 18 +++++-- 3 files changed, 79 insertions(+), 73 deletions(-) diff --git a/ceph-nvmeof.conf b/ceph-nvmeof.conf index 1f50c7c7a..48226def0 100644 --- a/ceph-nvmeof.conf +++ b/ceph-nvmeof.conf @@ -65,7 +65,9 @@ tgt_path = /usr/local/bin/nvmf_tgt #rpc_socket_name = spdk.sock #tgt_cmd_extra_args = --env-context="--no-huge -m1024" --iova-mode=va timeout = 60.0 -log_level = WARNING +log_level = +print_level = +protocol_log_level = WARNING # Example value: -m 0x3 -L all # tgt_cmd_extra_args = diff --git a/control/grpc.py b/control/grpc.py index 70076b76b..ee880cd01 100644 --- a/control/grpc.py +++ b/control/grpc.py @@ -2479,29 +2479,27 @@ def get_spdk_nvmf_log_flags_and_level_safe(self, request, context): peer_msg = self.get_peer_message(context) self.logger.info(f"Received request to get SPDK nvmf log flags and level{peer_msg}") log_flags = [] - omap_lock = self.omap_lock.get_omap_lock_to_use(context) - with omap_lock: - try: - nvmf_log_flags = {key: value for key, value in rpc_log.log_get_flags( - self.spdk_rpc_client).items() if key.startswith('nvmf')} - for flag, flagvalue in nvmf_log_flags.items(): - pb2_log_flag = pb2.spdk_log_flag_info(name = flag, enabled = flagvalue) - log_flags.append(pb2_log_flag) - spdk_log_level = rpc_log.log_get_level(self.spdk_rpc_client) - spdk_log_print_level = rpc_log.log_get_print_level(self.spdk_rpc_client) - self.logger.debug(f"spdk log flags: {nvmf_log_flags}, " - f"spdk log level: {spdk_log_level}, " - f"spdk log print level: {spdk_log_print_level}") - except Exception as ex: - errmsg = f"Failure getting SPDK log levels and nvmf log flags" - self.logger.exception(errmsg) - errmsg = f"{errmsg}:\n{ex}" - resp = self.parse_json_exeption(ex) - status = errno.ENOKEY - if resp: - status = resp["code"] - errmsg = f"Failure getting SPDK log levels and nvmf log flags: {resp['message']}" - return pb2.spdk_nvmf_log_flags_and_level_info(status = status, error_message = errmsg) + try: + nvmf_log_flags = {key: value for key, value in rpc_log.log_get_flags( + self.spdk_rpc_client).items() if key.startswith('nvmf')} + for flag, flagvalue in nvmf_log_flags.items(): + pb2_log_flag = pb2.spdk_log_flag_info(name = flag, enabled = flagvalue) + log_flags.append(pb2_log_flag) + spdk_log_level = rpc_log.log_get_level(self.spdk_rpc_client) + spdk_log_print_level = rpc_log.log_get_print_level(self.spdk_rpc_client) + self.logger.debug(f"spdk log flags: {nvmf_log_flags}, " + f"spdk log level: {spdk_log_level}, " + f"spdk log print level: {spdk_log_print_level}") + except Exception as ex: + errmsg = f"Failure getting SPDK log levels and nvmf log flags" + self.logger.exception(errmsg) + errmsg = f"{errmsg}:\n{ex}" + resp = self.parse_json_exeption(ex) + status = errno.ENOKEY + if resp: + status = resp["code"] + errmsg = f"Failure getting SPDK log levels and nvmf log flags: {resp['message']}" + return pb2.spdk_nvmf_log_flags_and_level_info(status = status, error_message = errmsg) return pb2.spdk_nvmf_log_flags_and_level_info( nvmf_log_flags=log_flags, @@ -2537,33 +2535,30 @@ def set_spdk_nvmf_logs_safe(self, request, context): self.logger.info(f"Received request to set SPDK nvmf logs: log_level: {log_level}, print_level: {print_level}{peer_msg}") - omap_lock = self.omap_lock.get_omap_lock_to_use(context) - with omap_lock: - try: - nvmf_log_flags = [key for key in rpc_log.log_get_flags(self.spdk_rpc_client).keys() \ - if key.startswith('nvmf')] - ret = [rpc_log.log_set_flag( - self.spdk_rpc_client, flag=flag) for flag in nvmf_log_flags] - self.logger.debug(f"Set SPDK nvmf log flags {nvmf_log_flags} to TRUE: {ret}") - if log_level != None: - ret_log = rpc_log.log_set_level(self.spdk_rpc_client, level=log_level) - self.logger.debug(f"Set log level to {log_level}: {ret_log}") - if print_level != None: - ret_print = rpc_log.log_set_print_level( - self.spdk_rpc_client, level=print_level) - self.logger.debug(f"Set log print level to {print_level}: {ret_print}") - except Exception as ex: - errmsg="Failure setting SPDK log levels" - self.logger.exception(errmsg) - errmsg="{errmsg}:\n{ex}" - for flag in nvmf_log_flags: - rpc_log.log_clear_flag(self.spdk_rpc_client, flag=flag) - resp = self.parse_json_exeption(ex) - status = errno.EINVAL - if resp: - status = resp["code"] - errmsg = f"Failure setting SPDK log levels: {resp['message']}" - return pb2.req_status(status=status, error_message=errmsg) + try: + nvmf_log_flags = [key for key in rpc_log.log_get_flags(self.spdk_rpc_client).keys() if key.startswith('nvmf')] + ret = [rpc_log.log_set_flag( + self.spdk_rpc_client, flag=flag) for flag in nvmf_log_flags] + self.logger.debug(f"Set SPDK nvmf log flags {nvmf_log_flags} to TRUE: {ret}") + if log_level != None: + ret_log = rpc_log.log_set_level(self.spdk_rpc_client, level=log_level) + self.logger.debug(f"Set log level to {log_level}: {ret_log}") + if print_level != None: + ret_print = rpc_log.log_set_print_level( + self.spdk_rpc_client, level=print_level) + self.logger.debug(f"Set log print level to {print_level}: {ret_print}") + except Exception as ex: + errmsg="Failure setting SPDK log levels" + self.logger.exception(errmsg) + errmsg="{errmsg}:\n{ex}" + for flag in nvmf_log_flags: + rpc_log.log_clear_flag(self.spdk_rpc_client, flag=flag) + resp = self.parse_json_exeption(ex) + status = errno.EINVAL + if resp: + status = resp["code"] + errmsg = f"Failure setting SPDK log levels: {resp['message']}" + return pb2.req_status(status=status, error_message=errmsg) status = 0 errmsg = os.strerror(0) @@ -2586,25 +2581,22 @@ def disable_spdk_nvmf_logs_safe(self, request, context): peer_msg = self.get_peer_message(context) self.logger.info(f"Received request to disable SPDK nvmf logs{peer_msg}") - omap_lock = self.omap_lock.get_omap_lock_to_use(context) - with omap_lock: - try: - nvmf_log_flags = [key for key in rpc_log.log_get_flags(self.spdk_rpc_client).keys() \ - if key.startswith('nvmf')] - ret = [rpc_log.log_clear_flag(self.spdk_rpc_client, flag=flag) for flag in nvmf_log_flags] - logs_level = [rpc_log.log_set_level(self.spdk_rpc_client, level='NOTICE'), - rpc_log.log_set_print_level(self.spdk_rpc_client, level='INFO')] - ret.extend(logs_level) - except Exception as ex: - errmsg = f"Failure in disable SPDK nvmf log flags" - self.logger.exception(errmsg) - errmsg = f"{errmsg}:\n{ex}" - resp = self.parse_json_exeption(ex) - status = errno.EINVAL - if resp: - status = resp["code"] - errmsg = f"Failure in disable SPDK nvmf log flags: {resp['message']}" - return pb2.req_status(status=status, error_message=errmsg) + try: + nvmf_log_flags = [key for key in rpc_log.log_get_flags(self.spdk_rpc_client).keys() if key.startswith('nvmf')] + ret = [rpc_log.log_clear_flag(self.spdk_rpc_client, flag=flag) for flag in nvmf_log_flags] + logs_level = [rpc_log.log_set_level(self.spdk_rpc_client, level='NOTICE'), + rpc_log.log_set_print_level(self.spdk_rpc_client, level='INFO')] + ret.extend(logs_level) + except Exception as ex: + errmsg = f"Failure in disable SPDK nvmf log flags" + self.logger.exception(errmsg) + errmsg = f"{errmsg}:\n{ex}" + resp = self.parse_json_exeption(ex) + status = errno.EINVAL + if resp: + status = resp["code"] + errmsg = f"Failure in disable SPDK nvmf log flags: {resp['message']}" + return pb2.req_status(status=status, error_message=errmsg) status = 0 errmsg = os.strerror(0) diff --git a/control/server.py b/control/server.py index 70e52bae4..0bee7abc3 100644 --- a/control/server.py +++ b/control/server.py @@ -200,6 +200,18 @@ def serve(self): else: self.logger.info(f"Prometheus endpoint is disabled. To enable, set the config option 'enable_prometheus_exporter = True'") + # Set SPDK log level + log_level_args = {} + log_level = self.config.get_with_default("spdk", "log_level", None) + print_level = self.config.get_with_default("spdk", "print_level", None) + if log_level: + log_level_args["log_level"] = log_level.upper() + if print_level: + log_level_args["print_level"] = print_level.upper() + if log_level_args: + log_req = pb2.set_spdk_nvmf_logs_req(**log_level_args) + self.gateway_rpc.set_spdk_nvmf_logs(log_req) + def _monitor_client_version(self) -> str: """Return monitor client version string.""" # Get the current SIGCHLD handler @@ -381,7 +393,7 @@ def _start_spdk(self, omap_state): # Initialization timeout = self.config.getfloat_with_default("spdk", "timeout", 60.0) - log_level = self.config.get_with_default("spdk", "log_level", "WARNING") + protocol_log_level = self.config.get_with_default("spdk", "protocol_log_level", "WARNING") # connect timeout: spdk client retries 5 times per sec conn_retries = int(timeout * 5) self.logger.info(f"SPDK process id: {self.spdk_process.pid}") @@ -394,14 +406,14 @@ def _start_spdk(self, omap_state): self.spdk_rpc_socket_path, None, timeout, - log_level=log_level, + log_level=protocol_log_level, conn_retries=conn_retries, ) self.spdk_rpc_ping_client = rpc_client.JSONRPCClient( self.spdk_rpc_socket_path, None, timeout, - log_level=log_level, + log_level=protocol_log_level, conn_retries=conn_retries, ) except Exception: