From b31aaff1c313f40836b1b8b00dec1a0155c6c1c5 Mon Sep 17 00:00:00 2001 From: Rod Christiansen Date: Wed, 2 Sep 2026 22:51:20 -0700 Subject: [PATCH] Stamp output captured from a package's own process A package's stdout was copied into the session log as one message, so only its first line carried a timestamp and level and the rest landed as bare text between two properly formatted lines. The log viewer renders stamped lines as event rows, which made the raw block stand out as the only thing in the file that was not one. WriteToFile now emits one stamped line per line and drops blank ones, so no multi-line message can produce bare text again. Captured output additionally goes through WriteCapturedOutput, which tags each line [OUTPUT] : and sends stderr at WARN, so a reader can tell the package's words from BootstrapMate's own. ANSI sequences are stripped: a package writes for a terminal, and nothing renders an escape code in a log file. --- Logger.cs | 49 +++++++++++++++++++++++++++++++++++++++++++++++-- Program.cs | 24 ++++++++++++++++++------ 2 files changed, 65 insertions(+), 8 deletions(-) diff --git a/Logger.cs b/Logger.cs index ecefe68..0daeaae 100644 --- a/Logger.cs +++ b/Logger.cs @@ -175,13 +175,40 @@ private static string FileLevel(LogLevel level) }; } + /// + /// Strips ANSI colour sequences. A package's own output is written for a terminal + /// and carries escape codes that nothing renders once they are in a log file. + /// + internal static string StripDecoration(string message) + => System.Text.RegularExpressions.Regex.Replace(message, @"\x1b\[[0-9;]*m", string.Empty); + + /// + /// Writes one stamped line per line of . + /// + /// + /// A multi-line message used to be written with a single stamp on the front, so only + /// its first line carried a timestamp and level and the rest landed in the log as bare + /// text. That is how a package's captured stdout ended up sitting unstamped between + /// two properly formatted lines. Blank lines are dropped: captured output is full of + /// them and they carry nothing. + /// private static void WriteToFile(LogLevel level, string message) { if (string.IsNullOrEmpty(LogFile)) return; - + try { - File.AppendAllText(LogFile, FormatLine(level, message, DateTime.Now) + Environment.NewLine); + var now = DateTime.Now; + var builder = new System.Text.StringBuilder(); + foreach (var line in StripDecoration(message).Split('\n')) + { + var text = line.TrimEnd('\r'); + if (string.IsNullOrWhiteSpace(text)) continue; + builder.Append(FormatLine(level, text, now)).Append(Environment.NewLine); + } + + if (builder.Length > 0) + File.AppendAllText(LogFile, builder.ToString()); } catch { @@ -189,6 +216,24 @@ private static void WriteToFile(LogLevel level, string message) } } + /// + /// Records output captured from a package's own process: stdout at INFO, stderr at + /// WARN, one stamped line each, tagged so a reader can tell the package's words from + /// BootstrapMate's own. The tag is uppercase in brackets at the start of the message, + /// matching [PROGRESS] and [SUCCESS], which the log viewer renders as a pill. + /// + public static void WriteCapturedOutput(string package, string output, bool isError = false) + { + if (string.IsNullOrWhiteSpace(output)) return; + var level = isError ? LogLevel.Warning : LogLevel.Info; + foreach (var line in StripDecoration(output).Split('\n')) + { + var text = line.TrimEnd('\r'); + if (string.IsNullOrWhiteSpace(text)) continue; + WriteToFile(level, $"[OUTPUT] {package}: {text}"); + } + } + private static void WriteToConsole(LogLevel level, string message) { // Skip console output in silent mode diff --git a/Program.cs b/Program.cs index f9c77fe..a5d1bbb 100644 --- a/Program.cs +++ b/Program.cs @@ -1231,6 +1231,18 @@ static bool VerifyInstallerSignature(string filePath, string type, JsonElement p return false; } + static string PackageLabel(JsonElement packageInfo) + { + if (packageInfo.ValueKind == JsonValueKind.Object && + packageInfo.TryGetProperty("name", out var nameProp) && + nameProp.ValueKind == JsonValueKind.String) + { + var name = nameProp.GetString(); + if (!string.IsNullOrWhiteSpace(name)) return name!; + } + return "package"; + } + static async Task RunPowerShellScript(string scriptPath, JsonElement packageInfo) { var args = GetArguments(packageInfo); @@ -1267,7 +1279,7 @@ static async Task RunPowerShellScript(string scriptPath, JsonElement packageInfo string output = await process.StandardOutput.ReadToEndAsync(); if (!string.IsNullOrWhiteSpace(output)) { - WriteLog($"PowerShell output: {output}"); + Logger.WriteCapturedOutput(PackageLabel(packageInfo), output); } } @@ -1276,7 +1288,7 @@ static async Task RunPowerShellScript(string scriptPath, JsonElement packageInfo string error = await process.StandardError.ReadToEndAsync(); if (!string.IsNullOrWhiteSpace(error)) { - WriteLog($"PowerShell error: {error}"); + Logger.WriteCapturedOutput(PackageLabel(packageInfo), error, isError: true); } } @@ -1571,7 +1583,7 @@ static async Task RunExecutable(string exePath, JsonElement packageInfo) string output = await process.StandardOutput.ReadToEndAsync(); if (!string.IsNullOrWhiteSpace(output)) { - WriteLog($"Executable output: {output}"); + Logger.WriteCapturedOutput(PackageLabel(packageInfo), output); } } @@ -1580,7 +1592,7 @@ static async Task RunExecutable(string exePath, JsonElement packageInfo) string error = await process.StandardError.ReadToEndAsync(); if (!string.IsNullOrWhiteSpace(error)) { - WriteLog($"Executable error: {error}"); + Logger.WriteCapturedOutput(PackageLabel(packageInfo), error, isError: true); } } @@ -2636,12 +2648,12 @@ static async Task RunChocolateyInstall(string nupkgPath, JsonElement packageInfo // Always log ALL output for debugging - this is critical for troubleshooting if (!string.IsNullOrWhiteSpace(stdout)) { - Logger.Debug($"Chocolatey stdout: {stdout.Trim()}"); + Logger.WriteCapturedOutput("Chocolatey", stdout); } if (!string.IsNullOrWhiteSpace(stderr)) { - Logger.Debug($"Chocolatey stderr: {stderr.Trim()}"); + Logger.WriteCapturedOutput("Chocolatey", stderr, isError: true); } if (process.ExitCode != 0)