101 lines
4.0 KiB
Python
101 lines
4.0 KiB
Python
"""
|
||
fork 安全：文件日志流在子进程重开（reentrant call 修复）测试
|
||
|
||
背景：gateway 的日志是"队列 handler + 监听线程"结构，文件 handler 的流在父进程
|
||
打开。granian/gunicorn 的 worker 由 master **fork** 而来（实测 worker 与 master 的
|
||
fd 表完全一致）——子进程会继承父进程的 BufferedWriter，其内部锁/owner 状态在
|
||
fork 瞬间可能正被父进程监听线程占用（跨 fork 复制不可靠）。症状：冻结版（Nuitka）
|
||
里每个 worker 的**每条文件日志**都报
|
||
RuntimeError: reentrant call inside <_io.BufferedWriter ...>
|
||
（控制台 handler 正常，文件日志整体失效）。
|
||
|
||
修复：_after_fork_child 里把文件 handler 的流在子进程重开（新文件描述符）。
|
||
本测试验证：
|
||
1. fork 后子进程的 handler.stream 不再是继承的那个对象（结构保证）
|
||
2. 子进程能真正把记录写进日志文件（行为保证——旧实现下这里写不进去）
|
||
3. 控制台等非文件 handler 不被动（无 _open，跳过）
|
||
|
||
运行: uv run python test_logging_fork.py
|
||
"""
|
||
import importlib.util
|
||
import logging
|
||
import os
|
||
import sys
|
||
import tempfile
|
||
from pathlib import Path
|
||
|
||
tmp = tempfile.TemporaryDirectory()
|
||
log_dir = Path(tmp.name)
|
||
|
||
# 与 test_logging_async.py 相同的加载方式：独立加载 logger 模块并把日志目录重定向
|
||
_logger_path = (
|
||
Path(__file__).resolve().parent.parent / "gateway" / "src" / "chongming" / "app" / "core" / "logger.py"
|
||
)
|
||
_spec = importlib.util.spec_from_file_location("chongming.app.core.logger", _logger_path)
|
||
logger_mod = importlib.util.module_from_spec(_spec)
|
||
sys.modules["chongming.app.core.logger"] = logger_mod
|
||
_spec.loader.exec_module(logger_mod) # type: ignore[union-attr]
|
||
logger_mod.log_config["file"] = str(log_dir)
|
||
|
||
failures = []
|
||
|
||
|
||
def check(name, cond, detail=""):
|
||
status = "PASS" if cond else "FAIL"
|
||
print(f"[{status}] {name}" + (f" — {detail}" if detail else ""))
|
||
if not cond:
|
||
failures.append(name)
|
||
|
||
|
||
check("os.register_at_fork 已注册 after_in_child", hasattr(os, "register_at_fork"))
|
||
|
||
logger = logging.getLogger("forktest")
|
||
logger_mod.setup_logging(logger, "forktest")
|
||
|
||
file_handler = next(
|
||
h for h in logger_mod._listener_handlers if isinstance(h, logger_mod.DailyRotatingFileHandler)
|
||
)
|
||
# 同步直写一条（不经队列），保持监听线程与流都活着，便于接下来 fork
|
||
parent_record = logging.LogRecord("forktest", logging.INFO, __file__, 0, "parent-line", (), None)
|
||
file_handler.handle(parent_record)
|
||
file_handler.flush()
|
||
|
||
check("父进程日志已落盘", "parent-line" in next(iter(log_dir.glob("forktest-*.log"))).read_text(encoding="utf-8"))
|
||
|
||
inherited_stream = file_handler.stream
|
||
check("父进程流已打开", inherited_stream is not None)
|
||
|
||
# ---- fork：子进程应换掉继承的流，并能独立写日志 ----
|
||
pid = os.fork()
|
||
if pid == 0: # 子进程
|
||
try:
|
||
reopened = file_handler.stream is not inherited_stream
|
||
record = logging.LogRecord(
|
||
"forktest", logging.INFO, __file__, 0, "child-line", (), None
|
||
)
|
||
# 直接同步走 handler（不经队列），写入结果立即可断言
|
||
file_handler.handle(record)
|
||
os._exit(0 if reopened else 3)
|
||
except BaseException: # noqa: BLE001 - 子进程异常用退出码传出
|
||
os._exit(4)
|
||
|
||
_, status = os.waitpid(pid, 0)
|
||
exit_code = os.waitstatus_to_exitcode(status)
|
||
check("fork 后子进程的流已换新（不再是继承对象）", exit_code == 0, f"exit={exit_code}")
|
||
check(
|
||
"子进程可直接写入日志文件（旧实现下 reentrant 失败）",
|
||
"child-line" in next(iter(log_dir.glob("forktest-*.log"))).read_text(encoding="utf-8"),
|
||
)
|
||
check(
|
||
"控制台 handler 不受影响（仍指向 stderr）",
|
||
any(isinstance(h, logging.StreamHandler) and not isinstance(h, logger_mod.DailyRotatingFileHandler) for h in logger_mod._listener_handlers),
|
||
)
|
||
|
||
tmp.cleanup()
|
||
|
||
print("\n" + ("=" * 40))
|
||
if failures:
|
||
print(f"❌ {len(failures)} 项未通过: {failures}")
|
||
sys.exit(1)
|
||
print("✅ 全部通过")
|