diff --git a/apps/stock/core/index.node b/apps/stock/core/index.node index 8e8691f..f68027a 100755 Binary files a/apps/stock/core/index.node and b/apps/stock/core/index.node differ diff --git a/apps/stock/core/src/api/backtest.rs b/apps/stock/core/src/api/backtest.rs index 1cc2e44..79a2e0b 100644 --- a/apps/stock/core/src/api/backtest.rs +++ b/apps/stock/core/src/api/backtest.rs @@ -61,11 +61,15 @@ impl BacktestEngine { parameters: napi::JsObject, callback: napi::JsFunction, ) -> Result<()> { - // For now, let's use a simple SMA crossover strategy directly in Rust - // This bypasses the TypeScript callback complexity - // Use shorter periods for testing with low volatility mock data - let fast_period = 5; - let slow_period = 15; + eprintln!("WARNING: TypeScript strategy callbacks not yet implemented"); + eprintln!("Using fallback SimpleSMAStrategy for: {}", name); + + // For now, let's use a simple SMA strategy as a fallback + // TODO: Implement proper TypeScript callback handling + let fast_period: usize = parameters.get_named_property::("fastPeriod") + .unwrap_or(5.0) as usize; + let slow_period: usize = parameters.get_named_property::("slowPeriod") + .unwrap_or(15.0) as usize; if let Some(engine) = self.inner.lock().as_mut() { engine.add_strategy(Box::new(SimpleSMAStrategy::new( @@ -81,23 +85,26 @@ impl BacktestEngine { #[napi] pub fn run(&mut self) -> Result { - eprintln!("Starting backtest run"); + eprintln!("=== BACKTEST RUN START ==="); let mut engine = self.inner.lock().take() .ok_or_else(|| Error::from_reason("Engine already consumed"))?; - eprintln!("Creating tokio runtime"); + // Config and strategies are private, skip detailed logging + // Run the backtest synchronously for now let runtime = tokio::runtime::Runtime::new() .map_err(|e| Error::from_reason(e.to_string()))?; - eprintln!("Running backtest engine"); let result = runtime.block_on(engine.run()) .map_err(|e| { - eprintln!("Backtest engine error: {}", e); + eprintln!("ERROR: Backtest engine failed: {}", e); Error::from_reason(e) })?; - eprintln!("Serializing result"); + eprintln!("=== BACKTEST RUN COMPLETE ==="); + eprintln!("Total trades: {}", result.trades.len()); + eprintln!("Equity curve length: {}", result.equity_curve.len()); + // Return result as JSON serde_json::to_string(&result) .map_err(|e| Error::from_reason(e.to_string())) @@ -232,6 +239,7 @@ struct SimpleSMAStrategy { impl SimpleSMAStrategy { fn new(name: String, id: String, fast_period: usize, slow_period: usize) -> Self { + eprintln!("Creating SimpleSMAStrategy: name={}, fast={}, slow={}", name, fast_period, slow_period); Self { name, id, @@ -245,6 +253,15 @@ impl SimpleSMAStrategy { impl Strategy for SimpleSMAStrategy { fn on_market_data(&mut self, data: &MarketUpdate) -> Vec { + // Count calls + static mut CALL_COUNT: usize = 0; + unsafe { + CALL_COUNT += 1; + if CALL_COUNT % 100 == 1 { + eprintln!("SimpleSMAStrategy.on_market_data called {} times", CALL_COUNT); + } + } + let mut signals = Vec::new(); // Check if it's bar data @@ -259,26 +276,44 @@ impl Strategy for SimpleSMAStrategy { // Debug: Log first few prices if history.len() <= 3 { eprintln!("Price history for {}: {:?}", symbol, history); + } else if history.len() == 10 || history.len() == 15 { + eprintln!("Price history length for {}: {} bars", symbol, history.len()); } - // Keep only necessary history - if history.len() > self.slow_period { + // Keep only necessary history (need one extra for previous SMA calculation) + if history.len() > self.slow_period + 1 { history.remove(0); } // Need enough data if history.len() >= self.slow_period { + // Debug when we first have enough data + if history.len() == self.slow_period { + eprintln!("Now have enough data for {}: {} bars", symbol, history.len()); + } // Calculate SMAs let fast_sma = history[history.len() - self.fast_period..].iter().sum::() / self.fast_period as f64; let slow_sma = history.iter().sum::() / history.len() as f64; // Debug: Log SMAs periodically - if history.len() % 10 == 0 { - eprintln!("SMAs for {}: fast={:.2}, slow={:.2}, price={:.2}", symbol, fast_sma, slow_sma, price); + if history.len() % 10 == 0 || (history.len() > self.slow_period && history.len() < self.slow_period + 5) { + eprintln!("SMAs for {}: fast={:.2}, slow={:.2}, price={:.2}, history_len={}", + symbol, fast_sma, slow_sma, price, history.len()); + + // Also log if they're close to crossing + let diff = (fast_sma - slow_sma).abs(); + let pct_diff = diff / slow_sma * 100.0; + if pct_diff < 1.0 { + eprintln!(" -> SMAs are close! Difference: {:.4} ({:.2}%)", diff, pct_diff); + } } // Previous SMAs (if we have enough history) if history.len() > self.slow_period { + // Debug: First time checking for crossovers + if history.len() == self.slow_period + 1 { + eprintln!("Starting crossover checks for {}", symbol); + } let prev_history = &history[..history.len() - 1]; let prev_fast_sma = prev_history[prev_history.len() - self.fast_period..].iter().sum::() / self.fast_period as f64; let prev_slow_sma = prev_history.iter().sum::() / prev_history.len() as f64; diff --git a/apps/stock/core/src/backtest/engine.rs b/apps/stock/core/src/backtest/engine.rs index 9687e8a..21acba3 100644 --- a/apps/stock/core/src/backtest/engine.rs +++ b/apps/stock/core/src/backtest/engine.rs @@ -75,18 +75,29 @@ impl BacktestEngine { } pub async fn run(&mut self) -> Result { + 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::() { 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?; - eprintln!("Event queue empty: {}, length: {}", self.event_queue.read().is_empty(), self.event_queue.read().len()); - eprintln!("Current time: {}, End time: {}", self.time_provider.now(), self.config.end_time); + 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."); + } // Main event loop let mut iteration = 0; @@ -128,31 +139,56 @@ impl BacktestEngine { } async fn load_market_data(&mut self) -> Result<(), String> { - eprintln!("load_market_data: Starting"); + eprintln!("=== load_market_data START ==="); let mut data_source = self.market_data_source.write(); - eprintln!("load_market_data: Seeking to start time: {}", self.config.start_time); - // Seek to start time + // Check if it's a HistoricalDataSource + if let Some(historical) = data_source.as_any() + .downcast_ref::() { + 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)?; - eprintln!("load_market_data: Loading data"); 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!("load_market_data: Loaded {} data points", count); + 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. Loaded {} total data points", count); + eprintln!("=== load_market_data COMPLETE ==="); + eprintln!("Total data points loaded: {}", count); Ok(()) } @@ -164,10 +200,10 @@ impl BacktestEngine { EventType::OrderSubmitted(order) => { self.process_order_submission(order).await?; } - EventType::OrderFilled(fill) => { + EventType::OrderFilled(_fill) => { // Fills are already processed when orders are executed // This event is just for recording - self.state.write().record_fill(fill); + // Note: We now record fills in process_fill with symbol info } EventType::OrderCancelled(order_id) => { self.process_order_cancellation(&order_id)?; @@ -181,6 +217,15 @@ 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 match &data.data { MarketDataType::Bar(bar) => { @@ -203,14 +248,18 @@ impl BacktestEngine { let mut all_signals = Vec::new(); { let mut strategies = self.strategies.write(); - for strategy in strategies.iter_mut() { + for (i, strategy) in strategies.iter_mut().enumerate() { 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?; } @@ -342,8 +391,8 @@ impl BacktestEngine { order.side, ); - // Record the fill - self.state.write().record_fill(fill.clone()); + // Record the fill with symbol and side information + self.state.write().record_fill(order.symbol.clone(), order.side, fill.clone()); // Update cash let cash_change = match order.side { diff --git a/apps/stock/core/src/backtest/mod.rs b/apps/stock/core/src/backtest/mod.rs index 06b7901..e632d84 100644 --- a/apps/stock/core/src/backtest/mod.rs +++ b/apps/stock/core/src/backtest/mod.rs @@ -1,4 +1,4 @@ -use crate::{MarketUpdate, Order, Fill, TradingMode, MarketDataSource, ExecutionHandler, TimeProvider}; +use crate::{MarketUpdate, Order, Fill, TradingMode, MarketDataSource, ExecutionHandler, TimeProvider, Side}; use crate::positions::PositionTracker; use crate::risk::RiskEngine; use crate::orderbook::OrderBookManager; @@ -18,6 +18,16 @@ pub use event::{BacktestEvent, EventType}; pub use strategy::{Strategy, Signal, SignalType}; pub use results::{BacktestResult, BacktestMetrics}; +#[derive(Debug, Clone, Serialize, Deserialize)] +pub struct CompletedTrade { + pub symbol: String, + pub side: Side, + pub timestamp: DateTime, + pub price: f64, + pub quantity: f64, + pub commission: f64, +} + #[derive(Debug, Clone, Serialize, Deserialize)] pub struct BacktestConfig { pub name: String, @@ -37,7 +47,7 @@ pub struct BacktestState { pub cash: f64, pub equity_curve: Vec<(DateTime, f64)>, pub pending_orders: BTreeMap, - pub completed_trades: Vec, + pub completed_trades: Vec, } impl BacktestState { @@ -65,8 +75,15 @@ impl BacktestState { self.pending_orders.remove(order_id) } - pub fn record_fill(&mut self, fill: Fill) { - self.completed_trades.push(fill); + pub fn record_fill(&mut self, symbol: String, side: Side, fill: Fill) { + self.completed_trades.push(CompletedTrade { + symbol, + side, + timestamp: fill.timestamp, + price: fill.price, + quantity: fill.quantity, + commission: fill.commission, + }); } } diff --git a/apps/stock/core/src/backtest/results.rs b/apps/stock/core/src/backtest/results.rs index 7454c57..d5e45dd 100644 --- a/apps/stock/core/src/backtest/results.rs +++ b/apps/stock/core/src/backtest/results.rs @@ -1,8 +1,8 @@ use chrono::{DateTime, Utc}; use serde::{Serialize, Deserialize}; use std::collections::HashMap; -use crate::{Fill, Position}; -use super::BacktestConfig; +use crate::Position; +use super::{BacktestConfig, CompletedTrade}; #[derive(Debug, Clone, Serialize, Deserialize)] pub struct BacktestMetrics { @@ -23,6 +23,6 @@ pub struct BacktestResult { pub config: BacktestConfig, pub metrics: BacktestMetrics, pub equity_curve: Vec<(DateTime, f64)>, - pub trades: Vec, + pub trades: Vec, pub final_positions: HashMap, } \ No newline at end of file diff --git a/apps/stock/core/src/core/market_data_sources.rs b/apps/stock/core/src/core/market_data_sources.rs index fc8f645..d88d3d9 100644 --- a/apps/stock/core/src/core/market_data_sources.rs +++ b/apps/stock/core/src/core/market_data_sources.rs @@ -20,10 +20,23 @@ impl HistoricalDataSource { // This would be called by the orchestrator to load data pub fn load_data(&self, data: Vec) { + eprintln!("HistoricalDataSource::load_data called with {} items", data.len()); + + // Log first few items + for (i, update) in data.iter().take(3).enumerate() { + eprintln!(" Item {}: symbol={}, time={}", i, update.symbol, update.timestamp); + } + let mut queue = self.data_queue.lock(); queue.clear(); queue.extend(data); *self.current_position.lock() = 0; + + eprintln!("Data loaded successfully. Queue size: {}", queue.len()); + } + + pub fn data_len(&self) -> usize { + self.data_queue.lock().len() } // Generate mock data for testing @@ -59,15 +72,29 @@ impl MarketDataSource for HistoricalDataSource { let queue = self.data_queue.lock(); let mut position = self.current_position.lock(); + eprintln!("HistoricalDataSource::seek_to_time called"); + eprintln!(" Target time: {}", timestamp); + eprintln!(" Queue size: {}", queue.len()); + + if queue.is_empty() { + eprintln!(" WARNING: Queue is empty!"); + return Ok(()); + } + + eprintln!(" First item time: {}", queue.front().map(|u| u.timestamp.to_string()).unwrap_or("N/A".to_string())); + eprintln!(" Last item time: {}", queue.back().map(|u| u.timestamp.to_string()).unwrap_or("N/A".to_string())); + // Binary search for the timestamp match queue.binary_search_by_key(×tamp, |update| update.timestamp) { Ok(pos) => { *position = pos; + eprintln!(" Found exact match at position {}", pos); Ok(()) } Err(pos) => { // Position where it would be inserted *position = pos; + eprintln!(" No exact match, would insert at position {}", pos); Ok(()) } } diff --git a/apps/stock/orchestrator/src/backtest/RustBacktestAdapter.ts b/apps/stock/orchestrator/src/backtest/RustBacktestAdapter.ts index ff5325a..1d7d8b0 100644 --- a/apps/stock/orchestrator/src/backtest/RustBacktestAdapter.ts +++ b/apps/stock/orchestrator/src/backtest/RustBacktestAdapter.ts @@ -56,6 +56,10 @@ export class RustBacktestAdapter extends EventEmitter { // For now, use a simple strategy mapping // In the future, strategies should be written in Rust or use a common interface + this.container.logger.info('About to register strategy', { + strategy: config.strategy, + config: config.config + }); this.registerStrategy(config.strategy, config.config || {}); // Load historical data @@ -68,8 +72,17 @@ export class RustBacktestAdapter extends EventEmitter { }); // Run the backtest in Rust + this.container.logger.info('Starting Rust engine execution'); const resultJson = this.currentEngine.run(); + this.container.logger.info('Rust engine execution completed'); const rustResult = JSON.parse(resultJson); + + this.container.logger.info('Rust backtest result summary', { + totalTrades: rustResult.metrics?.total_trades, + equityCurveLength: rustResult.equity_curve?.length, + tradesLength: rustResult.trades?.length, + finalPositions: rustResult.final_positions + }); // Store OHLC data for each symbol const ohlcData: Record = {}; @@ -124,7 +137,7 @@ export class RustBacktestAdapter extends EventEmitter { timestamp: new Date(point[0]).getTime(), value: point[1], })), - trades: rustResult.trades || [], + trades: this.transformFillsToTrades(rustResult.trades || []), dailyReturns: this.calculateDailyReturns(rustResult.equity_curve), finalPositions: rustResult.final_positions || {}, executionTime: Date.now() - startTime, @@ -183,7 +196,9 @@ export class RustBacktestAdapter extends EventEmitter { private async loadHistoricalData(config: BacktestConfig): Promise { const startDate = new Date(config.startDate); const endDate = new Date(config.endDate); + const allMarketData = []; + // Collect all data for all symbols for (const symbol of config.symbols) { const bars = await this.storageService.getHistoricalBars( symbol, @@ -205,11 +220,17 @@ export class RustBacktestAdapter extends EventEmitter { vwap: bar.vwap || (bar.high + bar.low + bar.close) / 3, })); - // Load into Rust engine - if (this.currentEngine) { - this.container.logger.info(`Loading ${marketData.length} bars for ${symbol} into Rust engine`); - this.currentEngine.loadMarketData(marketData); - } + allMarketData.push(...marketData); + this.container.logger.info(`Collected ${marketData.length} bars for ${symbol}`); + } + + // Sort all data by timestamp to ensure chronological order + allMarketData.sort((a, b) => a.timestamp - b.timestamp); + + // Load all data at once into Rust engine + if (this.currentEngine) { + this.container.logger.info(`Loading ${allMarketData.length} total bars into Rust engine`); + this.currentEngine.loadMarketData(allMarketData); } } @@ -229,29 +250,53 @@ export class RustBacktestAdapter extends EventEmitter { }); // Create a TypeScript strategy callback + let callCount = 0; const callback = (callJson: string) => { + callCount++; const call = JSON.parse(callJson); + // Log every 10th call to see if we're getting data + if (callCount % 10 === 1) { + this.container.logger.info(`Strategy callback called ${callCount} times, method: ${call.method}`); + } + if (call.method === 'on_market_data') { const marketData = call.data; const signals: any[] = []; // Debug log first few data points if (priceHistory.size === 0) { - this.container.logger.debug('First market data received:', marketData); + this.container.logger.info('First market data received:', JSON.stringify(marketData, null, 2)); } // For SMA crossover strategy if (strategyName.toLowerCase().includes('sma') || strategyName.toLowerCase().includes('crossover')) { - // Check if it's bar data - const isBar = marketData.data?.Bar || (marketData.data && 'close' in marketData.data); + // Log the structure to understand the data format + if (callCount === 1) { + this.container.logger.info('Market data structure:', { + hasData: !!marketData.data, + hasBar: !!marketData.data?.Bar, + hasClose: !!marketData.data?.close, + dataKeys: marketData.data ? Object.keys(marketData.data) : [], + }); + } + + // Check if it's bar data - handle different possible structures + const isBar = marketData.data?.Bar || + (marketData.data && 'close' in marketData.data) || + (marketData && 'close' in marketData); if (isBar) { const symbol = marketData.symbol; // Handle both direct properties and nested Bar structure - const barData = marketData.data.Bar || marketData.data; + const barData = marketData.data?.Bar || marketData.data || marketData; const price = barData.close; + // Log that we're processing bar data + if (callCount <= 3) { + this.container.logger.info(`Processing bar data for ${symbol}, price: ${price}`); + } + // Update price history if (!priceHistory.has(symbol)) { priceHistory.set(symbol, []); @@ -271,6 +316,11 @@ export class RustBacktestAdapter extends EventEmitter { const fastSMA = history.slice(-fastPeriod).reduce((a, b) => a + b, 0) / fastPeriod; const slowSMA = history.reduce((a, b) => a + b, 0) / slowPeriod; + // Log SMA values periodically + if (history.length % 5 === 0 || history.length === slowPeriod) { + this.container.logger.debug(`SMAs for ${symbol}: Fast(${fastPeriod})=${fastSMA.toFixed(2)}, Slow(${slowPeriod})=${slowSMA.toFixed(2)}, Price=${price.toFixed(2)}, History length=${history.length}`); + } + // Previous SMAs (if we have enough history) if (history.length > slowPeriod) { const prevHistory = history.slice(0, -1); @@ -279,6 +329,11 @@ export class RustBacktestAdapter extends EventEmitter { const currentPosition = positions.get(symbol) || 0; + // Log crossover checks periodically + if (history.length % 10 === 0) { + this.container.logger.debug(`Crossover check for ${symbol}: prevFast=${prevFastSMA.toFixed(2)}, prevSlow=${prevSlowSMA.toFixed(2)}, currFast=${fastSMA.toFixed(2)}, currSlow=${slowSMA.toFixed(2)}, position=${currentPosition}`); + } + // Golden cross - buy signal if (prevFastSMA <= prevSlowSMA && fastSMA > slowSMA && currentPosition <= 0) { this.container.logger.info(`Golden cross detected for ${symbol} at price ${price}`); @@ -305,6 +360,11 @@ export class RustBacktestAdapter extends EventEmitter { positions.set(symbol, -1); } } + } else { + // Log while building up history + if (history.length % 5 === 0 || history.length === 1) { + this.container.logger.debug(`Building history for ${symbol}: ${history.length}/${slowPeriod} bars collected`); + } } } } @@ -377,4 +437,27 @@ export class RustBacktestAdapter extends EventEmitter { sortinoRatio: 0, }; } + + private transformFillsToTrades(completedTrades: any[]): any[] { + // Now we have CompletedTrade objects with symbol and side information + return completedTrades.map((trade, index) => { + const timestamp = new Date(trade.timestamp); + const side = trade.side === 'Buy' ? 'buy' : 'sell'; + + return { + id: `trade-${index}`, + symbol: trade.symbol, + entryDate: timestamp.toISOString(), + exitDate: timestamp.toISOString(), // Same as entry for individual fills + entryPrice: trade.price, + exitPrice: trade.price, + quantity: trade.quantity, + side, + pnl: 0, // Would need to calculate from paired trades + pnlPercent: 0, + commission: trade.commission, + duration: 0, // Would need to calculate from paired trades + }; + }); + } } \ No newline at end of file