This commit is contained in:
SengokuCola
2025-06-24 02:04:25 +08:00
4 changed files with 40 additions and 26 deletions

View File

@@ -466,7 +466,9 @@ class HeartFChatting:
formatted_ptime = f"{ptime * 1000:.2f}毫秒" if ptime < 1 else f"{ptime:.2f}" formatted_ptime = f"{ptime * 1000:.2f}毫秒" if ptime < 1 else f"{ptime:.2f}"
post_processor_time_strings.append(f"{pname}: {formatted_ptime}") post_processor_time_strings.append(f"{pname}: {formatted_ptime}")
post_processor_time_log = ( post_processor_time_log = (
("\n后处理器耗时: " + "; ".join(post_processor_time_strings)) if post_processor_time_strings else "" ("\n后处理器耗时: " + "; ".join(post_processor_time_strings))
if post_processor_time_strings
else ""
) )
logger.info( logger.info(
@@ -769,7 +771,9 @@ class HeartFChatting:
return updated_action_data return updated_action_data
async def _process_post_planning_processors_with_timing(self, observations: List[Observation], action_data: dict) -> tuple[dict, dict]: async def _process_post_planning_processors_with_timing(
self, observations: List[Observation], action_data: dict
) -> tuple[dict, dict]:
""" """
处理后期处理器(规划后执行的处理器)并收集详细时间统计 处理后期处理器(规划后执行的处理器)并收集详细时间统计
包括:关系处理器、表达选择器、记忆激活器 包括:关系处理器、表达选择器、记忆激活器
@@ -883,7 +887,9 @@ class HeartFChatting:
) )
elif task_type == "memory": elif task_type == "memory":
post_processor_time_costs["MemoryActivator"] = elapsed_time post_processor_time_costs["MemoryActivator"] = elapsed_time
logger.warning(f"{self.log_prefix} 记忆激活器超时(>{MEMORY_ACTIVATION_TIMEOUT}s已跳过耗时: {elapsed_time:.3f}") logger.warning(
f"{self.log_prefix} 记忆激活器超时(>{MEMORY_ACTIVATION_TIMEOUT}s已跳过耗时: {elapsed_time:.3f}"
)
running_memorys = [] running_memorys = []
except Exception as e: except Exception as e:
# 对于异常任务,记录已用时间 # 对于异常任务,记录已用时间
@@ -896,7 +902,10 @@ class HeartFChatting:
) )
elif task_type == "memory": elif task_type == "memory":
post_processor_time_costs["MemoryActivator"] = elapsed_time post_processor_time_costs["MemoryActivator"] = elapsed_time
logger.error(f"{self.log_prefix} 记忆激活器执行失败,耗时: {elapsed_time:.3f}秒. 错误: {e}", exc_info=True) logger.error(
f"{self.log_prefix} 记忆激活器执行失败,耗时: {elapsed_time:.3f}秒. 错误: {e}",
exc_info=True,
)
running_memorys = [] running_memorys = []
# 将后期处理器的结果整合到 action_data 中 # 将后期处理器的结果整合到 action_data 中
@@ -938,7 +947,9 @@ class HeartFChatting:
# 输出详细统计信息 # 输出详细统计信息
if post_processor_time_costs: if post_processor_time_costs:
stats_str = ", ".join([f"{name}: {time_cost:.3f}s" for name, time_cost in post_processor_time_costs.items()]) stats_str = ", ".join(
[f"{name}: {time_cost:.3f}s" for name, time_cost in post_processor_time_costs.items()]
)
logger.info(f"{self.log_prefix} 后期处理器详细耗时统计: {stats_str}") logger.info(f"{self.log_prefix} 后期处理器详细耗时统计: {stats_str}")
return updated_action_data, post_processor_time_costs return updated_action_data, post_processor_time_costs
@@ -1048,7 +1059,9 @@ class HeartFChatting:
logger.debug(f"{self.log_prefix} 执行后期处理器(动作类型: {action_type}") logger.debug(f"{self.log_prefix} 执行后期处理器(动作类型: {action_type}")
# 记录详细的后处理器时间 # 记录详细的后处理器时间
post_start_time = time.time() post_start_time = time.time()
action_data, post_processor_time_costs = await self._process_post_planning_processors_with_timing(self.observations, action_data) action_data, post_processor_time_costs = await self._process_post_planning_processors_with_timing(
self.observations, action_data
)
post_end_time = time.time() post_end_time = time.time()
logger.info(f"{self.log_prefix} 后期处理器总耗时: {post_end_time - post_start_time:.3f}") logger.info(f"{self.log_prefix} 后期处理器总耗时: {post_end_time - post_start_time:.3f}")
else: else:

