Merge pull request #943 from KazWolfe/log-improvements

This commit is contained in:
goat 2022-09-03 23:45:58 +02:00 committed by GitHub
commit 678583d4ac
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
4 changed files with 127 additions and 54 deletions

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)

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; }
}
}
}

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));
}
}
}

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);
}
}
}