ToxicMushroom/Dalamud
1
0
Fork 0
mirror of https://github.com/goatcorp/Dalamud.git synced 2025-12-13 12:14:16 +01:00
Code Issues Projects Releases Packages Wiki Activity Actions 2

Add Per-Plugin Log Filtering Support

Browse source 
This commit adds first-pass support for more robust plugin log filtering. No changes were made that affect PluginLog's APIs nor log format. This change works by making use of Serilog's "SourceContext" property to attach plugin information to all log messages. The in-game log UI can then be used to filter based on this property.

Future expansions for this system include the ability to set different plugins to different log levels (something that already can technically be done, but requires those plugins be hard-coded through MinimumLevel.Override), creating new root loggers for each plugin (thereby giving plugin devs more control over their logging should they want to use it), plus other potential improvements in the way of adding context or rich information.

- Update PluginLog to attach a "SourceContext" property to all log messages.
- Tweak the SerilogEventSink to pass the original log event around.
- Suppress Info/Debug/Verbose exceptions from Troubleshooting reports.
- Fix the ConsoleWindow log filter to use _all_ filters, rather than just one.
- Add ConsoleWindow dropdown to select plugins to filter logs by
- Add support for multiple log levels to ConsoleWindow filtering
This commit is contained in:
Kaz Wolfe 2022-07-30 13:59:15 -07:00
parent 6692d56029
commit abecf2ffe4
No known key found for this signature in database
GPG key ID: 258813F53A16EBB4
4 changed files with 127 additions and 54 deletions
Download patch file Download diff file Expand all files Collapse all files

11
Dalamud/EntryPoint.cs
View file

@ -182,12 +182,17 @@ namespace Dalamud
}
}
private static void SerilogOnLogLine(object? sender, (string Line, LogEventLevel Level, DateTimeOffset TimeStamp, Exception? Exception) e)
private static void SerilogOnLogLine(object? sender, (string Line, LogEvent LogEvent) ev)
{
if (e.Exception == null)
if (ev.LogEvent.Exception == null)
return;
Troubleshooting.LogException(e.Exception, e.Line);
// Don't pass verbose/debug/info exceptions to the troubleshooter, as the developer is probably doing
// something intentionally (or this is known).
if (ev.LogEvent.Level < LogEventLevel.Warning)
return;
Troubleshooting.LogException(ev.LogEvent.Exception, ev.Line);
}
private static void InitSymbolHandler(DalamudStartInfo info)

92
Dalamud/Interface/Internal/Windows/ConsoleWindow.cs
View file

@ -12,6 +12,7 @@ using Dalamud.Interface.Colors;
using Dalamud.Interface.Components;
using Dalamud.Interface.Windowing;
using Dalamud.Logging.Internal;
using Dalamud.Plugin.Internal;
using ImGuiNET;
using Serilog;
using Serilog.Events;
@ -26,7 +27,7 @@ namespace Dalamud.Interface.Internal.Windows
private readonly List<LogEntry> logText = new();
private readonly object renderLock = new();
private readonly string[] logLevelStrings = new[] { "None", "Verbose", "Debug", "Information", "Warning", "Error", "Fatal" };
private readonly string[] logLevelStrings = new[] { "Verbose", "Debug", "Information", "Warning", "Error", "Fatal" };
private List<LogEntry> filteredLogText = new();
private bool autoScroll;
@ -37,7 +38,8 @@ namespace Dalamud.Interface.Internal.Windows
private string commandText = string.Empty;
private string textFilter = string.Empty;
private LogEventLevel? levelFilter = null;
private int levelFilter;
private List<string> sourceFilters = new();
private bool isFiltered = false;
private int historyPos;
@ -96,24 +98,23 @@ namespace Dalamud.Interface.Internal.Windows
/// Add a single log line to the display.
/// </summary>
/// <param name="line">The line to add.</param>
/// <param name="level">The level of the event.</param>
/// <param name="offset">The <see cref="DateTimeOffset"/> of the event.</param>
public void HandleLogLine(string line, LogEventLevel level, DateTimeOffset offset)
/// <param name="logEvent">The Serilog event associated with this line.</param>
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], level, offset, false);
this.AddAndFilter(subLines[0], logEvent, false);
for (var i = 1; i < subLines.Length; i++)
{
this.AddAndFilter(subLines[i], level, offset, true);
this.AddAndFilter(subLines[i], logEvent, true);
}
}
else
{
this.AddAndFilter(line, level, offset, false);
this.AddAndFilter(line, logEvent, false);
}
}
@ -160,12 +161,50 @@ namespace Dalamud.Interface.Internal.Windows
ImGui.TextColored(ImGuiColors.DalamudGrey, "Enter to confirm.");
var filterVal = this.levelFilter.HasValue ? (int)this.levelFilter.Value + 1 : 0;
if (ImGui.Combo("Level", ref filterVal, this.logLevelStrings, 7))
if (ImGui.BeginCombo("Levels", this.levelFilter == 0 ? "All Levels..." : "Selected Levels..."))
{
this.levelFilter = (LogEventLevel)(filterVal - 1);
for (var i = 0; i < this.logLevelStrings.Length; i++)
{
if (ImGui.Selectable(this.logLevelStrings[i], ((this.levelFilter >> i) & 1) == 1))
{
this.levelFilter ^= 1 << i;
this.Refilter();
}
}
ImGui.EndCombo();
}
// Filter by specific plugin(s)
var pluginInternalNames = Service<PluginManager>.Get().InstalledPlugins.Select(p => p.Manifest.InternalName).ToList();
var sourcePreviewVal = this.sourceFilters.Count switch
{
0 => "All plugins...",
1 => "1 plugin...",
_ => $"{this.sourceFilters.Count} plugins...",
};
var sourceSelectables = pluginInternalNames.Union(this.sourceFilters).ToList();
if (ImGui.BeginCombo("Plugins", sourcePreviewVal))
{
foreach (var selectable in sourceSelectables)
{
if (ImGui.Selectable(selectable, this.sourceFilters.Contains(selectable)))
{
if (!this.sourceFilters.Contains(selectable))
{
this.sourceFilters.Add(selectable);
}
else
{
this.sourceFilters.Remove(selectable);
}
this.Refilter();
}
}
ImGui.EndCombo();
}
ImGui.EndPopup();
}
@ -435,7 +474,7 @@ namespace Dalamud.Interface.Internal.Windows
return 0;
}
private void AddAndFilter(string line, LogEventLevel level, DateTimeOffset offset, bool isMultiline)
private void AddAndFilter(string line, LogEvent logEvent, bool isMultiline)
{
if (line.StartsWith("TROUBLESHOOTING:") || line.StartsWith("LASTEXCEPTION:"))
return;
@ -443,11 +482,17 @@ namespace Dalamud.Interface.Internal.Windows
var entry = new LogEntry
{
IsMultiline = isMultiline,
Level = level,
Level = logEvent.Level,
Line = line,
TimeStamp = offset,
TimeStamp = logEvent.Timestamp,
};
if (logEvent.Properties.TryGetValue("SourceContext", out var sourceProp) &&
sourceProp is ScalarValue { Value: string value })
{
entry.Source = value;
}
this.logText.Add(entry);
if (!this.isFiltered)
@ -459,13 +504,14 @@ namespace Dalamud.Interface.Internal.Windows
private bool IsFilterApplicable(LogEntry entry)
{
if (this.levelFilter.HasValue)
{
return entry.Level == this.levelFilter.Value;
}
if (this.levelFilter > 0 && ((this.levelFilter >> (int)entry.Level) & 1) == 0)
return false;
if (!string.IsNullOrEmpty(this.textFilter))
return entry.Line.Contains(this.textFilter);
if (this.sourceFilters.Count > 0 && !this.sourceFilters.Contains(entry.Source))
return false;
if (!string.IsNullOrEmpty(this.textFilter) && !entry.Line.Contains(this.textFilter))
return false;
return true;
}
@ -500,9 +546,9 @@ namespace Dalamud.Interface.Internal.Windows
_ => throw new ArgumentOutOfRangeException(level.ToString(), "Invalid LogEventLevel"),
};
private void OnLogLine(object sender, (string Line, LogEventLevel Level, DateTimeOffset Offset, Exception? Exception) logEvent)
private void OnLogLine(object sender, (string Line, LogEvent LogEvent) logEvent)
{
this.HandleLogLine(logEvent.Line, logEvent.Level, logEvent.Offset);
this.HandleLogLine(logEvent.Line, logEvent.LogEvent);
}
private class LogEntry
@ -514,6 +560,8 @@ namespace Dalamud.Interface.Internal.Windows
public DateTimeOffset TimeStamp { get; set; }
public bool IsMultiline { get; set; }
public string? Source { get; set; }
}
}
}

