426 lines
16 KiB
Python
426 lines
16 KiB
Python
from __future__ import annotations
|
||
|
||
from datetime import datetime
|
||
from uuid import uuid4
|
||
|
||
from app.core.files import load_detect_records, save_detect_records, tail_lines
|
||
|
||
|
||
_MAX_LOG_LINES = 240
|
||
_LOG_TAIL_LINES = 1200
|
||
_ACTIVE_STATUSES = {"starting", "running", "stopping"}
|
||
_TIMESTAMP_FORMATS = ("%Y-%m-%d %H:%M:%S.%f", "%Y-%m-%d %H:%M:%S")
|
||
|
||
|
||
def _now() -> str:
|
||
return datetime.now().isoformat(sep=" ", timespec="seconds")
|
||
|
||
|
||
def _save(records: list[dict]) -> None:
|
||
save_detect_records(records)
|
||
|
||
|
||
def _load() -> list[dict]:
|
||
return load_detect_records()
|
||
|
||
|
||
def _capture_worker_logs(max_lines: int = _LOG_TAIL_LINES) -> list[str]:
|
||
lines = tail_lines("detect_worker.log", max_lines=max_lines)
|
||
return lines[-max_lines:]
|
||
|
||
|
||
def _parse_time(raw: str | None) -> datetime | None:
|
||
if not raw:
|
||
return None
|
||
text = str(raw).strip()
|
||
if not text:
|
||
return None
|
||
try:
|
||
return datetime.fromisoformat(text)
|
||
except ValueError:
|
||
pass
|
||
for fmt in _TIMESTAMP_FORMATS:
|
||
try:
|
||
return datetime.strptime(text, fmt)
|
||
except ValueError:
|
||
continue
|
||
return None
|
||
|
||
|
||
def _extract_log_time(line: str) -> datetime | None:
|
||
if len(line) < 19:
|
||
return None
|
||
candidates = [line[:26], line[:19]]
|
||
for candidate in candidates:
|
||
for fmt in _TIMESTAMP_FORMATS:
|
||
if len(candidate) != len(datetime.now().strftime(fmt)):
|
||
continue
|
||
try:
|
||
return datetime.strptime(candidate, fmt)
|
||
except ValueError:
|
||
continue
|
||
return None
|
||
|
||
|
||
def _filter_logs_since(lines: list[str], started_at: str | None) -> list[str]:
|
||
if not started_at:
|
||
return lines[-_MAX_LOG_LINES:]
|
||
started_time = _parse_time(started_at)
|
||
if not started_time:
|
||
return lines[-_MAX_LOG_LINES:]
|
||
filtered = [line for line in lines if (_extract_log_time(line) or started_time) >= started_time]
|
||
if filtered:
|
||
return filtered[-_MAX_LOG_LINES:]
|
||
return lines[-_MAX_LOG_LINES:]
|
||
|
||
|
||
def _merge_logs(existing: list[str] | None, current: list[str]) -> list[str]:
|
||
merged = list(existing or [])
|
||
for line in current:
|
||
if line not in merged[-40:]:
|
||
merged.append(line)
|
||
continue
|
||
if not merged or merged[-1] != line:
|
||
merged.append(line)
|
||
return merged[-_MAX_LOG_LINES:]
|
||
|
||
|
||
def _find_active(records: list[dict]) -> dict | None:
|
||
return next((item for item in records if item.get("status") in _ACTIVE_STATUSES), None)
|
||
|
||
|
||
def _same_session(active: dict | None, runtime: dict) -> bool:
|
||
if not active:
|
||
return False
|
||
runtime_started_at = str(runtime.get("latest_start_time", "") or "").strip()
|
||
active_started_at = str(active.get("started_at", "") or "").strip()
|
||
if not runtime_started_at or not active_started_at:
|
||
return True
|
||
runtime_started = _parse_time(runtime_started_at)
|
||
active_started = _parse_time(active_started_at)
|
||
if not runtime_started or not active_started:
|
||
return True
|
||
return abs((runtime_started - active_started).total_seconds()) < 3
|
||
|
||
|
||
def _latest_matching_log(log_lines: list[str], keywords: tuple[str, ...]) -> str:
|
||
for line in reversed(log_lines or []):
|
||
if any(keyword in line for keyword in keywords):
|
||
return line
|
||
return ""
|
||
|
||
|
||
def _sync_phase_history(record: dict, phase_label: str, phase_detail: str) -> None:
|
||
history = list(record.get("phase_history") or [])
|
||
current = {
|
||
"at": _now(),
|
||
"label": phase_label or "-",
|
||
"detail": phase_detail or "",
|
||
}
|
||
if history:
|
||
latest = history[-1]
|
||
if latest.get("label") == current["label"] and latest.get("detail") == current["detail"]:
|
||
return
|
||
history.append(current)
|
||
record["phase_history"] = history[-20:]
|
||
|
||
|
||
def _phase_from_runtime(status: str, runtime: dict, progress: dict, log_lines: list[str], active_job: dict | None = None) -> tuple[str, str]:
|
||
active_job = active_job or {}
|
||
if status == "starting":
|
||
return "启动中", "正在拉起检测服务并等待 Worker 就绪"
|
||
if status == "stopping":
|
||
return "停止中", "已发送停止请求，等待 Worker 退出并归档日志"
|
||
if status == "completed":
|
||
terminal = int(active_job.get("items_terminal", 0) or 0)
|
||
return "已完成", f"本轮检测已自然完成，本次累计处理 {terminal} 个任务项"
|
||
if status == "partial_failed":
|
||
failed = int(active_job.get("items_failed", 0) or 0)
|
||
terminal = int(active_job.get("items_terminal", 0) or 0)
|
||
return "部分失败", f"本轮检测已结束，其中失败 {failed} 个，累计处理 {terminal} 个任务项"
|
||
if status == "failed":
|
||
return "失败", runtime.get("message") or "Worker 异常退出，请检查日志"
|
||
if status == "stopped":
|
||
return "已停止", runtime.get("message") or "检测服务已停止"
|
||
if runtime.get("running"):
|
||
proxy_runtime_state = str(runtime.get("proxy_runtime_state", "") or "").strip()
|
||
proxy_runtime_detail = str(runtime.get("proxy_runtime_detail", "") or "").strip()
|
||
running = (progress or {}).get("running", 0)
|
||
pending = (progress or {}).get("pending", 0)
|
||
phase_log = _latest_matching_log(
|
||
log_lines,
|
||
(
|
||
"Connection refused",
|
||
"Read timed out",
|
||
"ConnectTimeout",
|
||
"HTTPSConnectionPool",
|
||
"WaybackDetector",
|
||
"域名检测任务完成",
|
||
"当前批次检测完成",
|
||
"当前实际线程数量",
|
||
"开始创建线程",
|
||
"获取到",
|
||
"开始检测，刷新代理池",
|
||
"刷新代理池",
|
||
"没有需要检测的域名",
|
||
"开始执行域名检测任务",
|
||
),
|
||
)
|
||
if proxy_runtime_state == "blocked_no_proxy":
|
||
return "等待代理", proxy_runtime_detail or "代理池当前无可用代理，且未允许直连"
|
||
if proxy_runtime_state == "degraded_direct":
|
||
return "降级直连", proxy_runtime_detail or "代理池暂无可用代理，当前使用直连继续执行"
|
||
if "外部依赖异常，步骤降级继续执行" in phase_log:
|
||
return "外部站点异常", "外部依赖当前波动，系统已按降级策略继续执行并保留人工复核"
|
||
if "WaybackDetector" in phase_log or "web.archive.org" in phase_log:
|
||
return "外部站点异常", "时光机依赖当前访问异常，任务仍在继续，建议关注网络或代理策略"
|
||
if any(keyword in phase_log for keyword in ("Connection refused", "Read timed out", "ConnectTimeout", "HTTPSConnectionPool")):
|
||
return "网络波动", phase_log
|
||
if "域名检测任务完成" in phase_log:
|
||
return "完成归档", "本轮检测已处理完成，正在等待下一轮任务或归档最终日志"
|
||
if "当前批次检测完成" in phase_log:
|
||
return "批次完成", phase_log
|
||
if "当前实际线程数量" in phase_log or running > 0:
|
||
if running > 0:
|
||
return "检测中", f"Worker 正在处理 {running} 个检测任务"
|
||
return "检测中", phase_log
|
||
if "开始创建线程" in phase_log:
|
||
return "建线程中", phase_log
|
||
if "获取到" in phase_log:
|
||
return "取任务中", phase_log
|
||
if "刷新代理池" in phase_log:
|
||
return "刷新代理池", phase_log
|
||
if "没有需要检测的域名" in phase_log:
|
||
return "空闲等待", "Worker 在线，当前没有待检测域名"
|
||
if "开始执行域名检测任务" in phase_log:
|
||
return "准备检测", phase_log
|
||
if running > 0:
|
||
return "检测中", f"Worker 正在处理 {running} 个检测任务"
|
||
if pending > 0:
|
||
return "取任务中", f"Worker 在线，等待或领取待检测域名，当前剩余 {pending} 个"
|
||
return "运行中", "Worker 在线，当前没有活跃检测任务"
|
||
return "已停止", runtime.get("message") or "检测服务已停止"
|
||
|
||
|
||
def _sync_record(
|
||
record: dict,
|
||
*,
|
||
status: str,
|
||
message: str,
|
||
runtime: dict,
|
||
progress: dict,
|
||
settings_summary: dict,
|
||
log_lines: list[str],
|
||
active_job: dict | None = None,
|
||
) -> dict:
|
||
record["status"] = status
|
||
record["message"] = message
|
||
record["runtime"] = runtime
|
||
record["progress"] = progress
|
||
record["settings_summary"] = settings_summary
|
||
record["updated_at"] = _now()
|
||
if not record.get("started_at"):
|
||
record["started_at"] = runtime.get("latest_start_time") or record["updated_at"]
|
||
session_logs = _merge_logs(record.get("logs"), _filter_logs_since(log_lines, record.get("started_at")))
|
||
record["logs"] = session_logs
|
||
record["active_job"] = active_job or {}
|
||
record["phase_label"], record["phase_detail"] = _phase_from_runtime(status, runtime, progress, session_logs, active_job)
|
||
_sync_phase_history(record, record.get("phase_label", ""), record.get("phase_detail", ""))
|
||
if status in {"stopped", "failed", "completed", "partial_failed"} and not record.get("completed_at"):
|
||
record["completed_at"] = _now()
|
||
if status in _ACTIVE_STATUSES:
|
||
record["completed_at"] = ""
|
||
return record
|
||
|
||
|
||
def create_detect_run_snapshot(message: str, runtime: dict, progress: dict, settings_summary: dict) -> dict:
|
||
records = _load()
|
||
active = _find_active(records)
|
||
current_logs = _capture_worker_logs()
|
||
if active:
|
||
if active.get("status") == "stopping" and runtime.get("running"):
|
||
active["status"] = "running"
|
||
_sync_record(
|
||
active,
|
||
status=active.get("status", "starting"),
|
||
message=message,
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=current_logs,
|
||
)
|
||
_save(records)
|
||
return dict(active)
|
||
|
||
initial_started_at = runtime.get("latest_start_time") or _now()
|
||
record = {
|
||
"run_id": uuid4().hex,
|
||
"status": "starting",
|
||
"message": message,
|
||
"created_at": _now(),
|
||
"updated_at": _now(),
|
||
"started_at": initial_started_at,
|
||
"completed_at": "",
|
||
"runtime": runtime,
|
||
"progress": progress,
|
||
"settings_summary": settings_summary,
|
||
"phase_label": "",
|
||
"phase_detail": "",
|
||
"phase_history": [],
|
||
"logs": [],
|
||
}
|
||
_sync_record(
|
||
record,
|
||
status="starting",
|
||
message=message,
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=current_logs,
|
||
)
|
||
records.insert(0, record)
|
||
_save(records)
|
||
return dict(record)
|
||
|
||
|
||
def finalize_detect_run(message: str, runtime: dict, progress: dict, settings_summary: dict, active_job: dict | None = None) -> dict | None:
|
||
records = _load()
|
||
target = _find_active(records)
|
||
if not target:
|
||
return None
|
||
final_status = "stopped" if target.get("status") == "stopping" else "failed"
|
||
_sync_record(
|
||
target,
|
||
status=final_status,
|
||
message=message,
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=_capture_worker_logs(),
|
||
active_job=active_job,
|
||
)
|
||
_save(records)
|
||
return dict(target)
|
||
|
||
|
||
def sync_detect_runs(runtime: dict, progress: dict, settings_summary: dict, active_job: dict | None = None) -> list[dict]:
|
||
records = _load()
|
||
active = _find_active(records)
|
||
current_logs = _capture_worker_logs()
|
||
active_job = active_job or {}
|
||
runtime_detecting = bool(runtime.get("detecting", False))
|
||
active_job_status = str(active_job.get("status", "") or "").strip()
|
||
active_job_open = active_job_status in {"pending", "running"}
|
||
execution_active = runtime_detecting or active_job_open or int((progress or {}).get("running", 0) or 0) > 0
|
||
|
||
if runtime.get("running") and execution_active:
|
||
if active and not _same_session(active, runtime):
|
||
_sync_record(
|
||
active,
|
||
status="stopped",
|
||
message="检测服务已重启，上一轮会话已归档",
|
||
runtime=active.get("runtime") or runtime,
|
||
progress=active.get("progress") or progress,
|
||
settings_summary=active.get("settings_summary") or settings_summary,
|
||
log_lines=current_logs,
|
||
active_job=active.get("active_job") or active_job,
|
||
)
|
||
active = None
|
||
if active:
|
||
next_status = "running" if active.get("status") != "stopping" else "stopping"
|
||
_sync_record(
|
||
active,
|
||
status=next_status,
|
||
message=runtime.get("message") or active.get("message") or "检测服务运行中",
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=current_logs,
|
||
active_job=active_job,
|
||
)
|
||
else:
|
||
started_at = runtime.get("latest_start_time") or _now()
|
||
record = {
|
||
"run_id": uuid4().hex,
|
||
"status": "running",
|
||
"message": runtime.get("message") or "检测服务运行中",
|
||
"created_at": _now(),
|
||
"updated_at": _now(),
|
||
"started_at": started_at,
|
||
"completed_at": "",
|
||
"runtime": runtime,
|
||
"progress": progress,
|
||
"settings_summary": settings_summary,
|
||
"phase_label": "",
|
||
"phase_detail": "",
|
||
"phase_history": [],
|
||
"logs": [],
|
||
"active_job": active_job,
|
||
}
|
||
_sync_record(
|
||
record,
|
||
status="running",
|
||
message=record["message"],
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=current_logs,
|
||
active_job=active_job,
|
||
)
|
||
records.insert(0, record)
|
||
elif active:
|
||
if runtime.get("running") and not execution_active:
|
||
if active.get("status") == "stopping":
|
||
final_status = "stopped"
|
||
final_message = runtime.get("message") or "检测任务已停止，Worker 保持待命"
|
||
elif active_job_status == "partial_failed":
|
||
final_status = "partial_failed"
|
||
final_message = "检测任务已结束，存在部分失败项"
|
||
elif active_job_status == "failed":
|
||
final_status = "failed"
|
||
final_message = "检测任务已结束，任务结果为失败"
|
||
else:
|
||
final_status = "completed"
|
||
final_message = "检测任务已自然完成，Worker 保持待命"
|
||
else:
|
||
final_status = "stopped" if active.get("status") == "stopping" else "failed"
|
||
final_message = runtime.get("message") or ("检测服务已停止" if final_status == "stopped" else "检测服务异常退出")
|
||
_sync_record(
|
||
active,
|
||
status=final_status,
|
||
message=final_message,
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=current_logs,
|
||
active_job=active_job,
|
||
)
|
||
|
||
if records:
|
||
records[0]["logs"] = _merge_logs(
|
||
records[0].get("logs"),
|
||
_filter_logs_since(current_logs, records[0].get("started_at")),
|
||
)
|
||
|
||
_save(records)
|
||
return records
|
||
|
||
|
||
def mark_detect_run_stopping(message: str, runtime: dict, progress: dict, settings_summary: dict) -> dict | None:
|
||
records = _load()
|
||
target = _find_active(records)
|
||
if not target:
|
||
return None
|
||
_sync_record(
|
||
target,
|
||
status="stopping",
|
||
message=message,
|
||
runtime=runtime,
|
||
progress=progress,
|
||
settings_summary=settings_summary,
|
||
log_lines=_capture_worker_logs(),
|
||
active_job=target.get("active_job") or {},
|
||
)
|
||
_save(records)
|
||
return dict(target)
|