[LIB] ModCheck: patch tests and error logging for mod loading

Started by Nightinggale, October 31, 2017, 06:57:04 PM

Previous topic - Next topic

Nightinggale

Quote from: SargBjornson on June 18, 2018, 02:15:43 PM
Keep us informed! I hope Tynan can patch things up
Current status is that I received feedback on my feedback. The method in question changed and is updated in the next build. I'm told to report back if it's not enough to do what I want to do. Looks like we will keep ModCheck in RW 1.0  :)

I have no ETA for the next release though, partly due to not having seen the next build yet, partly because I know I more or less will have to modify the core of ModCheck. However it looks like it requires a lot of work (time) and I will likely end up releasing a partial version with the most used operations out ASAP. That way I will likely not hold back releases of other mods while I figure out how to get everything working perfectly as well as fully optimized to the new RW 1.0 code design (which is essentially a rewrite).
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

Build 1939 appears to have solved the issue. In fact everything without any exceptions related to xml loading and patching has become fully modable, which is even better than B18  :D

The situation is this. Vanilla patching approach:

B18:

  • Defs files loaded
  • Patching each file
  • Merge files

1.0:

  • Defs files loaded
  • Merge files
  • Patching the now single file

The reason for this change is that XPATH is by far the slowest part and by using it on just one file, the number of XPATH calls is reduced alot, which translates to faster patching. The problem is that this one file is huge compared to the multi file approach of B18 (and A17).

My plan:

  • Defs files loaded
  • Patching each file (ModCheckPatches)
  • Merge files
  • Patching the now single file (Patches)
My splitting patches into two folders, it will be possible to have vanilla patching and B18 style patching working side by side. This way mods using ModCheck will be able to use FindFile, which should still be significantly faster than even the new vanilla. Both approaches will then use a single XPATH search, but the performance difference lies in the fact that ModCheck will use the search a much smaller file. Mods not using ModCheck will use the new vanilla code and benefit from the improved performance.

All operations will work in both patch folders and both will be profiled. However the vanilla one will keep file and modName blank for obvious reasons, meaning features relying on those will not really work. This completely destroys the idea of FindFile, but it will technically still work. It just compares against empty strings.

Still no ETA on this, but I have a plan and I have made vanilla support the plan. That's way better than yesterday.
ModCheck - boost your patch loading times and include patchmods in your main mod.


Nightinggale

#78
I made a pre-release version for RW 1.0. It can be downloaded here. It's linked against the new Harmony 1.1.0, which I added to git here.

Do note that being a pre-release it's not intended to be released with other mods. It's purely intended to allow other mods to be tested with RimWorld 1.0 even if they use ModCheck. Testing is limited, but it passed the automated test. FindFile is broken for the time being and will always be true.

Now I will carry on to implement B18 style patching and generally optimize for the new conditions present in RW1.0.
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

I just committed a new version, which can be downloaded with the link from the last post. ModCheck now reads patches in ModCheckPatches and apply them to each xml file individually, just like B18. Patches are still applied by vanilla code. All PatchOperations work in both places. ModCheck.FindFile works again, though it only makes sense to use it in ModCheckPatches. Profiling adds M or P to tell which folder each patch is located in.

I haven't tested it much yet and as such it's still not ready for a real release. I have rewritten most of the harmony interface and the internal memory/cache in order to handle the new vanilla code and two locations for patches. As a result, it really should be tested well. The individual PatchOperations are however untouched.

Feel free to report back what works and what doesn't.
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

I pushed a new version. This time I fixed a crashing bug for empty patch folders and improved profiling.

However now I ran into an unexpected issue. I made a simple patch, which changes the construction cost of a building. This resulted in the following profiling.





B18 patching
20 ms
B18 patching with FindFile
14.5 ms
1.0 vanilla patching
0.065 ms
new operation (see below)
0.044 ms
This made me suspect something is wrong with my approach and I tried B18 style patching with an empty sequence and it turns out patching that one takes 0.3 ms or almost 5 times as long as applying the patch using the new 1.0 style patching. I honestly did not expect that or the big difference between B18 and 1.0. It would appear vanilla code itself is 300 times faster. I'm considering removing FindFile and B18 style patching, but since it works, I might as well keep it and see what happens with hundreds of patches when those are available.


