Reduce logs for backtests

This commit is contained in:
2025-10-10 01:59:27 +07:00
parent a3d6dd1238
commit 21314430ef
3 changed files with 46 additions and 30 deletions

View File

@@ -93,6 +93,15 @@ public class BacktestTradingBotGrain : Grain, IBacktestTradingBotGrain
currentCandle++; currentCandle++;
// Log progress every 10%
var currentPercentage = (currentCandle * 100) / totalCandles;
if (currentPercentage >= lastLoggedPercentage + 10)
{
lastLoggedPercentage = currentPercentage;
_logger.LogInformation("Backtest progress: {Percentage}% ({CurrentCandle}/{TotalCandles} candles processed)",
currentPercentage, currentCandle, totalCandles);
}
// Check if wallet balance fell below 10 USDC and break if so // Check if wallet balance fell below 10 USDC and break if so
var currentWalletBalance = tradingBot.WalletBalances.Values.LastOrDefault(); var currentWalletBalance = tradingBot.WalletBalances.Values.LastOrDefault();
if (currentWalletBalance < Constants.GMX.Config.MinimumPositionAmount) if (currentWalletBalance < Constants.GMX.Config.MinimumPositionAmount)

View File

@@ -858,7 +858,7 @@ public class TradingBotBase : ITradingBot
private async Task<Position> OpenPosition(LightSignal signal) private async Task<Position> OpenPosition(LightSignal signal)
{ {
Logger.LogInformation($"Opening position for {signal.Identifier}"); Logger.LogDebug($"Opening position for {signal.Identifier}");
// Check for any existing open position (not finished) for this ticker // Check for any existing open position (not finished) for this ticker
var openedPosition = var openedPosition =
@@ -970,7 +970,7 @@ public class TradingBotBase : ITradingBot
async messengerService => { await messengerService.SendPosition(position); }); async messengerService => { await messengerService.SendPosition(position); });
} }
Logger.LogInformation($"Position requested"); Logger.LogDebug($"Position requested");
return position; return position;
} }
else else
@@ -1184,7 +1184,7 @@ public class TradingBotBase : ITradingBot
// Get status of position before closing it. The position might be already close by the exchange // Get status of position before closing it. The position might be already close by the exchange
if (!Config.IsForBacktest && quantity == 0) if (!Config.IsForBacktest && quantity == 0)
{ {
Logger.LogInformation($"Trade already close on exchange"); Logger.LogDebug($"Trade already close on exchange");
await HandleClosedPosition(position); await HandleClosedPosition(position);
} }
else else
@@ -1249,7 +1249,7 @@ public class TradingBotBase : ITradingBot
{ {
try try
{ {
Logger.LogInformation( Logger.LogDebug(
$"🔍 Fetching Position History from GMX\nPosition: `{position.Identifier}`\nTicker: `{Config.Ticker}`"); $"🔍 Fetching Position History from GMX\nPosition: `{position.Identifier}`\nTicker: `{Config.Ticker}`");
List<Position> positionHistory = null; List<Position> positionHistory = null;
@@ -1272,7 +1272,7 @@ public class TradingBotBase : ITradingBot
if (gmxPosition != null && gmxPosition.ProfitAndLoss != null) if (gmxPosition != null && gmxPosition.ProfitAndLoss != null)
{ {
Logger.LogInformation( Logger.LogDebug(
$"✅ GMX Position History Found\n" + $"✅ GMX Position History Found\n" +
$"Position: `{position.Identifier}`\n" + $"Position: `{position.Identifier}`\n" +
$"GMX Realized PnL (after fees): `${gmxPosition.ProfitAndLoss.Realized:F2}`\n" + $"GMX Realized PnL (after fees): `${gmxPosition.ProfitAndLoss.Realized:F2}`\n" +
@@ -1336,7 +1336,7 @@ public class TradingBotBase : ITradingBot
} }
} }
Logger.LogInformation( Logger.LogDebug(
$"📊 Position Reconciliation Complete\n" + $"📊 Position Reconciliation Complete\n" +
$"Position: `{position.Identifier}`\n" + $"Position: `{position.Identifier}`\n" +
$"Closing Price: `${gmxClosingPrice:F2}`\n" + $"Closing Price: `${gmxClosingPrice:F2}`\n" +
@@ -1455,7 +1455,7 @@ public class TradingBotBase : ITradingBot
position.TakeProfit2.SetStatus(TradeStatus.Cancelled); position.TakeProfit2.SetStatus(TradeStatus.Cancelled);
} }
Logger.LogInformation( Logger.LogDebug(
$"🛑 Stop Loss Execution Confirmed\n" + $"🛑 Stop Loss Execution Confirmed\n" +
$"Position: `{position.Identifier}`\n" + $"Position: `{position.Identifier}`\n" +
$"SL Price: `${closingPrice:F2}` was hit (was `${position.StopLoss.Price:F2}`)\n" + $"SL Price: `${closingPrice:F2}` was hit (was `${position.StopLoss.Price:F2}`)\n" +
@@ -1478,7 +1478,7 @@ public class TradingBotBase : ITradingBot
position.StopLoss.SetStatus(TradeStatus.Cancelled); position.StopLoss.SetStatus(TradeStatus.Cancelled);
} }
Logger.LogInformation( Logger.LogDebug(
$"🎯 Take Profit Execution Confirmed\n" + $"🎯 Take Profit Execution Confirmed\n" +
$"Position: `{position.Identifier}`\n" + $"Position: `{position.Identifier}`\n" +
$"TP Price: `${closingPrice:F2}` was hit (was `${position.TakeProfit1.Price:F2}`)\n" + $"TP Price: `${closingPrice:F2}` was hit (was `${position.TakeProfit1.Price:F2}`)\n" +
@@ -1529,7 +1529,7 @@ public class TradingBotBase : ITradingBot
} }
} }
Logger.LogInformation( Logger.LogDebug(
$"✋ Manual/Exchange Close Detected\n" + $"✋ Manual/Exchange Close Detected\n" +
$"Position: `{position.Identifier}`\n" + $"Position: `{position.Identifier}`\n" +
$"SL: `${position.StopLoss.Price:F2}` | TP: `${position.TakeProfit1.Price:F2}`\n" + $"SL: `${position.StopLoss.Price:F2}` | TP: `${position.TakeProfit1.Price:F2}`\n" +
@@ -1598,7 +1598,7 @@ public class TradingBotBase : ITradingBot
position.ProfitAndLoss.Net = netPnl; position.ProfitAndLoss.Net = netPnl;
} }
Logger.LogInformation( Logger.LogDebug(
$"💰 P&L Calculated for Position {position.Identifier}\n" + $"💰 P&L Calculated for Position {position.Identifier}\n" +
$"Entry: `${entryPrice:F2}` | Exit: `${closingPrice:F2}`\n" + $"Entry: `${entryPrice:F2}` | Exit: `${closingPrice:F2}`\n" +
$"Realized P&L: `${pnl:F2}` | Net P&L (after fees): `${position.ProfitAndLoss.Net:F2}`\n" + $"Realized P&L: `${pnl:F2}` | Net P&L (after fees): `${position.ProfitAndLoss.Net:F2}`\n" +
@@ -1638,21 +1638,21 @@ public class TradingBotBase : ITradingBot
// Only update balance and log success if position was actually filled // Only update balance and log success if position was actually filled
if (position.Open?.Status == TradeStatus.Filled) if (position.Open?.Status == TradeStatus.Filled)
{ {
Logger.LogInformation( Logger.LogDebug(
$"✅ Position Closed Successfully\nPosition: `{position.SignalIdentifier}`\nPnL: `${position.ProfitAndLoss?.Net:F2}`"); $"✅ Position Closed Successfully\nPosition: `{position.SignalIdentifier}`\nPnL: `${position.ProfitAndLoss?.Net:F2}`");
if (position.ProfitAndLoss != null) if (position.ProfitAndLoss != null)
{ {
Config.BotTradingBalance += position.ProfitAndLoss.Net; Config.BotTradingBalance += position.ProfitAndLoss.Net;
Logger.LogInformation( Logger.LogDebug(
string.Format("💰 Balance Updated\nNew bot trading balance: `${0:F2}`", string.Format("💰 Balance Updated\nNew bot trading balance: `${0:F2}`",
Config.BotTradingBalance)); Config.BotTradingBalance));
} }
} }
else else
{ {
Logger.LogInformation( Logger.LogDebug(
$"✅ Position Cleanup\nPosition: `{position.SignalIdentifier}` was never filled - no balance or PnL changes"); $"✅ Position Cleanup\nPosition: `{position.SignalIdentifier}` was never filled - no balance or PnL changes");
} }
} }
@@ -1695,24 +1695,24 @@ public class TradingBotBase : ITradingBot
if (cancelClose) if (cancelClose)
{ {
Logger.LogInformation($"Position still open, cancel close orders"); Logger.LogDebug($"Position still open, cancel close orders");
} }
else else
{ {
Logger.LogInformation($"Canceling all orders for {Config.Ticker}"); Logger.LogDebug($"Canceling all orders for {Config.Ticker}");
await ServiceScopeHelpers.WithScopedService<IExchangeService>(_scopeFactory, await ServiceScopeHelpers.WithScopedService<IExchangeService>(_scopeFactory,
async exchangeService => async exchangeService =>
{ {
await exchangeService.CancelOrder(Account, Config.Ticker); await exchangeService.CancelOrder(Account, Config.Ticker);
var closePendingOrderStatus = await exchangeService.CancelOrder(Account, Config.Ticker); var closePendingOrderStatus = await exchangeService.CancelOrder(Account, Config.Ticker);
Logger.LogInformation( Logger.LogDebug(
$"Closing all {Config.Ticker} orders status : {closePendingOrderStatus}"); $"Closing all {Config.Ticker} orders status : {closePendingOrderStatus}");
}); });
} }
} }
else else
{ {
Logger.LogInformation($"No need to cancel orders for {Config.Ticker}"); Logger.LogDebug($"No need to cancel orders for {Config.Ticker}");
} }
} }
catch (Exception ex) catch (Exception ex)
@@ -1776,7 +1776,7 @@ public class TradingBotBase : ITradingBot
if (Signals.ContainsKey(signalIdentifier) && Signals[signalIdentifier].Status != signalStatus) if (Signals.ContainsKey(signalIdentifier) && Signals[signalIdentifier].Status != signalStatus)
{ {
Signals[signalIdentifier].Status = signalStatus; Signals[signalIdentifier].Status = signalStatus;
Logger.LogInformation($"Signal {signalIdentifier} is now {signalStatus}"); Logger.LogDebug($"Signal {signalIdentifier} is now {signalStatus}");
} }
} }
@@ -1834,11 +1834,11 @@ public class TradingBotBase : ITradingBot
public async Task LogInformation(string message) public async Task LogInformation(string message)
{ {
Logger.LogInformation(message);
if (Config.IsForBacktest) if (Config.IsForBacktest)
return; return;
Logger.LogInformation(message);
try try
{ {
await SendTradeMessage(message); await SendTradeMessage(message);
@@ -1851,6 +1851,9 @@ public class TradingBotBase : ITradingBot
public async Task LogWarning(string message) public async Task LogWarning(string message)
{ {
if (Config.IsForBacktest)
return;
message = $"[{Config.Name}] {message}"; message = $"[{Config.Name}] {message}";
SentrySdk.CaptureException(new Exception(message)); SentrySdk.CaptureException(new Exception(message));
@@ -1944,12 +1947,12 @@ public class TradingBotBase : ITradingBot
signalValidationResult.IsBlocked) signalValidationResult.IsBlocked)
{ {
signal.Status = SignalStatus.Expired; signal.Status = SignalStatus.Expired;
Logger.LogInformation($"Signal {signal.Identifier} blocked by Synth risk assessment"); Logger.LogDebug($"Signal {signal.Identifier} blocked by Synth risk assessment");
} }
else else
{ {
signal.Confidence = signalValidationResult.Confidence; signal.Confidence = signalValidationResult.Confidence;
Logger.LogInformation( Logger.LogDebug(
$"Signal {signal.Identifier} passed Synth risk assessment with confidence {signalValidationResult.Confidence}"); $"Signal {signal.Identifier} passed Synth risk assessment with confidence {signalValidationResult.Confidence}");
} }
}); });
@@ -1957,7 +1960,7 @@ public class TradingBotBase : ITradingBot
Signals.Add(signal.Identifier, signal); Signals.Add(signal.Identifier, signal);
Logger.LogInformation(signalText); Logger.LogDebug(signalText);
if (Config.IsForWatchingOnly && !Config.IsForBacktest && ExecutionCount > 0) if (Config.IsForWatchingOnly && !Config.IsForBacktest && ExecutionCount > 0)
{ {
@@ -1968,7 +1971,7 @@ public class TradingBotBase : ITradingBot
}); });
} }
Logger.LogInformation( Logger.LogDebug(
$"Processed signal for {Config.Ticker}: {signal.Direction} with status {signal.Status}"); $"Processed signal for {Config.Ticker}: {signal.Direction} with status {signal.Status}");
} }
catch (Exception ex) catch (Exception ex)

