diff --git a/dev.sh b/dev.sh index 73edaf9..aa7465c 100755 --- a/dev.sh +++ b/dev.sh @@ -18,7 +18,7 @@ BACKEND_HOST="${BACKEND_HOST:-0.0.0.0}" BACKEND_PORT="${BACKEND_PORT:-8800}" FRONTEND_HOST="${FRONTEND_HOST:-0.0.0.0}" FRONTEND_PORT="${FRONTEND_PORT:-5174}" -LOG_LEVEL="${LOG_LEVEL:-DEBUG}" +LOG_LEVEL="${LOG_LEVEL:-INFO}" MYSQL_IMAGE="${MYSQL_IMAGE:-mysql:8.4}" MYSQL_BIND_HOST="${MYSQL_BIND_HOST:-127.0.0.1}" MYSQL_HOST_PORT="${MYSQL_HOST_PORT:-3307}" @@ -40,10 +40,7 @@ DEV_YYB_WORKER_URL="${DEV_YYB_WORKER_URL:-http://127.0.0.1:${YYB_WORKER_PORT}}" YYB_WORKER_DATA_DIR="${YYB_WORKER_DATA_DIR:-$ROOT_DIR/data/yyb-worker-dev}" YYB_WORKER_NODE_MODULES="$ROOT_DIR/services/yyb-worker/node_modules" LOG_DIR="$ROOT_DIR/logs" -LOG_DATE="$(date +%Y-%m-%d)" -BACKEND_LOG="$LOG_DIR/backend-$LOG_DATE.log" -FRONTEND_LOG="$LOG_DIR/frontend-$LOG_DATE.log" -WORKER_LOG="$LOG_DIR/yyb-worker-$LOG_DATE.log" +APP_LOG="$LOG_DIR/app.log" BACKEND_PID="" FRONTEND_PID="" @@ -161,7 +158,7 @@ start_yyb_worker() { uv run --project "$ROOT_DIR" python scripts/yyb-worker.py \ --host 127.0.0.1 \ --port "$YYB_WORKER_PORT" \ - --data-dir "$YYB_WORKER_DATA_DIR" 2>&1 | tee -a "$WORKER_LOG" + --data-dir "$YYB_WORKER_DATA_DIR" ) & WORKER_PID=$! @@ -173,7 +170,7 @@ start_yyb_worker() { fi if [ "$i" = "15" ]; then echo "YYB Worker 启动超时，查看日志：" - tail -n 100 "$WORKER_LOG" 2>/dev/null || true + echo "请查看当前终端中的 Worker 输出。" exit 1 fi sleep 1 @@ -211,9 +208,8 @@ echo " 前端: http://localhost:${FRONTEND_PORT}" echo " API 代理: ${BACKEND_PROXY_TARGET}" echo " MySQL: ${DB_HOST}:${DB_PORT}/${DB_NAME}" echo " YYB Worker: ${DEV_YYB_WORKER_URL}" -echo " 后端日志: ${BACKEND_LOG}" -echo " 前端日志: ${FRONTEND_LOG}" -echo " Worker 日志: ${WORKER_LOG}" +echo " 应用日志: ${APP_LOG}" +echo " 前端与 Worker 输出: 当前终端" echo " 退出: Ctrl+C" echo "==============================" echo "" @@ -229,14 +225,14 @@ echo "" --reload \ --reload-dir core \ --reload-dir utils \ - --reload-dir web/backend 2>&1 | tee -a "$BACKEND_LOG" + --reload-dir web/backend ) & BACKEND_PID=$! ( cd web/frontend VITE_BACKEND_TARGET="$BACKEND_PROXY_TARGET" \ - npm run dev -- --host "$FRONTEND_HOST" --port "$FRONTEND_PORT" 2>&1 | tee -a "$FRONTEND_LOG" + npm run dev -- --host "$FRONTEND_HOST" --port "$FRONTEND_PORT" ) & FRONTEND_PID=$! diff --git a/services/yyb-worker/runtime/scripts/generate-devicefp-jsdom.mjs b/services/yyb-worker/runtime/scripts/generate-devicefp-jsdom.mjs index 6600b7a..4c5fd4a 100644 --- a/services/yyb-worker/runtime/scripts/generate-devicefp-jsdom.mjs +++ b/services/yyb-worker/runtime/scripts/generate-devicefp-jsdom.mjs @@ -23,7 +23,7 @@ const htmlPath = getArg('--html'); const goodsUrl = getArg('--goods-url'); const cookiePath = getArg('--cookies'); const outputPath = getArg('--output'); -const waitMs = Number.parseInt(getArg('--wait', '12000'), 10); +const waitMs = Number.parseInt(getArg('--wait', '5000'), 10); const useArchivedAssets = argv.includes('--archived-assets'); function fail(message) { @@ -61,8 +61,18 @@ class GoodsLoader extends ResourceLoader { const session = cookiePath ? JSON.parse(fs.readFileSync(cookiePath, 'utf8')) : {}; const cookies = session.cookies || {}; -const captured = []; const resourceErrors = []; +let capturedFp = null; +let resolveFpCapture = null; +const startedAt = Date.now(); + +function captureFp(url, body) { + const values = Object.fromEntries(new URLSearchParams(body)); + if (!values.SessionID || !values.DeviceFP) return; + capturedFp = { url, body }; + if (resolveFpCapture) resolveFpCapture(); +} + const dom = new JSDOM(fs.readFileSync(htmlPath, 'utf8'), { url: goodsUrl, referrer: 'https://z.iwan.yyb.qq.com/', @@ -88,7 +98,7 @@ const dom = new JSDOM(fs.readFileSync(htmlPath, 'utf8'), { send(body) { const requestBody = String(body || ''); if (this.__yybUrl.includes('fp-behv.fcg')) { - captured.push({ url: this.__yybUrl, body: requestBody }); + captureFp(this.__yybUrl, requestBody); } this.readyState = 4; this.status = 200; @@ -103,18 +113,23 @@ const dom = new JSDOM(fs.readFileSync(htmlPath, 'utf8'), { }, }); -await new Promise(resolve => setTimeout(resolve, Number.isFinite(waitMs) ? waitMs : 12000)); -const fp = captured.at(-1); -if (!fp) { +const timeoutMs = Number.isFinite(waitMs) && waitMs > 0 ? waitMs : 5000; +let timeoutId; +await Promise.race([ + new Promise(resolve => { + resolveFpCapture = resolve; + if (capturedFp) resolve(); + }), + new Promise(resolve => { timeoutId = setTimeout(resolve, timeoutMs); }), +]); +clearTimeout(timeoutId); +if (!capturedFp) { dom.window.close(); fail(`未生成 fp-behv；加载错误: ${resourceErrors.slice(0, 3).join(' | ') || '无'}`); } +const fp = capturedFp; const values = Object.fromEntries(new URLSearchParams(fp.body)); -if (!values.SessionID || !values.DeviceFP) { - dom.window.close(); - fail('fp-behv 缺少 SessionID 或 DeviceFP'); -} const result = { generated_at: new Date().toISOString(), goods_url: goodsUrl, @@ -130,3 +145,4 @@ dom.window.close(); console.log(`DeviceFP 已保存: ${outputPath}`); console.log(`SessionID: ${result.session_id}`); console.log(`DeviceFP 长度: ${result.device_fp_length}`); +console.log(`DeviceFP 捕获耗时: ${Date.now() - startedAt}ms`); diff --git a/services/yyb-worker/runtime/scripts/jsdom-pay.py b/services/yyb-worker/runtime/scripts/jsdom-pay.py index 1ec78b4..58f9301 100644 --- a/services/yyb-worker/runtime/scripts/jsdom-pay.py +++ b/services/yyb-worker/runtime/scripts/jsdom-pay.py @@ -375,7 +375,7 @@ def main() -> int: parser.add_argument("--mall-response", default=str(ROOT / "config/mall-order-response.json")) parser.add_argument("--out-dir", default=None, help="运行证据目录；默认 config/jsdom-order-") parser.add_argument("--qr", default=None, help="付款二维码 PNG 路径") - parser.add_argument("--wait", type=int, default=12, help="jsdom 等待 DeviceFP 的秒数") + parser.add_argument("--wait", type=int, default=5, help="jsdom 等待 DeviceFP 的秒数") parser.add_argument("--zone-id", default="1", help="所选游戏区服 ID") parser.add_argument("--pf", default="", help="所选 Android/iOS 支付平台标识") parser.add_argument("--amount-fen", type=int, default=0, help="所选点券的价格，单位分（check-only 模式不需要）") diff --git a/services/yyb-worker/runtime/scripts/yyb-worker.py b/services/yyb-worker/runtime/scripts/yyb-worker.py index bd2780e..2843ee6 100644 --- a/services/yyb-worker/runtime/scripts/yyb-worker.py +++ b/services/yyb-worker/runtime/scripts/yyb-worker.py @@ -61,8 +61,9 @@ def _safe_log(job: dict, line: str) -> None: clean = re.sub(r"(?:token|openid|openkey|cookie)=\S+", "[敏感字段已隐藏]", clean, flags=re.I) clean = re.sub(r"(?:pay_token|web_token|anti_token|session_id|sessionid)\s*[:= ]\s*\S+", "[敏感字段已隐藏]", clean, flags=re.I) + timestamp = time.strftime("%H:%M:%S") with _lock: - job["logs"] = (job.get("logs", []) + [clean.strip()])[-100:] + job["logs"] = (job.get("logs", []) + [f"[{timestamp}] {clean.strip()}"])[-100:] def _run_process(job_id: str, command: list[str], phase: str, mark_success: bool = True) -> int: @@ -79,6 +80,8 @@ def _run_process(job_id: str, command: list[str], phase: str, mark_success: bool with _lock: job["phase"] = phase job["status"] = "running" + stage_started = time.monotonic() + _safe_log(job, f"[{phase}] 开始执行") try: process = subprocess.Popen(command, cwd=ROOT, stdout=subprocess.PIPE, stderr=subprocess.STDOUT, text=True, @@ -89,6 +92,7 @@ def _run_process(job_id: str, command: list[str], phase: str, mark_success: bool for line in process.stdout: _safe_log(job, line) code = process.wait() + _safe_log(job, f"[{phase}] 执行结束，耗时 {time.monotonic() - stage_started:.1f} 秒") with _lock: job["process_pid"] = None if code != 0: @@ -109,6 +113,7 @@ def _run_process(job_id: str, command: list[str], phase: str, mark_success: bool job["message"] = "付款流程已完成" return code except Exception as exc: # noqa: BLE001 + _safe_log(job, f"[{phase}] 执行异常，耗时 {time.monotonic() - stage_started:.1f} 秒") with _lock: job["status"] = "failed" job["message"] = str(exc) @@ -189,10 +194,13 @@ def _check_payment_once(job_id: str) -> int: "--out-dir", str(directory / "jsdom-order")] environment = os.environ.copy() environment.pop("NODE_OPTIONS", None) + check_started = time.monotonic() + _safe_log(job, "[到账检测] 开始执行") try: result = subprocess.run(command, cwd=ROOT, capture_output=True, text=True, env=environment, timeout=90) except subprocess.TimeoutExpired: + _safe_log(job, f"[到账检测] 执行超时，耗时 {time.monotonic() - check_started:.1f} 秒") with _lock: job["payment_last_checked_at"] = int(time.time()) return 2 @@ -200,6 +208,7 @@ def _check_payment_once(job_id: str) -> int: _safe_log(job, line) for line in (result.stderr or "").splitlines(): _safe_log(job, line) + _safe_log(job, f"[到账检测] 执行结束，耗时 {time.monotonic() - check_started:.1f} 秒") with _lock: job["payment_last_checked_at"] = int(time.time()) return result.returncode diff --git a/utils/logger.py b/utils/logger.py index dff8f86..6eeb654 100644 --- a/utils/logger.py +++ b/utils/logger.py @@ -1,33 +1,28 @@ """日志配置模块""" -import os import sys import logging -from datetime import date +import re from logging.handlers import TimedRotatingFileHandler from pathlib import Path from loguru import logger -def _should_rotate(message, file): - """自定义轮转条件：每天0点轮转，或单文件超过10M。""" - if not file: - return False - try: - # 单文件超过 10M 则轮转 - if os.path.getsize(file.name) > 10 * 1024 * 1024: +class _RelevantAccessFilter(logging.Filter): + """仅保留异常 HTTP 请求，避免前端轮询淹没业务日志。""" + + _STATUS_RE = re.compile(r'"\s+(\d{3})\b') + + def filter(self, record: logging.LogRecord) -> bool: + if record.levelno >= logging.WARNING: return True - # 跨天则轮转：日志日期 ≠ 文件最后修改日期 - file_date = date.fromtimestamp(os.path.getmtime(file.name)) - log_date = message.record["time"].date() - return file_date != log_date - except OSError: - return False + matched = self._STATUS_RE.search(record.getMessage()) + return bool(matched and int(matched.group(1)) >= 400) -def _configure_standard_logging(level: str, log_dir: Path) -> None: - """将 Uvicorn/FastAPI 的标准日志同步到控制台和文件。""" +def _configure_standard_logging(level: str, log_dir: Path) -> logging.Logger: + """将业务日志和关键框架日志收敛到单一轮转文件。""" log_level = getattr(logging, level.upper(), logging.INFO) formatter = logging.Formatter( "%(asctime)s | %(levelname)-8s | %(name)s | %(message)s" @@ -38,17 +33,30 @@ def _configure_standard_logging(level: str, log_dir: Path) -> None: console_handler.setFormatter(formatter) file_handler = TimedRotatingFileHandler( - log_dir / "server.log", when="midnight", backupCount=7, encoding="utf-8" + log_dir / "app.log", when="midnight", backupCount=7, encoding="utf-8" ) file_handler.setLevel(log_level) file_handler.setFormatter(formatter) - for name in ("uvicorn", "uvicorn.error", "uvicorn.access", "fastapi", "starlette"): + app_logger = logging.getLogger("app") + app_logger.handlers.clear() + app_logger.handlers = [console_handler, file_handler] + app_logger.setLevel(log_level) + app_logger.propagate = False + + for name in ("uvicorn", "uvicorn.error", "fastapi", "starlette"): standard_logger = logging.getLogger(name) standard_logger.handlers = [console_handler, file_handler] standard_logger.setLevel(log_level) standard_logger.propagate = False + access_logger = logging.getLogger("uvicorn.access") + access_logger.handlers = [console_handler, file_handler] + access_logger.filters = [_RelevantAccessFilter()] + access_logger.setLevel(logging.INFO) + access_logger.propagate = False + return app_logger + def setup_logger(level: str = "INFO", log_dir: str = None, log_file: str = None) -> None: """ @@ -56,45 +64,26 @@ def setup_logger(level: str = "INFO", log_dir: str = None, log_file: str = None) Args: level: 日志级别 - log_dir: 日志目录路径（文件名按日期自动生成，如 app-2026-06-24.log） + log_dir: 日志目录路径（写入 app.log，按日轮转） log_file: 日志文件路径（兼容旧接口，优先级低于 log_dir） """ - # 移除默认handler + # 移除默认 handler，由标准 logging 统一处理控制台和文件输出。 logger.remove() - # 控制台输出 - logger.add( - sys.stdout, - level=level, - format="{time:YYYY-MM-DD HH:mm:ss} | " - "{level: <8} | " - "{name}:{function}:{line} | " - "{message}", - colorize=True, - ) - # 确定日志文件路径 if log_dir: - # 新接口：按目录 + 日期命名 dir_path = Path(log_dir) dir_path.mkdir(parents=True, exist_ok=True) - _configure_standard_logging(level, dir_path) - file_path = str(dir_path / "app-{time:YYYY-MM-DD}.log") + app_logger = _configure_standard_logging(level, dir_path) elif log_file: - # 兼容旧接口 file_path = Path(log_file) file_path.parent.mkdir(parents=True, exist_ok=True) - file_path = str(file_path) + app_logger = _configure_standard_logging(level, file_path.parent) else: return - # 文件输出：按天命名 + 单文件最大10M轮转 + 保留7天 - logger.add( - file_path, - level=level, - format="{time:YYYY-MM-DD HH:mm:ss} | {level: <8} | {name}:{function}:{line} | {message}", - rotation=_should_rotate, # 超过10M轮转 - retention="7 days", # 保留7天 - compression="zip", # 旧日志自动压缩节省空间 - encoding="utf-8", - ) + def forward_to_standard(message) -> None: + record = message.record + app_logger.log(record["level"].no, f"{record['name']} | {record['message']}") + + logger.add(forward_to_standard, level=level, format="{message}")