diff --git a/cron/jobs.py b/cron/jobs.py index 5a21f6d52461..356385cdce78 100644 --- a/cron/jobs.py +++ b/cron/jobs.py @@ -475,6 +475,44 @@ def _secure_file(path: Path): pass +def _preserve_file_ownership(path: Path, before: Optional[os.stat_result]) -> None: + """Restore a rewritten file's previous owner (POSIX, privileged writer only). + + The atomic-write pattern (mkstemp + replace) makes the rewritten file owned + by the *writer's* euid. When a root shell runs a state-writing cron CLI + command (``docker exec hermes hermes cron create ...`` — ``docker exec`` + defaults to root) against a store owned by the unprivileged gateway user, + the replace flips ``jobs.json`` to ``root:root`` mode 600 and the gateway's + ticker (uid 1000) is silently locked out of every subsequent tick (#68483). + + Root can always hand ownership back, so do exactly that: when the euid is 0 + and the pre-replace owner differs, chown the new file to the previous + uid/gid. Unprivileged writers are a no-op (their own rewrite already heals + a root-owned file back to their uid, and they couldn't chown anyway). + No-op on Windows. Best-effort: a failure must never break the save. + """ + if before is None or os.name != "posix": + return + geteuid = getattr(os, "geteuid", None) + getegid = getattr(os, "getegid", None) + if geteuid is None or getegid is None: + return + try: + euid = geteuid() + if euid != 0: + return # unprivileged writer — nothing to (or we could) restore + if (before.st_uid, before.st_gid) == (euid, getegid()): + return # already ours before the rewrite — nothing changed + os.chown(path, before.st_uid, before.st_gid) + except OSError as e: + logger.warning( + "Could not restore ownership of %s to uid=%s gid=%s after rewrite: %s " + "— if the gateway runs as a different user, its cron ticker may now " + "be locked out (see issue #68483).", + path, before.st_uid, before.st_gid, e, + ) + + def ensure_dirs(): """Ensure cron directories exist with secure permissions.""" store = _current_cron_store() @@ -867,6 +905,64 @@ def get_ticker_success_age() -> Optional[float]: return _epoch_file_age(store.cron_dir / "ticker_last_success") +def record_ticker_error(message: str) -> None: + """Persist the most recent tick failure so other processes can surface it. + + The ticker thread lives inside the gateway process; ``hermes cron + status``/``list`` run in a separate process and previously could only + infer "ticks may be failing" from marker staleness, with no clue WHY. + A root-owned ``jobs.json`` (#68483) failed every tick for ~14h with the + reason visible only in the gateway's errors.log. Writing the last error + next to the heartbeat markers gives the CLI something concrete to show. + + Best-effort: a write failure must never disrupt the tick loop. + """ + store = _current_cron_store() + path = store.cron_dir / "ticker_last_error" + try: + ensure_dirs() + fd, tmp_path = tempfile.mkstemp( + dir=str(path.parent), suffix=".tmp", prefix=".terr_" + ) + try: + with os.fdopen(fd, "w", encoding="utf-8") as f: + f.write(f"{time.time()}\n{message.strip()}\n") + f.flush() + os.fsync(f.fileno()) + atomic_replace(tmp_path, path) + except BaseException: + try: + os.unlink(tmp_path) + except OSError: + pass + raise + except Exception: + pass + + +def clear_ticker_error() -> None: + """Remove the last-tick-error marker after a successful tick. Best-effort.""" + store = _current_cron_store() + try: + (store.cron_dir / "ticker_last_error").unlink() + except OSError: + pass + + +def get_ticker_last_error() -> Optional[str]: + """Return the most recent recorded tick error message, or None.""" + store = _current_cron_store() + try: + raw = (store.cron_dir / "ticker_last_error").read_text(encoding="utf-8") + except Exception: + return None + lines = raw.splitlines() + if len(lines) < 2: + return None + message = "\n".join(lines[1:]).strip() + return message or None + + # ============================================================================= # Job CRUD Operations # ============================================================================= @@ -927,6 +1023,19 @@ def _save_jobs_unlocked(jobs: List[Dict[str, Any]]): """Save all jobs to storage. Caller must hold _jobs_lock().""" jobs_file = _current_cron_store().jobs_file ensure_dirs() + # Snapshot the current owner BEFORE the atomic replace so a privileged + # writer (root CLI in Docker) can hand ownership back to the gateway user + # afterwards instead of locking its ticker out (#68483). When the file is + # being created for the first time, inherit the cron dir's owner — in the + # Docker image that is the PUID/PGID gateway user who must be able to + # read the store on the next tick. + try: + _stat_before = os.stat(jobs_file) + except OSError: + try: + _stat_before = os.stat(jobs_file.parent) + except OSError: + _stat_before = None fd, tmp_path = tempfile.mkstemp(dir=str(jobs_file.parent), suffix='.tmp', prefix='.jobs_') try: with os.fdopen(fd, 'w', encoding='utf-8') as f: @@ -935,6 +1044,7 @@ def _save_jobs_unlocked(jobs: List[Dict[str, Any]]): os.fsync(f.fileno()) atomic_replace(tmp_path, jobs_file) _secure_file(jobs_file) + _preserve_file_ownership(jobs_file, _stat_before) except BaseException: try: os.unlink(tmp_path) diff --git a/cron/scheduler_provider.py b/cron/scheduler_provider.py index 13e8f0084e07..4c20db01c6d4 100644 --- a/cron/scheduler_provider.py +++ b/cron/scheduler_provider.py @@ -185,7 +185,11 @@ class InProcessCronScheduler(CronScheduler): ): import logging from cron.scheduler import tick as cron_tick - from cron.jobs import record_ticker_heartbeat + from cron.jobs import ( + clear_ticker_error, + record_ticker_error, + record_ticker_heartbeat, + ) logger = logging.getLogger("cron.scheduler_provider") logger.info("In-process cron scheduler started (interval=%ds)", interval) @@ -241,10 +245,19 @@ class InProcessCronScheduler(CronScheduler): # an exception in this daemon thread, so swallowing it and # re-checking stop_event keeps shutdown clean. logger.error("Cron tick error: %s", e, exc_info=True) + # Persist the failure reason next to the heartbeat markers so + # `hermes cron status`/`list` (separate processes) can show + # WHY ticks fail, not just that the success marker is stale — + # e.g. a root-rewritten jobs.json locking out the ticker's + # uid went unnoticed for ~14h with the reason buried in the + # gateway log (#68483). + record_ticker_error(f"{type(e).__name__}: {e}") # Record liveness every iteration; bump the success marker only on a # clean tick, so status can tell "alive but failing every tick" from # "actually firing jobs" (#32612, #32895). record_ticker_heartbeat(success=ok) + if ok: + clear_ticker_error() stop_event.wait(interval) def _start_multiplex( @@ -267,7 +280,12 @@ class InProcessCronScheduler(CronScheduler): """ import logging from cron.scheduler import tick as cron_tick - from cron.jobs import record_ticker_heartbeat, use_cron_store + from cron.jobs import ( + clear_ticker_error, + record_ticker_error, + record_ticker_heartbeat, + use_cron_store, + ) from hermes_constants import set_hermes_home_override, reset_hermes_home_override logger = logging.getLogger("cron.scheduler_provider") @@ -317,6 +335,9 @@ class InProcessCronScheduler(CronScheduler): ok = True except BaseException as e: logger.error("Cron tick error: %s", e, exc_info=True) + _tick_error = f"{type(e).__name__}: {e}" + else: + _tick_error = None # Record per-profile heartbeat after each tick cycle. for entry in profile_homes: home = entry[1] if isinstance(entry, tuple) else entry @@ -324,6 +345,13 @@ class InProcessCronScheduler(CronScheduler): try: with use_cron_store(home): record_ticker_heartbeat(success=ok) + # Surface the failure reason (or clear it) per profile + # so `hermes cron status` can show WHY ticks fail + # (#68483). + if ok: + clear_ticker_error() + elif _tick_error: + record_ticker_error(_tick_error) finally: reset_hermes_home_override(home_token) stop_event.wait(interval) diff --git a/hermes_cli/cron.py b/hermes_cli/cron.py index bf8a02fe099e..9c1fde724be5 100644 --- a/hermes_cli/cron.py +++ b/hermes_cli/cron.py @@ -254,6 +254,7 @@ def cron_status(): # (#32612, #32895). from cron.jobs import ( get_ticker_heartbeat_age, + get_ticker_last_error, get_ticker_success_age, TICKER_INTERVAL_SECONDS, ) @@ -283,6 +284,20 @@ def cron_status(): Colors.YELLOW, )) print(f" PID: {', '.join(map(str, pids))}") + last_error = get_ticker_last_error() + if last_error: + # Show WHY ticks fail — e.g. a root-rewritten jobs.json + # (PermissionError) that silently locked out the ticker's + # uid for ~14h in the field (#68483). + print(color(f" Last tick error: {last_error}", Colors.RED)) + if "Permission denied" in last_error: + print(color( + " Hint: jobs.json may be owned by another user " + "(e.g. rewritten by a root `docker exec hermes " + "hermes cron ...`). Fix ownership to match the " + "gateway user, and prefer `docker exec -u :`.", + Colors.YELLOW, + )) print(" Check the gateway log for 'Cron tick error'.") else: print(color("✓ Gateway is running — cron jobs will fire automatically", Colors.GREEN)) diff --git a/tests/cron/test_jobs_file_ownership.py b/tests/cron/test_jobs_file_ownership.py new file mode 100644 index 000000000000..b0e30fab9305 --- /dev/null +++ b/tests/cron/test_jobs_file_ownership.py @@ -0,0 +1,303 @@ +"""Regression tests for issue #68483. + +Running a state-writing ``hermes cron`` CLI command as root (the default for +``docker exec``) rewrote ``jobs.json`` as ``root:root`` mode 600 via the +mkstemp + atomic_replace pattern, silently locking out the unprivileged +gateway ticker — which then failed every tick with PermissionError while the +liveness heartbeat stayed fresh, so nothing surfaced the outage. + +Two behavior contracts are pinned here: + +1. Ownership preservation: a privileged (euid 0) writer must hand ownership + of the rewritten ``jobs.json`` back to its previous owner; unprivileged + writers must not attempt a chown at all. +2. Zombie-ticker surfacing: a failing tick must persist the failure reason + (``ticker_last_error``) where ``hermes cron status`` can show it, and a + subsequent clean tick must clear it. +""" + +import os +import sys +import threading + +import pytest + +import cron.jobs as jobs + + +pytestmark = pytest.mark.skipif( + sys.platform == "win32", reason="POSIX-only: uid/gid ownership semantics" +) + + +@pytest.fixture() +def cron_store(tmp_path, monkeypatch): + """Route the cron store to an isolated temp dir.""" + cron_dir = tmp_path / "cron" + monkeypatch.setattr(jobs, "CRON_DIR", cron_dir) + monkeypatch.setattr(jobs, "JOBS_FILE", cron_dir / "jobs.json") + monkeypatch.setattr(jobs, "OUTPUT_DIR", cron_dir / "output") + return cron_dir + + +# ========================================================================= +# 1. Ownership preservation on save (root writer) +# ========================================================================= + + +class TestSaveJobsOwnershipPreservation: + def test_root_writer_restores_previous_owner(self, cron_store, monkeypatch): + """When euid==0 and jobs.json was owned by another uid/gid, the + rewrite must chown the new file back to that owner.""" + jobs.save_jobs([{"id": "seed", "prompt": "hello"}]) + jobs_file = cron_store / "jobs.json" + assert jobs_file.exists() + + chown_calls = [] + + # Pretend the existing file is owned by the gateway user (uid 1000) + # and that WE are root. + real_stat = os.stat + + class _FakeStat: + def __init__(self, wrapped): + self._wrapped = wrapped + self.st_uid = 1000 + self.st_gid = 1000 + + def __getattr__(self, name): + return getattr(self._wrapped, name) + + def fake_stat(path, *a, **k): + result = real_stat(path, *a, **k) + if str(path) == str(jobs_file): + return _FakeStat(result) + return result + + monkeypatch.setattr(jobs.os, "stat", fake_stat) + monkeypatch.setattr(jobs.os, "geteuid", lambda: 0) + monkeypatch.setattr(jobs.os, "getegid", lambda: 0) + monkeypatch.setattr( + jobs.os, "chown", lambda path, uid, gid: chown_calls.append((str(path), uid, gid)) + ) + + jobs.save_jobs([{"id": "seed", "prompt": "updated"}]) + + assert chown_calls == [(str(jobs_file), 1000, 1000)], ( + "root rewrite must hand jobs.json back to the previous owner " + "(uid/gid 1000) instead of leaving it root:600 (#68483)" + ) + + def test_root_first_write_inherits_cron_dir_owner(self, cron_store, monkeypatch): + """Creating jobs.json for the first time as root must inherit the + cron dir's owner (the gateway user in the Docker image).""" + chown_calls = [] + jobs_file = cron_store / "jobs.json" + + real_stat = os.stat + + class _FakeStat: + def __init__(self, wrapped): + self._wrapped = wrapped + self.st_uid = 1000 + self.st_gid = 1000 + + def __getattr__(self, name): + return getattr(self._wrapped, name) + + def fake_stat(path, *a, **k): + result = real_stat(path, *a, **k) + if str(path) == str(cron_store): + return _FakeStat(result) + return result + + monkeypatch.setattr(jobs.os, "stat", fake_stat) + monkeypatch.setattr(jobs.os, "geteuid", lambda: 0) + monkeypatch.setattr(jobs.os, "getegid", lambda: 0) + monkeypatch.setattr( + jobs.os, "chown", lambda path, uid, gid: chown_calls.append((str(path), uid, gid)) + ) + + assert not jobs_file.exists() + jobs.save_jobs([{"id": "new", "prompt": "hello"}]) + + assert chown_calls == [(str(jobs_file), 1000, 1000)] + + def test_unprivileged_writer_never_chowns(self, cron_store, monkeypatch): + """A same-uid (non-root) writer must not attempt chown at all — + it would raise EPERM for foreign-owned files anyway.""" + jobs.save_jobs([{"id": "seed", "prompt": "hello"}]) + + def _fail_chown(*a, **k): + raise AssertionError("unprivileged save must not call os.chown") + + monkeypatch.setattr(jobs.os, "chown", _fail_chown) + jobs.save_jobs([{"id": "seed", "prompt": "updated"}]) # must not raise + + def test_chown_failure_never_breaks_save(self, cron_store, monkeypatch): + """A chown failure is logged, but the save itself must succeed.""" + jobs.save_jobs([{"id": "seed", "prompt": "hello"}]) + jobs_file = cron_store / "jobs.json" + + real_stat = os.stat + + class _FakeStat: + def __init__(self, wrapped): + self._wrapped = wrapped + self.st_uid = 1000 + self.st_gid = 1000 + + def __getattr__(self, name): + return getattr(self._wrapped, name) + + def fake_stat(path, *a, **k): + result = real_stat(path, *a, **k) + if str(path) == str(jobs_file): + return _FakeStat(result) + return result + + def _broken_chown(*a, **k): + raise PermissionError("simulated chown failure") + + monkeypatch.setattr(jobs.os, "stat", fake_stat) + monkeypatch.setattr(jobs.os, "geteuid", lambda: 0) + monkeypatch.setattr(jobs.os, "getegid", lambda: 0) + monkeypatch.setattr(jobs.os, "chown", _broken_chown) + + jobs.save_jobs([{"id": "seed", "prompt": "updated"}]) # must not raise + assert jobs.load_jobs()[0]["prompt"] == "updated" + + def test_save_still_enforces_0600(self, cron_store): + """The ownership fix must not regress the 0600 hardening.""" + import stat + + jobs.save_jobs([{"id": "seed", "prompt": "hello"}]) + mode = stat.S_IMODE(os.stat(cron_store / "jobs.json").st_mode) + assert mode == 0o600 + + +# ========================================================================= +# 2. Zombie-ticker surfacing (ticker_last_error marker) +# ========================================================================= + + +class TestTickerErrorMarker: + def test_record_and_get_roundtrip(self, cron_store): + assert jobs.get_ticker_last_error() is None + jobs.record_ticker_error( + "RuntimeError: Failed to read cron database: " + "[Errno 13] Permission denied: '/opt/data/cron/jobs.json'" + ) + msg = jobs.get_ticker_last_error() + assert msg is not None + assert "Permission denied" in msg + + def test_clear_removes_marker(self, cron_store): + jobs.record_ticker_error("RuntimeError: boom") + assert jobs.get_ticker_last_error() is not None + jobs.clear_ticker_error() + assert jobs.get_ticker_last_error() is None + + def test_clear_when_absent_is_noop(self, cron_store): + jobs.clear_ticker_error() # must not raise + assert jobs.get_ticker_last_error() is None + + def test_record_failure_is_silent(self, tmp_path, monkeypatch): + """Marker write failure must never disrupt the tick loop.""" + blocker = tmp_path / "not_a_dir" + blocker.write_text("i am a file") + bad_dir = blocker / "cron" + monkeypatch.setattr(jobs, "CRON_DIR", bad_dir) + monkeypatch.setattr(jobs, "JOBS_FILE", bad_dir / "jobs.json") + monkeypatch.setattr(jobs, "OUTPUT_DIR", bad_dir / "output") + + jobs.record_ticker_error("RuntimeError: boom") # must not raise + assert jobs.get_ticker_last_error() is None + + +class TestTickerLoopRecordsErrors: + def _run_one_tick(self, monkeypatch, tick_fn): + """Run one iteration of the built-in ticker loop with a stubbed tick.""" + from cron.scheduler_provider import InProcessCronScheduler + + provider = InProcessCronScheduler() + monkeypatch.setattr(provider, "recover_interrupted", lambda: 0) + monkeypatch.setattr("cron.scheduler.tick", tick_fn) + + stop_event = threading.Event() + original_wait = stop_event.wait + + def _stop_after_first_tick(timeout=None): + stop_event.set() + return original_wait(0) + + stop_event.wait = _stop_after_first_tick + provider.start(stop_event) + + def test_failing_tick_persists_error(self, cron_store, monkeypatch): + def _boom(**kwargs): + raise RuntimeError( + "Failed to read cron database: [Errno 13] Permission denied" + ) + + self._run_one_tick(monkeypatch, _boom) + + msg = jobs.get_ticker_last_error() + assert msg is not None, ( + "a failing tick must persist its reason for `hermes cron status` " + "to surface (#68483)" + ) + assert "Permission denied" in msg + + def test_successful_tick_clears_error(self, cron_store, monkeypatch): + jobs.record_ticker_error("RuntimeError: stale failure") + + self._run_one_tick(monkeypatch, lambda **kwargs: None) + + assert jobs.get_ticker_last_error() is None, ( + "a clean tick must clear the stale error marker" + ) + + +# ========================================================================= +# 3. `hermes cron status` surfaces the failure reason +# ========================================================================= + + +class TestCronStatusSurfacesError: + def test_status_shows_last_error_and_permission_hint(self, monkeypatch, capsys): + from hermes_cli import cron as cron_cli + + monkeypatch.setattr("hermes_cli.gateway.find_gateway_pids", lambda: [4321]) + monkeypatch.setattr(jobs, "get_ticker_heartbeat_age", lambda: 5.0) # alive + monkeypatch.setattr(jobs, "get_ticker_success_age", lambda: 9_999.0) # failing + monkeypatch.setattr( + jobs, + "get_ticker_last_error", + lambda: ( + "RuntimeError: Failed to read cron database: " + "[Errno 13] Permission denied: '/opt/data/cron/jobs.json'" + ), + ) + monkeypatch.setattr("cron.jobs.list_jobs", lambda **k: []) + + cron_cli.cron_status() + out = capsys.readouterr().out + assert "Last tick error:" in out + assert "Permission denied" in out + # The permission-specific hint must point at the ownership fix. + assert "docker exec -u" in out + + def test_status_without_marker_keeps_generic_message(self, monkeypatch, capsys): + from hermes_cli import cron as cron_cli + + monkeypatch.setattr("hermes_cli.gateway.find_gateway_pids", lambda: [4321]) + monkeypatch.setattr(jobs, "get_ticker_heartbeat_age", lambda: 5.0) + monkeypatch.setattr(jobs, "get_ticker_success_age", lambda: 9_999.0) + monkeypatch.setattr(jobs, "get_ticker_last_error", lambda: None) + monkeypatch.setattr("cron.jobs.list_jobs", lambda **k: []) + + cron_cli.cron_status() + out = capsys.readouterr().out + assert "no tick has succeeded" in out + assert "Last tick error:" not in out