feat: add trace log level

This commit is contained in:
Xuwznln
2025-08-04 20:27:02 +08:00
parent 5cd0f72fbd
commit 98ce360088
8 changed files with 81 additions and 36 deletions

View File

@@ -166,7 +166,7 @@ class MQTTClient:
status = {"data": device_status.get(device_id, {}), "device_id": device_id, "timestamp": time.time()} status = {"data": device_status.get(device_id, {}), "device_id": device_id, "timestamp": time.time()}
address = f"labs/{MQConfig.lab_id}/devices/" address = f"labs/{MQConfig.lab_id}/devices/"
self.client.publish(address, json.dumps(status), qos=2) self.client.publish(address, json.dumps(status), qos=2)
logger.info(f"Device {device_id} status published: address: {address}, {status}") # logger.info(f"Device {device_id} status published: address: {address}, {status}")
def publish_job_status(self, feedback_data: dict, job_id: str, status: str, return_info: Optional[str] = None): def publish_job_status(self, feedback_data: dict, job_id: str, status: str, return_info: Optional[str] = None):
if self.mqtt_disable: if self.mqtt_disable:

View File

@@ -331,7 +331,7 @@ class VirtualSolidDispenser:
"precision": self.precision "precision": self.precision
} }
self.logger.debug(f"📊 设备信息: 状态={self._status}, 试剂={self._current_reagent}, 加样量={self._dispensed_amount:.6f}g") # self.logger.debug(f"📊 设备信息: 状态={self._status}, 试剂={self._current_reagent}, 加样量={self._dispensed_amount:.6f}g")
return info return info
def __str__(self): def __str__(self):

View File

@@ -321,7 +321,7 @@ class VirtualStirrer:
"min_speed": self._min_speed "min_speed": self._min_speed
} }
self.logger.debug(f"📊 设备信息: 模式={self.operation_mode}, 速度={self.current_speed} RPM, 搅拌={self.is_stirring}") # self.logger.debug(f"📊 设备信息: 模式={self.operation_mode}, 速度={self.current_speed} RPM, 搅拌={self.is_stirring}")
return info return info
def __str__(self): def __str__(self):

View File

@@ -152,11 +152,11 @@ class Registry:
} }
} }
) )
logger.debug(f"[UniLab Registry] ----------Setup----------") logger.trace(f"[UniLab Registry] ----------Setup----------")
self.registry_paths = [Path(path).absolute() for path in self.registry_paths] self.registry_paths = [Path(path).absolute() for path in self.registry_paths]
for i, path in enumerate(self.registry_paths): for i, path in enumerate(self.registry_paths):
sys_path = path.parent sys_path = path.parent
logger.debug(f"[UniLab Registry] Path {i+1}/{len(self.registry_paths)}: {sys_path}") logger.trace(f"[UniLab Registry] Path {i+1}/{len(self.registry_paths)}: {sys_path}")
sys.path.append(str(sys_path)) sys.path.append(str(sys_path))
self.load_device_types(path, complete_registry) self.load_device_types(path, complete_registry)
if BasicConfig.enable_resource_load: if BasicConfig.enable_resource_load:
@@ -215,7 +215,7 @@ class Registry:
yaml.dump(complete_data, f, allow_unicode=True, default_flow_style=False, Dumper=NoAliasDumper) yaml.dump(complete_data, f, allow_unicode=True, default_flow_style=False, Dumper=NoAliasDumper)
self.resource_type_registry.update(data) self.resource_type_registry.update(data)
logger.debug( logger.trace(
f"[UniLab Registry] Resource-{current_resource_number} File-{i+1}/{len(files)} " f"[UniLab Registry] Resource-{current_resource_number} File-{i+1}/{len(files)} "
+ f"Add {list(data.keys())}" + f"Add {list(data.keys())}"
) )
@@ -402,7 +402,7 @@ class Registry:
devices_path = abs_path / "devices" devices_path = abs_path / "devices"
device_comms_path = abs_path / "device_comms" device_comms_path = abs_path / "device_comms"
files = list(devices_path.glob("*.yaml")) + list(device_comms_path.glob("*.yaml")) files = list(devices_path.glob("*.yaml")) + list(device_comms_path.glob("*.yaml"))
logger.debug( logger.trace(
f"[UniLab Registry] devices: {devices_path.exists()}, device_comms: {device_comms_path.exists()}, " f"[UniLab Registry] devices: {devices_path.exists()}, device_comms: {device_comms_path.exists()}, "
+ f"total: {len(files)}" + f"total: {len(files)}"
) )
@@ -565,7 +565,7 @@ class Registry:
} }
device_config["file_path"] = str(file.absolute()).replace("\\", "/") device_config["file_path"] = str(file.absolute()).replace("\\", "/")
device_config["registry_type"] = "device" device_config["registry_type"] = "device"
logger.debug( logger.trace(
f"[UniLab Registry] Device-{current_device_number} File-{i+1}/{len(files)} Add {device_id} " f"[UniLab Registry] Device-{current_device_number} File-{i+1}/{len(files)} Add {device_id} "
+ f"[{data[device_id].get('name', '未命名设备')}]" + f"[{data[device_id].get('name', '未命名设备')}]"
) )