View File

@@ -57,15 +57,14 @@ class HFCPerformanceLogger:
log_parts = [ log_parts = [
f"cycle_id={record['cycle_id']}", f"cycle_id={record['cycle_id']}",
f"action={record['action_type']}", f"action={record['action_type']}",
f"time={record['total_time']:.2f}s" f"time={record['total_time']:.2f}s",
] ]
# 添加后处理器时间信息到日志 # 添加后处理器时间信息到日志
if record['post_processor_time_costs']: if record["post_processor_time_costs"]:
post_processor_stats = ", ".join([ post_processor_stats = ", ".join(
f"{name}: {time_cost:.3f}s" [f"{name}: {time_cost:.3f}s" for name, time_cost in record["post_processor_time_costs"].items()]
for name, time_cost in record['post_processor_time_costs'].items() )
])
log_parts.append(f"post_processors=({post_processor_stats})") log_parts.append(f"post_processors=({post_processor_stats})")
logger.debug(f"记录HFC循环数据: {', '.join(log_parts)}") logger.debug(f"记录HFC循环数据: {', '.join(log_parts)}")

View File

@@ -60,7 +60,7 @@ FOCUS_AVG_TIMES_BY_VERSION = "focus_avg_times_by_version"
# 新增: 后处理器统计数据的键 # 新增: 后处理器统计数据的键
FOCUS_POST_PROCESSOR_TIMES = "focus_post_processor_times" FOCUS_POST_PROCESSOR_TIMES = "focus_post_processor_times"
FOCUS_POST_PROCESSOR_COUNT = "focus_post_processor_count" FOCUS_POST_PROCESSOR_COUNT = "focus_post_processor_count"
FOCUS_POST_PROCESSOR_SUCCESS_RATE = "focus_post_processor_success_rate" FOCUS_POST_PROCESSOR_SUCCESS_RATE = "focus_post_processor_success_rate"
FOCUS_PROCESSOR_TIMES = "focus_processor_times" # 前处理器统计 FOCUS_PROCESSOR_TIMES = "focus_processor_times" # 前处理器统计
@@ -566,7 +566,7 @@ class StatisticOutputTask(AsyncTask):
total_time = cycle_data.get("total_time", 0.0) total_time = cycle_data.get("total_time", 0.0)
step_times = cycle_data.get("step_times", {}) step_times = cycle_data.get("step_times", {})
version = cycle_data.get("version", "unknown") version = cycle_data.get("version", "unknown")
# 新增:获取前处理器和后处理器时间 # 新增:获取前处理器和后处理器时间
processor_time_costs = cycle_data.get("processor_time_costs", {}) processor_time_costs = cycle_data.get("processor_time_costs", {})
post_processor_time_costs = cycle_data.get("post_processor_time_costs", {}) post_processor_time_costs = cycle_data.get("post_processor_time_costs", {})
@@ -930,7 +930,7 @@ class StatisticOutputTask(AsyncTask):
# format总在线时间 # format总在线时间
# 按模型分类统计 # 按模型分类统计
model_rows = "\n".join( "\n".join(
[ [
f"<tr>" f"<tr>"
f"<td>{model_name}</td>" f"<td>{model_name}</td>"
@@ -944,7 +944,7 @@ class StatisticOutputTask(AsyncTask):
] ]
) )
# 按请求类型分类统计 # 按请求类型分类统计
type_rows = "\n".join( "\n".join(
[ [
f"<tr>" f"<tr>"
f"<td>{req_type}</td>" f"<td>{req_type}</td>"
@@ -958,7 +958,7 @@ class StatisticOutputTask(AsyncTask):
] ]
) )
# 按模块分类统计 # 按模块分类统计
module_rows = "\n".join( "\n".join(
[ [
f"<tr>" f"<tr>"
f"<td>{module_name}</td>" f"<td>{module_name}</td>"
@@ -973,7 +973,7 @@ class StatisticOutputTask(AsyncTask):
) )
# 聊天消息统计 # 聊天消息统计
chat_rows = "\n".join( "\n".join(
[ [
f"<tr><td>{self.name_mapping[chat_id][0]}</td><td>{count}</td></tr>" f"<tr><td>{self.name_mapping[chat_id][0]}</td><td>{count}</td></tr>"
for chat_id, count in sorted(stat_data[MSG_CNT_BY_CHAT].items()) for chat_id, count in sorted(stat_data[MSG_CNT_BY_CHAT].items())
@@ -1028,7 +1028,7 @@ class StatisticOutputTask(AsyncTask):
basic_stages = ["观察", "并行调整动作、处理", "规划器", "后期处理器", "动作执行"] basic_stages = ["观察", "并行调整动作、处理", "规划器", "后期处理器", "动作执行"]
existing_basic_stages = [] existing_basic_stages = []
for stage in basic_stages: for stage in basic_stages:
# 检查是否有任何聊天流在这个阶段有数据 # 检查是否有任何聊天流在这个阶段有数据
stage_exists = False stage_exists = False
for _chat_id, stage_times in stat_data[FOCUS_AVG_TIMES_BY_CHAT_ACTION].items(): for _chat_id, stage_times in stat_data[FOCUS_AVG_TIMES_BY_CHAT_ACTION].items():
if stage in stage_times: if stage in stage_times:
@@ -1275,7 +1275,9 @@ class StatisticOutputTask(AsyncTask):
for processor_name in sorted(stat_data[FOCUS_POST_PROCESSOR_TIMES].keys()): for processor_name in sorted(stat_data[FOCUS_POST_PROCESSOR_TIMES].keys()):
avg_time = stat_data[FOCUS_POST_PROCESSOR_TIMES][processor_name] avg_time = stat_data[FOCUS_POST_PROCESSOR_TIMES][processor_name]
count = stat_data[FOCUS_POST_PROCESSOR_COUNT].get(processor_name, 0) count = stat_data[FOCUS_POST_PROCESSOR_COUNT].get(processor_name, 0)
post_processor_rows.append(f"<tr><td>{processor_name}</td><td>{avg_time:.3f}秒</td><td>{count}</td></tr>") post_processor_rows.append(
f"<tr><td>{processor_name}</td><td>{avg_time:.3f}秒</td><td>{count}</td></tr>"
)
focus_post_processor_rows = "\n".join(post_processor_rows) focus_post_processor_rows = "\n".join(post_processor_rows)
# 计算时间范围 # 计算时间范围

View File

@@ -248,10 +248,10 @@ class NoReplyAction(BaseAction):
# 判定条件累计3条消息或等待超过5秒且有新消息 # 判定条件累计3条消息或等待超过5秒且有新消息
time_since_last_judge = current_time - last_judge_time time_since_last_judge = current_time - last_judge_time
should_judge = ( should_judge = (
new_message_count >= 3 or # 累计3条消息 new_message_count >= 3 # 累计3条消息
(new_message_count > 0 and time_since_last_judge >= 5.0) # 等待超过5秒且有新消息 or (new_message_count > 0 and time_since_last_judge >= 5.0) # 等待超过5秒且有新消息
) )
if should_judge and time_since_last_judge >= min_judge_interval: if should_judge and time_since_last_judge >= min_judge_interval:
# 判断触发原因 # 判断触发原因
trigger_reason = "" trigger_reason = ""
@@ -259,7 +259,7 @@ class NoReplyAction(BaseAction):
trigger_reason = f"累计{new_message_count}条消息" trigger_reason = f"累计{new_message_count}条消息"
elif time_since_last_judge >= 5.0: elif time_since_last_judge >= 5.0:
trigger_reason = f"等待{time_since_last_judge:.1f}秒且有{new_message_count}条新消息" trigger_reason = f"等待{time_since_last_judge:.1f}秒且有{new_message_count}条新消息"
logger.info(f"{self.log_prefix} 触发判定({trigger_reason}),进行智能判断...") logger.info(f"{self.log_prefix} 触发判定({trigger_reason}),进行智能判断...")
# 获取最近的消息内容用于判断 # 获取最近的消息内容用于判断
@@ -342,7 +342,7 @@ class NoReplyAction(BaseAction):
if self._skip_judge_when_tired and random.random() < skip_probability: if self._skip_judge_when_tired and random.random() < skip_probability:
should_skip_llm_judge = True should_skip_llm_judge = True
logger.info( logger.info(
f"{self.log_prefix} 发言过多(超过{over_count}条)随机决定跳过此次LLM判断(概率{skip_probability*100:.0f}%)" f"{self.log_prefix} 发言过多(超过{over_count}条)随机决定跳过此次LLM判断(概率{skip_probability * 100:.0f}%)"
) )
logger.info( logger.info(