Automations and webhooks for the AT Protocol airglow.run

Condition gate misses leave no trace in the delivery log #14

Closed tyb.there-hugo.dev
Closed opened by tyb.there-hugo.dev

Problem #

In live mode, when a condition step rejects an event, no row is written at all (lib/jetstream/run-steps.ts:6-7). "The event never arrived" and "the condition rejected it" look identical, so users can't debug their conditions.

Seen in the session #

In https://www.youtube.com/watch?v=5MnT-ZgbBIc:

  • 1:12 to 1:13, while trying to work out whether the trigger or the condition was failing.

Fix direction #

Record skipped runs (perhaps sampled or collapsed), or show a per-automation counter of events that were matched but filtered out.

Details: docs/brainstorms/2026-10-17-graze-conference-automation-feedback.md (M3).

Queued: the loop will work on this version of the issue.

loop:queued cid=bafyreichyk34cj4tjskg5hzhjikxzt6aza6ezz3ex7mnjk726ceytq5dkq

Working on this, attempt 1.

loop:claim run=contribute-20261024-150615-3my32fh6c6s22 branch=loop/3my32fh6c6s22 attempt=1 issue=14

The work is ready but touches owner-only paths: lib/db/migrations/0001_automation_condition_misses.sql, lib/db/migrations/meta/0001_snapshot.json, lib/db/migrations/meta/_journal.json, so it was not pushed. The diff is in the run directory.

feat(jetstream): count events a condition filters out and show the count on the logs page

When a condition rejects an event, nothing is written to the delivery log, so "the event never arrived" and "the condition rejected it" looked the same. Now each automation keeps a count of the events its conditions filtered out, with the time of the latest one, and the logs page shows it above the table: "Conditions filtered out 1,234 matching events (latest 2 minutes ago). Filtered events are counted here, not logged." I went with the counter from the issue's fix direction instead of writing a row per skipped event: a trigger-gate miss happens on the consumer's hot path once per non-matching event, and for a broad trigger, rows would flood the log and the database.

What changed #

  • New table automation_condition_misses (one row per automation: miss_count, last_miss_at, last_event_time_us; cascades on automation delete). Migration 0001_automation_condition_misses.sql, generated with pnpm db:generate.
  • lib/jetstream/condition-misses.ts: an in-memory counter that adds no awaits to the hot path. It is flushed in a single batched upsert on the existing cursor-flush timer (5s by default) and once more at worker shutdown. If a flush fails, the batch goes back into the pending counts. Counts for an automation deleted in the meantime are dropped through a join, so they never fail the foreign key.
  • Two places record a miss: trigger-gate misses in JetstreamSubscription.dispatchAutomations (legacy conditions rows included), and in-tree gate stops (runSteps outcome stopRun) in handleMatchedEvent.
  • The logs page (/u/:handle/:rkey/logs) and GET /api/automations/:rkey (field conditionMisses, read by the Refresh button) return the count, and the DeliveryLog island renders it. The line also shows when there are no log rows yet.
  • The CONCEPTS.md "Gate" entry now describes the counter.

Verification #

  • pnpm run check: passes.
  • pnpm run test: 162 files, 2549 tests pass.
  • New tests:
    • condition-misses.test.ts (PGlite): accumulate and flush, adding onto the stored total, a deleted automation dropped without failing the batch, cascade on delete.
    • consumer.test.ts: a gate that filters 2 of 3 events stores a count of 2.
    • run-steps.test.ts: an in-tree gate stop records one miss, and a completed run records none.
    • DeliveryLog.test.tsx: the line appears, including with no rows, is hidden at null, and uses the singular for one event.
  • I did not check the UI in a browser: this container has no dev server, PDS or curl.

Acceptance criteria #

Decisions you can reverse #

  • Counter instead of rows. A collapsed "skipped" row per window would also be possible, but it costs a write path inside the log.
  • Both modes are counted. Dry run already writes a "Would stop" row for an in-tree stop, so dry-run in-tree stops are counted twice, once as the row and once in the counter.
  • Loop gates are not counted. A gate inside a loop body that skips one item does not filter the event, so it is left out. A resumed (post-AI) run that ends at a gate is also not counted.
  • The total is lifetime and never resets. It does not reset when the conditions are edited; the "latest" time is what shows whether misses are still happening. A reset on edit would need a hook in the update route.
  • Counts can be lost. At most one flush interval of counts is lost if the process crashes. The counter assumes a single worker process, as the cursor store does.

loop:awaiting-owner run=contribute-20261024-150615-3my32fh6c6s22

The loop can now do migrations

Queued: the loop will work on this version of the issue.

loop:queued cid=bafyreichyk34cj4tjskg5hzhjikxzt6aza6ezz3ex7mnjk726ceytq5dkq

Working on this, attempt 1.

loop:claim run=contribute-20261026-124425-3my32fh6c6s22 branch=loop/3my32fh6c6s22 attempt=1 issue=14

feat(logs): count events that conditions filter out, per automation

When a condition rejects an event, no delivery row is written. That covers trigger-gate misses on the Jetstream hot path and in-tree gate-stops in live mode, so "the event never arrived" and "the condition rejected it" looked the same. Writing a row per rejection would flood the log on busy collections, where a trigger gate can turn away thousands of events a second. Each rejection is now counted per automation per UTC day instead, and the owner sees the count on the automation page and on its logs page.

What changed #

  • New table automation_filter_counts (automation_uri FK with cascade, day, count, last_filtered_at, PK (automation_uri, day)). Migration 0002_jittery_thunderbolts.sql was written by pnpm db:generate.

  • lib/jetstream/filter-counts.ts: noteFiltered(uri) is synchronous and runs no query, so the consumer's miss path stays free of awaits. The worker flushes the in-memory batch every 10 s with one additive upsert, and once more on shutdown after the handlers drain. If the batch fails (for example, an automation was deleted since its event was counted and its row breaks the foreign key), the flush retries row by row so only that row is lost. getFilterSummary returns the last 7 days' total and the time of the latest rejection. The hourly cleanup drops rows older than 30 days, the same retention as the delivery logs.

  • What is counted:

    • trigger-gate misses in consumer.dispatchAutomations, for steps rows and legacy rows alike;
    • in-tree gates that stop the run (runConditionStep, so resumed runs count too);
    • legacy per-fetch condition skips.

    A gate inside a loop body only skips that item and is not counted. Rate-limit, dedupe and catch-up skips are not counted either.

  • UI:

    • The owner's "Recent activity" card gets a "Filtered out" row: N events in the last 7 days, and when the last one was.
    • The logs page gets an info alert above the log that gives the same count and explains that these events are counted, not logged. It also says so when the count is zero.
  • CONCEPTS.md (Gate) and the run-steps header comment now mention the count.

Verification #

  • pnpm run check: pass. pnpm run test: pass (165 files, 2588 tests).
  • New tests:
    • lib/jetstream/filter-counts.test.ts (PGlite): nothing is written until a flush; a later flush adds to the same day's row and keeps the latest time; a new UTC day gets a new row; an automation deleted before the flush loses only its own count; the 7-day summary window; pruning.
    • Consumer: a trigger-gate miss is counted, and a pass or an automation without gates is not.
    • run-steps: an in-tree gate-stop is counted, a passing gate is not, and an in-loop item skip is not.
    • Automation page: owner sees "Filtered out" with the count, a visitor does not.
    • New logs.test.tsx: the alert text with a non-zero count and with a zero count.
  • pnpm db:generate run again reports no schema drift.
  • I did not test it on a running dev server: there is no PDS or Postgres in this container.

Acceptance criteria #

Decisions the owner can reverse #

  • A counter instead of rows (sampled or collapsed), because a trigger gate on a firehose-volume collection would otherwise write rows at wire speed. The count does not say why an event was rejected or which event it was. A later step could keep the last rejected event's URI on the day row.
  • Dry run is counted too. The trigger gate filters in both modes, and an in-tree gate-stop in dry run already writes its "Would stop" row; it is counted as well.
  • The count can be lost: a failed flush drops its batch, and counts not yet flushed are lost if the process dies. The UI trails live traffic by up to about 10 s.
  • The window is 7 days and retention is 30 days, matching the activity card and the log cleanup.
  • Per-day rows are attributed to the day of the batch's latest rejection. A batch that straddles midnight lands entirely on the new day.
  • The "Filtered out" row shows for every automation, including ones without conditions, where it always reads 0.

