wunianxiao/iAs
1
1
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

refactor(logger): 日志体系优化，分四类文件存储

Browse Source 
- 认证日志 (auth.log): 登录/token/监听器注册，target=ias::auth
- 消息队列日志 (queue.log): 入队/出队内容、消费路由，target=ias::queue
- 工具日志 (tool.log): 调用参数/输出/耗时/工具错误，target=ias::tool
- 错误日志 (error.log): 所有非工具调用的 ERROR/WARN 自动捕获

使用 tracing-subscriber 多层过滤架构，终端输出保持不变
This commit is contained in:
无念晓
2026-06-17 11:29:13 +08:00
parent 52f2593464
commit 57c030a62a
12 changed files with 149 additions and 102 deletions
Download Patch File Download Diff File Expand all files Collapse all files
src/context/builder.rs
+2 -2
View File
@@ -297,10 +297,10 @@ async fn generate_summary(messages: &[Message], summarizer: Option<&Summarizer>)
let prompt = build_summary_prompt(messages); let prompt = build_summary_prompt(messages);
match summarizer(prompt).await { match summarizer(prompt).await {
Ok(text) if !text.is_empty() => { Ok(text) if !text.is_empty() => {
tracing::info!("LLM 摘要: {:.100}...", text); tracing::info!(target: "ias::tool", "LLM 摘要: {:.100}...", text);
return text; return text;
} }
_ => tracing::warn!("LLM 摘要失败，回退到简单截断"), _ => tracing::warn!(target: "ias::tool", "LLM 摘要失败，回退到简单截断"),
} }
} }
summarize_messages(messages) summarize_messages(messages)
src/context/types.rs
+1 -1
View File
@@ -201,7 +201,7 @@ impl ChatSession {
&self.current_user_id &self.current_user_id
}; };
if let Err(e) = crate::db::models::save_summary(pool, uid, text, reason, message_count).await { if let Err(e) = crate::db::models::save_summary(pool, uid, text, reason, message_count).await {
tracing::warn!("保存摘要到数据库失败: {}", e); tracing::warn!(target: "ias::tool", "保存摘要到数据库失败: {}", e);
} }
} }
} }
src/daemon.rs
+42 -42
View File
@@ -90,7 +90,7 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
let auth = match load_auth(database).await { let auth = match load_auth(database).await {
Some(a) => a, Some(a) => a,
None => { None => {
error!("未登录"); error!(target: "ias::auth", "未登录");
return; return;
} }
}; };
@@ -102,11 +102,11 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
client.set_updates_buf(&buf).await; client.set_updates_buf(&buf).await;
} }
if let Err(e) = client.notify_start().await { if let Err(e) = client.notify_start().await {
error!("注册监听器失败: {}", e); error!(target: "ias::auth", "注册监听器失败: {}", e);
return; return;
} }
let account_id = auth.account_id.clone(); let account_id = auth.account_id.clone();
info!("Daemon 已启动"); info!(target: "ias::auth", "Daemon 已启动");
// 4-6. 审批管理器、工具列表、模型配置 // 4-6. 审批管理器、工具列表、模型配置
let approval_manager = Arc::new(ApprovalManager::new(Some(Arc::new( let approval_manager = Arc::new(ApprovalManager::new(Some(Arc::new(
@@ -179,7 +179,7 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
}) })
.await; .await;
}); });
info!("定时任务调度器已启动"); info!(target: "ias::queue", "定时任务调度器已启动");
// 12. QueueRunner // 12. QueueRunner
let runner_handle = tokio::spawn(async move { let runner_handle = tokio::spawn(async move {
@@ -199,7 +199,7 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
} }
}); });
info!("开始监听消息..."); info!(target: "ias::auth", "开始监听消息...");
// 13. 主循环 — 带 Ctrl+C 优雅退出 // 13. 主循环 — 带 Ctrl+C 优雅退出
let mut running = true; let mut running = true;
@@ -219,7 +219,7 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
let text = msg.text_content().unwrap_or("(非文本消息)"); let text = msg.text_content().unwrap_or("(非文本消息)");
let ctx_token = msg.context_token.as_deref(); let ctx_token = msg.context_token.as_deref();
let msg_id = msg.message_id.map(|id| id.to_string()).unwrap_or_default(); let msg_id = msg.message_id.map(|id| id.to_string()).unwrap_or_default();
info!("收到消息 from={}: {}", from, text); info!(target: "ias::queue", "收到消息 from={}: {}", from, text);
let _ = crate::db::models::insert_chat_record( let _ = crate::db::models::insert_chat_record(
ctx.db.pool(), "inbound", from, &ctx.account_id, text, "wechat", ctx_token, &msg_id, ctx.db.pool(), "inbound", from, &ctx.account_id, text, "wechat", ctx_token, &msg_id,
@@ -229,7 +229,7 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
if let Some((skill_name, decision)) = ctx.approval.handle_reply(from, text).await { if let Some((skill_name, decision)) = ctx.approval.handle_reply(from, text).await {
match decision { match decision {
ApprovalDecision::Approved => { ApprovalDecision::Approved => {
info!("审批通过: {}", skill_name); info!(target: "ias::auth", "审批通过: {}", skill_name);
// 5 元组: (orig_text, context_token, tool_name, tool_args, timestamp) // 5 元组: (orig_text, context_token, tool_name, tool_args, timestamp)
if let Some((orig_text, orig_ctx, _tn, _ta, _ts)) = ctx.approval_ctx.lock().await.remove(from) { if let Some((orig_text, orig_ctx, _tn, _ta, _ts)) = ctx.approval_ctx.lock().await.remove(from) {
enqueue_handle.enqueue(PipelineMessage { enqueue_handle.enqueue(PipelineMessage {
@@ -261,27 +261,27 @@ pub async fn run(database: &Arc<Database>, memory_store: &Arc<MemoryStore>) {
} }
Err(e) => { Err(e) => {
if !e.contains("超时") && !e.contains("timeout") { if !e.contains("超时") && !e.contains("timeout") {
error!("接收消息失败: {}", e); error!(target: "ias::auth", "接收消息失败: {}", e);
tokio::time::sleep(std::time::Duration::from_secs(2)).await; tokio::time::sleep(std::time::Duration::from_secs(2)).await;
} }
} }
} }
} }
_ = tokio::signal::ctrl_c() => { _ = tokio::signal::ctrl_c() => {
info!("收到 Ctrl+C，优雅关闭中..."); info!(target: "ias::auth", "收到 Ctrl+C，优雅关闭中...");
running = false; running = false;
} }
} }
} }
shutdown_handle.shutdown(); shutdown_handle.shutdown();
info!("等待消费者处理剩余消息..."); info!(target: "ias::queue", "等待消费者处理剩余消息...");
tokio::time::sleep(std::time::Duration::from_secs(3)).await; tokio::time::sleep(std::time::Duration::from_secs(3)).await;
for h in consumer_handles { for h in consumer_handles {
h.abort(); h.abort();
} }
runner_handle.abort(); runner_handle.abort();
info!("Daemon 已停止"); info!(target: "ias::auth", "Daemon 已停止");
} }
// ─── 消费者 ─── // ─── 消费者 ───
@@ -336,7 +336,7 @@ async fn llm_consumer_loop(
enqueue: &EnqueueHandle, enqueue: &EnqueueHandle,
sessions: &Arc<Mutex<HashMap<Uuid, (Conversation, Instant)>>>, sessions: &Arc<Mutex<HashMap<Uuid, (Conversation, Instant)>>>,
) { ) {
info!("LLM Consumer 已启动"); info!(target: "ias::queue", "LLM Consumer 已启动");
while let Some(msg) = rx.recv().await { while let Some(msg) = rx.recv().await {
let user_id = msg.channel.user_id.clone(); let user_id = msg.channel.user_id.clone();
@@ -476,7 +476,7 @@ async fn llm_consumer_loop(
*last_access = Instant::now(); // 更新访问时间，防止 TTL 误清理 *last_access = Instant::now(); // 更新访问时间，防止 TTL 误清理
conv.notify_tool_result() conv.notify_tool_result()
} else { } else {
warn!("会话已过期: corr={}", correlation_id); warn!(target: "ias::queue", "会话已过期: corr={}", correlation_id);
false false
} }
}; };
@@ -488,7 +488,7 @@ async fn llm_consumer_loop(
} }
MessageKind::ScheduledTask { text, task_name } => { MessageKind::ScheduledTask { text, task_name } => {
info!("LLM Consumer: 定时任务 user={} task={}", user_id, task_name); info!(target: "ias::queue", "LLM Consumer: 定时任务 user={} task={}", user_id, task_name);
let prompt = format!("[定时任务: {}]\n{}", task_name, text); let prompt = format!("[定时任务: {}]\n{}", task_name, text);
// 为保持简洁，定时任务直接作为用户消息处理（使用全新 correlation_id） // 为保持简洁，定时任务直接作为用户消息处理（使用全新 correlation_id）
@@ -508,13 +508,13 @@ async fn llm_consumer_loop(
eq.enqueue(msg).await; eq.enqueue(msg).await;
} }
other => warn!( other => warn!(target: "ias::queue",
"LLM Consumer 收到不期望的消息: {:?}", "LLM Consumer 收到不期望的消息: {:?}",
std::mem::discriminant(&other) std::mem::discriminant(&other)
), ),
} }
} }
info!("LLM Consumer 已停止"); info!(target: "ias::queue", "LLM Consumer 已停止");
} }
/// 执行一轮 LLM 对话，仅在无异步工具等待时发送回复并清理会话。 /// 执行一轮 LLM 对话，仅在无异步工具等待时发送回复并清理会话。
@@ -526,8 +526,8 @@ async fn run_llm_round(
sessions: &Arc<Mutex<HashMap<Uuid, (Conversation, Instant)>>>, sessions: &Arc<Mutex<HashMap<Uuid, (Conversation, Instant)>>>,
enqueue: &EnqueueHandle, enqueue: &EnqueueHandle,
) { ) {
info!("══════════════════════════════════════════════════"); info!(target: "ias::queue", "══════════════════════════════════════════════════");
info!("🔄 LLM 回合开始 user={} text={}", user_id, text); info!(target: "ias::queue", "🔄 LLM 回合开始 user={} text={}", user_id, text);
let result = { let result = {
let map = sessions.lock().await; let map = sessions.lock().await;
let conv = match map.get(&correlation_id) { let conv = match map.get(&correlation_id) {
@@ -571,8 +571,8 @@ async fn resume_llm_round(
sessions: &Arc<Mutex<HashMap<Uuid, (Conversation, Instant)>>>, sessions: &Arc<Mutex<HashMap<Uuid, (Conversation, Instant)>>>,
enqueue: &EnqueueHandle, enqueue: &EnqueueHandle,
) { ) {
info!("══════════════════════════════════════════════════"); info!(target: "ias::queue", "══════════════════════════════════════════════════");
info!("🔄 LLM 恢复 user={}", user_id); info!(target: "ias::queue", "🔄 LLM 恢复 user={}", user_id);
let result = { let result = {
let map = sessions.lock().await; let map = sessions.lock().await;
let conv = match map.get(&correlation_id) { let conv = match map.get(&correlation_id) {
@@ -634,7 +634,7 @@ async fn handle_chat_result(
enqueue.enqueue(msg).await; enqueue.enqueue(msg).await;
} }
sessions.lock().await.remove(&correlation_id); sessions.lock().await.remove(&correlation_id);
info!("✅ LLM 回合结束 user={}", user_id); info!(target: "ias::queue", "✅ LLM 回合结束 user={}", user_id);
} }
// ─── Tool Consumer ─── // ─── Tool Consumer ───
@@ -644,7 +644,7 @@ async fn tool_consumer_loop(
ctx: &DaemonCtx, ctx: &DaemonCtx,
enqueue: &EnqueueHandle, enqueue: &EnqueueHandle,
) { ) {
info!("Tool Consumer 已启动"); info!(target: "ias::queue", "Tool Consumer 已启动");
while let Some(msg) = rx.recv().await { while let Some(msg) = rx.recv().await {
let user_id = msg.channel.user_id.clone(); let user_id = msg.channel.user_id.clone();
@@ -659,14 +659,14 @@ async fn tool_consumer_loop(
context_token, context_token,
approved, approved,
} => { } => {
info!( info!(target: "ias::tool",
"Tool Consumer: user={} tool={} args={}", "Tool Consumer: user={} tool={} args={}",
user_id, tool_name, arguments user_id, tool_name, arguments
); );
// 高风险工具 → 审批（除非已被用户批准） // 高风险工具 → 审批（除非已被用户批准）
if !approved && crate::tools::is_high_risk(&tool_name) { if !approved && crate::tools::is_high_risk(&tool_name) {
info!("高风险工具 {} 需要审批", tool_name); info!(target: "ias::tool", "高风险工具 {} 需要审批", tool_name);
ctx.approval_ctx.lock().await.insert( ctx.approval_ctx.lock().await.insert(
user_id.clone(), user_id.clone(),
( (
@@ -689,7 +689,7 @@ async fn tool_consumer_loop(
.enqueue(PipelineMessage::llm_reply(ch, correlation_id, &m, None)) .enqueue(PipelineMessage::llm_reply(ch, correlation_id, &m, None))
.await; .await;
} }
Err(e) => error!("创建审批失败: {}", e), Err(e) => error!(target: "ias::tool", "创建审批失败: {}", e),
} }
continue; continue;
} }
@@ -710,15 +710,15 @@ async fn tool_consumer_loop(
.await; .await;
} }
MessageKind::ApprovalRequest { .. } => { MessageKind::ApprovalRequest { .. } => {
warn!("Tool Consumer 收到 ApprovalRequest"); warn!(target: "ias::queue", "Tool Consumer 收到 ApprovalRequest");
} }
other => warn!( other => warn!(target: "ias::queue",
"Tool Consumer 收到不期望: {:?}", "Tool Consumer 收到不期望: {:?}",
std::mem::discriminant(&other) std::mem::discriminant(&other)
), ),
} }
} }
info!("Tool Consumer 已停止"); info!(target: "ias::queue", "Tool Consumer 已停止");
} }
// ─── 统一工具执行 ─── // ─── 统一工具执行 ───
@@ -737,7 +737,7 @@ fn execute_tool<'a>(
match name { match name {
"read_memories" => { "read_memories" => {
let result = ctx.memory_store.read_for(user_id, None).await; let result = ctx.memory_store.read_for(user_id, None).await;
tracing::info!("🔧 execute_tool: read_memories → {}", result); tracing::info!(target: "ias::tool", "🔧 execute_tool: read_memories → {}", result);
return result; return result;
} }
"write_memory" => { "write_memory" => {
@@ -748,7 +748,7 @@ fn execute_tool<'a>(
} }
ctx.memory_store.write_for(user_id, content).await; ctx.memory_store.write_for(user_id, content).await;
let result = format!("已添加长期记忆: {}", content); let result = format!("已添加长期记忆: {}", content);
tracing::info!("🔧 execute_tool: write_memory → {}", result); tracing::info!(target: "ias::tool", "🔧 execute_tool: write_memory → {}", result);
return result; return result;
} }
"delete_memory" => { "delete_memory" => {
@@ -761,7 +761,7 @@ fn execute_tool<'a>(
return "请提供有效的 memory_id 参数".to_string(); return "请提供有效的 memory_id 参数".to_string();
} }
let result = ctx.memory_store.delete_for(user_id, memory_id).await; let result = ctx.memory_store.delete_for(user_id, memory_id).await;
tracing::info!("🔧 execute_tool: delete_memory({}) → {}", memory_id, result); tracing::info!(target: "ias::tool", "🔧 execute_tool: delete_memory({}) → {}", memory_id, result);
return result; return result;
} }
"update_memory" => { "update_memory" => {
@@ -781,7 +781,7 @@ fn execute_tool<'a>(
.memory_store .memory_store
.update_for(user_id, memory_id, content) .update_for(user_id, memory_id, content)
.await; .await;
tracing::info!("🔧 execute_tool: update_memory({}) → {}", memory_id, result); tracing::info!(target: "ias::tool", "🔧 execute_tool: update_memory({}) → {}", memory_id, result);
return result; return result;
} }
"read_summaries" => { "read_summaries" => {
@@ -795,13 +795,13 @@ fn execute_tool<'a>(
.collect::<Vec<_>>() .collect::<Vec<_>>()
.join("\n---\n") .join("\n---\n")
}; };
tracing::info!("🔧 execute_tool: read_summaries → {}条", sums.len()); tracing::info!(target: "ias::tool", "🔧 execute_tool: read_summaries → {}条", sums.len());
return result; return result;
} }
"query_capabilities" => { "query_capabilities" => {
let specs = crate::tools::specs(); let specs = crate::tools::specs();
let result = crate::tools::build_capability_guide(&specs); let result = crate::tools::build_capability_guide(&specs);
tracing::info!( tracing::info!(target: "ias::tool",
"🔧 execute_tool: query_capabilities → {}个工具", "🔧 execute_tool: query_capabilities → {}个工具",
specs.len() specs.len()
); );
@@ -824,7 +824,7 @@ fn execute_tool<'a>(
} }
let target_args = serde_json::to_string(&crate::tools::unpack_call_params(&cp)) let target_args = serde_json::to_string(&crate::tools::unpack_call_params(&cp))
.unwrap_or_default(); .unwrap_or_default();
tracing::info!( tracing::info!(target: "ias::tool",
"🔧 execute_tool: call_capability → {} args={}", "🔧 execute_tool: call_capability → {} args={}",
target_name, target_name,
target_args target_args
@@ -838,7 +838,7 @@ fn execute_tool<'a>(
// 内置工具注册表 // 内置工具注册表
match crate::tools::execute(name, arguments).await { match crate::tools::execute(name, arguments).await {
Some(r) => { Some(r) => {
tracing::info!( tracing::info!(target: "ias::tool",
"🔧 execute_tool: {} → success={} output={}", "🔧 execute_tool: {} → success={} output={}",
name, name,
r.success, r.success,
@@ -847,7 +847,7 @@ fn execute_tool<'a>(
r.output r.output
} }
None => { None => {
tracing::warn!("🔧 execute_tool: 未知工具 {}", name); tracing::warn!(target: "ias::tool", "🔧 execute_tool: 未知工具 {}", name);
format!("未知工具: {}", name) format!("未知工具: {}", name)
} }
} }
@@ -860,7 +860,7 @@ async fn send_consumer_loop(
rx: &mut tokio::sync::mpsc::Receiver<PipelineMessage>, rx: &mut tokio::sync::mpsc::Receiver<PipelineMessage>,
ctx: &DaemonCtx, ctx: &DaemonCtx,
) { ) {
info!("Send Consumer 已启动"); info!(target: "ias::queue", "Send Consumer 已启动");
while let Some(msg) = rx.recv().await { while let Some(msg) = rx.recv().await {
match msg.kind { match msg.kind {
@@ -869,7 +869,7 @@ async fn send_consumer_loop(
context_token, context_token,
} => { } => {
let user_id = &msg.channel.user_id; let user_id = &msg.channel.user_id;
info!( info!(target: "ias::queue",
"Send Consumer: user={} text_len={} text={}", "Send Consumer: user={} text_len={} text={}",
user_id, user_id,
text.len(), text.len(),
@@ -882,7 +882,7 @@ async fn send_consumer_loop(
.await .await
{ {
Ok(sent_id) => { Ok(sent_id) => {
info!( info!(target: "ias::queue",
"回复成功 user={} msg_id={}", "回复成功 user={} msg_id={}",
user_id.chars().take(5).collect::<String>(), user_id.chars().take(5).collect::<String>(),
sent_id sent_id
@@ -902,13 +902,13 @@ async fn send_consumer_loop(
Err(e) => error!("发送回复失败: {}", e), Err(e) => error!("发送回复失败: {}", e),
} }
} }
other => warn!( other => warn!(target: "ias::queue",
"Send Consumer 收到不期望: {:?}", "Send Consumer 收到不期望: {:?}",
std::mem::discriminant(&other) std::mem::discriminant(&other)
), ),
} }
} }
info!("Send Consumer 已停止"); info!(target: "ias::queue", "Send Consumer 已停止");
} }
// ─── 辅助函数 ─── // ─── 辅助函数 ───
src/db/mod.rs
+1 -1
View File
@@ -62,7 +62,7 @@ impl Database {
.await .await
.map_err(|e| format!("数据库迁移失败: {}", e))?; .map_err(|e| format!("数据库迁移失败: {}", e))?;
tracing::info!("数据库连接成功，迁移已完成"); tracing::info!(target: "ias::auth", "数据库连接成功，迁移已完成");
Ok(Self { pool }) Ok(Self { pool })
} }
src/llm/conversation.rs
+5 -5
View File
@@ -246,7 +246,7 @@ impl Conversation {
if s.is_idle_timeout() { if s.is_idle_timeout() {
drop(s); drop(s);
builder::trigger_idle_summary(&self.session, Some(&self.summarizer())).await; builder::trigger_idle_summary(&self.session, Some(&self.summarizer())).await;
tracing::info!("⏰ 检测到 12h 空闲，已生成摘要"); tracing::info!(target: "ias::tool", "⏰ 检测到 12h 空闲，已生成摘要");
} }
} }
@@ -308,7 +308,7 @@ impl Conversation {
if let Some(calls) = tool_calls if let Some(calls) = tool_calls
&& !calls.is_empty() { && !calls.is_empty() {
used_tools = true; used_tools = true;
tracing::info!( tracing::info!(target: "ias::tool",
"🔧 LLM 请求 {} 个工具: {}", "🔧 LLM 请求 {} 个工具: {}",
calls.len(), calls.len(),
calls calls
@@ -339,12 +339,12 @@ impl Conversation {
if result.starts_with(ASYNC_MARKER) { if result.starts_with(ASYNC_MARKER) {
has_async = true; has_async = true;
async_count += 1; async_count += 1;
tracing::info!("📦 {} → 异步入队", tc.function.name); tracing::info!(target: "ias::tool", "📦 {} → 异步入队", tc.function.name);
// 不添加到 session，等待 ToolResult 异步回喂 // 不添加到 session，等待 ToolResult 异步回喂
continue; continue;
} }
tracing::info!("📦 {} → {}", tc.function.name, result); tracing::info!(target: "ias::tool", "📦 {} → {}", tc.function.name, result);
self.session.lock().await.add_tool_result( self.session.lock().await.add_tool_result(
&tc.id, &tc.id,
&tc.function.name, &tc.function.name,
@@ -379,7 +379,7 @@ impl Conversation {
drop(s); drop(s);
builder::trigger_overflow_summary(&self.session, Some(&self.summarizer())) builder::trigger_overflow_summary(&self.session, Some(&self.summarizer()))
.await; .await;
tracing::info!("📦 上下文超预算，已触发溢出摘要"); tracing::info!(target: "ias::tool", "📦 上下文超预算，已触发溢出摘要");
} }
} }
src/logger.rs
+57 -11
View File
@@ -1,23 +1,37 @@
//! ## 日志初始化 //! ## 日志初始化 —— 四类日志分文件存储
//!
//! ### 日志分类
//! | 类别 | target | 文件 | 内容 |
//! |------|--------|------|------|
//! | 认证日志 | `ias::auth` | `auth.log` | 登录、token、监听器注册 |
//! | 消息队列日志 | `ias::queue` | `queue.log` | 消息入队/出队内容、队列路由 |
//! | 工具日志 | `ias::tool` | `tool.log` | 工具调用参数、输出、耗时、工具错误 |
//! | 错误日志 | (无特殊target) | `error.log` | 所有非工具调用的 ERROR/WARN |
//! //!
//! ### 两种模式 //! ### 两种模式
//! - **终端模式** — 彩色输出到 stderr，适合开发调试 //! - **终端模式** — 彩色输出到 stderr，适合开发调试
//! - **文件模式** (`with_file=true`) — 同时输出到终端和日滚文件 //! - **文件模式** (`with_file=true`) — 终端 + 四类日滚文件
//! `~/.ias/logs/ias.log.YYYY-MM-DD`
//! //!
//! 日志级别通过 `RUST_LOG` 环境变量控制（默认 `info`）。 //! 日志级别通过 `RUST_LOG` 环境变量控制（默认 `info`）。
use std::path::PathBuf; use std::path::PathBuf;
use tracing::Level;
use tracing_subscriber::filter::{filter_fn, Targets};
use tracing_subscriber::layer::SubscriberExt; use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt; use tracing_subscriber::util::SubscriberInitExt;
use tracing_subscriber::EnvFilter; use tracing_subscriber::{EnvFilter, Layer};
/// ## 日志初始化 /// ## 日志初始化 —— 四类日志分文件存储
///
/// ### 日志分类
/// * **认证日志** (`auth.log`) — 登录、token、监听器注册等认证相关
/// * **消息队列日志** (`queue.log`) — 消息入队/出队内容、队列路由
/// * **工具日志** (`tool.log`) — 工具调用参数、输出、耗时、工具错误
/// * **错误日志** (`error.log`) — 所有非工具调用的 ERROR/WARN 级别日志
/// ///
/// ### 两种模式 /// ### 两种模式
/// * **终端模式** — 彩色输出到 stderr，适合开发调试 /// * **终端模式** — 彩色输出到 stderr，适合开发调试
/// * **文件模式** (`with_file=true`) — 同时输出到终端和日滚文件 /// * **文件模式** (`with_file=true`) — 终端 + 四类日滚文件
/// `~/.ias/logs/ias.log.YYYY-MM-DD`
/// ///
/// 日志级别通过 `RUST_LOG` 环境变量控制（默认 `info`）。 /// 日志级别通过 `RUST_LOG` 环境变量控制（默认 `info`）。
pub fn init_logger(log_dir: Option<&str>, with_file: bool) { pub fn init_logger(log_dir: Option<&str>, with_file: bool) {
@@ -33,16 +47,48 @@ pub fn init_logger(log_dir: Option<&str>, with_file: bool) {
let dir_path = PathBuf::from(dir); let dir_path = PathBuf::from(dir);
std::fs::create_dir_all(&dir_path).ok(); std::fs::create_dir_all(&dir_path).ok();
let file_appender = tracing_appender::rolling::daily(&dir_path, "ias.log"); // ── 认证日志 ──
let file_layer = tracing_subscriber::fmt::layer() let auth_appender = tracing_appender::rolling::daily(&dir_path, "auth.log");
let auth_layer = tracing_subscriber::fmt::layer()
.with_target(false) .with_target(false)
.with_ansi(false) .with_ansi(false)
.with_writer(file_appender); .with_writer(auth_appender)
.with_filter(Targets::new().with_target("ias::auth", Level::INFO));
// ── 消息队列日志 ──
let queue_appender = tracing_appender::rolling::daily(&dir_path, "queue.log");
let queue_layer = tracing_subscriber::fmt::layer()
.with_target(false)
.with_ansi(false)
.with_writer(queue_appender)
.with_filter(Targets::new().with_target("ias::queue", Level::INFO));
// ── 工具日志 ──
let tool_appender = tracing_appender::rolling::daily(&dir_path, "tool.log");
let tool_layer = tracing_subscriber::fmt::layer()
.with_target(false)
.with_ansi(false)
.with_writer(tool_appender)
.with_filter(Targets::new().with_target("ias::tool", Level::INFO));
// ── 错误日志（所有非工具调用的 WARN/ERROR 级别日志） ──
let error_appender = tracing_appender::rolling::daily(&dir_path, "error.log");
let error_layer = tracing_subscriber::fmt::layer()
.with_target(false)
.with_ansi(false)
.with_writer(error_appender)
.with_filter(filter_fn(|metadata| {
metadata.level() <= &Level::WARN
&& !metadata.target().starts_with("ias::tool")
}));
tracing_subscriber::registry() tracing_subscriber::registry()
.with(env_filter) .with(env_filter)
.with(terminal) .with(terminal)
.with(file_layer) .with(auth_layer)
.with(queue_layer)
.with(tool_layer)
.with(error_layer)
.init(); .init();
return; return;
} }
src/main.rs
+6 -6
View File
@@ -59,7 +59,7 @@ async fn main() {
let fallback = std::path::PathBuf::from(&home).join(".ias").join(".env"); let fallback = std::path::PathBuf::from(&home).join(".ias").join(".env");
if fallback.exists() { if fallback.exists() {
dotenvy::from_path(&fallback).ok(); dotenvy::from_path(&fallback).ok();
tracing::info!("使用全局环境配置: {}", fallback.display()); tracing::info!(target: "ias::auth", "使用全局环境配置: {}", fallback.display());
} }
} }
@@ -89,7 +89,7 @@ async fn main() {
let database = match Database::connect().await { let database = match Database::connect().await {
Ok(db) => { Ok(db) => {
info!("✅ 数据库连接成功"); info!(target: "ias::auth", "✅ 数据库连接成功");
Arc::new(db) Arc::new(db)
} }
Err(e) => { Err(e) => {
@@ -159,9 +159,9 @@ async fn cmd_login(timeout_secs: u64, database: &Arc<Database>) {
// 存数据库 // 存数据库
if let Err(e) = db::models::save_auth(database.pool(), &auth).await { if let Err(e) = db::models::save_auth(database.pool(), &auth).await {
error!("保存 auth 到数据库失败: {}", e); error!(target: "ias::auth", "保存 auth 到数据库失败: {}", e);
} else { } else {
info!("认证信息已保存到数据库"); info!(target: "ias::auth", "认证信息已保存到数据库");
} }
println!("\n✅ 登录成功！"); println!("\n✅ 登录成功！");
@@ -172,7 +172,7 @@ async fn cmd_login(timeout_secs: u64, database: &Arc<Database>) {
); );
println!(" API: {}", result.base_url); println!(" API: {}", result.base_url);
} }
Err(e) => error!("登录失败: {}", e), Err(e) => error!(target: "ias::auth", "登录失败: {}", e),
} }
} }
@@ -263,7 +263,7 @@ async fn cmd_send(
let auth = match auth { let auth = match auth {
Some(a) => a, Some(a) => a,
None => { None => {
error!("未登录，请先执行 login 命令"); error!(target: "ias::auth", "未登录，请先执行 login 命令");
return; return;
} }
}; };
src/queue/runner.rs
+8 -6
View File
@@ -110,11 +110,11 @@ impl QueueRunner {
/// 启动路由主循环（阻塞，应在 tokio::spawn 中运行） /// 启动路由主循环（阻塞，应在 tokio::spawn 中运行）
pub async fn run(&self) { pub async fn run(&self) {
info!("QueueRunner 已启动"); info!(target: "ias::queue", "QueueRunner 已启动");
loop { loop {
// 检查关闭信号 // 检查关闭信号
if self.shutdown.load(Ordering::Relaxed) { if self.shutdown.load(Ordering::Relaxed) {
info!("QueueRunner 收到关闭信号，停止路由"); info!(target: "ias::queue", "QueueRunner 收到关闭信号，停止路由");
break; break;
} }
@@ -138,6 +138,7 @@ impl QueueRunner {
if let Err(_e) = result { if let Err(_e) = result {
warn!( warn!(
target: "ias::queue",
"路由消息失败 (target={:?}, user={}, corr={}): 通道已关闭，跳过", "路由消息失败 (target={:?}, user={}, corr={}): 通道已关闭，跳过",
target, user_id, correlation_id target, user_id, correlation_id
); );
@@ -155,7 +156,7 @@ impl QueueRunner {
} }
} }
} }
info!("QueueRunner 已停止"); info!(target: "ias::queue", "QueueRunner 已停止");
} }
} }
@@ -171,6 +172,7 @@ impl EnqueueHandle {
pub async fn enqueue(&self, msg: PipelineMessage) { pub async fn enqueue(&self, msg: PipelineMessage) {
if self.shutdown.load(Ordering::Relaxed) { if self.shutdown.load(Ordering::Relaxed) {
warn!( warn!(
target: "ias::queue",
"队列已关闭，丢弃消息: user={}", "队列已关闭，丢弃消息: user={}",
msg.user_id() msg.user_id()
); );
@@ -200,7 +202,7 @@ pub async fn drain_and_shutdown(
runner_shutdown: &ShutdownHandle, runner_shutdown: &ShutdownHandle,
consumer_handles: Vec<tokio::task::JoinHandle<()>>, consumer_handles: Vec<tokio::task::JoinHandle<()>>,
) { ) {
info!("开始关闭队列系统..."); info!(target: "ias::queue", "开始关闭队列系统...");
// 1. 阻止新消息入队（设置关闭标志） // 1. 阻止新消息入队（设置关闭标志）
runner_shutdown.shutdown(); runner_shutdown.shutdown();
@@ -211,9 +213,9 @@ pub async fn drain_and_shutdown(
// 3. 等待消费者 task 完成 // 3. 等待消费者 task 完成
for handle in consumer_handles { for handle in consumer_handles {
if let Err(e) = handle.await { if let Err(e) = handle.await {
error!("消费者 task 结束异常: {:?}", e); error!(target: "ias::queue", "消费者 task 结束异常: {:?}", e);
} }
} }
info!("队列系统已完全关闭"); info!(target: "ias::queue", "队列系统已完全关闭");
} }
src/scheduler.rs
+4 -4
View File
@@ -49,13 +49,13 @@ impl Scheduler {
let pool = match self.pool.as_ref() { let pool = match self.pool.as_ref() {
Some(p) => p.clone(), Some(p) => p.clone(),
None => { None => {
tracing::info!("调度器：数据库未配置，跳过"); tracing::info!(target: "ias::queue", "调度器：数据库未配置，跳过");
return; return;
} }
}; };
let mut tick = interval(Duration::from_secs(5)); let mut tick = interval(Duration::from_secs(5));
tracing::info!("调度器已启动（每 5s 检查）"); tracing::info!(target: "ias::queue", "调度器已启动（每 5s 检查）");
loop { loop {
tick.tick().await; tick.tick().await;
@@ -69,7 +69,7 @@ impl Scheduler {
}; };
for task in tasks { for task in tasks {
tracing::info!("⏰ 执行定时任务: {}", task.name); tracing::info!(target: "ias::queue", "⏰ 执行定时任务: {}", task.name);
// 执行任务 // 执行任务
let result = execute_task(&task).await; let result = execute_task(&task).await;
@@ -83,7 +83,7 @@ impl Scheduler {
tracing::error!("发送定时任务通知失败: {}", e); tracing::error!("发送定时任务通知失败: {}", e);
} }
tracing::info!("✅ 定时任务完成: {} → {}", task.name, result); tracing::info!(target: "ias::queue", "✅ 定时任务完成: {} → {}", task.name, result);
} }
} }
} }
src/tools/builtins/amap.rs
+13 -15
View File
@@ -41,8 +41,6 @@
use reqwest::Client; use reqwest::Client;
use std::time::Duration; use std::time::Duration;
use tracing::info;
use crate::tools::types::{RiskLevel, SkillResult, SkillSpec}; use crate::tools::types::{RiskLevel, SkillResult, SkillSpec};
// ═══════════════════════════════════════════════ // ═══════════════════════════════════════════════
@@ -273,8 +271,8 @@ impl AmapClient {
params.push(("waypoints", wp)); params.push(("waypoints", wp));
} }
info!( tracing::info!(target: "ias::tool",
"parms: {:?}", "驾车路线请求 parms: {:?}",
serde_json::to_string(&params).unwrap_or_default() serde_json::to_string(&params).unwrap_or_default()
); );
@@ -290,8 +288,8 @@ impl AmapClient {
.map_err(|e| format!("解析驾车路线响应失败: {}", e))?; .map_err(|e| format!("解析驾车路线响应失败: {}", e))?;
if resp["status"].as_str() != Some("1") { if resp["status"].as_str() != Some("1") {
info!( tracing::info!(target: "ias::tool",
"parms: {:?}", "驾车路线失败 parms: {:?}",
serde_json::to_string(&resp).unwrap_or_default() serde_json::to_string(&resp).unwrap_or_default()
); );
return Err(format!( return Err(format!(
@@ -456,7 +454,7 @@ pub async fn poi_search_execute(params: serde_json::Value) -> SkillResult {
}; };
let result = if let Some(loc) = location { let result = if let Some(loc) = location {
tracing::info!( tracing::info!(target: "ias::tool",
"📍 周边搜索: {} @ {} (radius={}m, sort=distance)", "📍 周边搜索: {} @ {} (radius={}m, sort=distance)",
keywords, keywords,
loc, loc,
@@ -466,7 +464,7 @@ pub async fn poi_search_execute(params: serde_json::Value) -> SkillResult {
.poi_around(keywords, loc, radius, page_num, page_size, "distance") .poi_around(keywords, loc, radius, page_num, page_size, "distance")
.await .await
} else { } else {
tracing::info!("🔍 POI 搜索: {} city={:?}", keywords, city); tracing::info!(target: "ias::tool", "🔍 POI 搜索: {} city={:?}", keywords, city);
client client
.poi_text_search(keywords, city, page_num, page_size) .poi_text_search(keywords, city, page_num, page_size)
.await .await
@@ -513,7 +511,7 @@ pub async fn geocode_execute(params: serde_json::Value) -> SkillResult {
Err(e) => return SkillResult::error(e), Err(e) => return SkillResult::error(e),
}; };
tracing::info!("📍 地理编码: {} city={:?}", address, city); tracing::info!(target: "ias::tool", "📍 地理编码: {} city={:?}", address, city);
match client.geocode(address, city).await { match client.geocode(address, city).await {
Ok(data) => SkillResult::ok_with_data("✅ 地理编码完成".to_string(), data), Ok(data) => SkillResult::ok_with_data("✅ 地理编码完成".to_string(), data),
@@ -554,7 +552,7 @@ pub async fn reverse_geocode_execute(params: serde_json::Value) -> SkillResult {
Err(e) => return SkillResult::error(e), Err(e) => return SkillResult::error(e),
}; };
tracing::info!("📍 逆地理编码: {}", location); tracing::info!(target: "ias::tool", "📍 逆地理编码: {}", location);
match client.regeocode(location).await { match client.regeocode(location).await {
Ok(data) => SkillResult::ok_with_data("✅ 逆地理编码完成".to_string(), data), Ok(data) => SkillResult::ok_with_data("✅ 逆地理编码完成".to_string(), data),
@@ -604,7 +602,7 @@ pub async fn route_plan_execute(params: serde_json::Value) -> SkillResult {
Err(e) => return SkillResult::error(e), Err(e) => return SkillResult::error(e),
}; };
tracing::info!( tracing::info!(target: "ias::tool",
"🛣️ 路径规划: type={}, {} → {}", "🛣️ 路径规划: type={}, {} → {}",
route_type, route_type,
origin, origin,
@@ -706,7 +704,7 @@ pub async fn travel_plan_execute(params: serde_json::Value) -> SkillResult {
Err(e) => return SkillResult::error(e), Err(e) => return SkillResult::error(e),
}; };
tracing::info!( tracing::info!(target: "ias::tool",
"🗺️ 旅游规划: city={}, interests={:?}, route={}", "🗺️ 旅游规划: city={}, interests={:?}, route={}",
city, city,
interests, interests,
@@ -718,7 +716,7 @@ pub async fn travel_plan_execute(params: serde_json::Value) -> SkillResult {
// 第一步：搜索各类兴趣点 // 第一步：搜索各类兴趣点
for interest in &interests { for interest in &interests {
tracing::info!("📍 搜索 {}...", interest); tracing::info!(target: "ias::tool", "📍 搜索 {}...", interest);
match client.poi_text_search(interest, Some(city), 1, 5).await { match client.poi_text_search(interest, Some(city), 1, 5).await {
Ok(data) => { Ok(data) => {
if let Some(pois) = data["pois"].as_array() { if let Some(pois) = data["pois"].as_array() {
@@ -740,10 +738,10 @@ pub async fn travel_plan_execute(params: serde_json::Value) -> SkillResult {
})); }));
} }
all_pois.extend(pois.clone()); all_pois.extend(pois.clone());
tracing::info!(" 找到 {} 个 {}", pois.len(), interest); tracing::info!(target: "ias::tool", " 找到 {} 个 {}", pois.len(), interest);
} }
} }
Err(e) => tracing::warn!(" 搜索 {} 失败: {}", interest, e), Err(e) => tracing::warn!(target: "ias::tool", " 搜索 {} 失败: {}", interest, e),
} }
} }
src/tools/builtins/weather.rs
+2 -2
View File
@@ -258,7 +258,7 @@ impl QWeatherClient {
async fn lookup_city(&self, location: &str) -> Result<String, String> { async fn lookup_city(&self, location: &str) -> Result<String, String> {
// 检查缓存 // 检查缓存
if let Some(id) = get_cached_city(location) { if let Some(id) = get_cached_city(location) {
tracing::debug!("🏙️ 城市缓存命中: {} → {}", location, id); tracing::debug!(target: "ias::tool", "🏙️ 城市缓存命中: {} → {}", location, id);
return Ok(id); return Ok(id);
} }
@@ -285,7 +285,7 @@ impl QWeatherClient {
let id = city.id.clone(); let id = city.id.clone();
cache_city(location.to_string(), id.clone()); cache_city(location.to_string(), id.clone());
tracing::debug!("🏙️ 城市查询: {} → {} ({})", location, city.name, id); tracing::debug!(target: "ias::tool", "🏙️ 城市查询: {} → {} ({})", location, city.name, id);
Ok(id) Ok(id)
} }
src/wechat/client.rs
+8 -7
View File
@@ -156,7 +156,7 @@ impl WeChatClient {
}) })
} }
Err(e) => { Err(e) => {
warn!("轮询二维码状态网络错误: {}，继续等待", e); warn!(target: "ias::auth", "轮询二维码状态网络错误: {}，继续等待", e);
Ok(StatusResponse { Ok(StatusResponse {
status: "wait".to_string(), status: "wait".to_string(),
bot_token: None, bot_token: None,
@@ -175,7 +175,7 @@ impl WeChatClient {
on_qrcode: impl Fn(&str), on_qrcode: impl Fn(&str),
timeout_secs: u64, timeout_secs: u64,
) -> Result<LoginResult, String> { ) -> Result<LoginResult, String> {
info!("开始微信扫码登录..."); info!(target: "ias::auth", "开始微信扫码登录...");
let (qrcode, qrcode_img_content) = self.get_qrcode().await?; let (qrcode, qrcode_img_content) = self.get_qrcode().await?;
@@ -217,7 +217,7 @@ impl WeChatClient {
"scaned_but_redirect" => { "scaned_but_redirect" => {
if let Some(host) = &status.redirect_host { if let Some(host) = &status.redirect_host {
current_base = format!("https://{}", host); current_base = format!("https://{}", host);
info!("IDC 重定向到: {}", current_base); info!(target: "ias::auth", "IDC 重定向到: {}", current_base);
} }
} }
"confirmed" => { "confirmed" => {
@@ -236,7 +236,7 @@ impl WeChatClient {
*self.token.lock().await = token.clone(); *self.token.lock().await = token.clone();
*self.account_id.lock().await = account_id.clone(); *self.account_id.lock().await = account_id.clone();
info!("✅ 登录成功! bot_id={}", account_id); info!(target: "ias::auth", "✅ 登录成功! bot_id={}", account_id);
return Ok(LoginResult { return Ok(LoginResult {
token, token,
account_id, account_id,
@@ -248,7 +248,7 @@ impl WeChatClient {
return Err("二维码已过期".to_string()); return Err("二维码已过期".to_string());
} }
_ => { _ => {
warn!("未知状态: {}", status.status); warn!(target: "ias::auth", "未知状态: {}", status.status);
} }
} }
@@ -279,7 +279,7 @@ impl WeChatClient {
)); ));
} }
info!("监听器已注册"); info!(target: "ias::auth", "监听器已注册");
Ok(()) Ok(())
} }
@@ -298,7 +298,7 @@ impl WeChatClient {
.await .await
.map_err(|e| format!("解析 notifyStop 响应失败: {}", e))?; .map_err(|e| format!("解析 notifyStop 响应失败: {}", e))?;
info!("监听器已注销"); info!(target: "ias::auth", "监听器已注销");
Ok(()) Ok(())
} }
@@ -322,6 +322,7 @@ impl WeChatClient {
.map_err(|e| format!("解析 getUpdates 响应失败: {}", e))?; .map_err(|e| format!("解析 getUpdates 响应失败: {}", e))?;
if resp.ret != 0 || resp.errcode.unwrap_or(0) != 0 { if resp.ret != 0 || resp.errcode.unwrap_or(0) != 0 {
tracing::warn!( tracing::warn!(
target: "ias::auth",
"getUpdates 返回错误: ret={} errcode={:?} errmsg={:?}", "getUpdates 返回错误: ret={} errcode={:?} errmsg={:?}",
resp.ret, resp.ret,
resp.errcode, resp.errcode,