feat(nostr): confirm publishes against the relay's OK #58

Merged
padreug merged 1 commit from feat/confirm-publish-with-relay-ok into main 2026-09-27 20:26:58 +00:00
Owner

Closes #56

publish_nostr_event returned as soon as the EVENT was on the send queue, and the publisher logged Published on the next line. Queueing is not delivery — nostrclient drops an EVENT outright when no relay is connected and answers OK false "error: no relays connected". We discarded that reply.

That cost a completed repair on cfaun this morning: the #55 sweep republished a 14-day-stale calendar event 21s before nostrclient finished connecting, got OK false, logged Published, reported 1/1 recovered and cleared the pending flag — leaving the count stale, the row unflagged and the log asserting success. So #55's contract was never true: it claimed to clear only on confirmed success but cleared on confirmed enqueue.

publish_nostr_event now registers a future per event id, awaits the OK, and returns whether it was accepted. publish_event_to_nostr returns None when unconfirmed, which keeps the row flagged for the sweep. Correlation lives in get_event — the one place relay messages cross from the websocket thread into the event loop, so there's no cross-thread future juggling. A disconnect settles in-flight publishes immediately rather than making callers wait out the timeout.

Verified on aio-demo, not just in tests

This is a change about the gap between what the code believes and what actually happened, so unit tests can only go so far. Ran it on aio-demo (which had the released v1.6.1-aio.16, i.e. #54 and #55 but not this) by patching the two files over the installed extension, then restored the originals — md5s confirmed identical to the pre-test values.

Delivery confirmed:

20:06:44  Republish sweep: 1 event(s) pending
20:06:46  Published NIP-52 calendar event: 0d914b7d9349e790... (kind 31923)
20:06:46  Republish sweep: 1/1 recovered
flag 1 -> 0,  nostr_event_created_at 1790539604
relay:  1790539604 0d914b7d9349 avail=25 sold=8

created_at on the relay matches the DB, so the OK tracked a real delivery rather than merely not timing out.

The cfaun failure, reproduced and now caught. Removed the relay from nostrclient to force OK false:

20:08:42.55  Republish sweep: 1 event(s) pending
20:08:42.78  Relay rejected event fa1d91773e05…: error: no relays connected
20:08:42.78  Relay did not confirm NIP-52 calendar event for eUhCwTTS37p2YgNN4vcUAu
20:08:42.78  Republish sweep: 0/1 recovered
flag stayed 1

Under aio.16 this exact sequence logs Published, says 1/1 recovered, and clears the flag. The relay's own diagnostic now reaches the journal verbatim — error: no relays connected is the sentence that would have ended this morning's investigation in seconds.

Recovery closes the loop. Restored the relay; the next sweep finished the job with nobody touching the event:

20:10:18  Republish sweep: 1 event(s) pending
20:10:19  Published NIP-52 calendar event: f99430fe08388cc0... (kind 31923)
20:10:19  Republish sweep: 1/1 recovered
flag -> 0,  relay: 1790539818 f99430fe0838

On latency — I had this wrong in the first draft

I initially wrote that a relay outage adds up to 12s per paid ticket on the invoice-listener task. The live run shows a disconnected relay is rejected in 230ms, because nostrclient's router short-circuits without touching a socket. The timeout budget only applies when relays are connected but silent, which nostrclient itself bounds at PUBLISH_TIMEOUT_SECONDS = 10.

That narrow case does still stall set_ticket_paid. If it ever matters, the remedy is to stop awaiting on the sale path while leaving the flag set — the sweep already guarantees eventual delivery — not to return to reporting unverified success. Commit message corrected before pushing.

Known and accepted: wait_for_nostr_events sleeps 10s after a dropped socket and nothing drains the receive queue meanwhile, so a publish landing in that window times out and gets flagged. Outcome is correct (the sweep retries), just noisier than necessary.

Testing

81 passed (74 existing + 7 new). The new tests cover accept, reject, timeout, an OK for a different event not settling ours, get_event swallowing OK frames while forwarding everything else, and a disconnect settling in-flight publishes. ruff and black clean on all three files.

No config.json bump — version gets cut on main per the release procedure.

Closes #56 `publish_nostr_event` returned as soon as the EVENT was on the send queue, and the publisher logged `Published` on the next line. Queueing is not delivery — nostrclient drops an EVENT outright when no relay is connected and answers `OK false "error: no relays connected"`. We discarded that reply. That cost a completed repair on cfaun this morning: the #55 sweep republished a 14-day-stale calendar event 21s before nostrclient finished connecting, got `OK false`, logged `Published`, reported `1/1 recovered` and **cleared the pending flag** — leaving the count stale, the row unflagged and the log asserting success. So #55's contract was never true: it claimed to clear only on confirmed success but cleared on confirmed *enqueue*. `publish_nostr_event` now registers a future per event id, awaits the `OK`, and returns whether it was accepted. `publish_event_to_nostr` returns `None` when unconfirmed, which keeps the row flagged for the sweep. Correlation lives in `get_event` — the one place relay messages cross from the websocket thread into the event loop, so there's no cross-thread future juggling. A disconnect settles in-flight publishes immediately rather than making callers wait out the timeout. ## Verified on aio-demo, not just in tests This is a change about the gap between what the code believes and what actually happened, so unit tests can only go so far. Ran it on `aio-demo` (which had the released `v1.6.1-aio.16`, i.e. #54 and #55 but not this) by patching the two files over the installed extension, then restored the originals — md5s confirmed identical to the pre-test values. **Delivery confirmed:** ``` 20:06:44 Republish sweep: 1 event(s) pending 20:06:46 Published NIP-52 calendar event: 0d914b7d9349e790... (kind 31923) 20:06:46 Republish sweep: 1/1 recovered flag 1 -> 0, nostr_event_created_at 1790539604 relay: 1790539604 0d914b7d9349 avail=25 sold=8 ``` `created_at` on the relay matches the DB, so the OK tracked a real delivery rather than merely not timing out. **The cfaun failure, reproduced and now caught.** Removed the relay from nostrclient to force `OK false`: ``` 20:08:42.55 Republish sweep: 1 event(s) pending 20:08:42.78 Relay rejected event fa1d91773e05…: error: no relays connected 20:08:42.78 Relay did not confirm NIP-52 calendar event for eUhCwTTS37p2YgNN4vcUAu 20:08:42.78 Republish sweep: 0/1 recovered flag stayed 1 ``` Under `aio.16` this exact sequence logs `Published`, says `1/1 recovered`, and clears the flag. The relay's own diagnostic now reaches the journal verbatim — `error: no relays connected` is the sentence that would have ended this morning's investigation in seconds. **Recovery closes the loop.** Restored the relay; the next sweep finished the job with nobody touching the event: ``` 20:10:18 Republish sweep: 1 event(s) pending 20:10:19 Published NIP-52 calendar event: f99430fe08388cc0... (kind 31923) 20:10:19 Republish sweep: 1/1 recovered flag -> 0, relay: 1790539818 f99430fe0838 ``` ## On latency — I had this wrong in the first draft I initially wrote that a relay outage adds up to 12s per paid ticket on the invoice-listener task. The live run shows a disconnected relay is rejected in **230ms**, because nostrclient's router short-circuits without touching a socket. The timeout budget only applies when relays are connected but *silent*, which nostrclient itself bounds at `PUBLISH_TIMEOUT_SECONDS = 10`. That narrow case does still stall `set_ticket_paid`. If it ever matters, the remedy is to stop awaiting on the sale path while leaving the flag set — the sweep already guarantees eventual delivery — not to return to reporting unverified success. Commit message corrected before pushing. Known and accepted: `wait_for_nostr_events` sleeps 10s after a dropped socket and nothing drains the receive queue meanwhile, so a publish landing in that window times out and gets flagged. Outcome is correct (the sweep retries), just noisier than necessary. ## Testing `81 passed` (74 existing + 7 new). The new tests cover accept, reject, timeout, an OK for a *different* event not settling ours, `get_event` swallowing OK frames while forwarding everything else, and a disconnect settling in-flight publishes. ruff and black clean on all three files. No `config.json` bump — version gets cut on main per the release procedure.
feat(nostr): confirm publishes against the relay's OK
Some checks failed
lint.yml / feat(nostr): confirm publishes against the relay's OK (pull_request) Failing after 0s
cc730256ab
`publish_nostr_event` returned as soon as the EVENT was on the send
queue, and the publisher logged "Published" on the next line. Queueing
is not delivery: nostrclient drops an EVENT outright when no relay is
connected, answering `OK false "error: no relays connected"`. We threw
that reply away.

On cfaun this cost a completed repair. The #55 sweep republished a
14-day-stale calendar event 21 seconds before nostrclient had finished
connecting to its relay, got `OK false`, logged `Published`, reported
`1/1 recovered` and cleared `nostr_publish_pending` — leaving the count
stale, the row unflagged and the log asserting success. It took a
manual re-arm of the flag to finish the job.

So the flag's contract was never true: it claimed to clear only on a
confirmed success but cleared on a confirmed enqueue.

`publish_nostr_event` now registers a future per event id, awaits the
`OK`, and returns whether it was accepted. `publish_event_to_nostr`
returns None when unconfirmed, which keeps the row flagged so the sweep
retries rather than recording a delivery that never happened.

Correlation lives in `get_event`, the one place relay messages cross
from the websocket thread into the event loop — no cross-thread future
juggling. OK frames are consumed there rather than forwarded; the sync
loop never handled them. A disconnect settles every in-flight publish
immediately instead of making callers wait out the timeout.

On latency: the timeout is not the common cost. A disconnected relay is
rejected by nostrclient's router in milliseconds (230ms measured on
aio-demo), so the 12s budget only applies when relays are connected but
silent, which nostrclient itself bounds at 10s. `set_ticket_paid` runs
on the invoice-listener task, so that narrow case does stall the loop;
if it ever matters, the remedy is to stop awaiting on the sale path
while leaving the flag set — the sweep already guarantees eventual
delivery — not to go back to reporting unverified success.

Closes #56
padreug deleted branch feat/confirm-publish-with-relay-ok 2026-09-27 20:26:58 +00:00
padreug referenced this pull request from a commit 2026-09-27 20:27:44 +00:00
Sign in to join this conversation.
No reviewers
No labels
No milestone
No project
No assignees
1 participant
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
aiolabs/events!58
No description provided.