Skip to content

Commit 2f83121

Browse files
committed
feat(logging): comprehensive logging overhaul
1 parent dd0cf34 commit 2f83121

23 files changed

Lines changed: 1325 additions & 228 deletions

.env.example

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -91,6 +91,17 @@ DEBUG_LOGS_ENABLED=false
9191
# 启用极详细的追踪日志 (会产生大量日志)
9292
TRACE_LOGS_ENABLED=false
9393

94+
# JSON 结构化日志 (Structured JSON Logging)
95+
# 设置为 true 以输出 JSON 格式日志,适用于 ELK/Datadog 等日志聚合工具。
96+
# Default: false
97+
JSON_LOGS=false
98+
99+
# 日志文件轮换配置 (Log Rotation Configuration)
100+
# 单个日志文件最大字节数 (默认 10MB)
101+
LOG_FILE_MAX_BYTES=10485760
102+
# 保留的日志备份文件数量 (默认 5 个)
103+
LOG_FILE_BACKUP_COUNT=5
104+
94105
# =============================================================================
95106
# 6. API 默认参数 (API Defaults)
96107
# =============================================================================

api_utils/queue_worker.py

Lines changed: 1 addition & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -13,11 +13,10 @@
1313
from fastapi.responses import JSONResponse, StreamingResponse
1414
from playwright.async_api import Locator
1515

16+
from api_utils.context_types import QueueItem
1617
from logging_utils import set_request_id, set_source
1718
from models import ChatCompletionRequest
1819

