AssetCompiler: canonical console format and an Asset module on asset messages

Warnings and errors print as origin(line,col): category code: text, with the asset file as
origin when known and the AssetMessageCode as code, so VS and MSBuild pick them up and
navigate to the asset. The elapsed time moves out of the code slot onto info/verbose lines,
the module is printed only with verbose/debug output, and the build summary carries the
total time. Step and prepare-failure messages now carry the asset file, and AssetLogMessage
stamps an Asset module and only prints a position when it has one.
This commit is contained in:
Virgile Bello
2026-09-09 09:54:00 +09:00
parent f184621de0
commit d29c098dd6
5 changed files with 104 additions and 51 deletions
@@ -405,39 +405,30 @@ namespace Stride.AssetCompiler
var assetItem = (AssetItem)e.Step.Tag;
var assetRef = assetItem.ToReference();
var project = assetItem.Package;
var assetFile = assetItem.FullPath.ToOSPath();
var stepLogger = e.Step.Logger;
// TODO: Big review of the log infrastructure of CompilerApp & BuildEngine!
if (stepLogger != null)
{
// Attach the asset file so the console can print a navigable origin; a message that already
// has one keeps it, along with its position.
foreach (var message in stepLogger.Messages.Where(x => x.IsAtLeast(LogMessageType.Warning)))
{
builderOptions.Logger.Log(message);
builderOptions.Logger.Log(message is AssetLogMessage { File.Length: > 0 } ? message : AssetLogMessage.From(project, assetRef, message, assetFile));
}
}
switch (e.Step.Status)
var (type, code) = e.Step.Status switch
{
// This case should never happen
case ResultStatus.NotProcessed:
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, LogMessageType.Fatal, AssetMessageCode.InternalCompilerError, assetRef.Location));
break;
case ResultStatus.Successful:
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, LogMessageType.Verbose, AssetMessageCode.CompilationSucceeded, assetRef.Location));
break;
case ResultStatus.Failed:
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, LogMessageType.Error, AssetMessageCode.CompilationFailed, assetRef.Location));
break;
case ResultStatus.Cancelled:
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, LogMessageType.Verbose, AssetMessageCode.CompilationCancelled, assetRef.Location));
break;
case ResultStatus.NotTriggeredWasSuccessful:
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, LogMessageType.Verbose, AssetMessageCode.AssetUpToDate, assetRef.Location));
break;
case ResultStatus.NotTriggeredPrerequisiteFailed:
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, LogMessageType.Error, AssetMessageCode.PrerequisiteFailed, assetRef.Location));
break;
default:
throw new ArgumentOutOfRangeException();
}
ResultStatus.NotProcessed => (LogMessageType.Fatal, AssetMessageCode.InternalCompilerError),
ResultStatus.Successful => (LogMessageType.Verbose, AssetMessageCode.CompilationSucceeded),
ResultStatus.Failed => (LogMessageType.Error, AssetMessageCode.CompilationFailed),
ResultStatus.Cancelled => (LogMessageType.Verbose, AssetMessageCode.CompilationCancelled),
ResultStatus.NotTriggeredWasSuccessful => (LogMessageType.Verbose, AssetMessageCode.AssetUpToDate),
ResultStatus.NotTriggeredPrerequisiteFailed => (LogMessageType.Error, AssetMessageCode.PrerequisiteFailed),
_ => throw new ArgumentOutOfRangeException(),
};
builderOptions.Logger.Log(new AssetLogMessage(project, assetRef, type, code, assetRef.Location) { File = assetFile });
e.Step.StepProcessed -= BuildStepProcessed;
}
@@ -43,6 +43,9 @@ namespace Stride.AssetCompiler
private static Stopwatch clock;
// Modules are only meaningful when following the compiler's internals (verbose/debug output).
private static bool showModule;
private LogListener globalLoggerOnGlobalMessageLogged;
private PackageBuilder builder;
@@ -239,6 +242,7 @@ namespace Stride.AssetCompiler
// Activate proper log level
buildEngineLogger.ActivateLog(options.LoggerType);
showModule = options.LoggerType <= LogMessageType.Verbose;
// Output logs to the console with colored messages
if (options.SlavePipe == null)
@@ -452,7 +456,7 @@ namespace Stride.AssetCompiler
GlobalLogger.GlobalMessageLogged += fileLogListener;
}
options.Logger.Info("BuildEngine arguments: " + string.Join(" ", args));
options.Logger.Info("BuildEngine arguments: " + string.Join(" ", args.Select(QuoteArgument)));
options.Logger.Info("Starting builder.");
}
else
@@ -575,21 +579,54 @@ namespace Stride.AssetCompiler
logger.Info($"Reconciled {changedCount} asset(s) with their base out of {graphs.Count}.");
}
// Re-quotes what the shell stripped, so the printed line can be pasted back: only the value of
// an --option=value argument, the whole argument otherwise.
private static string QuoteArgument(string argument)
{
if (!argument.Contains(' '))
return argument;
var separator = argument.IndexOf('=');
if (argument.StartsWith("--", StringComparison.Ordinal) && separator > 2 && argument.AsSpan(0, separator).IndexOf(' ') < 0)
return $"{argument[..(separator + 1)]}\"{argument[(separator + 1)..]}\"";
return $"\"{argument}\"";
}
private static string FormatLog(ILogMessage message)
{
//$filename($row,$column): $error_type $error_code: $error_message
//C:\Code\Stride\sources\assets\Stride.AssetCompiler\PackageBuilder.cs(89,13,89,70): warning CS1717: Assignment made to same variable; did you mean to assign something else?
// Warnings and errors use the canonical MSBuild/VS format, so they are picked up and navigable:
// origin(line,col): category code: text
// The origin is only known for asset messages carrying a file. Lower severities are
// not parsed by anyone and stay compact: type, elapsed time, text.
var builder = new StringBuilder();
var assetLogMessage = message as AssetLogMessage;
// Location
if (assetLogMessage != null)
builder.Append($"{assetLogMessage.File}({assetLogMessage.Line + 1},{assetLogMessage.Character + 1}): ");
// Message type
builder.Append(message.Type.ToString().ToLowerInvariant()).Append(" ");
builder.Append((clock.ElapsedMilliseconds * 0.001).ToString("0.000"));
builder.Append("s: ");
builder.Append($"[{message.Module ?? "AssetCompiler"}] ");
builder.Append(message.Text);
var text = message.Text;
if (message.Type >= LogMessageType.Warning)
{
if (!string.IsNullOrEmpty(assetLogMessage?.File))
{
builder.Append(assetLogMessage.File);
if (assetLogMessage.Line > 0 || assetLogMessage.Character > 0)
builder.Append($"({assetLogMessage.Line + 1},{assetLogMessage.Character + 1})");
builder.Append(": ");
text = assetLogMessage.TextWithoutLocation;
}
builder.Append(message.Type == LogMessageType.Warning ? "warning" : "error");
if (assetLogMessage != null)
builder.Append(' ').Append(assetLogMessage.MessageCode);
builder.Append(": ");
}
else
{
builder.Append(message.Type.ToString().ToLowerInvariant()).Append(": ");
builder.Append((clock.ElapsedMilliseconds * 0.001).ToString("0.000")).Append("s ");
}
if (showModule && message.Module != null)
builder.Append('[').Append(message.Module).Append("] ");
builder.Append(text);
var exceptionInfo = message.ExceptionInfo;
if (exceptionInfo != null)
{
@@ -2,6 +2,7 @@
// Distributed under the MIT license. See the LICENSE.md file in the project root for more information.
using Stride.Core.Assets.Analysis;
using Stride.Core.Assets.Diagnostics;
using Stride.Core.BuildEngine;
using Stride.Core.Diagnostics;
@@ -139,8 +140,10 @@ public class AssetDependenciesCompiler
public override Task<ResultStatus> Execute(IExecuteContext executeContext, BuilderContext builderContext)
{
var assetItem = AssetItem;
var assetFullPath = assetItem.FullPath.ToOSPath();
foreach (var message in messages)
executeContext.Logger.Log(message);
executeContext.Logger.Log(AssetLogMessage.From(assetItem.Package, assetItem.ToReference(), message, assetFullPath));
return Task.FromResult(ResultStatus.Failed);
}
}
@@ -13,6 +13,11 @@ namespace Stride.Core.Assets.Diagnostics;
/// </summary>
public class AssetLogMessage : LogMessage
{
/// <summary>
/// The <see cref="LogMessage.Module"/> of every asset message.
/// </summary>
public const string LogModule = "Asset";
/// <summary>
/// Initializes a new instance of the <see cref="AssetLogMessage" /> class.
/// </summary>
@@ -22,7 +27,7 @@ public class AssetLogMessage : LogMessage
/// <param name="messageCode">The message code.</param>
/// <exception cref="ArgumentNullException">asset</exception>
public AssetLogMessage(Package? package, IReference? assetReference, LogMessageType type, AssetMessageCode messageCode)
: base(null, type, AssetMessageStrings.ResourceManager.GetString(messageCode.ToString()) ?? messageCode.ToString())
: base(LogModule, type, AssetMessageStrings.ResourceManager.GetString(messageCode.ToString()) ?? messageCode.ToString())
{
Package = package;
AssetReference = assetReference;
@@ -40,7 +45,7 @@ public class AssetLogMessage : LogMessage
/// <param name="arguments">The arguments.</param>
/// <exception cref="ArgumentNullException">asset</exception>
public AssetLogMessage(Package? package, IReference? assetReference, LogMessageType type, AssetMessageCode messageCode, params object?[] arguments)
: base(null, type, string.Format(AssetMessageStrings.ResourceManager.GetString(messageCode.ToString()) ?? messageCode.ToString(), arguments))
: base(LogModule, type, string.Format(AssetMessageStrings.ResourceManager.GetString(messageCode.ToString()) ?? messageCode.ToString(), arguments))
{
Package = package;
AssetReference = assetReference;
@@ -56,10 +61,11 @@ public class AssetLogMessage : LogMessage
/// <param name="type">The type.</param>
/// <exception cref="ArgumentNullException">asset</exception>
public AssetLogMessage(Package? package, IReference? assetReference, LogMessageType type, string text)
: base(null, type, text)
: base(LogModule, type, text)
{
Package = package;
AssetReference = assetReference;
MessageCode = AssetMessageCode.CompilationMessage;
Related = [];
}
@@ -95,16 +101,26 @@ public class AssetLogMessage : LogMessage
public int Character { get; set; }
/// <summary>
/// Gets the text prefixed with the asset location, and the position in the asset when known.
/// </summary>
public override string Text
{
get
{
if (AssetReference?.Location != null)
return $"{AssetReference.Location}({Line + 1},{Character + 1}): {base.Text}";
return base.Text;
if (AssetReference?.Location == null)
return base.Text;
return Line > 0 || Character > 0
? $"{AssetReference.Location}({Line + 1},{Character + 1}): {base.Text}"
: $"{AssetReference.Location}: {base.Text}";
}
}
/// <summary>
/// Gets the text without the location prefix of <see cref="Text"/>, for formatters that print their own origin.
/// </summary>
public string TextWithoutLocation => base.Text;
/// <summary>
/// Gets or sets the message code.
/// </summary>
@@ -1,6 +1,7 @@
// Copyright (c) .NET Foundation and Contributors (https://dotnetfoundation.org/ & https://stride3d.net) and Silicon Studio Corp. (https://www.siliconstudio.co.jp)
// Distributed under the MIT license. See the LICENSE.md file in the project root for more information.
using System.Diagnostics;
using System.Globalization;
using Stride.Core.Diagnostics;
using Stride.Core.Extensions;
@@ -228,6 +229,7 @@ public class Builder : IDisposable
Cancelled = false;
IsRunning = true;
DisableCompressionIds.Clear();
var runClock = Stopwatch.StartNew();
// Reseting result map
var inputHashes = FileVersionTracker.GetDefault();
@@ -268,17 +270,21 @@ public class Builder : IDisposable
Logger.Error("Build cancelled.");
result = BuildResultCode.Cancelled;
}
else if (stepCounter.Get(ResultStatus.Failed) > 0 || stepCounter.Get(ResultStatus.NotTriggeredPrerequisiteFailed) > 0)
{
Logger.Error($"Build finished in {stepCounter.Total} steps. Command results: {stepCounter.Get(ResultStatus.Successful)} succeeded, {stepCounter.Get(ResultStatus.NotTriggeredWasSuccessful)} up-to-date, {stepCounter.Get(ResultStatus.Failed)} failed, {stepCounter.Get(ResultStatus.NotTriggeredPrerequisiteFailed)} not triggered due to previous failure.");
Logger.Error("Build failed.");
result = BuildResultCode.BuildError;
}
else
{
Logger.Info($"Build finished in {stepCounter.Total} steps. Command results: {stepCounter.Get(ResultStatus.Successful)} succeeded, {stepCounter.Get(ResultStatus.NotTriggeredWasSuccessful)} up-to-date, {stepCounter.Get(ResultStatus.Failed)} failed, {stepCounter.Get(ResultStatus.NotTriggeredPrerequisiteFailed)} not triggered due to previous failure.");
Logger.Info("Build is successful.");
result = BuildResultCode.Successful;
var summary = $"Build finished in {stepCounter.Total} steps ({runClock.Elapsed.TotalSeconds:0.0}s). Command results: {stepCounter.Get(ResultStatus.Successful)} succeeded, {stepCounter.Get(ResultStatus.NotTriggeredWasSuccessful)} up-to-date, {stepCounter.Get(ResultStatus.Failed)} failed, {stepCounter.Get(ResultStatus.NotTriggeredPrerequisiteFailed)} not triggered due to previous failure.";
if (stepCounter.Get(ResultStatus.Failed) > 0 || stepCounter.Get(ResultStatus.NotTriggeredPrerequisiteFailed) > 0)
{
Logger.Error(summary);
Logger.Error("Build failed.");
result = BuildResultCode.BuildError;
}
else
{
Logger.Info(summary);
Logger.Info("Build is successful.");
result = BuildResultCode.Successful;
}
}
}
else