From 14a5e5b652e4bf00de6ff470cf81a3155f725374 Mon Sep 17 00:00:00 2001 From: Soreepeong Date: Sat, 9 Mar 2024 04:09:29 +0900 Subject: [PATCH] ConsoleWindow racecon fix and highlight RollingList is not thread safe, but the lock around it was inconsistent, resulting in occasional null value in the log list. Fixed by utilizing ConcurrentQueue so that logs can be added from any thread without locks, and reading from the queue and adding to the list from the framework thread. Also, added log line highlight feature. --- .../Internal/Windows/ConsoleWindow.cs | 789 ++++++++++++------ Dalamud/Utility/ThreadSafety.cs | 12 + 2 files changed, 537 insertions(+), 264 deletions(-) diff --git a/Dalamud/Interface/Internal/Windows/ConsoleWindow.cs b/Dalamud/Interface/Internal/Windows/ConsoleWindow.cs index f36d79222..1957ab720 100644 --- a/Dalamud/Interface/Internal/Windows/ConsoleWindow.cs +++ b/Dalamud/Interface/Internal/Windows/ConsoleWindow.cs @@ -1,24 +1,28 @@ +using System.Collections.Concurrent; using System.Collections.Generic; using System.Diagnostics; -using System.Drawing; using System.Linq; using System.Numerics; using System.Runtime.InteropServices; using System.Text; using System.Text.RegularExpressions; -using System.Threading; using Dalamud.Configuration.Internal; +using Dalamud.Game; using Dalamud.Game.Command; using Dalamud.Interface.Colors; using Dalamud.Interface.Components; +using Dalamud.Interface.Internal.Notifications; using Dalamud.Interface.Utility; using Dalamud.Interface.Utility.Raii; using Dalamud.Interface.Windowing; using Dalamud.Logging.Internal; using Dalamud.Plugin.Internal; +using Dalamud.Plugin.Services; using Dalamud.Utility; + using ImGuiNET; + using Serilog; using Serilog.Events; @@ -31,39 +35,48 @@ internal class ConsoleWindow : Window, IDisposable { private const int LogLinesMinimum = 100; private const int LogLinesMaximum = 1000000; - + + // Only this field may be touched from any thread. + private readonly ConcurrentQueue<(string Line, LogEvent LogEvent)> newLogEntries; + + // Fields below should be touched only from the main thread. private readonly RollingList logText; - private volatile int newRolledLines; - private readonly object renderLock = new(); + private readonly RollingList filteredLogEntries; private readonly List history = new(); private readonly List pluginFilters = new(); + private int newRolledLines; + private bool pendingRefilter; + private bool pendingClearLog; + private bool? lastCmdSuccess; + private ImGuiListClipperPtr clipperPtr; private string commandText = string.Empty; private string textFilter = string.Empty; + private string textHighlight = string.Empty; private string selectedSource = "DalamudInternal"; private string pluginFilter = string.Empty; + private Regex? compiledLogFilter; + private Regex? compiledLogHighlight; + private Exception? exceptionLogFilter; + private Exception? exceptionLogHighlight; + private bool filterShowUncaughtExceptions; private bool settingsPopupWasOpen; private bool showFilterToolbar; - private bool clearLog; - private bool copyLog; private bool copyMode; private bool killGameArmed; private bool autoScroll; private int logLinesLimit; private bool autoOpen; - private bool regexError; private int historyPos; private int copyStart = -1; - /// - /// Initializes a new instance of the class. - /// + /// Initializes a new instance of the class. /// An instance of . public ConsoleWindow(DalamudConfiguration configuration) : base("Dalamud Console", ImGuiWindowFlags.NoScrollbar | ImGuiWindowFlags.NoScrollWithMouse) @@ -72,6 +85,8 @@ internal class ConsoleWindow : Window, IDisposable this.autoOpen = configuration.LogOpenAtStartup; SerilogEventSink.Instance.LogLine += this.OnLogLine; + Service.GetAsync().ContinueWith(r => r.Result.Update += this.FrameworkOnUpdate); + this.Size = new Vector2(500, 400); this.SizeCondition = ImGuiCond.FirstUseEver; @@ -85,13 +100,17 @@ internal class ConsoleWindow : Window, IDisposable this.logLinesLimit = configuration.LogLinesLimit; var limit = Math.Max(LogLinesMinimum, this.logLinesLimit); + this.newLogEntries = new(); this.logText = new(limit); - this.FilteredLogEntries = new(limit); + this.filteredLogEntries = new(limit); configuration.DalamudConfigurationSaved += this.OnDalamudConfigurationSaved; - } - private RollingList FilteredLogEntries { get; set; } + unsafe + { + this.clipperPtr = new(ImGuiNative.ImGuiListClipper_ImGuiListClipper()); + } + } /// public override void OnOpen() @@ -100,58 +119,16 @@ internal class ConsoleWindow : Window, IDisposable base.OnOpen(); } - /// - /// Dispose of managed and unmanaged resources. - /// + /// public void Dispose() { SerilogEventSink.Instance.LogLine -= this.OnLogLine; Service.Get().DalamudConfigurationSaved -= this.OnDalamudConfigurationSaved; - } + if (Service.GetNullable() is { } framework) + framework.Update -= this.FrameworkOnUpdate; - /// - /// Clear the window of all log entries. - /// - public void Clear() - { - lock (this.renderLock) - { - this.logText.Clear(); - this.FilteredLogEntries.Clear(); - this.clearLog = false; - } - } - - /// - /// Copies the entire log contents to clipboard. - /// - public void CopyLog() - { - ImGui.LogToClipboard(); - } - - /// - /// Add a single log line to the display. - /// - /// The line to add. - /// The Serilog event associated with this line. - public void HandleLogLine(string line, LogEvent logEvent) - { - if (line.IndexOfAny(new[] { '\n', '\r' }) != -1) - { - var subLines = line.Split(new[] { "\r\n", "\r", "\n" }, StringSplitOptions.RemoveEmptyEntries); - - this.AddAndFilter(subLines[0], logEvent, false); - - for (var i = 1; i < subLines.Length; i++) - { - this.AddAndFilter(subLines[i], logEvent, true); - } - } - else - { - this.AddAndFilter(line, logEvent, false); - } + this.clipperPtr.Destroy(); + this.clipperPtr = default; } /// @@ -161,112 +138,126 @@ internal class ConsoleWindow : Window, IDisposable this.DrawFilterToolbar(); - if (this.regexError) + if (this.exceptionLogFilter is not null) { - const string regexErrorString = "Regex Filter Error"; - ImGui.SetCursorPosX(ImGui.GetContentRegionMax().X / 2.0f - ImGui.CalcTextSize(regexErrorString).X / 2.0f); - ImGui.TextColored(ImGuiColors.DalamudRed, regexErrorString); + ImGui.TextColored( + ImGuiColors.DalamudRed, + $"Regex Filter Error: {this.exceptionLogFilter.GetType().Name}"); + ImGui.TextUnformatted(this.exceptionLogFilter.Message); + } + + if (this.exceptionLogHighlight is not null) + { + ImGui.TextColored( + ImGuiColors.DalamudRed, + $"Regex Highlight Error: {this.exceptionLogHighlight.GetType().Name}"); + ImGui.TextUnformatted(this.exceptionLogHighlight.Message); } var sendButtonSize = ImGui.CalcTextSize("Send") + ((new Vector2(16, 0) + (ImGui.GetStyle().FramePadding * 2)) * ImGuiHelpers.GlobalScale); var scrollingHeight = ImGui.GetContentRegionAvail().Y - sendButtonSize.Y; - ImGui.BeginChild("scrolling", new Vector2(0, scrollingHeight), false, ImGuiWindowFlags.AlwaysHorizontalScrollbar | ImGuiWindowFlags.AlwaysVerticalScrollbar); - - if (this.clearLog) this.Clear(); - - if (this.copyLog) this.CopyLog(); + ImGui.BeginChild( + "scrolling", + new Vector2(0, scrollingHeight), + false, + ImGuiWindowFlags.AlwaysHorizontalScrollbar | ImGuiWindowFlags.AlwaysVerticalScrollbar); ImGui.PushStyleVar(ImGuiStyleVar.ItemSpacing, Vector2.Zero); - ImGuiListClipperPtr clipper; - unsafe - { - clipper = new ImGuiListClipperPtr(ImGuiNative.ImGuiListClipper_ImGuiListClipper()); - } - ImGui.PushFont(InterfaceManager.MonoFont); var childPos = ImGui.GetWindowPos(); var childDrawList = ImGui.GetWindowDrawList(); var childSize = ImGui.GetWindowSize(); - var cursorDiv = ImGui.CalcTextSize("00:00:00.000 ").X; - var cursorLogLevel = ImGui.CalcTextSize("00:00:00.000 | ").X; - var dividerOffset = ImGui.CalcTextSize("00:00:00.000 | AAA ").X + (ImGui.CalcTextSize(" ").X / 2); - var cursorLogLine = ImGui.CalcTextSize("00:00:00.000 | AAA | ").X; + var timestampWidth = ImGui.CalcTextSize("00:00:00.000").X; + var levelWidth = ImGui.CalcTextSize("AAA").X; + var separatorWidth = ImGui.CalcTextSize(" | ").X; + var cursorLogLevel = timestampWidth + separatorWidth; + var cursorLogLine = cursorLogLevel + levelWidth + separatorWidth; var lastLinePosY = 0.0f; var logLineHeight = 0.0f; - lock (this.renderLock) + this.clipperPtr.Begin(this.filteredLogEntries.Count); + while (this.clipperPtr.Step()) { - clipper.Begin(this.FilteredLogEntries.Count); - while (clipper.Step()) + for (var i = this.clipperPtr.DisplayStart; i < this.clipperPtr.DisplayEnd; i++) { - for (var i = clipper.DisplayStart; i < clipper.DisplayEnd; i++) + var index = Math.Max( + i - this.newRolledLines, + 0); // Prevents flicker effect. Also workaround to avoid negative indexes. + var line = this.filteredLogEntries[index]; + + if (!line.IsMultiline) + ImGui.Separator(); + + if (line.SelectedForCopy) { - var index = Math.Max(i - this.newRolledLines, 0); // Prevents flicker effect. Also workaround to avoid negative indexes. - var line = this.FilteredLogEntries[index]; + ImGui.PushStyleColor(ImGuiCol.Header, ImGuiColors.ParsedGrey); + ImGui.PushStyleColor(ImGuiCol.HeaderActive, ImGuiColors.ParsedGrey); + ImGui.PushStyleColor(ImGuiCol.HeaderHovered, ImGuiColors.ParsedGrey); + } + else + { + ImGui.PushStyleColor(ImGuiCol.Header, GetColorForLogEventLevel(line.Level)); + ImGui.PushStyleColor(ImGuiCol.HeaderActive, GetColorForLogEventLevel(line.Level)); + ImGui.PushStyleColor(ImGuiCol.HeaderHovered, GetColorForLogEventLevel(line.Level)); + } - if (!line.IsMultiline && !this.copyLog) - ImGui.Separator(); - - if (line.SelectedForCopy) - { - ImGui.PushStyleColor(ImGuiCol.Header, ImGuiColors.ParsedGrey); - ImGui.PushStyleColor(ImGuiCol.HeaderActive, ImGuiColors.ParsedGrey); - ImGui.PushStyleColor(ImGuiCol.HeaderHovered, ImGuiColors.ParsedGrey); - } - else - { - ImGui.PushStyleColor(ImGuiCol.Header, this.GetColorForLogEventLevel(line.Level)); - ImGui.PushStyleColor(ImGuiCol.HeaderActive, this.GetColorForLogEventLevel(line.Level)); - ImGui.PushStyleColor(ImGuiCol.HeaderHovered, this.GetColorForLogEventLevel(line.Level)); - } + ImGui.Selectable( + "###console_null", + true, + ImGuiSelectableFlags.AllowItemOverlap | ImGuiSelectableFlags.SpanAllColumns); - ImGui.Selectable("###console_null", true, ImGuiSelectableFlags.AllowItemOverlap | ImGuiSelectableFlags.SpanAllColumns); + // This must be after ImGui.Selectable, it uses ImGui.IsItem... functions + this.HandleCopyMode(i, line); - // This must be after ImGui.Selectable, it uses ImGui.IsItem... functions - this.HandleCopyMode(i, line); - + ImGui.SameLine(); + + ImGui.PopStyleColor(3); + + if (!line.IsMultiline) + { + ImGui.TextUnformatted(line.TimestampString); ImGui.SameLine(); - ImGui.PopStyleColor(3); - - if (!line.IsMultiline) - { - ImGui.TextUnformatted(line.TimeStamp.ToString("HH:mm:ss.fff")); - ImGui.SameLine(); - ImGui.SetCursorPosX(cursorDiv); - ImGui.TextUnformatted("|"); - ImGui.SameLine(); - ImGui.SetCursorPosX(cursorLogLevel); - ImGui.TextUnformatted(this.GetTextForLogEventLevel(line.Level)); - ImGui.SameLine(); - } - - ImGui.SetCursorPosX(cursorLogLine); - ImGui.TextUnformatted(line.Line); - - var currentLinePosY = ImGui.GetCursorPosY(); - logLineHeight = currentLinePosY - lastLinePosY; - lastLinePosY = currentLinePosY; + ImGui.SetCursorPosX(cursorLogLevel); + ImGui.TextUnformatted(GetTextForLogEventLevel(line.Level)); + ImGui.SameLine(); } - } - clipper.End(); - clipper.Destroy(); + ImGui.SetCursorPosX(cursorLogLine); + line.HighlightMatches ??= (this.compiledLogHighlight ?? this.compiledLogFilter)?.Matches(line.Line); + if (line.HighlightMatches is { } matches) + { + this.DrawHighlighted( + line.Line, + matches, + ImGui.GetColorU32(ImGuiCol.Text), + ImGui.GetColorU32(ImGuiColors.HealerGreen)); + } + else + { + ImGui.TextUnformatted(line.Line); + } + + var currentLinePosY = ImGui.GetCursorPosY(); + logLineHeight = currentLinePosY - lastLinePosY; + lastLinePosY = currentLinePosY; + } } + this.clipperPtr.End(); + ImGui.PopFont(); ImGui.PopStyleVar(); - var newRolledLinesCount = Interlocked.Exchange(ref this.newRolledLines, 0); if (!this.autoScroll || ImGui.GetScrollY() < ImGui.GetScrollMaxY()) { - ImGui.SetScrollY(ImGui.GetScrollY() - (logLineHeight * newRolledLinesCount)); + ImGui.SetScrollY(ImGui.GetScrollY() - (logLineHeight * this.newRolledLines)); } if (this.autoScroll && ImGui.GetScrollY() >= ImGui.GetScrollMaxY()) @@ -274,8 +265,19 @@ internal class ConsoleWindow : Window, IDisposable ImGui.SetScrollHereY(1.0f); } - // Draw dividing line - childDrawList.AddLine(new Vector2(childPos.X + dividerOffset, childPos.Y), new Vector2(childPos.X + dividerOffset, childPos.Y + childSize.Y), 0x4FFFFFFF, 1.0f); + // Draw dividing lines + var div1Offset = MathF.Round((timestampWidth + (separatorWidth / 2)) - ImGui.GetScrollX()); + var div2Offset = MathF.Round((cursorLogLevel + levelWidth + (separatorWidth / 2)) - ImGui.GetScrollX()); + childDrawList.AddLine( + new(childPos.X + div1Offset, childPos.Y), + new(childPos.X + div1Offset, childPos.Y + childSize.Y), + 0x4FFFFFFF, + 1.0f); + childDrawList.AddLine( + new(childPos.X + div2Offset, childPos.Y), + new(childPos.X + div2Offset, childPos.Y + childSize.Y), + 0x4FFFFFFF, + 1.0f); ImGui.EndChild(); @@ -293,12 +295,20 @@ internal class ConsoleWindow : Window, IDisposable } } - ImGui.SetNextItemWidth(ImGui.GetContentRegionAvail().X - sendButtonSize.X - (ImGui.GetStyle().ItemSpacing.X * ImGuiHelpers.GlobalScale)); + ImGui.SetNextItemWidth( + ImGui.GetContentRegionAvail().X - sendButtonSize.X - + (ImGui.GetStyle().ItemSpacing.X * ImGuiHelpers.GlobalScale)); var getFocus = false; unsafe { - if (ImGui.InputText("##command_box", ref this.commandText, 255, ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.CallbackCompletion | ImGuiInputTextFlags.CallbackHistory, this.CommandInputCallback)) + if (ImGui.InputText( + "##command_box", + ref this.commandText, + 255, + ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.CallbackCompletion | + ImGuiInputTextFlags.CallbackHistory, + this.CommandInputCallback)) { this.ProcessCommand(); getFocus = true; @@ -316,14 +326,62 @@ internal class ConsoleWindow : Window, IDisposable { this.ProcessCommand(); } - - this.copyLog = false; } - + + private static string GetTextForLogEventLevel(LogEventLevel level) => level switch + { + LogEventLevel.Error => "ERR", + LogEventLevel.Verbose => "VRB", + LogEventLevel.Debug => "DBG", + LogEventLevel.Information => "INF", + LogEventLevel.Warning => "WRN", + LogEventLevel.Fatal => "FTL", + _ => "???", + }; + + private static uint GetColorForLogEventLevel(LogEventLevel level) => level switch + { + LogEventLevel.Error => 0x800000EE, + LogEventLevel.Verbose => 0x00000000, + LogEventLevel.Debug => 0x00000000, + LogEventLevel.Information => 0x00000000, + LogEventLevel.Warning => 0x8A0070EE, + LogEventLevel.Fatal => 0xFF00000A, + _ => 0x30FFFFFF, + }; + + private void FrameworkOnUpdate(IFramework framework) + { + if (this.pendingClearLog) + { + this.pendingClearLog = false; + this.logText.Clear(); + this.filteredLogEntries.Clear(); + this.newLogEntries.Clear(); + } + + if (this.pendingRefilter) + { + this.pendingRefilter = false; + this.filteredLogEntries.Clear(); + foreach (var log in this.logText) + { + if (this.IsFilterApplicable(log)) + this.filteredLogEntries.Add(log); + } + } + + var numPrevFilteredLogEntries = this.filteredLogEntries.Count; + var addedLines = 0; + while (this.newLogEntries.TryDequeue(out var logLine)) + addedLines += this.HandleLogLine(logLine.Line, logLine.LogEvent); + this.newRolledLines = addedLines - (this.filteredLogEntries.Count - numPrevFilteredLogEntries); + } + private void HandleCopyMode(int i, LogEntry line) { var selectionChanged = false; - + // If copyStart is -1, it means a drag has not been started yet, let's start one, and select the starting spot. if (this.copyMode && this.copyStart == -1 && ImGui.IsItemClicked()) { @@ -334,19 +392,20 @@ internal class ConsoleWindow : Window, IDisposable } // Update the selected range when dragging over entries - if (this.copyMode && this.copyStart != -1 && ImGui.IsItemHovered() && ImGui.IsMouseDragging(ImGuiMouseButton.Left)) + if (this.copyMode && this.copyStart != -1 && ImGui.IsItemHovered() && + ImGui.IsMouseDragging(ImGuiMouseButton.Left)) { if (!line.SelectedForCopy) { - foreach (var index in Enumerable.Range(0, this.FilteredLogEntries.Count)) + foreach (var index in Enumerable.Range(0, this.filteredLogEntries.Count)) { if (this.copyStart < i) { - this.FilteredLogEntries[index].SelectedForCopy = index >= this.copyStart && index <= i; + this.filteredLogEntries[index].SelectedForCopy = index >= this.copyStart && index <= i; } else { - this.FilteredLogEntries[index].SelectedForCopy = index >= i && index <= this.copyStart; + this.filteredLogEntries[index].SelectedForCopy = index >= i && index <= this.copyStart; } } @@ -355,19 +414,37 @@ internal class ConsoleWindow : Window, IDisposable } // Finish the drag, we should have already marked all dragged entries as selected by now. - if (this.copyMode && this.copyStart != -1 && ImGui.IsItemHovered() && ImGui.IsMouseReleased(ImGuiMouseButton.Left)) + if (this.copyMode && this.copyStart != -1 && ImGui.IsItemHovered() && + ImGui.IsMouseReleased(ImGuiMouseButton.Left)) { this.copyStart = -1; } if (selectionChanged) - { - var allSelectedLines = this.FilteredLogEntries - .Where(entry => entry.SelectedForCopy) - .Select(entry => $"{entry.TimeStamp:HH:mm:ss.fff} {this.GetTextForLogEventLevel(entry.Level)} | {entry.Line}"); + this.CopyFilteredLogEntries(true); + } - ImGui.SetClipboardText(string.Join("\n", allSelectedLines)); + private void CopyFilteredLogEntries(bool selectedOnly) + { + var sb = new StringBuilder(); + var n = 0; + foreach (var entry in this.filteredLogEntries) + { + if (selectedOnly && !entry.SelectedForCopy) + continue; + + n++; + sb.AppendLine(entry.ToString()); } + + if (n == 0) + return; + + ImGui.SetClipboardText(sb.ToString()); + Service.Get().AddNotification( + $"{n:n0} line(s) copied.", + this.WindowName, + NotificationType.Success); } private void DrawOptionsToolbar() @@ -384,7 +461,7 @@ internal class ConsoleWindow : Window, IDisposable EntryPoint.LogLevelSwitch.MinimumLevel = value; configuration.LogLevel = value; configuration.QueueSave(); - this.Refilter(); + this.QueueRefilter(); } } @@ -407,18 +484,27 @@ internal class ConsoleWindow : Window, IDisposable this.settingsPopupWasOpen = settingsPopup; - if (this.DrawToggleButtonWithTooltip("show_settings", "Show settings", FontAwesomeIcon.List, ref settingsPopup)) ImGui.OpenPopup("##console_settings"); + if (this.DrawToggleButtonWithTooltip("show_settings", "Show settings", FontAwesomeIcon.List, ref settingsPopup)) + ImGui.OpenPopup("##console_settings"); ImGui.SameLine(); - if (this.DrawToggleButtonWithTooltip("show_filters", "Show filter toolbar", FontAwesomeIcon.Search, ref this.showFilterToolbar)) + if (this.DrawToggleButtonWithTooltip( + "show_filters", + "Show filter toolbar", + FontAwesomeIcon.Search, + ref this.showFilterToolbar)) { this.showFilterToolbar = !this.showFilterToolbar; } ImGui.SameLine(); - if (this.DrawToggleButtonWithTooltip("show_uncaught_exceptions", "Show uncaught exception while filtering", FontAwesomeIcon.Bug, ref this.filterShowUncaughtExceptions)) + if (this.DrawToggleButtonWithTooltip( + "show_uncaught_exceptions", + "Show uncaught exception while filtering", + FontAwesomeIcon.Bug, + ref this.filterShowUncaughtExceptions)) { this.filterShowUncaughtExceptions = !this.filterShowUncaughtExceptions; } @@ -427,28 +513,33 @@ internal class ConsoleWindow : Window, IDisposable if (ImGuiComponents.IconButton("clear_log", FontAwesomeIcon.Trash)) { - this.clearLog = true; + this.QueueClear(); } if (ImGui.IsItemHovered()) ImGui.SetTooltip("Clear Log"); ImGui.SameLine(); - if (this.DrawToggleButtonWithTooltip("copy_mode", "Enable Copy Mode\nRight-click to copy entire log", FontAwesomeIcon.Copy, ref this.copyMode)) + if (this.DrawToggleButtonWithTooltip( + "copy_mode", + "Enable Copy Mode\nRight-click to copy entire log", + FontAwesomeIcon.Copy, + ref this.copyMode)) { this.copyMode = !this.copyMode; if (!this.copyMode) { - foreach (var entry in this.FilteredLogEntries) + foreach (var entry in this.filteredLogEntries) { entry.SelectedForCopy = false; } } } - if (ImGui.IsItemClicked(ImGuiMouseButton.Right)) this.copyLog = true; - + if (ImGui.IsItemClicked(ImGuiMouseButton.Right)) + this.CopyFilteredLogEntries(false); + ImGui.SameLine(); if (this.killGameArmed) { @@ -464,16 +555,59 @@ internal class ConsoleWindow : Window, IDisposable if (ImGui.IsItemHovered()) ImGui.SetTooltip("Kill game"); ImGui.SameLine(); - ImGui.SetCursorPosX(ImGui.GetContentRegionMax().X - (200.0f * ImGuiHelpers.GlobalScale)); + ImGui.SetCursorPosX( + ImGui.GetContentRegionMax().X - (2 * 200.0f * ImGuiHelpers.GlobalScale) - ImGui.GetStyle().ItemSpacing.X); + ImGui.PushItemWidth(200.0f * ImGuiHelpers.GlobalScale); - if (ImGui.InputTextWithHint("##global_filter", "regex global filter", ref this.textFilter, 2048, ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.AutoSelectAll)) + if (ImGui.InputTextWithHint( + "##textHighlight", + "regex highlight", + ref this.textHighlight, + 2048, + ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.AutoSelectAll) + || ImGui.IsItemDeactivatedAfterEdit()) { - this.Refilter(); + this.compiledLogHighlight = null; + this.exceptionLogHighlight = null; + try + { + if (this.textHighlight != string.Empty) + this.compiledLogHighlight = new(this.textHighlight, RegexOptions.IgnoreCase); + } + catch (Exception e) + { + this.exceptionLogHighlight = e; + } + + foreach (var log in this.logText) + log.HighlightMatches = null; } - if (ImGui.IsItemDeactivatedAfterEdit()) + ImGui.SameLine(); + ImGui.PushItemWidth(200.0f * ImGuiHelpers.GlobalScale); + if (ImGui.InputTextWithHint( + "##textFilter", + "regex global filter", + ref this.textFilter, + 2048, + ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.AutoSelectAll) + || ImGui.IsItemDeactivatedAfterEdit()) { - this.Refilter(); + this.compiledLogFilter = null; + this.exceptionLogFilter = null; + try + { + this.compiledLogFilter = new(this.textFilter, RegexOptions.IgnoreCase); + + this.QueueRefilter(); + } + catch (Exception e) + { + this.exceptionLogFilter = e; + } + + foreach (var log in this.logText) + log.HighlightMatches = null; } } @@ -509,9 +643,12 @@ internal class ConsoleWindow : Window, IDisposable if (!this.showFilterToolbar) return; PluginFilterEntry? removalEntry = null; - using var table = ImRaii.Table("plugin_filter_entries", 4, ImGuiTableFlags.Resizable | ImGuiTableFlags.BordersInnerV); + using var table = ImRaii.Table( + "plugin_filter_entries", + 4, + ImGuiTableFlags.Resizable | ImGuiTableFlags.BordersInnerV); if (!table) return; - + ImGui.TableSetupColumn("##remove_button", ImGuiTableColumnFlags.WidthFixed, 25.0f * ImGuiHelpers.GlobalScale); ImGui.TableSetupColumn("##source_name", ImGuiTableColumnFlags.WidthFixed, 150.0f * ImGuiHelpers.GlobalScale); ImGui.TableSetupColumn("##log_level", ImGuiTableColumnFlags.WidthFixed, 150.0f * ImGuiHelpers.GlobalScale); @@ -522,15 +659,16 @@ internal class ConsoleWindow : Window, IDisposable { if (this.pluginFilters.All(entry => entry.Source != this.selectedSource)) { - this.pluginFilters.Add(new PluginFilterEntry - { - Source = this.selectedSource, - Filter = string.Empty, - Level = LogEventLevel.Debug, - }); + this.pluginFilters.Add( + new PluginFilterEntry + { + Source = this.selectedSource, + Filter = string.Empty, + Level = LogEventLevel.Debug, + }); } - this.Refilter(); + this.QueueRefilter(); } ImGui.TableNextColumn(); @@ -541,13 +679,17 @@ internal class ConsoleWindow : Window, IDisposable .Select(p => p.Manifest.InternalName) .OrderBy(s => s) .Prepend("DalamudInternal") - .Where(name => this.pluginFilter is "" || new FuzzyMatcher(this.pluginFilter.ToLowerInvariant(), MatchMode.Fuzzy).Matches(name.ToLowerInvariant()) != 0) + .Where( + name => this.pluginFilter is "" || new FuzzyMatcher( + this.pluginFilter.ToLowerInvariant(), + MatchMode.Fuzzy).Matches(name.ToLowerInvariant()) != + 0) .ToList(); ImGui.PushItemWidth(ImGui.GetContentRegionAvail().X); ImGui.InputTextWithHint("##PluginSearchFilter", "Filter Plugin List", ref this.pluginFilter, 2048); ImGui.Separator(); - + if (!sourceNames.Any()) { ImGui.TextColored(ImGuiColors.DalamudRed, "No Results"); @@ -569,25 +711,27 @@ internal class ConsoleWindow : Window, IDisposable foreach (var entry in this.pluginFilters) { + ImGui.PushID(entry.Source); + ImGui.TableNextColumn(); - if (ImGuiComponents.IconButton($"remove{entry.Source}", FontAwesomeIcon.Trash)) + if (ImGuiComponents.IconButton(FontAwesomeIcon.Trash)) { removalEntry = entry; } ImGui.TableNextColumn(); ImGui.Text(entry.Source); - + ImGui.TableNextColumn(); ImGui.SetNextItemWidth(ImGui.GetContentRegionAvail().X); - if (ImGui.BeginCombo($"##levels{entry.Source}", $"{entry.Level}+")) + if (ImGui.BeginCombo("##levels", $"{entry.Level}+")) { foreach (var value in Enum.GetValues()) { if (ImGui.Selectable(value.ToString(), value == entry.Level)) { entry.Level = value; - this.Refilter(); + this.QueueRefilter(); } } @@ -597,19 +741,26 @@ internal class ConsoleWindow : Window, IDisposable ImGui.TableNextColumn(); ImGui.SetNextItemWidth(ImGui.GetContentRegionAvail().X); var entryFilter = entry.Filter; - if (ImGui.InputTextWithHint($"##filter{entry.Source}", $"{entry.Source} regex filter", ref entryFilter, 2048, ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.AutoSelectAll)) + if (ImGui.InputTextWithHint( + "##filter", + $"{entry.Source} regex filter", + ref entryFilter, + 2048, + ImGuiInputTextFlags.EnterReturnsTrue | ImGuiInputTextFlags.AutoSelectAll) + || ImGui.IsItemDeactivatedAfterEdit()) { entry.Filter = entryFilter; - this.Refilter(); + if (entry.FilterException is null) + this.QueueRefilter(); } - if (ImGui.IsItemDeactivatedAfterEdit()) this.Refilter(); + ImGui.PopID(); } if (removalEntry is { } toRemove) { this.pluginFilters.Remove(toRemove); - this.Refilter(); + this.QueueRefilter(); } } @@ -636,7 +787,7 @@ internal class ConsoleWindow : Window, IDisposable if (this.commandText is "clear" or "cls") { - this.Clear(); + this.QueueClear(); return; } @@ -717,16 +868,22 @@ internal class ConsoleWindow : Window, IDisposable return 0; } - private void AddAndFilter(string line, LogEvent logEvent, bool isMultiline) + /// Add a log entry to the display. + /// The line to add. + /// The Serilog event associated with this line. + /// Number of lines added to . + private int HandleLogLine(string line, LogEvent logEvent) { - if (line.StartsWith("TROUBLESHOOTING:") || line.StartsWith("LASTEXCEPTION:")) - return; + ThreadSafety.DebugAssertMainThread(); + // These lines are too huge, and only useful for troubleshooting after the game exist. + if (line.StartsWith("TROUBLESHOOTING:") || line.StartsWith("LASTEXCEPTION:")) + return 0; + + // Create a log entry template. var entry = new LogEntry { - IsMultiline = isMultiline, Level = logEvent.Level, - Line = line, TimeStamp = logEvent.Timestamp, HasException = logEvent.Exception != null, }; @@ -741,98 +898,118 @@ internal class ConsoleWindow : Window, IDisposable entry.Source = sourceValue; } + var ssp = line.AsSpan(); + var numLines = 0; + while (true) + { + var next = ssp.IndexOfAny('\r', '\n'); + if (next == -1) + { + // Last occurrence; transfer the ownership of the new entry to the queue. + entry.Line = ssp.ToString(); + numLines += this.AddAndFilter(entry); + break; + } + + // There will be more; create a clone of the entry with the current line. + numLines += this.AddAndFilter(entry with { Line = ssp[..next].ToString() }); + + // Mark further lines as multiline. + entry.IsMultiline = true; + + // Skip the detected line break. + ssp = ssp[next..]; + ssp = ssp.StartsWith("\r\n") ? ssp[2..] : ssp[1..]; + } + + return numLines; + } + + /// Adds a line to the log list and the filtered log list accordingly. + /// The new log entry to add. + /// Number of lines added to . + private int AddAndFilter(LogEntry entry) + { + ThreadSafety.DebugAssertMainThread(); + this.logText.Add(entry); - var avoidScroll = this.FilteredLogEntries.Count == this.FilteredLogEntries.Size; - if (this.IsFilterApplicable(entry)) - { - this.FilteredLogEntries.Add(entry); - if (avoidScroll) Interlocked.Increment(ref this.newRolledLines); - } + if (!this.IsFilterApplicable(entry)) + return 0; + + this.filteredLogEntries.Add(entry); + return 1; } + /// Determines if a log entry passes the user-specified filter. + /// The entry to test. + /// true if it passes the filter. private bool IsFilterApplicable(LogEntry entry) { - if (this.regexError) + ThreadSafety.DebugAssertMainThread(); + + if (this.exceptionLogFilter is not null) return false; - try + // If this entry is below a newly set minimum level, fail it + if (EntryPoint.LogLevelSwitch.MinimumLevel > entry.Level) + return false; + + // Show exceptions that weren't properly tagged with a Source (generally meaning they were uncaught) + // After log levels because uncaught exceptions should *never* fall below Error. + if (this.filterShowUncaughtExceptions && entry.HasException && entry.Source == null) + return true; + + // (global filter) && (plugin filter) must be satisfied. + var wholeCond = true; + + // If we have a global filter, check that first + if (this.compiledLogFilter is { } logFilter) { - // If this entry is below a newly set minimum level, fail it - if (EntryPoint.LogLevelSwitch.MinimumLevel > entry.Level) - return false; - - // Show exceptions that weren't properly tagged with a Source (generally meaning they were uncaught) - // After log levels because uncaught exceptions should *never* fall below Error. - if (this.filterShowUncaughtExceptions && entry.HasException && entry.Source == null) - return true; + // Someone will definitely try to just text filter a source without using the actual filters, should allow that. + var matchesSource = entry.Source is not null && logFilter.IsMatch(entry.Source); + var matchesContent = logFilter.IsMatch(entry.Line); - // If we have a global filter, check that first - if (!this.textFilter.IsNullOrEmpty()) + wholeCond &= matchesSource || matchesContent; + } + + // If this entry has a filter, check the filter + if (this.pluginFilters.Count > 0) + { + var matchesAny = false; + + foreach (var filterEntry in this.pluginFilters) { - // Someone will definitely try to just text filter a source without using the actual filters, should allow that. - var matchesSource = entry.Source is not null && Regex.IsMatch(entry.Source, this.textFilter, RegexOptions.IgnoreCase); - var matchesContent = Regex.IsMatch(entry.Line, this.textFilter, RegexOptions.IgnoreCase); + if (!string.Equals(filterEntry.Source, entry.Source, StringComparison.InvariantCultureIgnoreCase)) + continue; - return matchesSource || matchesContent; - } - - // If this entry has a filter, check the filter - if (this.pluginFilters.FirstOrDefault(filter => string.Equals(filter.Source, entry.Source, StringComparison.InvariantCultureIgnoreCase)) is { } filterEntry) - { var allowedLevel = filterEntry.Level <= entry.Level; - var matchesContent = filterEntry.Filter.IsNullOrEmpty() || Regex.IsMatch(entry.Line, filterEntry.Filter, RegexOptions.IgnoreCase); + var matchesContent = filterEntry.FilterRegex?.IsMatch(entry.Line) is not false; - return allowedLevel && matchesContent; + matchesAny |= allowedLevel && matchesContent; + if (matchesAny) + break; } - } - catch (Exception) - { - this.regexError = true; - return false; + + wholeCond &= matchesAny; } - // else we couldn't find a filter for this entry, if we have any filters, we need to block this entry. - return !this.pluginFilters.Any(); + return wholeCond; } - private void Refilter() - { - lock (this.renderLock) - { - this.regexError = false; - this.FilteredLogEntries = new RollingList(this.logText.Where(this.IsFilterApplicable), Math.Max(LogLinesMinimum, this.logLinesLimit)); - } - } + /// Queues clearing the window of all log entries, before next call to . + private void QueueClear() => this.pendingClearLog = true; - private string GetTextForLogEventLevel(LogEventLevel level) => level switch - { - LogEventLevel.Error => "ERR", - LogEventLevel.Verbose => "VRB", - LogEventLevel.Debug => "DBG", - LogEventLevel.Information => "INF", - LogEventLevel.Warning => "WRN", - LogEventLevel.Fatal => "FTL", - _ => throw new ArgumentOutOfRangeException(level.ToString(), "Invalid LogEventLevel"), - }; + /// Queues filtering the log entries again, before next call to . + private void QueueRefilter() => this.pendingRefilter = true; - private uint GetColorForLogEventLevel(LogEventLevel level) => level switch - { - LogEventLevel.Error => 0x800000EE, - LogEventLevel.Verbose => 0x00000000, - LogEventLevel.Debug => 0x00000000, - LogEventLevel.Information => 0x00000000, - LogEventLevel.Warning => 0x8A0070EE, - LogEventLevel.Fatal => 0xFF00000A, - _ => throw new ArgumentOutOfRangeException(level.ToString(), "Invalid LogEventLevel"), - }; + /// Enqueues the new log line to the log-to-be-processed queue. + /// See for the handler for the queued log entries. + private void OnLogLine(object sender, (string Line, LogEvent LogEvent) logEvent) => + this.newLogEntries.Enqueue(logEvent); - private void OnLogLine(object sender, (string Line, LogEvent LogEvent) logEvent) - { - this.HandleLogLine(logEvent.Line, logEvent.LogEvent); - } - - private bool DrawToggleButtonWithTooltip(string buttonId, string tooltip, FontAwesomeIcon icon, ref bool enabledState) + private bool DrawToggleButtonWithTooltip( + string buttonId, string tooltip, FontAwesomeIcon icon, ref bool enabledState) { var result = false; @@ -855,36 +1032,120 @@ internal class ConsoleWindow : Window, IDisposable this.logLinesLimit = dalamudConfiguration.LogLinesLimit; var limit = Math.Max(LogLinesMinimum, this.logLinesLimit); this.logText.Size = limit; - this.FilteredLogEntries.Size = limit; + this.filteredLogEntries.Size = limit; } - private class LogEntry + private unsafe void DrawHighlighted( + ReadOnlySpan line, + MatchCollection matches, + uint col, + uint highlightCol) { - public string Line { get; init; } = string.Empty; + Span charOffsets = stackalloc int[(matches.Count * 2) + 2]; + var charOffsetsIndex = 1; + for (var j = 0; j < matches.Count; j++) + { + var g = matches[j].Groups[0]; + charOffsets[charOffsetsIndex++] = g.Index; + charOffsets[charOffsetsIndex++] = g.Index + g.Length; + } + + charOffsets[charOffsetsIndex++] = line.Length; + + var screenPos = ImGui.GetCursorScreenPos(); + var drawList = ImGui.GetWindowDrawList().NativePtr; + var font = ImGui.GetFont(); + var size = ImGui.GetFontSize(); + var scale = size / font.FontSize; + var hotData = font.IndexedHotDataWrapped(); + var lookup = font.IndexLookupWrapped(); + var kern = (ImGui.GetIO().ConfigFlags & ImGuiConfigFlags.NoKerning) == 0; + var lastc = '\0'; + for (var i = 0; i < charOffsetsIndex - 1; i++) + { + var begin = charOffsets[i]; + var end = charOffsets[i + 1]; + if (begin == end) + continue; + + for (var j = begin; j < end; j++) + { + var currc = line[j]; + if (currc >= lookup.Length || lookup[currc] == ushort.MaxValue) + currc = (char)font.FallbackChar; + + if (kern) + screenPos.X += scale * ImGui.GetFont().GetDistanceAdjustmentForPair(lastc, currc); + font.RenderChar(drawList, size, screenPos, i % 2 == 1 ? highlightCol : col, currc); + + screenPos.X += scale * hotData[currc].AdvanceX; + lastc = currc; + } + } + } + + private record LogEntry + { + public string Line { get; set; } = string.Empty; public LogEventLevel Level { get; init; } public DateTimeOffset TimeStamp { get; init; } - public bool IsMultiline { get; init; } + public bool IsMultiline { get; set; } /// /// Gets or sets the system responsible for generating this log entry. Generally will be a plugin's /// InternalName. /// public string? Source { get; set; } - + public bool SelectedForCopy { get; set; } public bool HasException { get; init; } + + public MatchCollection? HighlightMatches { get; set; } + + public string TimestampString => this.TimeStamp.ToString("HH:mm:ss.fff"); + + public override string ToString() => + this.IsMultiline + ? $"\t{this.Line}" + : $"{this.TimestampString} | {GetTextForLogEventLevel(this.Level)} | {this.Line}"; } private class PluginFilterEntry { + private string filter = string.Empty; + public string Source { get; init; } = string.Empty; - public string Filter { get; set; } = string.Empty; - + public string Filter + { + get => this.filter; + set + { + this.filter = value; + this.FilterRegex = null; + this.FilterException = null; + if (value == string.Empty) + return; + + try + { + this.FilterRegex = new(value, RegexOptions.IgnoreCase); + } + catch (Exception e) + { + this.FilterException = e; + } + } + } + public LogEventLevel Level { get; set; } + + public Regex? FilterRegex { get; private set; } + + public Exception? FilterException { get; private set; } } } diff --git a/Dalamud/Utility/ThreadSafety.cs b/Dalamud/Utility/ThreadSafety.cs index 7c4b0dfcb..ce3ddc602 100644 --- a/Dalamud/Utility/ThreadSafety.cs +++ b/Dalamud/Utility/ThreadSafety.cs @@ -1,4 +1,5 @@ using System; +using System.Runtime.CompilerServices; namespace Dalamud.Utility; @@ -19,6 +20,7 @@ public static class ThreadSafety /// Throws an exception when the current thread is not the main thread. /// /// Thrown when the current thread is not the main thread. + [MethodImpl(MethodImplOptions.AggressiveInlining)] public static void AssertMainThread() { if (!threadStaticIsMainThread) @@ -31,6 +33,7 @@ public static class ThreadSafety /// Throws an exception when the current thread is the main thread. /// /// Thrown when the current thread is the main thread. + [MethodImpl(MethodImplOptions.AggressiveInlining)] public static void AssertNotMainThread() { if (threadStaticIsMainThread) @@ -39,6 +42,15 @@ public static class ThreadSafety } } + /// , but only on debug compilation mode. + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public static void DebugAssertMainThread() + { +#if DEBUG + AssertMainThread(); +#endif + } + /// /// Marks a thread as the main thread. ///