View File

@@ -51,7 +51,7 @@ from unilabos.ros.nodes.resource_tracker import DeviceNodeResourceTracker
from unilabos.ros.x.rclpyx import get_event_loop from unilabos.ros.x.rclpyx import get_event_loop
from unilabos.ros.utils.driver_creator import ProtocolNodeCreator, PyLabRobotCreator, DeviceClassCreator from unilabos.ros.utils.driver_creator import ProtocolNodeCreator, PyLabRobotCreator, DeviceClassCreator
from unilabos.utils.async_util import run_async_func from unilabos.utils.async_util import run_async_func
from unilabos.utils.log import info, debug, warning, error, critical, logger from unilabos.utils.log import info, debug, warning, error, critical, logger, trace
from unilabos.utils.type_check import get_type_class, TypeEncoder, serialize_result_info from unilabos.utils.type_check import get_type_class, TypeEncoder, serialize_result_info
T = TypeVar("T") T = TypeVar("T")
@@ -82,6 +82,7 @@ class ROSLoggerAdapter:
self.level_2_logger_func = { self.level_2_logger_func = {
"info": info, "info": info,
"debug": debug, "debug": debug,
"trace": trace,
"warning": warning, "warning": warning,
"error": error, "error": error,
"critical": critical, "critical": critical,
@@ -96,6 +97,10 @@ class ROSLoggerAdapter:
ros_log_func(msg) ros_log_func(msg)
self.level_2_logger_func[level](msg, *args, stack_level=1, **kwargs) self.level_2_logger_func[level](msg, *args, stack_level=1, **kwargs)
def trace(self, msg, *args, **kwargs):
"""记录TRACE级别日志"""
self._log("trace", msg, *args, **kwargs)
def debug(self, msg, *args, **kwargs): def debug(self, msg, *args, **kwargs):
"""记录DEBUG级别日志""" """记录DEBUG级别日志"""
self._log("debug", msg, *args, **kwargs) self._log("debug", msg, *args, **kwargs)
@@ -175,12 +180,12 @@ class PropertyPublisher:
self.timer = node.create_timer(self.timer_period, self.publish_property) self.timer = node.create_timer(self.timer_period, self.publish_property)
self.__loop = get_event_loop() self.__loop = get_event_loop()
str_msg_type = str(msg_type)[8:-2] str_msg_type = str(msg_type)[8:-2]
self.node.lab_logger().debug(f"发布属性: {name}, 类型: {str_msg_type}, 周期: {initial_period}") self.node.lab_logger().trace(f"发布属性: {name}, 类型: {str_msg_type}, 周期: {initial_period}")
def get_property(self): def get_property(self):
if asyncio.iscoroutinefunction(self.get_method): if asyncio.iscoroutinefunction(self.get_method):
# 如果是异步函数,运行事件循环并等待结果 # 如果是异步函数,运行事件循环并等待结果
self.node.lab_logger().debug(f"【PropertyPublisher.get_property】获取异步属性: {self.name}") self.node.lab_logger().trace(f"【PropertyPublisher.get_property】获取异步属性: {self.name}")
loop = self.__loop loop = self.__loop
if loop: if loop:
future = asyncio.run_coroutine_threadsafe(self.get_method(), loop) future = asyncio.run_coroutine_threadsafe(self.get_method(), loop)
@@ -191,28 +196,28 @@ class PropertyPublisher:
return None return None
else: else:
# 如果是同步函数,直接调用并返回结果 # 如果是同步函数,直接调用并返回结果
self.node.lab_logger().debug(f"【PropertyPublisher.get_property】获取同步属性: {self.name}") self.node.lab_logger().trace(f"【PropertyPublisher.get_property】获取同步属性: {self.name}")
self._value = self.get_method() self._value = self.get_method()
return self._value return self._value
async def get_property_async(self): async def get_property_async(self):
try: try:
# 获取异步属性值 # 获取异步属性值
self.node.lab_logger().debug(f"【PropertyPublisher.get_property_async】异步获取属性: {self.name}") self.node.lab_logger().trace(f"【PropertyPublisher.get_property_async】异步获取属性: {self.name}")
self._value = await self.get_method() self._value = await self.get_method()
except Exception as e: except Exception as e:
self.node.lab_logger().error(f"【PropertyPublisher.get_property_async】获取异步属性出错: {str(e)}") self.node.lab_logger().error(f"【PropertyPublisher.get_property_async】获取异步属性出错: {str(e)}")
def publish_property(self): def publish_property(self):
try: try:
self.node.lab_logger().debug(f"【PropertyPublisher.publish_property】开始发布属性: {self.name}") self.node.lab_logger().trace(f"【PropertyPublisher.publish_property】开始发布属性: {self.name}")
value = self.get_property() value = self.get_property()
if self.print_publish: if self.print_publish:
self.node.lab_logger().info(f"【PropertyPublisher.publish_property】发布 {self.msg_type}: {value}") self.node.lab_logger().trace(f"【PropertyPublisher.publish_property】发布 {self.msg_type}: {value}")
if value is not None: if value is not None:
msg = convert_to_ros_msg(self.msg_type, value) msg = convert_to_ros_msg(self.msg_type, value)
self.publisher_.publish(msg) self.publisher_.publish(msg)
self.node.lab_logger().debug(f"【PropertyPublisher.publish_property】属性 {self.name} 发布成功") self.node.lab_logger().trace(f"【PropertyPublisher.publish_property】属性 {self.name} 发布成功")
except Exception as e: except Exception as e:
self.node.lab_logger().error(f"【PropertyPublisher.publish_property】发布属性 {self.publisher_.topic} 出错: {str(e)}\n{traceback.format_exc()}") self.node.lab_logger().error(f"【PropertyPublisher.publish_property】发布属性 {self.publisher_.topic} 出错: {str(e)}\n{traceback.format_exc()}")
@@ -606,7 +611,7 @@ class BaseROS2DeviceNode(Node, Generic[T]):
callback_group=ReentrantCallbackGroup(), callback_group=ReentrantCallbackGroup(),
) )
self.lab_logger().debug(f"发布动作: {action_name}, 类型: {str_action_type}") self.lab_logger().trace(f"发布动作: {action_name}, 类型: {str_action_type}")
def get_real_function(self, instance, attr_name): def get_real_function(self, instance, attr_name):
if hasattr(instance.__class__, attr_name): if hasattr(instance.__class__, attr_name):

