foxhunt/docs/testing/WAVE4_DEBUGGING_GUIDE.md

Wave 4 Test Failure Debugging Guide

Version: 1.0 Date: 2025-10-22 Author: Agent W4-5 (Test Documentation Specialist)

---

Quick Reference

# Enable backtrace
RUST_BACKTRACE=1 cargo test failing_test

# Enable full backtrace
RUST_BACKTRACE=full cargo test failing_test

# Enable logging
RUST_LOG=debug cargo test failing_test
RUST_LOG=trading_engine=trace cargo test failing_test

# Run single test
cargo test --lib test_specific_failure -- --nocapture

# Run with debugger
cargo test --no-run failing_test
gdb target/debug/deps/crate_name-HASH

# Check database state
psql postgresql://foxhunt:foxhunt_dev_password@localhost:5432/foxhunt
SELECT * FROM orders WHERE status = 'FAILED';

---

1. Common Test Failures & Fixes

Failure: Connection Refused (os error 111)

Symptom:

thread 'integration::test_grpc_client' panicked at 'Connection refused (os error 111)'

Root Cause: Docker services not running

Fix:

# Start services
docker-compose up -d

# Verify health
docker-compose ps
# Expected: postgres, redis, vault all "healthy"

# Check logs if unhealthy
docker-compose logs postgres
docker-compose logs redis

Failure: Relation Does Not Exist

Symptom:

thread 'test_order_insert' panicked at 'relation "orders" does not exist'

Root Cause: Database migrations not applied

Fix:

# Apply migrations
cargo sqlx migrate run

# Verify migrations
psql postgresql://foxhunt:foxhunt_dev_password@localhost:5432/foxhunt
\dt  # List tables
\d orders  # Describe orders table

# If migrations are corrupted, reset:
docker-compose down -v
docker-compose up -d
cargo sqlx migrate run

Failure: Test Timeout

Symptom:

test test_async_operation has been running for over 60 seconds

Root Cause: Deadlock, infinite loop, or missing await

Debugging:

// Add timeout to test
#[tokio::test]
#[timeout(Duration::from_secs(5))]
async fn test_async_operation() {
    // Test code
}

// Or use tokio::time::timeout
tokio::time::timeout(Duration::from_secs(5), async {
    // Async operation
}).await.expect("Timeout waiting for operation");

Common Causes:

• Missing .await on async function
• Deadlock in mutex/RwLock
• Infinite loop in retry logic
• gRPC client waiting for unavailable service

Failure: Assertion Failed

Symptom:

thread 'test_order_matching' panicked at 'assertion failed: `(left == right)`
  left: `100`,
 right: `99`'

Debugging:

// Add detailed assertion messages
assert_eq!(filled_quantity, expected_quantity,
    "Order fill quantity mismatch: order_id={}, side={:?}, price={}",
    order_id, order.side, order.price
);

// Use assert! with custom message for complex conditions
assert!(
    filled_quantity <= order.quantity,
    "Filled quantity {} exceeds order quantity {}",
    filled_quantity, order.quantity
);

// Use approx for floating point comparisons
use approx::assert_relative_eq;
assert_relative_eq!(actual_price, expected_price, epsilon = 0.01);

Failure: Panic in Drop

Symptom:

thread 'test_resource_cleanup' panicked at 'Panic in Drop: connection pool not cleaned up'

Root Cause: Resource not properly cleaned up

Fix:

// Use Drop guard
struct TestContext {
    db_pool: PgPool,
}

impl Drop for TestContext {
    fn drop(&mut self) {
        // Cleanup
        let _ = self.db_pool.close();  // Ignore errors in Drop
    }
}

// Or use scopeguard
use scopeguard::defer;

#[tokio::test]
async fn test_with_cleanup() {
    let pool = create_pool().await;
    defer! {
        let _ = pool.close();
    }
    // Test code
}

---

2. Database State Inspection

Check Order State

-- View all orders
SELECT * FROM orders ORDER BY created_at DESC LIMIT 10;

-- Check failed orders
SELECT * FROM orders WHERE status = 'FAILED';

-- Check order fills
SELECT o.order_id, o.symbol, o.quantity,
       SUM(f.quantity) as filled_quantity
FROM orders o
LEFT JOIN order_fills f ON o.order_id = f.order_id
GROUP BY o.order_id, o.symbol, o.quantity;

-- Check positions
SELECT * FROM positions WHERE symbol = 'ES.FUT';

-- Check regime state (Wave D)
SELECT * FROM regime_states ORDER BY timestamp DESC LIMIT 1;
SELECT * FROM regime_transitions ORDER BY timestamp DESC LIMIT 10;

Check Database Locks

-- View active locks
SELECT pid, usename, pg_blocking_pids(pid) as blocked_by, query
FROM pg_stat_activity
WHERE cardinality(pg_blocking_pids(pid)) > 0;

-- Kill blocking query
SELECT pg_terminate_backend(pid) FROM pg_stat_activity WHERE pid = 12345;

Reset Test Database

# Drop and recreate
psql postgresql://foxhunt:foxhunt_dev_password@localhost:5432/postgres
DROP DATABASE IF EXISTS foxhunt_test;
CREATE DATABASE foxhunt_test;
\c foxhunt_test
# Run migrations
cargo sqlx migrate run --database-url postgresql://foxhunt:foxhunt_dev_password@localhost:5432/foxhunt_test

---

3. gRPC Request/Response Debugging

Enable gRPC Logging

# Enable tonic logs
RUST_LOG=tonic=debug,tower=debug cargo test test_grpc_streaming

Inspect gRPC Messages

use tonic::{Request, Response, Status};
use tracing::info;

