RimWorld

RimWorld

Research Data
Performance degradation report related to Subcore Scanner
1. Environment
- RimWorld 1.6 (vanilla) with all DLCs enabled
- Mods: Harmony, Dubs Performance Analyzer, Research Data (no other mods)

2. Reproduction steps
- Start a new colony with only the mods above enabled.
- Build a Subcore Scanner and start operating it.
- Open Dubs Performance Analyzer → Harmony Patches.

3. Observed
- While the Subcore Scanner is active, calls to Verse.IngredientCount.GetBaseCount() surge, and DPA attributes time to ResearchData_IngredientCount_GetBaseCount_Patch:Prefix.
- This causes a noticeable tick rate drop during scanner operation.

4. Control
- Disabling Research Data (keeping Harmony + vanilla + DLCs + DPA) removes the excessive calls and the tick rate drop.
Last edited by Cosmosteller; 13 Aug @ 3:49am
< >
Showing 1-15 of 15 comments
kongkim  [developer] 13 Aug @ 4:10am 
Cannot see what Subcore Scanner should have to do with Research Data? Its a bit wired :)
kongkim  [developer] 13 Aug @ 4:11am 
press F12 and give me a full log of your tests.
@kongkim
https://imgur.com/a/research-data-mod-report-vDQ9YOp

There is nothing unusual shown in the game’s own debug log. I’ve attached screenshots from Dubs Performance Analyzer with brief captions. In a developer quick-test environment, the performance drop was minimal, but in an actual gameplay environment it is significant (in my 6-year save, the tick rate drops by over 100). The logs show a very large number of calls to ResearchData.ResearchData_IngredientCount_GetBaseCount_Patch:Prefix, which do not occur while the game is paused. Interestingly, if the activated scanner is selected while paused, a relatively small amount of processing still occurs. These two conditions can combine, and if the building is selected while the game is running, the number of calls increases further. If the scanner is not selected while paused, these calls do not occur at all.
Last edited by Cosmosteller; 13 Aug @ 5:42am
kongkim  [developer] 13 Aug @ 5:49am 
Originally posted by Cosmosteller:
@kongkim
https://imgur.com/a/research-data-mod-report-vDQ9YOp

There is nothing unusual shown in the game’s own debug log. I’ve attached screenshots from Dubs Performance Analyzer with brief captions. In a developer quick-test environment, the performance drop was minimal, but in an actual gameplay environment it is significant (in my 6-year save, the tick rate drops by over 100). The logs show a very large number of calls to ResearchData.ResearchData_IngredientCount_GetBaseCount_Patch:Prefix, which do not occur while the game is paused. Interestingly, if the activated scanner is selected while paused, a relatively small amount of processing still occurs. These two conditions can combine, and if the building is selected while the game is running, the number of calls increases further. If the scanner is not selected while paused, these calls do not occur at all.
The Analyzer just shows there is a problem, but we alrady know that as you get the FPS drops frm the log. The Analyzer do not help us in any way.
I still need a full log to have anything to go on, my guss is something try to patch something with research, but i do not know what.

So still need to look in the log.
@kongkim

https://drive.google.com/file/d/1lcy60Ayse1801HRir4A8gNO6AsutHDU9/view?usp=sharing

I’m attaching the Player.log file generated after following these steps:
Launch the game → Developer quick test → Place a generator and a scanner → Open the DPA window → Activate the scanner → After some time, save and exit.
This is my first time submitting a log, so I’m not sure if I did it correctly. Please let me know if anything is wrong or if you need additional information.
kongkim  [developer] 13 Aug @ 6:18am 
Haha, it's all fair :) There is a first time for everything.
Just ask.

But when a modder in RimWorld asks for a log, it's a HugsLib log, as many mods use it, and it's the best way to make logs and find errors.

You need to have
HugsLib mod active, or its standalone version.
https://gtm.steamproxy.vip/sharedfiles/filedetails/?id=818773962
https://gtm.steamproxy.vip/sharedfiles/filedetails/?id=2873415404

