Signed-off-by: TIANHE <TIANHE@GMAIL.COM>
This commit is contained in:
TIANHE
2026-03-01 03:42:10 +08:00
parent 7c067fe61c
commit a6ea4d967c
77 changed files with 3368 additions and 193 deletions
+231 -55
View File
@@ -26,10 +26,10 @@ class BacktestService:
}
# Multi-timeframe backtest threshold configuration
# 1m backtest: max 1 month (~43,200 candles)
# 1m backtest: max 15 days (~21,600 candles) - reduced for performance
# 5m backtest: max 1 year (~105,120 candles)
MTF_CONFIG = {
'max_1m_days': 30, # Max days for 1-minute backtest
'max_1m_days': 15, # Max days for 1-minute backtest (reduced from 30 for performance)
'max_5m_days': 365, # Max days for 5-minute backtest
'default_exec_tf': '1m', # Default execution timeframe
'fallback_exec_tf': '5m', # Fallback execution timeframe
@@ -79,7 +79,7 @@ class BacktestService:
}
if days_diff <= self.MTF_CONFIG['max_1m_days']:
# Within 1 month: use 1-minute precision
# Within 15 days: use 1-minute precision
estimated_candles = days_diff * 24 * 60
return '1m', {
'enabled': True,
@@ -90,7 +90,7 @@ class BacktestService:
'message': f'Using 1-minute precision backtest (~{estimated_candles:,} candles)'
}
elif days_diff <= self.MTF_CONFIG['max_5m_days']:
# 1 month to 1 year: use 5-minute precision
# 15 days to 1 year: use 5-minute precision
estimated_candles = days_diff * 24 * 12
return '5m', {
'enabled': True,
@@ -98,7 +98,7 @@ class BacktestService:
'days': days_diff,
'estimated_candles': estimated_candles,
'precision': 'medium',
'message': f'Range exceeds 30 days, using 5-minute precision (~{estimated_candles:,} candles)'
'message': f'Range exceeds {self.MTF_CONFIG["max_1m_days"]} days, using 5-minute precision (~{estimated_candles:,} candles)'
}
else:
# Over 1 year: high-precision backtest not supported
@@ -192,9 +192,12 @@ class BacktestService:
'trade_direction': trade_direction
}
signals = self._execute_indicator(indicator_code, df_signal, backtest_params)
logger.info(f"Signals generated: {list(signals.keys()) if isinstance(signals, dict) else type(signals)}")
# 3. Fetch execution timeframe candles (for precise trade simulation)
logger.info(f"Fetching execution timeframe data: {exec_tf} for {market}:{symbol}")
df_exec = self._fetch_kline_data(market, symbol, exec_tf, start_date, end_date)
logger.info(f"Execution timeframe data fetched: {len(df_exec)} candles")
if df_exec.empty:
logger.warning(f"Cannot fetch {exec_tf} candles, falling back to standard backtest")
result = self.run(
@@ -221,7 +224,9 @@ class BacktestService:
logger.info(f"Data fetched: signal_candles={len(df_signal)}, exec_candles={len(df_exec)}")
# 4. Use execution timeframe for precise trade simulation
equity_curve, trades, total_commission = self._simulate_trading_mtf(
try:
logger.info("Starting MTF trading simulation...")
equity_curve, trades, total_commission = self._simulate_trading_mtf(
df_signal=df_signal,
df_exec=df_exec,
signals=signals,
@@ -231,19 +236,38 @@ class BacktestService:
leverage=leverage,
trade_direction=trade_direction,
strategy_config=strategy_config,
signal_timeframe=timeframe,
exec_timeframe=exec_tf
)
signal_timeframe=timeframe,
exec_timeframe=exec_tf
)
logger.info(f"MTF simulation completed: {len(trades)} trades executed")
except Exception as e:
logger.error(f"MTF simulation failed: {str(e)}")
logger.error(traceback.format_exc())
raise
# 5. Calculate metrics
metrics = self._calculate_metrics(equity_curve, trades, initial_capital, timeframe, start_date, end_date, total_commission)
try:
logger.info(f"Calculating metrics: equity_curve_len={len(equity_curve)}, trades_len={len(trades)}, initial_capital={initial_capital}")
metrics = self._calculate_metrics(equity_curve, trades, initial_capital, timeframe, start_date, end_date, total_commission)
logger.info(f"Metrics calculated successfully: {list(metrics.keys())}")
except Exception as e:
logger.error(f"Failed to calculate metrics: {str(e)}")
logger.error(traceback.format_exc())
raise
# 6. Format result
result = self._format_result(metrics, equity_curve, trades)
result['precision_info'] = precision_info
result['execution_timeframe'] = exec_tf
result['signal_candles'] = len(df_signal)
result['execution_candles'] = len(df_exec)
try:
logger.info("Formatting backtest result...")
result = self._format_result(metrics, equity_curve, trades)
result['precision_info'] = precision_info
result['execution_timeframe'] = exec_tf
result['signal_candles'] = len(df_signal)
result['execution_candles'] = len(df_exec)
logger.info("Backtest result formatted successfully")
except Exception as e:
logger.error(f"Failed to format result: {str(e)}")
logger.error(traceback.format_exc())
raise
return result
@@ -267,6 +291,11 @@ class BacktestService:
Simulates trades candle by candle on execution timeframe,
using inferred candle price path to determine trigger order.
"""
try:
logger.info(f"Entering _simulate_trading_mtf: df_signal={len(df_signal)}, df_exec={len(df_exec)}, signals_type={type(signals)}")
except Exception as e:
logger.error(f"Error in _simulate_trading_mtf entry logging: {e}")
equity_curve = []
trades = []
total_commission_paid = 0.0
@@ -342,19 +371,38 @@ class BacktestService:
norm_signals = signals
norm_signals['_both_mode'] = False # Explicit 4-signal mode, not both mode
elif all(k in signals for k in ['buy', 'sell']):
buy = signals['buy'].fillna(False).astype(bool)
sell = signals['sell'].fillna(False).astype(bool)
# Ensure signals have the same index as df_signal
buy_series = signals['buy']
sell_series = signals['sell']
# Reindex to match df_signal.index (fill missing with False)
if not buy_series.index.equals(df_signal.index):
logger.warning(f"Buy signal index mismatch! Signal index: {buy_series.index[:5].tolist()}, df_signal index: {df_signal.index[:5].tolist()}")
buy_series = buy_series.reindex(df_signal.index, fill_value=False)
if not sell_series.index.equals(df_signal.index):
logger.warning(f"Sell signal index mismatch! Signal index: {sell_series.index[:5].tolist()}, df_signal index: {df_signal.index[:5].tolist()}")
sell_series = sell_series.reindex(df_signal.index, fill_value=False)
buy = buy_series.fillna(False).astype(bool)
sell = sell_series.fillna(False).astype(bool)
# Debug: log signal statistics
buy_count = buy.sum()
sell_count = sell.sum()
logger.info(f"Signal statistics: buy={buy_count}, sell={sell_count}, total_candles={len(df_signal)}")
td = str(trade_direction or 'both').lower()
logger.info(f"Trade direction: {td} (original: {trade_direction})")
if td == 'long':
norm_signals = {
'open_long': buy, 'close_long': sell,
'open_short': pd.Series([False] * len(df_signal), index=df_signal.index),
'close_short': pd.Series([False] * len(df_signal), index=df_signal.index),
'open_short': pd.Series([False] * len(df_signal), index=df_signal.index, dtype=bool),
'close_short': pd.Series([False] * len(df_signal), index=df_signal.index, dtype=bool),
}
elif td == 'short':
norm_signals = {
'open_long': pd.Series([False] * len(df_signal), index=df_signal.index),
'close_long': pd.Series([False] * len(df_signal), index=df_signal.index),
'open_long': pd.Series([False] * len(df_signal), index=df_signal.index, dtype=bool),
'close_long': pd.Series([False] * len(df_signal), index=df_signal.index, dtype=bool),
'open_short': sell, 'close_short': buy,
}
else:
@@ -363,13 +411,15 @@ class BacktestService:
# We use special signal types 'enter_long' and 'enter_short' to indicate
# that the signal should auto-close opposing position before opening
norm_signals = {
'open_long': buy, 'close_long': pd.Series([False] * len(df_signal), index=df_signal.index),
'open_short': sell, 'close_short': pd.Series([False] * len(df_signal), index=df_signal.index),
'open_long': buy, 'close_long': pd.Series([False] * len(df_signal), index=df_signal.index, dtype=bool),
'open_short': sell, 'close_short': pd.Series([False] * len(df_signal), index=df_signal.index, dtype=bool),
'_both_mode': True # Flag to indicate both mode for special handling
}
else:
raise ValueError("Invalid signal format")
logger.info("Signal normalization completed, starting signal queue building...")
# Map signals to execution timeframe
# Strategy timeframe seconds (e.g. 1H=3600, 1D=86400)
signal_tf_seconds = self.TIMEFRAME_SECONDS.get(signal_timeframe, 3600)
@@ -379,24 +429,38 @@ class BacktestService:
# Preprocessing: create signal queue sorted by effective time
# Each signal executes at the open of the next execution candle after its candle closes
logger.info("Initializing signal queue...")
signal_queue = [] # [(effective_time, signal_type, signal_bar_time), ...]
# Debug: check signal values
debug_signal_counts = {'open_long': 0, 'close_long': 0, 'open_short': 0, 'close_short': 0}
# Verify all norm_signals have matching index
for sig_type in ['open_long', 'close_long', 'open_short', 'close_short']:
if not norm_signals[sig_type].index.equals(df_signal.index):
logger.error(f"Critical: {sig_type} signal index does not match df_signal.index!")
logger.error(f" Signal index: {norm_signals[sig_type].index[:5].tolist()}")
logger.error(f" df_signal index: {df_signal.index[:5].tolist()}")
# Reindex to fix
norm_signals[sig_type] = norm_signals[sig_type].reindex(df_signal.index, fill_value=False)
logger.warning(f" Fixed by reindexing {sig_type}")
for sig_time in df_signal.index:
# Signal candle end time = start time + period
sig_end = sig_time + timedelta(seconds=signal_tf_seconds)
# Check if this signal candle has signals
# Use .loc[] instead of .get() to be more explicit
# All signals should now have matching index, so we can safely use .loc[]
try:
ol = bool(norm_signals['open_long'].loc[sig_time]) if sig_time in norm_signals['open_long'].index else False
cl = bool(norm_signals['close_long'].loc[sig_time]) if sig_time in norm_signals['close_long'].index else False
os = bool(norm_signals['open_short'].loc[sig_time]) if sig_time in norm_signals['open_short'].index else False
cs = bool(norm_signals['close_short'].loc[sig_time]) if sig_time in norm_signals['close_short'].index else False
ol = bool(norm_signals['open_long'].loc[sig_time])
cl = bool(norm_signals['close_long'].loc[sig_time])
os = bool(norm_signals['open_short'].loc[sig_time])
cs = bool(norm_signals['close_short'].loc[sig_time])
except (KeyError, IndexError) as e:
logger.warning(f"Error accessing signal at {sig_time}: {e}, signal index: {norm_signals['open_long'].index[:5].tolist()}, df_signal index: {df_signal.index[:5].tolist()}")
continue
except Exception as e:
logger.warning(f"Error accessing signal at {sig_time}: {e}")
logger.warning(f"Unexpected error accessing signal at {sig_time}: {e}")
continue
if ol:
@@ -414,6 +478,22 @@ class BacktestService:
logger.info(f"Debug signal counts from queue building: {debug_signal_counts}")
# If no signals found, log detailed diagnostic info
if len(signal_queue) == 0:
logger.warning("No signals found in signal queue! Diagnostic info:")
logger.warning(f" df_signal length: {len(df_signal)}")
logger.warning(f" df_signal index range: {df_signal.index[0]} to {df_signal.index[-1]}")
for sig_type in ['open_long', 'close_long', 'open_short', 'close_short']:
sig_series = norm_signals[sig_type]
true_count = sig_series.sum()
logger.warning(f" {sig_type}: {true_count} True values out of {len(sig_series)}")
if true_count > 0:
true_indices = sig_series[sig_series].index.tolist()[:5]
logger.warning(f" First few True indices: {true_indices}")
# Check if signals might be in wrong format
if 'buy' in signals or 'sell' in signals:
logger.warning(" Original signals had 'buy'/'sell' keys - check if conversion was correct")
# Sort by effective time
signal_queue.sort(key=lambda x: x[0])
signal_queue_idx = 0 # Current signal queue pointer
@@ -422,6 +502,8 @@ class BacktestService:
if signal_queue:
logger.info(f"First signal: {signal_queue[0][1]} @ {signal_queue[0][0]} (from {signal_queue[0][2]})")
logger.info(f"Last signal: {signal_queue[-1][1]} @ {signal_queue[-1][0]} (from {signal_queue[-1][2]})")
else:
logger.error("Signal queue is empty! Backtest will fail. Check indicator code to ensure it generates buy/sell signals.")
# Count signals by type
signal_counts = {}
@@ -429,6 +511,12 @@ class BacktestService:
signal_counts[sig_type] = signal_counts.get(sig_type, 0) + 1
logger.info(f"Signal counts: {signal_counts}")
# Log first few signal details for debugging
if signal_queue:
logger.info(f"First 3 signals details:")
for idx, (sig_time, sig_type, sig_bar_time) in enumerate(signal_queue[:3]):
logger.info(f" Signal {idx+1}: {sig_type} @ effective_time={sig_time}, from_bar={sig_bar_time}")
# Log execution data range
if len(df_exec) > 0:
exec_start = df_exec.index[0]
@@ -443,7 +531,17 @@ class BacktestService:
pending_signal_time = None # Signal effective time
executed_trades_count = 0 # Debug counter
# Progress logging for large datasets
total_exec_candles = len(df_exec)
progress_log_interval = max(1000, total_exec_candles // 10) # Log every 10% or every 1000 candles
logger.info(f"Starting execution loop: {total_exec_candles} candles to process, {len(signal_queue)} signals in queue")
for i, (timestamp, row) in enumerate(df_exec.iterrows()):
# Progress logging
if i > 0 and i % progress_log_interval == 0:
progress_pct = (i / total_exec_candles) * 100
logger.info(f"Execution progress: {i}/{total_exec_candles} ({progress_pct:.1f}%), trades={executed_trades_count}, position={position}")
# 爆仓后直接停止回测,输出结果
if is_liquidated:
break
@@ -500,13 +598,15 @@ class BacktestService:
pending_signal = sig_type
pending_signal_time = sig_effective_time
signal_queue_idx += 1
if executed_trades_count < 5:
logger.info(f"Signal ready: {sig_type} @ {timestamp}, will execute at open price (both_mode={both_mode_active})")
if executed_trades_count < 5 or signal_queue_idx <= 5:
logger.info(f"Signal ready: {sig_type} @ {timestamp} (effective_time={sig_effective_time}, sig_bar_time={sig_bar_time}), "
f"will execute at open price (both_mode={both_mode_active}, position={position})")
break
else:
# Signal doesn't meet execution conditions, skip
if signal_queue_idx < 5:
logger.info(f"Skipping signal #{signal_queue_idx}: {sig_type} (position={position}, can_execute=False)")
if signal_queue_idx < 10:
logger.info(f"Skipping signal #{signal_queue_idx}: {sig_type} @ {sig_effective_time} "
f"(position={position}, can_execute=False, both_mode={both_mode_active})")
signal_queue_idx += 1
continue
else:
@@ -713,6 +813,8 @@ class BacktestService:
# 2. Execute pending signal (at open price)
if pending_signal and path_price == open_:
both_mode_active = norm_signals.get('_both_mode', False)
if executed_trades_count < 10:
logger.info(f"Executing pending signal: {pending_signal} @ {timestamp}, path_price={path_price}, open={open_}, position={position}")
# open_long: In both mode, first close short if any, then open long
if pending_signal == 'open_long' and (position == 0 or (both_mode_active and position < 0)):
@@ -909,9 +1011,25 @@ class BacktestService:
})
# Summary log
logger.info(f"MTF simulation complete: executed_trades={executed_trades_count}, total_trades_recorded={len(trades)}, final_capital={capital:.2f}")
logger.info(f"MTF simulation complete: executed_trades={executed_trades_count}, total_trades_recorded={len(trades)}, final_capital={capital:.2f}, final_position={position}")
if len(trades) == 0:
logger.warning(f"No trades executed! signal_queue_idx={signal_queue_idx}, total_signals={len(signal_queue)}")
if len(signal_queue) == 0:
logger.error(f"No trades executed because signal queue is empty! This usually means:")
logger.error(" 1. Indicator code did not generate any buy/sell signals")
logger.error(" 2. Signal index mismatch between indicator output and df_signal")
logger.error(" 3. All signal values are False")
raise ValueError("No signals generated by indicator code. Please check your indicator code to ensure it sets df['buy'] and/or df['sell'] columns with boolean values.")
else:
logger.error(f"No trades executed despite {len(signal_queue)} signals in queue. signal_queue_idx={signal_queue_idx}")
logger.error(f" Signal queue processed: {signal_queue_idx}/{len(signal_queue)}")
logger.error(f" Final position: {position}, Final capital: {capital:.2f}")
logger.error(" This may indicate:")
logger.error(" 1. Signal timing issues (signal effective time doesn't match execution timeframe)")
logger.error(" 2. Position state conflicts (signals skipped due to position state)")
logger.error(" 3. Capital insufficient for trading")
logger.error(f" First few signals: {signal_queue[:min(5, len(signal_queue))]}")
logger.error(f" Exec data range: {df_exec.index[0]} to {df_exec.index[-1]}")
raise ValueError(f"No trades executed despite {len(signal_queue)} signals. Check signal timing and position state logic.")
return equity_curve, trades, total_commission_paid
@@ -1057,28 +1175,70 @@ class BacktestService:
)
if not kline_data:
logger.warning("No candle data retrieved")
logger.warning(f"No candle data retrieved for {market}:{symbol}, timeframe={timeframe}, limit={limit}, before_time={before_time}")
return pd.DataFrame()
if kline_data:
first_time = datetime.fromtimestamp(kline_data[0]['time'])
last_time = datetime.fromtimestamp(kline_data[-1]['time'])
logger.info(f"Retrieved {len(kline_data)} candles for {market}:{symbol}, timeframe={timeframe}")
# Convert to DataFrame
df = pd.DataFrame(kline_data)
df['time'] = pd.to_datetime(df['time'], unit='s')
df = df.set_index('time')
if len(df) > 0:
pass
# Filter date range
df = df[(df.index >= start_date) & (df.index <= end_date)].copy()
if len(df) > 0:
pass
return df
try:
df = pd.DataFrame(kline_data)
if df.empty:
logger.warning(f"DataFrame is empty after conversion")
return pd.DataFrame()
# Handle time column - could be seconds or milliseconds
if 'time' not in df.columns:
logger.error(f"Missing 'time' column in kline data. Columns: {df.columns.tolist()}")
return pd.DataFrame()
# Try seconds first, if fails try milliseconds
try:
df['time'] = pd.to_datetime(df['time'], unit='s')
except (ValueError, OverflowError):
# If seconds fails, try milliseconds
try:
df['time'] = pd.to_datetime(df['time'], unit='ms')
except (ValueError, OverflowError):
# If both fail, try direct conversion
df['time'] = pd.to_datetime(df['time'])
df = df.set_index('time')
if df.empty:
logger.warning(f"DataFrame is empty after setting time index")
return pd.DataFrame()
# Log data range before filtering
data_start = df.index.min()
data_end = df.index.max()
logger.info(f"Kline data range: {data_start} to {data_end}, requested range: {start_date} to {end_date}")
# Check if requested range is within available data
if data_start > start_date:
logger.warning(f"Requested start date {start_date} is before available data start {data_start}. "
f"Using available start date instead.")
if data_end < end_date:
logger.warning(f"Requested end date {end_date} is after available data end {data_end}. "
f"Using available end date instead. This may affect backtest results.")
# Filter date range (use available data range if requested range is outside)
effective_start = max(start_date, data_start)
effective_end = min(end_date, data_end)
df_filtered = df[(df.index >= effective_start) & (df.index <= effective_end)].copy()
if df_filtered.empty:
logger.error(f"After filtering date range ({effective_start} to {effective_end}), no data remains. "
f"Available data range: {data_start} to {data_end}, requested: {start_date} to {end_date}")
return pd.DataFrame()
logger.info(f"After filtering: {len(df_filtered)} candles remain for backtest (effective range: {effective_start} to {effective_end})")
return df_filtered
except Exception as e:
logger.error(f"Error processing kline data: {str(e)}")
logger.error(traceback.format_exc())
return pd.DataFrame()
def _execute_indicator(self, code: str, df: pd.DataFrame, backtest_params: dict = None):
"""Execute indicator code to get signals.
@@ -1213,9 +1373,25 @@ import pandas as pd
# Position sizing, TP/SL, trailing, etc must be handled by strategy_config / strategy logic.
elif all(col in executed_df.columns for col in ['buy', 'sell']):
# Simple buy/sell signals (recommended for indicator authors)
buy_series = executed_df['buy'].fillna(False).astype(bool)
sell_series = executed_df['sell'].fillna(False).astype(bool)
# Ensure signals have the same index as df
if not buy_series.index.equals(df.index):
logger.warning(f"Buy signal index mismatch in _execute_indicator! Reindexing...")
buy_series = buy_series.reindex(df.index, fill_value=False)
if not sell_series.index.equals(df.index):
logger.warning(f"Sell signal index mismatch in _execute_indicator! Reindexing...")
sell_series = sell_series.reindex(df.index, fill_value=False)
# Debug: log signal statistics
buy_count = buy_series.sum()
sell_count = sell_series.sum()
logger.info(f"Indicator execution: buy signals={buy_count}, sell signals={sell_count}, total_candles={len(df)}")
signals = {
'buy': executed_df['buy'].fillna(False).astype(bool),
'sell': executed_df['sell'].fillna(False).astype(bool)
'buy': buy_series,
'sell': sell_series
}
else: