Browse Source

Add Harmony logging interceptor

pull/74/head
Anairkoen Schno 2 years ago
parent
commit
332823b46a
Signed by: DaNike GPG Key ID: BEFB74D5F3FC4387
28 changed files with 398 additions and 371 deletions
  1. +21
    -20
      IPA.Injector/Injector.cs
  2. +3
    -3
      IPA.Injector/PermissionFix.cs
  3. +15
    -15
      IPA.Injector/Updates.cs
  4. +6
    -6
      IPA.Loader/Config/ConfigRuntime.cs
  5. +9
    -9
      IPA.Loader/Config/Providers/JsonConfigProvider.cs
  6. +1
    -1
      IPA.Loader/Config/SelfConfig.cs
  7. +2
    -2
      IPA.Loader/Config/Stores/GeneratedStoreImpl/Deserialization.cs
  8. +4
    -4
      IPA.Loader/Config/Stores/GeneratedStoreImpl/IGeneratedStore.cs
  9. +2
    -2
      IPA.Loader/Config/Stores/GeneratedStoreImpl/MakeCreator.cs
  10. +5
    -5
      IPA.Loader/Config/Stores/GeneratedStoreImpl/ObjectStructure.cs
  11. +2
    -2
      IPA.Loader/Config/Stores/GeneratedStoreImpl/Serialization.cs
  12. +3
    -3
      IPA.Loader/Config/Stores/GeneratedStoreImpl/Utility.cs
  13. +2
    -2
      IPA.Loader/IPA.Loader.csproj
  14. +1
    -1
      IPA.Loader/JsonConverters/FeaturesFieldConverter.cs
  15. +1
    -1
      IPA.Loader/Loader/Composite/CompositeBSPlugin.cs
  16. +1
    -1
      IPA.Loader/Loader/Composite/CompositeIPAPlugin.cs
  17. +3
    -3
      IPA.Loader/Loader/DisabledConfig.cs
  18. +7
    -7
      IPA.Loader/Loader/Features/DefineFeature.cs
  19. +2
    -2
      IPA.Loader/Loader/LibLoader.cs
  20. +5
    -5
      IPA.Loader/Loader/PluginExecutor.cs
  21. +57
    -57
      IPA.Loader/Loader/PluginLoader.cs
  22. +19
    -19
      IPA.Loader/Loader/PluginManager.cs
  23. +1
    -1
      IPA.Loader/Loader/manifest.json
  24. +15
    -13
      IPA.Loader/Logging/Logger.cs
  25. +157
    -157
      IPA.Loader/Logging/Printers/GZFilePrinter.cs
  26. +44
    -20
      IPA.Loader/Logging/StdoutInterceptor.cs
  27. +1
    -1
      IPA.Loader/Utilities/CriticalSection.cs
  28. +9
    -9
      IPA.Loader/Utilities/UnityGame.cs

+ 21
- 20
IPA.Injector/Injector.cs View File

