diff --git a/IPA.Injector/Injector.cs b/IPA.Injector/Injector.cs index a36e2cb0..3df55ab2 100644 --- a/IPA.Injector/Injector.cs +++ b/IPA.Injector/Injector.cs @@ -44,7 +44,7 @@ namespace IPA.Injector } private static void Log(Level lvl, string message) { // multiple proxy methods to delay loading of assemblies until it's done - if (Logger.LogCreated) + if (LogCreated) AssemblyLibLoaderCallLogger(lvl, message); else if (((byte)lvl & (byte)StandardLogger.PrintFilter) != 0) @@ -52,7 +52,7 @@ namespace IPA.Injector } private static void AssemblyLibLoaderCallLogger(Level lvl, string message) { - Logger.log.Log(lvl, message); + libLoader.Log(lvl, message); } private static void Bootstrapper_Destroyed() diff --git a/IPA.Loader/IPA.Loader.csproj b/IPA.Loader/IPA.Loader.csproj index fde2bb16..21b93128 100644 --- a/IPA.Loader/IPA.Loader.csproj +++ b/IPA.Loader/IPA.Loader.csproj @@ -56,6 +56,7 @@ + diff --git a/IPA.Loader/Loader/PluginManager.cs b/IPA.Loader/Loader/PluginManager.cs index 8c66acdc..cd97e4a3 100644 --- a/IPA.Loader/Loader/PluginManager.cs +++ b/IPA.Loader/Loader/PluginManager.cs @@ -177,7 +177,7 @@ namespace IPA.Loader } catch (Exception e) { - Logger.log.Error($"Could not load plugin {t.FullName} in {Path.GetFileName(file)}! {e}"); + Logger.loader.Error($"Could not load plugin {t.FullName} in {Path.GetFileName(file)}! {e}"); } } @@ -276,7 +276,7 @@ namespace IPA.Loader } catch (AmbiguousMatchException) { - Logger.log.Error($"Only one Init allowed per plugin"); + Logger.loader.Error($"Only one Init allowed per plugin"); } } else @@ -292,7 +292,7 @@ namespace IPA.Loader } catch (Exception e) { - Logger.log.Error($"Could not load {Path.GetFileName(file)}! {e}"); + Logger.loader.Error($"Could not load {Path.GetFileName(file)}! {e}"); } return new Tuple, IEnumerable>(bsPlugins, ipaPlugins); diff --git a/IPA.Loader/Logging/Logger.cs b/IPA.Loader/Logging/Logger.cs index bfc187ec..93f1529f 100644 --- a/IPA.Loader/Logging/Logger.cs +++ b/IPA.Loader/Logging/Logger.cs @@ -21,6 +21,9 @@ namespace IPA.Logging return _log; } } + internal static Logger updater => log.GetChildLogger("Upater"); + internal static Logger libLoader => log.GetChildLogger("LibraryLoader"); + internal static Logger loader => log.GetChildLogger("Loader"); internal static bool LogCreated => _log != null; /// diff --git a/IPA.Loader/Logging/Printers/PluginLogFilePrinter.cs b/IPA.Loader/Logging/Printers/PluginLogFilePrinter.cs index e5a7d00d..6665f7da 100644 --- a/IPA.Loader/Logging/Printers/PluginLogFilePrinter.cs +++ b/IPA.Loader/Logging/Printers/PluginLogFilePrinter.cs @@ -51,7 +51,7 @@ namespace IPA.Logging.Printers public override void Print(Logger.Level level, DateTime time, string logName, string message) { foreach (var line in message.Split(new string[] { "\n", Environment.NewLine }, StringSplitOptions.RemoveEmptyEntries)) - fileWriter.WriteLine(string.Format("[{2} @ {1:HH:mm:ss}] {0}", line, time, level.ToString().ToUpper())); + fileWriter.WriteLine(string.Format(Logger.LogFormat, line, logName, time, level.ToString().ToUpper())); } } } diff --git a/IPA.Loader/Logging/Printers/PluginSubLogPrinter.cs b/IPA.Loader/Logging/Printers/PluginSubLogPrinter.cs new file mode 100644 index 00000000..a3120ca3 --- /dev/null +++ b/IPA.Loader/Logging/Printers/PluginSubLogPrinter.cs @@ -0,0 +1,60 @@ +using IPA.Logging; +using System; +using System.Collections.Generic; +using System.IO; +using System.Linq; +using System.Text; +using System.Threading.Tasks; + +namespace IPA.Logging.Printers +{ + /// + /// Prints log messages to the file specified by the name. + /// + public class PluginSubLogPrinter : GZFilePrinter + { + /// + /// Provides a filter for this specific printer. + /// + public override Logger.LogLevel Filter { get; set; } = Logger.LogLevel.All; + + private string name; + private string mainName; + + /// + /// Gets the for the target file. + /// + /// + protected override FileInfo GetFileInfo() + { + var logsDir = new DirectoryInfo(Path.Combine("Logs", mainName, name)); + logsDir.Create(); + var finfo = new FileInfo(Path.Combine(logsDir.FullName, $"{DateTime.Now:yyyy.MM.dd.HH.mm}.log")); + return finfo; + } + + /// + /// Creates a new printer with the given name. + /// + /// the name of the main logger + /// the name of the logger + public PluginSubLogPrinter(string mainname, string name) + { + this.name = name; + mainName = mainname; + } + + /// + /// Prints an entry to the associated file. + /// + /// the of the message + /// the the message was recorded at + /// the name of the log that sent the message + /// the message to print + public override void Print(Logger.Level level, DateTime time, string logName, string message) + { + foreach (var line in message.Split(new string[] { "\n", Environment.NewLine }, StringSplitOptions.RemoveEmptyEntries)) + fileWriter.WriteLine(string.Format("[{3} @ {2:HH:mm:ss}] {0}", line, logName, time, level.ToString().ToUpper())); + } + } +} diff --git a/IPA.Loader/Logging/StandardLogger.cs b/IPA.Loader/Logging/StandardLogger.cs index cdcfcdae..3799f4c7 100644 --- a/IPA.Loader/Logging/StandardLogger.cs +++ b/IPA.Loader/Logging/StandardLogger.cs @@ -48,13 +48,15 @@ namespace IPA.Logging }; private string logName; - private static bool showSourceClass = true; + private static readonly bool showSourceClass = true; /// /// All levels defined by this filter will be sent to loggers. All others will be ignored. /// public static LogLevel PrintFilter { get; set; } = LogLevel.InfoUp; private List printers = new List(defaultPrinters); + private Dictionary children = new Dictionary(); + static StandardLogger() { if (ModPrefs.GetBool("IPA", "PrintDebug", false, true)) @@ -62,6 +64,22 @@ namespace IPA.Logging showSourceClass = ModPrefs.GetBool("IPA", "DebugShowCallSource", false, true); } + private StandardLogger(string mainName, string subName, params LogPrinter[] inherited) + { + logName = $"{mainName}/{subName}"; + + printers = new List(inherited) + { + new PluginSubLogPrinter(mainName, subName) + }; + + if (_logThread == null || !_logThread.IsAlive) + { + _logThread = new Thread(LogThread); + _logThread.Start(); + } + } + internal StandardLogger(string name) { logName = name; @@ -75,6 +93,17 @@ namespace IPA.Logging } } + internal StandardLogger GetChild(string name) + { + if (!children.TryGetValue(name, out StandardLogger chld)) + { + chld = new StandardLogger(logName, name, printers.ToArray()); + children.Add(name, chld); + } + + return chld; + } + /// /// Logs a specific message at a given level. /// @@ -164,4 +193,28 @@ namespace IPA.Logging _logThread.Join(); } } + + /// + /// A class providing extensions for various loggers. + /// + public static class LoggerExtensions + { + /// + /// Gets a child logger, if supported. + /// + /// the parent + /// the name of the child + /// the child logger + public static Logger GetChildLogger(this Logger logger, string name) + { + if (logger is StandardLogger) + { + return (logger as StandardLogger).GetChild(name); + } + else + { + throw new InvalidOperationException(); + } + } + } } diff --git a/IPA.Loader/Updating/Backup/BackupUnit.cs b/IPA.Loader/Updating/Backup/BackupUnit.cs index c5e87d35..71c8dca2 100644 --- a/IPA.Loader/Updating/Backup/BackupUnit.cs +++ b/IPA.Loader/Updating/Backup/BackupUnit.cs @@ -77,7 +77,7 @@ namespace IPA.Updating.Backup if (_Files.Contains(relativePath)) { - Logger.log.Debug($"Skipping backup of {relativePath}"); + Logger.updater.Debug($"Skipping backup of {relativePath}"); return; } @@ -110,7 +110,7 @@ namespace IPA.Updating.Backup { foreach (var relativePath in _Files) { - Logger.log.Debug($"Restoring {relativePath}"); + Logger.updater.Debug($"Restoring {relativePath}"); // Original version var backupFile = new FileInfo(Path.Combine(_BackupPath.FullName, relativePath)); var target = new FileInfo(Path.Combine(Environment.CurrentDirectory, relativePath)); @@ -119,13 +119,13 @@ namespace IPA.Updating.Backup { if (backupFile.Length > 0) { - Logger.log.Debug($" {backupFile.FullName} => {target.FullName}"); + Logger.updater.Debug($" {backupFile.FullName} => {target.FullName}"); target.Directory.Create(); backupFile.CopyTo(target.FullName, true); } else { - Logger.log.Debug($" x {target.FullName}"); + Logger.updater.Debug($" x {target.FullName}"); if (target.Exists) { target.Delete(); @@ -134,7 +134,7 @@ namespace IPA.Updating.Backup } else { - Logger.log.Error("Backup not found!"); + Logger.updater.Error("Backup not found!"); } } } diff --git a/IPA.Loader/Updating/ModsaberML/Updater.cs b/IPA.Loader/Updating/ModsaberML/Updater.cs index 6ce5daab..a7251911 100644 --- a/IPA.Loader/Updating/ModsaberML/Updater.cs +++ b/IPA.Loader/Updating/ModsaberML/Updater.cs @@ -38,7 +38,7 @@ namespace IPA.Updating.ModsaberML } catch (Exception e) { - Logger.log.Error(e); + Logger.updater.Error(e); } } @@ -55,7 +55,7 @@ namespace IPA.Updating.ModsaberML IEnumerator CheckForUpdatesCoroutine() { - Logger.log.Info("Checking for mod updates..."); + Logger.updater.Info("Checking for mod updates..."); var toUpdate = new List(); var GameVersion = new Version(Application.version); @@ -71,20 +71,20 @@ namespace IPA.Updating.ModsaberML if (request.isNetworkError) { - Logger.log.Error("Network error while trying to update mods"); - Logger.log.Error(request.error); + Logger.updater.Error("Network error while trying to update mods"); + Logger.updater.Error(request.error); continue; } if (request.isHttpError) { if (request.responseCode == 404) { - Logger.log.Error($"Mod {plugin.Plugin.Name} not found under name {info.InternalName}"); + Logger.updater.Error($"Mod {plugin.Plugin.Name} not found under name {info.InternalName}"); continue; } - Logger.log.Error($"Server returned an error code while trying to update mod {plugin.Plugin.Name}"); - Logger.log.Error(request.error); + Logger.updater.Error($"Server returned an error code while trying to update mod {plugin.Plugin.Name}"); + Logger.updater.Error(request.error); continue; } @@ -94,23 +94,23 @@ namespace IPA.Updating.ModsaberML try { modRegistry = JsonConvert.DeserializeObject(json); - Logger.log.Debug(modRegistry.ToString()); + Logger.updater.Debug(modRegistry.ToString()); } catch (Exception e) { - Logger.log.Error($"Parse error while trying to update mods"); - Logger.log.Error(e); + Logger.updater.Error($"Parse error while trying to update mods"); + Logger.updater.Error(e); continue; } - Logger.log.Debug($"Found Modsaber.ML registration for {plugin.Plugin.Name} ({info.InternalName})"); - Logger.log.Debug($"Installed version: {info.CurrentVersion}; Latest version: {modRegistry.Version}"); + Logger.updater.Debug($"Found Modsaber.ML registration for {plugin.Plugin.Name} ({info.InternalName})"); + Logger.updater.Debug($"Installed version: {info.CurrentVersion}; Latest version: {modRegistry.Version}"); if (modRegistry.Version > info.CurrentVersion) { - Logger.log.Debug($"{plugin.Plugin.Name} needs an update!"); + Logger.updater.Debug($"{plugin.Plugin.Name} needs an update!"); if (modRegistry.GameVersion == GameVersion) { - Logger.log.Debug($"Queueing update..."); + Logger.updater.Debug($"Queueing update..."); toUpdate.Add(new UpdateStruct { plugin = plugin, @@ -119,13 +119,13 @@ namespace IPA.Updating.ModsaberML } else { - Logger.log.Warn($"Update avaliable for {plugin.Plugin.Name}, but for a different Beat Saber version!"); + Logger.updater.Warn($"Update avaliable for {plugin.Plugin.Name}, but for a different Beat Saber version!"); } } } } - Logger.log.Info($"{toUpdate.Count} mods need updating"); + Logger.updater.Info($"{toUpdate.Count} mods need updating"); if (toUpdate.Count == 0) yield break; @@ -149,19 +149,19 @@ namespace IPA.Updating.ModsaberML protected override void ReceiveContentLength(int contentLength) { Stream.Capacity = contentLength; - Logger.log.Debug($"Got content length: {contentLength}"); + Logger.updater.Debug($"Got content length: {contentLength}"); } protected override void CompleteContent() { - Logger.log.Debug("Download complete"); + Logger.updater.Debug("Download complete"); } protected override bool ReceiveData(byte[] data, int dataLength) { if (data == null || data.Length < 1) { - Logger.log.Debug("CustomWebRequest :: ReceiveData - received a null/empty buffer"); + Logger.updater.Debug("CustomWebRequest :: ReceiveData - received a null/empty buffer"); return false; } @@ -184,7 +184,7 @@ namespace IPA.Updating.ModsaberML private void ExtractPluginAsync(MemoryStream stream, UpdateStruct item, ApiEndpoint.Mod.PlatformFile fileInfo, string tempDirectory) { - Logger.log.Debug($"Extracting ZIP file for {item.plugin.Plugin.Name}"); + Logger.updater.Debug($"Extracting ZIP file for {item.plugin.Plugin.Name}"); var data = stream.GetBuffer(); SHA1 sha = new SHA1CryptoServiceProvider(); @@ -201,12 +201,12 @@ namespace IPA.Updating.ModsaberML using (var zipFile = ZipFile.Read(stream)) { - Logger.log.Debug("Streams opened"); + Logger.updater.Debug("Streams opened"); foreach (var entry in zipFile) { if (entry.IsDirectory) { - Logger.log.Debug($"Creating directory {entry.FileName}"); + Logger.updater.Debug($"Creating directory {entry.FileName}"); Directory.CreateDirectory(Path.Combine(Environment.CurrentDirectory, entry.FileName)); } else @@ -233,7 +233,7 @@ namespace IPA.Updating.ModsaberML else newFiles.Add(targetFile); - Logger.log.Debug($"Extracting file {targetFile.FullName}"); + Logger.updater.Debug($"Extracting file {targetFile.FullName}"); var fstream = targetFile.Create(); ostream.CopyTo(fstream); @@ -266,12 +266,12 @@ namespace IPA.Updating.ModsaberML backup.Delete(); - Logger.log.Debug("Downloader exited"); + Logger.updater.Debug("Downloader exited"); } IEnumerator UpdateModCoroutine(UpdateStruct item, string tempDirectory) { - Logger.log.Debug($"Steam avaliable: {SteamCheck.IsAvailable}"); + Logger.updater.Debug($"Steam avaliable: {SteamCheck.IsAvailable}"); ApiEndpoint.Mod.PlatformFile platformFile; if (SteamCheck.IsAvailable || item.externInfo.Files.Oculus == null) @@ -281,14 +281,14 @@ namespace IPA.Updating.ModsaberML string url = platformFile.DownloadPath; - Logger.log.Debug($"URL = {url}"); + Logger.updater.Debug($"URL = {url}"); const int MaxTries = 3; int maxTries = MaxTries; while (maxTries > 0) { if (maxTries-- != MaxTries) - Logger.log.Info($"Re-trying download..."); + Logger.updater.Info($"Re-trying download..."); using (var stream = new MemoryStream()) using (var request = UnityWebRequest.Get(url)) @@ -297,22 +297,22 @@ namespace IPA.Updating.ModsaberML var dlh = new StreamDownloadHandler(stream); request.downloadHandler = dlh; - Logger.log.Debug("Sending request"); - //Logger.log.Debug(request?.downloadHandler?.ToString() ?? "DLH==NULL"); + Logger.updater.Debug("Sending request"); + //Logger.updater.Debug(request?.downloadHandler?.ToString() ?? "DLH==NULL"); yield return request.SendWebRequest(); - Logger.log.Debug("Download finished"); + Logger.updater.Debug("Download finished"); if (request.isNetworkError) { - Logger.log.Error("Network error while trying to update mod"); - Logger.log.Error(request.error); + Logger.updater.Error("Network error while trying to update mod"); + Logger.updater.Error(request.error); taskTokenSource.Cancel(); continue; } if (request.isHttpError) { - Logger.log.Error($"Server returned an error code while trying to update mod"); - Logger.log.Error(request.error); + Logger.updater.Error($"Server returned an error code while trying to update mod"); + Logger.updater.Error(request.error); taskTokenSource.Cancel(); continue; } @@ -329,8 +329,8 @@ namespace IPA.Updating.ModsaberML if (downloadTask.IsFaulted) { - Logger.log.Error($"Error downloading mod {item.plugin.Plugin.Name}"); - Logger.log.Error(downloadTask.Exception); + Logger.updater.Error($"Error downloading mod {item.plugin.Plugin.Name}"); + Logger.updater.Error(downloadTask.Exception); continue; } @@ -339,9 +339,9 @@ namespace IPA.Updating.ModsaberML } if (maxTries == 0) - Logger.log.Warn($"Plugin download failed {MaxTries} times, not re-trying"); + Logger.updater.Warn($"Plugin download failed {MaxTries} times, not re-trying"); else - Logger.log.Debug("Download complete"); + Logger.updater.Debug("Download complete"); } } }