And when you see the errors in the log, there will be a green button that says share log in the log window. Click that, then copy the link. Alternatively, you can open it in a browser and copy and paste the link to the whole log.
No need to upload things, etc.

I gladly help you, but it's still a weird thing, so no guarantees that I can find the problem :)
@kongkim

Thanks for the guidance :) Here are two HugsLib logs from a minimal setup (Harmony + HugsLib + DPA + vanilla DLCs), using the same quick-start steps. Both cases followed the same process: place a generator and a scanner → activate the scanner → pause the game and share the log.

- With Research Data enabled: https://gist.github.com/HugsLibRecordKeeper/2d97111d2742801df8be578b44a9d46b#file-output_log-txt

- With Research Data disabled: https://gist.github.com/HugsLibRecordKeeper/a9f72de5505bd99f49e439d7541038e8
kongkim  [developer] 13 Aug @ 6:49am 
I looked at the log, and see no errors?

You said it spamed errors ResearchData_IngredientCount_GetBaseCount_Patch:Prefix.?
If it spam errors it will hit your FPS, and that is what i need to see.

In the log right now there are nothing wrong that i can see. :)
@kongkim

To clarify, I didn’t mean error spam. There are no errors in the log. The issue is an extreme number of calls to Verse.IngredientCount.GetBaseCount() while the Subcore Scanner is active, which Dubs Performance Analyzer attributes to ResearchData_IngredientCount_GetBaseCount_Patch:Prefix. The high call frequency + cost causes a tick-rate slowdown, even though the log shows no errors.
kongkim  [developer] 13 Aug @ 7:18am 
but things like that normally always show in the log?
If it happens again, try make a log, otherwise i have no idea what it is. Never seen it before.
@kongkim

I decompiled the mod and noticed that in ResearchData_IngredientCount_GetBaseCount_Patch:Prefix, the method GetRecipeDefForIngredient() scans all RecipeDefs every time it runs. This operation is O(n) over the number of RecipeDefs, and when the Subcore Scanner is active, Verse.IngredientCount.GetBaseCount() is called extremely frequently, causing this full scan to repeat many times per tick. This performance drop will not appear in the log because it’s “normal” execution rather than an exception.

I experimented with changing the code to build a cached IngredientCount → (RecipeDef, index) map once and then use O(1) lookups instead of scanning every time. The call frequency stayed the same, but in my tests, the per-tick delay dropped significantly — the Average Per Frame in Dubs Performance Analyzer went from about 0.3xx–0.5xx down to 0.00x.

I don’t fully understand all aspects of RimWorld modding, so I can’t be certain whether this change could have unintended side effects, but I believe it’s unlikely based on my testing.

I’m attaching the modified part of the code for your reference.

https://drive.google.com/drive/folders/1rDh2hO6b-7JaNBkYObXEYvCE43ppdfRd?usp=sharing
kongkim  [developer] 13 Aug @ 8:53am 
I looked at it, and Im not sure, way it happens, but i will try to implement a fix later or tomorrow to see if it can fix it :)
kongkim  [developer] 14 Aug @ 3:39am 
@Cosmosteller I have tried to make a fix, but im not 100% sure if it fixes it, as im working a bit in the blind as im not 100% sure way it dose it.

Try do unsub the mod, and resub it again, do download the new files.
Last edited by kongkim; 14 Aug @ 3:39am
@kongkim
I’ve tested the updated version after unsubscribing and resubscribing as you suggested.
Unfortunately, the performance drop still occurs under the same conditions. The Average Per Frame in DPA is still around 0.3xx.
kongkim  [developer] 14 Aug @ 9:42am 
Originally posted by Cosmosteller:
@kongkim
I’ve tested the updated version after unsubscribing and resubscribing as you suggested.
Unfortunately, the performance drop still occurs under the same conditions. The Average Per Frame in DPA is still around 0.3xx.
Okay thx, will try something else then.
It just do not understand way more people do not have this problem.
< >
Showing 1-15 of 15 comments
Per page: 1530 50