diff --git a/4bc5-relay-ngit-dev-migration-v2.md b/4bc5-relay-ngit-dev-migration-v2.md index cb8f3e7..c263222 100644 --- a/4bc5-relay-ngit-dev-migration-v2.md +++ b/4bc5-relay-ngit-dev-migration-v2.md @@ -424,6 +424,86 @@ relay.ngit.dev currently runs ngit-relay (reference implementation). We want to - 201 repos need re-sync, many with purgatory context "none" - These events may actually be in purgatory but stuck/unprocessed +### 2026-01-26 [Session 23:30 - CRITICAL: Silent Event Drop During Historic Sync] + +**Investigation of "rarenpubs" Repository:** + +**Repository:** rarenpubs (npub17qvqdrsn93zx93myrprlcu55h9gr0ed6sj7qt99h540mehzhz9ysqh5ymw) +**Status:** complete in prod, missing in archive, purgatory context: "none" + +**What We Discovered:** + +1. **Announcement event (kind 30617) WAS received:** + - First received at 08:58:01.048037Z from wss://relay.ngit.dev + - Received again from relay.damus.io and other relays + - Event ID: 3248b18b9d43a7eb4b23eb9608bd199aa71bc338bedd086a88269dac4cd4096a + - Log location: Line 347636 in `/tmp/ngit-grasp-logs-6h.txt` + +2. **Announcement event was NEVER processed:** + - No "Accepted repository announcement" log entry + - No "Rejected repository announcement" log entry + - Event was silently dropped somewhere in the processing pipeline + +3. **State event (kind 30618) was NEVER received:** + - Makes sense - if announcement isn't processed, system never subscribes to state events + - Event ID: a7c992bc72dcfb82160993a877ba237d2a6682dda9bff0bde7729032930bf3b1 + +4. **Comparison with working events:** + - Other announcements at the same time WERE processed (e.g., "website" repo) + - rarenpubs: complete silence - no accept, no reject + +**Why Manual Republishing Works:** + +When manually republishing via: +```bash +nak req -t d=rarenpubs relay.ngit.dev | nak event ws://localhost:7443 +``` + +The event arrives AFTER the system is fully initialized, so it processes correctly and syncs successfully. + +**Root Cause Hypothesis:** + +Events are being silently dropped during historic sync. Possible causes: +1. **Race condition** during historic sync startup +2. **LMDB deduplication** at database level before application-level processing +3. **Event handler not ready** when events arrive during startup +4. **Async queue loss** between event receipt and processing + +**Implications:** + +This is a **different and more serious issue** than the `expired_events` blacklist: +- The `expired_events` issue affects repos that entered purgatory but expired +- This **silent drop issue** affects repos that never even got processed +- Potentially affects many/most of the ~200 "missing" repos + +**Evidence Location:** +- Log file: `/tmp/ngit-grasp-logs-6h.txt` (166MB, 6 hours of logs) +- Announcement received: Line 347636 (08:58:01.048037Z) +- No processing logs found for this event ID + +**Next Steps:** + +1. **Code path investigation** (architect task - needed): + - Trace event flow from `nostr_relay_pool::relay::inner: Received` to `ngit_grasp::nostr::builder: Accepted/Rejected` + - Identify where events can be silently dropped + - Check LMDB deduplication logic + - Review event handler registration timing + +2. **Validate scope of issue:** + - Check other repos from needs-resync.txt with purgatory context "none" + - Determine how many are affected by silent drop vs expired_events blacklist + - Test manual republishing on a sample set + +3. **Fix strategy:** + - Ensure event handlers are registered before historic sync starts + - Add logging for dropped/deduplicated events + - Consider buffering events during startup until handlers ready + - Fix the `expired_events` persistence issue (separate but related) + +**Two Distinct Issues Identified:** +1. **Silent event drops during historic sync** (this finding - HIGH PRIORITY) +2. **`expired_events` blacklist persisted across restarts** (previous finding - MEDIUM PRIORITY) + ## Key Findings (Analysis Results) **Latest Analysis (2026-01-23, after script fixes):**