Files
didactyl/plans/fix_dm_delivery_during_triggers.md

11 KiB
Raw Permalink Blame History

FIXED: DM Delivery Failure During Cron-Triggered Skills

Status: ✅ Fixed and deployed in v0.2.72 (2026-08-25/26)

Five fixes applied:

  1. src/agent.c — nostr_handler_poll(0) calls in the agent_on_trigger() turn loop and tool-execution loop keep websockets serviced during long-running triggered skills
  2. src/nostr_handler.c — self-healing retry in nostr_handler_send_dm_with_role(): if a publish is accepted by 0 relays, service the pool for 500ms and retry once
  3. src/trigger_manager.c — periodic trigger reconciliation (every 60s) from the local self-skill cache, closing the EOSE/adoption-gate race that prevented triggers from loading after restart
  4. src/agent.c + src/main.c + src/main.h — systemd_notify_send("WATCHDOG=1") pings inside the trigger execution loop. The service unit has WatchdogSec=120 with Type=notify; the main loop's 10s ping cadence is suspended during blocking trigger executions, so systemd was killing the service mid-investigation (observed at 18:35:14). Pings now fire per-turn and per-tool-call.
  5. nostr_core_lib/nostr_core/core_relay_pool.c — dead-transport detection in check_connection_health(). When nostr_ws_ping() fails to send (remote closed the TCP connection), the ws client's cached state still claims CONNECTED (it only transitions on a clean WebSocket CLOSE frame), so the pool never marked the relay disconnected and never reconnected — the agent sat with zero TCP sockets for 13+ hours while reporting 3/3 connected (observed 2026-08-26: DMs silently ignored from 00:08 onward). The fix closes the stale client (ws_client = NULL) and marks the relay DISCONNECTED on ping-send failure or pong timeout, letting the reconnect logic perform a fresh connect.

Verification (2026-08-25 21:51 UTC): webhook test fired → investigation ran ~2 minutes (past the old 120s kill window) → service stayed up (no restart) → investigation DM delivered via 3 connected relay(s). All 3 triggers (dm, cron, webhook) register automatically after restart via reconciliation. The skills also needed to be adopted via skill_adopt — the original skill_create with auto_adopt: true had failed to publish the adoption event because publishing was broken at creation time.

Post-fix-5 verification (2026-08-26 13:41 UTC): service restarted with the lib fix, 3/3 relays connected, 4 live TCP sockets confirmed via ss. The midnight health report and a real watchdog alert (load 3.69 at 04:01) both fired correctly on 2026-08-26 — the monitoring features work; the dead-socket bug was silently swallowing all inbound DMs.

Symptom

The server-health-report cron skill fires correctly (confirmed at 00:00 and 12:00 UTC), gathers all metrics, and the LLM generates the report — but the DM never reaches the admin. The log shows a contradictory pair:

[12:01:22] kind 4 event published to wss://relay.damus.io (async)      ← targeted
[12:01:22] kind 4 event published to wss://relay.primal.net (async)
[12:01:22] kind 4 event published to wss://relay.laantungir.net (async)
[12:01:22] sent DM 2af454bd2034a08f... to 1ec454734dcbf6fe... via 0 connected relay(s)   ← actually sent to ZERO

Meanwhile the webhook test DM (22 hours earlier) succeeded: via 3 connected relay(s).

Root Cause Analysis

The single-threaded main loop blocks websocket servicing

The main loop in main.c:2480 is single-threaded:

while (g_running) {
    (void)nostr_handler_poll(100);                    // services websockets
    (void)trigger_manager_poll(&trigger_manager);     // BLOCKS during trigger execution
    if (http_api_started) {
        (void)http_api_poll(0);
    }
    ...
}

When a cron trigger fires, the call chain is:

trigger_manager_poll()                          [trigger_manager.c:1681]
  → execute_llm_action()                        [trigger_manager.c:903]
    → agent_on_trigger()                        [agent.c:1769]
      → multi-turn LLM loop (BLOCKING)
         - 8 × local_shell_exec (up to 30s each)
         - 3-4 × LLM HTTP round trips
      → nostr_dm_send tool call

The health report execution takes 50–72 seconds. During this entire window, nostr_handler_poll() is never called — the websocket connections receive zero servicing.

Two connection checks disagree

Check Location Basis Result during cron fire
nostr_relay_pool_get_relay_status() nostr_handler.c:3304 relay->status — only updated during poll CONNECTED (stale)
nostr_ws_get_state() core_relay_pool.c:1714 live ws client state NOT CONNECTED

In nostr_handler_send_dm_with_role():

  1. The relay-selection loop uses the stale relay->status → builds connected_relays[] with 3 entries → prints "kind 4 event published to ..." for each
  2. nostr_relay_pool_publish_async() internally re-checks with the live nostr_ws_get_state() → all relays fail the check → every send is skipped → returns 0
  3. The final log line prints the actual result: via 0 connected relay(s)

Why the webhook test succeeded

