v1.2.0 - Schema v11: Added event_json storage for 2500x performance improvement
This commit is contained in:
Your Name
270
tests/bulk_retrieval_test.sh
Executable file
270
tests/bulk_retrieval_test.sh
Executable file
@@ -0,0 +1,270 @@
|
||||
#!/bin/bash
|
||||
# Bulk Event Retrieval Performance Test
|
||||
# Tests retrieving hundreds of events to measure JSON reconstruction performance
|
||||
|
||||
# Load test keys
|
||||
source tests/.test_keys.txt
|
||||
|
||||
RELAY_URL="${RELAY_URL:-ws://localhost:8888}"
|
||||
NUM_EVENTS=500
|
||||
|
||||
# Use test secret keys for creating valid events
|
||||
SECRET_KEYS=(
|
||||
"3fdd8227a920c2385559400b2b14e464f22e80df312a73cc7a86e1d7e91d608f"
|
||||
"a156011cd65b71f84b4a488ac81687f2aed57e490b31c28f58195d787030db60"
|
||||
"1618aaa21f5bd45c5ffede0d9a60556db67d4a046900e5f66b0bae5c01c801fb"
|
||||
)
|
||||
|
||||
echo "=========================================="
|
||||
echo "Bulk Event Retrieval Performance Test"
|
||||
echo "=========================================="
|
||||
echo "Relay: $RELAY_URL"
|
||||
echo "Target: Retrieve $NUM_EVENTS events"
|
||||
echo ""
|
||||
|
||||
# Check if relay is running
|
||||
echo "Checking if relay is running..."
|
||||
if ! nc -z localhost 8888 2>/dev/null; then
|
||||
echo "ERROR: Relay is not running on port 8888"
|
||||
exit 1
|
||||
fi
|
||||
echo "✓ Relay is running"
|
||||
echo ""
|
||||
|
||||
# Check if nak is installed
|
||||
if ! command -v nak &> /dev/null; then
|
||||
echo "ERROR: 'nak' command not found. Please install nak:"
|
||||
echo " go install github.com/fiatjaf/nak@latest"
|
||||
exit 1
|
||||
fi
|
||||
|
||||
# Check current event count in database
|
||||
DB_FILE=$(ls build/*.db 2>/dev/null | head -1)
|
||||
if [ -n "$DB_FILE" ]; then
|
||||
CURRENT_COUNT=$(sqlite3 "$DB_FILE" "SELECT COUNT(*) FROM events WHERE kind=1;" 2>/dev/null || echo "0")
|
||||
echo "Current kind 1 events in database: $CURRENT_COUNT"
|
||||
|
||||
if [ "$CURRENT_COUNT" -ge "$NUM_EVENTS" ]; then
|
||||
echo "✓ Database already has $CURRENT_COUNT events (>= $NUM_EVENTS required)"
|
||||
echo " Skipping event posting..."
|
||||
echo ""
|
||||
else
|
||||
EVENTS_TO_POST=$((NUM_EVENTS - CURRENT_COUNT))
|
||||
echo "Need to post $EVENTS_TO_POST more events..."
|
||||
echo ""
|
||||
|
||||
# Post additional events
|
||||
echo "Posting $EVENTS_TO_POST test events using nak..."
|
||||
for i in $(seq 1 $EVENTS_TO_POST); do
|
||||
# Cycle through secret keys
|
||||
KEY_INDEX=$(( (i - 1) % ${#SECRET_KEYS[@]} ))
|
||||
CURRENT_KEY=${SECRET_KEYS[$KEY_INDEX]}
|
||||
|
||||
# Create content
|
||||
CONTENT="Bulk test event $i/$EVENTS_TO_POST for performance testing"
|
||||
|
||||
# Post event using nak (properly signed)
|
||||
nak event -c "$CONTENT" --sec "$CURRENT_KEY" "$RELAY_URL" >/dev/null 2>&1
|
||||
|
||||
# Progress indicator
|
||||
if [ $((i % 50)) -eq 0 ]; then
|
||||
echo " Posted $i/$EVENTS_TO_POST events..."
|
||||
fi
|
||||
done
|
||||
echo "✓ Posted $EVENTS_TO_POST test events"
|
||||
echo ""
|
||||
fi
|
||||
else
|
||||
echo "WARNING: Could not find database file"
|
||||
echo "Posting $NUM_EVENTS events anyway..."
|
||||
echo ""
|
||||
|
||||
# Post events
|
||||
echo "Posting $NUM_EVENTS test events using nak..."
|
||||
for i in $(seq 1 $NUM_EVENTS); do
|
||||
KEY_INDEX=$(( (i - 1) % ${#SECRET_KEYS[@]} ))
|
||||
CURRENT_KEY=${SECRET_KEYS[$KEY_INDEX]}
|
||||
CONTENT="Bulk test event $i/$NUM_EVENTS for performance testing"
|
||||
nak event -c "$CONTENT" --sec "$CURRENT_KEY" "$RELAY_URL" >/dev/null 2>&1
|
||||
|
||||
if [ $((i % 50)) -eq 0 ]; then
|
||||
echo " Posted $i/$NUM_EVENTS events..."
|
||||
fi
|
||||
done
|
||||
echo "✓ Posted $NUM_EVENTS test events"
|
||||
echo ""
|
||||
fi
|
||||
|
||||
# Wait for events to be stored
|
||||
echo "Waiting 2 seconds for events to be stored..."
|
||||
sleep 2
|
||||
echo ""
|
||||
|
||||
# Test 1: Retrieve 500 events using nak req
|
||||
echo "=========================================="
|
||||
echo "TEST 1: Retrieve $NUM_EVENTS events"
|
||||
echo "=========================================="
|
||||
echo "Sending REQ with limit=$NUM_EVENTS..."
|
||||
echo ""
|
||||
|
||||
START_TIME=$(date +%s%N)
|
||||
|
||||
# Use nak req to retrieve events (properly handles subscription protocol)
|
||||
RESPONSE=$(nak req -k 1 -l $NUM_EVENTS "$RELAY_URL" 2>/dev/null)
|
||||
|
||||
END_TIME=$(date +%s%N)
|
||||
ELAPSED_MS=$(( (END_TIME - START_TIME) / 1000000 ))
|
||||
|
||||
# Count events received (each line is one event)
|
||||
EVENT_COUNT=$(echo "$RESPONSE" | grep -c '^{')
|
||||
|
||||
echo "Results:"
|
||||
echo " Time elapsed: ${ELAPSED_MS}ms"
|
||||
echo " Events received: $EVENT_COUNT"
|
||||
echo ""
|
||||
|
||||
if [ $EVENT_COUNT -ge $((NUM_EVENTS - 10)) ]; then
|
||||
echo "✓ TEST 1 PASSED: Retrieved $EVENT_COUNT events in ${ELAPSED_MS}ms"
|
||||
if [ $ELAPSED_MS -lt 100 ]; then
|
||||
echo " ⚡ EXCELLENT: <100ms for $EVENT_COUNT events!"
|
||||
elif [ $ELAPSED_MS -lt 500 ]; then
|
||||
echo " ✓ GOOD: <500ms for $EVENT_COUNT events"
|
||||
elif [ $ELAPSED_MS -lt 2000 ]; then
|
||||
echo " ⚠ ACCEPTABLE: <2s for $EVENT_COUNT events"
|
||||
else
|
||||
echo " ⚠ SLOW: ${ELAPSED_MS}ms for $EVENT_COUNT events (expected <100ms)"
|
||||
fi
|
||||
else
|
||||
echo "✗ TEST 1 FAILED: Only retrieved $EVENT_COUNT events (expected ~$NUM_EVENTS)"
|
||||
fi
|
||||
echo ""
|
||||
|
||||
# Test 2: Retrieve events by author (use first test key's pubkey)
|
||||
echo "=========================================="
|
||||
echo "TEST 2: Retrieve events by author"
|
||||
echo "=========================================="
|
||||
echo "Sending REQ with authors filter..."
|
||||
echo ""
|
||||
|
||||
# Get pubkey from first secret key
|
||||
TEST_PUBKEY=$(nak key public ${SECRET_KEYS[0]})
|
||||
|
||||
START_TIME=$(date +%s%N)
|
||||
|
||||
RESPONSE=$(nak req -k 1 -a "$TEST_PUBKEY" -l $NUM_EVENTS "$RELAY_URL" 2>/dev/null)
|
||||
|
||||
END_TIME=$(date +%s%N)
|
||||
ELAPSED_MS=$(( (END_TIME - START_TIME) / 1000000 ))
|
||||
|
||||
EVENT_COUNT=$(echo "$RESPONSE" | grep -c '^{')
|
||||
|
||||
echo "Results:"
|
||||
echo " Time elapsed: ${ELAPSED_MS}ms"
|
||||
echo " Events received: $EVENT_COUNT"
|
||||
echo " (Note: Only events from first test key, ~1/3 of total)"
|
||||
echo ""
|
||||
|
||||
if [ $EVENT_COUNT -ge $((NUM_EVENTS / 3 - 20)) ]; then
|
||||
echo "✓ TEST 2 PASSED: Retrieved $EVENT_COUNT events in ${ELAPSED_MS}ms"
|
||||
else
|
||||
echo "⚠ TEST 2 WARNING: Only retrieved $EVENT_COUNT events (expected ~$((NUM_EVENTS / 3)))"
|
||||
fi
|
||||
echo ""
|
||||
|
||||
# Test 3: Retrieve events with time filter
|
||||
echo "=========================================="
|
||||
echo "TEST 3: Retrieve events with time filter"
|
||||
echo "=========================================="
|
||||
echo "Sending REQ with since filter (last hour)..."
|
||||
echo ""
|
||||
|
||||
SINCE_TIME=$(($(date +%s) - 3600))
|
||||
|
||||
START_TIME=$(date +%s%N)
|
||||
|
||||
RESPONSE=$(nak req -k 1 --since "$SINCE_TIME" -l $NUM_EVENTS "$RELAY_URL" 2>/dev/null)
|
||||
|
||||
END_TIME=$(date +%s%N)
|
||||
ELAPSED_MS=$(( (END_TIME - START_TIME) / 1000000 ))
|
||||
|
||||
EVENT_COUNT=$(echo "$RESPONSE" | grep -c '^{')
|
||||
|
||||
echo "Results:"
|
||||
echo " Time elapsed: ${ELAPSED_MS}ms"
|
||||
echo " Events received: $EVENT_COUNT"
|
||||
echo ""
|
||||
|
||||
if [ $EVENT_COUNT -ge $((NUM_EVENTS - 10)) ]; then
|
||||
echo "✓ TEST 3 PASSED: Retrieved $EVENT_COUNT events in ${ELAPSED_MS}ms"
|
||||
else
|
||||
echo "⚠ TEST 3 WARNING: Only retrieved $EVENT_COUNT events (expected ~$NUM_EVENTS)"
|
||||
fi
|
||||
echo ""
|
||||
|
||||
# Test 4: Multiple small retrievals (simulating real-world usage)
|
||||
echo "=========================================="
|
||||
echo "TEST 4: Multiple small retrievals (50 events × 10 times)"
|
||||
echo "=========================================="
|
||||
echo "Simulating real-world client behavior..."
|
||||
echo ""
|
||||
|
||||
TOTAL_TIME=0
|
||||
TOTAL_EVENTS=0
|
||||
for i in $(seq 1 10); do
|
||||
START_TIME=$(date +%s%N)
|
||||
|
||||
RESPONSE=$(nak req -k 1 -l 50 "$RELAY_URL" 2>/dev/null)
|
||||
|
||||
END_TIME=$(date +%s%N)
|
||||
ELAPSED_MS=$(( (END_TIME - START_TIME) / 1000000 ))
|
||||
TOTAL_TIME=$((TOTAL_TIME + ELAPSED_MS))
|
||||
|
||||
EVENT_COUNT=$(echo "$RESPONSE" | grep -c '^{')
|
||||
TOTAL_EVENTS=$((TOTAL_EVENTS + EVENT_COUNT))
|
||||
echo " Request $i: ${ELAPSED_MS}ms ($EVENT_COUNT events)"
|
||||
done
|
||||
|
||||
AVG_TIME=$((TOTAL_TIME / 10))
|
||||
|
||||
echo ""
|
||||
echo "Results:"
|
||||
echo " Total time: ${TOTAL_TIME}ms"
|
||||
echo " Total events: $TOTAL_EVENTS"
|
||||
echo " Average time per request: ${AVG_TIME}ms"
|
||||
echo ""
|
||||
|
||||
if [ $AVG_TIME -lt 50 ]; then
|
||||
echo "✓ TEST 4 PASSED: Average retrieval time ${AVG_TIME}ms (excellent)"
|
||||
elif [ $AVG_TIME -lt 200 ]; then
|
||||
echo "✓ TEST 4 PASSED: Average retrieval time ${AVG_TIME}ms (good)"
|
||||
else
|
||||
echo "⚠ TEST 4 WARNING: Average retrieval time ${AVG_TIME}ms (slow)"
|
||||
fi
|
||||
echo ""
|
||||
|
||||
# Performance Summary
|
||||
echo "=========================================="
|
||||
echo "PERFORMANCE SUMMARY"
|
||||
echo "=========================================="
|
||||
echo ""
|
||||
echo "Expected performance with event_json optimization:"
|
||||
echo " - 366 events: <10ms (previously 18 seconds)"
|
||||
echo " - 500 events: <15ms"
|
||||
echo " - Per-event overhead: ~0.02ms (vs 50ms before)"
|
||||
echo ""
|
||||
|
||||
if [ -n "$DB_FILE" ]; then
|
||||
FINAL_COUNT=$(sqlite3 "$DB_FILE" "SELECT COUNT(*) FROM events WHERE kind=1;" 2>/dev/null || echo "0")
|
||||
echo "Final database stats:"
|
||||
echo " Total kind 1 events: $FINAL_COUNT"
|
||||
echo " Database file: $DB_FILE"
|
||||
echo ""
|
||||
fi
|
||||
|
||||
echo "Check relay logs for [QUERY] entries to see actual query times:"
|
||||
echo " journalctl -u c-relay -n 100 | grep QUERY"
|
||||
echo ""
|
||||
|
||||
echo "=========================================="
|
||||
echo "Test Complete"
|
||||
echo "=========================================="
|
||||
Reference in New Issue
Block a user