@ -63,7 +63,7 @@ namespace IPA.Injector
*/ */
#endregion #endregion
log.Debug("Initializing logger");
Default.Debug("Initializing logger");
SelfConfig.ReadCommandLine(Environment.GetCommandLineArgs()); SelfConfig.ReadCommandLine(Environment.GetCommandLineArgs());
SelfConfig.Load(); SelfConfig.Load();
@ -71,14 +71,14 @@ namespace IPA.Injector
if (AntiPiracy.IsInvalid(Environment.CurrentDirectory)) 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; return;
} }
CriticalSection.Configure(); CriticalSection.Configure();
injector.Debug("Prepping bootstrapper");
Logging.Logger.Injector.Debug("Prepping bootstrapper");
// updates backup // updates backup
InstallBootstrapPatch(); InstallBootstrapPatch();
@ -89,7 +89,7 @@ namespace IPA.Injector
Updates.InstallPendingUpdates(); Updates.InstallPendingUpdates();
LibLoader.SetupAssemblyFilenames(true);
Loader.LibLoader.SetupAssemblyFilenames(true);
pluginAsyncLoadTask = PluginLoader.LoadTask(); pluginAsyncLoadTask = PluginLoader.LoadTask();
permissionFixTask = PermissionFix.FixPermissions(new DirectoryInfo(Environment.CurrentDirectory)); permissionFixTask = PermissionFix.FixPermissions(new DirectoryInfo(Environment.CurrentDirectory));
@ -113,7 +113,7 @@ namespace IPA.Injector
{ {
if (loadingDone) return; if (loadingDone) return;
loadingDone = true; loadingDone = true;
LibLoader.Configure();
Loader.LibLoader.Configure();
} }
private static void InstallHarmonyProtections() private static void InstallHarmonyProtections()
@ -131,13 +131,13 @@ namespace IPA.Injector
var dataDir = new DirectoryInfo(managedPath).Parent.Name; var dataDir = new DirectoryInfo(managedPath).Parent.Name;
var gameName = dataDir.Substring(0, dataDir.Length - 5); 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 backupPath = Path.Combine(Environment.CurrentDirectory, "IPA", "Backups", gameName);
var bkp = BackupManager.FindLatestBackup(backupPath); var bkp = BackupManager.FindLatestBackup(backupPath);
if (bkp == null) 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 #region Insert patch into UnityEngine.CoreModule.dll
@ -173,7 +173,7 @@ namespace IPA.Injector
if (application == null) 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!"); + "Nothing to patch to get ourselves into the Unity run cycle!");
goto endPatchCoreModule; goto endPatchCoreModule;
} }
@ -238,7 +238,7 @@ namespace IPA.Injector
endPatchCoreModule: endPatchCoreModule:
#endregion Insert patch into UnityEngine.CoreModule.dll #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 #region Virtualize game assemblies
bool isFirst = true; bool isFirst = true;
@ -250,15 +250,15 @@ namespace IPA.Injector
try try
{ {
injector.Debug($"Virtualizing {name}");
Logging.Logger.Injector.Debug($"Virtualizing {name}");
using var ascModule = VirtualizedModule.Load(ascPath); using var ascModule = VirtualizedModule.Load(ascPath);
ascModule.Virtualize(cAsmName, () => bkp?.Add(ascPath)); ascModule.Virtualize(cAsmName, () => bkp?.Add(ascPath));
} }
catch (Exception e) catch (Exception e)
{ {
injector.Error($"Could not virtualize {ascPath}");
Logging.Logger.Injector.Error($"Could not virtualize {ascPath}");
if (SelfConfig.Debug_.ShowHandledErrorStackTraces_) if (SelfConfig.Debug_.ShowHandledErrorStackTraces_)
injector.Error(e);
Logging.Logger.Injector.Error(e);
} }
#if BeatSaber #if BeatSaber
@ -266,7 +266,7 @@ namespace IPA.Injector
{ {
try try
{ {
injector.Debug("Applying anti-yeet patch");
Logging.Logger.Injector.Debug("Applying anti-yeet patch");
using var ascAsmDef = AssemblyDefinition.ReadAssembly(ascPath, new ReaderParameters using var ascAsmDef = AssemblyDefinition.ReadAssembly(ascPath, new ReaderParameters
{ {
@ -285,9 +285,9 @@ namespace IPA.Injector
} }
catch (Exception e) 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_) if (SelfConfig.Debug_.ShowHandledErrorStackTraces_)
injector.Warn(e);
Logging.Logger.Injector.Warn(e);
} }
} }
#endif #endif
@ -295,7 +295,7 @@ namespace IPA.Injector
#endregion #endregion
sw.Stop(); sw.Stop();
injector.Info($"Installing bootstrapper took {sw.Elapsed}");
Logging.Logger.Injector.Info($"Installing bootstrapper took {sw.Elapsed}");
} }
private static bool bootstrapped; private static bool bootstrapped;
@ -305,7 +305,6 @@ namespace IPA.Injector
if (bootstrapped) return; if (bootstrapped) return;
bootstrapped = true; bootstrapped = true;
Application.logMessageReceived += delegate (string condition, string stackTrace, LogType type) Application.logMessageReceived += delegate (string condition, string stackTrace, LogType type)
{ {
var level = UnityLogRedirector.LogTypeToLevel(type); var level = UnityLogRedirector.LogTypeToLevel(type);
@ -313,6 +312,8 @@ namespace IPA.Injector
UnityLogProvider.UnityLogger.Log(level, $"{stackTrace}"); UnityLogProvider.UnityLogger.Log(level, $"{stackTrace}");
}; };
ConfigureHarmonyLogging();
// need to reinit streams singe Unity seems to redirect stdout // need to reinit streams singe Unity seems to redirect stdout
StdoutInterceptor.RedirectConsole(); StdoutInterceptor.RedirectConsole();
@ -330,8 +331,8 @@ namespace IPA.Injector
pluginAsyncLoadTask?.Wait(); pluginAsyncLoadTask?.Wait();
permissionFixTask?.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(); _ = PluginComponent.Create();
} }
} }

+ 3
- 3
IPA.Injector/PermissionFix.cs View File

@ -62,11 +62,11 @@ namespace IPA.Injector
} }
catch (Exception e) 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(); sw.Stop();
Logger.log.Info($"Configuring permissions took {sw.Elapsed}");
Logger.Default.Info($"Configuring permissions took {sw.Elapsed}");
}); });
} }
} }


+ 15
- 15
IPA.Injector/Updates.cs View File

@ -42,12 +42,12 @@ namespace IPA.Injector
var scanResult = AntiMalwareEngine.Engine.ScanFile(new FileInfo(path)); var scanResult = AntiMalwareEngine.Engine.ScanFile(new FileInfo(path));
if (scanResult == ScanResult.Detected) 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; return;
} }
if (!SelfConfig.AntiMalware_.RunPartialThreatCode_ && scanResult is not ScanResult.KnownSafe and not ScanResult.NotDetected) 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; return;
} }
@ -59,7 +59,7 @@ namespace IPA.Injector
UseShellExecute = false UseShellExecute = false
}); });
updater.Info("Updating BSIPA...");
Updater.Info("Updating BSIPA...");
Environment.Exit(0); Environment.Exit(0);
} }
} }
@ -70,7 +70,7 @@ namespace IPA.Injector
if (!Directory.Exists(pendingDir)) return; if (!Directory.Exists(pendingDir)) return;
// there are pending updates, install // there are pending updates, install
updater.Info("Installing pending updates");
Updater.Info("Installing pending updates");
var toDelete = Array.Empty<string>(); var toDelete = Array.Empty<string>();
var delFn = Path.Combine(pendingDir, DeleteFileName); var delFn = Path.Combine(pendingDir, DeleteFileName);
@ -88,8 +88,8 @@ namespace IPA.Injector
} }
catch (Exception e) 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) catch (UnauthorizedAccessException e)
{ {
updater.Error(e);
Updater.Error(e);
continue; continue;
} }
catch (DirectoryNotFoundException e) catch (DirectoryNotFoundException e)
{ {
updater.Error(e);
Updater.Error(e);
continue; continue;
} }
@ -132,7 +132,7 @@ namespace IPA.Injector
} }
catch (FileNotFoundException e) 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) => 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; return true;
}); });
} }
catch (Exception e) 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 try
@ -170,8 +170,8 @@ namespace IPA.Injector
} }
catch (Exception e) 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);
} }
} }
} }


+ 6
- 6
IPA.Loader/Config/ConfigRuntime.cs View File

@ -185,8 +185,8 @@ namespace IPA.Config
} }
catch (Exception e) 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) 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) 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)); Thread.Sleep(TimeSpan.FromSeconds(1));
} }


