[1.4.3 <= KSP <= 1.12.5] KSP Recall - 0.5.0.2- 2024-0521

[아무생각]

i need help!

loading has been blocked here

useing ksp 1.11.2 version

and

this is my mod list

[Lisias]

12 minutes ago, 아무생각 said:

i need help!

loading has been blocked here

useing ksp 1.11.2 version

and

this is my mod list

Hi, Fellow... ClueLess?... Kerbonaut!

I need your KSP.log file, and since it's MM related, all the MM logs too. Zip KSP.log (on the same place where you will find KSP.exe) and everything inside the Logs folder on the same place and send it to me. This will help me to locate the point of failure and then try to reproduce it here to see what's happening.

I'm without time for exploratory tests these days due Real Life™ obligations, so I can't spare the time to do too much testings.

[아무생각]

4 minutes ago, Lisias said:

Hi, Fellow... ClueLess?... Kerbonaut!

I need your KSP.log file, and since it's MM related, all the MM logs too. Zip KSP.log (on the same place where you will find KSP.exe) and everything inside the Logs folder on the same place and send it to me. This will help me to locate the point of failure and then try to reproduce it here to see what's happening.

I'm without time for exploratory tests these days due Real Life™ obligations, so I can't spare the time to do too much testings.

ok! here is my ksp log zip  

I don't know how to upload the file, so I replace it with a link.
You can download a compressed copy of ksp.log from the link.

https://cdn.discordapp.com/attachments/607128852791296006/834243216312107038/KSP.zip

[Lisias]

10 minutes ago, 아무생각 said:

ok! here is my ksp log zip  

I don't know how to upload the file, so I replace it with a link.
You can download a compressed copy of ksp.log from the link.

It's exactly how to proceed, thanks! (there's a link somewhere on Forum about this, but I forgot to mention it)

Your log is huge, something is borking on a loop on your rig. Usually it's an older version of MiniAVC, and you have it borking on your rig:

[EXC 10:17:36.517] UnauthorizedAccessException: Access to the path "C:\Program Files (x86)\Kerbal Space Program stock\MiniAVC.log" is denied.
    System.IO.FileStream..ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share, System.Int32 bufferSize,