Review: https://tangled.org/exosphere.site/airglow/compare/main...loop/3my32fh6c6s22

loop:pushed run=contribute-20261026-124425-3my32fh6c6s22 sha=2263f2b188953ec910e5b68018ad741e214378ec

The migration on 2263f2b18895 is what pnpm db:generate writes from the schema, and it only adds. Only the owner merges a branch with a migration: loop merge 14, once the gate passes.

0002_jittery_thunderbolts.sql:

CREATE TABLE "automation_filter_counts" (
	"automation_uri" text NOT NULL,
	"day" date NOT NULL,
	"count" integer NOT NULL,
	"last_filtered_at" timestamp with time zone NOT NULL,
	CONSTRAINT "automation_filter_counts_automation_uri_day_pk" PRIMARY KEY("automation_uri","day")
);
--> statement-breakpoint
ALTER TABLE "automation_filter_counts" ADD CONSTRAINT "automation_filter_counts_automation_uri_automations_uri_fk" FOREIGN KEY ("automation_uri") REFERENCES "public"."automations"("uri") ON DELETE cascade ON UPDATE no action;

loop:migration run=verify-20261026-125256-3my32fh6c6s22 sha=2263f2b188953ec910e5b68018ad741e214378ec result=ok

Verdict: merge. The branch takes the issue's second fix direction. Each event that an automation's conditions reject is now counted per automation per UTC day, and the owner sees the count on the automation page and on the logs page, so "the condition rejected it" no longer looks like "the event never arrived". pnpm run check and pnpm run test both pass on 2263f2b (165 files, 2588 tests).

What I checked:

  • Every place an event is rejected calls noteFiltered, and none counts the same event twice.
    • Trigger-gate misses in consumer.dispatchAutomations are counted, for steps rows and legacy rows alike. This is the case from the session.
    • In-tree gate-stops in runConditionStep are counted only when the gate is outside a loop. The walk skips the trigger-gate prefix, so those gates are not counted a second time.
    • Legacy per-fetch condition skips in handler.ts are counted.
    • Events below the late-joiner floor are not counted, and neither are loop item skips, rate-limit skips or dedupe skips.
    • One subscription runs per wantedDids set, so an event from a repo the automation does not watch never reaches its gate and is never counted.
  • Flushing (filter-counts.ts) stays off the hot path and keeps counts it can keep. noteFiltered is synchronous and runs no query. The pending map has one entry per URI, so a batch upsert never hits the same row twice. The upsert adds to the count and keeps the later timestamp. If the batch fails, it retries row by row, so a deleted automation loses only its own count. The worker starts the flush and stops it after the handlers drain. server.ts runs the worker in the same process. The 7-day summary covers today and the six days before it, and old rows are pruned with the same 30-day cutoff as the logs.
  • The UI shows the count only to the owner. On the automation page it shows only when isOwner, and the logs page already redirects anyone who is not the owner. Timestamps are formatted with toLocaleString, as elsewhere on the page.
  • Migration 0002_jittery_thunderbolts.sql: it creates a new table, automation_filter_counts, with primary key (automation_uri, day) and a foreign key to automations.uri with cascade delete. It changes no existing table and touches no existing rows. Existing automations start at zero, and their counts are deleted with them. The table suits the issue. Only app/routes/api/automations/[rkey].ts deletes from automations, on an actual delete, so a record update keeps its counts.
  • Tests: I read the new and changed tests: filter-counts on PGlite, the consumer, run-steps, the automation page and the logs page. They cover the behaviour described above.

Minor points that do not block the merge, all already listed as decisions in pr.md:

  • When the cursor rewinds, the replayed trigger-gate misses are counted again.
  • A tick flush still in flight when the worker stops is not awaited.
  • Counts not yet flushed are lost if the process dies.

All three are acceptable for a diagnostic counter.

There is no followup.md.

loop:verdict run=review-20261026-125420-3my32fh6c6s22 sha=2263f2b188953ec910e5b68018ad741e214378ec verdict=merge

Merged onto main as 95cd138b2103104d581f4d97160f6bb1d14862ac.

loop:merged sha=95cd138b2103104d581f4d97160f6bb1d14862ac head=2263f2b188953ec910e5b68018ad741e214378ec

Sign up or Sign in to add to the discussion.