View File

@@ -1,3 +1,4 @@
import collections
import copy import copy
import json import json
import threading import threading
@@ -254,7 +255,7 @@ class HostNode(BaseROS2DeviceNode):
检测ROS2网络中的所有设备节点并为它们创建ActionClient 检测ROS2网络中的所有设备节点并为它们创建ActionClient
同时检测设备离线情况 同时检测设备离线情况
""" """
self.lab_logger().debug("[Host Node] Discovering devices in the network...") self.lab_logger().trace("[Host Node] Discovering devices in the network...")
# 获取当前所有设备 # 获取当前所有设备
nodes_and_names = self.get_node_names_and_namespaces() nodes_and_names = self.get_node_names_and_namespaces()
@@ -303,7 +304,7 @@ class HostNode(BaseROS2DeviceNode):
# 更新在线设备列表 # 更新在线设备列表
self._online_devices = current_devices self._online_devices = current_devices
self.lab_logger().debug(f"[Host Node] Total online devices: {len(self._online_devices)}") self.lab_logger().trace(f"[Host Node] Total online devices: {len(self._online_devices)}")
def _discovery_devices_callback(self) -> None: def _discovery_devices_callback(self) -> None:
""" """
@@ -335,7 +336,7 @@ class HostNode(BaseROS2DeviceNode):
self._action_clients[action_id] = ActionClient( self._action_clients[action_id] = ActionClient(
self, action_type, action_id, callback_group=self.callback_group self, action_type, action_id, callback_group=self.callback_group
) )
self.lab_logger().debug(f"[Host Node] Created ActionClient (Discovery): {action_id}") self.lab_logger().trace(f"[Host Node] Created ActionClient (Discovery): {action_id}")
action_name = action_id[len(namespace) + 1 :] action_name = action_id[len(namespace) + 1 :]
edge_device_id = namespace[9:] edge_device_id = namespace[9:]
# from unilabos.app.mq import mqtt_client # from unilabos.app.mq import mqtt_client
@@ -476,7 +477,7 @@ class HostNode(BaseROS2DeviceNode):
if action_id not in self._action_clients: if action_id not in self._action_clients:
action_type = action_value_mapping["type"] action_type = action_value_mapping["type"]
self._action_clients[action_id] = ActionClient(self, action_type, action_id) self._action_clients[action_id] = ActionClient(self, action_type, action_id)
self.lab_logger().debug( self.lab_logger().trace(
f"[Host Node] Created ActionClient (Local): {action_id}" f"[Host Node] Created ActionClient (Local): {action_id}"
) # 子设备再创建用的是Discover发现的 ) # 子设备再创建用的是Discover发现的
# from unilabos.app.mq import mqtt_client # from unilabos.app.mq import mqtt_client
@@ -521,7 +522,7 @@ class HostNode(BaseROS2DeviceNode):
self.device_status_timestamps[device_id] = {} self.device_status_timestamps[device_id] = {}
# 默认初始化属性值为 None # 默认初始化属性值为 None
self.device_status[device_id][property_name] = None self.device_status[device_id] = collections.defaultdict()
self.device_status_timestamps[device_id][property_name] = 0 # 初始化时间戳 self.device_status_timestamps[device_id][property_name] = 0 # 初始化时间戳
# 动态创建订阅 # 动态创建订阅
@@ -539,7 +540,7 @@ class HostNode(BaseROS2DeviceNode):
) )
# 标记为已订阅 # 标记为已订阅
self._subscribed_topics.add(topic) self._subscribed_topics.add(topic)
self.lab_logger().debug(f"[Host Node] Subscribed to new topic: {topic}") self.lab_logger().trace(f"[Host Node] Subscribed to new topic: {topic}")
except (NameError, SyntaxError) as e: except (NameError, SyntaxError) as e:
self.lab_logger().error(f"[Host Node] Failed to create subscription for topic {topic}: {e}") self.lab_logger().error(f"[Host Node] Failed to create subscription for topic {topic}: {e}")
@@ -557,10 +558,15 @@ class HostNode(BaseROS2DeviceNode):
# 更新设备状态字典 # 更新设备状态字典
if hasattr(msg, "data"): if hasattr(msg, "data"):
bChange = False bChange = False
bCreate = False
if isinstance(msg.data, (float, int, str)): if isinstance(msg.data, (float, int, str)):
if self.device_status[device_id][property_name] != msg.data: if property_name not in self.device_status[device_id]:
bCreate = True
bChange = True bChange = True
self.device_status[device_id][property_name] = msg.data self.device_status[device_id][property_name] = msg.data
elif self.device_status[device_id][property_name] != msg.data:
bChange = True
self.device_status[device_id][property_name] = msg.data
# 更新时间戳 # 更新时间戳
self.device_status_timestamps[device_id][property_name] = time.time() self.device_status_timestamps[device_id][property_name] = time.time()
else: else:
@@ -573,9 +579,14 @@ class HostNode(BaseROS2DeviceNode):
for bridge in self.bridges: for bridge in self.bridges:
if hasattr(bridge, "publish_device_status"): if hasattr(bridge, "publish_device_status"):
bridge.publish_device_status(self.device_status, device_id, property_name) bridge.publish_device_status(self.device_status, device_id, property_name)
self.lab_logger().debug( if bCreate:
f"[Host Node] Status updated: {device_id}.{property_name} = {msg.data}" self.lab_logger().trace(
) f"Status created: {device_id}.{property_name} = {msg.data}"
)
else:
self.lab_logger().debug(
f"Status updated: {device_id}.{property_name} = {msg.data}"
)
def send_goal( def send_goal(
self, self,

View File

@@ -151,7 +151,7 @@ class ROS2ProtocolNode(BaseROS2DeviceNode):
except Exception as ex: except Exception as ex:
self.lab_logger().error(f"创建动作客户端失败: {action_id}, 错误: {ex}") self.lab_logger().error(f"创建动作客户端失败: {action_id}, 错误: {ex}")
continue continue
self.lab_logger().debug(f"为子设备 {device_id} 创建动作客户端: {action_name}") self.lab_logger().trace(f"为子设备 {device_id} 创建动作客户端: {action_name}")
return d return d
def create_ros_action_server(self, action_name, action_value_mapping): def create_ros_action_server(self, action_name, action_value_mapping):
@@ -171,7 +171,7 @@ class ROS2ProtocolNode(BaseROS2DeviceNode):
callback_group=ReentrantCallbackGroup(), callback_group=ReentrantCallbackGroup(),
) )
self.lab_logger().debug(f"发布动作: {action_name}, 类型: {str_action_type}") self.lab_logger().trace(f"发布动作: {action_name}, 类型: {str_action_type}")
def _create_protocol_execute_callback(self, protocol_name, protocol_steps_generator): def _create_protocol_execute_callback(self, protocol_name, protocol_steps_generator):
async def execute_protocol(goal_handle: ServerGoalHandle): async def execute_protocol(goal_handle: ServerGoalHandle):