System.Boolean anonymous, System.IO.FileOptions options) (at <ad04dee02e7e4a85a1299c7ee81c79f6>:0)
    System.IO.FileStream..ctor (System.String path, System.IO.FileMode mode, System.IO.FileAccess access, System.IO.FileShare share, System.Int32 bufferSize,
System.IO.FileOptions options, System.String msgPath, System.Boolean bFromProxy, System.Boolean useLongPath, System.Boolean checkHost) (at <ad04dee02e7e4a85a1

There's 56.525 occurences of it on the file.

Fortunately, things are way less scary than it appears. Install ZeroMiniAVC and things should be fine:

 

On a side note, if you don't use CKAN, you may be interested on this thing (it helps to keep your installment updated):

Cheers!

[아무생각]

14 minutes ago, Lisias said:

진행하는 방법입니다. 감사합니다! (이에 대한 포럼 어딘가에 링크가 있지만 언급하는 것을 잊었습니다)

로그가 거대하고 장비의 루프에서 무언가 지루합니다. 일반적으로 MiniAVC의 이전 버전이며 리그에서 지루합니다.

파일에 56.525 개의 항목 이 있습니다.

다행히 상황은  방법  이 나타나는 것보다 덜 무서운. ZeroMiniAVC를 설치하면 괜찮습니다.

 

어떤 측면에서 사용하지 않는 경우 테, CKAN을 , 당신이이 일에 관심이있을 수 없다 (당신의 분할 업데이트를 유지하는 데 도움이) :

건배!

I downloaded the plugin, but it doesn't work.

[Lisias]

1 hour ago, 아무생각 said:

I downloaded the plugin, but it doesn't work.

The first time ZeroMiniAVC runs, KSP still halts because by the time ZeroMiniAVC manages to get rid of the oldies, they were already loaded.

Restart KSP and see what happens.

If even by that your rig still halts, publish the new KSP.log again and I will check what happened.

[UltraJohn]

11 hours ago, Lisias said:

 

1. Remove the @Contracts section.
   1. Fire up KSP, try again
2. Remove the CONTRACT_CONFIGURATION section.
   1. ditto
3. AGENT
4. CONTRACT_GROUP

It seems to be the 1st that's the culprit here. Completely removing @Contracts section fixes the issue. I have also tried removing individual things from inside the @Progression block as well, and I have observed that removing these 2 lines (or setting them to False) is what fixes the fps:

        @DisableTutorialContracts = True
        @DisableProgressionContracts = True

I also tried just removing one of each to narrow it down further... And this is where I'm probably gonna really baffle your mind...

We've already established that removing both lines fixes the issue. But what if I remove just line 1? The issue is still gone. But what if I remove just line 2? The issue is also gone! But if both lines are present, the issue returns, somehow.

 

Logs:

With the whole @Contracts block removed: https://www.dropbox.com/s/hefmflmslilywxf/KSP.log?dl=0

With just @DisableProgressionContracts removed/set to false: https://www.dropbox.com/s/dzsjt60tqlc1wgc/KSP.log?dl=0

[Lisias]

On 4/21/2021 at 9:56 AM, John007qwe said:

It seems to be the 1st that's the culprit here. Completely removing @Contracts section fixes the issue. I have also tried removing individual things from inside the @Progression block as well, and I have observed that removing these 2 lines (or setting them to False) is what fixes the fps:

        @DisableTutorialContracts = True
        @DisableProgressionContracts = True

I also tried just removing one of each to narrow it down further... And this is where I'm probably gonna really baffle your mind...

We've already established that removing both lines fixes the issue. But what if I remove just line 1? The issue is still gone. But what if I remove just line 2? The issue is also gone! But if both lines are present, the issue returns, somehow.

It's a wild guess, and I'm not being able to reproduce the issue here is not helping - but I think we have some missing initialisation somewhere on KSP, and it ends up fixed by "accident" when you unlock the RobotArmScanner.S1 on the Tech Tree.

Apparently you need a beefy machine in order to reproduce this in a perceptible way. I managed to get ~15 fps on my MiniCrap by deactivating VSync and AntiAlias, but the it dropped to 13.35 once I upgraded the facilities to be able to research Advanced Exploration, where the RobotArmScanner.S1 is...

Why this was triggered by the mere presence of the Recall DLLs (even by not being patched anywhere...) is something that only the KSP developers can answer (at least, without someone breaking some rules).

I'm afraid I can't be of much more help anymore - with this thing happening without the need for Recall running at all, and without access to KSP source code guts, all we can do is keeping guessing in the hope something yells by being hit.

I think we have one more test o be done before trying to find a way to report the thing on KSP's bug track (where it will probably be forgotten, but anyway...). Remove the file GameData/SquadExpansion/Serenity/Contracts/contracts.cfg . Since the robotic arm is part of the Breaking Ground DLC, perhaps the problem is on this DLC's contracts.

Of course, by removing Breaking Ground at all the issue should be "solved" too, as the whole thing is going to disappear from your rig, Or perhaps not? It may worth a shot to check if by removing Breaking Ground the issue "moves" to another place (i.e., the FPS still goes down, and it's only fixed by unlocking something else...).

Again, not being able to reproduce the thing on my rig is not helping too much, as this is something I could had tried myself easily...

[UltraJohn]

3 hours ago, Lisias said:

I think we have one more test o be done before trying to find a way to report the thing on KSP's bug track (where it will probably be forgotten, but anyway...). Remove the file GameData/SquadExpansion/Serenity/Contracts/contracts.cfg . Since the robotic arm is part of the Breaking Ground DLC, perhaps the problem is on this DLC's contracts.

Of course, by removing Breaking Ground at all the issue should be "solved" too, as the whole thing is going to disappear from your rig, Or perhaps not? It may worth a shot to check if by removing Breaking Ground the issue "moves" to another place (i.e., the FPS still goes down, and it's only fixed by unlocking something else...).

The results I've gotten from trying those two options are a bit of a weird one. Removing the contracts.cfg file posed no real change other than making my framerate fluctuate in a slightly bigger range, so not really any solution here it seems.

Removing the whole SquadExpansion folder would at first glance fix the issue with the part, since it would no longer exist. And it kinda did, but then, not really. It just moved the issue to somewhere else. When I loaded into KSC I noticed the framerate would be at the same lower level as before. But now it didn't matter how many parts i researched, it would stay the same. Instead I found that opening the cheats menu and clicking on "Progression" would somehow fix the framerate now. Perhaps you have any insight into what this cheat does and what could be the cause of it fixing the problem?

 

I made some new video clips of the situations.

This one is with SquadExpansion and showing that unlocking the robot arm scanner by unlocking all tech increases the fps. And that upgrading the Astronaut Complex to level 3 also increases fps:

https://streamable.com/uqh4jm

This second clip shows that after removing SquadExpansion, the issue is now solved only by the progression cheat (which I don't know what it does):

https://streamable.com/9g22lp

 

Also, on a side note, I've gotten some warnings in my log that I don't know why are there. Would you happen to know what it means?

[WRN 23:44:29.513] Contract Log: ContractDefs prebuilt craft at C:/Program Files (x86)/Steam/steamapps/common/Kerbal Space Program/KSP_x64_Data/../GameData/Squad/Contracts/PreBuiltCraft/RoverContract/Contract Rover 1a.craft invalid.
[WRN 23:44:29.513] Vessel Contract Rover 1a is missing part roverBody.v2
Vessel Contract Rover 1a is missing part externalTankRound
Vessel Contract Rover 1a is missing part domeLight1
Vessel Contract Rover 1a is missing part longAntenna
Vessel Contract Rover 1a is missing part stripLight1
Vessel Contract Rover 1a is missing part roverWheel2
[WRN 23:44:29.516] Contract Log: ContractDefs prebuilt craft at C:/Program Files (x86)/Steam/steamapps/common/Kerbal Space Program/KSP_x64_Data/../GameData/Squad/Contracts/PreBuiltCraft/RoverContract/Contract Rover 1b.craft invalid.
[WRN 23:44:29.516] Vessel Contract Rover 1b is missing part roverBody.v2
Vessel Contract Rover 1b is missing part externalTankRound
Vessel Contract Rover 1b is missing part domeLight1
Vessel Contract Rover 1b is missing part stripLight1
Vessel Contract Rover 1b is missing part roverWheel2
Vessel Contract Rover 1b is missing part FuelCell

Log: https://www.dropbox.com/s/zfqvpz6cit9tbge/KSP.log?dl=0

[Lisias]

13 minutes ago, John007qwe said:

The results I've gotten from trying those two options are a bit of a weird one. Removing the contracts.cfg file posed no real change other than making my framerate fluctuate in a slightly bigger range, so not really any solution here it seems.

13 minutes ago, John007qwe said:

Removing the whole SquadExpansion folder would at first glance fix the issue with the part, since it would no longer exist. And it kinda did, but then, not really. It just moved the issue to somewhere else. When I loaded into KSC I noticed the framerate would be at the same lower level as before.

Interesting....

14 minutes ago, John007qwe said:

But now it didn't matter how many parts i researched, it would stay the same. Instead I found that opening the cheats menu and clicking on "Progression" would somehow fix the framerate now. 

If my memory serves me well, it will maximize your contract achievements. You will get all the milestones as fulfilled (First Launch, Tower Buzz, etc).

If I'm right, we may had found what the trigger is triggering...

18 minutes ago, John007qwe said:

Perhaps you have any insight into what this cheat does and what could be the cause of it fixing the problem?

We must start to consider the hypothesis that this may not be exactly a "bug", but a feature implemented without optimisation (assuming it would be possible to optimise the fature, obviously). A non functional enhancement, if you like.

Apparently, something on the TechTree is constantly looking for achievements (IIRC, some achievements would give you in advance some parts you didn't researched yet on Tech-Tree, so I think the Tech-Tree code is constantly rescanning the Achievements looking for them).

Perhaps this constant rescanning (assuming my guess sticks) is a self-defense measure for add'ons that change the TechTree or the Contracts at runtime?

22 minutes ago, John007qwe said:

Also, on a side note, I've gotten some warnings in my log that I don't know why are there. Would you happen to know what it means?

[WRN 23:44:29.513] Contract Log: ContractDefs prebuilt craft at C:/Program Files (x86)/Steam/steamapps/common/Kerbal Space Program/KSP_x64_Data/../GameData/Squad/Contracts/PreBuiltCraft/RoverContract/Contract Rover 1a.craft invalid.
[WRN 23:44:29.513] Vessel Contract Rover 1a is missing part roverBody.v2
Vessel Contract Rover 1a is missing part externalTankRound
<yada yada yada>

 

Yep, I found these ones too on my KSP.log. 

-- -- -- STOP THE PRESS ! I THINK I REPRODUCED IT!!! -- -- -- 

I started a new Career Game, then cheated me a lot of Science, then researched things as follows:

1. Start (already researched)
2. Engineering 101
3. Survivabilty
4. Basic Science
5. Space Exploration

On this point, I was not being able to do more research because my facilites were not up to the task. So I cheated me a lot of funds and upgraded the R&D one level.

When I came back to R&D, my FPS raised from ~14 to ~15.3 on my MiniCrap. It's about 9% increase on the fps (your videos shows a FPS increase of 23 to 30% more or less).

Checking your first video again, I noticed that you had upgrade the R&D first then executed the test.

Why changing the point in which you upgrade the R&D affects where the fps impact happens I don't have the slightest clue, but it supports my current thesis of being just some code (over)loading the critical path of the frame.

On a blind guess, perhaps using FixedUpdate instead of Update would be a good enough workaround for this problem? There's no simulation happening at this point, I'm pretty sure we can drop the checkings per second count to 2 or 3 (and, again, assuming I'm right o my guess above).

[UltraJohn]

7 minutes ago, Lisias said:

Yep, I found these ones too on my KSP.log. 

So these are normal? I noticed it only happens on a new career save and not a sandbox save, so I assume it's just looking at currently unlocked parts, and showing a warning if the part is not available.. Maybe. I can't find any info on these errors anywhere.

 

9 minutes ago, Lisias said:

Checking your first video again, I noticed that you had upgrade the R&D first then executed the test.

Yes, I just upgraded R&D first since Advanced Exploration requires it.

 

17 minutes ago, Lisias said:

Why changing the point in which you upgrade the R&D affects where the fps impact happens I don't have the slightest clue, but it supports my current thesis of being just some code (over)loading the critical path of the frame.

It also seems that upgrading R&D atleast once can also trigger the astronaut complex fps problem, which is then fixed by upgrading AC to level 3. But I'm not 100% sure on this. I did a lot of testing repeatedly making new saves, but it just gets very tricky to test all kinds of combinations. I'm certain that there's a real fps problem in there somewhere, just not what the exact trigger is.

 

4 minutes ago, Lisias said:

Apparently, something on the TechTree is constantly looking for achievements (IIRC, some achievements would give you in advance some parts you didn't researched yet on Tech-Tree, so I think the Tech-Tree code is constantly rescanning the Achievements looking for them).

Perhaps this constant rescanning (assuming my guess sticks) is a self-defense measure for add'ons that change the TechTree or the Contracts at runtime?

Ah, that could be a possible reason.

 

10 minutes ago, Lisias said:

On a blind guess, perhaps using FixedUpdate instead of Update would be a good enough workaround for this problem? There's no simulation happening at this point, I'm pretty sure we can drop the checkings per second count to 2 or 3 (and, again, assuming I'm right o my guess above).

Well it depends, because the framerate issue isn't only tied to KSC menu, it affects all scenes. If the culprit really is achievement checking, perhaps that part of the code could be moved? Besides, if achievement checking is running every frame, then that seems like a pretty big optimization problem just in general. Such code should only be ran when an action that can trigger the achievement is run. Ofcourse, there might be a different reason that I don't know of. I'm somewhat adept at coding, but I'm no expert lol.

 

But anyway, I was thinking about some workarounds to atleast alleviate the problem, until the real issue is found and fixed. The easiest way is just making a patch that moves the robot arm scanner into the start tech node, which immediately unlocks it and fixes the issue. Something like this:

@PART[RobotArmScanner?S1]:NEEDS[SquadExpansion]
{
	@TechRequired = start
}

 

[Lisias]

24 minutes ago, John007qwe said:

So these are normal? I noticed it only happens on a new career save and not a sandbox save, so I assume it's just looking at currently unlocked parts, and showing a warning if the part is not available.. Maybe. I can't find any info on these errors anywhere.

Apparently yes. Not every log entry is an error, some of them are just informative to be used in the case something weird happens later. I use and abuse this thing on Recall and also on TweakScale, but I have a advantage - I can shove everything on a Debug conditional, and then only distribute the debugging code as needed (essentially what I did recently on Recall). KSP cannot do that, so they need to allow that informative thingy to go on Release.

 

24 minutes ago, John007qwe said:

So these are normal? I noticed it only happens on a new career save and not a sandbox save, so I assume it's just looking at Well it depends, because the framerate issue isn't only tied to KSC menu, it affects all scenes. If the culprit really is achievement checking, perhaps that part of the code could be moved? Besides, if achievement checking is running every frame, then that seems like a pretty big optimization problem just in general. Such code should only be ran when an action that can trigger the achievement is run. Ofcourse, there might be a different reason that I don't know of. I'm somewhat adept at coding, but I'm no expert lol.

There's yet a new problem to cope with. Unity's GUI system was a (bully) joke on the 3, 4 and 5 times. I remember getting some really older version of UBioWerding with a full reimplementation of a Event System for UIs (pretty similar to what we used to use on Windows 3 times), but that code was long deactivated. Peskying people around, I was told that KSP implemented the UI by using the Update as "clock tick" and doing things as we used to do on DOS (mouse GUI on DOS were very allergic to multitasking!!!), and this horribly overloads the FPS too.

On my machine, when the machine gets overload and the FPS goes down, clicking and dragging things is a pain in the SAS - the action now and then are only detected 1 or 2 seconds after I click the mouse button.

If you use the GUI events to trigger code, and that code is run inside the event... Boy, you have a problem.  I know of code (and not only on KSP,  this is happening everywhere!) doing I/O on Mouse Clicks (or Touch) Events, by Turing's Sake! It's probably the reason why my Android programs are borking all the time when the data is moved into the SD Card.  

In a way or another, since Unity 2017 multithreading is way more feasible than before, so you are right on this: there're a lot of opportunities for optimisation on KSP for sure.

[UltraJohn]

3 minutes ago, Lisias said:

In a way or another, since Unity 2017 multithreading is way more feasible than before, so you are right on this: there're a lot of opportunities for optimisation on KSP for sure.

Indeed. I'm looking forward to (hopefully) seeing proper multithreaded optimization in KSP 2. It really sucks having a 10 core cpu which ksp can only use 1 of...

6 minutes ago, Lisias said:

On my machine, when the machine gets overload and the FPS goes down, clicking and dragging things is a pain in the SAS - the action now and then are only detected 1 or 2 seconds after I click the mouse button.

That reminds me, when I load my full modded game up, the SPH/VAB editors can become incredibly laggy when I try to add certain parts and im holding them on the mouse cursor. Probably some kind of mod adding repeated code checking for stuff on the cursor part. Also the searching for parts gets very laggy, and for some reason deleting the text in the search field and clicking the mouse outside, will cause the game to stay at a low fps until i reclick one of the part categories on the left and it resets the search field. That's most likely due to having too many mods in general, increasing the memory usage perhaps. My game runs at around 10-12GB ram usage in total. I installed QuickSearch to alleviate this issue somewhat by having the option to allow search only when pressing enter, so that it doesn't freeze my game for every character i type.

[Lisias]

2 hours ago, John007qwe said:

Indeed. I'm looking forward to (hopefully) seeing proper multithreaded optimization in KSP 2. It really sucks having a 10 core cpu which ksp can only use 1 of...

That will not help so much, as the Unity's Physic Engine is monolithic and mono-threaded, so it will be as much a bottleneck in KSP2 as it's on KSP 1 nowadays.

I had read about multithreaded physics engines, and I think I kinda found a way to... simulate... something like that on a mono-threaded physics engine - so perhaps the KSP2 guys can find something similar (but that works!  ).

On the other hand, just by removing business logic from the Turing Damned UI Thread will be a huge relief, believe-me - things are already ugly by themselves, we don't need to make them worse by screwing up the UI thread.

[Krazy1]

Hi @Lisias I noticed Recall is still at 0.1.0.5 on CKAN.

[Lisias]

2 hours ago, Krazy1 said:

Hi @Lisias I noticed Recall is still at 0.1.0.5 on CKAN.

It must be some mistake, I just checked SpaceDock (where CKAN monitors the Recall releases) and the latest it's there. (I failed to correlate this to any update made in the last 5 minutes , I'm pretty sure you experienced some temporal misalignment on the spacetime fabric - please file a bug report to Albert Einstein Institution ) .

Thanks for the heads up - this was a really tough week on RL™.

[Jebs_SY]

Hello @Lisias,

can it be, that the "refunding" resource triggers this MAS check:
 (Utility.LogWarning(this, "Resource {0} has {1} PartResource modules, but no storage capacity.", resources.displayName, numPartResources);  (Link)
and then continuously spams the console with
"[WRN 01:51:47.393] [MASVesselComputer] Resource Refunding has 12 PartResource modules, but no storage capacity."

I dont know what's the best way to end that log spam. 
Ask @MOARdV,  to stop logging that check, (or maybe make it to be toggled with a debug switch in the config file), while his check usually make sense, or ask @Lisias to add some (fake?) storage, which I assume will add additional problems...
Currently it's adding almost 100 log entries per second....

BR Jebs_SY

Edited May 3, 2021 by Jebs_SY

[Lisias]

1 hour ago, Jebs_SY said:

Hello @Lisias,

can it be, that the "refunding" resource triggers this MAS check:
 (Utility.LogWarning(this, "Resource {0} has {1} PartResource modules, but no storage capacity.", resources.displayName, numPartResources);  (Link)
and then continuously spams the console with
"[WRN 01:51:47.393] [MASVesselComputer] Resource Refunding has 12 PartResource modules, but no storage capacity."

I dont know what's the best way to end that log spam. 
Ask @MOARdV,  to stop logging that check, (or maybe make it to be toggled with a debug switch in the config file), while his check usually make sense, or ask @Lisias to add some (fake?) storage, which I assume will add additional problems...
Currently it's adding almost 100 log entries per second....

How MAS do about ElectricCharge or Ablator? It appears to be a bug on MAS, because I modelled the Refunding stunt to be like the Ablator - but "weighting" like the ElectricCharge (no weight at all).

I checked the code, and I don't see where it tell one thing to another... And I don't even understand why this check is there at first place... Parts with Ablator has this same problem? At first look, it appears that yes, it should be complaining about the ElectricCharge too...

Well, a quick&dirty workaround for it is to give some weight to the Refunding Stunt. It will fool the code I mentioned above, but it will affect your part's weight slightly - so it may affect the performance of your craft. It may even unbalance it if by some reason the counter-part on a symmetry gets a different refunding value. Shove what follows somewhere in the GameData (I suggest __LOCAL, to make it easier to locate later):

@RESOURCE_DEFINITION[RefundingForKSP111x]
{
	@density = 0.001
}

But, and again, it should not be a problem - I failed to see why MAS is wasting time doing this check again and again (this thing is called on FixedUpdate, it appears) and why this should be a problem to it. Ideally @MOARdV  should be reached and asked why this check is there at first place, so I can at least understand why this would be a problem.

[Krazy1]

Well, everything was working smoothly until I I blew up the log with Null Refs and had to Ctrl-Alt-Del. I was on EVA on the Mun beside a ship with cargo storage and I tried to remove a light from storage. It looks like something on Recall or TweakScale? I was using older versions of Recall and maybe TweakScale when I launched the ship around 2 months ago. Just before this I did EVA construction with a probe core, a command seat, a strut - no problem. It didn't like the light.

[WRN 23:06:43.184] [Part]: PartModule indexing mismatch at spotLight1, index 1.
Node 'ModuleCargoPart' found in loaded data, but 'Refunding' is defined in prefab.
Looking for ModuleCargoPart in other indices...
[WRN 23:06:43.184] ...no ModuleCargoPart module found on part definition. Skipping...
[WRN 23:06:43.184] PartModule is null.
[WRN 23:06:43.184] [Part]: PartModule indexing mismatch at spotLight1, index 1.
Node 'TweakScale' found in loaded data, but 'Refunding' is defined in prefab.
Looking for TweakScale in other indices...
[WRN 23:06:43.184] ...TweakScale module found at index 2.
[EXC 23:06:43.190] NullReferenceException: Object reference not set to an instance of an object
	ModuleInventoryPart.PreviewLimits (Part newPart, System.Int32 amountToStore, AvailablePart slotPart, System.Int32 slotIndex) (at <06f13185617646e5bc801baeab53ab75>:0)
	ModuleInventoryPart.Update () (at <06f13185617646e5bc801baeab53ab75>:0)
	UnityEngine.DebugLogHandler:LogException(Exception, Object)
	ModuleManager.UnityLogHandle.InterceptLogHandler:LogException(Exception, Object)
	UnityEngine.Debug:CallOverridenDebugHandler(Exception, Object)
[EXC 23:06:43.213] NullReferenceException: Object reference not set to an instance of an object
	ModuleInventoryPart.PreviewLimits (Part newPart, System.Int32 amountToStore, AvailablePart slotPart, System.Int32 slotIndex) (at <06f13185617646e5bc801baeab53ab75>:0)
	ModuleInventoryPart.Update () (at <06f13185617646e5bc801baeab53ab75>:0)
	UnityEngine.DebugLogHandler:LogException(Exception, Object)
	ModuleManager.UnityLogHandle.InterceptLogHandler:LogException(Exception, Object)
	UnityEngine.Debug:CallOverridenDebugHandler(Exception, Object)
[EXC 23:06:43.231] NullReferenceException: Object reference not set to an instance of an object
	ModuleInventoryPart.PreviewLimits (Part newPart, System.Int32 amountToStore, AvailablePart slotPart, System.Int32 slotIndex) (at <06f13185617646e5bc801baeab53ab75>:0)
	ModuleInventoryPart.Update () (at <06f13185617646e5bc801baeab53ab75>:0)
	UnityEngine.DebugLogHandler:LogException(Exception, Object)
	ModuleManager.UnityLogHandle.InterceptLogHandler:LogException(Exception, Object)
	UnityEngine.Debug:CallOverridenDebugHandler(Exception, Object)

KSP log

[Lisias]

8 hours ago, Krazy1 said:

Well, everything was working smoothly until I I blew up the log with Null Refs and had to Ctrl-Alt-Del. I was on EVA on the Mun beside a ship with cargo storage and I tried to remove a light from storage. It looks like something on Recall or TweakScale? I was using older versions of Recall and maybe TweakScale when I launched the ship around 2 months ago. Just before this I did EVA construction with a probe core, a command seat, a strut - no problem. It didn't like the light.

I think you found something wrong on KSP.

These messages:

[WRN 22:50:22.613] [Part]: PartModule indexing mismatch at seatExternalCmd, index 2.
Node 'ModuleTripLogger' found in loaded data, but 'Refunding' is defined in prefab.
Looking for ModuleTripLogger in other indices...
[WRN 22:50:22.613] ...ModuleTripLogger module found at index 3.
[WRN 22:50:30.276] [Part]: PartModule indexing mismatch at seatExternalCmd, index 2.
Node 'ModuleTripLogger' found in loaded data, but 'Refunding' is defined in prefab.
Looking for ModuleTripLogger in other indices...
[WRN 22:50:30.276] ...ModuleTripLogger module found at index 3.

Are scattered on your KSP.log, and it means only that the index of a module on the savegame is different from the index of that same module on prefab. This happens when you add or remove a Module (by MM patching) between the time you saved that craft (on a file or on a savegame) and the time you load it again. This happens all the time, so it's not a surprise that you locate these messages near nasty exceptions, as they happens when there're no exceptions too.

What are really happening on  your game is this:

[EXC 23:06:43.190] NullReferenceException: Object reference not set to an instance of an object
	ModuleInventoryPart.PreviewLimits (Part newPart, System.Int32 amountToStore, AvailablePart slotPart, System.Int32 slotIndex) (at <06f13185617646e5bc801baeab53ab75>:0)
	ModuleInventoryPart.Update () (at <06f13185617646e5bc801baeab53ab75>:0)
	UnityEngine.DebugLogHandler:LogException(Exception, Object)
	ModuleManager.UnityLogHandle.InterceptLogHandler:LogException(Exception, Object)
	UnityEngine.Debug:CallOverridenDebugHandler(Exception, Object)

And this suggests there's something wrong on the ModuleInventoryPart itself. It also worth to mention that Lights were recently involved on another set of bugs too, so perhaps we have some more unfixed problems on KSP itself? The KSP bug fixing is not known for hunting root causes, but for merely patching the effects where they are found - so perhaps this could be a missed effect from an old problem that it's arising now that the previous effect on the chain was patched?

Without knowing how ModuleInventoryPart.PreviewLimits works, I can only guess - but by looking on the parameters of that function, it appears to be simulating what would happen by storing this light on a part with Inventory.

It worth to mention that TweakScale do not touches the ModuleInventoryPart neither ModuleCargoPart, so it's very unlikely it's playing a role on this problem.

Refunding, theoretically, could be a trigger as it adds Resources at runtime and badly written code would bork on it. You can check this by deactivating Refunding on the lights and trying to reproduce the problem.

Edited May 3, 2021 by Lisias
tyops, as usulla....

[Jebs_SY]

16 hours ago, Lisias said:

But, and again, it should not be a problem - I failed to see why MAS is wasting time doing this check again and again (this thing is called on FixedUpdate, it appears) and why this should be a problem to it. Ideally @MOARdV  should be reached and asked why this check is there at first place, so I can at least understand why this would be a problem.

Can it be, that this is about the storage capacity?
I think he want's to calculate (for example) how much (in percent) is still available. So he iterates over the parts to count all the max storage capacity.
So I think the problem could be, that the "refunding" resource has no part(module?) that can store/hold "refunding".
It's kinda like having 10 electric charge available but 0 battery storage to hold it.  How one then wants to calculate how many % battery charge one has still left? 10-ec out of 0-ec-storage-space? 
I could imagine that's the issue. I could be wrong, though.

Edited May 3, 2021 by Jebs_SY

[Lisias]

30 minutes ago, Jebs_SY said:

Can it be, that this is about the storage capacity?
I think he want's to calculate (for example) how much (in percent) is still available. So he iterates over the parts to count all the max storage capacity.
So I think the problem could be, that the "refunding" resource has no part(module?) that can store/hold "refunding".
It's kinda like having 10 electric charge available but 0 battery storage to hold it.  How one then wants to calculate how many % battery charge one has still left? 10-ec out of 0-ec-storage-space? 
I could imagine that's the issue. I could be wrong, though.

You are probably right, since MAS aims to provide information about parts. However, how MAS behave with the Ablator Resource?

I modelled refunding using Ablator exactly due the use Ablator have on parts - it's something that will vary with use (but, of course, without being "refilled" normally), and there's not storage for them. The only difference is that Ablator has some density, while I choose to go the ElectricCharge way on it to avoid taxing the physics of the part.

Understanding how MAS handles Ablator can help on creating a solution for this on my side. That Quick&Dirty patch of mine (giving 0.0001 density to Refunding) will trick the MAS into behave, but it will affect the physics of the part (very slightly, but will).

[Jebs_SY]

@Lisias
I think the ablator resource also has a "storage tank" on part's that have ablator... hmm.

    RESOURCE
    {
        name = Ablator
        amount = 200
        maxAmount = 200
    }    

from HeatShield1.cfg. 

 

Could it help to set maxAmount to some value that's big enough? This is from a save:

RESOURCE
                {
                    name = RefundingForKSP111x
                    amount = 1150.0000000000002
                    maxAmount = 0
                    flowState = False
                    isTweakable = False
                    hideFlow = False
                    isVisible = False
                    flowMode = None
}

Edited May 3, 2021 by Jebs_SY

[Lisias]

12 hours ago, Jebs_SY said:

Could it help to set maxAmount to some value that's big enough? This is from a save:

Now I got it. The problem is not about Storage in the sense of Cargo or Inventory, but about the Resource's MaxAmount.  

My initial approach was to shove the Refunding Resource on everything at startup and then setting the thing at Editor as needed (tried freezing the  amount to 1 and then set the price per unit as the Refunding, between other stunts), and so I had to convince the Editor to never "filler up" the part - so the MaxAmount was set to zero. I remember seeing a Resource like this somewhere, but I forgot from what Add'On.

But, then, to comply with new use cases I ended up creating the Refunding Resource on flight time when needed only - and since the Refunding is now a hidden Resource, the user cannot "cheat" by transferring Refunds between parts as they were Fuel or ElectricCharge. So I think I can set the MaxAmount to be equal the Amount at runtime - this will make MAS happy, I think.

On a side note, ideally I would create the Refunding Resource only on recovering the Craft - but I realised that this would work only when recovering the craft under focus at the moment - crafts on rails would fail. I tried removing the Refunding everytime the craft gets the focus, and then adding it only when the craft goes to rails, but then I realised that KSP don't issue the recover event when the craft don't have the focus, but yet it's on the physics range of the focused craft - (sigh) had KSP did that, all these problems would just no be able to happen.

On another side note, I think MAS should not be handling hidden Resources - they are set to hidden for a reason.  [Nope. See this comment.]

In a way or another, I will set the MaxAmount to the equal the Amount today by night and see what happens - I think this change will not cause impact on the expected behaviour, and it should make MAS happy.

Thanks for the heads up!

Edited May 4, 2021 by Lisias
Nope...

[Krazy1]

18 hours ago, Lisias said:

And this suggests there's something wrong on the ModuleInventoryPart itself. It also worth to mention that Lights were recently involved on another set of bugs too, so perhaps we have some more unfixed problems on KSP itself?

The thread you linked was started before 1.11.2 was released and EVA construction was horrible before that. I got all kinds of explosions when placing parts. But this time I just removed the part from inventory and got the Null Refs before I could even try to place the part. It's probably still a core game bug. I also installed other types of lights and they worked. I tried the same Mk1 Illuminator again and it gave the Null refs again.  I might try it in stock if I find motivation. Thanks