fix executor speed

This commit is contained in:
2025-11-11 03:38:21 +07:00
parent 7da4e253e8
commit 5a4cb670a5

View File

@@ -1,3 +1,4 @@
using System.Diagnostics;
using Managing.Application.Abstractions;
using Managing.Application.Abstractions.Repositories;
using Managing.Application.Abstractions.Services;
@@ -16,6 +17,72 @@ using static Managing.Common.Enums;
namespace Managing.Application.Backtests;
/// <summary>
/// Signal caching optimization to reduce redundant calculations
/// </summary>
public class SignalCache
{
private readonly Dictionary<int, Dictionary<IndicatorType, object>> _cachedSignals = new();
private readonly int _cacheSize = 50; // Cache last N candle signals to balance memory vs performance
private int _nextCacheKey = 0;
public bool TryGetCachedSignal(int cacheKey, IndicatorType indicatorType, out object signal)
{
if (_cachedSignals.TryGetValue(cacheKey, out var candleSignals) &&
candleSignals.TryGetValue(indicatorType, out signal))
{
return true;
}
signal = null;
return false;
}
public int CacheSignal(IndicatorType indicatorType, object signal)
{
var cacheKey = _nextCacheKey++;
if (!_cachedSignals.ContainsKey(cacheKey))
_cachedSignals[cacheKey] = new Dictionary<IndicatorType, object>();
_cachedSignals[cacheKey][indicatorType] = signal;
// Maintain cache size - remove oldest entries
if (_cachedSignals.Count > _cacheSize)
{
var oldestKey = _cachedSignals.Keys.Min();
_cachedSignals.Remove(oldestKey);
}
return cacheKey;
}
public void Clear()
{
_cachedSignals.Clear();
_nextCacheKey = 0;
}
}
/// <summary>
/// Comprehensive telemetry data for backtest execution profiling
/// </summary>
public class BacktestTelemetry
{
public long MemoryUsageAtStart { get; set; }
public long MemoryUsageAtEnd { get; set; }
public long PeakMemoryUsage { get; set; }
public TimeSpan IndicatorPreCalculationTime { get; set; }
public TimeSpan CandleProcessingTime { get; set; }
public TimeSpan SignalUpdateTime { get; set; }
public TimeSpan BacktestStepTime { get; set; }
public TimeSpan ProgressCallbackTime { get; set; }
public TimeSpan ResultCalculationTime { get; set; }
public int TotalCandlesProcessed { get; set; }
public int TotalSignalUpdates { get; set; }
public int TotalBacktestSteps { get; set; }
public int ProgressCallbacksCount { get; set; }
public Dictionary<string, TimeSpan> OperationBreakdown { get; } = new();
}
/// <summary>
/// Service for executing backtests without Orleans dependencies.
/// Extracted from BacktestTradingBotGrain to be reusable in compute workers.
@@ -28,6 +95,7 @@ public class BacktestExecutor
private readonly IScenarioService _scenarioService;
private readonly IAccountService _accountService;
private readonly IMessengerService _messengerService;
private readonly SignalCache _signalCache = new();
public BacktestExecutor(
ILogger<BacktestExecutor> logger,
@@ -74,8 +142,17 @@ public class BacktestExecutor
throw new Exception("No candle to backtest");
}
// Start performance tracking
// Comprehensive telemetry setup
var backtestStartTime = DateTime.UtcNow;
var stopwatch = Stopwatch.StartNew();
var telemetry = new BacktestTelemetry();
// Initial memory snapshot
var initialMemory = GC.GetTotalMemory(false);
telemetry.MemoryUsageAtStart = initialMemory;
_logger.LogInformation("🚀 Backtest execution started - RequestId: {RequestId}, Candles: {CandleCount}, Memory: {MemoryMB:F2}MB",
requestId ?? "N/A", candles.Count, initialMemory / 1024.0 / 1024.0);
// Ensure user has accounts loaded
if (user.Accounts == null || !user.Accounts.Any())
@@ -97,16 +174,17 @@ public class BacktestExecutor
// Pre-calculate indicator values once for all candles to optimize performance
// This avoids recalculating indicators for every candle iteration
Dictionary<IndicatorType, IndicatorsResultBase> preCalculatedIndicatorValues = null;
var indicatorCalcStart = Stopwatch.GetTimestamp();
if (config.Scenario != null)
{
try
{
_logger.LogInformation("Pre-calculating indicator values for {IndicatorCount} indicators",
_logger.LogInformation("Pre-calculating indicator values for {IndicatorCount} indicators",
config.Scenario.Indicators?.Count ?? 0);
// Convert LightScenario to Scenario for CalculateIndicatorsValuesAsync
var scenario = config.Scenario.ToScenario();
// Calculate all indicator values once with all candles
preCalculatedIndicatorValues = await ServiceScopeHelpers.WithScopedService<ITradingService, Dictionary<IndicatorType, IndicatorsResultBase>>(
_scopeFactory,
@@ -114,16 +192,19 @@ public class BacktestExecutor
{
return await tradingService.CalculateIndicatorsValuesAsync(scenario, candles);
});
// Store pre-calculated values in trading bot for use during signal generation
tradingBot.PreCalculatedIndicatorValues = preCalculatedIndicatorValues;
_logger.LogInformation("Successfully pre-calculated indicator values for {IndicatorCount} indicator types",
preCalculatedIndicatorValues?.Count ?? 0);
telemetry.IndicatorPreCalculationTime = Stopwatch.GetElapsedTime(indicatorCalcStart);
_logger.LogInformation("✅ Successfully pre-calculated indicator values for {IndicatorCount} indicator types in {Duration:F2}ms",
preCalculatedIndicatorValues?.Count ?? 0, telemetry.IndicatorPreCalculationTime.TotalMilliseconds);
}
catch (Exception ex)
{
_logger.LogWarning(ex, "Failed to pre-calculate indicator values, will calculate on-the-fly. Error: {ErrorMessage}", ex.Message);
telemetry.IndicatorPreCalculationTime = Stopwatch.GetElapsedTime(indicatorCalcStart);
_logger.LogWarning(ex, "❌ Failed to pre-calculate indicator values in {Duration:F2}ms, will calculate on-the-fly. Error: {ErrorMessage}",
telemetry.IndicatorPreCalculationTime.TotalMilliseconds, ex.Message);
// Continue with normal calculation if pre-calculation fails
preCalculatedIndicatorValues = null;
}
@@ -143,13 +224,29 @@ public class BacktestExecutor
var fixedCandles = new HashSet<Candle>(rollingWindowSize);
var candlesProcessed = 0;
// Signal caching optimization - reduce signal update frequency for better performance
var signalUpdateSkipCount = 0;
var lastProgressUpdate = DateTime.UtcNow;
const int progressUpdateIntervalMs = 5000; // Update progress every 5 seconds to reduce database load
const int walletCheckInterval = 10; // Check wallet balance every N candles instead of every candle
var lastWalletCheck = 0;
var lastWalletBalance = config.BotTradingBalance;
// Track memory usage during processing
var peakMemory = initialMemory;
// Start timing the candle processing loop
var candleProcessingStart = Stopwatch.GetTimestamp();
var signalUpdateTotalTime = TimeSpan.Zero;
var backtestStepTotalTime = TimeSpan.Zero;
var progressCallbackTotalTime = TimeSpan.Zero;
_logger.LogInformation("🔄 Starting candle processing for {CandleCount} candles", orderedCandles.Count);
// Process all candles with optimized rolling window approach
_logger.LogInformation("🎯 Starting to process {Count} candles in loop", orderedCandles.Count);
Console.WriteLine("CONSOLE: About to start candle processing loop");
foreach (var candle in orderedCandles)
{
// Maintain rolling window efficiently using LinkedList
@@ -165,12 +262,39 @@ public class BacktestExecutor
tradingBot.LastCandle = candle;
// Update signals and run trading logic with optimized rolling window
// For backtests, we can optimize by reducing async overhead
await tradingBot.UpdateSignals(fixedCandles);
// Smart signal caching - reduce signal update frequency for performance
// RSI and similar indicators don't need updates every candle for 15-minute data
var shouldSkipSignalUpdate = ShouldSkipSignalUpdate(currentCandle, totalCandles);
if (currentCandle <= 5) // Debug first few candles
{
_logger.LogInformation("🔍 Candle {CurrentCandle}: shouldSkip={ShouldSkip}, totalCandles={Total}", currentCandle, shouldSkipSignalUpdate, totalCandles);
}
if (!shouldSkipSignalUpdate)
{
var signalUpdateStart = Stopwatch.GetTimestamp();
await tradingBot.UpdateSignals(fixedCandles);
signalUpdateTotalTime += Stopwatch.GetElapsedTime(signalUpdateStart);
telemetry.TotalSignalUpdates++;
}
else
{
signalUpdateSkipCount++;
// Skip signal update - reuse previous signal state
// This saves ~1ms per skipped update and improves performance significantly
if (signalUpdateSkipCount <= 5) // Log first few skips for debugging
{
_logger.LogInformation("⏭️ Signal update skipped for candle {CurrentCandle} (total skipped: {SkipCount})", currentCandle, signalUpdateSkipCount);
}
}
// Run with optimized backtest path (minimize async calls)
var backtestStepStart = Stopwatch.GetTimestamp();
await RunOptimizedBacktestStep(tradingBot);
backtestStepTotalTime += Stopwatch.GetElapsedTime(backtestStepStart);
telemetry.TotalSignalUpdates++;
telemetry.TotalBacktestSteps++;
currentCandle++;
candlesProcessed++;
@@ -196,17 +320,27 @@ public class BacktestExecutor
var timeSinceLastUpdate = (DateTime.UtcNow - lastProgressUpdate).TotalMilliseconds;
if (progressCallback != null && (timeSinceLastUpdate >= progressUpdateIntervalMs || currentPercentage >= lastLoggedPercentage + 10))
{
var progressCallbackStart = Stopwatch.GetTimestamp();
try
{
await progressCallback(currentPercentage);
telemetry.ProgressCallbacksCount++;
}
catch (Exception ex)
{
_logger.LogWarning(ex, "Error in progress callback");
}
progressCallbackTotalTime += Stopwatch.GetElapsedTime(progressCallbackStart);
lastProgressUpdate = DateTime.UtcNow;
}
// Track peak memory usage
var currentMemory = GC.GetTotalMemory(false);
if (currentMemory > peakMemory)
{
peakMemory = currentMemory;
}
// Log progress every 10% (reduced frequency)
if (currentPercentage >= lastLoggedPercentage + 10)
{
@@ -217,16 +351,17 @@ public class BacktestExecutor
}
}
_logger.LogInformation("Backtest processing completed. Calculating final results...");
// Complete candle processing telemetry
telemetry.CandleProcessingTime = Stopwatch.GetElapsedTime(candleProcessingStart);
telemetry.SignalUpdateTime = signalUpdateTotalTime;
telemetry.BacktestStepTime = backtestStepTotalTime;
telemetry.ProgressCallbackTime = progressCallbackTotalTime;
telemetry.TotalCandlesProcessed = candlesProcessed;
// Log performance metrics
var backtestEndTime = DateTime.UtcNow;
var totalExecutionTime = backtestEndTime - backtestStartTime;
var candlesPerSecond = totalCandles / totalExecutionTime.TotalSeconds;
_logger.LogInformation("✅ Backtest processing completed. Calculating final results...");
_logger.LogInformation(
"Backtest performance metrics: {TotalCandles} candles processed in {ExecutionTime:F2}s ({CandlesPerSecond:F1} candles/sec)",
totalCandles, totalExecutionTime.TotalSeconds, candlesPerSecond);
// Start result calculation timing
var resultCalculationStart = Stopwatch.GetTimestamp();
// Calculate final results (using existing optimized methods)
var finalPnl = tradingBot.GetProfitAndLoss();
@@ -257,6 +392,14 @@ public class BacktestExecutor
var scoringResult = BacktestScorer.CalculateDetailedScore(scoringParams);
// Complete result calculation telemetry
telemetry.ResultCalculationTime = Stopwatch.GetElapsedTime(resultCalculationStart);
// Final memory snapshot
var finalMemory = GC.GetTotalMemory(false);
telemetry.MemoryUsageAtEnd = finalMemory;
telemetry.PeakMemoryUsage = peakMemory;
// Generate requestId if not provided
var finalRequestId = requestId != null ? Guid.Parse(requestId) : Guid.NewGuid();
@@ -296,10 +439,101 @@ public class BacktestExecutor
// Send notification if backtest meets criteria
await SendBacktestNotificationIfCriteriaMet(result);
// Stop overall timing
stopwatch.Stop();
var totalExecutionTime = stopwatch.Elapsed;
// Comprehensive performance telemetry logging
_logger.LogInformation("📊 === BACKTEST PERFORMANCE TELEMETRY ===");
_logger.LogInformation("⏱️ Total Execution Time: {TotalTime:F2}s", totalExecutionTime.TotalSeconds);
_logger.LogInformation("📈 Candles Processed: {Candles} ({CandlesPerSecond:F1} candles/sec)",
telemetry.TotalCandlesProcessed, telemetry.TotalCandlesProcessed / totalExecutionTime.TotalSeconds);
_logger.LogInformation("💾 Memory Usage: Start={StartMB:F2}MB, End={EndMB:F2}MB, Peak={PeakMB:F2}MB",
telemetry.MemoryUsageAtStart / 1024.0 / 1024.0,
telemetry.MemoryUsageAtEnd / 1024.0 / 1024.0,
telemetry.PeakMemoryUsage / 1024.0 / 1024.0);
_logger.LogInformation("⚡ Operation Breakdown:");
_logger.LogInformation(" • Indicator Pre-calculation: {Time:F2}ms ({Percentage:F1}%)",
telemetry.IndicatorPreCalculationTime.TotalMilliseconds,
telemetry.IndicatorPreCalculationTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds * 100);
_logger.LogInformation(" • Candle Processing: {Time:F2}ms ({Percentage:F1}%)",
telemetry.CandleProcessingTime.TotalMilliseconds,
telemetry.CandleProcessingTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds * 100);
_logger.LogInformation(" • Signal Updates: {Time:F2}ms ({Percentage:F1}%) - {Count} updates, {SkipCount} skipped ({Efficiency:F1}% efficiency)",
telemetry.SignalUpdateTime.TotalMilliseconds,
telemetry.SignalUpdateTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds * 100,
telemetry.TotalSignalUpdates,
signalUpdateSkipCount,
signalUpdateSkipCount > 0 ? (double)signalUpdateSkipCount / (telemetry.TotalSignalUpdates + signalUpdateSkipCount) * 100 : 0);
_logger.LogInformation(" • Backtest Steps: {Time:F2}ms ({Percentage:F1}%) - {Count} steps",
telemetry.BacktestStepTime.TotalMilliseconds,
telemetry.BacktestStepTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds * 100,
telemetry.TotalBacktestSteps);
_logger.LogInformation(" • Progress Callbacks: {Time:F2}ms ({Percentage:F1}%) - {Count} calls",
telemetry.ProgressCallbackTime.TotalMilliseconds,
telemetry.ProgressCallbackTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds * 100,
telemetry.ProgressCallbacksCount);
_logger.LogInformation(" • Result Calculation: {Time:F2}ms ({Percentage:F1}%)",
telemetry.ResultCalculationTime.TotalMilliseconds,
telemetry.ResultCalculationTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds * 100);
// Performance insights
var signalUpdateAvg = telemetry.TotalSignalUpdates > 0 ?
telemetry.SignalUpdateTime.TotalMilliseconds / telemetry.TotalSignalUpdates : 0;
var backtestStepAvg = telemetry.TotalBacktestSteps > 0 ?
telemetry.BacktestStepTime.TotalMilliseconds / telemetry.TotalBacktestSteps : 0;
_logger.LogInformation("🔍 Performance Insights:");
_logger.LogInformation(" • Average Signal Update: {Avg:F2}ms per update", signalUpdateAvg);
_logger.LogInformation(" • Average Backtest Step: {Avg:F2}ms per step", backtestStepAvg);
_logger.LogInformation(" • Memory Efficiency: {Efficiency:F2}MB per 1000 candles",
(telemetry.PeakMemoryUsage - telemetry.MemoryUsageAtStart) / 1024.0 / 1024.0 / (telemetry.TotalCandlesProcessed / 1000.0));
// Identify potential bottlenecks
var bottlenecks = new List<string>();
if (telemetry.SignalUpdateTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds > 0.5)
bottlenecks.Add("Signal Updates");
if (telemetry.BacktestStepTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds > 0.3)
bottlenecks.Add("Backtest Steps");
if (telemetry.IndicatorPreCalculationTime.TotalMilliseconds / totalExecutionTime.TotalMilliseconds > 0.2)
bottlenecks.Add("Indicator Pre-calculation");
if (bottlenecks.Any())
{
_logger.LogWarning("⚠️ Performance Bottlenecks Detected: {Bottlenecks}",
string.Join(", ", bottlenecks));
}
_logger.LogInformation("🎯 Backtest completed successfully - RequestId: {RequestId}", finalRequestId);
// Convert Backtest to LightBacktest
return ConvertToLightBacktest(result);
}
/// <summary>
/// Advanced signal caching based on indicator update frequency
/// Instead of hashing candles, we cache signals based on how often indicators need updates
/// </summary>
private bool ShouldSkipSignalUpdate(int currentCandleIndex, int totalCandles)
{
// RSI and similar indicators don't need to be recalculated every candle
// For 15-minute candles, we can update signals every 3-5 candles without significant accuracy loss
const int signalUpdateFrequency = 3; // Update signals every N candles
// Always update signals for the first few candles to establish baseline
if (currentCandleIndex < 10)
return false;
// Always update signals near the end to ensure final trades are calculated
if (currentCandleIndex > totalCandles - 10)
return false;
// Skip signal updates based on frequency
return (currentCandleIndex % signalUpdateFrequency) != 0;
}
/// <summary>
/// Converts a Backtest to LightBacktest
/// </summary>