View File

@@ -7,6 +7,10 @@ import atexit
import inspect import inspect
from typing import Tuple, cast from typing import Tuple, cast
# 添加TRACE级别到logging模块
TRACE_LEVEL = 5
logging.addLevelName(TRACE_LEVEL, "TRACE")
class CustomRecord: class CustomRecord:
custom_stack_info: Tuple[str, int, str, str] custom_stack_info: Tuple[str, int, str, str]
@@ -44,11 +48,13 @@ class ColoredFormatter(logging.Formatter):
"GRAY": "\033[37m", # 灰色 "GRAY": "\033[37m", # 灰色
"WHITE": "\033[97m", # 白色 "WHITE": "\033[97m", # 白色
"BLACK": "\033[30m", # 黑色 "BLACK": "\033[30m", # 黑色
"TRACE_LEVEL": "\033[1;90m", # 加粗深灰色
"DEBUG_LEVEL": "\033[1;36m", # 加粗青色 "DEBUG_LEVEL": "\033[1;36m", # 加粗青色
"INFO_LEVEL": "\033[1;32m", # 加粗绿色 "INFO_LEVEL": "\033[1;32m", # 加粗绿色
"WARNING_LEVEL": "\033[1;33m", # 加粗黄色 "WARNING_LEVEL": "\033[1;33m", # 加粗黄色
"ERROR_LEVEL": "\033[1;31m", # 加粗红色 "ERROR_LEVEL": "\033[1;31m", # 加粗红色
"CRITICAL_LEVEL": "\033[1;35m", # 加粗紫色 "CRITICAL_LEVEL": "\033[1;35m", # 加粗紫色
"TRACE_TEXT": "\033[90m", # 深灰色
"DEBUG_TEXT": "\033[37m", # 灰色 "DEBUG_TEXT": "\033[37m", # 灰色
"INFO_TEXT": "\033[97m", # 白色 "INFO_TEXT": "\033[97m", # 白色
"WARNING_TEXT": "\033[33m", # 黄色 "WARNING_TEXT": "\033[33m", # 黄色
@@ -148,8 +154,8 @@ def configure_logger(loglevel=None):
"""配置日志记录器 """配置日志记录器
Args: Args:
loglevel: 日志级别,可以是字符串('DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL' loglevel: 日志级别,可以是字符串('TRACE', 'DEBUG', 'INFO', 'WARNING', 'ERROR', 'CRITICAL'
或logging模块的常量如logging.DEBUG 或logging模块的常量如logging.DEBUG或TRACE_LEVEL
""" """
# 获取根日志记录器 # 获取根日志记录器
root_logger = logging.getLogger() root_logger = logging.getLogger()
@@ -158,10 +164,13 @@ def configure_logger(loglevel=None):
if loglevel is not None: if loglevel is not None:
if isinstance(loglevel, str): if isinstance(loglevel, str):
# 将字符串转换为logging级别 # 将字符串转换为logging级别
numeric_level = getattr(logging, loglevel.upper(), None) if loglevel.upper() == "TRACE":
if not isinstance(numeric_level, int): numeric_level = TRACE_LEVEL
print(f"警告: 无效的日志级别 '{loglevel}',使用默认级别 DEBUG") else:
numeric_level = logging.DEBUG numeric_level = getattr(logging, loglevel.upper(), None)
if not isinstance(numeric_level, int):
print(f"警告: 无效的日志级别 '{loglevel}',使用默认级别 DEBUG")
numeric_level = logging.DEBUG
else: else:
numeric_level = loglevel numeric_level = loglevel
root_logger.setLevel(numeric_level) root_logger.setLevel(numeric_level)
@@ -318,9 +327,29 @@ def critical(msg, *args, stack_level=0, **kwargs):
logger.critical(msg, *args, **kwargs) logger.critical(msg, *args, **kwargs)
def trace(msg, *args, stack_level=0, **kwargs):
"""
记录TRACE级别日志比DEBUG级别更低
Args:
msg: 日志消息
stack_level: 堆栈回溯级别,用于定位日志的实际调用位置
*args, **kwargs: 传递给logger.log的其他参数
"""
if stack_level > 0:
caller_info = _get_caller_info(stack_level)
extra = kwargs.get("extra", {})
extra["custom_stack_info"] = caller_info
kwargs["extra"] = extra
logger.log(TRACE_LEVEL, msg, *args, **kwargs)
logger.trace = trace
# 测试日志输出(如果直接运行此文件) # 测试日志输出(如果直接运行此文件)
if __name__ == "__main__": if __name__ == "__main__":
print("测试不同日志级别的颜色输出:") print("测试不同日志级别的颜色输出:")
trace("这是一条跟踪日志 (TRACE级别显示为深灰色其他文本也为深灰色)")
debug("这是一条调试日志 (DEBUG级别显示为蓝色其他文本为灰色)") debug("这是一条调试日志 (DEBUG级别显示为蓝色其他文本为灰色)")
info("这是一条信息日志 (INFO级别显示为绿色其他文本为白色)") info("这是一条信息日志 (INFO级别显示为绿色其他文本为白色)")
warning("这是一条警告日志 (WARNING级别显示为黄色其他文本也为黄色)") warning("这是一条警告日志 (WARNING级别显示为黄色其他文本也为黄色)")