issue: update 4bc5 - critical finding: silent event drops during historic sync

This commit is contained in:
DanConwayDev
2026-01-26 15:17:17 +00:00
parent 8c234abe02
commit f8a6d198ee
+80
View File
@@ -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):**