v0.2.39 - Add 15-minute relay-backed trigger reconciliation in trigger_manager_poll to recover missed self-skill events and re-register missing triggers

This commit is contained in:
Didactyl User
2026-04-14 16:36:53 -04:00
parent 5e6610823f
commit 59bd2603e2
6 changed files with 379 additions and 5 deletions

View File

@@ -54,11 +54,11 @@ Skills compose by adoption-list order (`10123`) and trigger tags carry runtime e
Didactyl will support local inference, which is very privacy preserving. Remote inference does however have it's advantages, and in those cases Didactyl supports using Bitcoin Lightning and eCash inference providers.
## Current Status — v0.2.38
## Current Status — v0.2.39
**Active build — this project is barely working. Experiment at your own risk.**
> Last release update: v0.2.38Resolve NIP-17 gift wrap send failure investigation and docs
> Last release update: v0.2.39Add 15-minute relay-backed trigger reconciliation in trigger_manager_poll to recover missed self-skill events and re-register missing triggers
- Connects to configured relays with auto-reconnect and relay state transition logging
- Publishes configured startup events per relay as each relay becomes connected

View File

@@ -0,0 +1,247 @@
# 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:14941515`](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:11061112`](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 23 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.

View File

@@ -12,8 +12,8 @@
// Using DIDACTYL_ prefix to avoid conflicts with nostr_core_lib VERSION macros
#define DIDACTYL_VERSION_MAJOR 0
#define DIDACTYL_VERSION_MINOR 2
#define DIDACTYL_VERSION_PATCH 38
#define DIDACTYL_VERSION "v0.2.38"
#define DIDACTYL_VERSION_PATCH 39
#define DIDACTYL_VERSION "v0.2.39"
// Agent metadata
#define DIDACTYL_NAME "Didactyl"

View File

