From d29c098dd6b36fbd33a8ace83208dbef7a1262a1 Mon Sep 17 00:00:00 2001 From: Virgile Bello Date: Tue, 8 Sep 2026 21:38:10 +0900 Subject: [PATCH] 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. --- .../Stride.AssetCompiler/PackageBuilder.cs | 37 +++++------ .../Stride.AssetCompiler/PackageBuilderApp.cs | 61 +++++++++++++++---- .../Compiler/AssetDependenciesCompiler.cs | 5 +- .../Diagnostics/AssetLogMessage.cs | 28 +++++++-- .../Stride.Core.BuildEngine.Common/Builder.cs | 24 +++++--- 5 files changed, 104 insertions(+), 51 deletions(-) diff --git a/sources/assets/Stride.AssetCompiler/PackageBuilder.cs b/sources/assets/Stride.AssetCompiler/PackageBuilder.cs index 7e5aa5c74..d54d59f1e 100644 --- a/sources/assets/Stride.AssetCompiler/PackageBuilder.cs +++ b/sources/assets/Stride.AssetCompiler/PackageBuilder.cs @@ -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; } diff --git a/sources/assets/Stride.AssetCompiler/PackageBuilderApp.cs b/sources/assets/Stride.AssetCompiler/PackageBuilderApp.cs index b12fbd676..5af955377 100644 --- a/sources/assets/Stride.AssetCompiler/PackageBuilderApp.cs +++ b/sources/assets/Stride.AssetCompiler/PackageBuilderApp.cs @@ -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) { diff --git a/sources/assets/Stride.Core.Assets/Compiler/AssetDependenciesCompiler.cs b/sources/assets/Stride.Core.Assets/Compiler/AssetDependenciesCompiler.cs index e0277205e..927b0fbb2 100644 --- a/sources/assets/Stride.Core.Assets/Compiler/AssetDependenciesCompiler.cs +++ b/sources/assets/Stride.Core.Assets/Compiler/AssetDependenciesCompiler.cs @@ -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 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); } } diff --git a/sources/assets/Stride.Core.Assets/Diagnostics/AssetLogMessage.cs b/sources/assets/Stride.Core.Assets/Diagnostics/AssetLogMessage.cs index 9f1cc5991..8a0d55fa8 100644 --- a/sources/assets/Stride.Core.Assets/Diagnostics/AssetLogMessage.cs +++ b/sources/assets/Stride.Core.Assets/Diagnostics/AssetLogMessage.cs @@ -13,6 +13,11 @@ namespace Stride.Core.Assets.Diagnostics; /// public class AssetLogMessage : LogMessage { + /// + /// The of every asset message. + /// + public const string LogModule = "Asset"; + /// /// Initializes a new instance of the class. /// @@ -22,7 +27,7 @@ public class AssetLogMessage : LogMessage /// The message code. /// asset 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 /// The arguments. /// asset 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 /// The type. /// asset 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; } + /// + /// Gets the text prefixed with the asset location, and the position in the asset when known. + /// 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}"; } } + /// + /// Gets the text without the location prefix of , for formatters that print their own origin. + /// + public string TextWithoutLocation => base.Text; + /// /// Gets or sets the message code. /// diff --git a/sources/buildengine/Stride.Core.BuildEngine.Common/Builder.cs b/sources/buildengine/Stride.Core.BuildEngine.Common/Builder.cs index 34806a95b..6c821ddb9 100644 --- a/sources/buildengine/Stride.Core.BuildEngine.Common/Builder.cs +++ b/sources/buildengine/Stride.Core.BuildEngine.Common/Builder.cs @@ -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