fix(scheduler): drop cross-task mutex, quiet window + retry

Incident: evening full snapshot could be recorded as ok with
already_completed/elapsed=0 after mutual skip with hourly sync, then
next_run jumped to the next day.

- Full-site snapshot never skips because another task is running
- 23:00-01:00 Asia/Shanghai: defer discovery / snapshot_recent /
  candidate_cleanup to after 01:00; fans never defers
- Skip records ok=false + skipped=true (not success / not completed)
- Skip/fail reschedule soon (~5m); daily success still next snapshot_at
- TaskControl return value drives next_run; system UI shows skip fields
This commit is contained in:
bot-ci committed 2026-11-03 00:07:19 +08:00
1 parent 39378c65b2
commit 9969e65202
10 files changed
+411 -84

No files matched your search

+144 -65
View File
@@ -33,13 +33,20 @@ from .database import Database
from .logging_json import JsonLogger
from .notify.telegram import TelegramClient
from .repository import Repository
from .scheduler import ScheduledTask, Scheduler
from .scheduler import ScheduledTask, Scheduler, TaskControl
from .services.discovery import DiscoveryService
from .services.library import LibraryService
from .services.snapshot import SnapshotService
from .services.telegram_poller import TelegramPoller
from .services.up_profile import UpProfileService
from .timeutil import next_daily_run, parse_hhmm, shanghai_date
from .timeutil import (
in_snapshot_quiet_window,
interval_next_run,
next_after_snapshot_quiet_window,
next_daily_run,
parse_hhmm,
shanghai_date,
)
ROOT = Path(__file__).resolve().parent.parent
DEFAULT_CONFIG = default_config_path(ROOT)
@@ -163,13 +170,6 @@ def _clear_task_running(repo: Repository, name: str) -> None:
pass
def _is_task_running(repo: Repository, name: str) -> bool:
try:
return bool(repo.kv_get(_task_running_key(name)))
except Exception: # noqa: BLE001
return False
def _record_task(
repo: Repository,
name: str,
@@ -179,12 +179,19 @@ def _record_task(
finished_at: int | None = None,
payload=None,
error: str | None = None,
skipped: bool = False,
) -> None:
"""把最近一次任务结果写入 kv,并清除 running 标记。"""
"""把最近一次任务结果写入 kv,并清除 running 标记。
``skipped=True`` 表示主动延后/避让,不得记成成功,也不推进「当日已完成」。
"""
now = int(time.time())
if skipped:
ok = False
record = {
"name": name,
"ok": bool(ok),
"skipped": bool(skipped),
"started_at": int(started_at if started_at is not None else now),
"finished_at": int(finished_at if finished_at is not None else now),
"error": error,
@@ -197,6 +204,42 @@ def _record_task(
_clear_task_running(repo, name)
# 全站快照 / 粉丝失败后的补跑间隔(秒)
_TASK_RETRY_SECONDS = 300.0
_QUIET_SKIP_REASON = "snapshot_quiet_window"
def _quiet_window_defer(
repo: Repository,
logger: JsonLogger,
name: str,
*,
started_at: int,
) -> TaskControl:
"""静默窗内不执行:记 skip(非成功),并排到 01:00 之后。"""
finished = int(time.time())
logger.info(f"{name}.skip", reason=_QUIET_SKIP_REASON)
_record_task(
repo,
name,
ok=False,
skipped=True,
started_at=started_at,
finished_at=finished,
payload={"skipped": True, "reason": _QUIET_SKIP_REASON},
error=_QUIET_SKIP_REASON,
)
return TaskControl(
ok=False,
next_run=next_after_snapshot_quiet_window(float(finished)),
error=_QUIET_SKIP_REASON,
)
def _retry_soon(now: float | None = None) -> float:
return (time.time() if now is None else now) + _TASK_RETRY_SECONDS
def _client(credentials, logger: JsonLogger, *, pacer=None, retries: int = 3) -> BilibiliClient:
return BilibiliClient(
cookie=credentials.cookie,
@@ -504,66 +547,83 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
logger=logger,
)
hh, mm = parse_hhmm(cfg.schedule.snapshot_at)
snapshot_at = f"{hh:02d}:{mm:02d}"
sh, sm = parse_hhmm(cfg.schedule.seed_at)
seed_at = f"{sh:02d}:{sm:02d}"
recent_minutes = int(store.get().schedule.recent_snapshot_minutes)
discover_minutes = int(store.get().schedule.discover_minutes)
def run_discover():
started = int(time.time())
if in_snapshot_quiet_window(float(started)):
return _quiet_window_defer(
repo, logger, "discovery", started_at=started,
)
_mark_task_running(repo, "discovery", started_at=started)
interval = float(store.get().schedule.discover_minutes * 60)
try:
summary = discovery_service.run()
except Exception as exc: # noqa: BLE001 记录后交给调度器隔离
except Exception as exc: # noqa: BLE001 记录后补跑,不抛给次日
finished = int(time.time())
_record_task(
repo, "discovery", ok=False, started_at=started,
finished_at=int(time.time()), error=str(exc),
finished_at=finished, error=str(exc),
)
return TaskControl(
ok=False, next_run=_retry_soon(float(finished)), error=str(exc),
)
raise
payload = summary.as_dict()
ok = not summary.errors
finished = int(summary.finished_at or time.time())
_record_task(
repo, "discovery", ok=not summary.errors,
repo, "discovery", ok=ok,
started_at=summary.started_at,
finished_at=summary.finished_at or int(time.time()),
finished_at=finished,
payload=payload,
error=";".join(summary.errors) if summary.errors else None,
)
last["discover"] = summary
logger.info("discovery.summary", **payload)
return summary
next_run = (
interval_next_run(float(finished), interval) if ok
else _retry_soon(float(finished))
)
return TaskControl(ok=ok, next_run=next_run)
def run_cleanup():
started = int(time.time())
if in_snapshot_quiet_window(float(started)):
return _quiet_window_defer(
repo, logger, "candidate_cleanup", started_at=started,
)
removed = repo.delete_expired_candidates(
ttl_days=cfg.schedule.candidate_ttl_days
)
expired = repo.expire_fav_actions()
if removed or expired:
repo.bump_cache_version("videos")
finished = int(time.time())
logger.info(
"cleanup.done",
candidates_removed=removed, fav_actions_expired=expired,
)
_record_task(
repo, "candidate_cleanup", ok=True, started_at=started,
finished_at=int(time.time()),
finished_at=finished,
payload={
"candidates_removed": removed,
"fav_actions_expired": expired,
},
)
return {
"candidates_removed": removed,
"fav_actions_expired": expired,
}
return TaskControl(
ok=True,
next_run=interval_next_run(float(finished), 86400.0),
)
def run_snapshot():
"""全站快照:不因其它任务 running 而 skip;失败/未完成则短间隔补跑。"""
started = int(time.time())
if _is_task_running(repo, "snapshot_recent"):
logger.info(
"snapshot.skip", reason="snapshot_recent_running",
)
_record_task(
repo, "snapshot", ok=True, started_at=started,
finished_at=int(time.time()),
payload={"skipped": True, "reason": "snapshot_recent_running"},
)
return None
_mark_task_running(repo, "snapshot", started_at=started)
try:
# 晚间全量:若当日是午夜 seed 壳,必须 force 打穿 ok=1 克隆行。
@@ -573,56 +633,68 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
) == "1"
summary = snapshot_service.run_if_needed(force=force_seed)
except Exception as exc: # noqa: BLE001
finished = int(time.time())
_record_task(
repo, "snapshot", ok=False, started_at=started,
finished_at=int(time.time()), error=str(exc),
finished_at=finished, error=str(exc),
)
return TaskControl(
ok=False, next_run=_retry_soon(float(finished)), error=str(exc),
)
raise
payload = summary.as_dict()
ok = bool(summary.completed and not summary.backup_error)
finished = int(summary.finished_at or time.time())
_record_task(
repo, "snapshot", ok=ok, started_at=summary.started_at,
finished_at=summary.finished_at or int(time.time()),
finished_at=finished,
payload=payload, error=summary.backup_error,
)
last["snapshot"] = summary
logger.info("snapshot.summary", **payload)
return summary
next_run = (
next_daily_run(float(finished), snapshot_at) if ok
else _retry_soon(float(finished))
)
return TaskControl(ok=ok, next_run=next_run)
def run_snapshot_recent():
started = int(time.time())
if _is_task_running(repo, "snapshot"):
logger.info(
"snapshot.recent_skip", reason="snapshot_running",
if in_snapshot_quiet_window(float(started)):
return _quiet_window_defer(
repo, logger, "snapshot_recent", started_at=started,
)
_record_task(
repo, "snapshot_recent", ok=True, started_at=started,
finished_at=int(time.time()),
payload={"skipped": True, "reason": "snapshot_running"},
)
return None
_mark_task_running(repo, "snapshot_recent", started_at=started)
interval = float(store.get().schedule.recent_snapshot_minutes * 60)
try:
summary = snapshot_service.run_recent_videos()
except Exception as exc: # noqa: BLE001
finished = int(time.time())
_record_task(
repo, "snapshot_recent", ok=False, started_at=started,
finished_at=int(time.time()), error=str(exc),
finished_at=finished, error=str(exc),
)
return TaskControl(
ok=False, next_run=_retry_soon(float(finished)), error=str(exc),
)
raise
payload = summary.as_dict()
ok = summary.failed == 0
error = ";".join(summary.errors) if summary.errors else None
finished = int(summary.finished_at or time.time())
_record_task(
repo, "snapshot_recent", ok=ok, started_at=summary.started_at,
finished_at=summary.finished_at or int(time.time()),
finished_at=finished,
payload=payload, error=error,
)
last["snapshot_recent"] = summary
logger.info("snapshot.recent_summary", **payload)
return summary
next_run = (
interval_next_run(float(finished), interval) if ok
else _retry_soon(float(finished))
)
return TaskControl(ok=ok, next_run=next_run)
def run_fans():
"""粉丝更新短耗时:不避开任何任务,可与全量并行。"""
started = int(time.time())
_mark_task_running(repo, "fans", started_at=started)
try:
@@ -632,24 +704,32 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
) == "1"
summary = snapshot_service.run_fans_if_needed(force=force_seed)
except Exception as exc: # noqa: BLE001
finished = int(time.time())
_record_task(
repo, "fans", ok=False, started_at=started,
finished_at=int(time.time()), error=str(exc),
finished_at=finished, error=str(exc),
)
return TaskControl(
ok=False, next_run=_retry_soon(float(finished)), error=str(exc),
)
raise
payload = summary.as_dict()
ok = summary.fans_failed == 0
error = ";".join(
err for err in summary.errors if str(err).startswith("fans ")
) or None
finished = int(summary.finished_at or time.time())
_record_task(
repo, "fans", ok=ok, started_at=summary.started_at,
finished_at=summary.finished_at or int(time.time()),
finished_at=finished,
payload=payload, error=error,
)
last["fans"] = summary
logger.info("fans.summary", **payload)
return summary
next_run = (
next_daily_run(float(finished), snapshot_at) if ok
else _retry_soon(float(finished))
)
return TaskControl(ok=ok, next_run=next_run)
def run_snapshot_seed():
started = int(time.time())
@@ -657,20 +737,26 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
try:
summary = snapshot_service.run_seed_from_last_completed()
except Exception as exc: # noqa: BLE001
finished = int(time.time())
_record_task(
repo, "snapshot_seed", ok=False, started_at=started,
finished_at=int(time.time()), error=str(exc),
finished_at=finished, error=str(exc),
)
return TaskControl(
ok=False, next_run=_retry_soon(float(finished)), error=str(exc),
)
raise
payload = summary.as_dict()
finished = int(summary.finished_at or time.time())
_record_task(
repo, "snapshot_seed", ok=True, started_at=summary.started_at,
finished_at=summary.finished_at or int(time.time()),
finished_at=finished,
payload=payload,
)
last["snapshot_seed"] = summary
logger.info("snapshot.seed_summary", **payload)
return summary
return TaskControl(
ok=True, next_run=next_daily_run(float(finished), seed_at),
)
def run_config_watch():
before = store.revision
@@ -679,11 +765,6 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
logger.info("config.reloaded", revision=store.revision)
return {"revision": store.revision}
hh, mm = parse_hhmm(cfg.schedule.snapshot_at)
snapshot_at = f"{hh:02d}:{mm:02d}"
sh, sm = parse_hhmm(cfg.schedule.seed_at)
seed_at = f"{sh:02d}:{sm:02d}"
recent_minutes = int(store.get().schedule.recent_snapshot_minutes)
scheduler = Scheduler(
[
ScheduledTask(
@@ -691,21 +772,18 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
86400.0,
run_snapshot_seed,
next_run=0.0,
next_run_fn=lambda started: next_daily_run(started, seed_at),
),
ScheduledTask(
"snapshot",
86400.0,
run_snapshot,
next_run=0.0,
next_run_fn=lambda started: next_daily_run(started, snapshot_at),
),
ScheduledTask(
"fans",
86400.0,
run_fans,
next_run=0.0,
next_run_fn=lambda started: next_daily_run(started, snapshot_at),
),
ScheduledTask(
"snapshot_recent",
@@ -714,7 +792,7 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
),
ScheduledTask(
"discovery",
float(cfg.schedule.discover_minutes * 60),
float(discover_minutes * 60),
run_discover,
),
ScheduledTask("candidate_cleanup", 86400.0, run_cleanup),
@@ -722,6 +800,7 @@ def cmd_run(args, logger: JsonLogger, *, serve_web: bool = False) -> int:
],
logger=logger,
)
if serve_web and not args.once:
from .web.server import create_server, serve_forever