@@ -2512,7 +2512,7 @@ int nostr_handler_init(didactyl_config_t* config) {
nostr_pool_reconnect_config_t reconnect = *nostr_pool_reconnect_config_default();
reconnect.enable_auto_reconnect = 1;
reconnect.ping_interval_seconds = 20;
reconnect.pong_timeout_seconds = 10;
reconnect.pong_timeout_seconds = 30;
g_pool = nostr_relay_pool_create(&reconnect);
if (!g_pool) {

View File

@@ -589,6 +589,126 @@ static void parse_trigger_runtime_tags(cJSON* tags,
}
}
static int trigger_manager_reconcile_from_relays(trigger_manager_t* mgr) {
if (!mgr || !mgr->cfg) {
return -1;
}
cJSON* filter = cJSON_CreateObject();
cJSON* kinds = cJSON_CreateArray();
cJSON* authors = cJSON_CreateArray();
if (!filter || !kinds || !authors) {
cJSON_Delete(filter);
cJSON_Delete(kinds);
cJSON_Delete(authors);
return -1;
}
cJSON_AddItemToArray(kinds, cJSON_CreateNumber(31123));
cJSON_AddItemToArray(kinds, cJSON_CreateNumber(31124));
cJSON_AddItemToObject(filter, "kinds", kinds);
cJSON_AddItemToArray(authors, cJSON_CreateString(mgr->cfg->keys.public_key_hex));
cJSON_AddItemToObject(filter, "authors", authors);
cJSON_AddNumberToObject(filter, "limit", 300);
char* events_json = nostr_handler_query_json(filter, 8000);
cJSON_Delete(filter);
if (!events_json) {
DEBUG_WARN("[didactyl] trigger reconcile skipped: relay query returned no data");
return -1;
}
cJSON* events = cJSON_Parse(events_json);
free(events_json);
if (!events || !cJSON_IsArray(events)) {
cJSON_Delete(events);
DEBUG_WARN("[didactyl] trigger reconcile skipped: invalid JSON from relay query");
return -1;
}
int considered = 0;
int loaded = 0;
int event_count = cJSON_GetArraySize(events);
for (int i = 0; i < event_count; i++) {
cJSON* skill_event = cJSON_GetArrayItem(events, i);
cJSON* content = skill_event ? cJSON_GetObjectItemCaseSensitive(skill_event, "content") : NULL;
cJSON* tags = skill_event ? cJSON_GetObjectItemCaseSensitive(skill_event, "tags") : NULL;
if (!content || !cJSON_IsString(content) || !content->valuestring || !tags || !cJSON_IsArray(tags)) {
continue;
}
cJSON* d = find_tag_value_string(tags, "d");
cJSON* trigger = find_tag_value_string(tags, "trigger");
cJSON* filter_j = find_tag_value_string(tags, "filter");
cJSON* action = find_tag_value_string(tags, "action");
const char* d_tag = (d && cJSON_IsString(d) && d->valuestring) ? d->valuestring : NULL;
const char* trigger_s = (trigger && cJSON_IsString(trigger) && trigger->valuestring) ? trigger->valuestring : NULL;
const char* filter_s = (filter_j && cJSON_IsString(filter_j) && filter_j->valuestring) ? filter_j->valuestring : NULL;
const char* action_s = (action && cJSON_IsString(action) && action->valuestring) ? action->valuestring : "llm";
considered++;
if (!d_tag || d_tag[0] == '\0') {
continue;
}
int trigger_supported = trigger_s &&
(strcmp(trigger_s, "nostr-subscription") == 0 ||
strcmp(trigger_s, "webhook") == 0 ||
strcmp(trigger_s, "cron") == 0 ||
strcmp(trigger_s, "chain") == 0 ||
strcmp(trigger_s, "dm") == 0);
if (!trigger_supported || !filter_s || filter_s[0] == '\0') {
continue;
}
if (strcmp(action_s, "template") == 0) {
DEBUG_WARN("[didactyl] trigger action template is deprecated; forcing llm for d_tag=%s", d_tag);
}
const char* llm_s = NULL;
const char* tools_s = NULL;
int has_max_tokens = 0;
int max_tokens = 0;
int has_temperature = 0;
double temperature = 0.0;
int has_seed = 0;
int seed = 0;
parse_trigger_runtime_tags(tags,
&llm_s,
&tools_s,
&has_max_tokens,
&max_tokens,
&has_temperature,
&temperature,
&has_seed,
&seed);
if (trigger_manager_add(mgr,
d_tag,
content->valuestring,
filter_s,
TRIGGER_ACTION_LLM,
trigger_s,
1,
llm_s,
tools_s,
has_max_tokens,
max_tokens,
has_temperature,
temperature,
has_seed,
seed) == 0) {
loaded++;
}
}
cJSON_Delete(events);
DEBUG_INFO("[didactyl] trigger reconcile complete: loaded=%d considered=%d", loaded, considered);
return 0;
}
static void apply_trigger_runtime_to_llm_config(const active_trigger_t* t, llm_config_t* cfg) {
if (!t || !cfg) return;
@@ -810,6 +930,7 @@ int trigger_manager_init(trigger_manager_t* mgr, didactyl_config_t* cfg) {
}
mgr->last_poll_at = 0;
mgr->last_reconcile_at = 0;
DEBUG_INFO("[didactyl] trigger manager initialized (capacity=%d)", mgr->capacity);
return 0;
@@ -1447,6 +1568,11 @@ int trigger_manager_poll(trigger_manager_t* mgr) {
}
pthread_mutex_unlock(&mgr->mutex);
if (mgr->last_reconcile_at <= 0 || (now - mgr->last_reconcile_at) >= 900) {
mgr->last_reconcile_at = now;
(void)trigger_manager_reconcile_from_relays(mgr);
}
return fired;
}

View File

@@ -57,6 +57,7 @@ typedef struct trigger_manager {
didactyl_config_t* cfg;
pthread_mutex_t mutex;
time_t last_poll_at;
time_t last_reconcile_at;
} trigger_manager_t;
int trigger_manager_init(trigger_manager_t* mgr, didactyl_config_t* cfg);