+ 9
- 9
IPA.Loader/Config/Providers/JsonConfigProvider.cs View File

@ -39,8 +39,8 @@ namespace IPA.Config.Providers
} }
catch (Exception e) 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(); 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 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)); return VisitToValue(JToken.Parse((tok as JRaw).Value as string));
case JTokenType.Undefined: case JTokenType.Undefined:
Logger.config.Warn("Found JTokenType.Undefined");
Logger.Config.Warn("Found JTokenType.Undefined");
goto case JTokenType.Null; goto case JTokenType.Null;
case JTokenType.Bytes: // never used by Newtonsoft case JTokenType.Bytes: // never used by Newtonsoft
Logger.config.Warn("Found JTokenType.Bytes");
Logger.Config.Warn("Found JTokenType.Bytes");
goto case JTokenType.Null; goto case JTokenType.Null;
case JTokenType.Comment: // never used by Newtonsoft case JTokenType.Comment: // never used by Newtonsoft
Logger.config.Warn("Found JTokenType.Comment");
Logger.Config.Warn("Found JTokenType.Comment");
goto case JTokenType.Null; goto case JTokenType.Null;
case JTokenType.Constructor: // never used by Newtonsoft case JTokenType.Constructor: // never used by Newtonsoft
Logger.config.Warn("Found JTokenType.Constructor");
Logger.Config.Warn("Found JTokenType.Constructor");
goto case JTokenType.Null; goto case JTokenType.Null;
case JTokenType.Property: // never used by Newtonsoft case JTokenType.Property: // never used by Newtonsoft
Logger.config.Warn("Found JTokenType.Property");
Logger.Config.Warn("Found JTokenType.Property");
goto case JTokenType.Null; goto case JTokenType.Null;
case JTokenType.Null: case JTokenType.Null:
return Value.Null(); return Value.Null();
@ -133,8 +133,8 @@ namespace IPA.Config.Providers
} }
catch (Exception e) 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);
} }
} }


+ 1
- 1
IPA.Loader/Config/SelfConfig.cs View File

@ -36,7 +36,7 @@ namespace IPA.Config
protected internal virtual void Changed() protected internal virtual void Changed()
{ {
Logger.log.Debug("SelfConfig Changed called");
Logger.Default.Debug("SelfConfig Changed called");
} }
public static void ReadCommandLine(string[] args) public static void ReadCommandLine(string[] args)


+ 2
- 2
IPA.Loader/Config/Stores/GeneratedStoreImpl/Deserialization.cs View File

@ -102,7 +102,7 @@ namespace IPA.Config.Stores
var structure = ReadObjectMembers(targetType); var structure = ReadObjectMembers(targetType);
if (!structure.Any()) 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"); $" {member.Name} on {member.Member.DeclaringType.FullName}) has no accessible members");
il.Emit(OpCodes.Pop); il.Emit(OpCodes.Pop);
il.Emit(OpCodes.Ldloca, resultLocal); il.Emit(OpCodes.Ldloca, resultLocal);
@ -123,7 +123,7 @@ namespace IPA.Config.Stores
} }
else 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.Pop);
il.Emit(OpCodes.Ldnull); il.Emit(OpCodes.Ldnull);
} }


+ 4
- 4
IPA.Loader/Config/Stores/GeneratedStoreImpl/IGeneratedStore.cs View File

@ -67,8 +67,8 @@ namespace IPA.Config.Stores
} }
catch (ObjectDisposedException e) 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 static void ImplReadFrom(IGeneratedStore s, ConfigProvider provider) => FindImpl(s)?.ReadFrom(provider);
public void ReadFrom(ConfigProvider 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(); var values = provider.Load();
//Logger.config.Debug($"Read {values}"); //Logger.config.Debug($"Read {values}");
generated.Deserialize(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 static void ImplWriteTo(IGeneratedStore s, ConfigProvider provider) => FindImpl(s)?.WriteTo(provider);
public void WriteTo(ConfigProvider 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(); var values = generated.Serialize();
//Logger.config.Debug($"Serialized {values}"); //Logger.config.Debug($"Serialized {values}");
provider.Store(values); provider.Store(values);


+ 2
- 2
IPA.Loader/Config/Stores/GeneratedStoreImpl/MakeCreator.cs View File

@ -53,7 +53,7 @@ namespace IPA.Config.Stores
var structure = ReadObjectMembers(type); var structure = ReadObjectMembers(type);
if (!structure.Any()) 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 #endregion
var typeBuilder = Module.DefineType($"{type.FullName}<Generated>", var typeBuilder = Module.DefineType($"{type.FullName}<Generated>",
@ -135,7 +135,7 @@ namespace IPA.Config.Stores
} }
else 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."); "'RaisePropertyChanged(string)' method, automatic raising of PropertyChanged event is disabled.");
} }
} }


+ 5
- 5
IPA.Loader/Config/Stores/GeneratedStoreImpl/ObjectStructure.cs View File

@ -85,19 +85,19 @@ namespace IPA.Config.Stores
if (member.Converter.GetConstructor(Type.EmptyTypes) == null) 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? goto endConverterAttr; // is there a better control flow structure to do this?
} }
if (member.Converter.ContainsGenericParameters) 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; goto endConverterAttr;
} }
if (member.Converter.IsInterface || member.Converter.IsAbstract) 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; goto endConverterAttr;
} }
@ -111,13 +111,13 @@ namespace IPA.Config.Stores
} }
catch 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; goto endConverterAttr;
} }
} }
if (targetType != member.Type) 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; goto endConverterAttr;
} }


+ 2
- 2
IPA.Loader/Config/Stores/GeneratedStoreImpl/Serialization.cs View File

