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)
This commit is contained in:
2026-07-02 21:00:40 +08:00
parent 934d6a7545
commit d334b6f3eb
5 changed files with 65 additions and 3 deletions

View File

@@ -116,8 +116,14 @@ def main():
for t in threads: for t in threads:
t.start() t.start()
logger.info("所有线程已启动,进入主循环")
tick = 0
try: try:
while _running: 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) time.sleep(1)
except KeyboardInterrupt: except KeyboardInterrupt:
_running = False _running = False

View File

@@ -1,9 +1,13 @@
import json import json
import logging
import time
from typing import Any from typing import Any
import requests import requests
from src.config import AIConfig from src.config import AIConfig
from src.retry import retry from src.retry import retry
logger = logging.getLogger(__name__)
SYSTEM_PROMPT = """你是一个邮件摘要助手。请分析邮件内容并以 JSON 格式返回结构化摘要。 SYSTEM_PROMPT = """你是一个邮件摘要助手。请分析邮件内容并以 JSON 格式返回结构化摘要。
返回格式必须严格遵循以下 JSON schema 返回格式必须严格遵循以下 JSON schema
@@ -35,6 +39,8 @@ SYSTEM_PROMPT = """你是一个邮件摘要助手。请分析邮件内容并以
@retry() @retry()
def summarize_email(ai_cfg: AIConfig, recipient: str, subject: str, sender: str, body: str) -> dict[str, Any]: 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]}" content = f"收件人: {recipient}\n发件人: {sender}\n主题: {subject}\n正文:\n{body[:4000]}"
payload = { payload = {
@@ -68,6 +74,8 @@ MORE_REPLIES_PROMPT = """你是一个邮件回复助手。根据以下邮件内
@retry() @retry()
def generate_more_replies(ai_cfg: AIConfig, sender: str, subject: str, body: str, def generate_more_replies(ai_cfg: AIConfig, sender: str, subject: str, body: str,
previous_suggestions: list[dict], user_hint: str = "") -> list[dict]: 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" content = f"发件人: {sender}\n主题: {subject}\n正文:\n{body[:4000]}\n\n已生成过的回复:\n"
for i, s in enumerate(previous_suggestions, 1): for i, s in enumerate(previous_suggestions, 1):
content += f"{i}. {s['text']}\n" 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: 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 = { headers = {
"Authorization": f"Bearer {ai_cfg.api_key}", "Authorization": f"Bearer {ai_cfg.api_key}",
"Content-Type": "application/json", "Content-Type": "application/json",
@@ -97,7 +108,13 @@ def _call_deepseek(ai_cfg: AIConfig, payload: dict) -> dict:
json=payload, json=payload,
timeout=60, timeout=60,
) )
elapsed = time.time() - t0
resp.raise_for_status() resp.raise_for_status()
result = resp.json() 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"] 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) return json.loads(raw)

View File

@@ -1,11 +1,14 @@
import imaplib import imaplib
import email import email
import logging
from email.header import decode_header from email.header import decode_header
from email.utils import parsedate_to_datetime from email.utils import parsedate_to_datetime
from typing import Optional from typing import Optional
from src.config import EmailAccount from src.config import EmailAccount
from src.retry import retry from src.retry import retry
logger = logging.getLogger(__name__)
class Email: class Email:
def __init__(self, uid: bytes, subject: str, sender: str, body: str, date: str): 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): 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 = imaplib.IMAP4_SSL(account.imap_server, account.imap_port)
conn.login(account.username, account.password) conn.login(account.username, account.password)
logger.info("登录成功: %s", account.username)
if _check_provider(account.username, _PROVIDERS_NEED_ID): if _check_provider(account.username, _PROVIDERS_NEED_ID):
logger.info("发送 ID 命令 (126/163 兼容)")
_send_id_command(conn) _send_id_command(conn)
_select_mailbox(conn) _select_mailbox(conn)
logger.info("已选择 INBOX")
return conn return conn
@@ -83,11 +90,13 @@ def fetch_unseen_emails(account: EmailAccount) -> list[Email]:
_, data = conn.uid("SEARCH", None, "UNSEEN") _, data = conn.uid("SEARCH", None, "UNSEEN")
uids = data[0].split() if data[0] else [] uids = data[0].split() if data[0] else []
logger.info("UNSEEN 数量: %d", len(uids))
emails = [] emails = []
for uid in uids: for uid in uids:
_, msg_data = conn.uid("FETCH", uid, "RFC822") _, msg_data = conn.uid("FETCH", uid, "RFC822")
if msg_data[0] is None: if msg_data[0] is None:
logger.warning("UID %s FETCH 返回空,跳过", uid)
continue continue
raw_email = msg_data[0][1] raw_email = msg_data[0][1]
msg = email.message_from_bytes(raw_email) 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", "")) sender = _decode_str(msg.get("From", ""))
date_str = msg.get("Date", "") date_str = msg.get("Date", "")
body = _get_text_from_msg(msg) 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)) emails.append(Email(uid=uid, subject=subject, sender=sender, body=body, date=date_str))
conn.logout() conn.logout()
logger.info("共获取 %d 封新邮件", len(emails))
return emails return emails
@@ -107,7 +119,9 @@ def fetch_unseen_emails(account: EmailAccount) -> list[Email]:
def mark_as_seen(account: EmailAccount, uids: list[bytes]): def mark_as_seen(account: EmailAccount, uids: list[bytes]):
if not uids: if not uids:
return return
logger.info("标记 %d 封邮件为已读", len(uids))
conn = _login_and_prepare(account) conn = _login_and_prepare(account)
for uid in uids: for uid in uids:
conn.uid("STORE", uid, "+FLAGS", "\\Seen") conn.uid("STORE", uid, "+FLAGS", "\\Seen")
conn.logout() conn.logout()
logger.info("标记完成")