#[tonic::async_trait]
impl TradingService for MyTradingService {
    async fn submit_order(
        &self,
        request: Request<SubmitOrderRequest>,
    ) -> Result<Response<SubmitOrderResponse>, Status> {
        // Log incoming request
        info!("Received request: {:?}", request.get_ref());

        let result = self.process_order(request.into_inner()).await;

        // Log outgoing response
        info!("Sending response: {:?}", result);

        result.map(Response::new)
    }
}

Test gRPC Client Directly

#[tokio::test]
async fn test_grpc_client_connection() {
    let channel = Channel::from_static("http://localhost:50052")
        .connect()
        .await
        .expect("Failed to connect");

    let mut client = TradingServiceClient::new(channel);

    let request = Request::new(SubmitOrderRequest {
        symbol: "ES.FUT".to_string(),
        side: "BUY".to_string(),
        quantity: 10,
        price: 4500.0,
    });

    match client.submit_order(request).await {
        Ok(response) => println!("Response: {:?}", response.into_inner()),
        Err(e) => panic!("gRPC error: {:?}", e),
    }
}

---

4. Async Test Debugging

Common Async Issues

Issue: Test hangs indefinitely

Diagnosis:

// Add timeout to all async operations
use tokio::time::{timeout, Duration};

#[tokio::test]
async fn test_async_operation() {
    let result = timeout(Duration::from_secs(5), async {
        // Async operation that might hang
        some_async_function().await
    }).await;

    match result {
        Ok(value) => assert_eq!(value, expected),
        Err(_) => panic!("Operation timed out after 5 seconds"),
    }
}

Issue: Tokio runtime not available

Fix:

// Use #[tokio::test] instead of #[test]
#[tokio::test]
async fn test_async_function() {
    // Async test code
}

// Or explicitly create runtime
#[test]
fn test_with_runtime() {
    let rt = tokio::runtime::Runtime::new().unwrap();
    rt.block_on(async {
        // Async test code
    });
}

Issue: Task spawned but never awaited

Fix:

// Bad: Task spawned but result ignored
tokio::spawn(async {
    some_async_operation().await;
});

// Good: Await task completion
let handle = tokio::spawn(async {
    some_async_operation().await
});
handle.await.unwrap();

---

5. Race Condition Debugging

Detect Race Conditions

# Run test repeatedly to trigger race
for i in {1..100}; do
    cargo test test_concurrent_access || break
done

# Use thread sanitizer (nightly Rust)
RUSTFLAGS="-Z sanitizer=thread" cargo +nightly test test_concurrent_access

Common Race Patterns

Race in Shared State:

// Bad: Race condition
use std::sync::Arc;

struct Counter {
    value: usize,  // Not atomic!
}

// Good: Use atomic or mutex
use std::sync::atomic::{AtomicUsize, Ordering};

struct Counter {
    value: AtomicUsize,
}

impl Counter {
    fn increment(&self) {
        self.value.fetch_add(1, Ordering::SeqCst);
    }
}

Race in Test Cleanup:

// Bad: Cleanup happens before test finishes
#[tokio::test]
async fn test_cleanup_race() {
    let resource = setup_resource().await;
    tokio::spawn(async move {
        use_resource(resource).await;
    });
    // Test ends, resource dropped before spawn completes
}

// Good: Await task completion
#[tokio::test]
async fn test_cleanup_safe() {
    let resource = Arc::new(setup_resource().await);
    let handle = tokio::spawn({
        let resource = resource.clone();
        async move {
            use_resource(resource).await
        }
    });
    handle.await.unwrap();
}

---

6. Memory Leak Investigation

Detect Memory Leaks

# Use valgrind (Linux)
cargo build --bin trading_service
valgrind --leak-check=full target/debug/trading_service

# Use heaptrack (Linux)
heaptrack target/debug/trading_service

# Use instruments (macOS)
instruments -t Leaks target/debug/trading_service

Common Leak Patterns

Reference Cycles:

// Bad: Reference cycle prevents cleanup
struct Node {
    next: Option<Rc<Node>>,
    prev: Option<Rc<Node>>,  // Cycle!
}

// Good: Use Weak for back-references
struct Node {
    next: Option<Rc<Node>>,
    prev: Option<Weak<Node>>,  // No cycle
}

Async Tasks Not Awaited:

// Bad: Spawned task never completes
tokio::spawn(async {
    loop {
        tokio::time::sleep(Duration::from_secs(1)).await;
    }
});

// Good: Use timeout or cancellation
let handle = tokio::spawn(async {
    // Task logic
});
tokio::time::timeout(Duration::from_secs(10), handle).await;

---

7. Test Data Issues

Stale Test Data

# Clear test data cache
rm -rf test_data/*.cache
rm -rf test_data/*.db

# Re-download test data
./scripts/download_test_data.sh

Corrupted Test Data

# Verify Parquet files
parquet-tools meta test_data/ES_FUT_180d.parquet
parquet-tools schema test_data/ES_FUT_180d.parquet

# Verify DBN files
databento inspect test_data/ES.FUT.dbn

---

8. CI/CD Test Failures

GitHub Actions Debugging

# Add debug logs to workflow
- name: Run tests with debug logs
  run: RUST_LOG=debug cargo test --workspace
  env:
    RUST_BACKTRACE: full

Download CI Artifacts

# Download test logs from GitHub Actions
gh run download <run-id>
cat test-logs/cargo-test.log

---

9. Performance Test Failures

Benchmark Regression

# Compare benchmarks
cargo bench --bench order_matching_latency -- --save-baseline before
# Make changes
cargo bench --bench order_matching_latency -- --baseline before

Profiling Slow Tests

# Use flamegraph
cargo install flamegraph
cargo flamegraph --test integration_slow_test

# Use perf (Linux)
perf record --call-graph=dwarf cargo test integration_slow_test
perf report

---

Last Updated: 2025-10-22