10
Dalamud/Logging/Internal/SerilogEventSink.cs
View file

@ -25,7 +25,7 @@ namespace Dalamud.Logging.Internal
/// <summary>
/// Event on a log line being emitted.
/// </summary>
public event EventHandler<(string Line, LogEventLevel Level, DateTimeOffset TimeStamp, Exception? Exception)>? LogLine;
public event EventHandler<(string Line, LogEvent LogEvent)>? LogLine;
/// <summary>
/// Gets the default instance.
@ -40,12 +40,18 @@ namespace Dalamud.Logging.Internal
{
var message = logEvent.RenderMessage(this.formatProvider);
if (logEvent.Properties.TryGetValue("SourceContext", out var sourceProp) &&
sourceProp is ScalarValue { Value: string source })
{
message = $"[{source}] {message}";
}
if (logEvent.Exception != null)
{
message += "\n" + logEvent.Exception;
}
this.LogLine?.Invoke(this, (message, logEvent.Level, logEvent.Timestamp, logEvent.Exception));
this.LogLine?.Invoke(this, (message, logEvent));
}
}
}

66
Dalamud/Logging/PluginLog.cs
View file

@ -1,6 +1,9 @@
using System;
using System.Reflection;
using Serilog;
using Serilog.Events;
namespace Dalamud.Logging
{
/// <summary>
@ -16,7 +19,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Log(string messageTemplate, params object[] values)
=> Serilog.Log.Information($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Information, messageTemplate, null, values);
/// <summary>
/// Log a templated message to the in-game debug log.
@ -25,7 +28,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Log(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Information(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Information, messageTemplate, exception, values);
/// <summary>
/// Log a templated verbose message to the in-game debug log.
@ -33,7 +36,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogVerbose(string messageTemplate, params object[] values)
=> Serilog.Log.Verbose($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Verbose, messageTemplate, null, values);
/// <summary>
/// Log a templated verbose message to the in-game debug log.
@ -42,7 +45,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogVerbose(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Verbose(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Verbose, messageTemplate, exception, values);
/// <summary>
/// Log a templated debug message to the in-game debug log.
@ -50,7 +53,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogDebug(string messageTemplate, params object[] values)
=> Serilog.Log.Debug($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Debug, messageTemplate, null, values);
/// <summary>
/// Log a templated debug message to the in-game debug log.
@ -59,7 +62,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogDebug(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Debug(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Debug, messageTemplate, exception, values);
/// <summary>
/// Log a templated information message to the in-game debug log.
@ -67,7 +70,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogInformation(string messageTemplate, params object[] values)
=> Serilog.Log.Information($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Information, messageTemplate, null, values);
/// <summary>
/// Log a templated information message to the in-game debug log.
@ -76,7 +79,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogInformation(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Information(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Information, messageTemplate, exception, values);
/// <summary>
/// Log a templated warning message to the in-game debug log.
@ -84,7 +87,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogWarning(string messageTemplate, params object[] values)
=> Serilog.Log.Warning($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Warning, messageTemplate, null, values);
/// <summary>
/// Log a templated warning message to the in-game debug log.
@ -93,7 +96,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogWarning(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Warning(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Warning, messageTemplate, exception, values);
/// <summary>
/// Log a templated error message to the in-game debug log.
@ -101,7 +104,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogError(string messageTemplate, params object[] values)
=> Serilog.Log.Error($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Error, messageTemplate, null, values);
/// <summary>
/// Log a templated error message to the in-game debug log.
@ -110,7 +113,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogError(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Error(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Error, messageTemplate, exception, values);
/// <summary>
/// Log a templated fatal message to the in-game debug log.
@ -118,7 +121,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogFatal(string messageTemplate, params object[] values)
=> Serilog.Log.Fatal($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Fatal, messageTemplate, null, values);
/// <summary>
/// Log a templated fatal message to the in-game debug log.
@ -127,7 +130,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void LogFatal(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Fatal(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Fatal, messageTemplate, exception, values);
#endregion
@ -139,7 +142,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Verbose(string messageTemplate, params object[] values)
=> Serilog.Log.Verbose($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Verbose, messageTemplate, null, values);
/// <summary>
/// Log a templated verbose message to the in-game debug log.
@ -148,7 +151,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Verbose(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Verbose(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Verbose, messageTemplate, exception, values);
/// <summary>
/// Log a templated debug message to the in-game debug log.
@ -156,7 +159,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Debug(string messageTemplate, params object[] values)
=> Serilog.Log.Debug($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Debug, messageTemplate, null, values);
/// <summary>
/// Log a templated debug message to the in-game debug log.
@ -165,7 +168,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Debug(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Debug(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Debug, messageTemplate, exception, values);
/// <summary>
/// Log a templated information message to the in-game debug log.
@ -173,7 +176,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Information(string messageTemplate, params object[] values)
=> Serilog.Log.Information($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Information, messageTemplate, null, values);
/// <summary>
/// Log a templated information message to the in-game debug log.
@ -182,7 +185,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Information(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Information(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Information, messageTemplate, exception, values);
/// <summary>
/// Log a templated warning message to the in-game debug log.
@ -190,7 +193,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Warning(string messageTemplate, params object[] values)
=> Serilog.Log.Warning($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Warning, messageTemplate, null, values);
/// <summary>
/// Log a templated warning message to the in-game debug log.
@ -199,7 +202,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Warning(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Warning(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Warning, messageTemplate, exception, values);
/// <summary>
/// Log a templated error message to the in-game debug log.
@ -207,7 +210,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Error(string messageTemplate, params object[] values)
=> Serilog.Log.Error($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Error, messageTemplate, null, values);
/// <summary>
/// Log a templated error message to the in-game debug log.
@ -216,7 +219,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Error(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Error(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Error, messageTemplate, exception, values);
/// <summary>
/// Log a templated fatal message to the in-game debug log.
@ -224,7 +227,7 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Fatal(string messageTemplate, params object[] values)
=> Serilog.Log.Fatal($"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Fatal, messageTemplate, null, values);
/// <summary>
/// Log a templated fatal message to the in-game debug log.
@ -233,8 +236,19 @@ namespace Dalamud.Logging
/// <param name="messageTemplate">The message template.</param>
/// <param name="values">Values to log.</param>
public static void Fatal(Exception exception, string messageTemplate, params object[] values)
=> Serilog.Log.Fatal(exception, $"[{Assembly.GetCallingAssembly().GetName().Name}] {messageTemplate}", values);
=> WriteLog(Assembly.GetCallingAssembly().GetName().Name, LogEventLevel.Fatal, messageTemplate, exception, values);
#endregion
private static ILogger GetPluginLogger(string? pluginName)
{
return Serilog.Log.ForContext("SourceContext", pluginName ?? string.Empty);
}
private static void WriteLog(string? pluginName, LogEventLevel level, string messageTemplate, Exception? exception = null, params object[] values)
{
var pluginLogger = GetPluginLogger(pluginName);
pluginLogger.Write(level, exception: exception, messageTemplate: messageTemplate, values);
}
}
}