diff --git a/tests/PHASE_3_EXECUTION_LOG.md b/tests/PHASE_3_EXECUTION_LOG.md new file mode 100644 index 00000000..177d85fd --- /dev/null +++ b/tests/PHASE_3_EXECUTION_LOG.md @@ -0,0 +1,201 @@ +# Phase 3: Crash Recovery Test Execution Log + +**Start Date:** 2026-08-03 22:35 KST +**Status:** πŸš€ **IN PROGRESS** +**Parallel with:** Phase 1 (Job 893 running) + +--- + +## πŸ§ͺ **Test Scenario 1: Outbox Message Loss** + +### Setup +- **Objective:** Verify ShadowRunCompletedConsumer recovery from lost outbox messages +- **Method:** Simulate message drop in Outbox table +- **Environment:** Host running, Job 893 active + +### Execution +``` +Step 1: Trigger message loss scenario + β–‘ Identify current outbox message + β–‘ Simulate deletion/loss + β–‘ Verify detection + Status: ⏳ QUEUED + +Step 2: Monitor recovery + β–‘ Watch ShadowRunCompletedConsumer logs + β–‘ Check retry mechanism activation + β–‘ Verify message re-processing + Status: ⏳ QUEUED + +Step 3: Validation + β–‘ No state corruption observed + β–‘ Message eventually processed + β–‘ Logs contain recovery trace + Status: ⏳ QUEUED +``` + +### Result +``` +Status: ⏳ PENDING +Evidence: [logs will be captured] +Outcome: [ ] PASS [ ] FAIL +``` + +--- + +## πŸ§ͺ **Test Scenario 2: PostgreSQL Connection Drop** + +### Setup +- **Objective:** Verify graceful recovery from database disconnection +- **Method:** Simulate connection timeout/reset +- **Environment:** SSH tunnel maintained + +### Execution +``` +Step 1: Trigger connection drop + β–‘ Monitor connection pool + β–‘ Simulate network disconnect + β–‘ Trigger reconnection + Status: ⏳ QUEUED + +Step 2: Monitor recovery + β–‘ Watch connection retry logic + β–‘ Check reconnection attempt + β–‘ Verify query resumption + Status: ⏳ QUEUED + +Step 3: Validation + β–‘ No data loss + β–‘ No duplicate processing + β–‘ Transaction consistency maintained + Status: ⏳ QUEUED +``` + +### Result +``` +Status: ⏳ PENDING +Evidence: [logs will be captured] +Outcome: [ ] PASS [ ] FAIL +``` + +--- + +## πŸ§ͺ **Test Scenario 3: Hangfire Lock Timeout** + +### Setup +- **Objective:** Verify lock timeout recovery (DEBT-015) +- **Method:** Simulate distributed lock contention +- **Environment:** Multiple worker simulation + +### Execution +``` +Step 1: Trigger lock timeout + β–‘ Create lock contention + β–‘ Trigger timeout condition + β–‘ Monitor fallback activation + Status: ⏳ QUEUED + +Step 2: Monitor recovery + β–‘ Verify DEBT-015 fallback mechanism + β–‘ Check job continues without blocking + β–‘ Verify other workers unaffected + Status: ⏳ QUEUED + +Step 3: Validation + β–‘ No deadlock observed + β–‘ Graceful degradation + β–‘ Recovery automatic + Status: ⏳ QUEUED +``` + +### Result +``` +Status: ⏳ PENDING +Evidence: [logs will be captured] +Outcome: [ ] PASS [ ] FAIL +``` + +--- + +## πŸ§ͺ **Test Scenario 4: Inbox Message Processing Failure** + +### Setup +- **Objective:** Verify consumer resilience to processing failures +- **Method:** Simulate deserialization/processing error +- **Environment:** ApprovalQueueConsumer or AuditLogConsumer + +### Execution +``` +Step 1: Trigger processing failure + β–‘ Inject malformed message + β–‘ Trigger deserialization error + β–‘ Monitor error handling + Status: ⏳ QUEUED + +Step 2: Monitor recovery + β–‘ Verify error caught by consumer + β–‘ Check DLQ (Dead Letter Queue) movement + β–‘ Monitor alert generation + Status: ⏳ QUEUED + +Step 3: Validation + β–‘ No data loss + β–‘ Failure logged with context + β–‘ Main pipeline unaffected + Status: ⏳ QUEUED +``` + +### Result +``` +Status: ⏳ PENDING +Evidence: [logs will be captured] +Outcome: [ ] PASS [ ] FAIL +``` + +--- + +## πŸ“Š **Test Summary** + +| Scenario | Status | Duration | Notes | +|----------|--------|----------|-------| +| Outbox Message Loss | ⏳ QUEUED | TBD | Recovery detection test | +| PostgreSQL Drop | ⏳ QUEUED | TBD | Connection retry test | +| Hangfire Lock Timeout | ⏳ QUEUED | TBD | DEBT-015 fallback test | +| Inbox Failure | ⏳ QUEUED | TBD | Consumer resilience test | + +**Overall Status:** πŸš€ **EXECUTION STARTING** + +--- + +## 🎯 **Next Steps** + +1. βœ… **Environment verified** (2026-08-03 22:35 KST) +2. ⏳ **Scenario 1: Outbox Message Loss** (START NOW) +3. ⏳ **Scenario 2: PostgreSQL Drop** (PARALLEL) +4. ⏳ **Scenario 3: Hangfire Lock Timeout** (PARALLEL) +5. ⏳ **Scenario 4: Inbox Failure** (PARALLEL) +6. ⏳ **Evidence compilation** (AFTER ALL SCENARIOS) + +--- + +## πŸ“‹ **Parallel Execution (A + B)** + +``` +PHASE 1 (Background): +└─ Job 893: Running (50-90 days) + └─ Monitor every 5 min (automatic) + +PHASE 3 (Active Now): +β”œβ”€ Scenario 1: Outbox Message Loss +β”œβ”€ Scenario 2: PostgreSQL Drop +β”œβ”€ Scenario 3: Hangfire Lock Timeout +└─ Scenario 4: Inbox Failure + └─ 4 tests running in parallel + └─ Duration: 1-2 hours estimated + └─ Evidence captured per scenario +``` + +--- + +**Status:** πŸš€ **READY TO BEGIN SCENARIO TESTING** + diff --git a/tests/PHASE_3_TEST_PROCEDURES.md b/tests/PHASE_3_TEST_PROCEDURES.md new file mode 100644 index 00000000..d5ff5c60 --- /dev/null +++ b/tests/PHASE_3_TEST_PROCEDURES.md @@ -0,0 +1,245 @@ +# Phase 3: Crash Recovery Test Procedures + +**Document:** Detailed procedures for 4 crash recovery scenarios +**Version:** 2026-08-03 +**Status:** πŸš€ READY TO EXECUTE + +--- + +## πŸ§ͺ **Scenario 1: Outbox Message Loss Recovery** + +### Procedure +``` +1. Identify Current State + β–‘ Connect to PostgreSQL (via SSH tunnel) + β–‘ Query: SELECT id, run_id FROM outbox.outbox LIMIT 1 + β–‘ Note the message ID + +2. Simulate Loss + β–‘ DELETE FROM outbox.outbox WHERE id = + β–‘ Verify deletion: SELECT COUNT(*) FROM outbox.outbox + +3. Trigger Recovery + β–‘ Watch ShadowRunCompletedConsumer logs in Host + β–‘ Monitor log pattern: "outbox message.*not found" + β–‘ Should auto-recover or retry + +4. Verify Results + β–‘ Check if message re-processed + β–‘ No errors in Host logs + β–‘ Outbox state consistent +``` + +### Evidence Capture +``` +- Before: SELECT id, run_id FROM outbox.outbox WHERE id = X +- After: SELECT COUNT(*) FROM outbox.outbox +- Logs: grep "outbox" host.log | tail -50 +``` + +### Pass Criteria +``` +βœ… PASS: Message loss detected, recovery completed, no corruption +❌ FAIL: Unrecovered state divergence or data corruption +``` + +--- + +## πŸ§ͺ **Scenario 2: PostgreSQL Connection Drop** + +### Procedure +``` +1. Baseline State + β–‘ Verify Host can execute queries + β–‘ Check connection pool status + β–‘ Note current connection count + +2. Simulate Connection Drop + β–‘ Terminate SSH tunnel (close terminal or Ctrl+C) + β–‘ Database becomes unreachable + β–‘ Connection pool timeout triggered + +3. Monitor Recovery + β–‘ Watch Host logs for connection error + β–‘ Wait for reconnection attempt + β–‘ SSH tunnel comes back online + β–‘ Connection re-established + +4. Verify Resumption + β–‘ Host queries successful again + β–‘ No hanging requests + β–‘ Transaction consistency maintained +``` + +### Evidence Capture +``` +- Connection logs: grep -i "connection\|timeout\|reconnect" host.log +- Query execution: Monitor query response times +- Timeline: Record startβ†’dropβ†’recovery time +``` + +### Pass Criteria +``` +βœ… PASS: Connection recovered, queries resumed, no data loss +❌ FAIL: Hanging requests, connection pool exhausted, duplicate processing +``` + +--- + +## πŸ§ͺ **Scenario 3: Hangfire Distributed Lock Timeout** + +### Procedure +``` +1. Monitor Hangfire State + β–‘ Check Hangfire dashboard (if available) or logs + β–‘ Note active recurring jobs + β–‘ Verify worker threads + +2. Trigger Lock Contention + β–‘ Multiple Hangfire workers attempt same lock + β–‘ Simulate timeout (>30s acquisition attempt) + β–‘ DEBT-015 fallback mechanism engages + +3. Monitor Behavior + β–‘ Watch Host logs for lock timeout trace + β–‘ Verify: "lock timeout.*fallback" pattern + β–‘ Check that worker continues (no deadlock) + β–‘ Other workers unaffected + +4. Verify Resolution + β–‘ Next job attempt succeeds + β–‘ No stuck locks in DB + β–‘ Logs show recovery +``` + +### Evidence Capture +``` +- Lock logs: grep -i "lock\|timeout\|distributed" host.log +- Job status: SELECT * FROM hangfire.job WHERE StateName IN ('Processing', 'Succeeded') +- Duration: Time from timeout to recovery +``` + +### Pass Criteria +``` +βœ… PASS: Lock timeout detected, DEBT-015 fallback activated, job continues +❌ FAIL: Deadlock, stuck lock, worker hang +``` + +--- + +## πŸ§ͺ **Scenario 4: Inbox Message Processing Failure** + +### Procedure +``` +1. Identify Consumer + β–‘ ApprovalQueueConsumer or AuditLogConsumer + β–‘ Monitor active processing + +2. Inject Malformed Message + β–‘ Insert test message with invalid JSON: + INSERT INTO inbox.inbox (msg_type, payload, created_at, processed_at) + VALUES ('approval', '{"invalid": json}', NOW(), NULL) + β–‘ Trigger consumer to process + +3. Monitor Error Handling + β–‘ Watch Host logs for deserialization error + β–‘ Verify error caught (no unhandled exception crash) + β–‘ Check if moved to DLQ + +4. Verify Impact + β–‘ Consumer continues processing next message + β–‘ No cascade failure + β–‘ Error logged with context +``` + +### Evidence Capture +``` +- Error logs: grep -i "deserialization\|inbox\|error" host.log +- DLQ check: SELECT COUNT(*) FROM inbox.dead_letter_queue +- Message state: SELECT * FROM inbox.inbox WHERE processed_at IS NULL +``` + +### Pass Criteria +``` +βœ… PASS: Error caught, message isolated, consumer continues +❌ FAIL: Cascade failure, consumer crash, message loss +``` + +--- + +## βš™οΈ **Execution Sequence (Parallel)** + +### Option 1: Manual Sequential +``` +Time | Scenario 1 | Scenario 2 | Scenario 3 | Scenario 4 +-----|-----------|-----------|-----------|---------- ++0m | Setup | | | ++5m | Execute | Setup | | ++10m | Verify | Execute | Setup | ++15m | | Verify | Execute | Setup ++20m | | | Verify | Execute ++25m | | | | Verify ++30m | Done | Done | Done | Done +``` + +### Option 2: Parallel (Recommended) +``` +All 4 scenarios execute in parallel +Estimated duration: 15-20 minutes total +Each scenario: 5-7 minutes +``` + +--- + +## πŸ“‹ **Required Prerequisites** + +Before executing tests: + +``` +βœ… Host is running (verified) +βœ… SSH tunnel is open (verified) +βœ… PostgreSQL is accessible (need to verify) +βœ… Job 893 is running (verified) +βœ… All consumer services are deployed (need to verify) +``` + +### Verification Checklist +``` +β–‘ Host logs accessible and monitored +β–‘ PostgreSQL connection working +β–‘ Hangfire workers active +β–‘ Consumer message handlers ready +β–‘ DLQ (Dead Letter Queue) exists +β–‘ Outbox/Inbox tables accessible +``` + +--- + +## πŸ“Š **Evidence Collection Plan** + +After each scenario: +``` +1. Capture logs (PHASE_3_EXECUTION_LOG.md) +2. Record query results +3. Document timeline +4. Note any issues +5. Mark PASS/FAIL +``` + +Final deliverable: +``` +tests/crash_recovery_evidence.md +β”œβ”€ Scenario 1: [PASS/FAIL with evidence] +β”œβ”€ Scenario 2: [PASS/FAIL with evidence] +β”œβ”€ Scenario 3: [PASS/FAIL with evidence] +└─ Scenario 4: [PASS/FAIL with evidence] +``` + +--- + +## πŸš€ **Status** + +**Current:** βœ… Procedures documented, environment verified +**Next:** Execute Scenarios 1-4 +**Estimated Duration:** 15-20 minutes (parallel) or 30 minutes (sequential) +**Target:** Complete Phase 3 testing before Phase 1 (Job 893) finishes