View File

@@ -1,9 +1,12 @@
import smtplib import smtplib
import logging
from email.mime.text import MIMEText from email.mime.text import MIMEText
from email.mime.multipart import MIMEMultipart from email.mime.multipart import MIMEMultipart
from src.config import EmailAccount from src.config import EmailAccount
from src.retry import retry from src.retry import retry
logger = logging.getLogger(__name__)
@retry() @retry()
def send_reply(account: EmailAccount, to_addr: str, subject: str, body: str): 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") raise RuntimeError(f"账号 {account.username} 未配置 SMTP")
s = account.smtp s = account.smtp
logger.info("SMTP 连接: %s:%d (ssl=%s)", s.server, s.port, s.use_ssl)
if s.use_ssl: if s.use_ssl:
conn = smtplib.SMTP_SSL(s.server, s.port, timeout=15) conn = smtplib.SMTP_SSL(s.server, s.port, timeout=15)
else: else:
@@ -19,8 +23,10 @@ def send_reply(account: EmailAccount, to_addr: str, subject: str, body: str):
conn.starttls() conn.starttls()
conn.login(account.username, account.password) conn.login(account.username, account.password)
logger.info("SMTP 登录成功")
reply_subject = subject if subject.lower().startswith("re:") else f"Re: {subject}" 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 = MIMEMultipart("alternative")
msg["From"] = account.username 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.sendmail(account.username, [to_addr], msg.as_string())
conn.quit() conn.quit()
logger.info("SMTP 发送完成")

View File

