From 332823b46a85992257fdfc42961fbf79ad50d583 Mon Sep 17 00:00:00 2001 From: Anairkoen Schno Date: Wed, 15 Dec 2021 16:08:34 -0600 Subject: [PATCH] Add Harmony logging interceptor --- IPA.Injector/Injector.cs | 41 +-- IPA.Injector/PermissionFix.cs | 6 +- IPA.Injector/Updates.cs | 30 +- IPA.Loader/Config/ConfigRuntime.cs | 12 +- .../Config/Providers/JsonConfigProvider.cs | 18 +- IPA.Loader/Config/SelfConfig.cs | 2 +- .../GeneratedStoreImpl/Deserialization.cs | 4 +- .../GeneratedStoreImpl/IGeneratedStore.cs | 8 +- .../Stores/GeneratedStoreImpl/MakeCreator.cs | 4 +- .../GeneratedStoreImpl/ObjectStructure.cs | 10 +- .../GeneratedStoreImpl/Serialization.cs | 4 +- .../Stores/GeneratedStoreImpl/Utility.cs | 6 +- IPA.Loader/IPA.Loader.csproj | 4 +- .../JsonConverters/FeaturesFieldConverter.cs | 2 +- .../Loader/Composite/CompositeBSPlugin.cs | 2 +- .../Loader/Composite/CompositeIPAPlugin.cs | 2 +- IPA.Loader/Loader/DisabledConfig.cs | 6 +- IPA.Loader/Loader/Features/DefineFeature.cs | 14 +- IPA.Loader/Loader/LibLoader.cs | 4 +- IPA.Loader/Loader/PluginExecutor.cs | 10 +- IPA.Loader/Loader/PluginLoader.cs | 114 +++---- IPA.Loader/Loader/PluginManager.cs | 38 +-- IPA.Loader/Loader/manifest.json | 2 +- IPA.Loader/Logging/Logger.cs | 28 +- IPA.Loader/Logging/Printers/GZFilePrinter.cs | 314 +++++++++--------- IPA.Loader/Logging/StdoutInterceptor.cs | 64 ++-- IPA.Loader/Utilities/CriticalSection.cs | 2 +- IPA.Loader/Utilities/UnityGame.cs | 18 +- 28 files changed, 398 insertions(+), 371 deletions(-) diff --git a/IPA.Injector/Injector.cs b/IPA.Injector/Injector.cs index edaa9ea2..523e869c 100644 --- a/IPA.Injector/Injector.cs +++ b/IPA.Injector/Injector.cs @@ -63,7 +63,7 @@ namespace IPA.Injector */ #endregion - log.Debug("Initializing logger"); + Default.Debug("Initializing logger"); SelfConfig.ReadCommandLine(Environment.GetCommandLineArgs()); SelfConfig.Load(); @@ -71,14 +71,14 @@ namespace IPA.Injector if (AntiPiracy.IsInvalid(Environment.CurrentDirectory)) { - log.Error("Invalid installation; please buy the game to run BSIPA."); + Default.Error("Invalid installation; please buy the game to run BSIPA."); return; } CriticalSection.Configure(); - injector.Debug("Prepping bootstrapper"); + Logging.Logger.Injector.Debug("Prepping bootstrapper"); // updates backup InstallBootstrapPatch(); @@ -89,7 +89,7 @@ namespace IPA.Injector Updates.InstallPendingUpdates(); - LibLoader.SetupAssemblyFilenames(true); + Loader.LibLoader.SetupAssemblyFilenames(true); pluginAsyncLoadTask = PluginLoader.LoadTask(); permissionFixTask = PermissionFix.FixPermissions(new DirectoryInfo(Environment.CurrentDirectory)); @@ -113,7 +113,7 @@ namespace IPA.Injector { if (loadingDone) return; loadingDone = true; - LibLoader.Configure(); + Loader.LibLoader.Configure(); } private static void InstallHarmonyProtections() @@ -131,13 +131,13 @@ namespace IPA.Injector var dataDir = new DirectoryInfo(managedPath).Parent.Name; var gameName = dataDir.Substring(0, dataDir.Length - 5); - injector.Debug("Finding backup"); + Logging.Logger.Injector.Debug("Finding backup"); var backupPath = Path.Combine(Environment.CurrentDirectory, "IPA", "Backups", gameName); var bkp = BackupManager.FindLatestBackup(backupPath); if (bkp == null) - injector.Warn("No backup found! Was BSIPA installed using the installer?"); + Logging.Logger.Injector.Warn("No backup found! Was BSIPA installed using the installer?"); - injector.Debug("Ensuring patch on UnityEngine.CoreModule exists"); + Logging.Logger.Injector.Debug("Ensuring patch on UnityEngine.CoreModule exists"); #region Insert patch into UnityEngine.CoreModule.dll @@ -173,7 +173,7 @@ namespace IPA.Injector if (application == null) { - injector.Critical("UnityEngine.CoreModule doesn't have a definition for UnityEngine.Camera!" + Logging.Logger.Injector.Critical("UnityEngine.CoreModule doesn't have a definition for UnityEngine.Camera!" + "Nothing to patch to get ourselves into the Unity run cycle!"); goto endPatchCoreModule; } @@ -238,7 +238,7 @@ namespace IPA.Injector endPatchCoreModule: #endregion Insert patch into UnityEngine.CoreModule.dll - injector.Debug("Ensuring game assemblies are virtualized"); + Logging.Logger.Injector.Debug("Ensuring game assemblies are virtualized"); #region Virtualize game assemblies bool isFirst = true; @@ -250,15 +250,15 @@ namespace IPA.Injector try { - injector.Debug($"Virtualizing {name}"); + Logging.Logger.Injector.Debug($"Virtualizing {name}"); using var ascModule = VirtualizedModule.Load(ascPath); ascModule.Virtualize(cAsmName, () => bkp?.Add(ascPath)); } catch (Exception e) { - injector.Error($"Could not virtualize {ascPath}"); + Logging.Logger.Injector.Error($"Could not virtualize {ascPath}"); if (SelfConfig.Debug_.ShowHandledErrorStackTraces_) - injector.Error(e); + Logging.Logger.Injector.Error(e); } #if BeatSaber @@ -266,7 +266,7 @@ namespace IPA.Injector { try { - injector.Debug("Applying anti-yeet patch"); + Logging.Logger.Injector.Debug("Applying anti-yeet patch"); using var ascAsmDef = AssemblyDefinition.ReadAssembly(ascPath, new ReaderParameters { @@ -285,9 +285,9 @@ namespace IPA.Injector } catch (Exception e) { - injector.Warn($"Could not apply anti-yeet patch to {ascPath}"); + Logging.Logger.Injector.Warn($"Could not apply anti-yeet patch to {ascPath}"); if (SelfConfig.Debug_.ShowHandledErrorStackTraces_) - injector.Warn(e); + Logging.Logger.Injector.Warn(e); } } #endif @@ -295,7 +295,7 @@ namespace IPA.Injector #endregion sw.Stop(); - injector.Info($"Installing bootstrapper took {sw.Elapsed}"); + Logging.Logger.Injector.Info($"Installing bootstrapper took {sw.Elapsed}"); } private static bool bootstrapped; @@ -305,7 +305,6 @@ namespace IPA.Injector if (bootstrapped) return; bootstrapped = true; - Application.logMessageReceived += delegate (string condition, string stackTrace, LogType type) { var level = UnityLogRedirector.LogTypeToLevel(type); @@ -313,6 +312,8 @@ namespace IPA.Injector UnityLogProvider.UnityLogger.Log(level, $"{stackTrace}"); }; + ConfigureHarmonyLogging(); + // need to reinit streams singe Unity seems to redirect stdout StdoutInterceptor.RedirectConsole(); @@ -330,8 +331,8 @@ namespace IPA.Injector pluginAsyncLoadTask?.Wait(); permissionFixTask?.Wait(); - log.Debug("Plugins loaded"); - log.Debug(string.Join(", ", PluginLoader.PluginsMetadata.StrJP())); + Default.Debug("Plugins loaded"); + Default.Debug(string.Join(", ", PluginLoader.PluginsMetadata.StrJP())); _ = PluginComponent.Create(); } } diff --git a/IPA.Injector/PermissionFix.cs b/IPA.Injector/PermissionFix.cs index 2cd891b2..152c6435 100644 --- a/IPA.Injector/PermissionFix.cs +++ b/IPA.Injector/PermissionFix.cs @@ -62,11 +62,11 @@ namespace IPA.Injector } catch (Exception e) { - Logger.log.Warn("Error configuring permissions in the game install dir"); - Logger.log.Warn(e); + Logger.Default.Warn("Error configuring permissions in the game install dir"); + Logger.Default.Warn(e); } sw.Stop(); - Logger.log.Info($"Configuring permissions took {sw.Elapsed}"); + Logger.Default.Info($"Configuring permissions took {sw.Elapsed}"); }); } } diff --git a/IPA.Injector/Updates.cs b/IPA.Injector/Updates.cs index bfe9658d..7822e209 100644 --- a/IPA.Injector/Updates.cs +++ b/IPA.Injector/Updates.cs @@ -42,12 +42,12 @@ namespace IPA.Injector var scanResult = AntiMalwareEngine.Engine.ScanFile(new FileInfo(path)); if (scanResult == ScanResult.Detected) { - updater.Error("Scan of BSIPA installer found malware; not updating"); + Updater.Error("Scan of BSIPA installer found malware; not updating"); return; } if (!SelfConfig.AntiMalware_.RunPartialThreatCode_ && scanResult is not ScanResult.KnownSafe and not ScanResult.NotDetected) { - updater.Error("Scan of BSIPA installer returned partial threat; not updating. To allow this, enable AntiMalware.RunPartialThreatCode in the config."); + Updater.Error("Scan of BSIPA installer returned partial threat; not updating. To allow this, enable AntiMalware.RunPartialThreatCode in the config."); return; } @@ -59,7 +59,7 @@ namespace IPA.Injector UseShellExecute = false }); - updater.Info("Updating BSIPA..."); + Updater.Info("Updating BSIPA..."); Environment.Exit(0); } } @@ -70,7 +70,7 @@ namespace IPA.Injector if (!Directory.Exists(pendingDir)) return; // there are pending updates, install - updater.Info("Installing pending updates"); + Updater.Info("Installing pending updates"); var toDelete = Array.Empty(); var delFn = Path.Combine(pendingDir, DeleteFileName); @@ -88,8 +88,8 @@ namespace IPA.Injector } catch (Exception e) { - updater.Error("While trying to install pending updates: Error deleting file marked for deletion"); - updater.Error(e); + Updater.Error("While trying to install pending updates: Error deleting file marked for deletion"); + Updater.Error(e); } } @@ -114,12 +114,12 @@ namespace IPA.Injector } catch (UnauthorizedAccessException e) { - updater.Error(e); + Updater.Error(e); continue; } catch (DirectoryNotFoundException e) { - updater.Error(e); + Updater.Error(e); continue; } @@ -132,7 +132,7 @@ namespace IPA.Injector } catch (FileNotFoundException e) { - updater.Error(e); + Updater.Error(e); } } @@ -153,15 +153,15 @@ namespace IPA.Injector { Utils.CopyAll(new DirectoryInfo(pendingDir), new DirectoryInfo(UnityGame.InstallPath), onCopyException: (e, f) => { - updater.Error($"Error copying file {Utils.GetRelativePath(f.FullName, pendingDir)} from Pending:"); - updater.Error(e); + Updater.Error($"Error copying file {Utils.GetRelativePath(f.FullName, pendingDir)} from Pending:"); + Updater.Error(e); return true; }); } catch (Exception e) { - updater.Error("While trying to install pending updates: Error copying files in"); - updater.Error(e); + Updater.Error("While trying to install pending updates: Error copying files in"); + Updater.Error(e); } try @@ -170,8 +170,8 @@ namespace IPA.Injector } catch (Exception e) { - updater.Error("Something went wrong performing an operation that should never fail!"); - updater.Error(e); + Updater.Error("Something went wrong performing an operation that should never fail!"); + Updater.Error(e); } } } diff --git a/IPA.Loader/Config/ConfigRuntime.cs b/IPA.Loader/Config/ConfigRuntime.cs index d9c4a203..baf5138f 100644 --- a/IPA.Loader/Config/ConfigRuntime.cs +++ b/IPA.Loader/Config/ConfigRuntime.cs @@ -185,8 +185,8 @@ namespace IPA.Config } catch (Exception e) { - Logger.config.Error($"{nameof(IConfigStore)} for {config.File} errored while writing to disk"); - Logger.config.Error(e); + Logger.Config.Error($"{nameof(IConfigStore)} for {config.File} errored while writing to disk"); + Logger.Config.Error(e); } } @@ -209,8 +209,8 @@ namespace IPA.Config } catch (Exception e) { - Logger.config.Error($"{nameof(IConfigStore)} for {config.File} errored while reading from the {nameof(IConfigProvider)}"); - Logger.config.Error(e); + Logger.Config.Error($"{nameof(IConfigStore)} for {config.File} errored while reading from the {nameof(IConfigProvider)}"); + Logger.Config.Error(e); } } @@ -235,8 +235,8 @@ namespace IPA.Config } catch (Exception e) { - Logger.config.Error($"Error waiting for in-memory updates"); - Logger.config.Error(e); + Logger.Config.Error($"Error waiting for in-memory updates"); + Logger.Config.Error(e); Thread.Sleep(TimeSpan.FromSeconds(1)); } diff --git a/IPA.Loader/Config/Providers/JsonConfigProvider.cs b/IPA.Loader/Config/Providers/JsonConfigProvider.cs index 250918cc..dd9c8dfb 100644 --- a/IPA.Loader/Config/Providers/JsonConfigProvider.cs +++ b/IPA.Loader/Config/Providers/JsonConfigProvider.cs @@ -39,8 +39,8 @@ namespace IPA.Config.Providers } catch (Exception e) { - Logger.config.Error($"Error reading JSON file {file.FullName}; ignoring"); - Logger.config.Error(e); + Logger.Config.Error($"Error reading JSON file {file.FullName}; ignoring"); + Logger.Config.Error(e); return Value.Null(); } } @@ -54,19 +54,19 @@ namespace IPA.Config.Providers case JTokenType.Raw: // idk if the parser will normally emit a Raw type, but just to be safe return VisitToValue(JToken.Parse((tok as JRaw).Value as string)); case JTokenType.Undefined: - Logger.config.Warn("Found JTokenType.Undefined"); + Logger.Config.Warn("Found JTokenType.Undefined"); goto case JTokenType.Null; case JTokenType.Bytes: // never used by Newtonsoft - Logger.config.Warn("Found JTokenType.Bytes"); + Logger.Config.Warn("Found JTokenType.Bytes"); goto case JTokenType.Null; case JTokenType.Comment: // never used by Newtonsoft - Logger.config.Warn("Found JTokenType.Comment"); + Logger.Config.Warn("Found JTokenType.Comment"); goto case JTokenType.Null; case JTokenType.Constructor: // never used by Newtonsoft - Logger.config.Warn("Found JTokenType.Constructor"); + Logger.Config.Warn("Found JTokenType.Constructor"); goto case JTokenType.Null; case JTokenType.Property: // never used by Newtonsoft - Logger.config.Warn("Found JTokenType.Property"); + Logger.Config.Warn("Found JTokenType.Property"); goto case JTokenType.Null; case JTokenType.Null: return Value.Null(); @@ -133,8 +133,8 @@ namespace IPA.Config.Providers } catch (Exception e) { - Logger.config.Error($"Error serializing value for {file.FullName}"); - Logger.config.Error(e); + Logger.Config.Error($"Error serializing value for {file.FullName}"); + Logger.Config.Error(e); } } diff --git a/IPA.Loader/Config/SelfConfig.cs b/IPA.Loader/Config/SelfConfig.cs index bc0d2b04..9611c487 100644 --- a/IPA.Loader/Config/SelfConfig.cs +++ b/IPA.Loader/Config/SelfConfig.cs @@ -36,7 +36,7 @@ namespace IPA.Config protected internal virtual void Changed() { - Logger.log.Debug("SelfConfig Changed called"); + Logger.Default.Debug("SelfConfig Changed called"); } public static void ReadCommandLine(string[] args) diff --git a/IPA.Loader/Config/Stores/GeneratedStoreImpl/Deserialization.cs b/IPA.Loader/Config/Stores/GeneratedStoreImpl/Deserialization.cs index ab424717..7f8e44f6 100644 --- a/IPA.Loader/Config/Stores/GeneratedStoreImpl/Deserialization.cs +++ b/IPA.Loader/Config/Stores/GeneratedStoreImpl/Deserialization.cs @@ -102,7 +102,7 @@ namespace IPA.Config.Stores var structure = ReadObjectMembers(targetType); if (!structure.Any()) { - Logger.config.Warn($"Custom value type {targetType.FullName} (when compiling serialization of" + + Logger.Config.Warn($"Custom value type {targetType.FullName} (when compiling serialization of" + $" {member.Name} on {member.Member.DeclaringType.FullName}) has no accessible members"); il.Emit(OpCodes.Pop); il.Emit(OpCodes.Ldloca, resultLocal); @@ -123,7 +123,7 @@ namespace IPA.Config.Stores } else { - Logger.config.Warn($"Implicit conversions to {expected} are not currently implemented"); + Logger.Config.Warn($"Implicit conversions to {expected} are not currently implemented"); il.Emit(OpCodes.Pop); il.Emit(OpCodes.Ldnull); } diff --git a/IPA.Loader/Config/Stores/GeneratedStoreImpl/IGeneratedStore.cs b/IPA.Loader/Config/Stores/GeneratedStoreImpl/IGeneratedStore.cs index dc323833..28620626 100644 --- a/IPA.Loader/Config/Stores/GeneratedStoreImpl/IGeneratedStore.cs +++ b/IPA.Loader/Config/Stores/GeneratedStoreImpl/IGeneratedStore.cs @@ -67,8 +67,8 @@ namespace IPA.Config.Stores } catch (ObjectDisposedException e) { - Logger.config.Error($"ObjectDisposedException while signalling a change for generated store {generated?.GetType()}"); - Logger.config.Error(e); + Logger.Config.Error($"ObjectDisposedException while signalling a change for generated store {generated?.GetType()}"); + Logger.Config.Error(e); } } @@ -174,7 +174,7 @@ namespace IPA.Config.Stores public static void ImplReadFrom(IGeneratedStore s, ConfigProvider provider) => FindImpl(s)?.ReadFrom(provider); public void ReadFrom(ConfigProvider provider) { - Logger.config.Debug($"Generated impl ReadFrom {generated.GetType()}"); + Logger.Config.Debug($"Generated impl ReadFrom {generated.GetType()}"); var values = provider.Load(); //Logger.config.Debug($"Read {values}"); generated.Deserialize(values); @@ -187,7 +187,7 @@ namespace IPA.Config.Stores public static void ImplWriteTo(IGeneratedStore s, ConfigProvider provider) => FindImpl(s)?.WriteTo(provider); public void WriteTo(ConfigProvider provider) { - Logger.config.Debug($"Generated impl WriteTo {generated.GetType()}"); + Logger.Config.Debug($"Generated impl WriteTo {generated.GetType()}"); var values = generated.Serialize(); //Logger.config.Debug($"Serialized {values}"); provider.Store(values); diff --git a/IPA.Loader/Config/Stores/GeneratedStoreImpl/MakeCreator.cs b/IPA.Loader/Config/Stores/GeneratedStoreImpl/MakeCreator.cs index c11af324..001e0393 100644 --- a/IPA.Loader/Config/Stores/GeneratedStoreImpl/MakeCreator.cs +++ b/IPA.Loader/Config/Stores/GeneratedStoreImpl/MakeCreator.cs @@ -53,7 +53,7 @@ namespace IPA.Config.Stores var structure = ReadObjectMembers(type); if (!structure.Any()) - Logger.config.Warn($"Custom type {type.FullName} has no accessible members"); + Logger.Config.Warn($"Custom type {type.FullName} has no accessible members"); #endregion var typeBuilder = Module.DefineType($"{type.FullName}", @@ -135,7 +135,7 @@ namespace IPA.Config.Stores } else { - Logger.log.Critical($"Type '{type.FullName}' implements INotifyPropertyChanged but does not have an accessible " + + Logger.Default.Critical($"Type '{type.FullName}' implements INotifyPropertyChanged but does not have an accessible " + "'RaisePropertyChanged(string)' method, automatic raising of PropertyChanged event is disabled."); } } diff --git a/IPA.Loader/Config/Stores/GeneratedStoreImpl/ObjectStructure.cs b/IPA.Loader/Config/Stores/GeneratedStoreImpl/ObjectStructure.cs index 904ee261..54595d76 100644 --- a/IPA.Loader/Config/Stores/GeneratedStoreImpl/ObjectStructure.cs +++ b/IPA.Loader/Config/Stores/GeneratedStoreImpl/ObjectStructure.cs @@ -85,19 +85,19 @@ namespace IPA.Config.Stores if (member.Converter.GetConstructor(Type.EmptyTypes) == null) { - Logger.config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that is not default-constructible"); + Logger.Config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that is not default-constructible"); goto endConverterAttr; // is there a better control flow structure to do this? } if (member.Converter.ContainsGenericParameters) { - Logger.config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that has unfilled type parameters"); + Logger.Config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that has unfilled type parameters"); goto endConverterAttr; } if (member.Converter.IsInterface || member.Converter.IsAbstract) { - Logger.config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that is not constructible"); + Logger.Config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that is not constructible"); goto endConverterAttr; } @@ -111,13 +111,13 @@ namespace IPA.Config.Stores } catch { - Logger.config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter who's target type could not be determined"); + Logger.Config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter who's target type could not be determined"); goto endConverterAttr; } } if (targetType != member.Type) { - Logger.config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that is not of the member's type"); + Logger.Config.Warn($"{type.FullName}'s member {member.Member.Name} requests a converter that is not of the member's type"); goto endConverterAttr; } diff --git a/IPA.Loader/Config/Stores/GeneratedStoreImpl/Serialization.cs b/IPA.Loader/Config/Stores/GeneratedStoreImpl/Serialization.cs index 9005d4e2..358bef88 100644 --- a/IPA.Loader/Config/Stores/GeneratedStoreImpl/Serialization.cs +++ b/IPA.Loader/Config/Stores/GeneratedStoreImpl/Serialization.cs @@ -125,7 +125,7 @@ namespace IPA.Config.Stores else if (targetType == typeof(List)) { // TODO: impl this (enumerables) - Logger.config.Warn($"Implicit conversions to {targetType} are not currently implemented"); + Logger.Config.Warn($"Implicit conversions to {targetType} are not currently implemented"); il.Emit(OpCodes.Pop); il.Emit(OpCodes.Ldnull); } @@ -168,7 +168,7 @@ namespace IPA.Config.Stores var structure = ReadObjectMembers(memberConversionType); if (!structure.Any()) { - Logger.config.Warn($"Custom value type {memberConversionType.FullName} (when compiling serialization of" + + Logger.Config.Warn($"Custom value type {memberConversionType.FullName} (when compiling serialization of" + $" {member.Name} on {member.Member.DeclaringType.FullName}) has no accessible members"); il.Emit(OpCodes.Pop); } diff --git a/IPA.Loader/Config/Stores/GeneratedStoreImpl/Utility.cs b/IPA.Loader/Config/Stores/GeneratedStoreImpl/Utility.cs index 216e0664..f1a9ddb6 100644 --- a/IPA.Loader/Config/Stores/GeneratedStoreImpl/Utility.cs +++ b/IPA.Loader/Config/Stores/GeneratedStoreImpl/Utility.cs @@ -25,17 +25,17 @@ namespace IPA.Config.Stores private static readonly MethodInfo LogErrorMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogError), BindingFlags.NonPublic | BindingFlags.Static); internal static void LogError(Type? expected, Type? found, string message) { - Logger.config.Notice($"{message}{(expected == null ? "" : $" (expected {expected}, found {found?.ToString() ?? "null"})")}"); + Logger.Config.Notice($"{message}{(expected == null ? "" : $" (expected {expected}, found {found?.ToString() ?? "null"})")}"); } private static readonly MethodInfo LogWarningMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogWarning), BindingFlags.NonPublic | BindingFlags.Static); internal static void LogWarning(string message) { - Logger.config.Warn(message); + Logger.Config.Warn(message); } private static readonly MethodInfo LogWarningExceptionMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogWarningException), BindingFlags.NonPublic | BindingFlags.Static); internal static void LogWarningException(Exception exception) { - Logger.config.Warn(exception); + Logger.Config.Warn(exception); } #endregion diff --git a/IPA.Loader/IPA.Loader.csproj b/IPA.Loader/IPA.Loader.csproj index d64f8285..99da2ecc 100644 --- a/IPA.Loader/IPA.Loader.csproj +++ b/IPA.Loader/IPA.Loader.csproj @@ -57,8 +57,8 @@ --> - - + + diff --git a/IPA.Loader/JsonConverters/FeaturesFieldConverter.cs b/IPA.Loader/JsonConverters/FeaturesFieldConverter.cs index c5f00090..d17c5781 100644 --- a/IPA.Loader/JsonConverters/FeaturesFieldConverter.cs +++ b/IPA.Loader/JsonConverters/FeaturesFieldConverter.cs @@ -22,7 +22,7 @@ namespace IPA.JsonConverters if (reader.TokenType == JsonToken.StartArray) { _ = serializer.Deserialize(reader); - Logger.features.Warn("Encountered old features used. They no longer do anything, please move to the new format."); + Logger.Features.Warn("Encountered old features used. They no longer do anything, please move to the new format."); return existingValue; } diff --git a/IPA.Loader/Loader/Composite/CompositeBSPlugin.cs b/IPA.Loader/Loader/Composite/CompositeBSPlugin.cs index 386443d9..883ad7c4 100644 --- a/IPA.Loader/Loader/Composite/CompositeBSPlugin.cs +++ b/IPA.Loader/Loader/Composite/CompositeBSPlugin.cs @@ -27,7 +27,7 @@ namespace IPA.Loader.Composite } catch (Exception ex) { - Logger.log.Error($"{plugin.Metadata.Name} {method}: {ex}"); + Logger.Default.Error($"{plugin.Metadata.Name} {method}: {ex}"); } } } diff --git a/IPA.Loader/Loader/Composite/CompositeIPAPlugin.cs b/IPA.Loader/Loader/Composite/CompositeIPAPlugin.cs index 37beeb6a..9a66a3b7 100644 --- a/IPA.Loader/Loader/Composite/CompositeIPAPlugin.cs +++ b/IPA.Loader/Loader/Composite/CompositeIPAPlugin.cs @@ -38,7 +38,7 @@ namespace IPA.Loader.Composite } catch (Exception ex) { - Logger.log.Error($"{plugin.Name} {member}: {ex}"); + Logger.Default.Error($"{plugin.Name} {member}: {ex}"); } } } diff --git a/IPA.Loader/Loader/DisabledConfig.cs b/IPA.Loader/Loader/DisabledConfig.cs index a8adcfe1..3d4aad77 100644 --- a/IPA.Loader/Loader/DisabledConfig.cs +++ b/IPA.Loader/Loader/DisabledConfig.cs @@ -86,13 +86,13 @@ namespace IPA.Loader try { if (transaction.WillNeedRestart) - Logger.loader.Warn("Runtime disabled config reload will need game restart to apply"); + Logger.Loader.Warn("Runtime disabled config reload will need game restart to apply"); return transaction.Commit().ContinueWith(t => { if (t.IsFaulted) { - Logger.loader.Error("Error changing disabled plugins"); - Logger.loader.Error(t.Exception); + Logger.Loader.Error("Error changing disabled plugins"); + Logger.Loader.Error(t.Exception); } }); } diff --git a/IPA.Loader/Loader/Features/DefineFeature.cs b/IPA.Loader/Loader/Features/DefineFeature.cs index 6590df1a..f4d628f6 100644 --- a/IPA.Loader/Loader/Features/DefineFeature.cs +++ b/IPA.Loader/Loader/Features/DefineFeature.cs @@ -25,7 +25,7 @@ namespace IPA.Loader.Features protected override bool Initialize(PluginMetadata meta, JObject featureData) { - Logger.features.Debug("Executing DefineFeature Init"); + Logger.Features.Debug("Executing DefineFeature Init"); try { @@ -43,7 +43,7 @@ namespace IPA.Loader.Features public override void BeforeInit(PluginMetadata meta) { - Logger.features.Debug("Executing DefineFeature AfterInit"); + Logger.Features.Debug("Executing DefineFeature AfterInit"); Type type; try @@ -52,7 +52,7 @@ namespace IPA.Loader.Features } catch (ArgumentException) { - Logger.features.Error($"Invalid type name {data.TypeName}"); + Logger.Features.Error($"Invalid type name {data.TypeName}"); return; } catch (Exception e) when (e is FileNotFoundException or FileLoadException or BadImageFormatException) @@ -72,13 +72,13 @@ namespace IPA.Loader.Features break; } - Logger.features.Error($"Could not find {filename} while loading type"); + Logger.Features.Error($"Could not find {filename} while loading type"); return; } if (type == null) { - Logger.features.Error($"Invalid type name {data.TypeName}"); + Logger.Features.Error($"Invalid type name {data.TypeName}"); return; } @@ -90,12 +90,12 @@ namespace IPA.Loader.Features return; } - Logger.features.Error($"Feature with name {data.Name} already exists"); + Logger.Features.Error($"Feature with name {data.Name} already exists"); return; } catch (ArgumentException) { - Logger.features.Error($"{type.FullName} not a subclass of {nameof(Feature)}"); + Logger.Features.Error($"{type.FullName} not a subclass of {nameof(Feature)}"); return; } } diff --git a/IPA.Loader/Loader/LibLoader.cs b/IPA.Loader/Loader/LibLoader.cs index 83b5d49d..49359e96 100644 --- a/IPA.Loader/Loader/LibLoader.cs +++ b/IPA.Loader/Loader/LibLoader.cs @@ -171,8 +171,8 @@ namespace IPA.Loader Console.WriteLine($"[{lvl}] {message}"); } - private static void AssemblyLibLoaderCallLogger(Logger.Level lvl, string message) => Logger.libLoader.Log(lvl, message); - private static void AssemblyLibLoaderCallLogger(Logger.Level lvl, Exception message) => Logger.libLoader.Log(lvl, message); + private static void AssemblyLibLoaderCallLogger(Logger.Level lvl, string message) => Logger.LibLoader.Log(lvl, message); + private static void AssemblyLibLoaderCallLogger(Logger.Level lvl, Exception message) => Logger.LibLoader.Log(lvl, message); // https://docs.microsoft.com/en-us/dotnet/csharp/programming-guide/file-system/how-to-iterate-through-a-directory-tree private static IEnumerable TraverseTree(string root, Func? dirValidator = null) diff --git a/IPA.Loader/Loader/PluginExecutor.cs b/IPA.Loader/Loader/PluginExecutor.cs index 8073c4fd..307d4557 100644 --- a/IPA.Loader/Loader/PluginExecutor.cs +++ b/IPA.Loader/Loader/PluginExecutor.cs @@ -80,7 +80,7 @@ namespace IPA.Loader .OrderByDescending(t => t.c.GetParameters().Length) .Select(t => t.c).ToArray(); if (ctors.Length > 1) - Logger.loader.Warn($"Plugin {name} has multiple [Init] constructors. Picking the one with the most parameters."); + Logger.Loader.Warn($"Plugin {name} has multiple [Init] constructors. Picking the one with the most parameters."); bool usingDefaultCtor = false; var ctor = ctors.FirstOrDefault(); @@ -131,7 +131,7 @@ namespace IPA.Loader if (enableMethods.Length == 0) { if (!noEnableDisable) - Logger.loader.Notice($"Plugin {name} has no methods marked [OnStart] or [OnEnable]. Is this intentional?"); + Logger.Loader.Notice($"Plugin {name} has no methods marked [OnStart] or [OnEnable]. Is this intentional?"); return o => { }; } @@ -140,7 +140,7 @@ namespace IPA.Loader if (m.GetParameters().Length > 0) throw new InvalidOperationException($"Method {m} on {type.FullName} is marked [OnStart] or [OnEnable] and has parameters."); if (m.ReturnType != typeof(void)) - Logger.loader.Warn($"Method {m} on {type.FullName} is marked [OnStart] or [OnEnable] and returns a value. It will be ignored."); + Logger.Loader.Warn($"Method {m} on {type.FullName} is marked [OnStart] or [OnEnable] and returns a value. It will be ignored."); } var objParam = Expression.Parameter(typeof(object), "obj"); @@ -164,7 +164,7 @@ namespace IPA.Loader if (disableMethods.Length == 0) { if (!noEnableDisable) - Logger.loader.Notice($"Plugin {name} has no methods marked [OnExit] or [OnDisable]. Is this intentional?"); + Logger.Loader.Notice($"Plugin {name} has no methods marked [OnExit] or [OnDisable]. Is this intentional?"); return o => TaskEx.WhenAll(); } @@ -182,7 +182,7 @@ namespace IPA.Loader continue; } else - Logger.loader.Warn($"Method {m} on {type.FullName} is marked [OnExit] or [OnDisable] and returns a non-Task value. It will be ignored."); + Logger.Loader.Warn($"Method {m} on {type.FullName} is marked [OnExit] or [OnDisable] and returns a non-Task value. It will be ignored."); } nonTaskMethods.Add(m); diff --git a/IPA.Loader/Loader/PluginLoader.cs b/IPA.Loader/Loader/PluginLoader.cs index e217ab43..10a5eae6 100644 --- a/IPA.Loader/Loader/PluginLoader.cs +++ b/IPA.Loader/Loader/PluginLoader.cs @@ -50,7 +50,7 @@ namespace IPA.Loader LoadMetadata(); sw.Stop(); - Logger.loader.Info($"Loading metadata took {sw.Elapsed}"); + Logger.Loader.Info($"Loading metadata took {sw.Elapsed}"); sw.Reset(); sw.Start(); @@ -60,7 +60,7 @@ namespace IPA.Loader DoOrderResolution(); sw.Stop(); - Logger.loader.Info($"Calculating load order took {sw.Elapsed}"); + Logger.Loader.Info($"Calculating load order took {sw.Elapsed}"); }); internal static void YeetIfNeeded() @@ -115,8 +115,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Critical("Error loading own manifest"); - Logger.loader.Critical(e); + Logger.Loader.Critical("Error loading own manifest"); + Logger.Loader.Critical(e); } using var resolver = new CecilLibLoader(); @@ -135,12 +135,12 @@ namespace IPA.Loader var scanResult = AntiMalwareEngine.Engine.ScanFile(metadata.File); if (scanResult is ScanResult.Detected) { - Logger.loader.Warn($"Scan of {plugin} found malware; not loading"); + Logger.Loader.Warn($"Scan of {plugin} found malware; not loading"); continue; } if (!SelfConfig.AntiMalware_.RunPartialThreatCode_ && scanResult is not ScanResult.KnownSafe and not ScanResult.NotDetected) { - Logger.loader.Warn($"Scan of {plugin} found partial threat; not loading. To load this, set AntiMalware.RunPartialThreatCode in the config."); + Logger.Loader.Warn($"Scan of {plugin} found partial threat; not loading. To load this, set AntiMalware.RunPartialThreatCode in the config."); continue; } @@ -175,14 +175,14 @@ namespace IPA.Loader #if DIRE_LOADER_WARNINGS Logger.loader.Error($"Could not find manifest.json for {Path.GetFileName(plugin)}"); #else - Logger.loader.Notice($"No manifest.json in {Path.GetFileName(plugin)}"); + Logger.Loader.Notice($"No manifest.json in {Path.GetFileName(plugin)}"); #endif continue; } if (pluginManifest.Id == null) { - Logger.loader.Warn($"Plugin '{pluginManifest.Name}' does not have a listed ID, using name"); + Logger.Loader.Warn($"Plugin '{pluginManifest.Name}' does not have a listed ID, using name"); pluginManifest.Id = pluginManifest.Name; } @@ -199,20 +199,20 @@ namespace IPA.Loader if (!attr.HasConstructorArguments) { - Logger.loader.Warn($"Attribute plugin found in {type.FullName}, but attribute has no arguments"); + Logger.Loader.Warn($"Attribute plugin found in {type.FullName}, but attribute has no arguments"); return false; } var args = attr.ConstructorArguments; if (args.Count != 1) { - Logger.loader.Warn($"Attribute plugin found in {type.FullName}, but attribute has unexpected number of arguments"); + Logger.Loader.Warn($"Attribute plugin found in {type.FullName}, but attribute has unexpected number of arguments"); return false; } var rtOptionsArg = args[0]; if (rtOptionsArg.Type.FullName != typeof(RuntimeOptions).FullName) { - Logger.loader.Warn($"Attribute plugin found in {type.FullName}, but first argument is of unexpected type {rtOptionsArg.Type.FullName}"); + Logger.Loader.Warn($"Attribute plugin found in {type.FullName}, but first argument is of unexpected type {rtOptionsArg.Type.FullName}"); return false; } @@ -248,17 +248,17 @@ namespace IPA.Loader if (metadata.PluginType == null) { - Logger.loader.Error($"No plugin found in the manifest {(hint != null ? $"hint path ({hint}) or " : "")}namespace ({pluginNs}) in {Path.GetFileName(plugin)}"); + Logger.Loader.Error($"No plugin found in the manifest {(hint != null ? $"hint path ({hint}) or " : "")}namespace ({pluginNs}) in {Path.GetFileName(plugin)}"); continue; } - Logger.loader.Debug($"Adding info for {Path.GetFileName(plugin)}"); + Logger.Loader.Debug($"Adding info for {Path.GetFileName(plugin)}"); PluginsMetadata.Add(metadata); } catch (Exception e) { - Logger.loader.Error($"Could not load data for plugin {Path.GetFileName(plugin)}"); - Logger.loader.Error(e); + Logger.Loader.Error($"Could not load data for plugin {Path.GetFileName(plugin)}"); + Logger.Loader.Error(e); ignoredPlugins.Add(metadata, new IgnoreReason(Reason.Error) { ReasonText = "An error occurred loading the data", @@ -283,16 +283,16 @@ namespace IPA.Loader metadata.Manifest = JsonConvert.DeserializeObject(File.ReadAllText(manifest)); if (metadata.Manifest.Files.Length < 1) - Logger.loader.Warn($"Bare manifest {Path.GetFileName(manifest)} does not declare any files. " + + Logger.Loader.Warn($"Bare manifest {Path.GetFileName(manifest)} does not declare any files. " + $"Dependency resolution and verification cannot be completed."); - Logger.loader.Debug($"Adding info for bare manifest {Path.GetFileName(manifest)}"); + Logger.Loader.Debug($"Adding info for bare manifest {Path.GetFileName(manifest)}"); PluginsMetadata.Add(metadata); } catch (Exception e) { - Logger.loader.Error($"Could not load data for bare manifest {Path.GetFileName(manifest)}"); - Logger.loader.Error(e); + Logger.Loader.Error($"Could not load data for bare manifest {Path.GetFileName(manifest)}"); + Logger.Loader.Error(e); } } @@ -304,7 +304,7 @@ namespace IPA.Loader { if (meta.IsBare) { - Logger.loader.Warn($"Bare manifest cannot specify description file"); + Logger.Loader.Warn($"Bare manifest cannot specify description file"); meta.Manifest.Description = string.Join("\n", lines.Skip(1).StrJP()); // ignore first line continue; } @@ -319,7 +319,7 @@ namespace IPA.Loader .FirstOrDefault(r => r.Name == name); if (resc == null) { - Logger.loader.Warn($"Could not find description file for plugin {meta.Name} ({name}); ignoring include"); + Logger.Loader.Warn($"Could not find description file for plugin {meta.Name} ({name}); ignoring include"); meta.Manifest.Description = string.Join("\n", lines.Skip(1).StrJP()); // ignore first line continue; } @@ -492,14 +492,14 @@ namespace IPA.Loader { #if DEBUG // print starting order - Logger.loader.Debug(string.Join(", ", PluginsMetadata.StrJP())); + Logger.Loader.Debug(string.Join(", ", PluginsMetadata.StrJP())); #endif PluginsMetadata.Sort((a, b) => b.HVersion.CompareTo(a.HVersion)); #if DEBUG // print base resolution order - Logger.loader.Debug(string.Join(", ", PluginsMetadata.StrJP())); + Logger.Loader.Debug(string.Join(", ", PluginsMetadata.StrJP())); #endif var metadataCache = new Dictionary(PluginsMetadata.Count); @@ -526,7 +526,7 @@ namespace IPA.Loader } else { - Logger.loader.Warn($"Found duplicates of {meta.Id}, using newest"); + Logger.Loader.Warn($"Found duplicates of {meta.Id}, using newest"); ignoredPlugins.Add(meta, new(Reason.Duplicate) { ReasonText = $"Duplicate entry of same ID ({meta.Id})", @@ -585,21 +585,21 @@ namespace IPA.Loader meta = null; disabled = false; ignored = true; - Logger.loader.Trace($"Trying to resolve plugin '{id}' partial:{partial}"); + Logger.Loader.Trace($"Trying to resolve plugin '{id}' partial:{partial}"); if (loadedPlugins.TryGetValue(id, out var foundMeta)) { meta = foundMeta.Meta; disabled = foundMeta.Disabled; ignored = foundMeta.Ignored; - Logger.loader.Trace($"- Found already processed"); + Logger.Loader.Trace($"- Found already processed"); return true; } if (metadataCache!.TryGetValue(id, out var plugin)) { - Logger.loader.Trace($"- In metadata cache"); + Logger.Loader.Trace($"- In metadata cache"); if (partial) { - Logger.loader.Trace($" - but requested in a partial lookup"); + Logger.Loader.Trace($" - but requested in a partial lookup"); return false; } @@ -616,8 +616,8 @@ namespace IPA.Loader { if (e is not DependencyResolutionLoopException) { - Logger.loader.Error($"While performing load order resolution for {id}:"); - Logger.loader.Error(e); + Logger.Loader.Error($"While performing load order resolution for {id}:"); + Logger.Loader.Error(e); } if (!ignored) @@ -635,23 +635,23 @@ namespace IPA.Loader if (!loadedPlugins.ContainsKey(id)) { // this condition is specifically for when we fail resolution because of a graph loop - Logger.loader.Trace($"- '{id}' resolved as ignored:{ignored},disabled:{disabled}"); + Logger.Loader.Trace($"- '{id}' resolved as ignored:{ignored},disabled:{disabled}"); loadedPlugins.Add(id, (plugin.Meta, disabled, ignored)); } return true; } - Logger.loader.Trace($"- Not found"); + Logger.Loader.Trace($"- Not found"); return false; } void Resolve(PluginMetadata plugin, ref bool disabled, out bool ignored) { - Logger.loader.Trace($">Resolving '{plugin.Name}'"); + Logger.Loader.Trace($">Resolving '{plugin.Name}'"); // first we need to check for loops in the resolution graph to prevent stack overflows if (isProcessing.Contains(plugin)) { - Logger.loader.Error($"Loop detected while processing '{plugin.Name}'; flagging as ignored"); + Logger.Loader.Error($"Loop detected while processing '{plugin.Name}'; flagging as ignored"); throw new DependencyResolutionLoopException(); } @@ -671,7 +671,7 @@ namespace IPA.Loader { ReasonText = $"File {Utils.GetRelativePath(file.FullName, UnityGame.InstallPath)} does not exist" }); - Logger.loader.Warn($"File {Utils.GetRelativePath(file.FullName, UnityGame.InstallPath)}" + + Logger.Loader.Warn($"File {Utils.GetRelativePath(file.FullName, UnityGame.InstallPath)}" + $" (declared by '{plugin.Name}') does not exist! Mod installation is incomplete, not loading it."); ignored = true; return; @@ -687,7 +687,7 @@ namespace IPA.Loader if (!TryResolveId(id, out var depMeta, out var depDisabled, out var depIgnored) || !range.Matches(depMeta.HVersion)) { - Logger.loader.Warn($"'{plugin.Id}' is missing dependency '{id}@{range}'; ignoring"); + Logger.Loader.Warn($"'{plugin.Id}' is missing dependency '{id}@{range}'; ignoring"); ignoredPlugins.Add(plugin, new(Reason.Dependency) { ReasonText = $"Dependency '{id}@{range}' not found", @@ -698,7 +698,7 @@ namespace IPA.Loader // make a point to propagate ignored if (depIgnored) { - Logger.loader.Warn($"Dependency '{id}' for '{plugin.Id}' previously ignored; ignoring '{plugin.Id}'"); + Logger.Loader.Warn($"Dependency '{id}' for '{plugin.Id}' previously ignored; ignoring '{plugin.Id}'"); ignoredPlugins.Add(plugin, new(Reason.Dependency) { ReasonText = $"Dependency '{id}' ignored", @@ -710,7 +710,7 @@ namespace IPA.Loader // make a point to propagate disabled if (depDisabled) { - Logger.loader.Warn($"Dependency '{id}' for '{plugin.Id}' disabled; disabling"); + Logger.Loader.Warn($"Dependency '{id}' for '{plugin.Id}' disabled; disabling"); disabledPlugins!.Add(plugin); _ = disabledIds!.Add(plugin.Id); disabled = true; @@ -723,7 +723,7 @@ namespace IPA.Loader // make sure the plugin depends on the loader (assuming it actually needs to) if (!dependsOnSelf && !plugin.IsSelf && !plugin.IsBare) { - Logger.loader.Warn($"Plugin '{plugin.Id}' does not depend on any particular loader version; assuming its incompatible"); + Logger.Loader.Warn($"Plugin '{plugin.Id}' does not depend on any particular loader version; assuming its incompatible"); ignoredPlugins.Add(plugin, new(Reason.Dependency) { ReasonText = "Does not depend on any loader version, so it is assumed to be incompatible", @@ -760,14 +760,14 @@ namespace IPA.Loader // after we handle dependencies and loadafters, then check conflicts foreach (var (id, range) in plugin.Manifest.Conflicts) { - Logger.loader.Trace($">- Checking conflict '{id}' {range}"); + Logger.Loader.Trace($">- Checking conflict '{id}' {range}"); // this lookup must be partial to prevent loadBefore/conflictsWith from creating a recursion loop if (TryResolveId(id, out var meta, out var conflDisabled, out var conflIgnored, partial: true) && range.Matches(meta.HVersion) && !conflIgnored && !conflDisabled) // the conflict is only *actually* a problem if it is both not ignored and not disabled { - Logger.loader.Warn($"Plugin '{plugin.Id}' conflicts with {meta.Id}@{meta.HVersion}; ignoring '{plugin.Id}'"); + Logger.Loader.Warn($"Plugin '{plugin.Id}' conflicts with {meta.Id}@{meta.HVersion}; ignoring '{plugin.Id}'"); ignoredPlugins.Add(plugin, new(Reason.Conflict) { ReasonText = $"Conflicts with {meta.Id}@{meta.HVersion}", @@ -783,13 +783,13 @@ namespace IPA.Loader if (!ignoredPlugins.ContainsKey(plugin)) { // we can now load the current plugin - Logger.loader.Trace($"->'{plugin.Name}' loads here"); + Logger.Loader.Trace($"->'{plugin.Name}' loads here"); outputOrder!.Add(plugin); } // loadbefores have already been preprocessed into loadafters - Logger.loader.Trace($">Processed '{plugin.Name}'"); + Logger.Loader.Trace($">Processed '{plugin.Name}'"); } // run TryResolveId over every plugin, which recursively calculates load order @@ -817,7 +817,7 @@ namespace IPA.Loader { // this is a DefineFeature, so we want to initialize it early if (!feature.TryCreate(out var inst)) { - Logger.features.Error($"Error evaluating {feature.Name}: {inst.InvalidMessage}"); + Logger.Features.Error($"Error evaluating {feature.Name}: {inst.InvalidMessage}"); } else { @@ -850,7 +850,7 @@ namespace IPA.Loader } else { - Logger.features.Warn($"No such feature {feature.Name}"); + Logger.Features.Warn($"No such feature {feature.Name}"); } } } @@ -889,7 +889,7 @@ namespace IPA.Loader internal static PluginExecutor? InitPlugin(PluginMetadata meta, IEnumerable alreadyLoaded) { if (meta.Manifest.GameVersion is { } gv && gv != UnityGame.GameVersion) - Logger.loader.Warn($"Mod {meta.Name} developed for game version {gv}, so it may not work properly."); + Logger.Loader.Warn($"Mod {meta.Name} developed for game version {gv}, so it may not work properly."); if (meta.IsSelf) return new PluginExecutor(meta, PluginExecutor.Special.Self); @@ -932,8 +932,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Error($"Error creating executor for {meta.Name}"); - Logger.loader.Error(e); + Logger.Loader.Error($"Error creating executor for {meta.Name}"); + Logger.Loader.Error(e); return null; } @@ -945,8 +945,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Critical($"Feature errored in {nameof(Feature.BeforeInit)}:"); - Logger.loader.Critical(e); + Logger.Loader.Critical($"Feature errored in {nameof(Feature.BeforeInit)}:"); + Logger.Loader.Critical(e); } } @@ -956,8 +956,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Error($"Could not init plugin {meta.Name}"); - Logger.loader.Error(e); + Logger.Loader.Error($"Could not init plugin {meta.Name}"); + Logger.Loader.Error(e); ignoredPlugins.Add(meta, new IgnoreReason(Reason.Error) { ReasonText = "Error occurred while initializing", @@ -971,7 +971,7 @@ namespace IPA.Loader { if (!feature.TryCreate(out var inst)) { - Logger.features.Warn($"Could not create instance of feature {feature.Name}: {inst.InvalidMessage}"); + Logger.Features.Warn($"Could not create instance of feature {feature.Name}: {inst.InvalidMessage}"); } else { @@ -988,8 +988,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Critical($"Feature errored in {nameof(Feature.AfterInit)}:"); - Logger.loader.Critical(e); + Logger.Loader.Critical($"Feature errored in {nameof(Feature.AfterInit)}:"); + Logger.Loader.Critical(e); } return exec; @@ -1016,8 +1016,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.log.Critical($"Uncaught exception while loading plugin {meta.Name}:"); - Logger.log.Critical(e); + Logger.Default.Critical($"Uncaught exception while loading plugin {meta.Name}:"); + Logger.Default.Critical(e); } } diff --git a/IPA.Loader/Loader/PluginManager.cs b/IPA.Loader/Loader/PluginManager.cs index 06239cd4..3112c419 100644 --- a/IPA.Loader/Loader/PluginManager.cs +++ b/IPA.Loader/Loader/PluginManager.cs @@ -153,8 +153,8 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Error($"Error while enabling {meta.Id}:"); - Logger.loader.Error(e); + Logger.Loader.Error($"Error while enabling {meta.Id}:"); + Logger.Loader.Error(e); // this should still be considered enabled, hence its position } } @@ -215,7 +215,7 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.Critical($"Feature errored in {nameof(Feature.AfterDisable)}: {e}"); + Logger.Loader.Critical($"Feature errored in {nameof(Feature.AfterDisable)}: {e}"); } } }, UnityMainThreadTaskScheduler.Default); @@ -442,26 +442,26 @@ namespace IPA.Loader sw.Stop(); - Logger.log.Info(exeName); - Logger.log.Info($"Running on Unity {Application.unityVersion}"); - Logger.log.Info($"Game version {UnityGame.GameVersion}"); - Logger.log.Info("-----------------------------"); - Logger.log.Info($"Loading plugins from {Utils.GetRelativePath(pluginDirectory, Environment.CurrentDirectory)} and found {_bsPlugins.Count + _ipaPlugins.Count}"); - Logger.log.Info("-----------------------------"); + Logger.Default.Info(exeName); + Logger.Default.Info($"Running on Unity {Application.unityVersion}"); + Logger.Default.Info($"Game version {UnityGame.GameVersion}"); + Logger.Default.Info("-----------------------------"); + Logger.Default.Info($"Loading plugins from {Utils.GetRelativePath(pluginDirectory, Environment.CurrentDirectory)} and found {_bsPlugins.Count + _ipaPlugins.Count}"); + Logger.Default.Info("-----------------------------"); foreach (var plugin in _bsPlugins) { - Logger.log.Info($"{plugin.Metadata.Name} ({plugin.Metadata.Id}): {plugin.Metadata.Version}"); + Logger.Default.Info($"{plugin.Metadata.Name} ({plugin.Metadata.Id}): {plugin.Metadata.Version}"); } - Logger.log.Info("-----------------------------"); + Logger.Default.Info("-----------------------------"); if (_ipaPlugins.Count > 0) { foreach (var plugin in _ipaPlugins) { - Logger.log.Info($"{plugin.Name}: {plugin.Version}"); + Logger.Default.Info($"{plugin.Name}: {plugin.Version}"); } - Logger.log.Info("-----------------------------"); + Logger.Default.Info("-----------------------------"); } - Logger.log.Info($"Initializing plugins took {sw.Elapsed}"); + Logger.Default.Info($"Initializing plugins took {sw.Elapsed}"); } private static IEnumerable LoadPluginsFromFile(string file) @@ -482,7 +482,7 @@ namespace IPA.Loader } catch (Exception e) { - Logger.loader.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}"); } } @@ -506,13 +506,13 @@ namespace IPA.Loader } catch (ReflectionTypeLoadException e) { - Logger.loader.Error($"Could not load the following types from {Path.GetFileName(file)}:"); - Logger.loader.Error($" {string.Join("\n ", e.LoaderExceptions?.Select(e1 => e1?.Message).StrJP() ?? Array.Empty())}"); + Logger.Loader.Error($"Could not load the following types from {Path.GetFileName(file)}:"); + Logger.Loader.Error($" {string.Join("\n ", e.LoaderExceptions?.Select(e1 => e1?.Message).StrJP() ?? Array.Empty())}"); } catch (Exception e) { - Logger.loader.Error($"Could not load {Path.GetFileName(file)}!"); - Logger.loader.Error(e); + Logger.Loader.Error($"Could not load {Path.GetFileName(file)}!"); + Logger.Loader.Error(e); } return ipaPlugins; diff --git a/IPA.Loader/Loader/manifest.json b/IPA.Loader/Loader/manifest.json index 2ad8a6cc..9a853f74 100644 --- a/IPA.Loader/Loader/manifest.json +++ b/IPA.Loader/Loader/manifest.json @@ -7,7 +7,7 @@ ], "id": "BSIPA", "name": "Beat Saber IPA", - "version": "4.2.1-pre.2", + "version": "4.2.1-pre.3", "icon": "IPA.icon_white.png", "features": { "IPA.DefineFeature": [ diff --git a/IPA.Loader/Logging/Logger.cs b/IPA.Loader/Logging/Logger.cs index d89f4f50..6a37bdca 100644 --- a/IPA.Loader/Logging/Logger.cs +++ b/IPA.Loader/Logging/Logger.cs @@ -1,6 +1,5 @@ -using System; - -// ReSharper disable InconsistentNaming +#nullable enable +using System; namespace IPA.Logging { @@ -9,9 +8,9 @@ namespace IPA.Logging /// public abstract class Logger { - private static Logger _log; + private static Logger? _log; - internal static Logger log + internal static Logger Default { get { @@ -21,7 +20,7 @@ namespace IPA.Logging } } - private static StandardLogger _stdout; + private static StandardLogger? _stdout; internal static StandardLogger stdout { @@ -33,13 +32,16 @@ namespace IPA.Logging } } - internal static Logger AntiMalware => log.GetChildLogger("AntiMalware"); - internal static Logger updater => log.GetChildLogger("Updater"); - internal static Logger libLoader => log.GetChildLogger("LibraryLoader"); - internal static Logger injector => log.GetChildLogger("Injector"); - internal static Logger loader => log.GetChildLogger("Loader"); - internal static Logger features => loader.GetChildLogger("Features"); - internal static Logger config => log.GetChildLogger("Config"); + private static StandardLogger? lazyHarmony; + internal static StandardLogger Harmony => lazyHarmony ??= new StandardLogger("Harmony"); + + internal static Logger AntiMalware => Default.GetChildLogger("AntiMalware"); + internal static Logger Updater => Default.GetChildLogger("Updater"); + internal static Logger LibLoader => Default.GetChildLogger("LibraryLoader"); + internal static Logger Injector => Default.GetChildLogger("Injector"); + internal static Logger Loader => Default.GetChildLogger("Loader"); + internal static Logger Features => Loader.GetChildLogger("Features"); + internal static Logger Config => Default.GetChildLogger("Config"); internal static bool LogCreated => _log != null; /// diff --git a/IPA.Loader/Logging/Printers/GZFilePrinter.cs b/IPA.Loader/Logging/Printers/GZFilePrinter.cs index 58d50053..ebd9b5a2 100644 --- a/IPA.Loader/Logging/Printers/GZFilePrinter.cs +++ b/IPA.Loader/Logging/Printers/GZFilePrinter.cs @@ -1,158 +1,158 @@ -using Ionic.Zlib; -using System; -using System.IO; -using System.Runtime.InteropServices; -using System.Text; -using System.Text.RegularExpressions; -#if NET3 -using Net3_Proxy; -using Path = Net3_Proxy.Path; -#endif - -namespace IPA.Logging.Printers -{ - /// - /// A abstract class that provides the utilities to write to a GZip file. - /// - public abstract class GZFilePrinter : LogPrinter, IDisposable - { - [DllImport("Kernel32.dll", CharSet = CharSet.Unicode, SetLastError = true)] - private static extern bool CreateHardLink( - string lpFileName, - string lpExistingFileName, - IntPtr lpSecurityAttributes - ); - -#if NET4 - private const RegexOptions reOptions = RegexOptions.Compiled; -#elif NET3 // Needed because Compiled doesn't exist in Unity's .NET 3 runtime - private const RegexOptions reOptions = RegexOptions.None; -#endif - - internal static Regex removeControlCodes = new Regex("\x1b\\[\\d+m", reOptions); - - private FileInfo fileInfo; - - /// - /// The that writes to the GZip file. - /// - /// the writer to the underlying filestream - protected StreamWriter FileWriter; - - private FileStream fstream; - - /// - /// Gets the for the file to write to. - /// - /// the file to write to - protected abstract FileInfo GetFileInfo(); - - private const string latestFormat = "_latest{0}"; - - private void InitLog() - { - try - { - if (fileInfo == null) - { // first init - fileInfo = GetFileInfo(); - var ext = fileInfo.Extension; - - var symlink = new FileInfo(Path.Combine(fileInfo.DirectoryName ?? throw new InvalidOperationException(), string.Format(latestFormat, ext))); - if (symlink.Exists) symlink.Delete(); - - foreach (var file in fileInfo.Directory.EnumerateFiles("*.log", SearchOption.TopDirectoryOnly)) - { - if (file.Equals(fileInfo)) continue; - if (file.Extension == ".gz") continue; - - CompressOldLog(file); - } - - fileInfo.Create().Close(); - - try - { - if (!CreateHardLink(symlink.FullName, fileInfo.FullName, IntPtr.Zero)) - { - var error = Marshal.GetLastWin32Error(); - Logger.log.Error($"Hardlink creation failed ({error})"); - } - } - catch (Exception e) - { - Logger.log.Error("Error creating latest hardlink!"); - Logger.log.Error(e); - } - } - } - catch (Exception e) - { - Logger.log.Error("Error initializing log!"); - Logger.log.Error(e); - } - } - - private static async void CompressOldLog(FileInfo file) - { - Logger.log.Debug($"Compressing log file {file}"); - - var newFile = new FileInfo(file.FullName + ".gz"); - - using (var istream = file.OpenRead()) - using (var ostream = newFile.Create()) - using (var gz = new GZipStream(ostream, CompressionMode.Compress, CompressionLevel.BestCompression, false)) - await istream.CopyToAsync(gz); - - file.Delete(); - } - - /// - /// Called at the start of any print session. - /// - public sealed override void StartPrint() - { - InitLog(); - - fstream = fileInfo.Open(FileMode.Append, FileAccess.Write); - FileWriter = new StreamWriter(fstream, new UTF8Encoding(false)); - } - - /// - /// Called at the end of any print session. - /// - public sealed override void EndPrint() - { - FileWriter.Flush(); - fstream.Flush(); - FileWriter.Dispose(); - fstream.Dispose(); - FileWriter = null; - fstream = null; - } - - /// - public void Dispose() - { - Dispose(true); - GC.SuppressFinalize(this); - } - - /// - /// Disposes the file printer. - /// - /// does nothing - protected virtual void Dispose(bool disposing) - { - if (disposing) - { - FileWriter.Flush(); - fstream.Flush(); - FileWriter.Close(); - fstream.Close(); - FileWriter.Dispose(); - fstream.Dispose(); - } - } - } +using Ionic.Zlib; +using System; +using System.IO; +using System.Runtime.InteropServices; +using System.Text; +using System.Text.RegularExpressions; +#if NET3 +using Net3_Proxy; +using Path = Net3_Proxy.Path; +#endif + +namespace IPA.Logging.Printers +{ + /// + /// A abstract class that provides the utilities to write to a GZip file. + /// + public abstract class GZFilePrinter : LogPrinter, IDisposable + { + [DllImport("Kernel32.dll", CharSet = CharSet.Unicode, SetLastError = true)] + private static extern bool CreateHardLink( + string lpFileName, + string lpExistingFileName, + IntPtr lpSecurityAttributes + ); + +#if NET4 + private const RegexOptions reOptions = RegexOptions.Compiled; +#elif NET3 // Needed because Compiled doesn't exist in Unity's .NET 3 runtime + private const RegexOptions reOptions = RegexOptions.None; +#endif + + internal static Regex removeControlCodes = new Regex("\x1b\\[\\d+m", reOptions); + + private FileInfo fileInfo; + + /// + /// The that writes to the GZip file. + /// + /// the writer to the underlying filestream + protected StreamWriter FileWriter; + + private FileStream fstream; + + /// + /// Gets the for the file to write to. + /// + /// the file to write to + protected abstract FileInfo GetFileInfo(); + + private const string latestFormat = "_latest{0}"; + + private void InitLog() + { + try + { + if (fileInfo == null) + { // first init + fileInfo = GetFileInfo(); + var ext = fileInfo.Extension; + + var symlink = new FileInfo(Path.Combine(fileInfo.DirectoryName ?? throw new InvalidOperationException(), string.Format(latestFormat, ext))); + if (symlink.Exists) symlink.Delete(); + + foreach (var file in fileInfo.Directory.EnumerateFiles("*.log", SearchOption.TopDirectoryOnly)) + { + if (file.Equals(fileInfo)) continue; + if (file.Extension == ".gz") continue; + + CompressOldLog(file); + } + + fileInfo.Create().Close(); + + try + { + if (!CreateHardLink(symlink.FullName, fileInfo.FullName, IntPtr.Zero)) + { + var error = Marshal.GetLastWin32Error(); + Logger.Default.Error($"Hardlink creation failed ({error})"); + } + } + catch (Exception e) + { + Logger.Default.Error("Error creating latest hardlink!"); + Logger.Default.Error(e); + } + } + } + catch (Exception e) + { + Logger.Default.Error("Error initializing log!"); + Logger.Default.Error(e); + } + } + + private static async void CompressOldLog(FileInfo file) + { + Logger.Default.Debug($"Compressing log file {file}"); + + var newFile = new FileInfo(file.FullName + ".gz"); + + using (var istream = file.OpenRead()) + using (var ostream = newFile.Create()) + using (var gz = new GZipStream(ostream, CompressionMode.Compress, CompressionLevel.BestCompression, false)) + await istream.CopyToAsync(gz); + + file.Delete(); + } + + /// + /// Called at the start of any print session. + /// + public sealed override void StartPrint() + { + InitLog(); + + fstream = fileInfo.Open(FileMode.Append, FileAccess.Write); + FileWriter = new StreamWriter(fstream, new UTF8Encoding(false)); + } + + /// + /// Called at the end of any print session. + /// + public sealed override void EndPrint() + { + FileWriter.Flush(); + fstream.Flush(); + FileWriter.Dispose(); + fstream.Dispose(); + FileWriter = null; + fstream = null; + } + + /// + public void Dispose() + { + Dispose(true); + GC.SuppressFinalize(this); + } + + /// + /// Disposes the file printer. + /// + /// does nothing + protected virtual void Dispose(bool disposing) + { + if (disposing) + { + FileWriter.Flush(); + fstream.Flush(); + FileWriter.Close(); + fstream.Close(); + FileWriter.Dispose(); + fstream.Dispose(); + } + } + } } \ No newline at end of file diff --git a/IPA.Loader/Logging/StdoutInterceptor.cs b/IPA.Loader/Logging/StdoutInterceptor.cs index 31efdae2..9d83851c 100644 --- a/IPA.Loader/Logging/StdoutInterceptor.cs +++ b/IPA.Loader/Logging/StdoutInterceptor.cs @@ -1,9 +1,11 @@ -using HarmonyLib; +#nullable enable +using HarmonyLib; using System; using System.Collections.Generic; using System.IO; using System.Reflection.Emit; using System.Text; +using static IPA.Logging.Logger; namespace IPA.Logging { @@ -19,7 +21,7 @@ namespace IPA.Logging } private string lineBuffer = ""; - private readonly object bufferLock = new object(); + private readonly object bufferLock = new(); public override void Write(string value) { @@ -111,8 +113,8 @@ namespace IPA.Logging return "\x1b[" + code + "m"; } - private static StdoutInterceptor stdoutInterceptor; - private static StdoutInterceptor stderrInterceptor; + private static StdoutInterceptor? stdoutInterceptor; + private static StdoutInterceptor? stderrInterceptor; private static class ConsoleHarmonyPatches { @@ -127,24 +129,24 @@ namespace IPA.Logging try { if (resetColor != null) - harmony.Patch(resetColor, transpiler: new HarmonyMethod(typeof(ConsoleHarmonyPatches), nameof(PatchResetColor))); + _ = harmony.Patch(resetColor, transpiler: new HarmonyMethod(typeof(ConsoleHarmonyPatches), nameof(PatchResetColor))); if (foregroundProperty != null) { - harmony.Patch(setFg, transpiler: new HarmonyMethod(typeof(ConsoleHarmonyPatches), nameof(PatchSetForegroundColor))); - harmony.Patch(getFg, transpiler: new HarmonyMethod(typeof(ConsoleHarmonyPatches), nameof(PatchGetForegroundColor))); + _ = harmony.Patch(setFg, transpiler: new HarmonyMethod(typeof(ConsoleHarmonyPatches), nameof(PatchSetForegroundColor))); + _ = harmony.Patch(getFg, transpiler: new HarmonyMethod(typeof(ConsoleHarmonyPatches), nameof(PatchGetForegroundColor))); } } catch (Exception e) { // Harmony might be fucked because of wierdness in Guid.NewGuid, don't let that kill us - Logger.log.Error("Error installing harmony patches to intercept Console color properties:"); - Logger.log.Error(e); + Logger.Default.Error("Error installing harmony patches to intercept Console color properties:"); + Logger.Default.Error(e); } } - public static ConsoleColor GetColor() => stdoutInterceptor.currentColor; - public static void SetColor(ConsoleColor col) => stdoutInterceptor.currentColor = col; - public static void ResetColor() => stdoutInterceptor.currentColor = defaultColor; + public static ConsoleColor GetColor() => stdoutInterceptor!.currentColor; + public static void SetColor(ConsoleColor col) => stdoutInterceptor!.currentColor = col; + public static void ResetColor() => stdoutInterceptor!.currentColor = defaultColor; public static IEnumerable PatchGetForegroundColor(IEnumerable _) { @@ -178,20 +180,20 @@ namespace IPA.Logging } } - private static Harmony harmony; - private static bool usingInterceptor = false; + private static Harmony? harmony; + private static bool usingInterceptor; public static void Intercept() { if (!usingInterceptor) { usingInterceptor = true; - if (harmony == null) - harmony = new Harmony("BSIPA Console Redirector Patcher"); - if (stdoutInterceptor == null) - stdoutInterceptor = new StdoutInterceptor(); - if (stderrInterceptor == null) - stderrInterceptor = new StdoutInterceptor() { isStdErr = true }; + + ConfigureHarmonyLogging(); + + harmony ??= new Harmony("BSIPA Console Redirector Patcher"); + stdoutInterceptor ??= new StdoutInterceptor(); + stderrInterceptor ??= new StdoutInterceptor() { isStdErr = true }; RedirectConsole(); ConsoleHarmonyPatches.Patch(harmony); @@ -206,5 +208,27 @@ namespace IPA.Logging Console.SetError(stderrInterceptor); } } + + // I'm not completely sure this is the best place for this, but whatever + private static void ConfigureHarmonyLogging() + { + HarmonyLib.Tools.Logger.ChannelFilter = HarmonyLib.Tools.Logger.LogChannel.All & ~HarmonyLib.Tools.Logger.LogChannel.IL; + HarmonyLib.Tools.Logger.MessageReceived += (s, e) => + { + var msg = e.Message; + var lvl = e.LogChannel switch + { + HarmonyLib.Tools.Logger.LogChannel.None => Level.Info, + HarmonyLib.Tools.Logger.LogChannel.Info => Level.Info, + HarmonyLib.Tools.Logger.LogChannel.IL => Level.Trace, + HarmonyLib.Tools.Logger.LogChannel.Warn => Level.Warning, + HarmonyLib.Tools.Logger.LogChannel.Error => Level.Error, + HarmonyLib.Tools.Logger.LogChannel.Debug => Level.Debug, + HarmonyLib.Tools.Logger.LogChannel.All => Level.Critical, + _ => Level.Critical, + }; + Logger.Harmony.Log(lvl, msg); + }; + } } } diff --git a/IPA.Loader/Utilities/CriticalSection.cs b/IPA.Loader/Utilities/CriticalSection.cs index c5ed1029..4630f572 100644 --- a/IPA.Loader/Utilities/CriticalSection.cs +++ b/IPA.Loader/Utilities/CriticalSection.cs @@ -16,7 +16,7 @@ namespace IPA.Utilities internal static void Configure() { - Logger.log.Debug("Configuring exit handlers"); + Logger.Default.Debug("Configuring exit handlers"); ResetExitHandlers(); } diff --git a/IPA.Loader/Utilities/UnityGame.cs b/IPA.Loader/Utilities/UnityGame.cs index 259c6305..9765af75 100644 --- a/IPA.Loader/Utilities/UnityGame.cs +++ b/IPA.Loader/Utilities/UnityGame.cs @@ -27,7 +27,7 @@ namespace IPA.Utilities internal static void SetEarlyGameVersion(AlmostVersion ver) { _gameVersion = ver; - Logging.Logger.log.Debug($"GameVersion set early to {ver}"); + Logging.Logger.Default.Debug($"GameVersion set early to {ver}"); } private static string ApplicationVersionProxy { @@ -40,15 +40,15 @@ namespace IPA.Utilities } catch(MissingMemberException ex) { - Logging.Logger.log.Error($"Tried to grab 'Application.version' too early, it's probably broken now."); + Logging.Logger.Default.Error($"Tried to grab 'Application.version' too early, it's probably broken now."); if (SelfConfig.Debug_.ShowHandledErrorStackTraces_) - Logging.Logger.log.Error(ex); + Logging.Logger.Default.Error(ex); } catch (Exception ex) { - Logging.Logger.log.Error($"Error getting Application.version: {ex.Message}"); + Logging.Logger.Default.Error($"Error getting Application.version: {ex.Message}"); if (SelfConfig.Debug_.ShowHandledErrorStackTraces_) - Logging.Logger.log.Error(ex); + Logging.Logger.Default.Error(ex); } return string.Empty; } @@ -60,18 +60,18 @@ namespace IPA.Utilities var rtVer = new AlmostVersion(ApplicationVersionProxy); if (!rtVer.Equals(_gameVersion)) // this actually uses stricter equality than == for AlmostVersion { - Logging.Logger.log.Warn($"Early version {_gameVersion} parsed from game files doesn't match runtime version {rtVer}!"); + Logging.Logger.Default.Warn($"Early version {_gameVersion} parsed from game files doesn't match runtime version {rtVer}!"); _gameVersion = rtVer; } } catch (MissingMethodException e) { - Logging.Logger.log.Error("Application.version was not found! Cannot check early parsed version"); + Logging.Logger.Default.Error("Application.version was not found! Cannot check early parsed version"); if (SelfConfig.Debug_.ShowHandledErrorStackTraces_) - Logging.Logger.log.Error(e); + Logging.Logger.Default.Error(e); var st = new StackTrace(); - Logging.Logger.log.Notice($"{st}"); + Logging.Logger.Default.Notice($"{st}"); } }