From 641010ac39b597fbccb834211a15f80fd0ed3f63 Mon Sep 17 00:00:00 2001 From: Josue Nina Date: Tue, 13 Jan 2026 11:14:06 -0500 Subject: [PATCH 1/2] Reduce excessive logs --- Engine/Results/LiveTradingResultHandler.cs | 23 ---------------------- 1 file changed, 23 deletions(-) diff --git a/Engine/Results/LiveTradingResultHandler.cs b/Engine/Results/LiveTradingResultHandler.cs index 39076274e95f..62d8f2f65714 100644 --- a/Engine/Results/LiveTradingResultHandler.cs +++ b/Engine/Results/LiveTradingResultHandler.cs @@ -158,7 +158,6 @@ private void Update() //Error checks if the algorithm & threads have not loaded yet, or are closing down. if (Algorithm?.Transactions == null || TransactionHandler.Orders == null || !Algorithm.GetLocked()) { - Log.Debug("LiveTradingResultHandler.Update(): Algorithm not yet initialized."); ExitEvent.WaitOne(1000); return; } @@ -183,7 +182,6 @@ private void Update() //Create and send back the changes in chart since the algorithm started. var deltaCharts = new Dictionary(); - Log.Debug("LiveTradingResultHandler.Update(): Build delta charts"); var performanceCharts = new Dictionary(); lock (ChartLock) { @@ -210,18 +208,15 @@ private void Update() } } } - Log.Debug("LiveTradingResultHandler.Update(): End build delta charts"); //Profit loss changes, get the banner statistics, summary information on the performance for the headers. var serverStatistics = GetServerStatistics(utcNow); var holdings = GetHoldings(Algorithm.Securities.Values, Algorithm.SubscriptionManager.SubscriptionDataConfigService); //Add the algorithm statistics first. - Log.Debug("LiveTradingResultHandler.Update(): Build run time stats"); var summary = GenerateStatisticsResults(performanceCharts).Summary; var runtimeStatistics = GetAlgorithmRuntimeStatistics(summary); - Log.Debug("LiveTradingResultHandler.Update(): End build run time stats"); // since we're sending multiple packets, let's do it async and forget about it @@ -236,7 +231,6 @@ private void Update() //Send full packet to storage. if (utcNow > _nextChartsUpdate) { - Log.Debug("LiveTradingResultHandler.Update(): Pre-store result"); var chartComplete = new Dictionary(); lock (ChartLock) { @@ -255,14 +249,12 @@ private void Update() var complete = new LiveResultPacket(_job, new LiveResult(new LiveResultParameters(chartComplete, orders, Algorithm.Transactions.TransactionRecord, holdings, Algorithm.Portfolio.CashBook, deltaStatistics, runtimeStatistics, orderEvents, serverStatistics, state: GetAlgorithmState()))); StoreResult(complete); _nextChartsUpdate = DateTime.UtcNow.Add(ChartUpdateInterval); - Log.Debug("LiveTradingResultHandler.Update(): End-store result"); } // Upload the logs every 1-2 minutes; this can be a heavy operation depending on amount of live logging and should probably be done asynchronously. if (utcNow > _nextLogStoreUpdate) { List logs; - Log.Debug("LiveTradingResultHandler.Update(): Storing log..."); lock (LogStore) { // we need a new container instance so we can store the logs outside the lock @@ -272,7 +264,6 @@ private void Update() SaveLogs(AlgorithmId, logs); _nextLogStoreUpdate = DateTime.UtcNow.AddMinutes(2); - Log.Debug("LiveTradingResultHandler.Update(): Finished storing log"); } // Every minute send usage statistics: @@ -331,7 +322,6 @@ private void Update() if (utcNow > _nextChartTrimming) { - Log.Debug("LiveTradingResultHandler.Update(): Trimming charts"); var timeLimitUtc = utcNow.AddDays(-2); lock (ChartLock) { @@ -348,7 +338,6 @@ where v.Time > timeLimitUtc } } _nextChartTrimming = DateTime.UtcNow.AddMinutes(10); - Log.Debug("LiveTradingResultHandler.Update(): Finished trimming charts"); } if (utcNow > _nextInsightStoreUpdate) @@ -421,8 +410,6 @@ private void StoreStatusFile(SortedDictionary runtimeStatistics, { try { - Log.Debug("LiveTradingResultHandler.Update(): status update start..."); - if (statistics == null) { statistics = GenerateStatisticsResults(chartComplete, profitLoss); @@ -449,7 +436,6 @@ private void StoreStatusFile(SortedDictionary runtimeStatistics, state: algorithmState)); SaveResults($"{AlgorithmId}.json", result); - Log.Debug("LiveTradingResultHandler.Update(): status update end."); } catch (Exception err) { @@ -613,7 +599,6 @@ protected override void Sample(string chartName, string seriesName, int seriesIn return; } - Log.Debug("LiveTradingResultHandler.Sample(): Sampling " + chartName + "." + seriesName); lock (ChartLock) { //Add a copy locally: @@ -633,7 +618,6 @@ protected override void Sample(string chartName, string seriesName, int seriesIn //Add our value: series.Values.Add(value); } - Log.Debug("LiveTradingResultHandler.Sample(): Done sampling " + chartName + "." + seriesName); } /// @@ -643,7 +627,6 @@ protected override void Sample(string chartName, string seriesName, int seriesIn /// protected void SampleRange(IEnumerable updates) { - Log.Debug("LiveTradingResultHandler.SampleRange(): Begin sampling"); lock (ChartLock) { foreach (var update in updates) @@ -679,7 +662,6 @@ protected void SampleRange(IEnumerable updates) } } } - Log.Debug("LiveTradingResultHandler.SampleRange(): Finished sampling"); } /// @@ -1047,8 +1029,6 @@ public virtual void ProcessSynchronousEvents(bool forceProcess = false) if (time > _nextSample || forceProcess) { - Log.Debug("LiveTradingResultHandler.ProcessSynchronousEvents(): Enter"); - //Set next sample time: 4000 samples per backtest _nextSample = time.Add(ResamplePeriod); @@ -1078,7 +1058,6 @@ public virtual void ProcessSynchronousEvents(bool forceProcess = false) if (Algorithm.Notify.Messages.TryDequeue(out message)) { //Process the notification messages: - Log.Trace("LiveTradingResultHandler.ProcessSynchronousEvents(): Processing Notification..."); try { MessagingHandler.SendNotification(message); @@ -1090,8 +1069,6 @@ public virtual void ProcessSynchronousEvents(bool forceProcess = false) } } } - - Log.Debug("LiveTradingResultHandler.ProcessSynchronousEvents(): Exit"); } /// From aa8a60e19d7abffaa6442341822a01300562b83c Mon Sep 17 00:00:00 2001 From: Josue Nina Date: Tue, 13 Jan 2026 11:37:11 -0500 Subject: [PATCH 2/2] Revert unnecesary log changes --- Engine/Results/LiveTradingResultHandler.cs | 11 +++++++++++ 1 file changed, 11 insertions(+) diff --git a/Engine/Results/LiveTradingResultHandler.cs b/Engine/Results/LiveTradingResultHandler.cs index 62d8f2f65714..2e375cf2274c 100644 --- a/Engine/Results/LiveTradingResultHandler.cs +++ b/Engine/Results/LiveTradingResultHandler.cs @@ -158,6 +158,7 @@ private void Update() //Error checks if the algorithm & threads have not loaded yet, or are closing down. if (Algorithm?.Transactions == null || TransactionHandler.Orders == null || !Algorithm.GetLocked()) { + Log.Debug("LiveTradingResultHandler.Update(): Algorithm not yet initialized."); ExitEvent.WaitOne(1000); return; } @@ -231,6 +232,7 @@ private void Update() //Send full packet to storage. if (utcNow > _nextChartsUpdate) { + Log.Debug("LiveTradingResultHandler.Update(): Pre-store result"); var chartComplete = new Dictionary(); lock (ChartLock) { @@ -249,12 +251,14 @@ private void Update() var complete = new LiveResultPacket(_job, new LiveResult(new LiveResultParameters(chartComplete, orders, Algorithm.Transactions.TransactionRecord, holdings, Algorithm.Portfolio.CashBook, deltaStatistics, runtimeStatistics, orderEvents, serverStatistics, state: GetAlgorithmState()))); StoreResult(complete); _nextChartsUpdate = DateTime.UtcNow.Add(ChartUpdateInterval); + Log.Debug("LiveTradingResultHandler.Update(): End-store result"); } // Upload the logs every 1-2 minutes; this can be a heavy operation depending on amount of live logging and should probably be done asynchronously. if (utcNow > _nextLogStoreUpdate) { List logs; + Log.Debug("LiveTradingResultHandler.Update(): Storing log..."); lock (LogStore) { // we need a new container instance so we can store the logs outside the lock @@ -264,6 +268,7 @@ private void Update() SaveLogs(AlgorithmId, logs); _nextLogStoreUpdate = DateTime.UtcNow.AddMinutes(2); + Log.Debug("LiveTradingResultHandler.Update(): Finished storing log"); } // Every minute send usage statistics: @@ -322,6 +327,7 @@ private void Update() if (utcNow > _nextChartTrimming) { + Log.Debug("LiveTradingResultHandler.Update(): Trimming charts"); var timeLimitUtc = utcNow.AddDays(-2); lock (ChartLock) { @@ -338,6 +344,7 @@ where v.Time > timeLimitUtc } } _nextChartTrimming = DateTime.UtcNow.AddMinutes(10); + Log.Debug("LiveTradingResultHandler.Update(): Finished trimming charts"); } if (utcNow > _nextInsightStoreUpdate) @@ -410,6 +417,8 @@ private void StoreStatusFile(SortedDictionary runtimeStatistics, { try { + Log.Debug("LiveTradingResultHandler.Update(): status update start..."); + if (statistics == null) { statistics = GenerateStatisticsResults(chartComplete, profitLoss); @@ -436,6 +445,7 @@ private void StoreStatusFile(SortedDictionary runtimeStatistics, state: algorithmState)); SaveResults($"{AlgorithmId}.json", result); + Log.Debug("LiveTradingResultHandler.Update(): status update end."); } catch (Exception err) { @@ -1058,6 +1068,7 @@ public virtual void ProcessSynchronousEvents(bool forceProcess = false) if (Algorithm.Notify.Messages.TryDequeue(out message)) { //Process the notification messages: + Log.Trace("LiveTradingResultHandler.ProcessSynchronousEvents(): Processing Notification..."); try { MessagingHandler.SendNotification(message);