|
@@ -6,6 +6,11 @@ SQLite so queued work survives an app restart.
|
|
|
|
|
|
|
|
One JobQueue instance owns a single SQLite connection (guarded by a lock) shared
|
|
One JobQueue instance owns a single SQLite connection (guarded by a lock) shared
|
|
|
between Flask request threads and the worker thread.
|
|
between Flask request threads and the worker thread.
|
|
|
|
|
+
|
|
|
|
|
+Because that worker thread is single, nothing may sleep in it. A Report & Release job
|
|
|
|
|
+that has to wait between two pipeline steps saves its progress and goes back to
|
|
|
|
|
+'pending' with a future `run_after` (`_defer`); the loop runs everything else that is
|
|
|
|
|
+queued and re-claims the job when the wait is over.
|
|
|
"""
|
|
"""
|
|
|
|
|
|
|
|
from __future__ import annotations
|
|
from __future__ import annotations
|
|
@@ -16,7 +21,7 @@ import sqlite3
|
|
|
import threading
|
|
import threading
|
|
|
import time
|
|
import time
|
|
|
import traceback
|
|
import traceback
|
|
|
-from datetime import datetime, timezone
|
|
|
|
|
|
|
+from datetime import datetime, timedelta, timezone
|
|
|
from logging.handlers import RotatingFileHandler
|
|
from logging.handlers import RotatingFileHandler
|
|
|
from typing import Callable, Mapping
|
|
from typing import Callable, Mapping
|
|
|
|
|
|
|
@@ -51,6 +56,22 @@ def _now() -> str:
|
|
|
return datetime.now(timezone.utc).strftime("%Y-%m-%d %H:%M:%S")
|
|
return datetime.now(timezone.utc).strftime("%Y-%m-%d %H:%M:%S")
|
|
|
|
|
|
|
|
|
|
|
|
|
|
|
+def _plus_seconds(seconds: int) -> str:
|
|
|
|
|
+ """A `_now()`-comparable UTC timestamp `seconds` in the future (sorts lexically)."""
|
|
|
|
|
+ return (datetime.now(timezone.utc) + timedelta(seconds=seconds)).strftime(
|
|
|
|
|
+ "%Y-%m-%d %H:%M:%S"
|
|
|
|
|
+ )
|
|
|
|
|
+
|
|
|
|
|
+
|
|
|
|
|
+def _progress(total_items: int, steps: int, step_index: int, done_in_step: int) -> int:
|
|
|
|
|
+ """Job progress in item units, spread evenly over the pipeline's steps.
|
|
|
|
|
+
|
|
|
|
|
+ Keeps `processed` monotonic and comparable to `total` (the message count) even
|
|
|
|
|
+ though a multi-step job walks every message several times.
|
|
|
|
|
+ """
|
|
|
|
|
+ return (step_index * total_items + done_in_step) // max(steps, 1)
|
|
|
|
|
+
|
|
|
|
|
+
|
|
|
class JobQueue:
|
|
class JobQueue:
|
|
|
def __init__(self, db_path: str,
|
|
def __init__(self, db_path: str,
|
|
|
pps_provider: Callable[[], PPSClient],
|
|
pps_provider: Callable[[], PPSClient],
|
|
@@ -91,6 +112,10 @@ class JobQueue:
|
|
|
processed INTEGER NOT NULL DEFAULT 0,
|
|
processed INTEGER NOT NULL DEFAULT 0,
|
|
|
total INTEGER NOT NULL DEFAULT 0,
|
|
total INTEGER NOT NULL DEFAULT 0,
|
|
|
error TEXT,
|
|
error TEXT,
|
|
|
|
|
+ -- A pending job with run_after in the future is waiting out a
|
|
|
|
|
+ -- pipeline step delay; `state` holds where it got to (see _defer).
|
|
|
|
|
+ run_after TEXT,
|
|
|
|
|
+ state TEXT NOT NULL DEFAULT '{}',
|
|
|
created_at TEXT NOT NULL,
|
|
created_at TEXT NOT NULL,
|
|
|
updated_at TEXT NOT NULL
|
|
updated_at TEXT NOT NULL
|
|
|
);
|
|
);
|
|
@@ -117,10 +142,17 @@ class JobQueue:
|
|
|
job_cols = {r["name"] for r in self._conn.execute("PRAGMA table_info(jobs)")}
|
|
job_cols = {r["name"] for r in self._conn.execute("PRAGMA table_info(jobs)")}
|
|
|
if "user" not in job_cols:
|
|
if "user" not in job_cols:
|
|
|
self._conn.execute("ALTER TABLE jobs ADD COLUMN user TEXT")
|
|
self._conn.execute("ALTER TABLE jobs ADD COLUMN user TEXT")
|
|
|
|
|
+ if "run_after" not in job_cols:
|
|
|
|
|
+ self._conn.execute("ALTER TABLE jobs ADD COLUMN run_after TEXT")
|
|
|
|
|
+ if "state" not in job_cols:
|
|
|
|
|
+ self._conn.execute(
|
|
|
|
|
+ "ALTER TABLE jobs ADD COLUMN state TEXT NOT NULL DEFAULT '{}'"
|
|
|
|
|
+ )
|
|
|
self._conn.commit()
|
|
self._conn.commit()
|
|
|
|
|
|
|
|
def _recover(self) -> None:
|
|
def _recover(self) -> None:
|
|
|
- # Any job left 'running' when the process died is requeued.
|
|
|
|
|
|
|
+ # Any job left 'running' when the process died is requeued. Its `state` survives,
|
|
|
|
|
+ # so a multi-step pipeline resumes at the step it had reached.
|
|
|
with self._lock:
|
|
with self._lock:
|
|
|
cur = self._conn.execute(
|
|
cur = self._conn.execute(
|
|
|
"UPDATE jobs SET status='pending', updated_at=? WHERE status='running'",
|
|
"UPDATE jobs SET status='pending', updated_at=? WHERE status='running'",
|
|
@@ -173,7 +205,7 @@ class JobQueue:
|
|
|
|
|
|
|
|
def recent_jobs(self, limit: int = 25, user: str | None = None) -> list[dict]:
|
|
def recent_jobs(self, limit: int = 25, user: str | None = None) -> list[dict]:
|
|
|
"""Recent jobs, newest first. Pass `user` to scope to one owner (None = all)."""
|
|
"""Recent jobs, newest first. Pass `user` to scope to one owner (None = all)."""
|
|
|
- cols = ("id, action, folder, user, status, processed, total, error,"
|
|
|
|
|
|
|
+ cols = ("id, action, folder, user, status, processed, total, error, run_after,"
|
|
|
" created_at, updated_at")
|
|
" created_at, updated_at")
|
|
|
with self._lock:
|
|
with self._lock:
|
|
|
if user is None:
|
|
if user is None:
|
|
@@ -195,10 +227,11 @@ class JobQueue:
|
|
|
return row is not None
|
|
return row is not None
|
|
|
|
|
|
|
|
def retry(self, job_id: int) -> bool:
|
|
def retry(self, job_id: int) -> bool:
|
|
|
- """Requeue a failed job. Returns False if it isn't a failed job."""
|
|
|
|
|
|
|
+ """Requeue a failed job — from the top: progress state and any wait are cleared."""
|
|
|
with self._lock:
|
|
with self._lock:
|
|
|
cur = self._conn.execute(
|
|
cur = self._conn.execute(
|
|
|
- "UPDATE jobs SET status='pending', processed=0, error=NULL, updated_at=?"
|
|
|
|
|
|
|
+ "UPDATE jobs SET status='pending', processed=0, error=NULL,"
|
|
|
|
|
+ " run_after=NULL, state='{}', updated_at=?"
|
|
|
" WHERE id=? AND status='failed'",
|
|
" WHERE id=? AND status='failed'",
|
|
|
(_now(), job_id),
|
|
(_now(), job_id),
|
|
|
)
|
|
)
|
|
@@ -226,9 +259,14 @@ class JobQueue:
|
|
|
self._mark_failed(job["id"], traceback.format_exc())
|
|
self._mark_failed(job["id"], traceback.format_exc())
|
|
|
|
|
|
|
|
def _claim_next(self) -> dict | None:
|
|
def _claim_next(self) -> dict | None:
|
|
|
|
|
+ # A job waiting out a step delay carries a future `run_after` and is simply
|
|
|
|
|
+ # skipped, so jobs queued behind it run instead of being blocked by the wait.
|
|
|
with self._lock:
|
|
with self._lock:
|
|
|
row = self._conn.execute(
|
|
row = self._conn.execute(
|
|
|
- "SELECT * FROM jobs WHERE status='pending' ORDER BY id ASC LIMIT 1"
|
|
|
|
|
|
|
+ "SELECT * FROM jobs WHERE status='pending'"
|
|
|
|
|
+ " AND (run_after IS NULL OR run_after <= ?)"
|
|
|
|
|
+ " ORDER BY id ASC LIMIT 1",
|
|
|
|
|
+ (_now(),),
|
|
|
).fetchone()
|
|
).fetchone()
|
|
|
if row is None:
|
|
if row is None:
|
|
|
return None
|
|
return None
|
|
@@ -240,42 +278,91 @@ class JobQueue:
|
|
|
return dict(row)
|
|
return dict(row)
|
|
|
|
|
|
|
|
def _process(self, job: dict) -> None:
|
|
def _process(self, job: dict) -> None:
|
|
|
|
|
+ """Run a job, or the next step of one, and either finish or re-park it.
|
|
|
|
|
+
|
|
|
|
|
+ A Report & Release job is a sequence of steps (move → release → delete). Each
|
|
|
|
|
+ step is run for every chunk, then — if another step follows — the job is put back
|
|
|
|
|
+ on the queue with `run_after` set (`_defer`) instead of sleeping here: the worker
|
|
|
|
|
+ thread is single, so sleeping would stall every job queued behind this one.
|
|
|
|
|
+ Resuming re-reads the messages' current location, never the cached localguids.
|
|
|
|
|
+ """
|
|
|
job_id = job["id"]
|
|
job_id = job["id"]
|
|
|
action = job["action"]
|
|
action = job["action"]
|
|
|
- folder = job["folder"]
|
|
|
|
|
user = job["user"] if "user" in job.keys() else None
|
|
user = job["user"] if "user" in job.keys() else None
|
|
|
extra = json.loads(job["extra"] or "{}")
|
|
extra = json.loads(job["extra"] or "{}")
|
|
|
|
|
+ state = json.loads((job["state"] if "state" in job.keys() else None) or "{}")
|
|
|
items = self._items_for(job_id)
|
|
items = self._items_for(job_id)
|
|
|
|
|
|
|
|
# Snapshot config + client ONCE at job start — a mid-job admin edit affects the
|
|
# Snapshot config + client ONCE at job start — a mid-job admin edit affects the
|
|
|
- # next job, not this one (see AGENTS.md "snapshot-per-job").
|
|
|
|
|
|
|
+ # next job, not this one (see AGENTS.md "snapshot-per-job"). A job that resumes
|
|
|
|
|
+ # after a wait re-reads the snapshot, so the plan it started with (steps, delay)
|
|
|
|
|
+ # is carried in `state` rather than re-derived from the new config.
|
|
|
cfg = self._cfg()
|
|
cfg = self._cfg()
|
|
|
pps = self._pps()
|
|
pps = self._pps()
|
|
|
chunk_size = int(cfg.get("chunk_size", 25))
|
|
chunk_size = int(cfg.get("chunk_size", 25))
|
|
|
|
|
+ chunks = list(_chunks(items, chunk_size))
|
|
|
|
|
+
|
|
|
|
|
+ if action == "report_release":
|
|
|
|
|
+ steps: list[str | None] = list(state.get("steps") or pipeline.job_steps(cfg))
|
|
|
|
|
+ delay = int(state.get("delay", pipeline.step_delay(cfg)))
|
|
|
|
|
+ else:
|
|
|
|
|
+ steps, delay = [None], 0
|
|
|
|
|
+ index = int(state.get("step_index", 0))
|
|
|
|
|
+ folder = state.get("folder") or job["folder"]
|
|
|
|
|
+ errors: list[str] = list(state.get("errors") or [])
|
|
|
|
|
+ failed: set[int] = set(state.get("failed") or [])
|
|
|
|
|
+
|
|
|
log.info(
|
|
log.info(
|
|
|
- "job #%d start: action=%s folder=%r user=%s total=%d",
|
|
|
|
|
- job_id, action, folder, user, len(items),
|
|
|
|
|
|
|
+ "job #%d %s: action=%s folder=%r user=%s total=%d step=%s",
|
|
|
|
|
+ job_id, "resume" if index else "start", action, folder, user,
|
|
|
|
|
+ len(items), steps[index] or "-",
|
|
|
)
|
|
)
|
|
|
|
|
|
|
|
- dst = _destination(action, extra, cfg)
|
|
|
|
|
- errors: list[str] = []
|
|
|
|
|
- processed = 0
|
|
|
|
|
started = time.monotonic()
|
|
started = time.monotonic()
|
|
|
- for chunk in _chunks(items, chunk_size):
|
|
|
|
|
- try:
|
|
|
|
|
- self._run_action(pps, cfg, action, folder, chunk, extra)
|
|
|
|
|
- processed += len(chunk)
|
|
|
|
|
- self._set_processed(job_id, processed)
|
|
|
|
|
- self._log_ops(job_id, action, folder, dst, chunk, user, "ok", None)
|
|
|
|
|
- except PPSError as exc:
|
|
|
|
|
- log.error("job #%d chunk failed: %s", job_id, exc)
|
|
|
|
|
- errors.append(f"chunk failed: {exc}")
|
|
|
|
|
- self._log_ops(job_id, action, folder, dst, chunk, user, "FAILED", str(exc))
|
|
|
|
|
- except Exception as exc: # noqa: BLE001
|
|
|
|
|
- log.exception("job #%d chunk raised", job_id)
|
|
|
|
|
- errors.append(f"chunk failed: {exc}")
|
|
|
|
|
- self._log_ops(job_id, action, folder, dst, chunk, user, "FAILED", str(exc))
|
|
|
|
|
-
|
|
|
|
|
|
|
+ while index < len(steps):
|
|
|
|
|
+ step = steps[index]
|
|
|
|
|
+ dst = (pipeline.step_destination(cfg, step, folder) if step
|
|
|
|
|
+ else _destination(action, extra, cfg))
|
|
|
|
|
+ done = 0
|
|
|
|
|
+ for i, chunk in enumerate(chunks):
|
|
|
|
|
+ if i in failed:
|
|
|
|
|
+ continue # an earlier step gave up on this chunk
|
|
|
|
|
+ try:
|
|
|
|
|
+ if step is None:
|
|
|
|
|
+ self._run_action(pps, cfg, action, folder, chunk, extra)
|
|
|
|
|
+ else:
|
|
|
|
|
+ # refresh after the first step: the wait has passed, so re-read
|
|
|
|
|
+ # where these messages are now instead of trusting stale handles.
|
|
|
|
|
+ pipeline.run_step(pps, cfg, step, folder, chunk, refresh=index > 0)
|
|
|
|
|
+ except PPSError as exc:
|
|
|
|
|
+ log.error("job #%d chunk failed: %s", job_id, exc)
|
|
|
|
|
+ errors.append(f"chunk failed: {exc}")
|
|
|
|
|
+ failed.add(i)
|
|
|
|
|
+ self._log_ops(job_id, action, step, folder, dst, chunk, user,
|
|
|
|
|
+ "FAILED", str(exc))
|
|
|
|
|
+ except Exception as exc: # noqa: BLE001
|
|
|
|
|
+ log.exception("job #%d chunk raised", job_id)
|
|
|
|
|
+ errors.append(f"chunk failed: {exc}")
|
|
|
|
|
+ failed.add(i)
|
|
|
|
|
+ self._log_ops(job_id, action, step, folder, dst, chunk, user,
|
|
|
|
|
+ "FAILED", str(exc))
|
|
|
|
|
+ else:
|
|
|
|
|
+ done += len(chunk)
|
|
|
|
|
+ self._set_processed(job_id, _progress(len(items), len(steps), index, done))
|
|
|
|
|
+ self._log_ops(job_id, action, step, folder, dst, chunk, user, "ok", None)
|
|
|
|
|
+
|
|
|
|
|
+ index += 1
|
|
|
|
|
+ folder = dst if step and dst else folder
|
|
|
|
|
+ if index < len(steps) and delay > 0:
|
|
|
|
|
+ self._defer(job_id, delay, {
|
|
|
|
|
+ "steps": steps, "delay": delay, "step_index": index,
|
|
|
|
|
+ "folder": folder, "errors": errors, "failed": sorted(failed),
|
|
|
|
|
+ })
|
|
|
|
|
+ log.info("job #%d waiting %ds before %r step — other jobs run meanwhile",
|
|
|
|
|
+ job_id, delay, steps[index])
|
|
|
|
|
+ return
|
|
|
|
|
+
|
|
|
|
|
+ processed = len(items) - sum(len(chunks[i]) for i in failed)
|
|
|
took = _fmt_duration(time.monotonic() - started)
|
|
took = _fmt_duration(time.monotonic() - started)
|
|
|
if errors:
|
|
if errors:
|
|
|
log.error("job #%d FAILED: %d/%d processed, %d chunk error(s), took %s",
|
|
log.error("job #%d FAILED: %d/%d processed, %d chunk error(s), took %s",
|
|
@@ -286,15 +373,35 @@ class JobQueue:
|
|
|
job_id, processed, len(items), took)
|
|
job_id, processed, len(items), took)
|
|
|
self._mark_done(job_id)
|
|
self._mark_done(job_id)
|
|
|
|
|
|
|
|
- def _log_ops(self, job_id: int, action: str, src: str, dst: str | None,
|
|
|
|
|
- chunk: list[dict], user: str | None,
|
|
|
|
|
|
|
+ def _defer(self, job_id: int, delay: int, state: dict) -> None:
|
|
|
|
|
+ """Park a partly-done job back on the queue, runnable again in `delay` seconds.
|
|
|
|
|
+
|
|
|
|
|
+ This is what keeps the step delay from blocking the queue: the job goes back to
|
|
|
|
|
+ 'pending' with a future `run_after`, `_claim_next` skips it until then, and every
|
|
|
|
|
+ other queued job gets its turn in the meantime.
|
|
|
|
|
+ """
|
|
|
|
|
+ with self._lock:
|
|
|
|
|
+ self._conn.execute(
|
|
|
|
|
+ "UPDATE jobs SET status='pending', run_after=?, state=?, updated_at=?"
|
|
|
|
|
+ " WHERE id=?",
|
|
|
|
|
+ (_plus_seconds(delay), json.dumps(state), _now(), job_id),
|
|
|
|
|
+ )
|
|
|
|
|
+ self._conn.commit()
|
|
|
|
|
+
|
|
|
|
|
+ def _log_ops(self, job_id: int, action: str, step: str | None, src: str,
|
|
|
|
|
+ dst: str | None, chunk: list[dict], user: str | None,
|
|
|
result: str, error: str | None) -> None:
|
|
result: str, error: str | None) -> None:
|
|
|
- """Write one audit line per message in the chunk to the operations log."""
|
|
|
|
|
|
|
+ """Write one audit line per message in the chunk to the operations log.
|
|
|
|
|
+
|
|
|
|
|
+ Multi-step Report & Release writes one line per message PER STEP, each naming the
|
|
|
|
|
+ step it reports on (`step=move`) and that step's own src/dst.
|
|
|
|
|
+ """
|
|
|
for it in chunk:
|
|
for it in chunk:
|
|
|
fields = [
|
|
fields = [
|
|
|
f"job=#{job_id}",
|
|
f"job=#{job_id}",
|
|
|
f"user={user or '-'}",
|
|
f"user={user or '-'}",
|
|
|
f"action={action}",
|
|
f"action={action}",
|
|
|
|
|
+ *([f"step={step}"] if step else []),
|
|
|
f"result={result}",
|
|
f"result={result}",
|
|
|
f"src={src!r}",
|
|
f"src={src!r}",
|
|
|
f"dst={dst!r}",
|
|
f"dst={dst!r}",
|
|
@@ -327,11 +434,9 @@ class JobQueue:
|
|
|
raise ValueError("move action requires targetfolder")
|
|
raise ValueError("move action requires targetfolder")
|
|
|
pps.act("move", folder, localguids, targetfolder=target)
|
|
pps.act("move", folder, localguids, targetfolder=target)
|
|
|
|
|
|
|
|
- elif action == "report_release":
|
|
|
|
|
- # Data-driven pipeline (release -> move -> delete, configurable subset).
|
|
|
|
|
- pipeline.run_pipeline(pps, cfg, folder, chunk)
|
|
|
|
|
-
|
|
|
|
|
else:
|
|
else:
|
|
|
|
|
+ # report_release never lands here: `_process` drives its steps one at a time
|
|
|
|
|
+ # so it can yield the worker thread during the between-step delay.
|
|
|
raise ValueError(f"unknown action: {action}")
|
|
raise ValueError(f"unknown action: {action}")
|
|
|
|
|
|
|
|
# -------------------------------------------------------------- db helpers
|
|
# -------------------------------------------------------------- db helpers
|
|
@@ -355,7 +460,8 @@ class JobQueue:
|
|
|
def _mark_done(self, job_id: int) -> None:
|
|
def _mark_done(self, job_id: int) -> None:
|
|
|
with self._lock:
|
|
with self._lock:
|
|
|
self._conn.execute(
|
|
self._conn.execute(
|
|
|
- "UPDATE jobs SET status='done', updated_at=? WHERE id=?",
|
|
|
|
|
|
|
+ "UPDATE jobs SET status='done', run_after=NULL, state='{}', updated_at=?"
|
|
|
|
|
+ " WHERE id=?",
|
|
|
(_now(), job_id),
|
|
(_now(), job_id),
|
|
|
)
|
|
)
|
|
|
self._conn.commit()
|
|
self._conn.commit()
|
|
@@ -363,7 +469,8 @@ class JobQueue:
|
|
|
def _mark_failed(self, job_id: int, error: str) -> None:
|
|
def _mark_failed(self, job_id: int, error: str) -> None:
|
|
|
with self._lock:
|
|
with self._lock:
|
|
|
self._conn.execute(
|
|
self._conn.execute(
|
|
|
- "UPDATE jobs SET status='failed', error=?, updated_at=? WHERE id=?",
|
|
|
|
|
|
|
+ "UPDATE jobs SET status='failed', error=?, run_after=NULL, state='{}',"
|
|
|
|
|
+ " updated_at=? WHERE id=?",
|
|
|
(error, _now(), job_id),
|
|
(error, _now(), job_id),
|
|
|
)
|
|
)
|
|
|
self._conn.commit()
|
|
self._conn.commit()
|