@ -125,7 +125,7 @@ namespace IPA.Config.Stores
else if (targetType == typeof(List)) else if (targetType == typeof(List))
{ {
// TODO: impl this (enumerables) // 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.Pop);
il.Emit(OpCodes.Ldnull); il.Emit(OpCodes.Ldnull);
} }
@ -168,7 +168,7 @@ namespace IPA.Config.Stores
var structure = ReadObjectMembers(memberConversionType); var structure = ReadObjectMembers(memberConversionType);
if (!structure.Any()) 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"); $" {member.Name} on {member.Member.DeclaringType.FullName}) has no accessible members");
il.Emit(OpCodes.Pop); il.Emit(OpCodes.Pop);
} }


+ 3
- 3
IPA.Loader/Config/Stores/GeneratedStoreImpl/Utility.cs View File

@ -25,17 +25,17 @@ namespace IPA.Config.Stores
private static readonly MethodInfo LogErrorMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogError), BindingFlags.NonPublic | BindingFlags.Static); private static readonly MethodInfo LogErrorMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogError), BindingFlags.NonPublic | BindingFlags.Static);
internal static void LogError(Type? expected, Type? found, string message) 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); private static readonly MethodInfo LogWarningMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogWarning), BindingFlags.NonPublic | BindingFlags.Static);
internal static void LogWarning(string message) 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); private static readonly MethodInfo LogWarningExceptionMethod = typeof(GeneratedStoreImpl).GetMethod(nameof(LogWarningException), BindingFlags.NonPublic | BindingFlags.Static);
internal static void LogWarningException(Exception exception) internal static void LogWarningException(Exception exception)
{ {
Logger.config.Warn(exception);
Logger.Config.Warn(exception);
} }
#endregion #endregion


+ 2
- 2
IPA.Loader/IPA.Loader.csproj View File

@ -57,8 +57,8 @@
</PackageReference>--> </PackageReference>-->
<PackageReference Include="Mono.Cecil" Version="0.11.4" /> <PackageReference Include="Mono.Cecil" Version="0.11.4" />
<PackageReference Include="HarmonyX" Version="2.5.0" />
<PackageReference Include="MonoMod.RuntimeDetour" Version="21.7.8.3" />
<PackageReference Include="HarmonyX" Version="2.6.1" />
<PackageReference Include="MonoMod.RuntimeDetour" Version="21.11.1.1" />
<PackageReference Include="Hive.Versioning.Standalone" Version="0.1.0-gh846.1" /> <PackageReference Include="Hive.Versioning.Standalone" Version="0.1.0-gh846.1" />
<ProjectReference Include="..\SemVer\SemVer.csproj" /> <ProjectReference Include="..\SemVer\SemVer.csproj" />


+ 1
- 1
IPA.Loader/JsonConverters/FeaturesFieldConverter.cs View File

@ -22,7 +22,7 @@ namespace IPA.JsonConverters
if (reader.TokenType == JsonToken.StartArray) if (reader.TokenType == JsonToken.StartArray)
{ {
_ = serializer.Deserialize<string[]>(reader); _ = serializer.Deserialize<string[]>(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; return existingValue;
} }


+ 1
- 1
IPA.Loader/Loader/Composite/CompositeBSPlugin.cs View File

@ -27,7 +27,7 @@ namespace IPA.Loader.Composite
} }
catch (Exception ex) catch (Exception ex)
{ {
Logger.log.Error($"{plugin.Metadata.Name} {method}: {ex}");
Logger.Default.Error($"{plugin.Metadata.Name} {method}: {ex}");
} }
} }
} }


+ 1
- 1
IPA.Loader/Loader/Composite/CompositeIPAPlugin.cs View File

@ -38,7 +38,7 @@ namespace IPA.Loader.Composite
} }
catch (Exception ex) catch (Exception ex)
{ {
Logger.log.Error($"{plugin.Name} {member}: {ex}");
Logger.Default.Error($"{plugin.Name} {member}: {ex}");
} }
} }
} }


+ 3
- 3
IPA.Loader/Loader/DisabledConfig.cs View File

@ -86,13 +86,13 @@ namespace IPA.Loader
try try
{ {
if (transaction.WillNeedRestart) 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 => return transaction.Commit().ContinueWith(t =>
{ {
if (t.IsFaulted) 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);
} }
}); });
} }


+ 7
- 7
IPA.Loader/Loader/Features/DefineFeature.cs View File

@ -25,7 +25,7 @@ namespace IPA.Loader.Features
protected override bool Initialize(PluginMetadata meta, JObject featureData) protected override bool Initialize(PluginMetadata meta, JObject featureData)
{ {
Logger.features.Debug("Executing DefineFeature Init");
Logger.Features.Debug("Executing DefineFeature Init");
try try
{ {
@ -43,7 +43,7 @@ namespace IPA.Loader.Features
public override void BeforeInit(PluginMetadata meta) public override void BeforeInit(PluginMetadata meta)
{ {
Logger.features.Debug("Executing DefineFeature AfterInit");
Logger.Features.Debug("Executing DefineFeature AfterInit");
Type type; Type type;
try try
@ -52,7 +52,7 @@ namespace IPA.Loader.Features
} }
catch (ArgumentException) catch (ArgumentException)
{ {
Logger.features.Error($"Invalid type name {data.TypeName}");
Logger.Features.Error($"Invalid type name {data.TypeName}");
return; return;
} }
catch (Exception e) when (e is FileNotFoundException or FileLoadException or BadImageFormatException) catch (Exception e) when (e is FileNotFoundException or FileLoadException or BadImageFormatException)
@ -72,13 +72,13 @@ namespace IPA.Loader.Features
break; break;
} }
Logger.features.Error($"Could not find {filename} while loading type");
Logger.Features.Error($"Could not find {filename} while loading type");
return; return;
} }
if (type == null) if (type == null)
{ {
Logger.features.Error($"Invalid type name {data.TypeName}");
Logger.Features.Error($"Invalid type name {data.TypeName}");
return; return;
} }
@ -90,12 +90,12 @@ namespace IPA.Loader.Features
return; return;
} }
Logger.features.Error($"Feature with name {data.Name} already exists");
Logger.Features.Error($"Feature with name {data.Name} already exists");
return; return;
} }
catch (ArgumentException) 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; return;
} }
} }


