From ee3d13bfb7eb064774f51c25408f638fa87db6d5 Mon Sep 17 00:00:00 2001 From: Rod Christiansen Date: Thu, 3 Sep 2026 01:03:35 -0700 Subject: [PATCH] Give each run a session directory with structured events #21 A run now owns logs\YYYY-MM-DD\HHMMSS\, holding bootstrap.log beside events.jsonl and session.json, matching the macOS build and the managed-software tools. Every line written to the human log is also appended as a JSON record with its bracketed tag lifted into an event type and status, and session.json carries the run type, outcome, tool version, environment and counts. Retention drops day directories past the window and session directories past a cap of 100, and still sweeps the flat per-run files the old layout left. --- Logger.cs | 34 +- SessionLog.cs | 294 ++++++++++++++++++ .../ViewModels/LogsViewModel.cs | 46 ++- 3 files changed, 363 insertions(+), 11 deletions(-) create mode 100644 SessionLog.cs diff --git a/Logger.cs b/Logger.cs index 0daeaae..c8773ee 100644 --- a/Logger.cs +++ b/Logger.cs @@ -1,4 +1,5 @@ using System; +using System.Collections.Generic; using System.IO; namespace BootstrapMate @@ -15,6 +16,12 @@ public enum LogLevel public static class Logger { private static string? LogFile; + /// + /// The run's session directory and its structured files. Null only when the + /// session directory could not be created, in which case the run falls back + /// to a flat per-run file at the logs root. + /// + private static SessionLog? _session; private static bool _verboseConsole = false; private static bool _silentMode = false; private static DateTime _sessionStartTime; @@ -26,7 +33,7 @@ public static class Logger /// public static void SetPipeWriter(TextWriter? writer) => _pipeWriter = writer; - public static void Initialize(string logDirectory, string version = "Unknown", bool verboseConsole = false, bool silentMode = false) + public static void Initialize(string logDirectory, string version = "Unknown", bool verboseConsole = false, bool silentMode = false, string runType = "provisioning") { try { @@ -40,10 +47,18 @@ public static void Initialize(string logDirectory, string version = "Unknown", b Directory.CreateDirectory(logDirectory); } - LogFile = Path.Combine(logDirectory, $"{DateTime.Now:yyyy-MM-dd-HHmmss}.log"); - + // Retention runs before the run opens its own directory: day directories + // past the window, session directories past the cap, and the loose per-run + // files the flat layout left at the root. + SessionLog.Prune(logDirectory, BootstrapMate.Core.BootstrapMateConstants.LogRetentionDays, _sessionStartTime); PruneExpiredLogs(logDirectory); + // This run's session directory: logs\YYYY-MM-DD\HHMMSS\, holding + // bootstrap.log beside events.jsonl and session.json. + _session = SessionLog.Create(logDirectory, version, runType, _sessionStartTime); + LogFile = _session?.LogFilePath + ?? Path.Combine(logDirectory, $"{_sessionStartTime:yyyy-MM-dd-HHmmss}.log"); + // Write session header to log file WriteToFile(LogLevel.Info, "=== BootstrapMate Session Started ==="); WriteToFile(LogLevel.Info, $"Version: {version}"); @@ -200,15 +215,24 @@ private static void WriteToFile(LogLevel level, string message) { var now = DateTime.Now; var builder = new System.Text.StringBuilder(); + var records = new List(); 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); + records.Add(text); } if (builder.Length > 0) File.AppendAllText(LogFile, builder.ToString()); + + // The same records, structured, one JSON object per physical line. + if (_session is not null) + { + var label = FileLevel(level); + foreach (var text in records) _session.Append(label, text, now); + } } catch { @@ -408,6 +432,10 @@ public static void WriteSessionSummary() WriteToFile(LogLevel.Info, $"=== BootstrapMate Session Ended === (Duration: {duration.TotalSeconds:F1}s)"); WriteToFile(LogLevel.Info, $"Session End Time: {timestamp}"); WriteToFile(LogLevel.Info, $"Total Session Duration: {duration.TotalMinutes:F2} minutes"); + _session?.Finish(); } + + /// The session id of the run in progress, when it has a session directory. + public static string? GetSessionId() => _session?.SessionId; } } diff --git a/SessionLog.cs b/SessionLog.cs new file mode 100644 index 0000000..59bf49d --- /dev/null +++ b/SessionLog.cs @@ -0,0 +1,294 @@ +using System; +using System.Collections.Generic; +using System.IO; +using System.Linq; +using System.Text.Json; +using System.Text.Json.Serialization; + +namespace BootstrapMate +{ + /// + /// The structured half of a run's logs. + /// + /// + /// Every run owns a session directory under the tool's logs root, + /// C:\ProgramData\ManagedBootstrap\logs\YYYY-MM-DD\HHMMSS\, holding + /// bootstrap.log (the human log, written by ), events.jsonl + /// (one JSON record per line, appended as the run proceeds) and session.json + /// (the run as a whole, written when it starts and rewritten when it ends). + /// The layout and field names match Cimian's session logger and the macOS + /// BootstrapMate's, so the same readers work on every managed tool. + /// + public sealed class SessionLog + { + /// Session directories kept across all days, newest first. + public const int MaxSessions = 100; + + private static readonly JsonSerializerOptions EventOptions = new() + { + DefaultIgnoreCondition = JsonIgnoreCondition.WhenWritingNull + }; + + private static readonly JsonSerializerOptions SessionOptions = new() + { + WriteIndented = true, + DefaultIgnoreCondition = JsonIgnoreCondition.WhenWritingNull + }; + + public string SessionId { get; } + public string SessionDirectory { get; } + public string LogFilePath { get; } + + private readonly DateTime _startTime; + private readonly string _runType; + private readonly string _version; + private readonly string _eventsPath; + private readonly object _writeLock = new(); + private int _eventIndex; + private int _errors; + private int _warnings; + private int _events; + + private SessionLog(string sessionDirectory, string sessionId, DateTime start, string runType, string version) + { + SessionDirectory = sessionDirectory; + SessionId = sessionId; + LogFilePath = Path.Combine(sessionDirectory, "bootstrap.log"); + _startTime = start; + _runType = runType; + _version = version; + _eventsPath = Path.Combine(sessionDirectory, "events.jsonl"); + WriteSessionFile("running"); + } + + /// + /// Creates logs\YYYY-MM-DD\HHMMSS\, appending _2 through _9 + /// when a previous run started in the same second. Returns null when the directory + /// cannot be created, which leaves the caller to fall back to a flat file. + /// + public static SessionLog? Create(string logsDirectory, string version, string runType, DateTime start) + { + try + { + var day = start.ToString("yyyy-MM-dd"); + var time = start.ToString("HHmmss"); + var dayDirectory = Path.Combine(logsDirectory, day); + var directory = Path.Combine(dayDirectory, time); + var name = time; + + if (Directory.Exists(directory)) + { + var placed = false; + for (var suffix = 2; suffix <= 9; suffix++) + { + var candidate = Path.Combine(dayDirectory, $"{time}_{suffix}"); + if (Directory.Exists(candidate)) continue; + directory = candidate; + name = $"{time}_{suffix}"; + placed = true; + break; + } + if (!placed) return null; + } + + Directory.CreateDirectory(directory); + return new SessionLog(directory, $"{day}-{name}", start, runType, version); + } + catch + { + // A session directory is a convenience; a run must never fail over one. + return null; + } + } + + /// + /// Appends one record to events.jsonl and keeps the run's counts. + /// is the same text the human log carries, with any leading [TAG] lifted into the + /// event's type and status. + /// + public void Append(string level, string message, DateTime timestamp) + { + var (eventType, status, text) = Classify(level, message); + lock (_writeLock) + { + if (level == "ERROR") _errors++; + else if (level == "WARN") _warnings++; + _events++; + _eventIndex++; + + var record = new SessionEvent + { + EventId = $"{SessionId}-{_eventIndex:D5}", + SessionId = SessionId, + Timestamp = timestamp.ToString("yyyy-MM-ddTHH:mm:ss.fffzzz"), + Level = level, + EventType = eventType, + Status = status, + Message = text, + Error = level == "ERROR" ? text : null + }; + + try + { + File.AppendAllText(_eventsPath, JsonSerializer.Serialize(record, EventOptions) + Environment.NewLine); + } + catch + { + // Structured logging is best-effort and must never stop a run. + } + } + } + + /// Rewrites session.json with the run's outcome. + public void Finish(string? status = null, DateTime? end = null) + { + var finished = end ?? DateTime.Now; + var resolved = status ?? (_errors > 0 ? "partial_failure" : "completed"); + WriteSessionFile(resolved, finished); + } + + private void WriteSessionFile(string status, DateTime? end = null) + { + var record = new SessionRecord + { + SessionId = SessionId, + StartTime = _startTime.ToString("yyyy-MM-ddTHH:mm:ss.fffzzz"), + EndTime = end?.ToString("yyyy-MM-ddTHH:mm:ss.fffzzz"), + DurationSeconds = end.HasValue ? (int)Math.Round((end.Value - _startTime).TotalSeconds) : null, + RunType = _runType, + Status = status, + ToolVersion = _version, + Environment = new Dictionary + { + ["hostname"] = System.Environment.MachineName, + ["os_version"] = System.Environment.OSVersion.ToString(), + ["user"] = System.Environment.UserName, + ["pid"] = System.Environment.ProcessId.ToString(), + ["command_line"] = System.Environment.CommandLine + }, + Summary = new SessionSummary { Events = _events, Errors = _errors, Warnings = _warnings } + }; + + try + { + File.WriteAllText(Path.Combine(SessionDirectory, "session.json"), + JsonSerializer.Serialize(record, SessionOptions)); + } + catch + { + // Best-effort, as above. + } + } + + /// + /// Lifts a leading [TAG] off a message into an event type and status, so the + /// structured stream carries what the human log carries in prose. An unrecognised + /// bracket is left in the message rather than invented into a type. + /// + internal static (string EventType, string? Status, string Message) Classify(string level, string message) + { + var fallbackType = level == "ERROR" ? "error" : "message"; + var fallbackStatus = level == "ERROR" ? "FAILED" : null; + if (!message.StartsWith('[')) return (fallbackType, fallbackStatus, message); + var close = message.IndexOf(']'); + if (close < 0) return (fallbackType, fallbackStatus, message); + + var tag = message.Substring(1, close - 1).ToUpperInvariant(); + var text = message[(close + 1)..].TrimStart(' '); + return tag switch + { + "SECTION" => ("section", null, text), + "PROGRESS" or "SUB-PROGRESS" => ("progress", "PROGRESS", text), + "SUCCESS" => ("item", "SUCCESS", text), + "SKIPPED" => ("item", "SKIPPED", text), + "COMPLETION" => ("session_end", "SUCCESS", text), + "OUTPUT" => ("output", null, text), + _ => (fallbackType, fallbackStatus, message) + }; + } + + /// + /// Removes day directories older than the retention window, then the oldest session + /// directories beyond the cap. Loose per-run files left at the logs root by the flat + /// layout this replaced are swept separately, by the same age rule, in + /// . + /// + internal static int Prune(string logsDirectory, int retentionDays, DateTime now) + { + var removed = 0; + try + { + if (!Directory.Exists(logsDirectory)) return 0; + var cutoff = now.AddDays(-retentionDays).Date; + var dayDirectories = Directory.GetDirectories(logsDirectory) + .Select(path => (Path: path, Name: Path.GetFileName(path))) + .Where(entry => DateTime.TryParseExact(entry.Name, "yyyy-MM-dd", + System.Globalization.CultureInfo.InvariantCulture, + System.Globalization.DateTimeStyles.None, out _)) + .OrderByDescending(entry => entry.Name, StringComparer.Ordinal) + .ToList(); + + var surviving = new List<(string Path, string Name)>(); + foreach (var entry in dayDirectories) + { + var day = DateTime.ParseExact(entry.Name, "yyyy-MM-dd", + System.Globalization.CultureInfo.InvariantCulture); + if (day < cutoff) + { + try { Directory.Delete(entry.Path, recursive: true); removed++; } catch { } + } + else + { + surviving.Add(entry); + } + } + + var sessions = surviving + .SelectMany(entry => Directory.GetDirectories(entry.Path) + .OrderByDescending(Path.GetFileName, StringComparer.Ordinal)) + .ToList(); + foreach (var path in sessions.Skip(MaxSessions)) + { + try { Directory.Delete(path, recursive: true); removed++; } catch { } + } + } + catch + { + // Retention is best-effort and must never stop a bootstrap run. + } + return removed; + } + + private sealed class SessionEvent + { + [JsonPropertyName("event_id")] public string EventId { get; set; } = ""; + [JsonPropertyName("session_id")] public string SessionId { get; set; } = ""; + [JsonPropertyName("timestamp")] public string Timestamp { get; set; } = ""; + [JsonPropertyName("level")] public string Level { get; set; } = ""; + [JsonPropertyName("event_type")] public string EventType { get; set; } = ""; + [JsonPropertyName("status")] public string? Status { get; set; } + [JsonPropertyName("message")] public string Message { get; set; } = ""; + [JsonPropertyName("error")] public string? Error { get; set; } + } + + private sealed class SessionSummary + { + [JsonPropertyName("events")] public int Events { get; set; } + [JsonPropertyName("errors")] public int Errors { get; set; } + [JsonPropertyName("warnings")] public int Warnings { get; set; } + } + + private sealed class SessionRecord + { + [JsonPropertyName("session_id")] public string SessionId { get; set; } = ""; + [JsonPropertyName("start_time")] public string StartTime { get; set; } = ""; + [JsonPropertyName("end_time")] public string? EndTime { get; set; } + [JsonPropertyName("duration_seconds")] public int? DurationSeconds { get; set; } + [JsonPropertyName("run_type")] public string RunType { get; set; } = ""; + [JsonPropertyName("status")] public string Status { get; set; } = ""; + [JsonPropertyName("tool_version")] public string ToolVersion { get; set; } = ""; + [JsonPropertyName("environment")] public Dictionary Environment { get; set; } = new(); + [JsonPropertyName("summary")] public SessionSummary Summary { get; set; } = new(); + } + } +} diff --git a/src/BootstrapMate.App/ViewModels/LogsViewModel.cs b/src/BootstrapMate.App/ViewModels/LogsViewModel.cs index 1bd8065..1319028 100644 --- a/src/BootstrapMate.App/ViewModels/LogsViewModel.cs +++ b/src/BootstrapMate.App/ViewModels/LogsViewModel.cs @@ -70,17 +70,28 @@ public void Refresh() if (!Directory.Exists(LogDirectory)) return; - var files = Directory.GetFiles(LogDirectory, "*.log") + // A run is a session directory, logs\YYYY-MM-DD\HHMMSS\bootstrap.log. Flat + // per-run files at the root predate that layout and are still listed. + var sessions = Directory.GetDirectories(LogDirectory) + .SelectMany(day => Directory.GetDirectories(day) + .Select(session => (Day: System.IO.Path.GetFileName(day), Session: System.IO.Path.GetFileName(session), Path: session))) + .Select(entry => + { + var log = Directory.GetFiles(entry.Path, "*.log") + .OrderBy(path => System.IO.Path.GetFileName(path) == "bootstrap.log" ? 0 : 1) + .FirstOrDefault(); + return log is null ? null : new LogFile($"{entry.Day}-{entry.Session}", log, ParseStamp($"{entry.Day}-{entry.Session}"), FileSize(log)); + }) + .OfType(); + + var loose = Directory.GetFiles(LogDirectory, "*.log") .Select(path => { var name = System.IO.Path.GetFileName(path); - var baseName = System.IO.Path.GetFileNameWithoutExtension(name); - DateTime? date = DateTime.TryParseExact(baseName, "yyyy-MM-dd-HHmmss", - CultureInfo.InvariantCulture, DateTimeStyles.None, out var d) ? d : null; - long size = 0; - try { size = new FileInfo(path).Length; } catch { } - return new LogFile(name, path, date, size); - }) + return new LogFile(name, path, ParseStamp(System.IO.Path.GetFileNameWithoutExtension(name)), FileSize(path)); + }); + + var files = sessions.Concat(loose) .OrderByDescending(f => f.Date ?? DateTime.MinValue) .ToList(); @@ -92,6 +103,25 @@ public void Refresh() SelectedLog = LogFiles[0]; } + /// + /// A session or flat-file stamp, at second or minute resolution. The minute form + /// predates seconds and still appears on a device that has not been rebuilt. + /// + private static DateTime? ParseStamp(string stamp) + { + foreach (var format in new[] { "yyyy-MM-dd-HHmmss", "yyyy-MM-dd-HHmm" }) + { + if (DateTime.TryParseExact(stamp, format, CultureInfo.InvariantCulture, DateTimeStyles.None, out var parsed)) + return parsed; + } + return null; + } + + private static long FileSize(string path) + { + try { return new FileInfo(path).Length; } catch { return 0; } + } + // ── Load Content ───────────────────────────────────────────── partial void OnSelectedLogChanged(LogFile? value)