I did however finally implement the last operation I have been thinking of regarding performance boosting.
<li Class="ModCheck.tmp">
<xpath>Defs/ThingDef[defName="WatermillGenerator"]</xpath>
<operation Class="PatchOperationReplace">
<xpath>Defs/tmp/ThingDef/costList/WoodLog</xpath>
<value>
<WoodLog>100</WoodLog>
</value>
</operation>
</li>

What it does is it makes the search and for each found xml node, it moves that node into Defs/tmp, calls operation and then it moves the node back. The result is that when operation is called, Defs/tmp will only contain a single node and as such xpath can use a fixed path without any searching. This simplifies the xpath search and as the table shows, this is even faster than vanilla patching. Even better, if operation is a sequence, multiple patching can be done on the same node (in this case ThingDef). I can't really tell the time difference between patching one or 3 values, meaning I can patch all 3 cost values for less than it takes to change even just one using pure vanilla operations.

This leaves one question: what should the new operation be called? And what should the temporal path be called?
Right now I can't think of a good name. Hopefully somebody else can come up with something, which doesn't seem to be disconnected from the functionality.
ModCheck - boost your patch loading times and include patchmods in your main mod.

larSyn

Hey Nightinggale

I don't have a name for the new operation, but I wanted to ask if this new operation is more efficient than findFile?  Now that B19 is official I wanted to get to work on the updates for my mods that use Modcheck, and everything uses findFile.  I am just wondering if there is going to need to be significant changes to my patches, as there are a lot of them.

And, thanks for keeping modcheck going.  SI is pretty much designed to work with it now and I'd hate to rewrite all of it using the vanilla system.  :)

Edit:  I'm also getting an error anytime I use the .isModLoaded and .findFile together.  See the code below for how I had it written for B18 (this is how I was modifying my mods files in the presence of other mods)
<Operation Class="PatchOperationSequence">
<success>Always</success>
<operations>
<li Class="ModCheck.isModLoaded">
<modName>VGP Garden Gourmet</modName>
<yourMod>Smokeleaf Industry</yourMod>
</li>
                        <li Class="ModCheck.FindFile">
                                <modName>Smokeleaf Industry</modName>
                                <file>MSI_Items_Edibles.xml</file>
                        </li>
<li Class="PatchOperationReplace">
<xpath>Defs/ThingDef[defName = "HempFlour"]/thingCategories</xpath>
<value>
<thingCategories>
<li>CookingSupplies</li>
</thingCategories>
</value>
</li>
<li Class="PatchOperationReplace">
<xpath>Defs/ThingDef[defName = "HempMilk"]/thingCategories</xpath>
<value>
<thingCategories>
<li>CookingSupplies</li>
</thingCategories>
</value>
</li>
<li Class="PatchOperationReplace">
<xpath>Defs/ThingDef[defName = "SmokeleafSeedOil"]/thingCategories</xpath>
<value>
<thingCategories>
<li>CookingSupplies</li>
</thingCategories>
</value>
</li>
<li Class="PatchOperationReplace">
<xpath>Defs/ThingDef[defName = "SmokeleafButter"]/thingCategories</xpath>
<value>
<thingCategories>
<li>CookingSupplies</li>
</thingCategories>
</value>
</li>
</operations>
</Operation>


Here's the error from the debug window:
[Smokeleaf Industry] Patch operation Verse.PatchOperationSequence(count=6) failed
file: C:\Games\Steam\steamapps\common\RimWorld\Mods\Smokeleaf_Industry\Patches\Vegetable Garden Patches\SmokeleafInd-VG_ediblesPatch.xml
Verse.Log:Error(String, Boolean)
Verse.PatchOperation:Complete(String)
Verse.PatchOperationSequence:Complete(String)
Verse.LoadedModManager:ClearCachedPatches()
Verse.LoadedModManager:LoadAllActiveMods()
Verse.PlayDataLoader:DoPlayLoad()
Verse.PlayDataLoader:LoadAllPlayData(Boolean)
Verse.Root:<Start>m__1()
Verse.LongEventHandler:RunEventFromAnotherThread(Action)
Verse.LongEventHandler:<UpdateCurrentAsynchronousEvent>m__1()


