From d334b6f3eb6b4c2f2d5939e6f66fc8ee6189b809 Mon Sep 17 00:00:00 2001 From: Zichao Lin Date: Thu, 2 Jul 2026 21:00:40 +0800 Subject: [PATCH] feat: enhance logging detail across all modules - email_client: log IMAP connection, login, UNSEEN count, each email details (subject/sender/body size), mark-as-seen progress - ai_client: log AI request params, timing, token usage, response size - smtp_client: log SMTP connect, login, send details - tg_bot: log all callback actions with subject context, message states - main: periodic queue depth report (email_queue/tg_queue/pending_uids) --- main.py | 6 ++++++ src/ai_client.py | 17 +++++++++++++++++ src/email_client.py | 14 ++++++++++++++ src/smtp_client.py | 7 +++++++ src/tg_bot.py | 24 +++++++++++++++++++++--- 5 files changed, 65 insertions(+), 3 deletions(-) diff --git a/main.py b/main.py index 25b2ba7..f5a680e 100644 --- a/main.py +++ b/main.py @@ -116,8 +116,14 @@ def main(): for t in threads: t.start() + logger.info("所有线程已启动,进入主循环") + tick = 0 try: while _running: + tick += 1 + if tick % 30 == 0: + logger.info("队列状态: email_queue=%d tg_queue=%d pending_uids=%d", + _email_queue.qsize(), _tg_queue.qsize(), len(_pending_uids)) time.sleep(1) except KeyboardInterrupt: _running = False diff --git a/src/ai_client.py b/src/ai_client.py index bcc2e4c..52de362 100644 --- a/src/ai_client.py +++ b/src/ai_client.py @@ -1,9 +1,13 @@ import json +import logging +import time from typing import Any import requests from src.config import AIConfig from src.retry import retry +logger = logging.getLogger(__name__) + SYSTEM_PROMPT = """你是一个邮件摘要助手。请分析邮件内容并以 JSON 格式返回结构化摘要。 返回格式必须严格遵循以下 JSON schema: @@ -35,6 +39,8 @@ SYSTEM_PROMPT = """你是一个邮件摘要助手。请分析邮件内容并以 @retry() def summarize_email(ai_cfg: AIConfig, recipient: str, subject: str, sender: str, body: str) -> dict[str, Any]: + body_preview = body[:80].replace("\n", " ") + logger.info("AI 摘要请求: sender=%s subject=%s body_preview=%s", sender, subject, body_preview) content = f"收件人: {recipient}\n发件人: {sender}\n主题: {subject}\n正文:\n{body[:4000]}" payload = { @@ -68,6 +74,8 @@ MORE_REPLIES_PROMPT = """你是一个邮件回复助手。根据以下邮件内 @retry() def generate_more_replies(ai_cfg: AIConfig, sender: str, subject: str, body: str, previous_suggestions: list[dict], user_hint: str = "") -> list[dict]: + logger.info("AI 换批请求: sender=%s subject=%s user_hint=%s prev=%d 条", + sender, subject, user_hint or "(无)", len(previous_suggestions)) content = f"发件人: {sender}\n主题: {subject}\n正文:\n{body[:4000]}\n\n已生成过的回复:\n" for i, s in enumerate(previous_suggestions, 1): content += f"{i}. {s['text']}\n" @@ -87,6 +95,9 @@ def generate_more_replies(ai_cfg: AIConfig, sender: str, subject: str, body: str def _call_deepseek(ai_cfg: AIConfig, payload: dict) -> dict: + model = payload.get("model", ai_cfg.model) + logger.info("DeepSeek API 请求: model=%s", model) + t0 = time.time() headers = { "Authorization": f"Bearer {ai_cfg.api_key}", "Content-Type": "application/json", @@ -97,7 +108,13 @@ def _call_deepseek(ai_cfg: AIConfig, payload: dict) -> dict: json=payload, timeout=60, ) + elapsed = time.time() - t0 resp.raise_for_status() result = resp.json() + usage = result.get("usage", {}) + prompt_tokens = usage.get("prompt_tokens", "?") + completion_tokens = usage.get("completion_tokens", "?") raw = result["choices"][0]["message"]["content"] + logger.info("DeepSeek API 响应: %.2fs, token=%d+%d, 输出长度=%d", + elapsed, prompt_tokens, completion_tokens, len(raw)) return json.loads(raw) diff --git a/src/email_client.py b/src/email_client.py index 8a5d54c..6417eb0 100644 --- a/src/email_client.py +++ b/src/email_client.py @@ -1,11 +1,14 @@ import imaplib import email +import logging from email.header import decode_header from email.utils import parsedate_to_datetime from typing import Optional from src.config import EmailAccount from src.retry import retry +logger = logging.getLogger(__name__) + class Email: def __init__(self, uid: bytes, subject: str, sender: str, body: str, date: str): @@ -69,11 +72,15 @@ def _select_mailbox(conn, mailbox: str = "INBOX"): def _login_and_prepare(account: EmailAccount): + logger.info("连接 %s:%d", account.imap_server, account.imap_port) conn = imaplib.IMAP4_SSL(account.imap_server, account.imap_port) conn.login(account.username, account.password) + logger.info("登录成功: %s", account.username) if _check_provider(account.username, _PROVIDERS_NEED_ID): + logger.info("发送 ID 命令 (126/163 兼容)") _send_id_command(conn) _select_mailbox(conn) + logger.info("已选择 INBOX") return conn @@ -83,11 +90,13 @@ def fetch_unseen_emails(account: EmailAccount) -> list[Email]: _, data = conn.uid("SEARCH", None, "UNSEEN") uids = data[0].split() if data[0] else [] + logger.info("UNSEEN 数量: %d", len(uids)) emails = [] for uid in uids: _, msg_data = conn.uid("FETCH", uid, "RFC822") if msg_data[0] is None: + logger.warning("UID %s FETCH 返回空,跳过", uid) continue raw_email = msg_data[0][1] msg = email.message_from_bytes(raw_email) @@ -96,10 +105,13 @@ def fetch_unseen_emails(account: EmailAccount) -> list[Email]: sender = _decode_str(msg.get("From", "")) date_str = msg.get("Date", "") body = _get_text_from_msg(msg) + body_len = len(body) + logger.info(" 邮件: [%s] %s <%s> (%d 字符)", subject, sender, date_str, body_len) emails.append(Email(uid=uid, subject=subject, sender=sender, body=body, date=date_str)) conn.logout() + logger.info("共获取 %d 封新邮件", len(emails)) return emails @@ -107,7 +119,9 @@ def fetch_unseen_emails(account: EmailAccount) -> list[Email]: def mark_as_seen(account: EmailAccount, uids: list[bytes]): if not uids: return + logger.info("标记 %d 封邮件为已读", len(uids)) conn = _login_and_prepare(account) for uid in uids: conn.uid("STORE", uid, "+FLAGS", "\\Seen") conn.logout() + logger.info("标记完成") diff --git a/src/smtp_client.py b/src/smtp_client.py index 7ad2b94..e1c9f7c 100644 --- a/src/smtp_client.py +++ b/src/smtp_client.py @@ -1,9 +1,12 @@ import smtplib +import logging from email.mime.text import MIMEText from email.mime.multipart import MIMEMultipart from src.config import EmailAccount from src.retry import retry +logger = logging.getLogger(__name__) + @retry() def send_reply(account: EmailAccount, to_addr: str, subject: str, body: str): @@ -11,6 +14,7 @@ def send_reply(account: EmailAccount, to_addr: str, subject: str, body: str): raise RuntimeError(f"账号 {account.username} 未配置 SMTP") s = account.smtp + logger.info("SMTP 连接: %s:%d (ssl=%s)", s.server, s.port, s.use_ssl) if s.use_ssl: conn = smtplib.SMTP_SSL(s.server, s.port, timeout=15) else: @@ -19,8 +23,10 @@ def send_reply(account: EmailAccount, to_addr: str, subject: str, body: str): conn.starttls() conn.login(account.username, account.password) + logger.info("SMTP 登录成功") reply_subject = subject if subject.lower().startswith("re:") else f"Re: {subject}" + logger.info("SMTP 发送: to=%s subject=%s body=%d 字符", to_addr, reply_subject, len(body)) msg = MIMEMultipart("alternative") msg["From"] = account.username @@ -30,3 +36,4 @@ def send_reply(account: EmailAccount, to_addr: str, subject: str, body: str): conn.sendmail(account.username, [to_addr], msg.as_string()) conn.quit() + logger.info("SMTP 发送完成") diff --git a/src/tg_bot.py b/src/tg_bot.py index 074e1ad..8e60859 100644 --- a/src/tg_bot.py +++ b/src/tg_bot.py @@ -210,6 +210,8 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): action = parts[0] ctx = _email_contexts.get(msg_id) + subject = ctx["subject"] if ctx else "?" + logger.info("TG 回调: action=%s msg_id=%d subject=%s", action, msg_id, subject) if action == CALLBACK_VIEW_ORIG and ctx: can_reply = ctx.get("can_reply", True) @@ -219,6 +221,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): "text": text, "parse_mode": "MarkdownV2", "reply_markup": _orig_keyboard(can_reply), }) + logger.info(" 切换为原文视图") elif action == CALLBACK_VIEW_SUMM and ctx: can_reply = ctx.get("can_reply", True) @@ -227,6 +230,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): "text": ctx["summary_text"], "parse_mode": "MarkdownV2", "reply_markup": _summary_keyboard(can_reply), }) + logger.info(" 切换回摘要视图") elif action == CALLBACK_REPLY and ctx: prompt_msg_id = send_text( @@ -237,11 +241,13 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): "state": "awaiting_reply", "summary_msg_id": msg_id, "prompt_msg_id": prompt_msg_id, } + logger.info(" 进入回复流程, prompt_msg_id=%d", prompt_msg_id) elif action == CALLBACK_AI_REPLY and ctx: suggestions = ctx["summary_data"].get("reply_suggestions", []) if not suggestions: send_text(tg_cfg, str(chat_id), "此邮件无需回复。") + logger.info(" AI 判定无需回复,隐藏") return _conversations[chat_id] = { @@ -250,7 +256,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): "ai_suggestions": suggestions, "all_suggestions": list(suggestions), } - + logger.info(" 显示 AI 回复建议 (%d 条)", len(suggestions)) _show_ai_suggestions(tg_cfg, chat_id, msg_id, suggestions) elif action == CALLBACK_SELECT_REPLY and ctx: @@ -262,6 +268,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): if idx >= len(suggestions): return sel = suggestions[idx] + logger.info(" 选择回复 #%d: %s", idx, sel["text"][:60]) _do_send_reply(tg_cfg, cfg, chat_id, msg_id, ctx, sel["text"]) send_text(tg_cfg, str(chat_id), f"✅ 已发送: {sel['text']}") _conversations.pop(chat_id, None) @@ -276,6 +283,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): conv = _conversations.get(chat_id) if not conv or conv.get("summary_msg_id") != msg_id: return + logger.info(" 换一批 (已有 %d 条历史)", len(conv.get("all_suggestions", []))) try: new_suggestions = generate_more_replies( cfg.ai, ctx["sender"], ctx["subject"], ctx["original_body"], @@ -287,6 +295,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): if new_suggestions: conv["ai_suggestions"] = new_suggestions conv["all_suggestions"].extend(new_suggestions) + logger.info(" 新生成 %d 条回复", len(new_suggestions)) _show_ai_suggestions(tg_cfg, chat_id, msg_id, new_suggestions) elif action == CALLBACK_HINT and ctx: @@ -298,6 +307,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): if conv and conv.get("summary_msg_id") == msg_id: conv["state"] = "awaiting_ai_hint" conv["prompt_msg_id"] = prompt_msg_id + logger.info(" 等待用户输入 AI 提示") elif action == CALLBACK_CANCEL: _conversations.pop(chat_id, None) @@ -308,8 +318,10 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict): "text": ctx["summary_text"], "parse_mode": "MarkdownV2", "reply_markup": _summary_keyboard(can_reply), }) + logger.info(" 取消, 恢复摘要视图") else: delete_message(tg_cfg, str(chat_id), msg_id) + logger.info(" 取消, 删除提示消息") def _handle_message(tg_cfg: TelegramConfig, cfg: Config, msg: dict): @@ -323,14 +335,18 @@ def _handle_message(tg_cfg: TelegramConfig, cfg: Config, msg: dict): user_msg_id = msg["message_id"] chat_id_str = str(chat_id) prompt_msg_id = conv.get("prompt_msg_id") + state = conv.get("state") - if conv.get("state") == "awaiting_reply": + logger.info("TG 消息: state=%s text=%s", state, text[:60]) + + if state == "awaiting_reply": ctx = _email_contexts.get(conv["summary_msg_id"]) if not ctx: _conversations.pop(chat_id, None) delete_message(tg_cfg, chat_id_str, user_msg_id) if prompt_msg_id: delete_message(tg_cfg, chat_id_str, prompt_msg_id) + logger.info(" 上下文已丢失,清理") return delete_message(tg_cfg, chat_id_str, user_msg_id) @@ -339,8 +355,9 @@ def _handle_message(tg_cfg: TelegramConfig, cfg: Config, msg: dict): _do_send_reply(tg_cfg, cfg, chat_id, conv["summary_msg_id"], ctx, text) send_text(tg_cfg, chat_id_str, "✅ 回复已发送!") _conversations.pop(chat_id, None) + logger.info(" 回复发送完成") - elif conv.get("state") == "awaiting_ai_hint": + elif state == "awaiting_ai_hint": ctx = _email_contexts.get(conv["summary_msg_id"]) if not ctx: _conversations.pop(chat_id, None) @@ -367,6 +384,7 @@ def _handle_message(tg_cfg: TelegramConfig, cfg: Config, msg: dict): conv["all_suggestions"].extend(new_suggestions) conv["state"] = "ai_reply_selection" conv.pop("prompt_msg_id", None) + logger.info(" 根据提示生成 %d 条新回复", len(new_suggestions)) _show_ai_suggestions(tg_cfg, chat_id, conv["summary_msg_id"], new_suggestions)