BepInEx
Fail to create trampoline ONLY when AssemblyCache is enabled.
What happened?
Running a few server side mods for a V Rising server under wine on Linux and BepInEx pre1 (but is reproducible with other builds as well such as 577). I originally reported at the mod's repo here: https://github.com/decaprime/LeadAHorseToWater/issues/14 before starting to read code and documentation to understand implementations in order to debug. The plugin runs properly and bepinex log is clean on initial installation or after replacing the binary (which invalidates the cache).
If EnableAssemblyCache is set to false or I manually delete cache/chainloader_typeloader.dat before running the server everything works fine and the log is clean. There's something wrong with the caching of assembly metadata.
Steps to reproduce
- V Rising dedicated server under wine-devel from WineHQ
- EnableAssemblyCache=true
- Start the server with https://github.com/decaprime/LeadAHorseToWater mod
-
[Error : BepInEx] Error loading [LeadAHorseToWater 0.5.11]: HarmonyLib.HarmonyException: IL Compile Error (unknown location) ---> System.Exception: IP relative memory operand is too far away and isn't currently supported. Try to allocate memory close to the original instruction (+/-2GB).
BepInEx Distribution
BepInEx 6.0.0-pre.1
Log outputs
Log of the error:
[Message: Preloader] BepInEx 6.0.0-pre.1 - VRisingServer
[Info : BepInEx] System platform: Windows 7 64-bit
[Info : BepInEx] Process bitness: 64-bit (x64)
[Info : Preloader] Running under Unity v2020.3.31
[Info : Preloader] 0 patcher plugins loaded
[Info : Preloader] 0 assemblies discovered
[Message:AssemblyPatcher] Executing 0 patch(es)
[Message: BepInEx] Chainloader initialized
[Info :Unhollower] Registered mono type UnhollowerRuntimeLib.DelegateSupport+Il2CppToMonoDelegateReference in il2cpp domain
[Info : BepInEx] 7 plugins to load
[Info : BepInEx] Loading [CasualSiege 0.0.3]
[Info :CasualSiege] Plugin CasualSiege-v0.0.3 is loaded!
[Info : BepInEx] Loading [AutoCloseDoors 1.0.4]
[Info :AutoCloseDoors] Plugin AutoCloseDoors-v1.0.4 is loaded!
[Info : BepInEx] Loading [Wetstone 1.1.0]
[Info : Wetstone] Detouring ProjectM.ChatMessageSystem+__c__DisplayClass_ChatMessageJob.OriginalLambdaBody at 7F362C5682B0
[Info : Wetstone] Detouring NetworkEvents_Serialize.SerializeEvent at 7F362A58D6B0
[Info : Wetstone] Detouring NetworkEvents_Serialize.DeserializeEvent at 7F362A584510
[Info : Wetstone] Wetstone v1.1.0 loaded.
[Info : BepInEx] Loading [LeadAHorseToWater 0.5.11]
[Info :LeadAHorseToWater] 986517450 is stone well type
[Info :LeadAHorseToWater] 177891172 is large well type
[Info :LeadAHorseToWater] 1247163010 is iron well type
[Info :LeadAHorseToWater] 549920910 is small well type
[Error : BepInEx] Error loading [LeadAHorseToWater 0.5.11]: HarmonyLib.HarmonyException: IL Compile Error (unknown location) ---> System.Exception: IP relative memory operand is too far away and isn't currently supported. Try to allocate memory close to the original instruction (+/-2GB).
at BepInEx.IL2CPP.DetourGenerator.CreateTrampolineFromFunction (System.Byte[] instructionBuffer, System.IntPtr functionPtr, System.IntPtr trampolinePtr, System.Int32 minimumTrampolineLength, System.Runtime.InteropServices.Architecture arch, System.Int32& trampolineLength, System.Int32& jmpLength) [0x001bd] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.FastNativeDetour.GenerateTrampolineInner (System.Int32& trampolineLength, System.Int32& jmpLength) [0x0012c] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.FastNativeDetour.Apply (BepInEx.Logging.ManualLogSource debuggerLogSource) [0x000a6] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.FastNativeDetour.Apply () [0x00000] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.IL2CPPDetourMethodPatcher.DetourTo (System.Reflection.MethodBase replacement) [0x00086] in <e9997477cd8143c9a348224def0a337e>:0
at HarmonyLib.PatchFunctions.UpdateWrapper (System.Reflection.MethodBase original, HarmonyLib.PatchInfo patchInfo) [0x00033] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
--- End of inner exception stack trace ---
at HarmonyLib.PatchClassProcessor.ReportException (System.Exception exception, System.Reflection.MethodBase original) [0x00045] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.PatchClassProcessor.Patch () [0x00093] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.Harmony.<PatchAll>b__11_0 (System.Type type) [0x00007] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.CollectionExtensions.Do[T] (System.Collections.Generic.IEnumerable`1[T] sequence, System.Action`1[T] action) [0x00014] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.Harmony.PatchAll (System.Reflection.Assembly assembly) [0x00006] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.Harmony.PatchAll () [0x0001b] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at LeadAHorseToWater.Plugin.Load () [0x00049] in <1691a5df2c824ae18332d76d80e614ce>:0
at BepInEx.IL2CPP.IL2CPPChainloader.LoadPlugin (BepInEx.PluginInfo pluginInfo, System.Reflection.Assembly pluginAssembly) [0x00011] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.Bootstrap.BaseChainloader`1[TPlugin].LoadPlugins (System.Collections.Generic.IList`1[T] plugins) [0x0025c] in <16694cdb03bf4887828a298c286d045b>:0
[Info : BepInEx] Loading [Notify 1.4.7]
[Warning: Detour] Failed to init IL2CPP patch backend for void ProjectM.LoadPersistenceSystemV2::SetLoadState(ProjectM.ServerStartupState+State loadState), using normal patch handlers: IP relative memory operand is too far away and isn't currently supported. Try to allocate memory close to the original instruction (+/-2GB).
[Info :Unhollower] Registered mono type Notify.AutoAnnouncer.Timers.GameFrame in il2cpp domain
[Info : Notify] Plugin Notify is loaded!
[Info : BepInEx] Loading [VMods.BloodRefill 1.0.1]
[Info :VMods.BloodRefill] Plugin VMods.BloodRefill (v1.0.1) is loaded!
[Info : BepInEx] Loading [VMods.RecoverEmptyContainers 1.0.1]
[Info :VMods.RecoverEmptyContainers] Plugin VMods.RecoverEmptyContainers (v1.0.1) is loaded!
[Message: BepInEx] Chainloader startup complete
[Info : Wetstone] Game has bootstrapped. Worlds and systems now exist.
[Warning:AutoCloseDoors] All doors (Total: 114) has been set to auto close at 2s.
Clean log without assembly cache enabled:
[Message: Preloader] BepInEx 6.0.0-pre.1 - VRisingServer
[Info : BepInEx] System platform: Windows 7 64-bit
[Info : BepInEx] Process bitness: 64-bit (x64)
[Info : Preloader] Running under Unity v2020.3.31
[Info : Preloader] 0 patcher plugins loaded
[Info : Preloader] 0 assemblies discovered
[Message:AssemblyPatcher] Executing 0 patch(es)
[Message: BepInEx] Chainloader initialized
[Info :Unhollower] Registered mono type UnhollowerRuntimeLib.DelegateSupport+Il2CppToMonoDelegateReference in il2cpp domain
[Info : BepInEx] 7 plugins to load
[Info : BepInEx] Loading [CasualSiege 0.0.3]
[Info :CasualSiege] Plugin CasualSiege-v0.0.3 is loaded!
[Info : BepInEx] Loading [AutoCloseDoors 1.0.4]
[Info :AutoCloseDoors] Plugin AutoCloseDoors-v1.0.4 is loaded!
[Info : BepInEx] Loading [Wetstone 1.1.0]
[Info : Wetstone] Detouring ProjectM.ChatMessageSystem+__c__DisplayClass_ChatMessageJob.OriginalLambdaBody at 7F2042B582B0
[Info : Wetstone] Detouring NetworkEvents_Serialize.SerializeEvent at 7F2040B7D6B0
[Info : Wetstone] Detouring NetworkEvents_Serialize.DeserializeEvent at 7F2040B74510
[Info : Wetstone] Wetstone v1.1.0 loaded.
[Info : BepInEx] Loading [LeadAHorseToWater 0.5.11]
[Info :LeadAHorseToWater] 986517450 is stone well type
[Info :LeadAHorseToWater] 177891172 is large well type
[Info :LeadAHorseToWater] 1247163010 is iron well type
[Info :LeadAHorseToWater] 549920910 is small well type
[Info :LeadAHorseToWater] Plugin LeadAHorseToWater is loaded!
[Info : BepInEx] Loading [Notify 1.4.7]
[Info :Unhollower] Registered mono type Notify.AutoAnnouncer.Timers.GameFrame in il2cpp domain
[Info : Notify] Plugin Notify is loaded!
[Info : BepInEx] Loading [VMods.BloodRefill 1.0.1]
[Info :VMods.BloodRefill] Plugin VMods.BloodRefill (v1.0.1) is loaded!
[Info : BepInEx] Loading [VMods.RecoverEmptyContainers 1.0.1]
[Info :VMods.RecoverEmptyContainers] Plugin VMods.RecoverEmptyContainers (v1.0.1) is loaded!
[Message: BepInEx] Chainloader startup complete
[Info : Wetstone] Game has bootstrapped. Worlds and systems now exist.
[Info : Notify] GameData Init
[Info :VRising.GameData] GameData initialized
[Warning:AutoCloseDoors] All doors (Total: 114) has been set to auto close at 2s.
Environment
- OS: Fedora 36
- BepInEx: BepInEx 6 pre1
- Game: V Rising Dedicated Server
If I understand the issue correctly (I come from a native code RE background and have barely touched .NET, so correct me if I'm wrong) the trampoline function is being created beyond +/-2GB offset which breaks relative addressing due to the size of the instruction pointer (I'm guessing 32bit by the 2GB signed number). It does happen only when the assembly cache is enabled though which points to an issue in logic when read from cache (different engine used? cecil?) or maybe an issue with Cpp2IL saving of the metadata?
Further debugging. Enabling [HarmonyDebug]
Clean output:
[Info : BepInEx] Loading [LeadAHorseToWater 0.5.11]
[Info :LeadAHorseToWater] 986517450 is stone well type
[Info :LeadAHorseToWater] 177891172 is large well type
[Info :LeadAHorseToWater] 1247163010 is iron well type
[Info :LeadAHorseToWater] 549920910 is small well type
[Info : HarmonyX] Patching virtual void ProjectM.FeedableInventorySystem_Update::OnUpdate() with 1 prefixes, 0 postfixes, 0 transpilers, 0 finalizers
1 prefixes:
* static void LeadAHorseToWater.FeedSystemUpdatePatch::Prefix(ProjectM.FeedableInventorySystem_Update __instance)
[Info : HarmonyX] Running ILHook manipulator on virtual void ProjectM.FeedableInventorySystem_Update::OnUpdate()
[Info : HarmonyX] Writing prefixes
[Info : HarmonyX] Patching static void ProjectM.PlaceTileModelSystem::ClearEditing(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Moving(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character)
[Info : HarmonyX] Running ILHook manipulator on static void ProjectM.PlaceTileModelSystem::ClearEditing(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character)
[Info : HarmonyX] Writing postfixes
[Info : HarmonyX] Patching static bool ProjectM.PlaceTileModelSystem::VerifyCanBuildTileModels(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Destroying(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character)
[Info : HarmonyX] Running ILHook manipulator on static bool ProjectM.PlaceTileModelSystem::VerifyCanBuildTileModels(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character)
[Info : HarmonyX] Writing postfixes
[Info : HarmonyX] Patching bool ProjectM.PlaceTileModelSystem::HasUnlockedBlueprint(Unity.Entities.Entity user, ProjectM.PrefabGUID prefabGuid, Unity.Entities.Entity prefab) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Building(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.Entity user, ProjectM.PrefabGUID prefabGuid, Unity.Entities.Entity prefab)
[Info : HarmonyX] Running ILHook manipulator on bool ProjectM.PlaceTileModelSystem::HasUnlockedBlueprint(Unity.Entities.Entity user, ProjectM.PrefabGUID prefabGuid, Unity.Entities.Entity prefab)
[Info : HarmonyX] Writing postfixes
[Info :LeadAHorseToWater] Plugin LeadAHorseToWater is loaded!
Failure with assembly cache:
[Info : BepInEx] Loading [LeadAHorseToWater 0.5.11]
[Info :LeadAHorseToWater] 986517450 is stone well type
[Info :LeadAHorseToWater] 177891172 is large well type
[Info :LeadAHorseToWater] 1247163010 is iron well type
[Info :LeadAHorseToWater] 549920910 is small well type
[Info : HarmonyX] Patching virtual void ProjectM.FeedableInventorySystem_Update::OnUpdate() with 1 prefixes, 0 postfixes, 0 transpilers, 0 finalizers
1 prefixes:
* static void LeadAHorseToWater.FeedSystemUpdatePatch::Prefix(ProjectM.FeedableInventorySystem_Update __instance)
[Info : HarmonyX] Running ILHook manipulator on virtual void ProjectM.FeedableInventorySystem_Update::OnUpdate()
[Info : HarmonyX] Writing prefixes
[Info : HarmonyX] Patching static void ProjectM.PlaceTileModelSystem::ClearEditing(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Moving(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character)
[Info : HarmonyX] Running ILHook manipulator on static void ProjectM.PlaceTileModelSystem::ClearEditing(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character)
[Info : HarmonyX] Writing postfixes
[Info : HarmonyX] Patching static bool ProjectM.PlaceTileModelSystem::VerifyCanBuildTileModels(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Destroying(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character)
[Info : HarmonyX] Running ILHook manipulator on static bool ProjectM.PlaceTileModelSystem::VerifyCanBuildTileModels(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character)
[Info : HarmonyX] Writing postfixes
[Error : BepInEx] Error loading [LeadAHorseToWater 0.5.11]: HarmonyLib.HarmonyException: IL Compile Error (unknown location) ---> System.Exception: IP relative memory operand is too far away and isn't currently supported. Try to allocate memory close to the original instruction (+/-2GB).
at BepInEx.IL2CPP.DetourGenerator.CreateTrampolineFromFunction (System.Byte[] instructionBuffer, System.IntPtr functionPtr, System.IntPtr trampolinePtr, System.Int32 minimumTrampolineLength, System.Runtime.InteropServices.Architecture arch, System.Int32& trampolineLength, System.Int32& jmpLength) [0x001bd] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.FastNativeDetour.GenerateTrampolineInner (System.Int32& trampolineLength, System.Int32& jmpLength) [0x0012c] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.FastNativeDetour.Apply (BepInEx.Logging.ManualLogSource debuggerLogSource) [0x000a6] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.FastNativeDetour.Apply () [0x00000] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.IL2CPP.Hook.IL2CPPDetourMethodPatcher.DetourTo (System.Reflection.MethodBase replacement) [0x00086] in <e9997477cd8143c9a348224def0a337e>:0
at HarmonyLib.PatchFunctions.UpdateWrapper (System.Reflection.MethodBase original, HarmonyLib.PatchInfo patchInfo) [0x00033] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
--- End of inner exception stack trace ---
at HarmonyLib.PatchClassProcessor.ReportException (System.Exception exception, System.Reflection.MethodBase original) [0x00045] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.PatchClassProcessor.Patch () [0x00093] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.Harmony.<PatchAll>b__11_0 (System.Type type) [0x00007] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.CollectionExtensions.Do[T] (System.Collections.Generic.IEnumerable`1[T] sequence, System.Action`1[T] action) [0x00014] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.Harmony.PatchAll (System.Reflection.Assembly assembly) [0x00006] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at HarmonyLib.Harmony.CreateAndPatchAll (System.Reflection.Assembly assembly, System.String harmonyInstanceId) [0x0001e] in <e91f9877f5984f8e82e24dfb4afeb4ec>:0
at LeadAHorseToWater.Plugin.Load () [0x0003f] in <3271e49d9cbe46379f6b17e0e488f2fe>:0
at BepInEx.IL2CPP.IL2CPPChainloader.LoadPlugin (BepInEx.PluginInfo pluginInfo, System.Reflection.Assembly pluginAssembly) [0x00011] in <e9997477cd8143c9a348224def0a337e>:0
at BepInEx.Bootstrap.BaseChainloader`1[TPlugin].LoadPlugins (System.Collections.Generic.IList`1[T] plugins) [0x0025c] in <16694cdb03bf4887828a298c286d045b>:0
This points to this specific patch failing: https://github.com/decaprime/LeadAHorseToWater/blob/d3d9fb82d154b0e8d07fbeb84da8c09dc477933f/PlaceTileModelSystem_Patches.cs#L33-L42
I patched the mod using Wetstone's IRunOnInitialized and moved HarmonyX patching into public void OnGameInitialized() now the mod patches properly with assembly cache enabled as well. BUT there is still some underlying issue with the assembly cache. Is it a race condition? Earlier entrypoint when cache is available?
[Info : Wetstone] Wetstone v1.1.0 loaded.
[Info : BepInEx] Loading [LeadAHorseToWater 0.5.11]
[Info :LeadAHorseToWater] 986517450 is stone well type
[Info :LeadAHorseToWater] 177891172 is large well type
[Info :LeadAHorseToWater] 1247163010 is iron well type
[Info :LeadAHorseToWater] 549920910 is small well type
[Info : BepInEx] Loading [Notify 1.4.7]
[Info :Unhollower] Registered mono type Notify.AutoAnnouncer.Timers.GameFrame in il2cpp domain
[Info : Notify] Plugin Notify is loaded!
[Info : BepInEx] Loading [VMods.BloodRefill 1.0.1]
[Info :VMods.BloodRefill] Plugin VMods.BloodRefill (v1.0.1) is loaded!
[Info : BepInEx] Loading [VMods.RecoverEmptyContainers 1.0.1]
[Info :VMods.RecoverEmptyContainers] Plugin VMods.RecoverEmptyContainers (v1.0.1) is loaded!
[Message: BepInEx] Chainloader startup complete
[Info : Wetstone] Game has bootstrapped. Worlds and systems now exist.
[Info : HarmonyX] Patching virtual void ProjectM.FeedableInventorySystem_Update::OnUpdate() with 1 prefixes, 0 postfixes, 0 transpilers, 0 finalizers
1 prefixes:
* static void LeadAHorseToWater.FeedSystemUpdatePatch::Prefix(ProjectM.FeedableInventorySystem_Update __instance)
[Info : HarmonyX] Running ILHook manipulator on virtual void ProjectM.FeedableInventorySystem_Update::OnUpdate()
[Info : HarmonyX] Writing prefixes
[Info : HarmonyX] Patching static void ProjectM.PlaceTileModelSystem::ClearEditing(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Moving(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character)
[Info : HarmonyX] Running ILHook manipulator on static void ProjectM.PlaceTileModelSystem::ClearEditing(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity tileModelEntity, Unity.Entities.Entity character)
[Info : HarmonyX] Writing postfixes
[Info : HarmonyX] Patching static bool ProjectM.PlaceTileModelSystem::VerifyCanBuildTileModels(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Destroying(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character)
[Info : HarmonyX] Running ILHook manipulator on static bool ProjectM.PlaceTileModelSystem::VerifyCanBuildTileModels(Unity.Entities.EntityManager entityManager, Unity.Entities.Entity character)
[Info : HarmonyX] Writing postfixes
[Info : HarmonyX] Patching bool ProjectM.PlaceTileModelSystem::HasUnlockedBlueprint(Unity.Entities.Entity user, ProjectM.PrefabGUID prefabGuid, Unity.Entities.Entity prefab) with 0 prefixes, 1 postfixes, 0 transpilers, 0 finalizers
1 postfixes:
* static void LeadAHorseToWater.PlaceTileModelSystem_Patches::Building(ProjectM.PlaceTileModelSystem __instance, Unity.Entities.Entity user, ProjectM.PrefabGUID prefabGuid, Unity.Entities.Entity prefab)
[Info : HarmonyX] Running ILHook manipulator on bool ProjectM.PlaceTileModelSystem::HasUnlockedBlueprint(Unity.Entities.Entity user, ProjectM.PrefabGUID prefabGuid, Unity.Entities.Entity prefab)
[Info : HarmonyX] Writing postfixes
[Info :LeadAHorseToWater] Plugin LeadAHorseToWater is loaded!
It does happen only when the assembly cache is enabled though which points to an issue in logic when read from cache (different engine used? cecil?) or maybe an issue with Cpp2IL saving of the metadata?
The cache file is only for plugin metadata, my guess would be that it's existence simply leads to different methods being JITd at different times, which leads to hitting this failure when Iced re-assembles. I'm not really sure how this could be fixed either, other than maybe changing AllocateChunk to search behind the page instead of only in front of it, to have better chances of existing within the 2GB radius.
I know it's only for metadata, which begs the question on why reading cached metadata instead of generating them again would cause this. I have not dived too deep into the code (yet) but it does sound like a race condition. Shouldn't the actual patching process happen the exact same way regardless on if the metadata were just generated or being already available in cache?
Regarding AllocateChunk() that is probably a good idea in general. Change the logic so that it starts looking from -2GB up to +2GB and fail there if it can't find a hole because relative addressing will fail anyhow otherwise.
I know it's only for metadata, which begs the question on why reading cached metadata instead of generating them again would cause this.
As C# is compiled to assembly Just-In-Time, a change in execution order of methods (like what happens when it finds the cache file) can cause methods to get turned into assembly in a different order, which leads to a different memory layout. I doubt the caching itself is doing it, and it is likely a coincidence that removing the cache changes the order of execution enough to make the memory for the trampolines able to fit within that required +-2GB.
I'm not saying it couldn't be something else, just that the cache itself really has no way to be the cause, and the unpredictability of the JIT allows for this possibility.
I agree that while caching is not really the cause, the extra methods that are jitted with it disabled likely alters memory layout enough for the basic memory slot searching work.
Hooking was considerably changed after pre.1 (in other words in all be.6xx builds) so the issue is most likely fixed now. I'll try to verify this by making a basic plugin for be.6xx that applies the patches shown in logs). If this works fine on BE builds, I'll probably close this since there are no plans on working on the pre.1 codebase and the old native hooking that it uses.
I know that C# is JITed. What I do not understand, probably because I have not read that part of the code yet -- although I have much better understanding now than before I opened this issue, is the implementation. I would assume that it was something like: metadata generated or read from cache, then as assemblies are loaded, hooking takes place by parsing the mod patch directives and creating trampolines. I mean the order should not, in theory, change. Shouldn't the mapping in memory be identical in both cases? By @ghorsington 's answer I see that there are extra methods JITed when the cache is not enabled? Why? (This is may be getting a bit off scope but I want to understand the implementation.)
I also agree that if it works on BE builds there's no point fixing it in the old hooking implementation.
EDIT: Also I would appreciate it if you can point me to the related code at pre1 commit to read.
The issue is not the implementation but likely the fact that when cache is not generated, a lot more code is being executed which causes different methods to be jitted, in turn affecting how hooking works. If anything, I'd be looking at the original implementation of native detouring that we had in pre.1: it works by looking for "holes" of free memory within the +-2GB memory range of certain size. More likely is that JITting all the extra methods with the cache disabled (and there are a lot, but mostly on Mono.Cecil side) causes such allocations that the very basic pre.1 detour implementation works better with.
TL;DR: I'd actually look into the pre.1's memory allocator, enabling/disabling cache is most likely a red herring since its code is unrelated to how memory is allocated -- but disabling cache affects what methods are jitted and in turn the final location of methods. JITter also doesn't place methods in the same addresses between runs, so technically memory layout is never the same either.
If you really want to debug it for some reason, I'd look at the allocator implementation and debug that. In fact, that's the place where you'd also have to write a fix too. That said, be.6xx uses a proper hooking library instead which has much more elaborate logic for memory allocation. Therefore it's probably easier to verify that the issue doesn't persist on master before going forward with anything else.
I do not want to debug it, in fact I was talking with members of the VR mod community regarding a push to the new BE builds with the new hooking implementation. So if things break there we actually work with the current builds, debug and possibly contribute PRs as well while obviously utilizing the better hooking lib. Working with the outdated builds that won't get fixes, because the old hooking engine has been deprecated, is not a good idea. And neither is maintaining a fork at pre.1.
What I am interested though, as an engineer, is learning exactly how and why it happens, as like I said, although I have extensive native code RE background, I have only barely touched the internals of .NET. I'm actually interested in the part before the allocator, as what the allocator does is kind of common practice in patching code caves etc. I wanted to understand why the behavior is different between the two cases, why a hole doesn't exist at +2GB (it's not searching the entire possible space) address space on one case while it does on the other and that being a 100% reproducible scenario (at least on my system).
I did a bit of research the past couple of days on the internals of the JIT compiler and I think I have a better understanding now on why it's different. So please correct me if I'm wrong but I believe that this happens because without the cache, during the metadata extraction process, all assemblies are loaded which causes .NET to JIT x methods it decides it must but when the cache is utilized, assemblies are loaded as needed, which causes the JIT compiler to JIT dependency methods from the call tree on the spot and in this particular case a lot of the methods JITed are methods that were already JITed in the uncached scenario, by the time our method is JITed. Those methods now all end up allocated in front of the offset of the method we're hooking, which ends up with the allocator not finding a hole. If this theory is correct, academically speaking, we could avoid this behavior by building a dependency call tree from the methods we're hooking, sort it in a special way, load dependency assemblies if not loaded and force the JIT compiler to AOT JIT dependency methods by calling something like System.Runtime.CompilerServices.RuntimeHelpers.PrepareMethod() on them, leaving our "top/to-be-hooked" methods as "last" as possible.
EDIT: I will soon try to replicate this with BE nightlies and close this if I can't.
I'm actually interested in the part before the allocator, as what the allocator does is kind of common practice in patching code caves etc. I wanted to understand why the behavior is different between the two cases, why a hole doesn't exist at +2GB (it's not searching the entire possible space) address space on one case while it does on the other and that being a 100% reproducible scenario (at least on my system).
Fair, though from the actual perspective of the issue at hand, I'd indeed look at the allocator first since the implementation is fairly naive compared to what we have in current master. My guess is that the current logic for just looking at "free" pages is not really enough for this case. The new lib we use for native detouring (Dobby) does some extra work of also looking for space that looks unused even if the page is already reserved.
You're free to test, debug and theorise, and I welcome you to join BepInEx Discord for discussion there. As this is just an issue tracker, I'll just look at whether this is an issue we need to really address before dwelling deeper.
I now tested the original LeadAHorseToWater (specifically commit d3d9fb82d154b0e8d07fbeb84da8c09dc477933f which was before the PR that reportedly fixes the issue) on the latest BE. From my quick tests, it and Wetstone apply patches fine, although I didn't test the plugin's functionality. For reference, here are both DLLs converted to work with latest BE
(not adding source as it's a bit of a custom mess to get it built; the process of converting is generally straightforward).
Mind giving it a test when you have a moment and verify that the server boots up for you too without crashing?