Edit 2:  Also getting these two errors:
Error while instantiating a mod of type ModCheck.HarmonyStarter: System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.MissingMethodException: Method not found: 'Verse.Log.Error'.
  at ModCheck.HarmonyStarter..ctor (Verse.ModContentPack content) [0x00000] in <filename unknown>:0
  at (wrapper managed-to-native) System.Reflection.MonoCMethod:InternalInvoke (object,object[],System.Exception&)
  at System.Reflection.MonoCMethod.Invoke (System.Object obj, BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00000] in <filename unknown>:0
  --- End of inner exception stack trace ---
  at System.Reflection.MonoCMethod.Invoke (System.Object obj, BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00000] in <filename unknown>:0
  at System.Reflection.MonoCMethod.Invoke (BindingFlags invokeAttr, System.Reflection.Binder binder, System.Object[] parameters, System.Globalization.CultureInfo culture) [0x00000] in <filename unknown>:0
  at System.Activator.CreateInstance (System.Type type, BindingFlags bindingAttr, System.Reflection.Binder binder, System.Object[] args, System.Globalization.CultureInfo culture, System.Object[] activationAttributes) [0x00000] in <filename unknown>:0
  at System.Activator.CreateInstance (System.Type type, System.Object[] args, System.Object[] activationAttributes) [0x00000] in <filename unknown>:0
  at System.Activator.CreateInstance (System.Type type, System.Object[] args) [0x00000] in <filename unknown>:0
  at Verse.LoadedModManager.CreateModClasses () [0x00000] in <filename unknown>:0
Verse.Log:Error(String, Boolean)
Verse.LoadedModManager:CreateModClasses()
Verse.LoadedModManager:LoadAllActiveMods()
Verse.PlayDataLoader:DoPlayLoad()
Verse.PlayDataLoader:LoadAllPlayData(Boolean)
Verse.Root:<Start>m__1()
Verse.LongEventHandler:RunEventFromAnotherThread(Action)
Verse.LongEventHandler:<UpdateCurrentAsynchronousEvent>m__1()


Error in patch.Apply(): System.MissingMethodException: Method not found: 'Verse.Log.Message'.
  at ModCheck.ModCheckLog.printLogMessages (Boolean success) [0x00000] in <filename unknown>:0
  at ModCheck.ModCheckBase.ApplyWorker (System.Xml.XmlDocument xml) [0x00000] in <filename unknown>:0
  at Verse.PatchOperation.Apply (System.Xml.XmlDocument xml) [0x00000] in <filename unknown>:0
  at Verse.PatchOperationSequence.ApplyWorker (System.Xml.XmlDocument xml) [0x00000] in <filename unknown>:0
  at Verse.PatchOperation.Apply (System.Xml.XmlDocument xml) [0x00000] in <filename unknown>:0
  at Verse.LoadedModManager.ApplyPatches (System.Xml.XmlDocument xmlDoc, System.Collections.Generic.Dictionary`2 assetlookup) [0x00000] in <filename unknown>:0
Verse.Log:Error(String, Boolean)
Verse.LoadedModManager:ApplyPatches(XmlDocument, Dictionary`2)
Verse.LoadedModManager:LoadAllActiveMods()
Verse.PlayDataLoader:DoPlayLoad()
Verse.PlayDataLoader:LoadAllPlayData(Boolean)
Verse.Root:<Start>m__1()
Verse.LongEventHandler:RunEventFromAnotherThread(Action)
Verse.LongEventHandler:<UpdateCurrentAsynchronousEvent>m__1()






Fuglypump

Pretty much have my mods stuck on hold to update for B19 until modcheck is updated, the B18 .dll does not seem to work properly for B19

Nightinggale

ModCheck 1.8 has been released. The main change is B19 support and dropped support for B18.

