Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion Algorithm/QCAlgorithm.cs
Original file line number Diff line number Diff line change
Expand Up @@ -3817,7 +3817,7 @@ private DateTime GetTimeInExchangeTimeZone(Symbol symbol)

private string FormatLog(string message)
{
return $"{Time.ToStringInvariant(DateFormat.UI)} {message}";
return message.PrefixWithAlgorithmTime(Time);
}
}
}
12 changes: 12 additions & 0 deletions Common/Extensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,18 @@ public static class Extensions
private static readonly Dictionary<IntPtr, PythonActivator> PythonActivators
= new Dictionary<IntPtr, PythonActivator>();

/// <summary>
/// Prefixes the given message with the provided algorithm time, producing the standard
/// timestamped format shared by algorithm logs and messages
/// </summary>
/// <param name="message">The message to prefix</param>
/// <param name="algorithmTime">The algorithm time to prefix the message with</param>
/// <returns>The message prefixed with the algorithm time</returns>
public static string PrefixWithAlgorithmTime(this string message, DateTime algorithmTime)
{
return $"{algorithmTime.ToStringInvariant(DateFormat.UI)} {message}";
}

/// <summary>
/// Maintains old behavior of NodaTime's (&lt; 2.0) daylight savings mapping.
/// We keep the old behavior to ensure the FillForwardEnumerator does not get stuck on an infinite loop.
Expand Down
8 changes: 6 additions & 2 deletions Engine/Results/BacktestingResultHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -469,6 +469,7 @@ public override void SetAlgorithm(IAlgorithm algorithm, decimal startingPortfoli
/// <param name="message">Message we'd like shown in console.</param>
public virtual void DebugMessage(string message)
{
message = FormatMessage(message);
Messages.Enqueue(new DebugPacket(_projectId, AlgorithmId, CompileId, message));
AddToLogStore(message);
}
Expand All @@ -479,6 +480,7 @@ public virtual void DebugMessage(string message)
/// <param name="message">Message we'd like shown in console.</param>
public virtual void SystemDebugMessage(string message)
{
message = FormatMessage(message);
Messages.Enqueue(new SystemDebugPacket(_projectId, AlgorithmId, CompileId, message));
AddToLogStore(message);
}
Expand All @@ -489,6 +491,7 @@ public virtual void SystemDebugMessage(string message)
/// <param name="message">Message we'd in the log.</param>
public virtual void LogMessage(string message)
{
message = FormatMessage(message);
Messages.Enqueue(new LogPacket(AlgorithmId, message));
AddToLogStore(message);
}
Expand All @@ -502,8 +505,8 @@ public virtual void ErrorMessage(string message, string stacktrace = "")
{
if (message == _errorMessage) return;
if (Messages.Count > 500) return;
Messages.Enqueue(new HandledErrorPacket(AlgorithmId, message, stacktrace));
_errorMessage = message;
Messages.Enqueue(new HandledErrorPacket(AlgorithmId, FormatMessage(message), stacktrace));
}

/// <summary>
Expand All @@ -514,8 +517,9 @@ public virtual void ErrorMessage(string message, string stacktrace = "")
public virtual void RuntimeError(string message, string stacktrace = "")
{
PurgeQueue();
Messages.Enqueue(new RuntimeErrorPacket(_job.UserId, AlgorithmId, message, stacktrace));
_errorMessage = message;
message = FormatMessage(message);
Messages.Enqueue(new RuntimeErrorPacket(_job.UserId, AlgorithmId, message, stacktrace));
SetAlgorithmState(message, stacktrace);
}

Expand Down
14 changes: 13 additions & 1 deletion Engine/Results/BaseResultsHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -1122,6 +1122,18 @@ protected StatisticsResults GenerateStatisticsResults(CapacityEstimate estimated
return GenerateStatisticsResults(charts, profitLoss, estimatedStrategyCapacity);
}

/// <summary>
/// Prefixes the given message with the algorithm time, matching the format used by
/// the algorithm's own log messages (see <see cref="IAlgorithm.Log"/>). Used to normalize
/// the timestamp across all algorithm logs and messages.
/// </summary>
/// <param name="message">The message to format</param>
/// <returns>The message prefixed with the algorithm time, or the original message if the algorithm is not yet available</returns>
protected string FormatMessage(string message)
{
return Algorithm != null ? message.PrefixWithAlgorithmTime(Algorithm.Time) : message;
}

/// <summary>
/// Save an algorithm message to the log store. Uses a different timestamped method of adding messaging to interweve debug and logging messages.
/// </summary>
Expand Down Expand Up @@ -1171,7 +1183,7 @@ private void ProcessAlgorithmLogsImpl(ConcurrentQueue<string> concurrentQueue, P
{
_packetDroppedWarning = true;
// this shouldn't happen in most cases, queue limit is high and consumed often but just in case let's not silently drop packets without a warning
Messages.Enqueue(new HandledErrorPacket(AlgorithmId, "Your algorithm messaging has been rate limited to prevent browser flooding."));
Messages.Enqueue(new HandledErrorPacket(AlgorithmId, FormatMessage("Your algorithm messaging has been rate limited to prevent browser flooding.")));
}
//if too many in the queue already skip the logging and drop the messages
continue;
Expand Down
9 changes: 7 additions & 2 deletions Engine/Results/LiveTradingResultHandler.cs
Original file line number Diff line number Diff line change
Expand Up @@ -254,8 +254,8 @@ private void Update()

var deltaStatistics = new Dictionary<string, string>();
var orders = new Dictionary<int, Order>(TransactionHandler.Orders);
var complete = new LiveResultPacket(_job, new LiveResult(new LiveResultParameters(chartComplete, orders,
Algorithm.Transactions.TransactionRecord, holdings, Algorithm.Portfolio.CashBook, deltaStatistics,
var complete = new LiveResultPacket(_job, new LiveResult(new LiveResultParameters(chartComplete, orders,
Algorithm.Transactions.TransactionRecord, holdings, Algorithm.Portfolio.CashBook, deltaStatistics,
runtimeStatistics, orderEvents, statistics.TotalPerformance, serverStatistics, state: GetAlgorithmState())));
StoreResult(complete);
_nextChartsUpdate = DateTime.UtcNow.Add(ChartUpdateInterval);
Expand Down Expand Up @@ -544,6 +544,7 @@ private IEnumerable<LiveResultPacket> SplitPackets(Dictionary<string, Chart> del
public void DebugMessage(string message)
{
if (Messages.Count > 500) return; //if too many in the queue already skip the logging.
message = FormatMessage(message);
Messages.Enqueue(new DebugPacket(_job.ProjectId, AlgorithmId, CompileId, message));
AddToLogStore(message);
}
Expand All @@ -554,6 +555,7 @@ public void DebugMessage(string message)
/// <param name="message">Message we'd like shown in console.</param>
public void SystemDebugMessage(string message)
{
message = FormatMessage(message);
Messages.Enqueue(new SystemDebugPacket(_job.ProjectId, AlgorithmId, CompileId, message));
AddToLogStore(message);
}
Expand All @@ -568,6 +570,7 @@ public void LogMessage(string message)
{
//Send the logging messages out immediately for live trading:
if (Messages.Count > 500) return;
message = FormatMessage(message);
Messages.Enqueue(new LogPacket(AlgorithmId, message));
AddToLogStore(message);
}
Expand All @@ -580,6 +583,7 @@ public void LogMessage(string message)
public void ErrorMessage(string message, string stacktrace = "")
{
if (Messages.Count > 500) return;
message = FormatMessage(message);
Messages.Enqueue(new HandledErrorPacket(AlgorithmId, message, stacktrace));
AddToLogStore(message + (!string.IsNullOrEmpty(stacktrace) ? ": StackTrace: " + stacktrace : string.Empty));
}
Expand All @@ -591,6 +595,7 @@ public void ErrorMessage(string message, string stacktrace = "")
/// <param name="stacktrace">Associated error stack trace.</param>
public virtual void RuntimeError(string message, string stacktrace = "")
{
message = FormatMessage(message);
Messages.Enqueue(new RuntimeErrorPacket(_job.UserId, AlgorithmId, message, stacktrace));
AddToLogStore(message + (!string.IsNullOrEmpty(stacktrace) ? ": StackTrace: " + stacktrace : string.Empty));
SetAlgorithmState(message, stacktrace);
Expand Down
32 changes: 32 additions & 0 deletions Tests/Engine/Results/LiveTradingResultHandlerTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,7 @@
using QuantConnect.Lean.Engine.TransactionHandlers;
using QuantConnect.Tests.Common.Data.UniverseSelection;
using QuantConnect.Data.Custom.IconicTypes;
using System.Collections.Generic;

namespace QuantConnect.Tests.Engine.Results
{
Expand Down Expand Up @@ -190,6 +191,37 @@ public void DailySampleValueBasedOnMarketHour(bool extendedMarketHoursEnabled)
}
}

[Test]
public void MessagesArePrefixedWithAlgorithmTime()
{
using var messaging = new QuantConnect.Messaging.Messaging();
var result = new LiveTradingResultHandler();
result.Initialize(new(new LiveNodePacket(), messaging, null, new BacktestingTransactionHandler(), null));

var algorithm = new AlgorithmStub();
algorithm.AddEquity("SPY");
algorithm.SetDateTime(new DateTime(2026, 1, 15, 9, 30, 0));
result.SetAlgorithm(algorithm, 10);

var algorithmTimePrefix = algorithm.Time.ToStringInvariant(DateFormat.UI);

result.Messages.Clear();
result.DebugMessage("debug message");
result.LogMessage("log message");
result.ErrorMessage("error message");
result.RuntimeError("runtime message");

var messages = new List<string>()
{
result.Messages.OfType<DebugPacket>().Single().Message,
result.Messages.OfType<LogPacket>().Single().Message,
result.Messages.OfType<HandledErrorPacket>().Single().Message,
result.Messages.OfType<RuntimeErrorPacket>().Single().Message
};

Assert.That(messages, Has.All.StartsWith(algorithmTimePrefix));
}

private class TestDataFeed : IDataFeed
{
public bool IsActive { get; }
Expand Down
Loading