+ 2
- 2
IPA.Loader/Loader/LibLoader.cs View File

@ -171,8 +171,8 @@ namespace IPA.Loader
Console.WriteLine($"[{lvl}] {message}"); 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 // https://docs.microsoft.com/en-us/dotnet/csharp/programming-guide/file-system/how-to-iterate-through-a-directory-tree
private static IEnumerable<FileInfo> TraverseTree(string root, Func<string, bool>? dirValidator = null) private static IEnumerable<FileInfo> TraverseTree(string root, Func<string, bool>? dirValidator = null)


+ 5
- 5
IPA.Loader/Loader/PluginExecutor.cs View File

@ -80,7 +80,7 @@ namespace IPA.Loader
.OrderByDescending(t => t.c.GetParameters().Length) .OrderByDescending(t => t.c.GetParameters().Length)
.Select(t => t.c).ToArray(); .Select(t => t.c).ToArray();
if (ctors.Length > 1) 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; bool usingDefaultCtor = false;
var ctor = ctors.FirstOrDefault(); var ctor = ctors.FirstOrDefault();
@ -131,7 +131,7 @@ namespace IPA.Loader
if (enableMethods.Length == 0) if (enableMethods.Length == 0)
{ {
if (!noEnableDisable) 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 => { }; return o => { };
} }
@ -140,7 +140,7 @@ namespace IPA.Loader
if (m.GetParameters().Length > 0) if (m.GetParameters().Length > 0)
throw new InvalidOperationException($"Method {m} on {type.FullName} is marked [OnStart] or [OnEnable] and has parameters."); throw new InvalidOperationException($"Method {m} on {type.FullName} is marked [OnStart] or [OnEnable] and has parameters.");
if (m.ReturnType != typeof(void)) 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"); var objParam = Expression.Parameter(typeof(object), "obj");
@ -164,7 +164,7 @@ namespace IPA.Loader
if (disableMethods.Length == 0) if (disableMethods.Length == 0)
{ {
if (!noEnableDisable) 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(); return o => TaskEx.WhenAll();
} }
@ -182,7 +182,7 @@ namespace IPA.Loader
continue; continue;
} }
else 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); nonTaskMethods.Add(m);


+ 57
- 57
IPA.Loader/Loader/PluginLoader.cs View File

