[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: larSyn on November 15, 2017, 10:18:53 AMYeah, Steam seems to be the place to post mods.  I got far more users there than from here.  But, that's all right, I like it here.  Lots of helpful, friendly people.
I realize that's the case for players, but it has turned out it's the case for modders as well.

Quote from: larSyn on November 15, 2017, 10:18:53 AMThe only bit of trouble I had was which mod name to use, the folder name or the name in About.xml.  I obviously figured it out, but maybe you should throw that in the guide on your Github page to prevent any future confusion.  Other than that, everything was very easy to follow.
Updated and good point. At the time ModCheck activates, it only has access to xml contents and is not really aware of folder or filenames. Well it might be aware of other stuff, but I haven't found out yet. This makes it obvoius that it's the name inside an xml file. I tried to write the guide to not require any knowledge of how the code works, but it seems I missed this one.

Quote from: larSyn on November 15, 2017, 10:18:53 AMThat sounds good.  I was going to ask about the patch operation staying the same, since I don't really want to go back and rewrite it all...lol 
Completely as expected  ;D

The thing is that now ModCheck is on steam and for all I know modders will start to depend on the user adding ModCheck rather than downloading the dll. This means if I update on steam and it's not backward compatible, a worst case scenario is that maybe half the mods break. This is of cause completely unacceptable and even the excuse "it's very easy to fix in xml" is not good enough. This means breaking backward compatibility is simply not an option.

If I have to do something, which will break backward compatibility, I will add a new class, possibly based on copy paste of an existing one and then change the new one. Existing mods can then continue to work off the old class. It's entirely likely that I will update the guide to tell modders not to make new mods using the old class, but it will still be there to ensure mods will not break.

If a mod breaks from this (like the user stops using ModCheck), all what will happen is an error in the log each time a ModCheck class is called and all the calls will return false, like mod is not loaded, regardless of it is or not. Other than that, the mods will behave normally, meaning they will often be fully playable. Even if it's not the end of the world to cause problems like this, I will still avoid it as much as possible.

Quote from: larSyn on November 15, 2017, 10:18:53 AMWould something that lets users know about compatibility patches be possible?  For example, I have a patch for Vegetable Garden in my mod.  When someone activates my mod would it be possible to have it say something like "Hey this mod works great with Vegetable Garden!" or something else along those lines?
That's a nice idea. Here is what I'm going to do:

  • Add two new optional strings to xml (names still unknown). One is for success, the other is for failure.
  • If not empty, the string matching the test result will be written to the log.
  • if errorOnFail is set, the fail string will be written as an error (red)
  • if errorOnFail and the string is empty, the current strings will be used for error messages
It's nice and simple and it allows great freedom to write whatever you want to the log. Maybe adding default options like "yourMod: detected modName and patched itself to become compatible".

Quote from: larSyn on November 15, 2017, 10:18:53 AMPerhaps have it in green text on the log, a pop-up, or something in the Mod Settings menu?  And, while I'm at it here, maybe also a way to direct them to the Steam/forum page to download it (a url in the xml maybe)?  I'm just starting to learn about C#, so I don't really know what is and isn't doable in regards to this kind of stuff...so don't worry about it if this isn't possible.
All nice ideas, but they all clashes with the design strategy, which is to make a lightweight mod, which adds classes to be called from xml and not touch existing code. By not touching any existing code, the chance for conflicts with other mods is kept at a minimum. It's likely part of the reason why the very same DLL works on both A17 and A18. Not just the same code, but the very same file. The difference between A17 and A18 releases is the number in About.xml and nothing else.

I agree it would be nice to add such info in the mod load menu, but it would have to be done by some other mod. Maybe I will do something like that in the far future, but not anytime soon and it will be in a different mod. It is important that if it conflicts with anything else modding the mod menu, people can turn that feature off without turning ModCheck itself off. With a little creativity, it should be possible to make some xml layout, which can be executed by both mods, meaning you only have to write once that your mod works together with some other mod.
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

Is there anybody, who use the patch operators from ModCheck for conditional patching?
I mean the only real reason to do that is to patch if a mod is loaded or not loaded using ModCheck.isModLoaded and B18 fixed that issue with PatchOperationFindMod.

The reason I'm asking this is that I have run into some limitations and is considering to discontinue PatchOperations and implement my own system. The benefits would be the following (most likely incomplete):

  • Allows translated text
    Patching is done prior to loading the language, making translation impossible.
  • Much cleaner xml layout
    With complete control of the xml loading code, everything goes as short or long as needed.
  • Better control and easier access to fixes
    I just had one error repeat 415 times and fixing that seems... tricky
  • ModCheck xml is ignored if user didn't load ModCheck
    Right now that will cause errors, meaning ModCheck is mandatory. A new system will make it optional.
  • Xml file should be planned to work with a mod for the mod list in the future
The mod list is not something I have plans for at all for the time being. However with a well defined xml layout and C# code to copy paste to pass the xml file, any mod can read the contents and say add red dots if mod is missing requirements or order is incorrect and even write what is wrong. One beauty of this approach is that if somebody writes such a mod for the modlist, the mod creators can write one xml file to support both mod list and ModCheck, making it really easy to use both.

The only issue is that the new system doesn't support patching based on mod order or mod version. I don't really see a big need for this though, but since those are already released, I feel like I better need to ask. Maybe I should just leave those in the DLL and ignore them. It's not like they will hurt the ability to add a new system.
ModCheck - boost your patch loading times and include patchmods in your main mod.

larSyn

Quote from: Nightinggale on November 20, 2017, 10:47:36 PM
Is there anybody, who use the patch operators from ModCheck for conditional patching?
I mean the only real reason to do that is to patch if a mod is loaded or not loaded using ModCheck.isModLoaded and B18 fixed that issue with PatchOperationFindMod.

Yup, I do, if by "conditional patching" you mean "if Mod X is loaded run this patch" (like I've said before, I'm still very green with all this coding stuff, so if I screw up with/misunderstand some terminology, sorry...I'm actually a 3d artist/designer by profession, so I'm slightly out of my element lol).  I made all my patches with ModCheck in A17 and they all continue to work fine in B18.  I didn't find out they were adding "PatchOperationFindMod" until after I had finished writing the patches with ModCheck. Not a huge deal if you remove it, just means a bunch of copy/pasting the new FindMod operation.  I also used it to check for Architect Sense and then used "ModCheck.loadOrder" to make sure they are loaded in the proper order.

Glad you liked some of my suggestions.  And I see what you mean about the redirect defeating the purpose of the lightweight design.  Looking forward to seeing what you do with it all!


Nightinggale

ModCheck 1.2 has been released on Github and steam. I updated the first post with a changelog.

I don't think I will develop this much further, if at all. It seems fairly complete. Also I discovered something interesting in the vanilla code yesterday. It has given me the idea to make a completely new mod where when the game starts, it will verify the loaded mods similar to what ModCheck does. However on failure, it will create a popup asking if it should fix the problems automatically and if you say yes, it will change the order of loaded mods and then restart the game. It might even become able to detect missing mods and subscribe to them from steam if the user clicks yes. While I'm far from certain that this will ever work, it sounds too good to not investigate further and ignore that it smells strongly of being very time consuming to investigate and make.
ModCheck - boost your patch loading times and include patchmods in your main mod.

SargBjornson

I'm trying to use Modcheck to provide A Dog Said compatibility for Genetic Rim, and everything went perfectly so far, except for one thing! Operations using attributes on the xpath, like for example:

<xpath>/Defs/RecipeDef[@Name = "OldWoundsAnimal"]/recipeUsers</xpath>

seem to be failing. Is this a limitation, or am I derping hard?

Nightinggale

If you have an issue where one xPath works and one fails, then it's a vanilla issue. All ModCheck does is make a test and return true/false to tell the vanilla patch engine if the test passed. If it passes, then the vanilla patch engine moves on to the next PatchOperation and whatever happens here is completely unrelated to ModCheck.

I left out log writing because while ModCheck can do that, it's completely unrelated to how patching takes place.
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

I downgraded the steam version to v1.1 because people report severe performance issues in v1.2, like adding 10 minutes to the startup when using a lot of mods and v1.1 apparently didn't have this issue.

The big question is why because there is no obvious candidate for this, particularly since the vast majority of mods will not even call the DLL.
ModCheck - boost your patch loading times and include patchmods in your main mod.

larSyn

Quote from: Nightinggale on November 24, 2017, 03:46:09 AM
I downgraded the steam version to v1.1 because people report severe performance issues in v1.2, like adding 10 minutes to the startup when using a lot of mods and v1.1 apparently didn't have this issue.

The big question is why because there is no obvious candidate for this, particularly since the vast majority of mods will not even call the DLL.

I had a couple users on Steam report this to me as well.  I know that one of them (haven't heard back from the other) has the standalone version of ModCheck downloaded, so I'm guessing that is what caused his long loads.  Also, removing my mod stopped the long load times.  This leads to me to a few questions, does the standalone version take precedence over an included dll?  Is it possible that the presence of both causes the long load times?  Did the people who reported it to you have my or some other mod with the ModCheck dll in it? 

*Edit: I've tried downloading the standalone pre-release on github, and running it with my mod with both versions of the dll, but I still couldn't reproduce this.  I will add that I only have a handful of mods installed, if that helps/makes any difference at all.

Nightinggale

Quote from: larSyn on November 24, 2017, 11:16:52 PMThis leads to my question, does the standalone version take precedence over an included dll?
The one used is the one first in the mod list, which is why I recommend the steam version to be first. The reason is that v1.2 can read all xml files for v1.1, but v1.1 can't read v1.2 files if they use the tags added in v1.2.

I figured out what the problem is. It turns out that patching is done differently from what I thought. Instead of reading all defs and then patch, it reads everything in patches in all mods, then read def xml files in the mods one by one and when read file is read, all patches is executed on it. Last all the xml files are merged into one big system in the game.

As a result of this, each patch in ModCheck is executed once for each xml file in Defs in each mod instead of once like I thought it would. Obviously this scales very poorly. Since the result depends on the mod list only, not the individual files, I have turned the checks into checking the first time they are called and the following will return the cached result. I will release this once I'm done testing to ensure that the cache will not break something else.

As a nice sideeffect this happens to be the reason why output was written multiple times in the log and the fix will at the same time fix this issue as well.

All versions of ModCheck suffer from this issue, but the reason why v1.2 is worse is that it supports multiple mod names. What it does is it adds modName to the list and then it loops the list until it finds one, which is present. If none are present, it will loop the entire list. The problem with this is that it adds modName each time it's called, meaning even if you gave just one name, the 500th xml file will have a list of 500 modNames, all the same and it will check each. This mean while v1.1 will have a slowdown of (number of def files), v1.2 will have a slowdown of (number of def files)2. Each is worst case scenario, but it seem that some people ran into it with v1.2.

I ran some tests and with 200 mods and ModCheck can do around 50k tests in the time it takes to load the def files. Even with room for scaling issues I didn't take into account, I will say that the cache will make ModCheck feel instant.
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

Quote from: larSyn on November 24, 2017, 11:16:52 PM*Edit: I've tried downloading the standalone pre-release on github, and running it with my mod with both versions of the dll, but I still couldn't reproduce this.  I will add that I only have a handful of mods installed, if that helps/makes any difference at all.
To reproduce this, you need tests where modName is not in your modlist. When that happens, the execution time will be multiplied by (number of def files in all mods)2. I didn't manage to hit that condition either by testing different mod configurations at random. I had run multiple times with verbose logging and read vanilla source code before I figured out what happened and how to trigger the slowdown.
ModCheck - boost your patch loading times and include patchmods in your main mod.

Nightinggale

ModCheck 1.3 has been released. Upgrading right away is strongly recommended.

Table to give an idea of the scale of the performance issue. It lists iterations (executions) of the check code vs the number of def files in all mods combined. This includes core. Remember this is for each test in xml, those numbers will have to be multiplied by the number of times somebody adds patch operation.








500
1000
2000
PatchOperationFindMod (vanilla)
501
1001
2001
ModCheck 1.0
501
1001
2001
ModCheck 1.1
501
1001
2001
ModCheck 1.2*
125251
500501
2001001
ModCheck 1.3**
1
1
1
*v1.2 can be as fast as v1.1, but it depends on what is tested and the test result.
**While called the same number of times as vanilla, it executes once and use cache for the rest of the calls.

I view the performance issue as a lucky accident because if it didn't, we would still be stuck with v1.1 speed. Now we know time spend on each check is too low to be measured because it's below 0.001 seconds. Not even vanilla is that fast.
ModCheck - boost your patch loading times and include patchmods in your main mod.

SargBjornson

Hi Nightinggale!

People reported errors to me, and it seems Modcheck is giving some problems with 1.3. I swapped it for 1.1 and it seems to work. The operation that seems to be failing is:

<li Class="ModCheck.isModLoaded">
<modName>A Dog Said...</modName>
<yourMod>GeneticRim a18</yourMod>
</li>


Which seems quite simple, and works on 1.1

Nightinggale

ModCheck 1.4 has been released to fix the issue mentioned below.

Quote from: SargBjornson on November 26, 2017, 05:14:57 AM
Hi Nightinggale!

People reported errors to me, and it seems Modcheck is giving some problems with 1.3. I swapped it for 1.1 and it seems to work. The operation that seems to be failing is:

<li Class="ModCheck.isModLoaded">
<modName>A Dog Said...</modName>
<yourMod>GeneticRim a18</yourMod>
</li>


Which seems quite simple, and works on 1.1
Now that's a bug report, which is really useful when it comes to figuring out what went wrong. It provides both the file, which failed, the mod combo and the info that it used to work. This means instant success in reproducing the problem, which doubles as testing for a fix and the git history provides info on what changed since it last worked.

The issue turned out to be that a copy paste error had resulted in having two variables with the same name, which meant the cache update in this case was written to the short lived variable and then discarded. Usually compilers warn about hiding a variable like that because it's almost always a bug, but it doesn't look like I can get MSVS to provide that warning ???
ModCheck - boost your patch loading times and include patchmods in your main mod.


Nightinggale

Following the v1.2 incident, I have been looking into patching and performance. It turns out that patching is actually quite slow and as the number of mods increase, so does both the number of patches and how much time each patch will spend patching. Poorly written patches can easily take up most of the startup time, though good written patches can't be considered fast either, just faster than horribly slow. Interestingly the majority of the time spend on a patch is for that patch to look through def xml files and go "no, nothing in this one to patch".

I have come up with a concept where you can write something like:
<li Class="ModCheck.something">
<modName>A Dog Said...</modName>
<file>Defs/RecipeDefs/Recipes_Surgery.xml</file>
</li>

This will then be a test, which is only passed when the two strings match the strings for the current file. This comparison is a lot faster than xpath searching to locate the correct file and as such should improve performance. Since the vast majority of patches are written to patch one specific file, this approach should be something, which can be used for more or less all patches.

An added bonus for this is that it exposes data, which can be used to profile each PatchOperation. Right now xml loading and patching is heavily profiled with results written to the log if verbose logging is on. However it is based on files/mods and figuring out if your newly added patch file is slow is almost impossible. I have an idea on how to get combined time spend on each PatchOperation, which should be reported with owner modname. That way everybody can identify poorly written patches and we can hopefully locate and optimize all of them. I estimate that for people with lots of mods, this can likely save at least 30 seconds for every minute spend on xml loading, though going as high as 45-50 seconds can't be completely ruled out.

There is one big problem though. This will require Harmony. This will clash with the current distribution system where people add a single dll file to their own mods. Instead it will become like HugsLib or similar where the user has to add it. I can probably do something like HugsLibChecker, but the user still has to add it. The number of steam subscribers is 672 and that's before any mod has it as requirement.

I thought about splitting ModCheck into two or somehow make a minor version of it, but I think it's a bad idea. Ideally everybody should use the fastest approach and having a version with isModLoaded only or similar will encourage not using the new and faster checks.

Do any of you have anything to say about this before I make up my mind on what to do?

Quote from: SargBjornson on November 29, 2017, 03:41:15 PM
So it should be safe to update to 1.4 now, right? :)
Yeah, it was safe the moment it was released. If people subscribed on steam they already upgraded because the standalone mod takes priority if people load it first, which the description tells them to do  ;)
ModCheck - boost your patch loading times and include patchmods in your main mod.