@@ -210,6 +210,8 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict):
action = parts[0] action = parts[0]
ctx = _email_contexts.get(msg_id) 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: if action == CALLBACK_VIEW_ORIG and ctx:
can_reply = ctx.get("can_reply", True) 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", "text": text, "parse_mode": "MarkdownV2",
"reply_markup": _orig_keyboard(can_reply), "reply_markup": _orig_keyboard(can_reply),
}) })
logger.info(" 切换为原文视图")
elif action == CALLBACK_VIEW_SUMM and ctx: elif action == CALLBACK_VIEW_SUMM and ctx:
can_reply = ctx.get("can_reply", True) 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", "text": ctx["summary_text"], "parse_mode": "MarkdownV2",
"reply_markup": _summary_keyboard(can_reply), "reply_markup": _summary_keyboard(can_reply),
}) })
logger.info(" 切换回摘要视图")
elif action == CALLBACK_REPLY and ctx: elif action == CALLBACK_REPLY and ctx:
prompt_msg_id = send_text( 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, "state": "awaiting_reply", "summary_msg_id": msg_id,
"prompt_msg_id": prompt_msg_id, "prompt_msg_id": prompt_msg_id,
} }
logger.info(" 进入回复流程, prompt_msg_id=%d", prompt_msg_id)
elif action == CALLBACK_AI_REPLY and ctx: elif action == CALLBACK_AI_REPLY and ctx:
suggestions = ctx["summary_data"].get("reply_suggestions", []) suggestions = ctx["summary_data"].get("reply_suggestions", [])
if not suggestions: if not suggestions:
send_text(tg_cfg, str(chat_id), "此邮件无需回复。") send_text(tg_cfg, str(chat_id), "此邮件无需回复。")
logger.info(" AI 判定无需回复,隐藏")
return return
_conversations[chat_id] = { _conversations[chat_id] = {
@@ -250,7 +256,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict):
"ai_suggestions": suggestions, "ai_suggestions": suggestions,
"all_suggestions": list(suggestions), "all_suggestions": list(suggestions),
} }
logger.info(" 显示 AI 回复建议 (%d 条)", len(suggestions))
_show_ai_suggestions(tg_cfg, chat_id, msg_id, suggestions) _show_ai_suggestions(tg_cfg, chat_id, msg_id, suggestions)
elif action == CALLBACK_SELECT_REPLY and ctx: 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): if idx >= len(suggestions):
return return
sel = suggestions[idx] sel = suggestions[idx]
logger.info(" 选择回复 #%d: %s", idx, sel["text"][:60])
_do_send_reply(tg_cfg, cfg, chat_id, msg_id, ctx, sel["text"]) _do_send_reply(tg_cfg, cfg, chat_id, msg_id, ctx, sel["text"])
send_text(tg_cfg, str(chat_id), f"✅ 已发送: {sel['text']}") send_text(tg_cfg, str(chat_id), f"✅ 已发送: {sel['text']}")
_conversations.pop(chat_id, None) _conversations.pop(chat_id, None)
@@ -276,6 +283,7 @@ def _handle_callback(tg_cfg: TelegramConfig, cfg: Config, cb: dict):
conv = _conversations.get(chat_id) conv = _conversations.get(chat_id)
if not conv or conv.get("summary_msg_id") != msg_id: if not conv or conv.get("summary_msg_id") != msg_id:
return return
logger.info(" 换一批 (已有 %d 条历史)", len(conv.get("all_suggestions", [])))
try: try:
new_suggestions = generate_more_replies( new_suggestions = generate_more_replies(
cfg.ai, ctx["sender"], ctx["subject"], ctx["original_body"], 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: if new_suggestions:
conv["ai_suggestions"] = new_suggestions conv["ai_suggestions"] = new_suggestions
conv["all_suggestions"].extend(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) _show_ai_suggestions(tg_cfg, chat_id, msg_id, new_suggestions)
elif action == CALLBACK_HINT and ctx: 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: if conv and conv.get("summary_msg_id") == msg_id:
conv["state"] = "awaiting_ai_hint" conv["state"] = "awaiting_ai_hint"
conv["prompt_msg_id"] = prompt_msg_id conv["prompt_msg_id"] = prompt_msg_id
logger.info(" 等待用户输入 AI 提示")
elif action == CALLBACK_CANCEL: elif action == CALLBACK_CANCEL:
_conversations.pop(chat_id, None) _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", "text": ctx["summary_text"], "parse_mode": "MarkdownV2",
"reply_markup": _summary_keyboard(can_reply), "reply_markup": _summary_keyboard(can_reply),
}) })
logger.info(" 取消, 恢复摘要视图")
else: else:
delete_message(tg_cfg, str(chat_id), msg_id) delete_message(tg_cfg, str(chat_id), msg_id)
logger.info(" 取消, 删除提示消息")
def _handle_message(tg_cfg: TelegramConfig, cfg: Config, msg: dict): 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"] user_msg_id = msg["message_id"]
chat_id_str = str(chat_id) chat_id_str = str(chat_id)
prompt_msg_id = conv.get("prompt_msg_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"]) ctx = _email_contexts.get(conv["summary_msg_id"])
if not ctx: if not ctx:
_conversations.pop(chat_id, None) _conversations.pop(chat_id, None)
delete_message(tg_cfg, chat_id_str, user_msg_id) delete_message(tg_cfg, chat_id_str, user_msg_id)
if prompt_msg_id: if prompt_msg_id:
delete_message(tg_cfg, chat_id_str, prompt_msg_id) delete_message(tg_cfg, chat_id_str, prompt_msg_id)
logger.info(" 上下文已丢失,清理")
return return
delete_message(tg_cfg, chat_id_str, user_msg_id) 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) _do_send_reply(tg_cfg, cfg, chat_id, conv["summary_msg_id"], ctx, text)
send_text(tg_cfg, chat_id_str, "✅ 回复已发送!") send_text(tg_cfg, chat_id_str, "✅ 回复已发送!")
_conversations.pop(chat_id, None) _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"]) ctx = _email_contexts.get(conv["summary_msg_id"])
if not ctx: if not ctx:
_conversations.pop(chat_id, None) _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["all_suggestions"].extend(new_suggestions)
conv["state"] = "ai_reply_selection" conv["state"] = "ai_reply_selection"
conv.pop("prompt_msg_id", None) 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) _show_ai_suggestions(tg_cfg, chat_id, conv["summary_msg_id"], new_suggestions)