Skip to content

Automations: a stale automation-poll.lock starves the whole workspace scheduler for 10 minutes, with no log record and a zero-delay spin loop #983

Description

@rafalwolak

Version: @open-mercato/cezar@0.10.1 (global install). Line references are to dist/; I do not have the sources.

Summary

If the cockpit is killed while a poll is in flight, automation-poll.lock is left behind holding a dead pid. For the next ten minutes the workspace scheduler polls nothing - in every project, not just the one that owns the lock - writes no log record, writes no state, and spins in a zero-delay reschedule loop. The only observable symptom is CPU.

Mechanism

1. The lease is taken before the block that reports anything.

dist/automations/scheduler.js, ProjectAutomationScheduler.check():

const lease = store.acquireLease();
if (!lease)
    throw new Error('automation polling lease is held by another process');
const started = Date.now();
let completion;
try {
    ...
}
catch (error) {
    if (mode === 'execute') this.recordFailure(definition, error);
    else store.appendLog({ ..., result: 'error', ... });
    throw error;
}
finally {
    if (completion) store.appendLog({ ... });
    ...
}

The throw happens before the try, so it reaches neither recordFailure (which would write consecutiveFailures, backoffUntil and an error log record) nor the finally. Every other failure in this function is recorded; this one is not.

2. The caller swallows it and reschedules immediately.

WorkspaceAutomationScheduler.schedule():

this.timer = setTimeout(() => {
    this.timer = undefined;
    void next.scheduler.check(next.definition).catch(() => undefined).finally(() => this.schedule());
}, Math.max(0, next.at - (this.options.now?.() ?? Date.now())));

.catch(() => undefined) discards the rejection. .finally(() => this.schedule()) re-enters. next.at is the automation's nextCheckAt, which is already in the past because the check never completed, so Math.max(0, ...) is 0. This is a tight loop.

3. It is a workspace-wide loop, not a per-project one.

due is built across coordinator.enabledProjectIds() and sorted globally; only due[0] is run per tick. So the automation whose project holds the stale lock is picked, throws, reschedules at 0, and is picked again - and no other project's automations ever get a turn.

4. The lock is only reclaimed on age.

dist/automations/store.js:

acquireLease(staleAfterMs = 10 * 60_000) {
    ...
    if (this.now().getTime() - statSync(path).mtimeMs > staleAfterMs) {
        unlinkSync(path);
        return this.acquireLease(staleAfterMs);
    }
    return undefined;
}

The lock records {"pid":...,"startedAt":...} but the pid is never consulted. A dead writer is indistinguishable from a live one for ten minutes.

Reproduction

  1. Two projects registered and enabled, automations running.
  2. launchctl bootout gui/$(id -u)/dev.cezar.cockpit while any poll is in flight (ours are 2-6s, so a poll is in flight a meaningful fraction of the time).
  3. launchctl bootstrap ....
  4. Observe: no records appended to either project's automation-log.ndjson, no mtime change on either automation-state.json, elevated CPU on the cockpit, for ten minutes.

Observed

08:44:55  last automation log record, both projects
08:45:15  money-tracker.online/.ai/cezar/automation-poll.lock  {"pid":982,"startedAt":"2026-09-14T06:45:15.820Z"}
08:45:22  cockpit restarts as pid 2180 - pid 982 is gone
          ... 10 minutes, zero log records in either project, cockpit at 13.8% CPU ...
08:55:31  lock reclaimed as stale; both projects resume polling normally

planned.travel had no lock of its own and was blocked for the entire ten minutes.

Suggested fixes

Any one of these removes the silence; the first two also remove the spin.

  1. Reclaim a lock whose pid is not alive. The pid is already written into the lock file. process.kill(pid, 0) distinguishes a crashed writer from a live one, and makes the common case instant instead of ten minutes.
  2. Do not reschedule a failed check at zero delay. When check() rejects, the next attempt should be pushed out by at least the automation's interval. As written, any pre-try throw becomes a busy loop.
  3. Move the lease acquisition inside the try, or log the skip explicitly. A poll that does not happen should leave a trace; right now the one failure mode that produces no diagnostics is the one that lasts longest.
  4. Consider a per-project turn. One project's lock currently stops every project. Even with the above fixed, a project that genuinely cannot acquire its lease should not consume the workspace's only scheduling slot.

Context: we hit this because our host-patch script restarted the cockpit unconditionally, including on reruns that changed nothing. We have since made the restart conditional - but the ten silent minutes are worth fixing upstream regardless, since any crash or upgrade can land in the same window.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions