Add configurable retention for successful routine operations
This commit is contained in:
+69
-9
@@ -32,7 +32,7 @@ import urllib.parse
|
||||
import urllib.request
|
||||
import uuid
|
||||
|
||||
VERSION = "1.4.8"
|
||||
VERSION = "1.4.9"
|
||||
LABEL = "io.electric-cherry"
|
||||
MAX_FILE = 32 * 1024 * 1024
|
||||
MANIFEST_MAX_ENTRIES = 10000
|
||||
@@ -516,6 +516,19 @@ class ReadWriteGate:
|
||||
self.condition.notify_all()
|
||||
|
||||
|
||||
def read_operation(operation):
|
||||
if not isinstance(operation, dict):
|
||||
return False
|
||||
if operation.get("kind") in ("host.inspect", "instance.inspect", "files.read", "files.list", "files.stat", "files.manifest", "logs.read"):
|
||||
return True
|
||||
payload = operation.get("payload")
|
||||
return operation.get("kind") == "rcon.execute" and isinstance(payload, dict) and payload.get("command") in ("status", "getstatus", "version")
|
||||
|
||||
|
||||
def valid_observation_keep_days(value):
|
||||
return type(value) is int and 0 <= value <= 36500
|
||||
|
||||
|
||||
class Journal:
|
||||
def __init__(self, path, recover=True):
|
||||
self.db = sqlite3.connect(path)
|
||||
@@ -525,8 +538,14 @@ class Journal:
|
||||
self.db.execute("PRAGMA journal_mode=WAL")
|
||||
self.db.execute("PRAGMA synchronous=FULL")
|
||||
self.db.execute("CREATE TABLE IF NOT EXISTS operations (id TEXT PRIMARY KEY, fingerprint TEXT NOT NULL, request TEXT NOT NULL, state TEXT NOT NULL, result TEXT, error TEXT, updated REAL NOT NULL)")
|
||||
if "checkpoint" not in {row[1] for row in self.db.execute("PRAGMA table_info(operations)")}:
|
||||
columns = {row[1] for row in self.db.execute("PRAGMA table_info(operations)")}
|
||||
if "checkpoint" not in columns:
|
||||
self.db.execute("ALTER TABLE operations ADD COLUMN checkpoint TEXT")
|
||||
if "reported_at" not in columns:
|
||||
self.db.execute("ALTER TABLE operations ADD COLUMN reported_at REAL")
|
||||
if "retention_eligible" not in columns:
|
||||
self.db.execute("ALTER TABLE operations ADD COLUMN retention_eligible INTEGER NOT NULL DEFAULT 0")
|
||||
self.db.execute("CREATE INDEX IF NOT EXISTS operations_observation_retention ON operations(updated,id) WHERE state='completed' AND reported_at IS NOT NULL AND retention_eligible=1")
|
||||
self.db.execute("UPDATE operations SET state='unknown', error='Agent restarted during execution; inspect before reconciliation', updated=? WHERE state='running'", (time.time(),))
|
||||
self.db.commit()
|
||||
|
||||
@@ -551,10 +570,37 @@ class Journal:
|
||||
return dict(row)
|
||||
|
||||
def update(self, op_id, state, result=None, error=None):
|
||||
self.db.execute("UPDATE operations SET state=?, result=?, error=?, updated=? WHERE id=?", (state, json.dumps(result) if result is not None else None, error, time.time(), op_id))
|
||||
self.db.execute("UPDATE operations SET state=?, result=?, error=?, updated=?, reported_at=NULL, retention_eligible=0 WHERE id=?", (state, json.dumps(result) if result is not None else None, error, time.time(), op_id))
|
||||
self.db.commit()
|
||||
return self.get(op_id)
|
||||
|
||||
def confirm_completed(self, row):
|
||||
"""Only an acknowledged, unchanged completion can become disposable."""
|
||||
if row["state"] != "completed":
|
||||
return
|
||||
eligible = False
|
||||
try:
|
||||
result = json.loads(row["result"]) if row.get("result") is not None else None
|
||||
eligible = read_operation(json.loads(row["request"])) and not row.get("error") and not (
|
||||
isinstance(result, dict) and (result.get("ok") is False or result.get("healthy") is False or result.get("error") not in (None, ""))
|
||||
)
|
||||
except (ValueError, TypeError, KeyError):
|
||||
pass # Malformed historical records are retained for inspection.
|
||||
self.db.execute("""UPDATE operations SET reported_at=COALESCE(reported_at,?), retention_eligible=?
|
||||
WHERE id=? AND state='completed' AND updated=? AND result IS ? AND error IS ?""",
|
||||
(time.time(), int(bool(eligible)), row["id"], row["updated"], row.get("result"), row.get("error")))
|
||||
self.db.commit()
|
||||
|
||||
def prune_observations(self, keep_days):
|
||||
if not valid_observation_keep_days(keep_days) or keep_days == 0:
|
||||
return 0
|
||||
cutoff = time.time() - keep_days * 86400
|
||||
removed = self.db.execute("""DELETE FROM operations WHERE id IN (
|
||||
SELECT id FROM operations WHERE state='completed' AND reported_at IS NOT NULL AND retention_eligible=1
|
||||
AND updated<? ORDER BY updated,id LIMIT 500)""", (cutoff,)).rowcount
|
||||
self.db.commit()
|
||||
return removed
|
||||
|
||||
def close(self):
|
||||
self.db.close()
|
||||
|
||||
@@ -868,6 +914,7 @@ class Agent:
|
||||
self.read_claim_lock = threading.Lock()
|
||||
self.read_claims = set()
|
||||
self.cancelled_creations = frozenset()
|
||||
self.observation_keep_days = 0 # Older controllers do not authorize cleanup.
|
||||
self.library_progress = {}
|
||||
self.library_transfers = {}
|
||||
self.config_path = config.get("configPath", "/etc/electric-cherry/agent.json")
|
||||
@@ -2118,7 +2165,7 @@ class Agent:
|
||||
return self.journal.update(operation["id"], "failed", error="Interrupted library download could not be resumed")
|
||||
if kind == "files.stage":
|
||||
return self.journal.update(operation["id"], "completed", self.stage(instance_id, generation, payload, operation["id"]))
|
||||
if kind in ("host.inspect", "instance.inspect", "files.read", "files.list", "files.stat", "files.manifest", "logs.read") or kind == "rcon.execute" and payload.get("command") in ("status", "getstatus", "version"):
|
||||
if self.read_operation(operation):
|
||||
return self.journal.update(operation["id"], "completed", self.dispatch(operation))
|
||||
if kind in ("files.activate", "files.rollback") and checkpoint:
|
||||
stage = self.instance_dir(instance_id, generation) / "stages" / identifier(payload["stageId"]) / "manifest.json"
|
||||
@@ -2172,7 +2219,7 @@ class Agent:
|
||||
pass
|
||||
return row
|
||||
|
||||
def report(self, row):
|
||||
def report(self, row, journal=None):
|
||||
payload = {"state": row["state"]}
|
||||
if row.get("result"):
|
||||
payload["result"] = json.loads(row["result"])
|
||||
@@ -2182,13 +2229,19 @@ class Agent:
|
||||
payload["state"] = "running"
|
||||
if row.get("error"):
|
||||
payload["error"] = row["error"]
|
||||
return self.request("POST", "/api/agent/operations/" + urllib.parse.quote(row["id"], safe=""), payload)
|
||||
response = self.request("POST", "/api/agent/operations/" + urllib.parse.quote(row["id"], safe=""), payload)
|
||||
confirmed = response.get("operation") if isinstance(response, dict) else None
|
||||
if row["state"] == "completed" and isinstance(confirmed, dict) and confirmed.get("id") == row["id"] and confirmed.get("state") == "completed":
|
||||
(journal if journal is not None else self.journal).confirm_completed(row)
|
||||
return response
|
||||
|
||||
def heartbeat(self):
|
||||
response = self.request("POST", "/api/agent/heartbeat", {"inventory": self.inventory(), "operationId": self.current_operation})
|
||||
# Only the heartbeat thread replaces this immutable snapshot; it never
|
||||
# mutates the operation journal or races Docker cleanup against create.
|
||||
self.cancelled_creations = frozenset(value for value in response.get("cancelledCreations", []) if isinstance(value, str))
|
||||
keep_days = response.get("observationKeepDays")
|
||||
self.observation_keep_days = keep_days if valid_observation_keep_days(keep_days) else 0
|
||||
host = response.get("host", {})
|
||||
if isinstance(host.get("portMin"), int) and isinstance(host.get("portMax"), int):
|
||||
self.config["portRange"] = {"min": host["portMin"], "max": host["portMax"]}
|
||||
@@ -2205,7 +2258,7 @@ class Agent:
|
||||
|
||||
@staticmethod
|
||||
def read_operation(operation):
|
||||
return operation.get("kind") in ("host.inspect", "instance.inspect", "files.read", "files.list", "files.stat", "files.manifest", "logs.read") or (operation.get("kind") == "rcon.execute" and operation.get("payload", {}).get("command") in ("status", "getstatus", "version"))
|
||||
return read_operation(operation)
|
||||
|
||||
def instance_lock(self, operation):
|
||||
key = operation.get("instanceId")
|
||||
@@ -2219,12 +2272,19 @@ class Agent:
|
||||
# Each lane owns its SQLite connection and never writes executing_id,
|
||||
# checkpoints, or current_operation used by the mutation state machine.
|
||||
journal = Journal(self.root / "agent" / "operations.sqlite3", recover=False)
|
||||
next_prune = time.monotonic()
|
||||
try:
|
||||
while not self.stopping.is_set():
|
||||
try:
|
||||
if self.update_pending():
|
||||
self.stopping.wait(3)
|
||||
continue
|
||||
if lane == "read" and time.monotonic() >= next_prune:
|
||||
next_prune = time.monotonic() + 60
|
||||
with self.activity(read_only=True) as acquired:
|
||||
if acquired and not self.update_pending():
|
||||
if journal.prune_observations(self.observation_keep_days) == 500:
|
||||
next_prune = time.monotonic() + 15
|
||||
response = self.request("GET", f"/api/agent/operations?lane={lane}&wait=20")
|
||||
handled = False
|
||||
for operation in response.get("operations", []):
|
||||
@@ -2242,7 +2302,7 @@ class Agent:
|
||||
continue
|
||||
row, _ = journal.accept(operation)
|
||||
if row["state"] in ("accepted", "unknown", "running"):
|
||||
self.report(journal.update(operation["id"], "running"))
|
||||
self.report(journal.update(operation["id"], "running"), journal=journal)
|
||||
with self.read_gate.read(), self.instance_lock(operation):
|
||||
try:
|
||||
result = self.dispatch(operation)
|
||||
@@ -2251,7 +2311,7 @@ class Agent:
|
||||
row = journal.update(operation["id"], "failed", error=str(err) if isinstance(err, AgentError) else "Observation unavailable")
|
||||
# Receipt delivery can take seconds; it must not
|
||||
# hold the instance lock needed by health checks.
|
||||
self.report(row)
|
||||
self.report(row, journal=journal)
|
||||
handled = True
|
||||
finally:
|
||||
with self.read_claim_lock:
|
||||
|
||||
@@ -57,6 +57,115 @@ class Response(io.BytesIO):
|
||||
self.headers = headers or {}
|
||||
|
||||
|
||||
class JournalRetentionTests(unittest.TestCase):
|
||||
def setUp(self):
|
||||
self.temp = tempfile.TemporaryDirectory()
|
||||
self.path = Path(self.temp.name) / "operations.sqlite3"
|
||||
self.journal = Journal(self.path)
|
||||
self.now = 2000000
|
||||
self.sequence = 0
|
||||
|
||||
def tearDown(self):
|
||||
self.journal.close()
|
||||
self.temp.cleanup()
|
||||
|
||||
def record(self, kind="files.stat", payload=None, result=None, state="completed", error=None, at=None, confirmed=True):
|
||||
self.sequence += 1
|
||||
operation = {"id": f"operation-{self.sequence}", "kind": kind, "payload": payload or {}}
|
||||
self.journal.accept(operation)
|
||||
with patch.object(module.time, "time", return_value=self.now - 172800 if at is None else at):
|
||||
row = self.journal.update(operation["id"], state, result, error)
|
||||
if confirmed:
|
||||
self.journal.confirm_completed(row)
|
||||
return row
|
||||
|
||||
def prune(self, days=1):
|
||||
with patch.object(module.time, "time", return_value=self.now):
|
||||
return self.journal.prune_observations(days)
|
||||
|
||||
def test_cutoff_requires_an_older_confirmed_success(self):
|
||||
old = self.record(at=self.now - 86401)
|
||||
boundary = self.record(at=self.now - 86400)
|
||||
recent = self.record(at=self.now - 10)
|
||||
unconfirmed = self.record(confirmed=False)
|
||||
self.assertEqual(self.prune(), 1)
|
||||
with self.assertRaisesRegex(AgentError, "Unknown operation"):
|
||||
self.journal.get(old["id"])
|
||||
for row in (boundary, recent, unconfirmed):
|
||||
self.assertEqual(self.journal.get(row["id"])["state"], "completed")
|
||||
|
||||
def test_zero_and_invalid_retention_preserve_every_record(self):
|
||||
row = self.record()
|
||||
for days in (0, -1, 36501, True, False, None, "1", 1.0, 1.5):
|
||||
with self.subTest(days=days):
|
||||
self.assertEqual(self.prune(days), 0)
|
||||
self.assertEqual(self.journal.get(row["id"])["state"], "completed")
|
||||
|
||||
def test_all_read_kinds_are_eligible_but_mutations_keep_their_replay_journal(self):
|
||||
for kind in ("host.inspect", "instance.inspect", "files.read", "files.list", "files.stat", "files.manifest", "logs.read"):
|
||||
self.record(kind, result={"healthy": True})
|
||||
for command in ("status", "getstatus", "version"):
|
||||
self.record("rcon.execute", {"command": command}, {"ok": True})
|
||||
mutations = [self.record(kind) for kind in ("instance.restart", "instance.stop", "instance.create", "files.stage", "files.activate", "credentials.rotate")]
|
||||
mutations.append(self.record("rcon.execute", {"command": "map_restart"}, {"ok": True}))
|
||||
self.assertEqual(self.prune(), 10)
|
||||
for row in mutations:
|
||||
saved, accepted = self.journal.accept(json.loads(row["request"]))
|
||||
self.assertFalse(accepted)
|
||||
self.assertEqual(saved["id"], row["id"])
|
||||
|
||||
def test_errors_failures_and_unfinished_operations_are_retained(self):
|
||||
retained = [self.record(result=result) for result in ({"ok": False}, {"healthy": False}, {"error": "partial result"}, {"error": False}, {"error": []})]
|
||||
retained.append(self.record(error="read did not finish"))
|
||||
retained.extend(self.record(state=state) for state in ("accepted", "running", "unknown", "failed"))
|
||||
self.assertEqual(self.prune(), 0)
|
||||
for row in retained:
|
||||
self.assertEqual(self.journal.get(row["id"])["state"], row["state"])
|
||||
|
||||
def test_old_receipt_cannot_confirm_a_changed_or_reexecuted_result(self):
|
||||
old = self.record(confirmed=False)
|
||||
with patch.object(module.time, "time", return_value=self.now - 90000):
|
||||
current = self.journal.update(old["id"], "completed", {"new": "result"})
|
||||
self.journal.confirm_completed(old)
|
||||
self.assertIsNone(self.journal.get(old["id"])["reported_at"])
|
||||
self.assertEqual(self.prune(), 0)
|
||||
self.journal.confirm_completed(current)
|
||||
self.assertEqual(self.prune(), 1)
|
||||
|
||||
def test_pruning_uses_bounded_indexed_batches(self):
|
||||
template = self.record()
|
||||
self.journal.db.executemany("""INSERT INTO operations(id,fingerprint,request,state,result,updated,reported_at,retention_eligible)
|
||||
VALUES(?,?,?,'completed',NULL,?,?,1)""", [
|
||||
(f"batch-{index}", template["fingerprint"], template["request"], self.now - 172800, self.now - 172800)
|
||||
for index in range(504)
|
||||
])
|
||||
self.journal.db.commit()
|
||||
self.assertEqual(self.prune(), 500)
|
||||
self.assertEqual(self.journal.db.execute("SELECT COUNT(*) FROM operations").fetchone()[0], 5)
|
||||
self.assertEqual(self.prune(), 5)
|
||||
plan = self.journal.db.execute("""EXPLAIN QUERY PLAN SELECT id FROM operations
|
||||
WHERE state='completed' AND reported_at IS NOT NULL AND retention_eligible=1 AND updated<? ORDER BY updated,id LIMIT 500""", (self.now,)).fetchall()
|
||||
self.assertIn("operations_observation_retention", " ".join(str(tuple(row)) for row in plan))
|
||||
|
||||
def test_migration_keeps_legacy_completions_until_their_receipt_is_reacknowledged(self):
|
||||
self.journal.close()
|
||||
self.path.unlink()
|
||||
legacy = module.sqlite3.connect(self.path)
|
||||
legacy.execute("CREATE TABLE operations(id TEXT PRIMARY KEY, fingerprint TEXT NOT NULL, request TEXT NOT NULL, state TEXT NOT NULL, result TEXT, error TEXT, updated REAL NOT NULL)")
|
||||
request = {"id": "legacy-read", "kind": "files.list", "instanceId": None, "generation": None, "payload": {}}
|
||||
canonical = json.dumps(request, sort_keys=True, separators=(",", ":"))
|
||||
legacy.execute("INSERT INTO operations VALUES(?,?,?,'completed',?,NULL,?)", (request["id"], module.digest(canonical.encode()), canonical, '{"entries":[]}', self.now - 172800))
|
||||
legacy.commit()
|
||||
legacy.close()
|
||||
self.journal = Journal(self.path)
|
||||
row, accepted = self.journal.accept(request)
|
||||
self.assertFalse(accepted)
|
||||
self.assertIsNone(row["reported_at"])
|
||||
self.assertEqual(self.prune(), 0)
|
||||
self.journal.confirm_completed(row)
|
||||
self.assertEqual(self.prune(), 1)
|
||||
|
||||
|
||||
class ManifestTests(unittest.TestCase):
|
||||
def setUp(self):
|
||||
self.temp = tempfile.TemporaryDirectory()
|
||||
@@ -1418,6 +1527,85 @@ class AgentTests(unittest.TestCase):
|
||||
self.agent.heartbeat()
|
||||
self.assertEqual(self.agent.config["portRange"], {"min": 30000, "max": 30100})
|
||||
|
||||
def test_heartbeat_requires_valid_retention_and_never_changes_the_journal(self):
|
||||
self.assertEqual(self.agent.observation_keep_days, 0)
|
||||
with patch.object(self.agent.journal, "prune_observations", side_effect=AssertionError("heartbeat must not use the journal")), patch.object(self.agent.journal, "confirm_completed", side_effect=AssertionError("heartbeat must not use the journal")):
|
||||
for value, expected in ((1, 1), (36500, 36500), (0, 0), (True, 0), (False, 0), (1.0, 0), ("1", 0), (-1, 0), (36501, 0), (None, 0)):
|
||||
with self.subTest(value=value):
|
||||
self.agent.observation_keep_days = 3
|
||||
self.agent.request = lambda *_, value=value: {"observationKeepDays": value}
|
||||
self.agent.heartbeat()
|
||||
self.assertEqual(self.agent.observation_keep_days, expected)
|
||||
self.agent.observation_keep_days = 3
|
||||
self.agent.request = lambda *_: {}
|
||||
self.agent.heartbeat()
|
||||
self.assertEqual(self.agent.observation_keep_days, 0)
|
||||
|
||||
def test_lost_completed_receipt_is_retained_and_replay_reports_the_saved_result(self):
|
||||
operation = self.operation("files.stat", {"path": "configs/server.cfg"})
|
||||
self.agent.journal.accept(operation)
|
||||
with patch.object(module.time, "time", return_value=module.time.time() - 172800):
|
||||
row = self.agent.journal.update(operation["id"], "completed", {"size": 8})
|
||||
self.agent.request = MagicMock(side_effect=AgentError("receipt lost"))
|
||||
with self.assertRaisesRegex(AgentError, "receipt lost"):
|
||||
self.agent.report(row)
|
||||
self.assertIsNone(self.agent.journal.get(operation["id"])["reported_at"])
|
||||
self.assertEqual(self.agent.journal.prune_observations(1), 0)
|
||||
with patch.object(self.agent, "dispatch", side_effect=AssertionError("completed read must not be executed again")):
|
||||
replay = self.agent.execute(operation)
|
||||
self.assertEqual(replay["result"], row["result"])
|
||||
for response in ({}, None, {"operation": {"id": "different", "state": "completed"}}, {"operation": {"id": operation["id"], "state": "running"}}):
|
||||
self.agent.request = lambda *_, response=response: response
|
||||
self.agent.report(replay)
|
||||
self.assertIsNone(self.agent.journal.get(operation["id"])["reported_at"])
|
||||
self.agent.request = lambda *_: {"operation": {"id": operation["id"], "state": "completed"}}
|
||||
self.agent.report(replay)
|
||||
self.assertIsNotNone(self.agent.journal.get(operation["id"])["reported_at"])
|
||||
self.assertEqual(self.agent.journal.prune_observations(1), 1)
|
||||
|
||||
def test_threaded_read_lane_confirms_and_prunes_through_its_own_connection(self):
|
||||
self.create()
|
||||
old_operation = self.operation("files.list", op_id="old-observation")
|
||||
self.agent.journal.accept(old_operation)
|
||||
with patch.object(module.time, "time", return_value=module.time.time() - 172800):
|
||||
old = self.agent.journal.update(old_operation["id"], "completed", {"entries": []})
|
||||
self.agent.journal.confirm_completed(old)
|
||||
self.agent.observation_keep_days = 1
|
||||
operation = self.operation("files.stat", {"path": "configs/server.cfg"}, "thread-observation")
|
||||
polls = 0
|
||||
failures = []
|
||||
|
||||
def request(method, path, payload=None):
|
||||
nonlocal polls
|
||||
if method == "POST":
|
||||
return {"operation": {"id": operation["id"], "state": payload["state"]}}
|
||||
polls += 1
|
||||
if polls == 1:
|
||||
return {"operations": [operation]}
|
||||
self.agent.stopping.set()
|
||||
return {"operations": []}
|
||||
|
||||
def run():
|
||||
try:
|
||||
self.agent.read_loop()
|
||||
except BaseException as error:
|
||||
failures.append(error)
|
||||
|
||||
self.agent.request = request
|
||||
with patch.object(self.agent.journal, "confirm_completed", side_effect=AssertionError("main journal used by reader")), patch.object(self.agent.journal, "prune_observations", side_effect=AssertionError("main journal used by reader")):
|
||||
thread = threading.Thread(target=run)
|
||||
thread.start()
|
||||
thread.join(timeout=5)
|
||||
self.agent.stopping.set()
|
||||
thread.join(timeout=5)
|
||||
self.assertFalse(thread.is_alive())
|
||||
self.assertEqual(failures, [])
|
||||
self.assertEqual(polls, 2)
|
||||
self.assertIsNotNone(self.agent.journal.get(operation["id"])["reported_at"])
|
||||
with self.assertRaisesRegex(AgentError, "Unknown operation"):
|
||||
self.agent.journal.get(old_operation["id"])
|
||||
self.assertEqual(self.agent.journal.get("create")["state"], "completed")
|
||||
|
||||
def test_download_content_permissions_allow_container_read_access_with_private_umask(self):
|
||||
content = b"complete-game-file"
|
||||
manifest = self.manifest(content)
|
||||
|
||||
Reference in New Issue
Block a user