248 lines
11 KiB
Markdown
248 lines
11 KiB
Markdown
# Cron Trigger Pipeline: How It Works and How to Make It Robust
|
||
|
||
## Current Architecture: Skill Events → Trigger Registration
|
||
|
||
The pipeline has **two paths** for getting a cron trigger loaded, plus a **polling loop** that actually fires them.
|
||
|
||
### Path 1: Bulk load at startup (EOSE-driven)
|
||
|
||
```mermaid
|
||
sequenceDiagram
|
||
participant Main as main.c startup
|
||
participant NH as nostr_handler
|
||
participant Relays as Nostr Relays
|
||
participant TM as trigger_manager
|
||
|
||
Main->>TM: trigger_manager_init - capacity=16, last_poll_at=0
|
||
Main->>TM: trigger_manager_load_from_startup_events
|
||
Note over TM: Loads triggers from genesis startup_events<br/>only dm triggers typically here
|
||
Main->>NH: nostr_handler_set_self_skill_eose_callback<br/>registers on_self_skill_eose_load_triggers
|
||
Main->>NH: nostr_handler_subscribe_self_skills
|
||
NH->>Relays: REQ kinds 31123, 31124, 10123<br/>authors = agent pubkey
|
||
Relays-->>NH: EVENT skill events arrive one by one
|
||
NH->>NH: on_self_skill_event for each<br/>caches in g_self_skill_events<br/>calls register_trigger_from_self_skill_event
|
||
Relays-->>NH: EOSE
|
||
NH->>NH: on_self_skill_eose sets g_self_skill_eose_received=1
|
||
NH->>Main: calls on_self_skill_eose_load_triggers callback
|
||
Main->>TM: trigger_manager_load_from_skills<br/>reads ALL cached skills via<br/>nostr_handler_get_self_events_by_kind_json
|
||
Note over TM: For each skill with trigger+filter tags:<br/>calls trigger_manager_add
|
||
Main->>Main: nostr_handler_wait_for_self_skill_eose returns 0
|
||
Main->>Main: Startup step 14 passes
|
||
Main->>Main: Enter main poll loop
|
||
```
|
||
|
||
### Path 2: Live skill event (post-startup)
|
||
|
||
```mermaid
|
||
sequenceDiagram
|
||
participant Relays as Nostr Relays
|
||
participant NH as nostr_handler
|
||
participant TM as trigger_manager
|
||
|
||
Note over NH: Subscription stays open after EOSE
|
||
Relays-->>NH: New/updated skill EVENT arrives
|
||
NH->>NH: on_self_skill_event
|
||
NH->>NH: register_trigger_from_self_skill_event
|
||
Note over NH: Checks: kind 31123/31124?<br/>Has trigger+filter tags?<br/>Is adopted via kind 10123?
|
||
NH->>TM: trigger_manager_add or update
|
||
NH->>NH: self_skill_cache_upsert_event_locked
|
||
```
|
||
|
||
### Path 3: Cron polling in main loop
|
||
|
||
```mermaid
|
||
sequenceDiagram
|
||
participant Main as main loop
|
||
participant TM as trigger_manager
|
||
participant Agent as agent.c
|
||
|
||
loop Every iteration
|
||
Main->>TM: trigger_manager_poll
|
||
Note over TM: Throttled to once per 30 seconds
|
||
TM->>TM: For each trigger where type==CRON:<br/>1. Validate cron_expr<br/>2. Check cron_matches_now<br/>3. Check last_cron_fire dedup - 50s guard
|
||
TM->>Agent: execute_llm_action with synthetic cron event
|
||
end
|
||
```
|
||
|
||
---
|
||
|
||
## The Six Failure Points
|
||
|
||
I have identified six places where a cron trigger can silently fail to load or fire. They are ordered from most likely to least likely given the logs from laantungir.net.
|
||
|
||
### 1. EOSE timeout kills startup entirely
|
||
|
||
**Where:** [`main.c:1494–1515`](src/main.c:1494)
|
||
|
||
The agent waits 15 seconds for self-skill EOSE. If relays are slow or the connection is flaky, this times out and **the entire agent process exits**:
|
||
|
||
```c
|
||
const int self_skill_eose_timeout_ms = 15000;
|
||
if (nostr_handler_wait_for_self_skill_eose(self_skill_eose_timeout_ms) != 0) {
|
||
// ... prints error, cleans up, return 1
|
||
}
|
||
```
|
||
|
||
From [`debug.log`](debug.log) line 670:
|
||
```
|
||
[2026-04-06 16:16:49] [ERROR] startup checklist [14] Subscribe self-skill cache: failed
|
||
(self-skill EOSE not received within timeout)
|
||
```
|
||
|
||
**Impact:** If the agent crashes at startup, no triggers load at all. If systemd restarts it and it crashes again, you get a restart loop with zero cron execution.
|
||
|
||
### 2. Adoption check gates live trigger registration
|
||
|
||
**Where:** [`nostr_handler.c:1462`](src/nostr_handler.c:1462)
|
||
|
||
When a skill event arrives live via [`on_self_skill_event()`](src/nostr_handler.c:2428), it calls [`register_trigger_from_self_skill_event()`](src/nostr_handler.c:1418) which checks:
|
||
|
||
```c
|
||
if (!self_skill_is_adopted_local(kind_val, pubkey->valuestring, d_tag)) {
|
||
DEBUG_INFO("live self-skill trigger ignored (not adopted) d_tag=%s", d_tag);
|
||
return;
|
||
}
|
||
```
|
||
|
||
[`self_skill_is_adopted_local()`](src/nostr_handler.c:1366) scans `g_self_skill_events` for a kind 10123 event with an `["a", "31123:<pubkey>:<d_tag>"]` tag. If the adoption event hasn't arrived yet (race condition — skill event arrives before adoption event), the trigger is silently skipped.
|
||
|
||
**Critically:** The bulk load path in [`trigger_manager_load_from_skills()`](src/trigger_manager.c:818) does **NOT** check adoption at all — it loads every skill with trigger+filter tags. So the adoption gate only affects the live path.
|
||
|
||
### 3. Bulk load is one-shot with `loaded_once` guard
|
||
|
||
**Where:** [`main.c:42`](src/main.c:42)
|
||
|
||
```c
|
||
if (ctx->loaded_once) {
|
||
DEBUG_TRACE("deferred trigger load skipped (already loaded once)");
|
||
return;
|
||
}
|
||
```
|
||
|
||
The EOSE callback fires once, calls [`trigger_manager_load_from_skills()`](src/trigger_manager.c:818), sets `loaded_once = 1`, and never runs again. If a skill event arrives **after** EOSE but **before** the live path processes it, it falls into a gap:
|
||
- The bulk load already ran and won't run again
|
||
- The live [`register_trigger_from_self_skill_event()`](src/nostr_handler.c:1418) may reject it due to the adoption check
|
||
|
||
### 4. Cron expression validation rejects silently at add time
|
||
|
||
**Where:** [`trigger_manager.c:1106–1112`](src/trigger_manager.c:1106)
|
||
|
||
```c
|
||
if (t->trigger_type == TRIGGER_TYPE_CRON) {
|
||
if (!cron_expr_is_valid(filter_json, normalized_cron, sizeof(normalized_cron))) {
|
||
DEBUG_WARN("trigger add rejected: invalid cron expression d_tag=%s expr=%s", ...);
|
||
memset(t, 0, sizeof(*t));
|
||
return -1;
|
||
}
|
||
}
|
||
```
|
||
|
||
This does log a warning, but the caller in [`trigger_manager_load_from_skills()`](src/trigger_manager.c:896) just silently skips to the next skill. The `considered` count increments but `loaded` does not — the only evidence is in the log line `trigger manager loaded X trigger(s) from self skills (considered=Y)` where X < Y.
|
||
|
||
The existing plan in [`fix_cron_triggers_not_firing.md`](plans/fix_cron_triggers_not_firing.md) documents that a bare `*` was being used instead of `* * * * *`, and that shorthand expansion was added. This has been fixed.
|
||
|
||
### 5. Poll throttle delays first evaluation by up to 30 seconds
|
||
|
||
**Where:** [`trigger_manager.c:1395`](src/trigger_manager.c:1395)
|
||
|
||
```c
|
||
if (mgr->last_poll_at > 0 && (now - mgr->last_poll_at) < 30) {
|
||
return 0;
|
||
}
|
||
```
|
||
|
||
After init, `last_poll_at` starts at 0 (fixed from the original bug where it was `time(NULL)`), so the first poll runs immediately. But subsequent polls are throttled to every 30 seconds. For a daily cron this is fine, but it means the cron match window is checked at most twice per minute.
|
||
|
||
### 6. Cron dedup guard can skip legitimate fires
|
||
|
||
**Where:** [`trigger_manager.c:1422`](src/trigger_manager.c:1422)
|
||
|
||
```c
|
||
if (t->last_cron_fire > 0 && (now - t->last_cron_fire) < 50) {
|
||
continue;
|
||
}
|
||
```
|
||
|
||
With a 30-second poll interval and a 50-second dedup window, a cron that matches at minute X will fire once and then be suppressed for the next poll. This is correct behavior for preventing double-fires within the same minute. But if the system clock jumps or NTP adjusts, this could cause unexpected skips.
|
||
|
||
---
|
||
|
||
## Robustness Suggestions
|
||
|
||
### A. Retry EOSE with backoff instead of hard abort
|
||
|
||
**Current:** EOSE timeout → process exit.
|
||
**Proposed:** Retry 2–3 times with increasing timeout (15s, 30s, 60s). If all retries fail, start the agent in degraded mode with only startup-config triggers active, and schedule a background re-attempt.
|
||
|
||
```mermaid
|
||
flowchart TD
|
||
SUB[Subscribe self-skills] --> WAIT{Wait for EOSE}
|
||
WAIT -->|Received| LOAD[Load triggers from skills]
|
||
WAIT -->|Timeout 15s| RETRY1{Retry 1 - 30s timeout}
|
||
RETRY1 -->|Received| LOAD
|
||
RETRY1 -->|Timeout| RETRY2{Retry 2 - 60s timeout}
|
||
RETRY2 -->|Received| LOAD
|
||
RETRY2 -->|Timeout| DEGRADED[Start in degraded mode<br/>startup triggers only<br/>schedule background retry]
|
||
LOAD --> READY[Agent READY]
|
||
DEGRADED --> READY
|
||
```
|
||
|
||
### B. Remove adoption gate from live trigger registration
|
||
|
||
The bulk load path doesn't check adoption. The live path does. This inconsistency means a skill created via `skill_create` with `auto_adopt=true` might not register its trigger if the adoption event arrives on a different relay or with different timing.
|
||
|
||
**Proposed:** Either:
|
||
1. Remove the adoption check from [`register_trigger_from_self_skill_event()`](src/nostr_handler.c:1462) to match the bulk path, OR
|
||
2. Add the adoption check to the bulk path too for consistency, but with a fallback: if adoption events haven't loaded yet, defer the check.
|
||
|
||
Option 1 is simpler and more robust. The agent already only subscribes to its own pubkey's events, so all skills in the cache are self-authored.
|
||
|
||
### C. Allow re-running bulk trigger load
|
||
|
||
Remove the `loaded_once` guard or replace it with a debounced re-load. When new skill events arrive after EOSE, schedule a re-scan of all cached skills after a short delay (e.g., 5 seconds). This closes the gap between EOSE and late-arriving events.
|
||
|
||
### D. Add a periodic trigger reconciliation
|
||
|
||
Every N minutes (e.g., 5), compare the set of cached skills that have trigger+filter tags against the active trigger list. Register any missing triggers. This is a safety net that catches any trigger that was missed during startup.
|
||
|
||
```c
|
||
// In trigger_manager_poll, after cron evaluation:
|
||
if (now - mgr->last_reconcile_at > 300) {
|
||
trigger_manager_load_from_skills(mgr); // idempotent via update path
|
||
mgr->last_reconcile_at = now;
|
||
}
|
||
```
|
||
|
||
### E. Log trigger registration summary at startup
|
||
|
||
After the deferred trigger load, log not just the count but also which trigger types were loaded:
|
||
|
||
```
|
||
trigger manager loaded 3 trigger(s): dm=2 cron=1 webhook=0 chain=0 nostr-sub=0
|
||
```
|
||
|
||
This makes it immediately obvious from the log whether a cron trigger was picked up.
|
||
|
||
### F. Add an HTTP API endpoint for trigger status
|
||
|
||
Expose `/api/triggers` that returns the same JSON as the `trigger_list` tool. This allows external monitoring (e.g., a health check script) to verify that expected cron triggers are loaded without going through the LLM.
|
||
|
||
---
|
||
|
||
## Summary of What Happened on laantungir.net
|
||
|
||
Based on the logs:
|
||
|
||
1. The agent started successfully multiple times (startup step 14 passed with `skills=3 adoptions=1` or similar).
|
||
2. The deferred trigger load status shows **only dm-type triggers** were loaded — no cron triggers appear in any log entry.
|
||
3. On 2026-04-06, the agent failed at startup step 14 with EOSE timeout, meaning it never even got to trigger loading.
|
||
4. There is **zero** evidence of `cron trigger matched` or `cron trigger skipped` in any log file, confirming the cron trigger was never in the active trigger set.
|
||
|
||
The most likely explanation: the cron skill event exists on relays but either:
|
||
- It was missing the `["trigger", "cron"]` and/or `["filter", "<expr>"]` tags when it was published
|
||
- It was not adopted (no kind 10123 event referencing it) and arrived via the live path where adoption is checked
|
||
- The cron expression was invalid and was silently rejected at add time
|
||
- The EOSE timeout prevented the agent from ever reaching the trigger loading phase
|
||
|
||
Running `trigger_list` on the live server will definitively answer which of these is the case.
|