View File

@@ -42,7 +42,7 @@ namespace Managing.Infrastructure.Exchanges
decimal? stopLossPrice = null, decimal? stopLossPrice = null,
decimal? takeProfitPrice = null) decimal? takeProfitPrice = null)
{ {
_logger.LogInformation( _logger.LogDebug(
$"OpenMarketTrade - {ticker} - Type: {tradeType} - {direction} - Price: {price} - Quantity: {quantity} - Leverage: {leverage} - SL: {stopLossPrice} - TP: {takeProfitPrice}"); $"OpenMarketTrade - {ticker} - Type: {tradeType} - {direction} - Price: {price} - Quantity: {quantity} - Leverage: {leverage} - SL: {stopLossPrice} - TP: {takeProfitPrice}");
if (isForPaperTrading) if (isForPaperTrading)
@@ -282,7 +282,8 @@ namespace Managing.Infrastructure.Exchanges
} }
catch (InvalidOperationException ex) when (ex.Message.Contains("no candle data available")) catch (InvalidOperationException ex) when (ex.Message.Contains("no candle data available"))
{ {
_logger.LogWarning($"Primary price source failed for {ticker} at {date:yyyy-MM-dd HH:mm:ss}. Attempting fallback to current price."); _logger.LogWarning(
$"Primary price source failed for {ticker} at {date:yyyy-MM-dd HH:mm:ss}. Attempting fallback to current price.");
// Fallback: Try to get current price instead of historical price // Fallback: Try to get current price instead of historical price
try try
@@ -292,8 +293,11 @@ namespace Managing.Infrastructure.Exchanges
} }
catch (Exception fallbackEx) catch (Exception fallbackEx)
{ {
_logger.LogError(fallbackEx, $"Fallback price retrieval also failed for {ticker} at {date:yyyy-MM-dd HH:mm:ss}"); _logger.LogError(fallbackEx,
throw new InvalidOperationException($"Unable to retrieve price for {ticker}. Both primary and fallback methods failed. Please check if the ticker is valid and data sources are accessible.", ex); $"Fallback price retrieval also failed for {ticker} at {date:yyyy-MM-dd HH:mm:ss}");
throw new InvalidOperationException(
$"Unable to retrieve price for {ticker}. Both primary and fallback methods failed. Please check if the ticker is valid and data sources are accessible.",
ex);
} }
} }
} }