fixed up backtest

This commit is contained in:
Boki 2025-07-04 13:05:08 -04:00
parent cbe8f0282c
commit 38a6e73ad5
5 changed files with 77 additions and 231 deletions

Binary file not shown.

View file

@ -184,6 +184,10 @@ impl BacktestEngine {
eprintln!("=== BACKTEST RUN COMPLETE ===");
eprintln!("Total trades: {}", result.trades.len());
eprintln!("Equity points: {}", result.equity.len());
eprintln!("OHLC data symbols: {:?}", result.ohlc_data.keys().collect::<Vec<_>>());
for (symbol, data) in &result.ohlc_data {
eprintln!(" {}: {} bars", symbol, data.len());
}
// Return result as JSON
serde_json::to_string(&result)

View file

@ -43,6 +43,9 @@ pub struct BacktestEngine {
// Store latest bar data for each symbol to ensure accurate closing prices
latest_bars: HashMap<String, crate::Bar>,
// Store all OHLC data processed by the engine
ohlc_history: HashMap<String, Vec<(DateTime<Utc>, crate::Bar)>>,
// Trade tracking
trade_tracker: TradeTracker,
}
@ -75,6 +78,7 @@ impl BacktestEngine {
total_pnl: 0.0,
last_prices: HashMap::new(),
latest_bars: HashMap::new(),
ohlc_history: HashMap::new(),
trade_tracker: TradeTracker::new(),
}
}
@ -84,28 +88,21 @@ impl BacktestEngine {
}
pub async fn run(&mut self) -> Result<BacktestResult, String> {
eprintln!("=== BacktestEngine::run() START ===");
eprintln!("Config: start={}, end={}, symbols={:?}",
self.config.start_time, self.config.end_time, self.config.symbols);
eprintln!("Number of strategies loaded: {}", self.strategies.read().len());
// Initialize start time
if let Some(simulated_time) = self.time_provider.as_any()
.downcast_ref::<crate::core::time_providers::SimulatedTime>()
{
simulated_time.advance_to(self.config.start_time);
eprintln!("Time initialized to: {}", self.config.start_time);
}
// Load market data
eprintln!("Loading market data from data source...");
self.load_market_data().await?;
let queue_len = self.event_queue.read().len();
eprintln!("Event queue length after loading: {}", queue_len);
if queue_len == 0 {
eprintln!("WARNING: No events loaded! Check data source.");
return Err("No market data loaded".to_string());
}
// Main event loop - process events grouped by timestamp
@ -128,11 +125,6 @@ impl BacktestEngine {
let current_time = self.time_provider.now();
let events = self.event_queue.write().pop_until(current_time);
if iteration <= 5 || iteration % 100 == 0 {
eprintln!("Processing iteration {} at time {} with {} events",
iteration, current_time, events.len());
}
// Process all events at this timestamp
for event in events {
self.process_event(event).await?;
@ -150,8 +142,6 @@ impl BacktestEngine {
}
}
eprintln!("Backtest complete. Total trades: {}", self.total_trades);
// Close all open positions at market prices
self.close_all_positions().await?;
@ -160,56 +150,19 @@ impl BacktestEngine {
}
async fn load_market_data(&mut self) -> Result<(), String> {
eprintln!("=== load_market_data START ===");
let mut data_source = self.market_data_source.write();
// Check if it's a HistoricalDataSource
if let Some(historical) = data_source.as_any()
.downcast_ref::<crate::core::market_data_sources::HistoricalDataSource>() {
eprintln!("Data source is HistoricalDataSource");
eprintln!("Historical data points available: {}", historical.data_len());
} else {
eprintln!("WARNING: Data source is NOT HistoricalDataSource!");
}
eprintln!("Seeking to start time: {}", self.config.start_time);
data_source.seek_to_time(self.config.start_time)?;
let mut count = 0;
let mut first_few = 0;
// Load all data into event queue
while let Some(update) = data_source.get_next_update().await {
if update.timestamp > self.config.end_time {
eprintln!("Reached end time at {} data points", count);
break;
}
count += 1;
// Log first few data points
if first_few < 3 {
eprintln!("Data point {}: symbol={}, time={}, type={:?}",
count, update.symbol, update.timestamp,
match &update.data {
MarketDataType::Bar(b) => format!("Bar(close={})", b.close),
MarketDataType::Quote(q) => format!("Quote(bid={}, ask={})", q.bid, q.ask),
MarketDataType::Trade(t) => format!("Trade(price={})", t.price),
}
);
first_few += 1;
}
if count % 100 == 0 {
eprintln!("Loaded {} data points so far...", count);
}
let event = BacktestEvent::market_data(update.timestamp, update);
self.event_queue.write().push(event);
}
eprintln!("=== load_market_data COMPLETE ===");
eprintln!("Total data points loaded: {}", count);
Ok(())
}
@ -238,26 +191,30 @@ impl BacktestEngine {
}
async fn process_market_data(&mut self, data: MarketUpdate) -> Result<(), String> {
static mut MARKET_DATA_COUNT: usize = 0;
unsafe {
MARKET_DATA_COUNT += 1;
if MARKET_DATA_COUNT <= 3 || MARKET_DATA_COUNT % 100 == 0 {
eprintln!("process_market_data #{}: symbol={}, time={}",
MARKET_DATA_COUNT, data.symbol, data.timestamp);
}
}
// Update price tracking - single source of truth
let price = match &data.data {
MarketDataType::Bar(bar) => {
let old_entry = self.last_prices.get(&data.symbol);
let old_price = old_entry.map(|(_, p)| *p);
eprintln!("📊 PRICE UPDATE: {} @ {} - close: ${:.2} (was: ${:?})",
data.symbol, data.timestamp.format("%Y-%m-%d"), bar.close, old_price);
// Log OHLCV data for each tick
eprintln!("[TICK] {} @ {} - O:{:.2} H:{:.2} L:{:.2} C:{:.2} V:{:.0}",
data.symbol,
data.timestamp.format("%Y-%m-%d %H:%M:%S"),
bar.open, bar.high, bar.low, bar.close, bar.volume);
// Store the complete bar data for accurate position closing
self.latest_bars.insert(data.symbol.clone(), bar.clone());
// Store in OHLC history
self.ohlc_history
.entry(data.symbol.clone())
.or_insert_with(Vec::new)
.push((data.timestamp, bar.clone()));
// Debug: Log OHLC history size periodically
let history_len = self.ohlc_history.get(&data.symbol).map(|v| v.len()).unwrap_or(0);
if history_len == 1 || history_len % 100 == 0 {
eprintln!("[DEBUG] OHLC history for {}: {} bars stored", data.symbol, history_len);
}
bar.close
}
MarketDataType::Quote(quote) => {
@ -279,18 +236,14 @@ impl BacktestEngine {
let mut all_signals = Vec::new();
{
let mut strategies = self.strategies.write();
for (i, strategy) in strategies.iter_mut().enumerate() {
for strategy in strategies.iter_mut() {
let signals = strategy.on_market_data(&market_data);
if !signals.is_empty() {
eprintln!("Strategy {} generated {} signals!", i, signals.len());
}
all_signals.extend(signals);
}
}
// Process signals
for signal in all_signals {
eprintln!("Processing signal: {:?}", signal);
self.process_signal(signal).await?;
}
@ -308,31 +261,14 @@ impl BacktestEngine {
}
async fn process_signal(&mut self, signal: Signal) -> Result<(), String> {
let current_time = self.time_provider.now();
eprintln!("📡 SIGNAL at {}: {:?} {} (strength: {}, reason: {:?})",
current_time.format("%Y-%m-%d"),
signal.signal_type,
signal.symbol,
signal.strength,
signal.reason);
// Only process strong signals
if signal.strength.abs() < 0.7 {
eprintln!(" Signal ignored (strength < 0.7)");
return Ok(());
}
// Check current price before creating order
if let Some((price_time, price)) = self.last_prices.get(&signal.symbol) {
eprintln!(" Current price for {}: ${:.2} (from {})",
signal.symbol, price, price_time.format("%Y-%m-%d"));
}
// Convert signal to order
let order = self.signal_to_order(signal)?;
eprintln!(" Creating {:?} order for {} shares", order.side, order.quantity);
// Submit order
self.process_order_submission(order).await
}
@ -409,36 +345,36 @@ impl BacktestEngine {
async fn check_order_fill(&mut self, order: &Order) -> Result<(), String> {
let current_time = self.time_provider.now();
// Get current market price - only use if it's from the current time
// Get current market price
let (price_time, base_price) = self.last_prices.get(&order.symbol)
.copied()
.ok_or_else(|| format!("No price available for symbol: {}", order.symbol))?;
// CRITICAL: Verify the price is from the current time
if price_time != current_time {
eprintln!("⚠️ WARNING: Price timestamp mismatch! Current: {}, Price from: {}",
current_time.format("%Y-%m-%d %H:%M:%S"),
price_time.format("%Y-%m-%d %H:%M:%S"));
// In a real system, we would reject this fill or fetch current price
// For now, log the issue
}
eprintln!("🔍 CHECK_ORDER_FILL: {:?} {} @ time {} - price: ${:.2} (from {})",
order.side, order.symbol, current_time.format("%Y-%m-%d"),
base_price, price_time.format("%Y-%m-%d"));
// DEBUG: Check what's in last_prices for this symbol
eprintln!(" DEBUG: All prices for {}: {:?}",
order.symbol,
self.last_prices.get(&order.symbol));
// Apply slippage
let fill_price = match order.side {
crate::Side::Buy => base_price * (1.0 + self.config.slippage),
crate::Side::Sell => base_price * (1.0 - self.config.slippage),
};
eprintln!(" Fill price after slippage ({}): ${:.2}", self.config.slippage, fill_price);
// Get the OHLC data that was used
let ohlc_info = if let Some(bar) = self.latest_bars.get(&order.symbol) {
format!("O:{:.2} H:{:.2} L:{:.2} C:{:.2}", bar.open, bar.high, bar.low, bar.close)
} else {
"No OHLC data".to_string()
};
// Log trade execution
eprintln!("[TRADE] {} {} {} @ {:.2} | OHLC: {} | Time: {}",
match order.side {
crate::Side::Buy => "BUY",
crate::Side::Sell => "SELL",
},
order.quantity,
order.symbol,
fill_price,
ohlc_info,
current_time.format("%Y-%m-%d %H:%M:%S")
);
// Create fill
let fill = crate::Fill {
@ -511,23 +447,6 @@ impl BacktestEngine {
}
}
let fill_date = fill.timestamp.format("%Y-%m-%d").to_string();
let is_feb_mar_2024 = fill_date >= "2024-02-28".to_string() && fill_date <= "2024-03-05".to_string();
if is_feb_mar_2024 {
eprintln!("
🔴 CRITICAL FILL on {}: {} {} @ {} (side: {:?})",
fill_date, fill.quantity, order.symbol, fill.price, order.side);
eprintln!("Cash before: ${:.2}, Cash after: ${:.2}, Cash change: ${:.2}",
self.state.read().cash - cash_change, self.state.read().cash, cash_change);
}
eprintln!("Fill processed: {} {} @ {} (side: {:?})",
fill.quantity, order.symbol, fill.price, order.side);
eprintln!("Current position after fill: {}",
self.position_tracker.get_position(&order.symbol)
.map(|p| p.quantity)
.unwrap_or(0.0));
// Update metrics
self.total_trades += 1;
@ -560,15 +479,6 @@ impl BacktestEngine {
if old_time < time {
// Update the timestamp to current time, keeping the same price (forward-fill)
self.last_prices.insert(symbol.clone(), (time, price));
// Log only if significant time gap (more than 1 day)
let time_gap = time.signed_duration_since(old_time);
if time_gap.num_days() > 1 {
eprintln!("⏩ Forward-filled {} price ${:.2} from {} to {} (gap: {} days)",
symbol, price,
old_time.format("%Y-%m-%d"),
time.format("%Y-%m-%d"),
time_gap.num_days());
}
}
}
}
@ -578,20 +488,6 @@ impl BacktestEngine {
let positions = self.position_tracker.get_all_positions();
let cash = self.state.read().cash;
let mut portfolio_value = cash;
let current_time = self.time_provider.now();
// Debug logging for first few updates
static mut UPDATE_COUNT: usize = 0;
unsafe {
UPDATE_COUNT += 1;
if UPDATE_COUNT <= 5 || UPDATE_COUNT % 100 == 0 ||
// Log around Feb 28 - Mar 5, 2024
(current_time.format("%Y-%m-%d").to_string() >= "2024-02-28".to_string() &&
current_time.format("%Y-%m-%d").to_string() <= "2024-03-05".to_string()) {
eprintln!("=== Portfolio Update #{} at {} ===", UPDATE_COUNT, current_time);
eprintln!("Cash: ${:.2}", cash);
}
}
for position in &positions {
// Use last known price for the symbol
@ -612,32 +508,6 @@ impl BacktestEngine {
};
portfolio_value += market_value;
unsafe {
if UPDATE_COUNT <= 5 || UPDATE_COUNT % 100 == 0 ||
// Log around Feb 28 - Mar 5, 2024
(current_time.format("%Y-%m-%d").to_string() >= "2024-02-28".to_string() &&
current_time.format("%Y-%m-%d").to_string() <= "2024-03-05".to_string()) {
let pnl = if position.quantity > 0.0 {
(price - position.average_price) * position.quantity
} else {
(position.average_price - price) * position.quantity.abs()
};
let position_type = if position.quantity > 0.0 { "LONG" } else { "SHORT" };
eprintln!(" {} {} position: {} shares @ avg ${:.2}, current ${:.2} = ${:.2} (P&L: ${:.2})",
position_type, position.symbol, position.quantity, position.average_price, price, market_value, pnl);
}
}
}
unsafe {
if UPDATE_COUNT <= 5 || UPDATE_COUNT % 100 == 0 ||
// Log around Feb 28 - Mar 5, 2024
(current_time.format("%Y-%m-%d").to_string() >= "2024-02-28".to_string() &&
current_time.format("%Y-%m-%d").to_string() <= "2024-03-05".to_string()) {
eprintln!("Total Portfolio Value: ${:.2}", portfolio_value);
eprintln!("===================================");
}
}
self.state.write().update_portfolio_value(portfolio_value);
@ -655,12 +525,7 @@ impl BacktestEngine {
let price = self.last_prices.get(symbol)
.map(|(_, p)| *p)
.unwrap_or(100.0);
let shares = (position_value / price).floor();
eprintln!("Position sizing for {}: portfolio=${:.2}, cash=${:.2}, price=${:.2}, shares={}",
symbol, portfolio_value, cash, price, shares);
shares
(position_value / price).floor()
}
fn get_next_event_time(&self) -> Option<DateTime<Utc>> {
@ -671,14 +536,7 @@ impl BacktestEngine {
}
async fn close_all_positions(&mut self) -> Result<(), String> {
eprintln!("=== Closing all open positions at end of backtest ===");
eprintln!("Current time: {}", self.time_provider.now());
eprintln!("Last prices:");
for (symbol, (time, price)) in &self.last_prices {
eprintln!(" {}: ${:.2} (from {})", symbol, price, time.format("%Y-%m-%d %H:%M:%S"));
}
// CRITICAL FIX: Ensure we have the most recent prices for symbols with positions
// Ensure we have the most recent prices for symbols with positions
let current_time = self.time_provider.now();
let positions = self.position_tracker.get_all_positions();
@ -689,35 +547,17 @@ impl BacktestEngine {
if let Some(latest_bar) = self.latest_bars.get(&position.symbol) {
// Use the close price from the latest bar
self.last_prices.insert(position.symbol.clone(), (current_time, latest_bar.close));
eprintln!("Updated {} to latest bar close price: ${:.2}", position.symbol, latest_bar.close);
} else if let Some((price_time, price)) = self.last_prices.get(&position.symbol).copied() {
if price_time < current_time {
eprintln!("⚠️ WARNING: Stale price for {} - last update was {} (current time: {})",
position.symbol,
price_time.format("%Y-%m-%d %H:%M:%S"),
current_time.format("%Y-%m-%d %H:%M:%S")
);
// Update timestamp to current time for proper fill processing
self.last_prices.insert(position.symbol.clone(), (current_time, price));
}
} else {
eprintln!("❌ ERROR: No price data available for symbol {}", position.symbol);
// TODO: In a production system, we should ensure all symbols have continuous price updates
// or implement a mechanism to fetch the latest price on-demand
}
}
}
for position in positions {
if position.quantity.abs() > 0.001 {
let last_price = self.last_prices.get(&position.symbol).map(|(_, p)| *p);
eprintln!("Closing position: {} {} shares of {} at last price: {:?}",
if position.quantity > 0.0 { "Selling" } else { "Buying" },
position.quantity.abs(),
position.symbol,
last_price
);
// Create market order to close position
let order = crate::Order {
id: format!("close_{}", uuid::Uuid::new_v4()),
@ -733,7 +573,6 @@ impl BacktestEngine {
}
}
eprintln!("All positions closed. Final cash: {}", self.state.read().cash);
Ok(())
}
@ -756,6 +595,12 @@ impl BacktestEngine {
.map(|(symbol, (_, price))| (symbol.clone(), *price))
.collect();
// Debug: Log OHLC history size before generating results
eprintln!("[DEBUG] Generating results with OHLC history:");
for (symbol, bars) in &self.ohlc_history {
eprintln!(" {}: {} bars", symbol, bars.len());
}
// Use simple results builder with proper trade data
BacktestResult::from_engine_data_with_trades(
self.config.clone(),
@ -765,6 +610,7 @@ impl BacktestEngine {
final_positions,
start_time,
&simple_last_prices,
&self.ohlc_history,
)
}
}

View file

@ -1,5 +1,6 @@
use chrono::{DateTime, Utc, Datelike};
use serde::{Serialize, Deserialize};
use serde_json;
use std::collections::HashMap;
use crate::Position;
use super::{BacktestConfig, CompletedTrade};
@ -301,6 +302,7 @@ impl BacktestResult {
final_positions: HashMap<String, Position>,
start_time: DateTime<Utc>,
last_prices: &HashMap<String, f64>,
ohlc_history: &HashMap<String, Vec<(DateTime<Utc>, crate::Bar)>>,
) -> Self {
let initial_capital = config.initial_capital;
let final_value = equity_curve.last().map(|(_, v)| *v).unwrap_or(initial_capital);
@ -559,7 +561,23 @@ impl BacktestResult {
analytics,
execution_time: (Utc::now() - start_time).num_milliseconds() as u64,
error: None,
ohlc_data: HashMap::new(),
ohlc_data: {
let mut ohlc_map = HashMap::new();
for (symbol, bars) in ohlc_history {
let ohlc_vec: Vec<serde_json::Value> = bars.iter()
.map(|(timestamp, bar)| serde_json::json!({
"timestamp": timestamp.timestamp_millis(),
"open": bar.open,
"high": bar.high,
"low": bar.low,
"close": bar.close,
"volume": bar.volume,
}))
.collect();
ohlc_map.insert(symbol.clone(), ohlc_vec);
}
ohlc_map
},
}
}
}

View file

@ -92,30 +92,8 @@ export class RustBacktestAdapter extends EventEmitter {
this.container.logger.info('First trade structure:', rustResult.trades[0]);
}
// Store OHLC data for each symbol
const ohlcData: Record<string, any[]> = {};
for (const symbol of config.symbols) {
const bars = await this.storageService.getHistoricalBars(
symbol,
new Date(config.startDate),
new Date(config.endDate),
config.dataFrequency || '1d'
);
ohlcData[symbol] = bars.map(bar => ({
timestamp: bar.timestamp.getTime(),
open: bar.open,
high: bar.high,
low: bar.low,
close: bar.close,
volume: bar.volume,
}));
}
// Rust result is already in the correct format, just add OHLC data
const result: BacktestResult = {
...rustResult,
ohlcData,
};
// Rust result already contains OHLC data from the engine
const result: BacktestResult = rustResult;
this.emit('complete', result);
return result;