@ -50,7 +50,7 @@ namespace IPA.Loader
LoadMetadata(); LoadMetadata();
sw.Stop(); sw.Stop();
Logger.loader.Info($"Loading metadata took {sw.Elapsed}");
Logger.Loader.Info($"Loading metadata took {sw.Elapsed}");
sw.Reset(); sw.Reset();
sw.Start(); sw.Start();
@ -60,7 +60,7 @@ namespace IPA.Loader
DoOrderResolution(); DoOrderResolution();
sw.Stop(); sw.Stop();
Logger.loader.Info($"Calculating load order took {sw.Elapsed}");
Logger.Loader.Info($"Calculating load order took {sw.Elapsed}");
}); });
internal static void YeetIfNeeded() internal static void YeetIfNeeded()
@ -115,8 +115,8 @@ namespace IPA.Loader
} }
catch (Exception e) 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(); using var resolver = new CecilLibLoader();
@ -135,12 +135,12 @@ namespace IPA.Loader
var scanResult = AntiMalwareEngine.Engine.ScanFile(metadata.File); var scanResult = AntiMalwareEngine.Engine.ScanFile(metadata.File);
if (scanResult is ScanResult.Detected) 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; continue;
} }
if (!SelfConfig.AntiMalware_.RunPartialThreatCode_ && scanResult is not ScanResult.KnownSafe and not ScanResult.NotDetected) 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; continue;
} }
@ -175,14 +175,14 @@ namespace IPA.Loader
#if DIRE_LOADER_WARNINGS #if DIRE_LOADER_WARNINGS
Logger.loader.Error($"Could not find manifest.json for {Path.GetFileName(plugin)}"); Logger.loader.Error($"Could not find manifest.json for {Path.GetFileName(plugin)}");
#else #else
Logger.loader.Notice($"No manifest.json in {Path.GetFileName(plugin)}");
Logger.Loader.Notice($"No manifest.json in {Path.GetFileName(plugin)}");
#endif #endif
continue; continue;
} }
if (pluginManifest.Id == null) 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; pluginManifest.Id = pluginManifest.Name;
} }
@ -199,20 +199,20 @@ namespace IPA.Loader
if (!attr.HasConstructorArguments) 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; return false;
} }
var args = attr.ConstructorArguments; var args = attr.ConstructorArguments;
if (args.Count != 1) 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; return false;
} }
var rtOptionsArg = args[0]; var rtOptionsArg = args[0];
if (rtOptionsArg.Type.FullName != typeof(RuntimeOptions).FullName) 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; return false;
} }
@ -248,17 +248,17 @@ namespace IPA.Loader
if (metadata.PluginType == null) 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; continue;
} }
Logger.loader.Debug($"Adding info for {Path.GetFileName(plugin)}");
Logger.Loader.Debug($"Adding info for {Path.GetFileName(plugin)}");
PluginsMetadata.Add(metadata); PluginsMetadata.Add(metadata);
} }
catch (Exception e) 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) ignoredPlugins.Add(metadata, new IgnoreReason(Reason.Error)
{ {
ReasonText = "An error occurred loading the data", ReasonText = "An error occurred loading the data",
@ -283,16 +283,16 @@ namespace IPA.Loader
metadata.Manifest = JsonConvert.DeserializeObject<PluginManifest>(File.ReadAllText(manifest)); metadata.Manifest = JsonConvert.DeserializeObject<PluginManifest>(File.ReadAllText(manifest));
if (metadata.Manifest.Files.Length < 1) 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."); $"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); PluginsMetadata.Add(metadata);
} }
catch (Exception e) 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) 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 meta.Manifest.Description = string.Join("\n", lines.Skip(1).StrJP()); // ignore first line
continue; continue;
} }
@ -319,7 +319,7 @@ namespace IPA.Loader
.FirstOrDefault(r => r.Name == name); .FirstOrDefault(r => r.Name == name);
if (resc == null) 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 meta.Manifest.Description = string.Join("\n", lines.Skip(1).StrJP()); // ignore first line
continue; continue;
} }
@ -492,14 +492,14 @@ namespace IPA.Loader
{ {
#if DEBUG #if DEBUG
// print starting order // print starting order
Logger.loader.Debug(string.Join(", ", PluginsMetadata.StrJP()));
Logger.Loader.Debug(string.Join(", ", PluginsMetadata.StrJP()));
#endif #endif
PluginsMetadata.Sort((a, b) => b.HVersion.CompareTo(a.HVersion)); PluginsMetadata.Sort((a, b) => b.HVersion.CompareTo(a.HVersion));
#if DEBUG #if DEBUG
// print base resolution order // print base resolution order
Logger.loader.Debug(string.Join(", ", PluginsMetadata.StrJP()));
Logger.Loader.Debug(string.Join(", ", PluginsMetadata.StrJP()));
#endif #endif
var metadataCache = new Dictionary<string, (PluginMetadata Meta, bool Enabled)>(PluginsMetadata.Count); var metadataCache = new Dictionary<string, (PluginMetadata Meta, bool Enabled)>(PluginsMetadata.Count);
@ -526,7 +526,7 @@ namespace IPA.Loader
} }
else 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) ignoredPlugins.Add(meta, new(Reason.Duplicate)
{ {
ReasonText = $"Duplicate entry of same ID ({meta.Id})", ReasonText = $"Duplicate entry of same ID ({meta.Id})",
@ -585,21 +585,21 @@ namespace IPA.Loader
meta = null; meta = null;
disabled = false; disabled = false;
ignored = true; 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)) if (loadedPlugins.TryGetValue(id, out var foundMeta))
{ {
meta = foundMeta.Meta; meta = foundMeta.Meta;
disabled = foundMeta.Disabled; disabled = foundMeta.Disabled;
ignored = foundMeta.Ignored; ignored = foundMeta.Ignored;
Logger.loader.Trace($"- Found already processed");
Logger.Loader.Trace($"- Found already processed");
return true; return true;
} }
if (metadataCache!.TryGetValue(id, out var plugin)) if (metadataCache!.TryGetValue(id, out var plugin))
{ {
Logger.loader.Trace($"- In metadata cache");
Logger.Loader.Trace($"- In metadata cache");
if (partial) if (partial)
{ {
Logger.loader.Trace($" - but requested in a partial lookup");
Logger.Loader.Trace($" - but requested in a partial lookup");
return false; return false;
} }
@ -616,8 +616,8 @@ namespace IPA.Loader
{ {
if (e is not DependencyResolutionLoopException) 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) if (!ignored)
@ -635,23 +635,23 @@ namespace IPA.Loader
if (!loadedPlugins.ContainsKey(id)) if (!loadedPlugins.ContainsKey(id))
{ {
// this condition is specifically for when we fail resolution because of a graph loop // 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)); loadedPlugins.Add(id, (plugin.Meta, disabled, ignored));
} }
return true; return true;
} }
Logger.loader.Trace($"- Not found");
Logger.Loader.Trace($"- Not found");
return false; return false;
} }
void Resolve(PluginMetadata plugin, ref bool disabled, out bool ignored) 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 // first we need to check for loops in the resolution graph to prevent stack overflows
if (isProcessing.Contains(plugin)) 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(); throw new DependencyResolutionLoopException();
} }
@ -671,7 +671,7 @@ namespace IPA.Loader
{ {
ReasonText = $"File {Utils.GetRelativePath(file.FullName, UnityGame.InstallPath)} does not exist" 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."); $" (declared by '{plugin.Name}') does not exist! Mod installation is incomplete, not loading it.");
ignored = true; ignored = true;
return; return;
@ -687,7 +687,7 @@ namespace IPA.Loader
if (!TryResolveId(id, out var depMeta, out var depDisabled, out var depIgnored) if (!TryResolveId(id, out var depMeta, out var depDisabled, out var depIgnored)
|| !range.Matches(depMeta.HVersion)) || !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) ignoredPlugins.Add(plugin, new(Reason.Dependency)
{ {
ReasonText = $"Dependency '{id}@{range}' not found", ReasonText = $"Dependency '{id}@{range}' not found",
@ -698,7 +698,7 @@ namespace IPA.Loader
// make a point to propagate ignored // make a point to propagate ignored
if (depIgnored) 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) ignoredPlugins.Add(plugin, new(Reason.Dependency)
{ {
ReasonText = $"Dependency '{id}' ignored", ReasonText = $"Dependency '{id}' ignored",
@ -710,7 +710,7 @@ namespace IPA.Loader
// make a point to propagate disabled // make a point to propagate disabled
if (depDisabled) 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); disabledPlugins!.Add(plugin);
_ = disabledIds!.Add(plugin.Id); _ = disabledIds!.Add(plugin.Id);
disabled = true; disabled = true;
@ -723,7 +723,7 @@ namespace IPA.Loader
// make sure the plugin depends on the loader (assuming it actually needs to) // make sure the plugin depends on the loader (assuming it actually needs to)
if (!dependsOnSelf && !plugin.IsSelf && !plugin.IsBare) 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) ignoredPlugins.Add(plugin, new(Reason.Dependency)
{ {
ReasonText = "Does not depend on any loader version, so it is assumed to be incompatible", 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 // after we handle dependencies and loadafters, then check conflicts
foreach (var (id, range) in plugin.Manifest.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 // 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) if (TryResolveId(id, out var meta, out var conflDisabled, out var conflIgnored, partial: true)
&& range.Matches(meta.HVersion) && range.Matches(meta.HVersion)
&& !conflIgnored && !conflDisabled) // the conflict is only *actually* a problem if it is both not ignored and not disabled && !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) ignoredPlugins.Add(plugin, new(Reason.Conflict)
{ {
ReasonText = $"Conflicts with {meta.Id}@{meta.HVersion}", ReasonText = $"Conflicts with {meta.Id}@{meta.HVersion}",
@ -783,13 +783,13 @@ namespace IPA.Loader
if (!ignoredPlugins.ContainsKey(plugin)) if (!ignoredPlugins.ContainsKey(plugin))
{ {
// we can now load the current 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); outputOrder!.Add(plugin);
} }
// loadbefores have already been preprocessed into loadafters // 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 // 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 { // this is a DefineFeature, so we want to initialize it early
if (!feature.TryCreate(out var inst)) 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 else
{ {
@ -850,7 +850,7 @@ namespace IPA.Loader
} }
else 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<PluginMetadata> alreadyLoaded) internal static PluginExecutor? InitPlugin(PluginMetadata meta, IEnumerable<PluginMetadata> alreadyLoaded)
{ {
if (meta.Manifest.GameVersion is { } gv && gv != UnityGame.GameVersion) 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) if (meta.IsSelf)
return new PluginExecutor(meta, PluginExecutor.Special.Self); return new PluginExecutor(meta, PluginExecutor.Special.Self);
@ -932,8 +932,8 @@ namespace IPA.Loader
} }
catch (Exception e) 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; return null;
} }
@ -945,8 +945,8 @@ namespace IPA.Loader
} }
catch (Exception e) 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) 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) ignoredPlugins.Add(meta, new IgnoreReason(Reason.Error)
{ {
ReasonText = "Error occurred while initializing", ReasonText = "Error occurred while initializing",
@ -971,7 +971,7 @@ namespace IPA.Loader
{ {
if (!feature.TryCreate(out var inst)) 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 else
{ {
@ -988,8 +988,8 @@ namespace IPA.Loader
} }
catch (Exception e) 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; return exec;
@ -1016,8 +1016,8 @@ namespace IPA.Loader
} }
catch (Exception e) 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);
} }
} }