Vanilla made a complete rewrite of xml loading from mods, meaning ModCheck had to be partially rewritten too. Now all files are read, merged into one giant xml file and then patched. This is a great move because it's much faster, even faster than ModCheck could make B18. However since there is no longer an owner of the file being patched, FindFile is dead. I did work on preserving it, but it didn't turn out well and actually slowed down patching. You will have to rewrite FindFile to either not use it at all or use the other operations to test for presence of other mods.

I added a search operation. It's used like this:
<li Class="ModCheck.Search">
<xpath>Defs/ThingDef[defName="WatermillGenerator"]</xpath>
<operations>
same code as a sequence
</operations>

What it does is whatever it finds will be moved to Defs/SearchResult/ThingDef and then back once operations are done. This mean xpaths can use "Defs/SearchResult/ThingDef" instead of "Defs/ThingDef[defName="WatermillGenerator"]". It has an overhead in setting up, which is around 2.5-2.7 xpath searches (at least if only vanilla is loaded). However if you need to do 3 modifications it will be faster because "Defs/SearchResult/ThingDef" is following a path, not a search. If you need to do 4 operations, it's still faster than 3 vanilla operations with a searching xpath. In other words it's a performance boosting tool for the cases where you need to do a bunch of operations to the same item.

I also added the Move operation.
<Operation Class="ModCheck.Move">
<xpath>Defs/ThingDef[defName="SolarGenerator"]</xpath>
<followers>
<li>Defs/ThingDef[defName="AdvancedSolarGenerator"]</li>
</followers>
</Operation>

This will make use of the fact that it's now one big xml file. What is does is that it will find xpath and then it will take whatever is in followers (it's a list of unlimited size) and move the elements to be right after the xpath element. In this specific case it will move AdvancedSolarGenerator to be next to SolarGenerator. If multiple followers are added, they will be added in the order they are written. This should allow placing the buildings in useful groupings rather than the vanilla approach, which is semi random based on load order.
ModCheck - boost your patch loading times and include patchmods in your main mod.

larSyn


hauvega

Thanks Nightinggale.  This mod has help in patching everything in one mod instead of a bunch of separate mods.

Work on mod
Break mod
Fix Mod
Break mod again

ilikegoodfood

#87
Hey folks.

I've finally reached the final stage of updating my one and only mod to b19; compatibility. I'm trying to understand what changes I'll need to make in order to get my patches working as smoothly as possible. Having read through the conversation, I have extracted the following information:


  • ModCheck.FindFile is no longer necessary at all, and can simply be removed.
  • Change <errorOnFail> Log Outputs to <errorFail>.
  • If performing three or more operations on a single def, use ModCheck.Search to increase performance. The absolute patch is then Defs/SearchResult/ThingDef.

Is that correct, and is that all I need to do?
I've already updated ModCheck and it works, but I need to rebuild some of it anyway, so I should tidy up as I do so.

Thanks.

Nightinggale

Quote from: ilikegoodfood on October 07, 2018, 09:29:37 AM
2. Performing ModCheck.isModLoaded, immediately followed by ModCheck.loadOrder causes ModCheck.LoadOrder to fail. Does anyone have a fix for this?
Huh  :o
The checks themselves shouldn't influence each other at all, other than the obvious failure stops sequence.

  • IsModLoaded
  • LoadOrder
If the mod isn't loaded, LoadOrder is never called. If the mod is loaded, LoadOrder should be called just like IsModLoaded isn't there at all. If you managed to get it to do anything else, then do tell about it.

Quote from: ilikegoodfood on October 07, 2018, 09:29:37 AM3. If performing three or more operations on a single def, use ModCheck.Search to increase performance. The absolute patch is then Defs/SearchResult/ThingDef.
Yeah that's pretty much it. However like with everything else regarding performance you should likely test the result to see if you get the expected result.

Also remember the wiki on GitHub has a full list of operations, complete with explanations of each possible tag for each and how to use it.
ModCheck - boost your patch loading times and include patchmods in your main mod.

ilikegoodfood

#89
I have found the error. The XML for the fail message used to be <errorOnFail>Message</erroronFail>, but it is now just <errorFail>Message</errorFail>. It's my version of the command that is outdated and broken.

EDIT: Various small changes to the way patches are labelled now all fixed and restructured. It works perfectly. Thanks.