#nullable enable
using IPA.Config;
using IPA.Logging.Printers;
using IPA.Utilities;
using System;
using System.Collections.Concurrent;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Linq;
using System.Threading;
namespace IPA.Logging
{
///
/// The default (and standard) implementation.
///
///
/// uses a multi-threaded approach to logging. All actual I/O is done on another thread,
/// where all messaged are guaranteed to be logged in the order they appeared. It is up to the printers to format them.
///
/// This logger supports child loggers. Use to safely get a child.
/// The modification of printers on a parent are reflected down the chain.
///
public class StandardLogger : Logger
{
private static readonly List defaultPrinters = new();
static StandardLogger()
{
ConsoleColorSupport();
}
private static bool addedConsolePrinters;
private static bool finalizedDefaultPrinters;
internal static void ConsoleColorSupport()
{
if (!addedConsolePrinters && !finalizedDefaultPrinters && WinConsole.IsInitialized )
{
defaultPrinters.AddRange(new []
{
new ColoredConsolePrinter()
{
Filter = LogLevel.TraceOnly,
Color = ConsoleColor.DarkMagenta,
},
new ColoredConsolePrinter()
{
Filter = LogLevel.DebugOnly,
Color = ConsoleColor.Green,
},
new ColoredConsolePrinter()
{
Filter = LogLevel.InfoOnly,
Color = ConsoleColor.White,
},
new ColoredConsolePrinter()
{
Filter = LogLevel.NoticeOnly,
Color = ConsoleColor.Cyan
},
new ColoredConsolePrinter()
{
Filter = LogLevel.WarningOnly,
Color = ConsoleColor.Yellow,
},
new ColoredConsolePrinter()
{
Filter = LogLevel.ErrorOnly,
Color = ConsoleColor.Red,
},
new ColoredConsolePrinter()
{
Filter = LogLevel.CriticalOnly,
Color = ConsoleColor.Magenta,
}
});
addedConsolePrinters = true;
}
}
///
/// The for writing directly to the console window, or stdout if no window open.
///
/// a for the current primary text output
public static TextWriter ConsoleWriter { get; internal set; } = Console.Out;
///
/// Adds to the default printer pool that all printers inherit from. Printers added this way will be passed every message from every logger.
///
/// the printer to add
internal static void AddDefaultPrinter(LogPrinter printer)
{
defaultPrinters.Add(printer);
}
private readonly string logName;
private static bool showSourceClass;
///
/// All levels defined by this filter will be sent to loggers. All others will be ignored.
///
/// the global filter level
public static LogLevel PrintFilter { get; internal set; } = LogLevel.All;
private static bool showTrace = false;
private static volatile bool syncLogging = false;
private readonly List printers = new();
private readonly StandardLogger? parent;
private readonly Dictionary children = new();
private static bool addedFilePrinter = false;
///
/// Configures internal debug settings based on the config passed in.
///
internal static void Configure()
{
showSourceClass = SelfConfig.Debug_.ShowCallSource_;
PrintFilter = SelfConfig.Debug_.ShowDebug_ ? LogLevel.All : LogLevel.InfoUp;
showTrace = SelfConfig.Debug_.ShowTrace_;
syncLogging = SelfConfig.Debug_.SyncLogging_;
if(SelfConfig.CommandLineValues.WriteLogs && !addedFilePrinter) {
addedFilePrinter = true;
AddDefaultPrinter(new GZFilePrinter());
}
}
private StandardLogger(StandardLogger parent, string subName)
{
logName = $"{parent.logName}/{subName}";
this.parent = parent;
printers = new List();
if (SelfConfig.Debug_.CreateModLogs_ && !SelfConfig.Debug_.CondenseModLogs_)
printers.Add(new PluginSubLogPrinter(parent.logName, subName));
if (logThread == null || !logThread.IsAlive)
{
logThread = new Thread(LogThread);
logThread.Start();
}
}
internal StandardLogger(string name)
{
ConsoleColorSupport();
if (!finalizedDefaultPrinters)
{
if (!addedConsolePrinters)
AddDefaultPrinter(new ColorlessConsolePrinter());
finalizedDefaultPrinters = true;
}
logName = name;
if (SelfConfig.Debug_.CreateModLogs_)
printers.Add(new PluginLogFilePrinter(name));
if (logThread == null || !logThread.IsAlive)
{
logThread = new Thread(LogThread);
logThread.Start();
}
}
///
/// Gets a child printer with the given name, either constructing a new one or using one that was already made.
///
///
/// a child with the given sub-name
internal StandardLogger GetChild(string name)
{
if (!children.TryGetValue(name, out var child))
{
child = new StandardLogger(this, name);
children.Add(name, child);
}
return child;
}
///
/// Adds a log printer to the logger.
///
/// the printer to add
public void AddPrinter(LogPrinter printer)
{
printers.Add(printer);
}
///
/// Logs a specific message at a given level.
///
/// the message level
/// the message to log
public override void Log(Level level, string message)
{
if (message == null)
throw new ArgumentNullException(nameof(message));
// FIXME: trace doesn't seem to ever actually appear
if (!showTrace && level == Level.Trace) return;
// make sure that the queue isn't being cleared
logWaitEvent.Wait();
try
{
var sync = syncLogging && !IsOnLoggerThread;
if (sync)
{
threadSync ??= new ManualResetEventSlim();
threadSync.Reset();
}
logQueue.Add(new LogMessage
{
Level = level,
Message = message,
Logger = this,
Time = Utils.CurrentTime(),
Sync = threadSync
});
if (sync) threadSync!.Wait();
}
catch (InvalidOperationException)
{
// the queue has been closed, so we leave it
}
}
[ThreadStatic]
private static ManualResetEventSlim? threadSync;
///
///
/// An override to which shows the method that called it.
///
/// the message to log
public override void Debug(string message)
{
if (showSourceClass)
{
// add source to message
var stackFrame = new StackTrace(true).GetFrame(1);
var lineNo = stackFrame.GetFileLineNumber();
if (lineNo == 0)
{ // no debug info
var method = stackFrame.GetMethod();
var paramString = string.Join(", ", method.GetParameters().Select(p => p.ParameterType.FullName).StrJP());
message = $"{{{method.DeclaringType?.FullName}::{method.Name}({paramString})}} {message}";
}
else
message = $"{{{stackFrame.GetFileName()}:{lineNo}}} {message}";
}
base.Debug(message);
}
private struct LogMessage
{
public Level Level;
public StandardLogger Logger;
public string Message;
public DateTime Time;
public ManualResetEventSlim? Sync;
}
[ThreadStatic]
private static bool? isOnLoggerThread = null;
///
/// Whether or not the calling thread is the logger thread.
///
/// if the current thread is the logger thread, otherwise
public static bool IsOnLoggerThread => isOnLoggerThread ??= Thread.CurrentThread.ManagedThreadId == logThread?.ManagedThreadId;
private static readonly ManualResetEventSlim logWaitEvent = new(true);
private static readonly BlockingCollection logQueue = new();
private static Thread? logThread;
private static StandardLogger? loggerLogger;
private const int LogCloseTimeout = 250;
///
/// The log printer thread for .
///
private static void LogThread()
{
AppDomain.CurrentDomain.ProcessExit += (sender, args) =>
{
StopLogThread();
};
loggerLogger = new StandardLogger("Log Subsystem");
loggerLogger.printers.Clear(); // don't need a log file for this one
var timeout = TimeSpan.FromMilliseconds(LogCloseTimeout);
try
{
var started = new HashSet();
while (logQueue.TryTake(out var msg, Timeout.Infinite))
{
StdoutInterceptor.Intercept(); // only runs once, after the first message is queued
do
{
var logger = msg.Logger;
IEnumerable printers = logger.printers;
do
{ // aggregate all printers in the inheritance chain
logger = logger.parent;
if (logger != null)
printers = printers.Concat(logger.printers);
} while (logger != null);
foreach (var printer in printers.Concat(defaultPrinters))
{
try
{ // print to them all
if (((byte)msg.Level & (byte)printer.Filter) != 0)
{
if (!started.Contains(printer))
{ // start printer if not started
printer.StartPrint();
_ = started.Add(printer);
}
// update last use time and print
printer.LastUse = Utils.CurrentTime();
printer.Print(msg.Level, msg.Time, msg.Logger.logName, msg.Message);
}
}
catch (Exception e)
{
// do something sane in the face of an error
Console.WriteLine($"printer errored: {e}");
}
}
msg.Sync?.Set();
var debugConfig = SelfConfig.Instance?.Debug;
if (debugConfig != null && debugConfig.HideMessagesForPerformance
&& logQueue.Count > debugConfig.HideLogThreshold)
{ // spam filtering (if queue has more than HideLogThreshold elements)
logWaitEvent.Reset(); // pause incoming log requests
// clear loggers for this instance, to print the message to all affected logs
loggerLogger.printers.Clear();
var prints = new HashSet();
// clear the queue
while (logQueue.TryTake(out var message))
{ // aggregate loggers in the process
var messageLogger = message.Logger;
foreach (var print in messageLogger.printers)
_ = prints.Add(print);
do
{
messageLogger = messageLogger.parent;
if (messageLogger != null)
foreach (var print in messageLogger.printers)
_ = prints.Add(print);
} while (messageLogger != null);
message.Sync?.Set();
}
// print using logging subsystem to all logger printers
loggerLogger.printers.AddRange(prints);
logQueue.Add(new LogMessage
{ // manually adding to the queue instead of using Warn() because calls to the logger are suspended here
Level = Level.Warning,
Logger = loggerLogger,
Message = $"{loggerLogger.logName.ToUpper()}: Messages omitted to improve performance",
Time = Utils.CurrentTime()
});
// resume log calls
logWaitEvent.Set();
}
var now = Utils.CurrentTime();
var copy = new List(started);
foreach (var printer in copy)
{
// close printer after 500ms from its last use
if (now - printer.LastUse > timeout)
{
try
{
printer.EndPrint();
}
catch (Exception e)
{
Console.WriteLine($"printer errored: {e}");
}
_ = started.Remove(printer);
}
}
}
// wait for messages for 500ms before ending the prints
while (logQueue.TryTake(out msg, timeout));
if (logQueue.Count == 0)
{ // when the queue has been empty for 500ms, end all prints
foreach (var printer in started)
{
try
{
printer.EndPrint();
}
catch (Exception e)
{
Console.WriteLine($"printer errored: {e}");
}
}
started.Clear();
}
}
}
catch (InvalidOperationException)
{
}
}
///
/// Stops and joins the log printer thread.
///
internal static void StopLogThread()
{
logQueue.CompleteAdding();
logThread!.Join();
}
}
///
/// A class providing extensions for various loggers.
///
public static class LoggerExtensions
{
///
/// Gets a child logger, if supported. Currently the only defined and supported logger is , and most plugins will only ever receive this anyway.
///
/// the parent
/// the name of the child
/// the child logger
public static Logger GetChildLogger(this Logger logger, string name)
=> logger switch
{
StandardLogger l => l.GetChild(name),
_ => throw new InvalidOperationException()
};
}
}