19-
from api_utils.context_types import QueueItem
20-
2120
from .error_utils import (
2221
client_cancelled,
2322
client_disconnected,

browser_utils/operations_modules/interactions.py

Lines changed: 7 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -116,7 +116,9 @@ async def get_response_via_edit_button(
116116
except asyncio.CancelledError:
117117
raise
118118
except Exception as edit_btn_err:
119-
logger.error(f" - 'Edit' 按钮不可见或点击失败: {edit_btn_err}")
119+
logger.error(
120+
f" - 'Edit' 按钮不可见或点击失败: {edit_btn_err}", exc_info=True
121+
)
120122
await save_error_snapshot(f"edit_response_edit_button_failed_{req_id}")
121123
return None
122124

@@ -193,7 +195,9 @@ async def get_response_via_edit_button(
193195
except asyncio.CancelledError:
194196
raise
195197
except Exception as textarea_err:
196-
logger.error(f" - 定位或处理文本区域时失败: {textarea_err}")
198+
logger.error(
199+
f" - 定位或处理文本区域时失败: {textarea_err}", exc_info=True
200+
)
197201
textarea_failed = True
198202
response_content = None
199203
check_client_disconnected("编辑响应 - 获取文本区域错误后: ")
@@ -323,7 +327,7 @@ async def get_response_via_copy_button(
323327
f" - 读取剪贴板失败: 可能是权限问题。错误: {clipboard_err}"
324328
)
325329
else:
326-
logger.error(f" - 读取剪贴板失败: {clipboard_err}")
330+
logger.error(f" - 读取剪贴板失败: {clipboard_err}", exc_info=True)
327331
await save_error_snapshot(f"copy_response_clipboard_read_failed_{req_id}")
328332
return None
329333

browser_utils/operations_modules/parsers.py

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -71,7 +71,7 @@ def _parse_userscript_models(script_content: str):
7171
return models
7272

7373
except Exception as e:
74-
logger.error(f"解析油猴脚本模型列表失败: {e}")
74+
logger.error(f"解析油猴脚本模型列表失败: {e}", exc_info=True)
7575
return []
7676

7777

browser_utils/script_manager.py

Lines changed: 4 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -35,7 +35,7 @@ def load_script(self, script_name: str) -> Optional[str]:
3535
logger.info(f"成功加载脚本: {script_name}")
3636
return script_content
3737
except Exception as e:
38-
logger.error(f"加载脚本失败 {script_name}: {e}")
38+
logger.error(f"加载脚本失败 {script_name}: {e}", exc_info=True)
3939
return None
4040

4141
def load_model_config(self, config_path: str) -> Optional[List[Dict[str, Any]]]:
@@ -52,7 +52,7 @@ def load_model_config(self, config_path: str) -> Optional[List[Dict[str, Any]]]:
5252
logger.info(f"成功加载模型配置: {len(models)} 个模型")
5353
return models
5454
except Exception as e:
55-
logger.error(f"加载模型配置失败 {config_path}: {e}")
55+
logger.error(f"加载模型配置失败 {config_path}: {e}", exc_info=True)
5656
return None
5757

5858
def generate_dynamic_script(
@@ -125,7 +125,7 @@ def generate_dynamic_script(
125125
return new_script
126126

127127
except Exception as e:
128-
logger.error(f"生成动态脚本失败: {e}")
128+
logger.error(f"生成动态脚本失败: {e}", exc_info=True)
129129
return base_script
130130

131131
async def inject_script_to_page(
@@ -144,7 +144,7 @@ async def inject_script_to_page(
144144
except asyncio.CancelledError:
145145
raise
146146
except Exception as e:
147-
logger.error(f"注入脚本到页面失败 {script_name}: {e}")
147+
logger.error(f"注入脚本到页面失败 {script_name}: {e}", exc_info=True)
148148
return False
149149

150150
def _clean_userscript_headers(self, script_content: str) -> str:

config/settings.py

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,17 @@
2121
"1",
2222
"yes",
2323
)
24+
JSON_LOGS_ENABLED = os.environ.get("JSON_LOGS", "false").lower() in (
25+
"true",
26+
"1",
27+
"yes",
28+
)
29+
30+
# --- Log Rotation Configuration ---
31+
LOG_FILE_MAX_BYTES = int(
32+
os.environ.get("LOG_FILE_MAX_BYTES", str(10 * 1024 * 1024))
33+
) # 10MB default
34+
LOG_FILE_BACKUP_COUNT = int(os.environ.get("LOG_FILE_BACKUP_COUNT", "5"))
2435

2536
# --- 认证相关配置 ---
2637
AUTO_SAVE_AUTH = os.environ.get("AUTO_SAVE_AUTH", "").lower() in ("1", "true", "yes")

launcher/checks.py

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -65,7 +65,9 @@ def check_dependencies(
6565
if server_app_check:
6666
logger.info(" 成功从 'server.py' 导入 'app' 对象。")
6767
except ImportError as e_import_server:
68-
logger.error(f" 无法从 'server.py' 导入 'app' 对象: {e_import_server}")
68+
logger.error(
69+
f" 无法从 'server.py' 导入 'app' 对象: {e_import_server}", exc_info=True
70+
)
6971
logger.error(" 请确保 'server.py' 文件存在且没有导入错误。")
7072
dependencies_ok = False
7173

launcher/logging_setup.py

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -40,8 +40,8 @@ def setup_launcher_logging(log_level: int = logging.INFO) -> None:
4040

4141
file_handler = logging.handlers.RotatingFileHandler(
4242
LAUNCHER_LOG_FILE_PATH,
43-
maxBytes=2 * 1024 * 1024,
44-
backupCount=3,
43+
maxBytes=10 * 1024 * 1024, # 10MB
44+
backupCount=5,
4545
encoding="utf-8",
4646
mode="w",
4747
)

logging_utils/__init__.py

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,10 @@
11
# 日志设置功能
22
# Grid logging system v2.0
3+
from .core.error_handler import (
4+
install_asyncio_handler_on_loop,
5+
log_error,
6+
setup_global_exception_handlers,
7+
)
38
from .grid_logger import (
49
# Source mapping
510
SOURCE_MAP,
@@ -10,6 +15,8 @@
1015
Colors,
1116
Columns,
1217
GridFormatter,
18+
# JSON formatter for structured logging
19+
JSONFormatter,
1320
PlainGridFormatter,
1421
ProgressLine,
1522
SemanticHighlighter,
@@ -70,4 +77,10 @@
7077
"format_object",
7178
"log_object",
7279
"flush_burst_buffer",
80+
# JSON formatter
81+
"JSONFormatter",
82+
# Error handling utilities
83+
"log_error",
84+
"setup_global_exception_handlers",
85+
"install_asyncio_handler_on_loop",
7386
]
Lines changed: 218 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,218 @@
1+
# -*- coding: utf-8 -*-
2+
"""
3+
Centralized Error Handling Utilities
4+
=====================================
5+
Provides consistent error logging, global exception handlers, and
6+
optional error snapshot integration for robust debugging.
7+
"""
8+
9+
import asyncio
10+
import logging
11+
import threading
12+
from typing import Optional
13+
14+
from .context import request_id_var, source_var
15+
16+
17+
def log_error(
18+
logger: logging.Logger,
19+
message: str,
20+
exception: Optional[BaseException] = None,
21+
*,
22+
save_snapshot: bool = False,
23+
req_id: str = "",
24+
exc_info: bool = True,
25+
) -> None:
26+
"""
27+
Centralized error logging with automatic stack trace capture.
28+
29+
This function ensures consistent error logging across the codebase:
30+
- Always includes exc_info for full stack traces
31+
- Optionally saves error snapshots for debugging
32+
- Integrates with request context for tracing
33+
34+
Args:
35+
logger: Logger instance to use
36+
message: Error message to log
37+
exception: Optional exception object (used for snapshot)
38+
save_snapshot: Whether to save an error snapshot (screenshot, DOM, etc.)
39+
req_id: Optional request ID override (uses context var if empty)
40+
exc_info: Whether to include exception info (default True)
41+
42+
Usage:
43+
try:
44+
risky_operation()
45+
except Exception as e:
46+
log_error(logger, f"Operation failed: {e}", e, save_snapshot=True)
47+
"""
48+
# Get request ID from context if not provided
49+
if not req_id:
50+
try:
51+
req_id = request_id_var.get()
52+
except LookupError:
53+
req_id = "unknown"
54+
55+
# Log with exc_info for full stack trace
56+
logger.error(message, exc_info=exc_info)
57+
58+
# Save error snapshot if requested
59+
if save_snapshot:
60+
try:
61+
# Lazy import to avoid circular dependencies
62+
from browser_utils.debug_utils import save_error_snapshot_enhanced
63+
64+
# Generate error name from message (first 30 chars, sanitized)
65+
error_name = (
66+
message[:30].replace(" ", "_").replace(":", "").replace("/", "_")
67+
)
68+
# This is async, but we're in sync context - schedule it
69+
try:
70+
loop = asyncio.get_running_loop()
71+
loop.create_task(
72+
save_error_snapshot_enhanced(
73+
error_name=error_name,
74+
error_exception=exception
75+
if isinstance(exception, Exception)
76+
else None,
77+
error_stage="log_error",
78+
)
79+
)
80+
except RuntimeError:
81+
# No running event loop - can't save async snapshot
82+
logger.debug("Cannot save error snapshot: no running event loop")
83+
except ImportError:
84+
# debug_utils not available (e.g., in tests or standalone mode)
85+
pass
86+
except Exception as snapshot_err:
87+
# Don't let snapshot failures break the main error handling
88+
logger.debug(f"Failed to save error snapshot: {snapshot_err}")
89+
90+
91+
def _asyncio_exception_handler(loop: asyncio.AbstractEventLoop, context: dict) -> None:
92+
"""
93+
Global asyncio exception handler for uncaught exceptions in tasks.
94+
95+
This catches exceptions that would otherwise be silently ignored when:
96+
- A Task raises an exception but is never awaited
97+
- A callback raises an exception
98+
99+
Args:
100+
loop: The event loop that caught the exception
101+
context: Exception context dict with 'message', 'exception', etc.
102+
"""
103+
logger = logging.getLogger("AIStudioProxyServer")
104+
105+
# Extract exception info
106+
exception = context.get("exception")
107+
message = context.get("message", "Unhandled exception in asyncio task")
108+
109+
# Get additional context
110+
task = context.get("task")
111+
future = context.get("future")
112+
113+
# Build detailed error message
114+
error_parts = [f"[ASYNCIO EXCEPTION] {message}"]
115+
116+
if task is not None:
117+
error_parts.append(
118+
f"Task: {task.get_name() if hasattr(task, 'get_name') else repr(task)}"
119+
)
120+
121+
if future is not None and future is not task:
122+
error_parts.append(f"Future: {repr(future)}")
123+
124+
# Get source from context if available
125+
try:
126+
source = source_var.get()
127+
error_parts.append(f"Source: {source}")
128+
except LookupError:
129+
pass
130+
131+
try:
132+
req_id = request_id_var.get()
133+
if req_id.strip():
134+
error_parts.append(f"Request ID: {req_id}")
135+
except LookupError:
136+
pass
137+
138+
full_message = " | ".join(error_parts)
139+
140+
if exception is not None:
141+
# Log with full traceback
142+
logger.error(
143+
full_message, exc_info=(type(exception), exception, exception.__traceback__)
144+
)
145+
else:
146+
logger.error(full_message)
147+
148+
149+
def _threading_exception_handler(args: threading.ExceptHookArgs) -> None:
150+
"""
151+
Global threading exception handler for uncaught exceptions in threads.
152+
153+
Args:
154+
args: ExceptHookArgs containing exc_type, exc_value, exc_traceback, thread
155+
"""
156+
logger = logging.getLogger("AIStudioProxyServer")
157+
158+
thread_name = args.thread.name if args.thread else "unknown"
159+
160+
error_message = f"[THREAD EXCEPTION] Uncaught exception in thread '{thread_name}'"
161+
162+
if args.exc_value is not None:
163+
logger.error(
164+
error_message,
165+
exc_info=(args.exc_type, args.exc_value, args.exc_traceback),
166+
)
167+
else:
168+
logger.error(error_message)
169+
170+
171+
def setup_global_exception_handlers(
172+
*, install_asyncio: bool = True, install_threading: bool = True
173+
) -> None:
174+
"""
175+
Install global exception handlers for asyncio and threading.
176+
177+
This ensures that uncaught exceptions in background tasks and threads
178+
are properly logged instead of being silently ignored.
179+
180+
Should be called once during application startup.
181+
182+
Args:
183+
install_asyncio: Install asyncio exception handler
184+
install_threading: Install threading exception handler
185+
186+
Usage:
187+
# In application startup
188+
setup_global_exception_handlers()
189+
"""
190+
logger = logging.getLogger("AIStudioProxyServer")
191+
192+
if install_asyncio:
193+
try:
194+
loop = asyncio.get_running_loop()
195+
loop.set_exception_handler(_asyncio_exception_handler)
196+
logger.debug("Installed asyncio global exception handler")
197+
except RuntimeError:
198+
# No running event loop yet - will be installed when loop starts
199+
# This is common during module import
200+
pass
201+
202+
if install_threading:
203+
# Python 3.8+
204+
if hasattr(threading, "excepthook"):
205+
threading.excepthook = _threading_exception_handler
206+
logger.debug("Installed threading global exception handler")
207+
208+
209+
def install_asyncio_handler_on_loop(loop: asyncio.AbstractEventLoop) -> None:
210+
"""
211+
Install the asyncio exception handler on a specific event loop.
212+
213+
Use this when you need to install the handler after the loop is created.
214+
215+
Args:
216+
loop: The event loop to install the handler on
217+
"""
218+
loop.set_exception_handler(_asyncio_exception_handler)

0 commit comments

Comments
 (0)