+ 19
- 19
IPA.Loader/Loader/PluginManager.cs View File

@ -153,8 +153,8 @@ namespace IPA.Loader
} }
catch (Exception e) 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 // this should still be considered enabled, hence its position
} }
} }
@ -215,7 +215,7 @@ namespace IPA.Loader
} }
catch (Exception e) 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); }, UnityMainThreadTaskScheduler.Default);
@ -442,26 +442,26 @@ namespace IPA.Loader
sw.Stop(); 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) 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) if (_ipaPlugins.Count > 0)
{ {
foreach (var plugin in _ipaPlugins) 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<Old.IPlugin> LoadPluginsFromFile(string file) private static IEnumerable<Old.IPlugin> LoadPluginsFromFile(string file)
@ -482,7 +482,7 @@ namespace IPA.Loader
} }
catch (Exception e) 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) 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<string>())}");
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<string>())}");
} }
catch (Exception e) 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; return ipaPlugins;


+ 1
- 1
IPA.Loader/Loader/manifest.json View File

@ -7,7 +7,7 @@
], ],
"id": "BSIPA", "id": "BSIPA",
"name": "Beat Saber IPA", "name": "Beat Saber IPA",
"version": "4.2.1-pre.2",
"version": "4.2.1-pre.3",
"icon": "IPA.icon_white.png", "icon": "IPA.icon_white.png",
"features": { "features": {
"IPA.DefineFeature": [ "IPA.DefineFeature": [


+ 15
- 13
IPA.Loader/Logging/Logger.cs View File

@ -1,6 +1,5 @@
using System;
// ReSharper disable InconsistentNaming
#nullable enable
using System;
namespace IPA.Logging namespace IPA.Logging
{ {
@ -9,9 +8,9 @@ namespace IPA.Logging
/// </summary> /// </summary>
public abstract class Logger public abstract class Logger
{ {
private static Logger _log;
private static Logger? _log;
internal static Logger log
internal static Logger Default
{ {
get get
{ {
@ -21,7 +20,7 @@ namespace IPA.Logging
} }
} }
private static StandardLogger _stdout;
private static StandardLogger? _stdout;
internal 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; internal static bool LogCreated => _log != null;
/// <summary> /// <summary>


+ 157
- 157
IPA.Loader/Logging/Printers/GZFilePrinter.cs View File

@ -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
{
/// <summary>
/// A <see cref="LogPrinter"/> abstract class that provides the utilities to write to a GZip file.
/// </summary>
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;
/// <summary>
/// The <see cref="StreamWriter"/> that writes to the GZip file.
/// </summary>
/// <value>the writer to the underlying filestream</value>
protected StreamWriter FileWriter;
private FileStream fstream;
/// <summary>
/// Gets the <see cref="FileInfo"/> for the file to write to.
/// </summary>
/// <returns>the file to write to</returns>
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();
}
/// <summary>
/// Called at the start of any print session.
/// </summary>
public sealed override void StartPrint()
{
InitLog();
fstream = fileInfo.Open(FileMode.Append, FileAccess.Write);
FileWriter = new StreamWriter(fstream, new UTF8Encoding(false));
}
/// <summary>
/// Called at the end of any print session.
/// </summary>
public sealed override void EndPrint()
{
FileWriter.Flush();
fstream.Flush();
FileWriter.Dispose();
fstream.Dispose();
FileWriter = null;
fstream = null;
}
/// <inheritdoc />
public void Dispose()
{
Dispose(true);
GC.SuppressFinalize(this);
}
/// <summary>
/// Disposes the file printer.
/// </summary>
/// <param name="disposing">does nothing</param>
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
{
/// <summary>
/// A <see cref="LogPrinter"/> abstract class that provides the utilities to write to a GZip file.
/// </summary>
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;
/// <summary>
/// The <see cref="StreamWriter"/> that writes to the GZip file.
/// </summary>
/// <value>the writer to the underlying filestream</value>
protected StreamWriter FileWriter;
private FileStream fstream;
/// <summary>
/// Gets the <see cref="FileInfo"/> for the file to write to.
/// </summary>
/// <returns>the file to write to</returns>
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();
}
/// <summary>
/// Called at the start of any print session.
/// </summary>
public sealed override void StartPrint()
{
InitLog();
fstream = fileInfo.Open(FileMode.Append, FileAccess.Write);
FileWriter = new StreamWriter(fstream, new UTF8Encoding(false));
}
/// <summary>
/// Called at the end of any print session.
/// </summary>
public sealed override void EndPrint()
{
FileWriter.Flush();
fstream.Flush();
FileWriter.Dispose();
fstream.Dispose();
FileWriter = null;
fstream = null;
}
/// <inheritdoc />
public void Dispose()
{
Dispose(true);
GC.SuppressFinalize(this);
}
/// <summary>
/// Disposes the file printer.
/// </summary>
/// <param name="disposing">does nothing</param>
protected virtual void Dispose(bool disposing)
{
if (disposing)
{
FileWriter.Flush();
fstream.Flush();
FileWriter.Close();
fstream.Close();
FileWriter.Dispose();
fstream.Dispose();
}
}
}
} }

+ 44
- 20
IPA.Loader/Logging/StdoutInterceptor.cs View File

@ -1,9 +1,11 @@
using HarmonyLib;
#nullable enable
using HarmonyLib;
using System; using System;
using System.Collections.Generic; using System.Collections.Generic;
using System.IO; using System.IO;
using System.Reflection.Emit; using System.Reflection.Emit;
using System.Text; using System.Text;
using static IPA.Logging.Logger;
namespace IPA.Logging namespace IPA.Logging
{ {
@ -19,7 +21,7 @@ namespace IPA.Logging
} }
private string lineBuffer = ""; private string lineBuffer = "";
private readonly object bufferLock = new object();
private readonly object bufferLock = new();
public override void Write(string value) public override void Write(string value)
{ {
@ -111,8 +113,8 @@ namespace IPA.Logging
return "\x1b[" + code + "m"; return "\x1b[" + code + "m";
} }
private static StdoutInterceptor stdoutInterceptor;
private static StdoutInterceptor stderrInterceptor;
private static StdoutInterceptor? stdoutInterceptor;
private static StdoutInterceptor? stderrInterceptor;
private static class ConsoleHarmonyPatches private static class ConsoleHarmonyPatches
{ {
@ -127,24 +129,24 @@ namespace IPA.Logging
try try
{ {
if (resetColor != null) 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) 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) catch (Exception e)
{ {
// Harmony might be fucked because of wierdness in Guid.NewGuid, don't let that kill us // 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<CodeInstruction> PatchGetForegroundColor(IEnumerable<CodeInstruction> _) public static IEnumerable<CodeInstruction> PatchGetForegroundColor(IEnumerable<CodeInstruction> _)
{ {
@ -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() public static void Intercept()
{ {
if (!usingInterceptor) if (!usingInterceptor)
{ {
usingInterceptor = true; 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(); RedirectConsole();
ConsoleHarmonyPatches.Patch(harmony); ConsoleHarmonyPatches.Patch(harmony);
@ -206,5 +208,27 @@ namespace IPA.Logging
Console.SetError(stderrInterceptor); 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);
};
}
} }
} }

+ 1
- 1
IPA.Loader/Utilities/CriticalSection.cs View File

@ -16,7 +16,7 @@ namespace IPA.Utilities
internal static void Configure() internal static void Configure()
{ {
Logger.log.Debug("Configuring exit handlers");
Logger.Default.Debug("Configuring exit handlers");
ResetExitHandlers(); ResetExitHandlers();
} }


+ 9
- 9
IPA.Loader/Utilities/UnityGame.cs View File

@ -27,7 +27,7 @@ namespace IPA.Utilities
internal static void SetEarlyGameVersion(AlmostVersion ver) internal static void SetEarlyGameVersion(AlmostVersion ver)
{ {
_gameVersion = 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 private static string ApplicationVersionProxy
{ {
@ -40,15 +40,15 @@ namespace IPA.Utilities
} }
catch(MissingMemberException ex) 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_) if (SelfConfig.Debug_.ShowHandledErrorStackTraces_)
Logging.Logger.log.Error(ex);
Logging.Logger.Default.Error(ex);
} }
catch (Exception 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_) if (SelfConfig.Debug_.ShowHandledErrorStackTraces_)
Logging.Logger.log.Error(ex);
Logging.Logger.Default.Error(ex);
} }
return string.Empty; return string.Empty;
} }
@ -60,18 +60,18 @@ namespace IPA.Utilities
var rtVer = new AlmostVersion(ApplicationVersionProxy); var rtVer = new AlmostVersion(ApplicationVersionProxy);
if (!rtVer.Equals(_gameVersion)) // this actually uses stricter equality than == for AlmostVersion 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; _gameVersion = rtVer;
} }
} }
catch (MissingMethodException e) 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_) if (SelfConfig.Debug_.ShowHandledErrorStackTraces_)
Logging.Logger.log.Error(e);
Logging.Logger.Default.Error(e);
var st = new StackTrace(); var st = new StackTrace();
Logging.Logger.log.Notice($"{st}");
Logging.Logger.Default.Notice($"{st}");
} }
} }


Loading…
Cancel
Save