docs: add production sync testing guide and log sanitizer script

Add infrastructure for iterative debugging of sync against production data:
- scripts/sanitize-logs.sh: Truncates verbose log lines for LLM analysis
- docs/how-to/production-sync-testing.md: Step-by-step guide for testing
  sync against real relays, identifying issues, and improving logging
This commit is contained in:
DanConwayDev
2026-01-09 21:41:45 +00:00
parent 5fed2e2f32
commit 6a8346441e
3 changed files with 366 additions and 0 deletions
+12
View File
@@ -36,6 +36,18 @@ How-to guides are **recipes** that show you how to solve specific problems or ac
---
### [Test Sync Against Production Data](production-sync-testing.md)
**Problem:** Debug and improve sync using real-world data
**Difficulty:** Intermediate
**You'll learn:**
- Run sync against production relays
- Sanitize logs for LLM analysis
- Identify common issues and patterns
- Iteratively improve sync behavior
---
## Planned How-To Guides
### Deploy ngit-grasp
+283
View File
@@ -0,0 +1,283 @@
# How-To: Test Sync Against Production Data
**Problem:** Debug and improve sync behavior using real-world data from production relays
**Difficulty:** Intermediate
**Time:** 30 minutes per iteration
## Overview
This guide helps you run ngit-grasp's sync system against production relays to discover unexpected errors, inefficiencies, and edge cases that don't appear in controlled tests.
**Why production testing matters:**
- Real data has inconsistencies, malformed events, and edge cases
- Production relays may behave differently (rate limiting, timeouts, partial NIP-77 support)
- Volume and patterns reveal performance bottlenecks
- Sync discovery leads to cascading subscriptions we can't predict in tests
## Prerequisites
- ngit-grasp compiles successfully (`cargo build`)
- Familiarity with [GRASP-02 Proactive Sync](../explanation/grasp-02-proactive-sync.md)
- Understanding of log levels and tracing
## Test Setup
### 1. Choose a Test Identity
Pick a domain with manageable sync volume. Smaller domains mean fewer repos to sync, making logs tractable.
**Recommended starting point:**
```bash
--domain ngit.danconwaydev.com
```
This domain has few repo announcements listing it, so sync stays manageable.
### 2. Choose a Bootstrap Relay
The bootstrap relay provides the initial set of announcements to discover repos:
```bash
--sync-bootstrap-relay wss://git.shakespeare.diy
```
### 3. Run with Time Limit
Start with short runs (30 seconds) to capture manageable log volumes:
```bash
# Clear any existing data for clean state
rm -rf /tmp/ngit-test-*
# Run for 30 seconds with sanitized output
timeout 30s cargo run -- \
--sync-bootstrap-relay wss://git.shakespeare.diy \
--domain ngit.danconwaydev.com \
--git-path /tmp/ngit-test-git \
--relay-data-path /tmp/ngit-test-relay \
2>&1 | ./scripts/sanitize-logs.sh | tee sync-test.log
```
**Note:** The `timeout` command returns exit code 124, which is expected.
## Log Sanitization
Raw logs include full events and hundreds of event IDs per line, making them unwieldy for analysis. The sanitizer truncates long lines:
```bash
./scripts/sanitize-logs.sh < raw.log > sanitized.log
# Or pipe directly
cargo run -- [args] 2>&1 | ./scripts/sanitize-logs.sh
```
**Options:**
- `--head-chars N` - First N characters to show (default: 100)
- `--tail-chars N` - Last N characters to show (default: 20)
Example output:
```
2024-01-09T10:00:00Z DEBUG sync: Processing events ids=[abc123, def456, ghi789, jkl012...<1847 chars>...xyz999, end123]
```
## What to Look For
### Phase 1: Connection & Bootstrap (0-5 seconds)
**Expected behavior:**
- Connection to bootstrap relay succeeds
- Layer 1 (announcement) subscription starts
- First batch of 30617/30618 events received
**Red flags:**
- Connection timeout or failure
- NIP-77 negentropy errors (should fall back gracefully)
- Immediate rate limiting
### Phase 2: Discovery Cascade (5-15 seconds)
**Expected behavior:**
- Self-subscriber batches fire as announcements are processed
- New relays discovered from announcement `relays` tags
- Layer 2 (repo tags) subscriptions created
**Red flags:**
- Excessive relay discovery (>10 relays rapidly)
- Filter consolidation warnings (>70 filters)
- Missing self-subscriber batch logs
### Phase 3: Steady State (15+ seconds)
**Expected behavior:**
- Historic sync batches completing (EOSE received)
- Periodic health checks running
- Events being saved to database
**Red flags:**
- Pending batches never confirming
- Repeated connection/disconnect cycles
- Memory growth (check with `top` in another terminal)
## Debugging Checklist
When analyzing logs, look for these patterns:
### Errors to Investigate
| Pattern | Possible Cause | Action |
|---------|----------------|--------|
| `error` (any) | Unexpected failure | Investigate immediately |
| `connection failed` | Network/relay issue | Check relay URL, try different relay |
| `rate limit` | Too many requests | Check consolidation, increase backoff |
| `negentropy` + `error` | NIP-77 incompatibility | Should fall back - verify it does |
| `timeout` | Slow relay or large sync | Increase timeouts or reduce scope |
### Warnings to Monitor
| Pattern | Meaning | Action |
|---------|---------|--------|
| `consolidating filters` | Filter count high | Expected, but frequent = problem |
| `backing off` | Health tracker retry | Normal, but watch for excessive |
| `batch failed` | Historic sync incomplete | Check which batches, why |
### Debug Patterns to Verify
| Pattern | What it shows |
|---------|---------------|
| `fresh_start` | Full sync initiated |
| `quick_reconnect` | Incremental sync (<15min gap) |
| `historic sync complete` | Sync finished successfully |
| `sync_live` | Live subscriptions active |
| `PendingBatch` | Items awaiting EOSE confirmation |
## Iterative Improvement Process
### Step 1: Run and Capture
```bash
timeout 30s cargo run -- [args] 2>&1 | ./scripts/sanitize-logs.sh > iteration-1.log
```
### Step 2: Identify Issues
Scan logs for errors and unexpected patterns:
```bash
grep -i error iteration-1.log
grep -i warn iteration-1.log
grep -i panic iteration-1.log
```
### Step 3: Document Findings
Add findings to this file's [Known Issues](#known-issues) section or create GitHub issues.
### Step 4: Fix and Re-test
After code changes, run again to verify the fix.
### Step 5: Extend Duration
Once 30-second runs are clean, extend to 2 minutes, then 5 minutes:
```bash
timeout 120s cargo run -- [args] 2>&1 | ./scripts/sanitize-logs.sh > iteration-2.log
```
## Logging Improvements
If the logs aren't helpful enough, improve them. Common needs:
### Add Context to Existing Logs
```rust
// Before
tracing::debug!("Processing events");
// After
tracing::debug!(
relay = %relay_url,
event_count = events.len(),
"Processing events"
);
```
### Add New Log Points
Key places that may need more logging:
- `src/sync/mod.rs` - SyncManager state transitions
- `src/sync/relay_connection.rs` - Connection lifecycle
- `src/sync/self_subscriber.rs` - Batch processing
### Reduce Noise
If a log line appears too frequently:
```rust
// Change from debug! to trace!
tracing::trace!("Per-event detail that's too noisy");
```
## Known Issues
*Document issues discovered during testing here. Delete this section when empty.*
### Template for New Issues
```markdown
### Issue: [Short description]
**Discovered:** [Date]
**Status:** [Open/Fixed in PR#xxx]
**Symptoms:**
- Log pattern observed
**Root cause:**
- [If known]
**Fix:**
- [If known]
```
---
## Quick Reference
### Minimal Test Command
```bash
timeout 30s cargo run -- \
--sync-bootstrap-relay wss://git.shakespeare.diy \
--domain ngit.danconwaydev.com \
--git-path /tmp/ngit-test-git \
--relay-data-path /tmp/ngit-test-relay \
2>&1 | ./scripts/sanitize-logs.sh
```
### With Metrics Endpoint
```bash
timeout 30s cargo run -- \
--sync-bootstrap-relay wss://git.shakespeare.diy \
--domain ngit.danconwaydev.com \
--git-path /tmp/ngit-test-git \
--relay-data-path /tmp/ngit-test-relay \
--metrics-address 127.0.0.1:9090 \
2>&1 | ./scripts/sanitize-logs.sh
```
Then in another terminal: `curl http://127.0.0.1:9090/metrics`
### Different Log Level
The default is DEBUG. For more detail:
```bash
RUST_LOG=trace cargo run -- [args]
```
For less noise:
```bash
RUST_LOG=info cargo run -- [args]
```
---
*Part of the [ngit-grasp documentation](../README.md) using the [Diátaxis](https://diataxis.fr/) framework.*
+71
View File
@@ -0,0 +1,71 @@
#!/bin/bash
# sanitize-logs.sh - Truncates verbose log lines for LLM analysis
#
# Usage:
# cargo run -- [args] 2>&1 | ./scripts/sanitize-logs.sh
# ./scripts/sanitize-logs.sh < logfile.txt
# ./scripts/sanitize-logs.sh --head-chars 150 --tail-chars 30 < logfile.txt
set -euo pipefail
# Default settings
HEAD_CHARS=100
TAIL_CHARS=20
MAX_LINE_LENGTH=$((HEAD_CHARS + TAIL_CHARS + 20)) # buffer for the ellipsis marker
# Parse arguments
while [[ $# -gt 0 ]]; do
case $1 in
--head-chars)
HEAD_CHARS="$2"
shift 2
;;
--tail-chars)
TAIL_CHARS="$2"
shift 2
;;
--max-line)
MAX_LINE_LENGTH="$2"
shift 2
;;
-h|--help)
echo "Usage: $0 [OPTIONS]"
echo ""
echo "Sanitizes log output for LLM analysis by truncating long lines."
echo "Reads from stdin, writes to stdout."
echo ""
echo "Options:"
echo " --head-chars N Show first N chars of long lines (default: 100)"
echo " --tail-chars N Show last N chars of long lines (default: 20)"
echo " --max-line N Lines shorter than this are unchanged (default: head+tail+20)"
echo " -h, --help Show this help"
echo ""
echo "Examples:"
echo " cargo run -- --sync-bootstrap-relay wss://git.shakespeare.diy 2>&1 | $0"
echo " timeout 30s cargo run -- [args] 2>&1 | $0 > sanitized.log"
exit 0
;;
*)
echo "Unknown option: $1" >&2
exit 1
;;
esac
done
MAX_LINE_LENGTH=$((HEAD_CHARS + TAIL_CHARS + 20))
# Process each line
while IFS= read -r line; do
len=${#line}
if [[ $len -le $MAX_LINE_LENGTH ]]; then
# Short line - pass through unchanged
echo "$line"
else
# Long line - truncate with marker showing omitted char count
head="${line:0:$HEAD_CHARS}"
tail="${line: -$TAIL_CHARS}"
omitted=$((len - HEAD_CHARS - TAIL_CHARS))
echo "${head}...<${omitted} chars>...${tail}"
fi
done