The webhook test completed in ~23 seconds — under the ~30s threshold where the unserviced websockets degrade (relay-side ping timeouts, TCP buffer stalls). The cron health report takes 50–72 seconds, well past it.

nostr_core_lib version check

The vendored lib is v0.6.15 (nostr_core.h:5), which is the latest per update_nostr_core_lib_nsigner.md. The lib's behavior is correct — it refuses to send on connections whose live state isn't CONNECTED. The bug is in didactyl's usage pattern: blocking the poll loop for a minute.


Debugging Steps (in priority order)

Step 1: Confirm the timing hypothesis — zero risk, 5 minutes

Create a minimal cron skill that fires every 5 minutes with ONE fast command and an immediate DM:

{
  "d": "dm-timing-test",
  "trigger": "cron",
  "filter": "*/5 * * * *",
  "content": "Run `uptime` with local_shell_exec, then immediately DM the admin with the result using nostr_dm_send. Do nothing else."
}
  • If the short skill's DM arrives → timing/blocking confirmed
  • If it also fails → hypothesis wrong, go to Step 2 instrumentation
  • Remove the test skill afterward (skill_remove)

Step 2: Instrument the send path — confirms the state disagreement

Add temporary logging in nostr_handler_send_dm_with_role() before the publish:

for (int i = 0; i < g_cfg->relay_count; i++) {
    DEBUG_INFO("[didactyl] DM pre-check: relay=%s pool_status=%d",
               g_cfg->relays[i],
               nostr_relay_pool_get_relay_status(g_pool, g_cfg->relays[i]));
}

And in nostr_relay_pool_publish_async(), log per-relay ws state and send result:

DEBUG_INFO("[pool] publish_async relay=%s ws_state=%d",
           relay_urls[i],
           relay && relay->ws_client ? nostr_ws_get_state(relay->ws_client) : -1);

Expected output during a cron fire: pool_status=2 (CONNECTED) but ws_state != CONNECTED for all relays — proving the stale-vs-live disagreement.

Step 3: The fix — poll websockets during trigger execution

Add non-blocking polls inside the agent_on_trigger() execution loop:

// In agent_on_trigger(), at the top of the per-turn loop (before llm_chat_with_tools_messages):
(void)nostr_handler_poll(0);   // non-blocking: service websocket I/O

// Also inside the tool-execution loop (after each tools_execute call),
// since local_shell_exec can block up to 30 seconds per call:
(void)nostr_handler_poll(0);

This keeps the websocket state fresh and the connections alive throughout long-running triggered skills. It also benefits DM-triggered conversations that run long tool loops.

Files to change:

  • src/agent.c — add poll calls in agent_on_trigger() (and consider the same for the DM conversation path in agent_on_message() if it has the same pattern)

Step 4: Rebuild, redeploy, verify

./build_static.sh
./deploy_lt.sh

Then watch the next 12:00 UTC fire (or use the Step 1 test skill for faster iteration):

ssh ubuntu@laantungir.net "grep -E 'sent DM.*via' /home/simon/debug.log | tail -5"

Success criterion: via 3 connected relay(s) and the admin receives the report DM.

Step 5 (optional hardening): surface send failures to the LLM

Currently nostr_dm_send returns success: false when sent == 0, but the LLM may not retry. Two options:

  1. Retry in the tool: in nostr_handler_send_dm_with_role(), if sent == 0, call nostr_handler_poll(100) a few times and retry the publish once — self-healing without LLM involvement
  2. Retry via LLM: make the tool result error message explicit ("DM not delivered: 0 relays accepted. Retry after servicing connections.") so the LLM retries on the next turn

Option 1 is more robust; option 2 is simpler.

Step 6 (optional): check upstream nostr_core_lib

The vendored v0.6.15 is current, but worth a quick check of the upstream repo for any post-0.6.15 changes to core_relay_pool.c — particularly whether nostr_ws_get_state() semantics changed or whether a queued-publish mechanism (send after reconnect) was added. If upstream added a publish queue, updating the vendored lib could make sends self-healing.


Workarounds (if a code fix must wait)

  1. Split the skill into a chain: server-health-report (gather metrics, write to file) → chain trigger → server-health-report-send (read file, DM admin). Each skill stays under ~30s, keeping websocket degradation below threshold. Fragile — depends on the exact timeout window.
  2. DM first, investigate later: restructure the skill to send a brief DM immediately (before the long shell commands), then send findings. Only helps if the first DM goes out within ~30s of trigger fire.

Both are stopgaps — the real fix is Step 3.


Verification Checklist

  • Step 1 test skill DM arrives (timing hypothesis confirmed)
  • Step 2 instrumentation shows pool_status=CONNECTED but ws_state≠CONNECTED during cron fire
  • Step 3 fix applied: nostr_handler_poll(0) calls in agent_on_trigger() loops
  • Rebuilt and deployed via ./build_static.sh + ./deploy_lt.sh
  • Next cron fire logs via 3 connected relay(s)
  • Admin receives the health report DM at 00:00/12:00 UTC
  • Webhook alert path still works (regression check)